Watch out LOB operation!
发现有条SQL语句执行很耗时间，首先看到这条SQL非常复杂，因此刚开始想想能不能重写这个SQL来进行优化啥的，结果费了半天劲发现瓶颈在于在SQL中调用的一个函数。这个函数做的事情很简单就是类似于string aggregation, 不过是通过实现oracle data cartridge interface (ODCI)来实现的。代码如下...
CREATE OR REPLACE FUNCTION RO.IMPLODE(x varchar2)
RETURN clob PARALLEL_ENABLE AGGREGATE USING T_IMPLODE_IMPL
;
/
CREATE OR REPLACE TYPE RO.T_IMPLODE_IMPL as object
(
runningConcat clob
, runningCount number
, separator varchar2(100)
, static function setSeparator(
sctx IN OUT T_IMPLODE_IMPL
, separator varchar2 default ','
) return number
, static function ODCIAggregateInitialize(
sctx IN OUT T_IMPLODE_IMPL
, valueSeparator varchar2 default ','
) return number
, member function ODCIAggregateIterate(
self IN OUT T_IMPLODE_IMPL
, value IN varchar2
) return number
, member function ODCIAggregateTerminate(
self IN T_IMPLODE_IMPL
, returnValue OUT clob
, flags IN number
) return number
, member function ODCIAggregateMerge(
self IN OUT T_IMPLODE_IMPL
, ctx2 IN T_IMPLODE_IMPL
) return number
);
/
CREATE OR REPLACE TYPE BODY RO.T_IMPLODE_IMPL IS
static function setSeparator(
sctx IN OUT T_IMPLODE_IMPL
, separator varchar2 default ','
) return number
is
begin
return ODCIConst.Success;
end;
STATIC FUNCTION ODCIAggregateInitialize (
sctx IN OUT T_IMPLODE_IMPL
, valueSeparator varchar2
) return number
is
v_sep varchar2(100);
begin
-- 100: separator variable length
sctx := T_IMPLODE_IMPL('', 0, substr(nvl(sys_context(pack_utils.get_schema_owner(), 'IMPLODE_SEPARATOR'), ','), 1, 100));
return ODCIConst.Success;
end;
member function ODCIAggregateIterate(
self IN OUT T_IMPLODE_IMPL
, value IN varchar2
) return number
is
begin
if runningCount = 0 then
self.runningConcat := value;
else
-- to remove separator use the special separator <no separator> in IMPLODE_SEPARATOR context variable
dbms_lob.append(self.runningConcat, case when self.separator='<no separator>' then empty_clob() else self.separator end);
dbms_lob.append(self.runningConcat, value);
end if;
runningCount := runningCount + 1;
return ODCIConst.Success;
end;
member function ODCIAggregateMerge(
self IN OUT T_IMPLODE_IMPL
, ctx2 IN T_IMPLODE_IMPL
) return number
is
begin
-- to remove separator use the special separator <no separator> in IMPLODE_SEPARATOR context variable
dbms_lob.append(self.runningConcat, case when self.separator='<no separator>' then empty_clob() else self.separator end);
dbms_lob.append(self.runningConcat, ctx2.runningConcat);
return ODCIConst.Success;
end;
member function ODCIAggregateTerminate(
self IN T_IMPLODE_IMPL
, returnValue OUT clob
, flags IN number
) return number
is
begin
returnValue := self.runningConcat;
return ODCIConst.Success;
end;
END;
/
这种自定义聚集函数其实是非常笨重的。因为Oracle10以后内置了COLLECT函数，因此想利用这个COLLECT函数来实现这个聚集函数。COLLECT只是把一组数据变成了一个nested table,所以需要一个辅助函数来进行字符串的拼接操作。最容易的实现方式如下： (把clob当成varchar2来进行拼接操作）
CREATE OR REPLACE FUNCTION RO.ARG_TABLE_TO_CLOB(V_ARG_TABLE IN T_V4000_TABLE, V_DELIMITER IN VARCHAR2 DEFAULT ',') RETURN CLOB
AS
l_return CLOB;
begin
for IDX in 1..V_ARG_TABLE.count
LOOP
-- IF V_ARG_TABLE(IDX) IS NOT NULL THEN
l_return := l_return || V_ARG_TABLE(IDX) || V_DELIMITER;
-- END IF;
end LOOP;
l_return := RTRIM(l_return, V_DELIMITER);
return l_return;
END;
/
这样自然很方便实现，但是很容易怀疑到这种写法的效率。既然Oracle提供了DBMS_LOB来进行LOB的操作，自然是有原因的。因此对上述的函数进行改下，如下...
CREATE OR REPLACE FUNCTION RO.ARG_TABLE_TO_CLOB2(V_ARG_TABLE IN T_V4000_TABLE, V_DELIMITER IN VARCHAR2 DEFAULT ',') RETURN CLOB
AS
l_return CLOB;
begin
DBMS_LOB.createtemporary (lob_loc => l_return, cache => TRUE);
for IDX in 1..V_ARG_TABLE.count
LOOP
--IF V_ARG_TABLE(IDX) IS NOT NULL THEN
DBMS_LOB.WRITEAPPEND(l_return, length(V_ARG_TABLE(IDX) || V_DELIMITER), V_ARG_TABLE(IDX) || V_DELIMITER);
-- END IF;
end LOOP;
DBMS_LOB.TRIM(l_return, DBMS_LOB.GETLENGTH(l_return) - length(V_DELIMITER));
return l_return;
END;
/
因为字符串的操作比LOB来说轻量多了，上面这个函数其实还可以进一步改进，以减少DBMS_LOB.WRITEAPPEND的操作次数...
CREATE OR REPLACE FUNCTION RO.ARG_TABLE_TO_CLOB3(V_ARG_TABLE IN T_V4000_TABLE, V_DELIMITER IN VARCHAR2 DEFAULT ',') RETURN CLOB
AS
l_return CLOB;
l_temp_str VARCHAR2(32767);
l_temp_len pls_integer := 0;
begin
IF V_ARG_TABLE IS NULL THEN RETURN NULL; END IF;
DBMS_LOB.createtemporary (lob_loc => l_return, cache => TRUE);
for IDX in 1..V_ARG_TABLE.count
LOOP
-- IF V_ARG_TABLE(IDX) IS NOT NULL THEN
l_temp_len := l_temp_len + length(V_ARG_TABLE(IDX) || V_DELIMITER);
IF l_temp_len > 32767 THEN
DBMS_LOB.WRITEAPPEND(l_return, length(l_temp_str), l_temp_str);
l_temp_str := V_ARG_TABLE(IDX) || V_DELIMITER;
l_temp_len := length(V_ARG_TABLE(IDX) || V_DELIMITER);
ELSE
l_temp_str := l_temp_str || V_ARG_TABLE(IDX) || V_DELIMITER;
END IF;
-- END IF;
end LOOP;
DBMS_LOB.WRITEAPPEND(l_return, length(l_temp_str) - length(v_delimiter), RTRIM(l_temp_str,V_DELIMITER) );
--DBMS_LOB.TRIM(l_return, DBMS_LOB.GETLENGTH(l_return) - length(V_DELIMITER));
return l_return;
END;
/
那么这几种写法到底有多区别呢，可以进行下简单的测试....
SQL> set timing on
SQL> select count(*) from user_objects;
COUNT(*)
----------
5515
Elapsed: 00:00:00.12
SQL> exec dbms_monitor.session_trace_enable(binds=>true, waits=>true);
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.01
SQL> select implode (object_name) from user_objects;
IMPLODE(OBJECT_NAME)
--------------------------------------------------------------------------------
BOOK_GAAP_TYPE,BROWSER,SYS_LOB0000074618C00009$$,BROWSER_CUSTOM_DW,BROWSER_CUSTO
Elapsed: 00:00:06.09
SQL> select ARG_TABLE_TO_CLOB(cast (collect(object_name) as t_v4000_table) )from user_objects
2 ;
ARG_TABLE_TO_CLOB(CAST(COLLECT(OBJECT_NAME)AST_V4000_TABLE))
--------------------------------------------------------------------------------
BOOK_GAAP_TYPE,BROWSER,SYS_LOB0000074618C00009$$,BROWSER_CUSTOM_DW,BROWSER_CUSTO
Elapsed: 00:00:04.96
SQL> select ARG_TABLE_TO_CLOB2(cast (collect(object_name) as t_v4000_table) )from user_objects
2 ;
ARG_TABLE_TO_CLOB2(CAST(COLLECT(OBJECT_NAME)AST_V4000_TABLE))
--------------------------------------------------------------------------------
BOOK_GAAP_TYPE,BROWSER,SYS_LOB0000074618C00009$$,BROWSER_CUSTOM_DW,BROWSER_CUSTO
Elapsed: 00:00:00.50
SQL> select ARG_TABLE_TO_CLOB3(cast (collect(object_name) as t_v4000_table) )from user_objects
2 ;
ARG_TABLE_TO_CLOB3(CAST(COLLECT(OBJECT_NAME)AST_V4000_TABLE))
--------------------------------------------------------------------------------
BOOK_GAAP_TYPE,BROWSER,SYS_LOB0000074618C00009$$,BROWSER_CUSTOM_DW,BROWSER_CUSTO
Elapsed: 00:00:00.18
SQL> exec dbms_monitor.session_trace_disable();
PL/SQL procedure successfully completed.
时间花销如下：
（1） implode (ODCI): 6.09s
(2) ARG_TABLE_TO_CLOB + COLLECT: 4.96s
(3) ARG_TABLE_TO_CLOB2 + COLLECT: 0.50s
(4) ARG_TABLE_TO_CLOB3 + COLLECT: 0.18S
可以看到CLOB操作次数越少越好！
因为开启了trace， 可以从trace文件中得到更多的信息...
(1) IMPLODE:
PARSING IN CURSOR #880084168 len=46 dep=0 uid=84 oct=3 lid=84 tim=415119069540 hv=2901700352 ad='56ee1b318' sqlid='c8sg0m2qg8vs0'
select implode (object_name) from user_objects
END OF STMT
PARSE #880084168:c=46875,e=40099,p=0,cr=109,cu=0,mis=1,r=0,dep=0,og=1,plh=891653971,tim=415119069537
EXEC #880084168:c=0,e=146,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=891653971,tim=415119069950
WAIT #880084168: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415119070124
WAIT #880084168: nam='SQL*Net message from client' ela= 620 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415119070876
WAIT #880084168: nam='asynch descriptor resize' ela= 6 outstanding #aio=0 current aio limit=4294967295 new aio limit=455 obj#=-1 tim=415124320376
WAIT #880084168: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415124320745
FETCH #880084168:c=5250000,e=5250956,p=0,cr=104334,cu=537819,mis=0,r=1,dep=0,og=1,plh=891653971,tim=415124321934
STAT #880084168 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=104334 pr=0 pw=0 time=5249781 us)'
STAT #880084168 id=2 cnt=5515 pid=1 pos=1 obj=3273 op='VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=103098 us cost=276 size=194700 card=2950)'
STAT #880084168 id=3 cnt=5515 pid=2 pos=1 obj=0 op='UNION-ALL (cr=1237 pr=0 pw=0 time=97831 us)'
STAT #880084168 id=4 cnt=5515 pid=3 pos=1 obj=0 op='FILTER (cr=1236 pr=0 pw=0 time=90050 us)'
STAT #880084168 id=5 cnt=5646 pid=4 pos=1 obj=0 op='HASH JOIN (cr=1010 pr=0 pw=0 time=57250 us cost=276 size=340790 card=3215)'
STAT #880084168 id=6 cnt=103 pid=5 pos=1 obj=47 op='INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=152 us cost=1 size=2266 card=103)'
STAT #880084168 id=7 cnt=5646 pid=5 pos=2 obj=18 op='TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=40165 us cost=275 size=270060 card=3215)'
STAT #880084168 id=8 cnt=1484 pid=4 pos=2 obj=19 op='TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=20018 us cost=2 size=8 card=1)'
STAT #880084168 id=9 cnt=1615 pid=8 pos=1 obj=41 op='INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=8718 us cost=1 size=0 card=1)'
STAT #880084168 id=10 cnt=0 pid=4 pos=3 obj=0 op='NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)'
STAT #880084168 id=11 cnt=0 pid=10 pos=1 obj=47 op='INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)'
STAT #880084168 id=12 cnt=0 pid=10 pos=2 obj=39 op='INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)'
STAT #880084168 id=13 cnt=0 pid=3 pos=2 obj=138 op='INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=31 us cost=0 size=79 card=1)'
WAIT #880084168: nam='SQL*Net message from client' ela= 516 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415125859018
WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415125859410
LOBREAD: c=0,e=163,p=0,cr=2,cu=0,tim=415125859458
WAIT #0: nam='SQL*Net message from client' ela= 817 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415125860343
LOBTMPFRE: c=0,e=1529,p=0,cr=0,cu=208,tim=415125861975
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415125862031
WAIT #0: nam='SQL*Net message from client' ela= 393 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415125862469
FETCH #880084168:c=0,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=891653971,tim=415125862575
WAIT #880084168: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415125862631
WAIT #880084168: nam='SQL*Net message from client' ela= 21164707 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415147027383
CLOSE #880084168:c=0,e=108,dep=0,type=0,tim=415147027743
(2) ARG_TABLE_TO_CLOB
PARSING IN CURSOR #879849088 len=89 dep=0 uid=84 oct=3 lid=84 tim=415325713228 hv=206197708 ad='56b053a00' sqlid='f1wp8hw64nnyc'
select ARG_TABLE_TO_CLOB(cast (collect(object_name) as t_v4000_table) )from user_objects
END OF STMT
PARSE #879849088:c=187500,e=187022,p=0,cr=304,cu=137,mis=1,r=0,dep=0,og=1,plh=891653971,tim=415325713226
EXEC #879849088:c=0,e=128,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=891653971,tim=415325713609
WAIT #879849088: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415325713727
WAIT #879849088: nam='SQL*Net message from client' ela= 682 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415325714906
WAIT #879849088: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330475985
FETCH #879849088:c=4765625,e=4761364,p=0,cr=174436,cu=1603681,mis=0,r=1,dep=0,og=1,plh=891653971,tim=415330476371
STAT #879849088 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1237 pr=0 pw=0 time=132757 us)'
STAT #879849088 id=2 cnt=5516 pid=1 pos=1 obj=3273 op='VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=82408 us cost=276 size=194700 card=2950)'
STAT #879849088 id=3 cnt=5516 pid=2 pos=1 obj=0 op='UNION-ALL (cr=1237 pr=0 pw=0 time=75260 us)'
STAT #879849088 id=4 cnt=5516 pid=3 pos=1 obj=0 op='FILTER (cr=1236 pr=0 pw=0 time=63092 us)'
STAT #879849088 id=5 cnt=5647 pid=4 pos=1 obj=0 op='HASH JOIN (cr=1010 pr=0 pw=0 time=42684 us cost=276 size=340790 card=3215)'
STAT #879849088 id=6 cnt=103 pid=5 pos=1 obj=47 op='INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=139 us cost=1 size=2266 card=103)'
STAT #879849088 id=7 cnt=5647 pid=5 pos=2 obj=18 op='TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=25205 us cost=275 size=270060 card=3215)'
STAT #879849088 id=8 cnt=1484 pid=4 pos=2 obj=19 op='TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=16304 us cost=2 size=8 card=1)'
STAT #879849088 id=9 cnt=1615 pid=8 pos=1 obj=41 op='INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=6350 us cost=1 size=0 card=1)'
STAT #879849088 id=10 cnt=0 pid=4 pos=3 obj=0 op='NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)'
STAT #879849088 id=11 cnt=0 pid=10 pos=1 obj=47 op='INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)'
STAT #879849088 id=12 cnt=0 pid=10 pos=2 obj=39 op='INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)'
STAT #879849088 id=13 cnt=0 pid=3 pos=2 obj=138 op='INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=32 us cost=0 size=79 card=1)'
WAIT #879849088: nam='SQL*Net message from client' ela= 439 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330477220
WAIT #0: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330477488
LOBREAD: c=0,e=156,p=0,cr=2,cu=0,tim=415330477537
WAIT #0: nam='SQL*Net message from client' ela= 795 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330478401
LOBTMPFRE: c=0,e=699,p=0,cr=0,cu=149,tim=415330479204
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330479259
WAIT #0: nam='SQL*Net message from client' ela= 332 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330479635
FETCH #879849088:c=0,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=891653971,tim=415330479740
WAIT #879849088: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415330479797
WAIT #879849088: nam='SQL*Net message from client' ela= 8821707 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339301549
CLOSE #879849088:c=0,e=71,dep=0,type=0,tim=415339301886
(3) ARG_TABLE_TO_CLOB2
PARSING IN CURSOR #879849088 len=90 dep=0 uid=84 oct=3 lid=84 tim=415339336969 hv=1955421889 ad='5756338d8' sqlid='6sw54x1u8urq1'
select ARG_TABLE_TO_CLOB2(cast (collect(object_name) as t_v4000_table) )from user_objects
END OF STMT
PARSE #879849088:c=31250,e=34780,p=0,cr=109,cu=0,mis=1,r=0,dep=0,og=1,plh=891653971,tim=415339336967
EXEC #879849088:c=0,e=139,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=891653971,tim=415339337364
WAIT #879849088: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339337505
WAIT #879849088: nam='SQL*Net message from client' ela= 553 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339338417
WAIT #879849088: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339790633
FETCH #879849088:c=453125,e=452599,p=0,cr=6751,cu=22354,mis=0,r=1,dep=0,og=1,plh=891653971,tim=415339791116
STAT #879849088 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1237 pr=0 pw=0 time=133052 us)'
STAT #879849088 id=2 cnt=5516 pid=1 pos=1 obj=3273 op='VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=82399 us cost=276 size=194700 card=2950)'
STAT #879849088 id=3 cnt=5516 pid=2 pos=1 obj=0 op='UNION-ALL (cr=1237 pr=0 pw=0 time=75877 us)'
STAT #879849088 id=4 cnt=5516 pid=3 pos=1 obj=0 op='FILTER (cr=1236 pr=0 pw=0 time=63836 us)'
STAT #879849088 id=5 cnt=5647 pid=4 pos=1 obj=0 op='HASH JOIN (cr=1010 pr=0 pw=0 time=42549 us cost=276 size=340790 card=3215)'
STAT #879849088 id=6 cnt=103 pid=5 pos=1 obj=47 op='INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=248 us cost=1 size=2266 card=103)'
STAT #879849088 id=7 cnt=5647 pid=5 pos=2 obj=18 op='TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=25059 us cost=275 size=270060 card=3215)'
STAT #879849088 id=8 cnt=1484 pid=4 pos=2 obj=19 op='TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=16112 us cost=2 size=8 card=1)'
STAT #879849088 id=9 cnt=1615 pid=8 pos=1 obj=41 op='INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=6362 us cost=1 size=0 card=1)'
STAT #879849088 id=10 cnt=0 pid=4 pos=3 obj=0 op='NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)'
STAT #879849088 id=11 cnt=0 pid=10 pos=1 obj=47 op='INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)'
STAT #879849088 id=12 cnt=0 pid=10 pos=2 obj=39 op='INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)'
STAT #879849088 id=13 cnt=0 pid=3 pos=2 obj=138 op='INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=34 us cost=0 size=79 card=1)'
WAIT #879849088: nam='SQL*Net message from client' ela= 524 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339792495
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339792679
LOBREAD: c=0,e=139,p=0,cr=2,cu=0,tim=415339792748
WAIT #0: nam='SQL*Net message from client' ela= 817 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339793622
LOBTMPFRE: c=0,e=609,p=0,cr=0,cu=149,tim=415339794330
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339794384
WAIT #0: nam='SQL*Net message from client' ela= 386 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339794813
FETCH #879849088:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=891653971,tim=415339794913
WAIT #879849088: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415339794968
WAIT #879849088: nam='SQL*Net message from client' ela= 8219705 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348014717
CLOSE #879849088:c=0,e=64,dep=0,type=0,tim=415348015048
(4) ARG_TABLE_TO_CLOB3
PARSING IN CURSOR #879849088 len=90 dep=0 uid=84 oct=3 lid=84 tim=415348050208 hv=1136644906 ad='56bcc5dc8' sqlid='ftgcr411vznta'
select ARG_TABLE_TO_CLOB3(cast (collect(object_name) as t_v4000_table) )from user_objects
END OF STMT
PARSE #879849088:c=31250,e=34866,p=0,cr=109,cu=0,mis=1,r=0,dep=0,og=1,plh=891653971,tim=415348050206
EXEC #879849088:c=0,e=137,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=891653971,tim=415348050603
WAIT #879849088: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348050741
WAIT #879849088: nam='SQL*Net message from client' ela= 598 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348051693
WAIT #879849088: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348208416
FETCH #879849088:c=156250,e=157048,p=0,cr=1240,cu=138,mis=0,r=1,dep=0,og=1,plh=891653971,tim=415348208840
STAT #879849088 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1237 pr=0 pw=0 time=133738 us)'
STAT #879849088 id=2 cnt=5516 pid=1 pos=1 obj=3273 op='VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=83717 us cost=276 size=194700 card=2950)'
STAT #879849088 id=3 cnt=5516 pid=2 pos=1 obj=0 op='UNION-ALL (cr=1237 pr=0 pw=0 time=76066 us)'
STAT #879849088 id=4 cnt=5516 pid=3 pos=1 obj=0 op='FILTER (cr=1236 pr=0 pw=0 time=64525 us)'
STAT #879849088 id=5 cnt=5647 pid=4 pos=1 obj=0 op='HASH JOIN (cr=1010 pr=0 pw=0 time=43615 us cost=276 size=340790 card=3215)'
STAT #879849088 id=6 cnt=103 pid=5 pos=1 obj=47 op='INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=145 us cost=1 size=2266 card=103)'
STAT #879849088 id=7 cnt=5647 pid=5 pos=2 obj=18 op='TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=25872 us cost=275 size=270060 card=3215)'
STAT #879849088 id=8 cnt=1484 pid=4 pos=2 obj=19 op='TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=16590 us cost=2 size=8 card=1)'
STAT #879849088 id=9 cnt=1615 pid=8 pos=1 obj=41 op='INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=6423 us cost=1 size=0 card=1)'
STAT #879849088 id=10 cnt=0 pid=4 pos=3 obj=0 op='NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)'
STAT #879849088 id=11 cnt=0 pid=10 pos=1 obj=47 op='INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)'
STAT #879849088 id=12 cnt=0 pid=10 pos=2 obj=39 op='INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)'
STAT #879849088 id=13 cnt=0 pid=3 pos=2 obj=138 op='INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=34 us cost=0 size=79 card=1)'
WAIT #879849088: nam='SQL*Net message from client' ela= 552 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348210629
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348210818
LOBREAD: c=0,e=121,p=0,cr=2,cu=0,tim=415348210864
WAIT #0: nam='SQL*Net message from client' ela= 813 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348211733
LOBTMPFRE: c=0,e=580,p=0,cr=0,cu=149,tim=415348212412
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348212466
WAIT #0: nam='SQL*Net message from client' ela= 385 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348212895
FETCH #879849088:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=891653971,tim=415348212995
WAIT #879849088: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415348213050
WAIT #879849088: nam='SQL*Net message from client' ela= 16067504 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=415364280598
CLOSE #879849088:c=0,e=67,dep=0,type=0,tim=415364280999
对应的TKPROF输出结果...
(1) IMPLODE
select implode (object_name)
from
user_objects
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 2 4.84 4.84 0 104334 483748 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 4.84 4.84 0 104334 483748 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 84
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=104344 pr=0 pw=0 time=4852284 us)
5515 5515 5515 VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=97057 us cost=276 size=194700 card=2950)
5515 5515 5515 UNION-ALL (cr=1237 pr=0 pw=0 time=91412 us)
5515 5515 5515 FILTER (cr=1236 pr=0 pw=0 time=83633 us)
5646 5646 5646 HASH JOIN (cr=1010 pr=0 pw=0 time=53206 us cost=276 size=340790 card=3215)
103 103 103 INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=255 us cost=1 size=2266 card=103)(object id 47)
5646 5646 5646 TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=37074 us cost=275 size=270060 card=3215)
1484 1484 1484 TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=18125 us cost=2 size=8 card=1)
1615 1615 1615 INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=7881 us cost=1 size=0 card=1)(object id 41)
0 0 0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)
0 0 0 INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)
0 0 0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)
0 0 0 INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=20 us cost=0 size=79 card=1)(object id 138)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 8.13 8.14
Disk file operations I/O 1 0.00 0.00
********************************************************************************
(2) ARG_TABLE_TO_CLOB
select ARG_TABLE_TO_CLOB(cast (collect(object_name) as t_v4000_table) )
from
user_objects
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.06 0.05 0 102 2 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 4.76 4.76 0 174436 1603681 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 4.82 4.81 0 174538 1603683 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=1237 pr=0 pw=0 time=132757 us)
5516 5516 5516 VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=82408 us cost=276 size=194700 card=2950)
5516 5516 5516 UNION-ALL (cr=1237 pr=0 pw=0 time=75260 us)
5516 5516 5516 FILTER (cr=1236 pr=0 pw=0 time=63092 us)
5647 5647 5647 HASH JOIN (cr=1010 pr=0 pw=0 time=42684 us cost=276 size=340790 card=3215)
103 103 103 INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=139 us cost=1 size=2266 card=103)(object id 47)
5647 5647 5647 TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=25205 us cost=275 size=270060 card=3215)
1484 1484 1484 TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=16304 us cost=2 size=8 card=1)
1615 1615 1615 INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=6350 us cost=1 size=0 card=1)(object id 41)
0 0 0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)
0 0 0 INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)
0 0 0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)
0 0 0 INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=32 us cost=0 size=79 card=1)(object id 138)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 8.82 8.82
********************************************************************************
(3) ARG_TABLE_TO_CLOB2
select ARG_TABLE_TO_CLOB2(cast (collect(object_name) as t_v4000_table) )
from
user_objects
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 99 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.45 0.45 0 6751 22354 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.48 0.48 0 6850 22354 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=1237 pr=0 pw=0 time=133052 us)
5516 5516 5516 VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=82399 us cost=276 size=194700 card=2950)
5516 5516 5516 UNION-ALL (cr=1237 pr=0 pw=0 time=75877 us)
5516 5516 5516 FILTER (cr=1236 pr=0 pw=0 time=63836 us)
5647 5647 5647 HASH JOIN (cr=1010 pr=0 pw=0 time=42549 us cost=276 size=340790 card=3215)
103 103 103 INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=248 us cost=1 size=2266 card=103)(object id 47)
5647 5647 5647 TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=25059 us cost=275 size=270060 card=3215)
1484 1484 1484 TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=16112 us cost=2 size=8 card=1)
1615 1615 1615 INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=6362 us cost=1 size=0 card=1)(object id 41)
0 0 0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)
0 0 0 INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)
0 0 0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)
0 0 0 INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=34 us cost=0 size=79 card=1)(object id 138)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 8.21 8.22
********************************************************************************
(4) ARG_TABLE_TO_CLOB3
select ARG_TABLE_TO_CLOB3(cast (collect(object_name) as t_v4000_table) )
from
user_objects
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 99 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.15 0.15 0 1240 138 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.18 0.19 0 1339 138 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=1237 pr=0 pw=0 time=133738 us)
5516 5516 5516 VIEW USER_OBJECTS (cr=1237 pr=0 pw=0 time=83717 us cost=276 size=194700 card=2950)
5516 5516 5516 UNION-ALL (cr=1237 pr=0 pw=0 time=76066 us)
5516 5516 5516 FILTER (cr=1236 pr=0 pw=0 time=64525 us)
5647 5647 5647 HASH JOIN (cr=1010 pr=0 pw=0 time=43615 us cost=276 size=340790 card=3215)
103 103 103 INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=145 us cost=1 size=2266 card=103)(object id 47)
5647 5647 5647 TABLE ACCESS FULL OBJ$ (cr=1009 pr=0 pw=0 time=25872 us cost=275 size=270060 card=3215)
1484 1484 1484 TABLE ACCESS BY INDEX ROWID IND$ (cr=226 pr=0 pw=0 time=16590 us cost=2 size=8 card=1)
1615 1615 1615 INDEX UNIQUE SCAN I_IND1 (cr=39 pr=0 pw=0 time=6423 us cost=1 size=0 card=1)(object id 41)
0 0 0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)
0 0 0 INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)
0 0 0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)
0 0 0 INDEX RANGE SCAN I_LINK1 (cr=1 pr=0 pw=0 time=34 us cost=0 size=79 card=1)(object id 138)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 16.06 16.06
********************************************************************************
从这个结果可以看出ARG_TABLE_TO_CLOB3之所以最快是因为引入的I/O代价最低！因此正确使用LOB非常重要，千万不能像用varchar那样来简单进行CLOB的拼接！
--------------------------------------
Regards,
FangwenYu
