11.2.0.2.0 bug? 簡單查詢代價異常

aaqwsh發表於2011-07-05
上禮拜五快下班時,同事說一個很簡單的查詢非常慢(單表32條記錄):

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE 11.2.0.2.0 Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

表結構如下(primary key (DIST_ID, PROV_ID)):
SQL> desc COM_DIST_PROV;
Name                                      Null?    Type
----------------------------------------- -------- ----------------------------
DIST_ID                                   NOT NULL NUMBER(4)
PROV_ID                               NOT NULL NUMBER(10)
PROV_NAME                             NOT NULL VARCHAR2(200)

SQL> select count(*) from COM_DIST_PROV;

  COUNT(*)
----------
        32



異常的執行計劃,DISK_READS和Buffer Gets:

SQL_TEXT
----------------------------------------------------------------
SELECT X.DIST_ID FROM COM_DIST_PROV X WHERE X.PROV_ID =
:B1


SQL_ID        CHILD      outline/plan_hash_value                                                  Ex DISK_READS              bg      bg/exec       rows LOAD_TIME
------------- ---------- ---------------------------------------------------------------- ---------- ---------- --------------- ------------ ---------- -----------
b836wun0fy7sh 0          68496714                                                              47267      95377        99212467      2098.98      46092 07-01/17:24
              TOTAL                                                                            47267      95377        99212467      2098.94      46092


Optimizer Plan:
------------------------------------------------------------------------------------------------------------------------------
| Operation                         |  Name                        |  Rows | Bytes|  Cost  | Pstart| Pstop |
------------------------------------------------------------------------------------------------------------
| SELECT STATEMENT                  |                              |       |      |      1 |       |       |
| INDEX SKIP SCAN                   |SYS_C00103606                 |     1 |    6 |      1 |       |       |
------------------------------------------------------------------------------------------------------------


當時急著想下班,簡單看了一眼,沒有考慮資料量和查詢的值,在PROV_ID上建了個索引,其實資料庫原來的執行計劃是很正確的,
雖然INDEX SKIP SCAN,但是資料都在一個索引根塊上。
重新生成執行計劃,執行計劃還是原來的,Buffer Gets變為1:


SQL_TEXT
----------------------------------------------------------------
SELECT X.DIST_ID FROM COM_DIST_PROV X WHERE X.PROV_ID =
:B1


SQL_ID        CHILD      outline/plan_hash_value                                                  Ex DISK_READS              bg      bg/exec       rows LOAD_TIME
------------- ---------- ---------------------------------------------------------------- ---------- ---------- --------------- ------------ ---------- -----------
b836wun0fy7sh 0          68496714                                                              12990          0           12990         1.00      12707 07-01/17:24
              TOTAL                                                                            12991          0           12991         1.00      12708


Optimizer Plan:
------------------------------------------------------------------------------------------------------------------------------
| Operation                         |  Name                        |  Rows | Bytes|  Cost  | Pstart| Pstop |
------------------------------------------------------------------------------------------------------------
| SELECT STATEMENT                  |                              |       |      |      1 |       |       |
| INDEX SKIP SCAN                   |SYS_C00103606                 |     1 |    6 |      1 |       |       |
------------------------------------------------------------------------------------------------------------


今天建了一個類似的表測試了一下,第一次的代價比較高,後續執行就趨於穩定,Buffer Gets變為2:


Execution Plan
----------------------------------------------------------
Plan hash value: 1839328710

--------------------------------------------------------------------------------
--

| Id  | Operation        | Name          | Rows  | Bytes | Cost (%CPU)| Time
|

--------------------------------------------------------------------------------
--

|   0 | SELECT STATEMENT |               |     1 |    26 |     1   (0)| 00:00:01
|

|*  1 |  INDEX FULL SCAN | SYS_C00110119 |     1 |    26 |     1   (0)| 00:00:01
|

--------------------------------------------------------------------------------
--


Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("X"."PROV_ID"=2)
       filter("X"."PROV_ID"=2)

Note
-----
   - dynamic sampling used for this statement (level=2)


Statistics
----------------------------------------------------------
        105  recursive calls
         50  db block gets
       1886  consistent gets
          2  physical reads
      15204  redo size
        525  bytes sent via SQL*Net to client
        524  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          6  sorts (memory)
          0  sorts (disk)
          1  rows processed


Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("X"."PROVINCE_ID"=2)
       filter("X"."PROVINCE_ID"=2)

Note
-----
   - dynamic sampling used for this statement (level=2)


Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
          2  consistent gets
          0  physical reads
          0  redo size
        525  bytes sent via SQL*Net to client
        524  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

疑問:
下面是異常時的兩個snap,發現當時有個語句一起出現MERGE INTO sqlobj$auxdata,跟這個有關係?
第一次執行代價很大可以理解,為什麼執行上萬次後還是這樣,bug?


Buffer Gets  Executions Gets per Exec  %Total Elapsed Time (s) %CPU %IO SQL Id SQL Module SQL Text
66,983,588 31,911 2,099.08 53.00 1,765.21 89.80 9.89 b836wun0fy7sh PL/SQL Developer  SELECT X.DIST_ID FROM COM_AREA...
44,247,719 31,972 1,383.95 35.01 924.39 99.60 0.00 44z7snw61qx9x sqlplus@racdb02 (TNS V1-V3)  MERGE INTO sqlobj$auxdata USIN...


MERGE INTO sqlobj$auxdata USING dual ON (:1 IS NULL) WHEN MATCHED THEN UPDATE SET description = :2, creator = nvl(:3, creator), rigin = :4, version = :5, created = :6, last_modified = :7, last_verified = nvl(:8, last_verified), parse_cpu_time = null, optimizer_cost = nvl(:9, optimizer_cost), module = nvl(:10, module), action = nvl(:11, action), priority = nvl(:12, priority), optimizer_env = nvl(:13, optimizer_env), bind_data = nvl(:14, bind_data), parsing_schema_name = nvl(:15, parsing_schema_name), executions = nvl(:16, executions), elapsed_time = nvl(:17, elapsed_time), cpu_time = nvl(:18, cpu_time), buffer_gets = nvl(:19, buffer_gets), disk_reads = nvl(:20, disk_reads), direct_writes = nvl(:21, direct_writes), rows_processed = nvl(:22, rows_processed), fetches = nvl(:23, fetches), end_of_fetch_count = nvl(:24, end_of_fetch_count), task_id = nvl(:25, task_id), task_exec_name = nvl(:26, task_exec_name), task_obj_id = nvl(:27, task_obj_id), task_fnd_id = nvl(:28, task_fnd_id), task_rec_id = nvl(:29, task_rec_id), flags = 0, spare1 = null, spare2 = null WHERE signature = :30 AND category = :31 AND obj_type = :32 AND plan_id = :33 WHEN NOT MATCHED THEN INSERT (signature, category, obj_type, plan_id, description, creator, origin, version, created, last_modified, last_verified, parse_cpu_time, optimizer_cost, module, action, priority, optimizer_env, bind_data, parsing_schema_name, executions, elapsed_time, cpu_time, buffer_gets, disk_reads, direct_writes, rows_processed, fetches, end_of_fetch_count, task_id, task_exec_name, task_obj_id, task_fnd_id, task_rec_id, flags, spare1, spare2) VALUES (:34, :35, :36, :37, :38, :39, :40, :41, :42, :43, null, null, :44, :45, :46, :47, :48, :49, :50, :51, :52, :53, :54, :55, :56, :57, :58, :59, :60, :61, :62, :63, :64, 0, null, null)

[ 本帖最後由 aaqwsh 於 2011-7-4 11:27 編輯 ]

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/758322/viewspace-701400/,如需轉載,請註明出處,否則將追究法律責任。

相關文章