[20210208]lob字段与查询的问题.txt

[20210208]lob字段与查询的问题.txt --//链接:http://www.itpub.net/thread-2140819-1-1.html,查询很慢.里面包含lob字段. --//不知道对方在什么环境或者工具下测试得到的,不过toad,PLSQLDev存在一定欺骗性.它并没有取出lob字段的全部, --//至少在toad下如此.通过测试说明问题. 1.环境: SCOTT@book> @ ver1 PORT_STRING         VERSION        BANNER ------------------- -------------- -------------------------------------------------------------------------------- x86_64/Linux 2.4.xx 11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production CREATE TABLE t1 (id INT, a VARCHAR2(100), b CLOB, c CLOB); INSERT INTO t1 SELECT rownum, dummy, lpad('a',4000,'a') ,lpad('b',4000,'b') FROM dual CONNECT BY LEVEL <= 1000; commit ; --//分析略,每个字段保存4000个字符,实际上这些blob并不保存在段内. SELECT segment_name, segment_type, bytes   FROM user_segments  WHERE segment_name IN ('T1'                        ,'SYS_IL0000096089C00004$$'                        ,'SYS_IL0000096089C00003$$'                        ,'SYS_LOB0000096089C00003$$'                        ,'SYS_LOB0000096089C00004$$'); SEGMENT_NAME                   SEGMENT_TYPE            BYTES ------------------------------ ------------------ ---------- SYS_IL0000096089C00003$$       LOBINDEX                65536 SYS_IL0000096089C00004$$       LOBINDEX                65536 SYS_LOB0000096089C00003$$      LOBSEGMENT            9437184 SYS_LOB0000096089C00004$$      LOBSEGMENT            9437184 T1                             TABLE                  131072 --//表占128K. 2.分析: --//sqlplus: SCOTT@book>  set timing on SCOTT@book>  set autot traceonly SCOTT@book> select * from t1; 1000 rows selected. Elapsed: 00:00:25.43 Execution Plan --------------------------- Plan hash value: 3617692013 -------------------------------------------------------------------------- | Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     | -------------------------------------------------------------------------- |   0 | SELECT STATEMENT  |      |  1000 |   214K|     5   (0)| 00:00:01 | |   1 |  TABLE ACCESS FULL| T1   |  1000 |   214K|     5   (0)| 00:00:01 | -------------------------------------------------------------------------- Statistics ----------------------------------------------------------           0  recursive calls           0  db block gets        5002  consistent gets        4000  physical reads           0  redo size    17488548  bytes sent via SQL*Net to client     1119519  bytes received via SQL*Net from client        5002  SQL*Net roundtrips to/from client           0  sorts (memory)           0  sorts (disk)        1000  rows processed --//25秒.如果你使用10046跟踪,你可以发现每个lob2个fetch,因为在段外1次lob索引1次lob字段.这样自然很慢.你可以从上面的SQL*Net --//roundtrips to/from client=5002可以看出来问题. --//physical reads = 4000, 因为lob缺省采用直接路径读取.不占用缓存数据. SCOTT@book> select id,a from t1; 1000 rows selected. Elapsed: 00:00:00.01 Execution Plan ---------------------------------------------------------- Plan hash value: 3617692013 -------------------------------------------------------------------------- | Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     | -------------------------------------------------------------------------- |   0 | SELECT STATEMENT  |      |  1000 |  6000 |     5   (0)| 00:00:01 | |   1 |  TABLE ACCESS FULL| T1   |  1000 |  6000 |     5   (0)| 00:00:01 | -------------------------------------------------------------------------- Statistics ----------------------------------------------------------           1  recursive calls           0  db block gets          20  consistent gets           0  physical reads           0  redo size       10248  bytes sent via SQL*Net to client         563  bytes received via SQL*Net from client           6  SQL*Net roundtrips to/from client           0  sorts (memory)           0  sorts (disk)        1000  rows processed 3.测试toad下: SCOTT@book> @ sid 44 SPID       PID        SID    SERIAL# PNAME  TRACEFILE                                                         PROGRAM   TERMINAL     SQL_ID  STATUS ------ ------- ---------- ---------- ------ ----------------------------------------------------------------- --------- ------------ ------- -------- 22343       27         44      17971        /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22343.trc     Toad.exe  XX9984BCP             INACTIVE SYS@book> exec dbms_system.set_sql_trace_in_session( sid => 44, serial# => 17971, sql_trace=>true); PL/SQL procedure successfully completed. --//在toad下执行,注意打开auto trace,因为这样才能全部取出. select * from t1; SYS@book> exec dbms_system.set_sql_trace_in_session( sid => 44, serial# => 17971, sql_trace=>false); PL/SQL procedure successfully completed. --//可以query viewer发现仅仅25msecs完成. --//查看跟踪文件: ===================== PARSING IN CURSOR #139777477988224 len=16 dep=0 uid=83 oct=3 lid=83 tim=1612747781609757 hv=2245880055 ad='7d8447e8' sqlid='27uhu2q2xuu7r' select * from t1 END OF STMT PARSE #139777477988224:c=0,e=573,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3617692013,tim=1612747781609756 EXEC #139777477988224:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3617692013,tim=1612747781611476 FETCH #139777477988224:c=0,e=86,p=0,cr=3,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747781611605 FETCH #139777477988224:c=0,e=33,p=0,cr=1,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747781633977 FETCH #139777477988224:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747781636460 LOBGETLEN: c=1000,e=243,p=0,cr=0,cu=0,tim=1612747781641507 LOBGETLEN: c=0,e=9,p=0,cr=0,cu=0,tim=1612747781642322 LOBREAD: c=0,e=205,p=1,cr=1,cu=0,tim=1612747781643403 LOBGETLEN: c=0,e=9,p=0,cr=0,cu=0,tim=1612747781645535 LOBGETLEN: c=0,e=9,p=0,cr=0,cu=0,tim=1612747781646236 LOBREAD: c=0,e=48,p=1,cr=1,cu=0,tim=1612747781647081 LOBGETLEN: c=0,e=9,p=0,cr=0,cu=0,tim=1612747781648681 LOBGETLEN: c=0,e=8,p=0,cr=0,cu=0,tim=1612747781649322 ... --//注意看跟踪的fetch r=25,也就是连续3次fetch,75条,使用tkprof生成报表. ******************************************************************************** SQL ID: 27uhu2q2xuu7r Plan Hash: 3617692013 select * from  t1 call     count       cpu    elapsed       disk      query    current        rows ------- ------  -------- ---------- ---------- ---------- ----------  ---------- Parse        1      0.00       0.00          0          0          0           0 Execute      1      0.00       0.00          0          0          0           0 Fetch       41      0.00       0.00          0         54          0        1000 ------- ------  -------- ---------- ---------- ---------- ----------  ---------- total       43      0.00       0.00          0         54          0        1000 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max)  Row Source Operation ---------- ---------- ----------  ---------------------------------------------------       1000       1000       1000  TABLE ACCESS FULL T1 (cr=54 pr=0 pw=0 time=1055 us cost=5 size=220000 card=1000) --//fetch 41 ,每次25条.实际上如果没有lob字段,fetch每次1000条.可以参考 --//http://blog.itpub.net/267265/viewspace-2152038/=>[20180320]toad环境中一次fetch等于多少 --//fetch 1001,1000... $ grep "FETCH" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22343.trc | grep "#139777477988224"|head -4 FETCH #139777477988224:c=0,e=86,p=0,cr=3,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747781611605 FETCH #139777477988224:c=0,e=33,p=0,cr=1,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747781633977 FETCH #139777477988224:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747781636460 FETCH #139777477988224:c=0,e=86,p=0,cr=2,cu=0,mis=0,r=25,dep=0,og=1,plh=3617692013,tim=1612747782265124 $ grep "FETCH" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22343.trc | grep "#139777477988224"|wc      41      82    4279 --//toad缺省是preview clob and long date是勾上的,通过toad菜单的view->options查询lob确定. 4.PLSQLDev: --//首先说明一点我很少使用它. SYS@book> @ sid 86 sid = 86 SPID       PID        SID    SERIAL# PNAME  TRACEFILE                                                         PROGRAM      TERMINAL     SQL_ID        STATUS ------ ------- ---------- ---------- ------ ----------------------------------------------------------------- ------------ ------------ ------------- -------- 22480       30         86       7215        /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22480.trc     PLSQLDev.exe IKD84BCP                   INACTIVE SYS@book> exec dbms_system.set_sql_trace_in_session( sid => 86, serial# => 7215, sql_trace=>true); PL/SQL procedure successfully completed. select * from t1; --//选择全部,是7秒完成. SYS@book> exec dbms_system.set_sql_trace_in_session( sid => 86, serial# => 7215, sql_trace=>false); PL/SQL procedure successfully completed. $ grep FETCH /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22480.trc | grep "#14061305745925" FETCH #140613057459256:c=999,e=325,p=0,cr=4,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749198858424 FETCH #140613057459256:c=0,e=260,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749200579073 FETCH #140613057459256:c=0,e=235,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749201249537 FETCH #140613057459256:c=0,e=251,p=0,cr=3,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749201973919 FETCH #140613057459256:c=0,e=256,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749202695432 FETCH #140613057459256:c=1000,e=262,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749203418385 FETCH #140613057459256:c=0,e=253,p=0,cr=3,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749204246545 FETCH #140613057459256:c=0,e=261,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749204998188 FETCH #140613057459256:c=0,e=273,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749205714597 FETCH #140613057459256:c=1000,e=277,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=1,plh=3617692013,tim=1612749206438245 FETCH #140613057459256:c=0,e=13,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3617692013,tim=1612749207161531 --//fetch 每次100. ******************************************************************************** SQL ID: 2z5kqzmsngdpd Plan Hash: 3617692013 select * from  t1 call     count       cpu    elapsed       disk      query    current        rows ------- ------  -------- ---------- ---------- ---------- ----------  ---------- Parse        1      0.00       0.00          0          0          0           0 Execute      1      0.00       0.00          0          0          0           0 Fetch       11      0.00       0.00          0         24          0        1000 ------- ------  -------- ---------- ---------- ---------- ----------  ---------- total       13      0.00       0.00          0         24          0        1000 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max)  Row Source Operation ---------- ---------- ----------  ---------------------------------------------------       1000       1000       1000  TABLE ACCESS FULL T1 (cr=24 pr=0 pw=0 time=1327 us cost=5 size=220000 card=1000) ******************************************************************************** --//大量的读取浪费在lob字段上. 5.总结: sqlplus下,fetch 基本是每行1次,通过lob索引次数还会增加.并且每个lob一次,这样大量的时间浪费在lob以及网络往返上. toad每次fetch 25,但是我估计它并没有完全取出lob,时间相当较短. PLSQLDev每次fetch 100. 但是我有点不明白toad,PLSQLDev的LOBREAD不一样,也许是这个导致toad比PLSQLDev快. --//toad: $ grep LOBREAD /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22343.trc | wc     147     294    7863 $ grep LOBGETLEN /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22343.trc | wc     294     588   16156      --//294/2 = 147 --//PLSQLDev $ grep LOBREAD /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22480.trc|wc    2000    4000  106538 $ grep LOBGETLEN /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_22480.trc|wc    2000    4000  110119 --//toad下LOBGETLEN=294次,是LOBREAD的2倍.但是LOBGETLEN,LOBREAD次数比PLSQLDev少,其中细节我不是很清楚.