最近有一套系统一条简单的语句执行很慢:create table xxx as select * from xxx;
做了简单的10046如下:
SQL ID: 479aa0z9yttdr Plan Hash: 2897757325
create table CRE000_HR_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.24 12 36 0 0
Execute 1 7.21 18.24 29867 30189 33465 3032342
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 7.22 18.48 29879 30225 33465 3032342
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD AS SELECT (cr=30161 pr=29868 pw=29863 time=18243403 us)
3032342 3032342 3032342 OPTIMIZER STATISTICS GATHERING (cr=29868 pr=29864 pw=0 time=11393334 us cost=8190 size=200134572 card=3032342)
3032342 3032342 3032342 TABLE ACCESS FULL TEST01 (cr=29868 pr=29864 pw=0 time=7556276 us cost=8190 size=200134572 card=3032342)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
library cache lock 1 0.00 0.00
row cache lock 25 0.00 0.01
library cache pin 1 0.00 0.00
enq: IV - contention 7 0.00 0.00
db file sequential read 4 0.02 0.02
reliable message 7 0.00 0.01
enq: KO - fast object checkpoint 2 0.00 0.00
direct path read 1443 0.24 9.19
enq: TS - contention 1 0.00 0.00
gc current grant 2-way 6 0.00 0.00
enq: HW - contention 1 0.00 0.00
gc current grant busy 2 0.00 0.00
CSS initialization 2 0.00 0.00
CSS operation: query 6 0.00 0.00
CSS operation: action 2 0.00 0.00
direct path write 23 0.51 1.22
KJC: Wait for msg sends to complete 1 0.00 0.00
gc current multi block request 39 0.00 0.02
gc buffer busy acquire 1 0.34 0.34
gc current block lost 1 0.00 0.00
lock deadlock retry 1 0.00 0.00
gc current block busy 1 0.00 0.00
gc current block 2-way 1 0.00 0.00
log file switch completion 1 0.09 0.09
enq: RC - Result Cache: Contention 1 0.00 0.00
Disk file operations I/O 1 0.00 0.00
log file sync 1 0.07 0.07
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 15.17 15.17
********************************************************************************
在会话层做了
首先调整了oracle12C上优化器参数:
set optimizer_adaptive_features=false
接着继续做10046查看情况:
create table CRE000_HR_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.15 9 27 0 0
Execute 1 7.52 13.29 29868 30189 33560 3032342
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 7.53 13.44 29877 30216 33560 3032342
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD AS SELECT (cr=30161 pr=29868 pw=29863 time=13265259 us)
3032342 3032342 3032342 OPTIMIZER STATISTICS GATHERING (cr=29868 pr=29864 pw=0 time=7046218 us cost=8190 size=200134572 card=3032342)
3032342 3032342 3032342 TABLE ACCESS FULL TEST01 (cr=29868 pr=29864 pw=0 time=3189042 us cost=8190 size=200134572 card=3032342)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
library cache lock 1 0.00 0.00
library cache pin 9 0.00 0.00
row cache lock 5 0.00 0.00
KJC: Wait for msg sends to complete 3 0.00 0.00
enq: IV - contention 7 0.00 0.00
db file sequential read 5 0.02 0.08
enq: KO - fast object checkpoint 3 0.00 0.00
reliable message 7 0.00 0.01
direct path read 3824 0.32 5.41
enq: TT - contention 4 0.00 0.00
gc current grant busy 10 0.01 0.01
gc current grant 2-way 4 0.00 0.00
enq: TS - contention 1 0.00 0.00
enq: HW - contention 1 0.00 0.00
direct path write 27 0.04 0.22
gc current multi block request 31 0.00 0.02
enq: RC - Result Cache: Contention 1 0.00 0.00
Disk file operations I/O 1 0.00 0.00
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 7.21 7.21
********************************************************************************
这一次direct path read仍然很高,统计收集小了很多,继续对 direct path read 问题进行调整 :
通过与11g上执行情况的比较,12C除了时间长了很多 direct path read等待事件很场外没有其他差异,检查参数:
什么是全表扫描?
全表扫描就是扫表表中所有的行,实际上是扫描表中所有的数据块,oracle的最小 单位是Oracle block。
扫描所有的数据块就包括高水位线以内的数据块,即使是空数据块在没有被释放的情形下也会被扫描而导致I/O增加。
在全表扫描期间,通常情况下,表上这些相邻的数据块被按顺序(sequentially)的方式访问以使得一次I/O可以读取多个数据块。
一次读取更多的数据块有助于全表扫描使用更少的I/O,对于可读取的数据块被限制于参数DB_FILE_MULTIBLOCK_READ_COUNT
检查参数: DB_FILE_MULTIBLOCK_READ_COUNT发现在改12C系统上,该参数值为2,果断调整到128
然后继续做10046:
create table CRE000_HR_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.12 12 36 0 0
Execute 1 6.19 6.63 29869 30221 33979 3032342
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 6.21 6.76 29881 30257 33979 3032342
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD AS SELECT (cr=30193 pr=29872 pw=29863 time=6659863 us)
3032342 3032342 3032342 OPTIMIZER STATISTICS GATHERING (cr=29868 pr=29864 pw=0 time=4357814 us cost=5252 size=200134572 card=3032342)
3032342 3032342 3032342 TABLE ACCESS FULL TEST01 (cr=29868 pr=29864 pw=0 time=739219 us cost=5252 size=200134572 card=3032342)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
row cache lock 8 0.00 0.00
enq: IV - contention 7 0.00 0.00
Disk file operations I/O 3 0.00 0.00
db file sequential read 6 0.01 0.06
enq: KO - fast object checkpoint 3 0.00 0.00
KJC: Wait for msg sends to complete 4 0.00 0.00
reliable message 7 0.00 0.01
direct path read 19 0.06 0.23
gc current grant 2-way 21 0.00 0.01
enq: TS - contention 1 0.00 0.00
enq: HW - contention 1 0.00 0.00
CSS initialization 2 0.00 0.00
CSS operation: query 6 0.00 0.00
CSS operation: action 2 0.00 0.00
direct path write 11 0.00 0.02
gc current multi block request 31 0.00 0.03
enq: RC - Result Cache: Contention 3 0.00 0.00
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 4.47 4.47
********************************************************************************
问题终于解决了
做了简单的10046如下:
SQL ID: 479aa0z9yttdr Plan Hash: 2897757325
create table CRE000_HR_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.24 12 36 0 0
Execute 1 7.21 18.24 29867 30189 33465 3032342
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 7.22 18.48 29879 30225 33465 3032342
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD AS SELECT (cr=30161 pr=29868 pw=29863 time=18243403 us)
3032342 3032342 3032342 OPTIMIZER STATISTICS GATHERING (cr=29868 pr=29864 pw=0 time=11393334 us cost=8190 size=200134572 card=3032342)
3032342 3032342 3032342 TABLE ACCESS FULL TEST01 (cr=29868 pr=29864 pw=0 time=7556276 us cost=8190 size=200134572 card=3032342)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
library cache lock 1 0.00 0.00
row cache lock 25 0.00 0.01
library cache pin 1 0.00 0.00
enq: IV - contention 7 0.00 0.00
db file sequential read 4 0.02 0.02
reliable message 7 0.00 0.01
enq: KO - fast object checkpoint 2 0.00 0.00
direct path read 1443 0.24 9.19
enq: TS - contention 1 0.00 0.00
gc current grant 2-way 6 0.00 0.00
enq: HW - contention 1 0.00 0.00
gc current grant busy 2 0.00 0.00
CSS initialization 2 0.00 0.00
CSS operation: query 6 0.00 0.00
CSS operation: action 2 0.00 0.00
direct path write 23 0.51 1.22
KJC: Wait for msg sends to complete 1 0.00 0.00
gc current multi block request 39 0.00 0.02
gc buffer busy acquire 1 0.34 0.34
gc current block lost 1 0.00 0.00
lock deadlock retry 1 0.00 0.00
gc current block busy 1 0.00 0.00
gc current block 2-way 1 0.00 0.00
log file switch completion 1 0.09 0.09
enq: RC - Result Cache: Contention 1 0.00 0.00
Disk file operations I/O 1 0.00 0.00
log file sync 1 0.07 0.07
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 15.17 15.17
********************************************************************************
在会话层做了
首先调整了oracle12C上优化器参数:
set optimizer_adaptive_features=false
接着继续做10046查看情况:
create table CRE000_HR_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.15 9 27 0 0
Execute 1 7.52 13.29 29868 30189 33560 3032342
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 7.53 13.44 29877 30216 33560 3032342
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD AS SELECT (cr=30161 pr=29868 pw=29863 time=13265259 us)
3032342 3032342 3032342 OPTIMIZER STATISTICS GATHERING (cr=29868 pr=29864 pw=0 time=7046218 us cost=8190 size=200134572 card=3032342)
3032342 3032342 3032342 TABLE ACCESS FULL TEST01 (cr=29868 pr=29864 pw=0 time=3189042 us cost=8190 size=200134572 card=3032342)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
library cache lock 1 0.00 0.00
library cache pin 9 0.00 0.00
row cache lock 5 0.00 0.00
KJC: Wait for msg sends to complete 3 0.00 0.00
enq: IV - contention 7 0.00 0.00
db file sequential read 5 0.02 0.08
enq: KO - fast object checkpoint 3 0.00 0.00
reliable message 7 0.00 0.01
direct path read 3824 0.32 5.41
enq: TT - contention 4 0.00 0.00
gc current grant busy 10 0.01 0.01
gc current grant 2-way 4 0.00 0.00
enq: TS - contention 1 0.00 0.00
enq: HW - contention 1 0.00 0.00
direct path write 27 0.04 0.22
gc current multi block request 31 0.00 0.02
enq: RC - Result Cache: Contention 1 0.00 0.00
Disk file operations I/O 1 0.00 0.00
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 7.21 7.21
********************************************************************************
这一次direct path read仍然很高,统计收集小了很多,继续对 direct path read 问题进行调整 :
通过与11g上执行情况的比较,12C除了时间长了很多 direct path read等待事件很场外没有其他差异,检查参数:
什么是全表扫描?
全表扫描就是扫表表中所有的行,实际上是扫描表中所有的数据块,oracle的最小 单位是Oracle block。
扫描所有的数据块就包括高水位线以内的数据块,即使是空数据块在没有被释放的情形下也会被扫描而导致I/O增加。
在全表扫描期间,通常情况下,表上这些相邻的数据块被按顺序(sequentially)的方式访问以使得一次I/O可以读取多个数据块。
一次读取更多的数据块有助于全表扫描使用更少的I/O,对于可读取的数据块被限制于参数DB_FILE_MULTIBLOCK_READ_COUNT
检查参数: DB_FILE_MULTIBLOCK_READ_COUNT发现在改12C系统上,该参数值为2,果断调整到128
然后继续做10046:
create table CRE000_HR_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.12 12 36 0 0
Execute 1 6.19 6.63 29869 30221 33979 3032342
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 6.21 6.76 29881 30257 33979 3032342
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD AS SELECT (cr=30193 pr=29872 pw=29863 time=6659863 us)
3032342 3032342 3032342 OPTIMIZER STATISTICS GATHERING (cr=29868 pr=29864 pw=0 time=4357814 us cost=5252 size=200134572 card=3032342)
3032342 3032342 3032342 TABLE ACCESS FULL TEST01 (cr=29868 pr=29864 pw=0 time=739219 us cost=5252 size=200134572 card=3032342)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
row cache lock 8 0.00 0.00
enq: IV - contention 7 0.00 0.00
Disk file operations I/O 3 0.00 0.00
db file sequential read 6 0.01 0.06
enq: KO - fast object checkpoint 3 0.00 0.00
KJC: Wait for msg sends to complete 4 0.00 0.00
reliable message 7 0.00 0.01
direct path read 19 0.06 0.23
gc current grant 2-way 21 0.00 0.01
enq: TS - contention 1 0.00 0.00
enq: HW - contention 1 0.00 0.00
CSS initialization 2 0.00 0.00
CSS operation: query 6 0.00 0.00
CSS operation: action 2 0.00 0.00
direct path write 11 0.00 0.02
gc current multi block request 31 0.00 0.03
enq: RC - Result Cache: Contention 3 0.00 0.00
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 4.47 4.47
********************************************************************************
问题终于解决了
来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/28612416/viewspace-2131375/,如需转载,请注明出处,否则将追究法律责任。
转载于:http://blog.itpub.net/28612416/viewspace-2131375/