ITPub博客

首页 > 数据库 > Oracle > [20180905]lob与direct path read.txt

[20180905]lob与direct path read.txt

原创 Oracle 作者:lfree 时间:2018-09-05 21:43:10 0 删除 编辑

[20180905]lob与direct path read.txt

--//如果表有存在lob字段,通常采用直接路径读取.

1.环境:
SCOTT@test01p> @ ver1
PORT_STRING                    VERSION        BANNER                                                                               CON_ID
------------------------------ -------------- -------------------------------------------------------------------------------- ----------
IBMPC/WIN_NT64-9.1.0           12.1.0.1.0     Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production              0

SCOTT@test01p> @ ev_name "direct path read"
EVENT#   EVENT_ID NAME                  PARAMETER1  PARAMETER2 PARAMETER3 WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS DISPLAY_NAME          CON_ID
------ ---------- --------------------- ----------- ---------- ---------- ------------- ----------- ---------- --------------------- ------
   204 3926164927 direct path read      file number first dba  block cnt     1740759767           8 User I/O   direct path read      0
   205  861319509 direct path read temp file number first dba  block cnt     1740759767           8 User I/O   direct path read temp 0

SCOTT@test01p> @ ev_name direct%lob
no rows selected

--//没有单独direct path read/write(lob)等待事件,我开始以为lob会单独区别开来.

create table t1 as select rownum id from dual connect by level<=100;
create table t2 (id number ,text clob);
insert into t2  select rownum id,lpad('a',5000,'a') text from dual connect by level<=100;
--//注:我使用12c,可以插入大于4000的字符.
commit;

--//分析表略.

2.测试:

SCOTT@test01p> alter system flush buffer_cache;
System altered.

@ 10046on 12
select * from t1,t2 where t1.id = t2.id ;
@ 10046off

3.检查跟踪文件:
--//截取一段:
=====================
PARSING IN CURSOR #395065056 len=40 dep=0 uid=109 oct=3 lid=109 tim=3316897002 hv=430785427 ad='7ff1ec5a3e0' sqlid='13a4sa4cuuhwm'
select * from t1,t2 where t1.id = t2.id
END OF STMT
PARSE #395065056:c=15600,e=4362,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1838229974,tim=3316896999
EXEC #395065056:c=0,e=115,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=3316897592
WAIT #395065056: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3316897848
WAIT #395065056: nam='SQL*Net message from client' ela= 27109 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3316925177
WAIT #395065056: nam='Disk file operations I/O' ela= 178 FileOperation=2 fileno=9 filetype=2 obj#=107979 tim=3316925953
WAIT #395065056: nam='db file sequential read' ela= 18341 file#=9 block#=202 blocks=1 obj#=107979 tim=3316944366
WAIT #395065056: nam='db file sequential read' ela= 409 file#=9 block#=203 blocks=1 obj#=107979 tim=3316945039
WAIT #395065056: nam='db file sequential read' ela= 410 file#=9 block#=210 blocks=1 obj#=107980 tim=3316946295
WAIT #395065056: nam='db file scattered read' ela= 499 file#=9 block#=211 blocks=5 obj#=107980 tim=3316946928
WAIT #395065056: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=107980 tim=3316947083
FETCH #395065056:c=0,e=21773,p=8,cr=10,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3316947149
WAIT #395065056: nam='SQL*Net message from client' ela= 223 driver id=1413697536 #bytes=1 p3=0 obj#=107980 tim=3316947449
WAIT #0: nam='direct path read' ela= 149 file number=9 first dba=247 block cnt=1 obj#=107981 tim=3317031776
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317032377
WAIT #0: nam='SQL*Net vector data to client' ela= 369 driver id=1413697536 #bytes=8060 p3=2 obj#=107981 tim=3317032816
WAIT #0: nam='SQL*Net vector data to client' ela= 61 driver id=1413697536 #bytes=1940 p3=2 obj#=107981 tim=3317032980
LOBREAD: c=0,e=85538,p=2,cr=1,cu=0,tim=3317033061
WAIT #0: nam='SQL*Net message from client' ela= 24719 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317057879
WAIT #0: nam='direct path read' ela= 342 file number=9 first dba=243 block cnt=1 obj#=107981 tim=3317068651
LOBREAD: c=0,e=11012,p=1,cr=1,cu=0,tim=3317069214

--//注意看下划线内容,可以发现WAIT #0: 怪不得在对应sql_id看不到lob端的直接路径读.

SCOTT@test01p> SELECT *  FROM V$ACTIVE_SESSION_HISTORY  WHERE sample_time >= '2018-09-04 20:50:56' AND event = 'direct path read';
no rows selected

--//awr竟然没有抓到.

D:\tools\rlwrap>grep -i "direct path read" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc | head -4
grep -i "direct path read" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc | head -4
WAIT #0: nam='direct path read' ela= 149 file number=9 first dba=247 block cnt=1 obj#=107981 tim=3317031776
WAIT #0: nam='direct path read' ela= 342 file number=9 first dba=243 block cnt=1 obj#=107981 tim=3317068651
WAIT #0: nam='direct path read' ela= 170 file number=9 first dba=246 block cnt=1 obj#=107981 tim=3317105728
WAIT #0: nam='direct path read' ela= 8544 file number=9 first dba=439 block cnt=1 obj#=107981 tim=3317119670

SCOTT@test01p> @ which_obj 9 247
OWNER                SEGMENT_NAME         PARTITION_NAME       SEGMENT_TYPE         TABLESPACE_NAME       EXTENT_ID    FILE_ID   BLOCK_ID      BYTES     BLOCKS RELATIVE_FNO
-------------------- -------------------- -------------------- -------------------- -------------------- ---------- ---------- ---------- ---------- ---------- ------------
SCOTT                SYS_LOB0000107980C00                      LOBSEGMENT           USERS                         0          9        232     131072         16            9
                     002$$

SCOTT@test01p> SCOTT@test01p> select segment_name,bytes/1024/1024/1024 gb from dba_segments where segment_name in (select segment_name from DBA_LOBS where table_name='T2' and owner=user);
SEGMENT_NAME                 GB
-------------------- ----------
SYS_LOB0000107980C00 .003051758
002$$

--//能对上没有问题.

--//查看生成的tkpfor报表:
********************************************************************************

SQL ID: 13a4sa4cuuhwm Plan Hash: 1838229974

select *
from
 t1,t2 where t1.id = t2.id


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch      101      0.03       0.05          8        109          0         100
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      103      0.04       0.05          8        109          0         100

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 109  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
       100        100        100  HASH JOIN  (cr=109 pr=8 pw=0 time=21697 us cost=6 size=9300 card=100)
       100        100        100   TABLE ACCESS FULL T1 (cr=3 pr=2 pw=0 time=19474 us cost=3 size=300 card=100)
       100        100        100   TABLE ACCESS FULL T2 (cr=106 pr=6 pw=0 time=1190 us cost=3 size=9000 card=100)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                     102        0.00          0.00
  SQL*Net message from client                   102        8.85          8.92
  Disk file operations I/O                        1        0.00          0.00
  db file sequential read                         3        0.01          0.01
  db file scattered read                          1        0.00          0.00
********************************************************************************
--//可以发现对应sql语句也没有对应的direct path read.

********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.01       0.00          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch      101      0.03       0.05          8        109          0         100
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      105      0.04       0.05          8        109          0         100

Misses in library cache during parse: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                     303        0.00          0.00
  SQL*Net message from client                   303        8.85         20.52
  Disk file operations I/O                        1        0.00          0.00
  db file sequential read                         3        0.01          0.01
  db file scattered read                          1        0.00          0.00
  direct path read                              199        0.01          0.10
  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  SQL*Net vector data to client                 200        0.00          0.08

D:\tools\rlwrap>grep -i "direct path read" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc | wc
    199    2985   21498

--//为什么会是199次,有点意外.测了几次数量都变化,不过我插入的lpad('a',5000,'a'),保存信息与安装字符集定义有关.
--//我的定义NLS_LANG=SIMPLIFIED CHINESE_CHINA.ZHS16GBK.这样占2块.

D:\tools\rlwrap>grep -i "direct path read" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc | cut -f11 -d" " | sort | uniq -c
     1 dba=243
     1 dba=246
     1 dba=247
     2 dba=439
     1 dba=440
     1 dba=441
     1 dba=442
     1 dba=443
     ...
     1 dba=633
     1 dba=634
     1 dba=635
     1 dba=636
     1 dba=637
     1 dba=638

D:\tools\rlwrap>grep -i "FETCH" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc
grep -i "FETCH" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc
FETCH #395065056:c=0,e=21773,p=8,cr=10,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3316947149
FETCH #395065056:c=0,e=446,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317076447
FETCH #395065056:c=0,e=320,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317104531
FETCH #395065056:c=0,e=156,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317137430
FETCH #395065056:c=0,e=278,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317163755
FETCH #395065056:c=0,e=536,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317192693
FETCH #395065056:c=0,e=284,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317219213
FETCH #395065056:c=0,e=212,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317247117
FETCH #395065056:c=0,e=73,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317274761
FETCH #395065056:c=0,e=239,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317304771
...
FETCH #395065056:c=0,e=225,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3327492053
FETCH #395065056:c=0,e=162,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=3327631486

D:\tools\rlwrap>grep -i "FETCH" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_3992.trc |wc
    101     202    9302
--//可以发现r=1.这也是为什么访问lob慢的原因,每次fetch 1行.最后一次fetch r=0.

FETCH #395065056:c=0,e=21773,p=8,cr=10,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3316947149
WAIT #395065056: nam='SQL*Net message from client' ela= 223 driver id=1413697536 #bytes=1 p3=0 obj#=107980 tim=3316947449
WAIT #0: nam='direct path read' ela= 149 file number=9 first dba=247 block cnt=1 obj#=107981 tim=3317031776
WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317032377
WAIT #0: nam='SQL*Net vector data to client' ela= 369 driver id=1413697536 #bytes=8060 p3=2 obj#=107981 tim=3317032816
WAIT #0: nam='SQL*Net vector data to client' ela= 61 driver id=1413697536 #bytes=1940 p3=2 obj#=107981 tim=3317032980
LOBREAD: c=0,e=85538,p=2,cr=1,cu=0,tim=3317033061
WAIT #0: nam='SQL*Net message from client' ela= 24719 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317057879
WAIT #0: nam='direct path read' ela= 342 file number=9 first dba=243 block cnt=1 obj#=107981 tim=3317068651
LOBREAD: c=0,e=11012,p=1,cr=1,cu=0,tim=3317069214
WAIT #0: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317069372
WAIT #0: nam='SQL*Net message from client' ela= 6160 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317075637
WAIT #395065056: nam='SQL*Net message to client' ela= 11 driver id=1413697536 #bytes=1 p3=0 obj#=107981 tim=3317076216

FETCH #395065056:c=0,e=446,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=1838229974,tim=3317076447

--//想起以前的测试,链接:http://blog.itpub.net/267265/viewspace-1760052/=>[20150803]无法通过sql_id找到sql语句2.txt

SCOTT@test01p> select object_id,data_object_id from dba_objects where owner=user and object_name='T2';
 OBJECT_ID DATA_OBJECT_ID
---------- --------------
    107980         107980

SCOTT@test01p> @ 10to16 107980
10 to 16 HEX      REVERSE16
----------------- ------------------------------
000000000001a5cc  0xcca50100-00000000

SCOTT@test01p> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID                     PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- -------------------- ------- ---------- --------------------------------------------------
       233        257 5808:4024                DEDICATED 3992                      39         31 alter system kill session '233,257' immediate;

SCOTT@test01p> select * from V$OPEN_CURSOR where sid=233 and  sql_text like 'table%\_1a5cc%' escape '\';
SADDR            SID USER_NAME ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT              LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE CHILD_ADDRESS        CON_ID
---------------- --- --------- ---------------- ---------- ------------- --------------------- ------------------- ----------- ----------- ---------------- ----------
000007FF306D61C0 233 SCOTT     000007FF1EC446D8 1102864567 3qnfp350vss5r table_4_9_1a5cc_0_0_0                                 OPEN        000007FF1EC43468          3
--//ADDRESS=000007FF1EC446D8,对应父游标句柄地址.
--//CHILD_ADDRESS=000007FF1EC43468,对应子游标句柄地址.

SYS@test> @ sharepool/shp4  3qnfp350vss5r 0
TEXT           KGLHDADR         KGLHDPAR         C40                   KGLHDLMD   KGLHDPMD   KGLHDIVC KGLOBHD0         KGLOBHD6           KGLOBHS0   KGLOBHS6   KGLOBT16   N0_6_16        N20   KGLNAHSH KGLOBT03        KGLOBT09
-------------- ---------------- ---------------- --------------------- -------- ---------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ----------
子游标句柄地址 000007FF1EC43468 000007FF1EC446D8 table_4_9_1a5cc_0_0_         1          2          1 000007FF25E2F9B8 000007FF1EC43D58       8144       4032       3102     15278      15278 1102864567 3qnfp350vss5r          0
父游标句柄地址 000007FF1EC446D8 000007FF1EC446D8 table_4_9_1a5cc_0_0_         1          0          1 000007FF1EC44620 00                     4072          0          0      4072       4072 1102864567 3qnfp350vss5r      65535

--//这样就很好理解我前面诊断链接http://blog.itpub.net/267265/viewspace-2213256/,为什么查看sql_id看不到lob段的direct path read.

3.实际上lob字段可以放入数据缓存的,修改lob属性cache或者cache read就ok了.

SCOTT@test01p> ALTER TABLE T2 MODIFY LOB (TEXT) ( CACHE);
Table altered.

--//这样读写都可以进入数据缓存,如果修改ALTER TABLE T2 MODIFY LOB (TEXT) ( CACHE READS);注意read后面有1个S.
--//仅仅读进入数据缓存,写入依旧走direct path write.

SCOTT@test01p> ALTER TABLE T2 MODIFY LOB (TEXT) ( CACHE READs);
Table altered.

SCOTT@test01p> ALTER TABLE T2 MODIFY LOB (TEXT) ( CACHE );
Table altered.

--//oracle缺省不这样定义,主要是避免大量消耗数据缓存.如果你这些对象频繁读取,可以根据需要修改.
--//退出会话重新测试:

alter system flush buffer_cache;
@ 10046on 12
select * from t1,t2 where t1.id = t2.id ;
@ 10046off

D:\tools\rlwrap>grep "direct path read" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_2768.trc
grep "direct path read" D:\app\oracle\diag\rdbms\test\test\trace\test_ora_2768.trc

--//可以发现cache后没有再出现direct path read等待事件.

SYS@test> @ bh 9 243
HLADDR              DBARFIL     DBABLK      CLASS CLASS_TYPE         STATE             TCH CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ BA               OBJECT_NAME
---------------- ---------- ---------- ---------- ------------------ ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------------- --------------------
000007FF2F096DE8          9        243          1 data block         xcur                1          0          0          0          0          0 000007FF1B520000

SYS@test01p> @ bh 9 247
HLADDR              DBARFIL     DBABLK      CLASS CLASS_TYPE         STATE             TCH CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ BA               OBJECT_NAME
---------------- ---------- ---------- ---------- ------------------ ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------------- --------------------
000007FF2F1E3868          9        247          1 data block         xcur                1          0          0          0          0          0 000007FF19E60000 SYS_LOB0000107980C00
                                                                                                                                                                   002$$
--//可以lob段进入数据缓存.前面@ bh 9 243看不到OBJECT_NAME,是因为pdb的原因.

SCOTT@test01p> @ which_obj 9 243
OWNER                SEGMENT_NAME         PARTITION_NAME       SEGMENT_TYPE         TABLESPACE_NAME       EXTENT_ID    FILE_ID   BLOCK_ID      BYTES     BLOCKS RELATIVE_FNO
-------------------- -------------------- -------------------- -------------------- -------------------- ---------- ---------- ---------- ---------- ---------- ------------
SCOTT                SYS_LOB0000107980C00                      LOBSEGMENT           USERS                         0          9        232     131072         16            9
                     002$$

4.在测试结束,我突然想起一些工具比如toad,在data grid里面执行时可能并不访问lob.继续测试:

SCOTT@test01p> ALTER TABLE T2 MODIFY LOB (TEXT) ( noCACHE );
Table altered.

SCOTT@test01p> alter system flush buffer_cache;
System altered.

--//在toad下执行:
begin sys.dbms_monitor.session_trace_enable(231,1653,true,true); end;
select * from t1,t2 where t1.id = t2.id;
begin sys.dbms_monitor.session_trace_disable(231,1653); end;

--//检查转储:
begin sys.dbms_monitor.session_trace_enable(231,1653,true,true); end;
=====================
PARSING IN CURSOR #688704480 len=39 dep=0 uid=109 oct=3 lid=109 tim=9446964636 hv=3964999012 ad='7ff25d5db20' sqlid='5fx1rnbq5a5b4'
select * from t1,t2 where t1.id = t2.id
END OF STMT
PARSE #688704480:c=0,e=58,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=9446964636
EXEC #688704480:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=9446964761
WAIT #688704480: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=28 tim=9446964824
WAIT #688704480: nam='SQL*Net message from client' ela= 1055 driver id=1413697536 #bytes=1 p3=0 obj#=28 tim=9446965916
WAIT #688704480: nam='db file sequential read' ela= 5806 file#=9 block#=202 blocks=1 obj#=107979 tim=9446971899
WAIT #688704480: nam='db file sequential read' ela= 339 file#=9 block#=203 blocks=1 obj#=107979 tim=9446972418
WAIT #688704480: nam='db file sequential read' ela= 363 file#=9 block#=210 blocks=1 obj#=107980 tim=9446973203
WAIT #688704480: nam='db file scattered read' ela= 495 file#=9 block#=211 blocks=5 obj#=107980 tim=9446973863
WAIT #688704480: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=107980 tim=9446974045
WAIT #688704480: nam='SQL*Net more data to client' ela= 86 driver id=1413697536 #bytes=8102 p3=0 obj#=107980 tim=9446974245
FETCH #688704480:c=15601,e=8382,p=8,cr=10,cu=0,mis=0,r=100,dep=0,og=1,plh=1838229974,tim=9446974357
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
STAT #688704480 id=1 cnt=100 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=10 pr=8 pw=0 time=8447 us cost=6 size=9300 card=100)'
STAT #688704480 id=2 cnt=100 pid=1 pos=1 obj=107979 op='TABLE ACCESS FULL T1 (cr=3 pr=2 pw=0 time=6489 us cost=3 size=300 card=100)'
STAT #688704480 id=3 cnt=100 pid=1 pos=2 obj=107980 op='TABLE ACCESS FULL T2 (cr=7 pr=6 pw=0 time=1395 us cost=3 size=9000 card=100)'

*** 2018-09-04 22:33:09.756
WAIT #688704480: nam='SQL*Net message from client' ela= 3534786 driver id=1413697536 #bytes=1 p3=0 obj#=107980 tim=9450509316
=====================
PARSING IN CURSOR #816744024 len=60 dep=0 uid=109 oct=47 lid=109 tim=9450510050 hv=2791809845 ad='7ff23b373b0' sqlid='7frv1cum6g8tp'
begin sys.dbms_monitor.session_trace_disable(231,1653); end;
END OF STMT

--//可以发现fetch r=100,也说明在toad下没有提取lob字段内容(特别在数据段外,我觉得数据段内会访问,这样才能获得locate信息).没有发现direct path read 等待事件.
--//如果通过toad菜单,view=>toad options=>Data Grids    可以发现Preview CLOB and LONG data没有选上.
--//如果选上重复测试.toad下与sqplus操作方式存在不同:
--//测试注意一个细节:要选择auto trace或者执行后拖动到最后1条.这样才算执行完成,不然实际上仅仅访问前面几条记录.

=====================
=====================
PARSING IN CURSOR #381342464 len=39 dep=0 uid=109 oct=3 lid=109 tim=4113882451 hv=3964999012 ad='7ff1f96bac0' sqlid='5fx1rnbq5a5b4'
select * from t1,t2 where t1.id = t2.id
END OF STMT
PARSE #381342464:c=0,e=92,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=4113882450
WAIT #381342464: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4113882660
WAIT #381342464: nam='SQL*Net message from client' ela= 443 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4113883160
CLOSE #381342464:c=0,e=10,dep=0,type=1,tim=4113883235
PARSE #381342464:c=0,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=4113883301
EXEC #381342464:c=0,e=40,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1838229974,tim=4113883384
WAIT #381342464: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4113883469
WAIT #381342464: nam='SQL*Net message from client' ela= 1785 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4113885309
WAIT #381342464: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4113886168
WAIT #381342464: nam='SQL*Net more data to client' ela= 127 driver id=1413697536 #bytes=8102 p3=0 obj#=-1 tim=4113886456
FETCH #381342464:c=0,e=1138,p=0,cr=10,cu=0,mis=0,r=100,dep=0,og=1,plh=1838229974,tim=4113886559
STAT #381342464 id=1 cnt=100 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=10 pr=0 pw=0 time=1229 us cost=6 size=9300 card=100)'
STAT #381342464 id=2 cnt=100 pid=1 pos=1 obj=107979 op='TABLE ACCESS FULL T1 (cr=3 pr=0 pw=0 time=138 us cost=3 size=300 card=100)'
STAT #381342464 id=3 cnt=100 pid=1 pos=2 obj=107980 op='TABLE ACCESS FULL T2 (cr=7 pr=0 pw=0 time=247 us cost=3 size=9000 card=100)'
WAIT #381342464: nam='SQL*Net message from client' ela= 27884 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4113914744

--//可以发现fetch r=100

D:\app\oracle\diag\rdbms\test\test\trace>grep -i "direct path read" test_ora_5844.trc|head -10
WAIT #0: nam='direct path read' ela= 50598 file number=9 first dba=247 block cnt=1 obj#=107981 tim=4113966551
WAIT #0: nam='direct path read' ela= 283 file number=9 first dba=244 block cnt=2 obj#=107981 tim=4113971148
WAIT #0: nam='direct path read' ela= 271 file number=9 first dba=246 block cnt=1 obj#=107981 tim=4113975251
WAIT #0: nam='direct path read' ela= 29137 file number=9 first dba=439 block cnt=1 obj#=107981 tim=4114005099
WAIT #0: nam='direct path read' ela= 426 file number=9 first dba=440 block cnt=2 obj#=107981 tim=4114009080
WAIT #0: nam='direct path read' ela= 284 file number=9 first dba=442 block cnt=2 obj#=107981 tim=4114013304
WAIT #0: nam='direct path read' ela= 322 file number=9 first dba=444 block cnt=2 obj#=107981 tim=4114017174
WAIT #0: nam='direct path read' ela= 289 file number=9 first dba=446 block cnt=2 obj#=107981 tim=4114020944
WAIT #0: nam='direct path read' ela= 31560 file number=9 first dba=448 block cnt=2 obj#=107981 tim=4114056440
WAIT #0: nam='direct path read' ela= 50977 file number=9 first dba=498 block cnt=2 obj#=107981 tim=4114111350

D:\app\oracle\diag\rdbms\test\test\trace>grep -i "direct path read" test_ora_5844.trc|wc
    101    1515   10936

--//说明一下:执行后必须在data grid中选中text字段,一条一条移动到最后,不然direct path read记数不会这么多.
--//我测试快速拖最少45次direct path read.

总结:
--//总之:在一些开发工具toad与sqlplus执行存在不同,sqlplus要访问lob字段.而toad下可以做到先不访问lob段外数据.
--//我觉得数据段内要访问的.不然lob定位信息无法获得.
--//而且sqlplus下fetch是1条1条提取,这样效率很低,而toad是一次提取许多(我以前测试是第1次1001,第二次1000.)
--//参考:http://blog.itpub.net/267265/viewspace-2152038/=>[20180320]toad环境中一次fetch等于多少.

--//lob类型可以修改属性(cache 或者cache reads),避免direct path read.

--//另外如果在exadata下全表扫描大表(包含lob字段),不会出现cell smart table scan等待事件,而是direct path read.



来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/267265/viewspace-2213630/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
熟悉oracle相关技术,擅长sql优化,rman备份与恢复,熟悉linux shell编程。

注册时间:2008-01-03

  • 博文量
    2852
  • 访问量
    6640507