上礼拜五快下班时,同事说一个很简单的查询非常慢(单表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博客 ” ,链接:https://blog.itpub.net/758322/viewspace-701400/
,如需转载,请注明出处,否则将追究法律责任。