11.2.0.2.0 bug？ 簡單查詢代價異常
上禮拜五快下班時，同事說一個很簡單的查詢非常慢(單表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 編輯 ]
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/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- hibernate異常之--count查詢異常
- MySQL - 資料查詢 - 簡單查詢MySql
- Mybatis簡單查詢MyBatis
- 簡單的查詢
- MongoDB 查詢超時異常 SocketTimeoutExceptionMongoDBException
- 簡單的mysql查詢MySql
- 關聯查詢子查詢效率簡單比照
- #查詢演算法#【1】簡單查詢：順序、折半查詢演算法
- ATM-簡單SQL查詢SQL
- 簡單的查詢語法
- ElasticSearch中的簡單查詢Elasticsearch
- 一次分割槽查詢異常的分析
- 讀書筆記】《PostgreSQL指南-內幕探索》-3.2單表查詢的代價估計筆記SQL
- mysql查詢快取簡單使用MySql快取
- MySQL的簡單查詢語句MySql
- 插值查詢的簡單理解
- 一個簡單的樹查詢
- 嘗試讓查詢更簡單
- 簡單解析MySQL中的cardinality異常MySql
- bug及異常處理1
- Java 列舉查詢並不拋異常的實現Java
- Centos 系統簡單排查流量異常問題CentOS
- 簡單的全域性異常統一處理
- javascript異常報錯型別簡單介紹JavaScript型別
- SQL Server-簡單查詢語句SQLServer
- 二分查詢的簡單理解
- MySQL之資料的簡單查詢MySql
- 一個簡單的字串查詢程式字串
- 日常Bug排查-拋異常不回滾
- Spring Data Jpa 的簡單查詢多表查詢HQL，SQL ，動態查詢， QueryDsl ，自定義查詢筆記SpringSQL筆記
- 全國省市區地址查詢API：簡單易用的地址查詢服務API
- 聊聊簡單又不簡單的圖上多跳過濾查詢
- Mysql-基本練習(09-刪除單表記錄、查詢指定列資料、列的別名、簡單單表條件查詢、簡單分組查詢)MySql
- 簡單介紹Python中異常處理用法Python
- 解決：layUI資料表格+簡單查詢UI
- vim下多行查詢替換簡單命令
- SSM的查詢簡單練習+JSPSSMJS
- 讓NoSQL支援簡單條件查詢VRSQLVR