-- Demo case: Researching LOB fetching with JDBC -- Date: 20-07-2015 -- References: https://oracleriddleblog.wordpress.com/2015/07/20/solution-why-is-the-new-hardware-slower/ -- http://hemantoracledba.blogspot.ch/2013/04/single-row-fetch-from-lob.html -- http://docs.oracle.com/cd/E11882_01/java.112/e16548/oraperf.htm#JJDBC23210 -- http://blog.tanelpoder.com/2011/03/20/lobread-sql-trace-entry-in-oracle-11-2/ -- Demo run on Oracle version: 11.2.0.3.6 -- Demo used JDBC version: 10.2.0.4 (ojdbc14.jar) and 11.2.0.4 (ojdbc6.jar) create table MY_VC_CLOB (id_col number, vc_col varchar2(200), clob_col clob); insert into my_vc_clob select rownum, 'Row : ' || rownum ||' : This is the VARCHAR2 column ', 'Row : ' || rownum ||' : This is the CLOB column ' from dual connect by level < 101; commit; LOBPrefetchJDBC.java ------------------------------------------------------------------------------------------------------------------------------------------------------ import java.sql.Clob; import java.sql.Connection; import java.sql.DriverManager; import java.sql.PreparedStatement; import java.sql.ResultSet; import java.sql.SQLException; import java.util.Properties; public class LOBPrefetchJDBC { public static void main(String args[]) throws SQLException { //URL of Oracle database server String url = "jdbc:oracle:thin:@OEL:1522:T11DB"; //properties for creating connection to Oracle database Properties props = new Properties(); props.setProperty("user", "TEST"); props.setProperty("password", ""); //creating connection to Oracle database using JDBC Connection conn = DriverManager.getConnection(url,props); String sql = "select * from MY_VC_CLOB"; //creating PreparedStatement object to execute query PreparedStatement preStatement = conn.prepareStatement(sql); preStatement.setFetchSize(30); ResultSet result = preStatement.executeQuery(); while(result.next()){ Clob clob_col = result.getClob("clob_col"); String text = clob_col.getSubString(1, (int) clob_col.length()); System.out.println(text); } } } ------------------------------------------------------------------------------------------------------------------------------------------------------ javac -g LOBPrefetchJDBC.java exec DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE('SYS$USERS','JDBC Thin Client', waits => TRUE, binds => TRUE, plan_stat => 'ALL_EXECUTIONS'); java -cp /Users/Downloads/ojdbc6.jar:. LOBPrefetchJDBC Row : 1 : This is the CLOB column Row : 2 : This is the CLOB column Row : 3 : This is the CLOB column .. .. Row : 98 : This is the CLOB column Row : 99 : This is the CLOB column Row : 100 : This is the CLOB column exec DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE('SYS$USERS','JDBC Thin Client'); Extended SQL Trace with JDBC 11.2.0.4 (ojdbc6.jar) ------------------------------------------------------------------------------------------------------------------------------------------------------ PARSING IN CURSOR #140731137299392 len=24 dep=0 uid=91 oct=3 lid=91 tim=1437399987548787 hv=426457469 ad='7ae9f508' sqlid='7py431scqqfbx' select * from MY_VC_CLOB END OF STMT PARSE #140731137299392:c=0,e=145,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4046223463,tim=1437399987548782 EXEC #140731137299392:c=0,e=49,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4046223463,tim=1437399987548911 WAIT #140731137299392: nam='SQL*Net message to client' ela= 4 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987548958 WAIT #140731137299392: nam='SQL*Net message from client' ela= 16543 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987565578 WAIT #140731137299392: nam='SQL*Net message to client' ela= 6 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987565898 FETCH #140731137299392:c=1000,e=670,p=0,cr=65,cu=0,mis=0,r=30,dep=0,og=1,plh=4046223463,tim=1437399987566435 WAIT #140731137299392: nam='SQL*Net message from client' ela= 9581 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987576080 WAIT #140731137299392: nam='SQL*Net message to client' ela= 4 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987576206 FETCH #140731137299392:c=0,e=327,p=0,cr=62,cu=0,mis=0,r=30,dep=0,og=1,plh=4046223463,tim=1437399987576500 WAIT #140731137299392: nam='SQL*Net message from client' ela= 2797 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987579491 WAIT #140731137299392: nam='SQL*Net message to client' ela= 3 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987579590 FETCH #140731137299392:c=0,e=69,p=0,cr=61,cu=0,mis=0,r=30,dep=0,og=1,plh=4046223463,tim=1437399987579633 WAIT #140731137299392: nam='SQL*Net message from client' ela= 2524 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987582276 WAIT #140731137299392: nam='SQL*Net message to client' ela= 4 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987582397 FETCH #140731137299392:c=0,e=197,p=0,cr=21,cu=0,mis=0,r=10,dep=0,og=1,plh=4046223463,tim=1437399987582552 STAT #140731137299392 id=1 cnt=100 pid=0 pos=1 obj=76300 op='TABLE ACCESS FULL MY_VC_CLOB (cr=9 pr=0 pw=0 time=598 us cost=3 size=211700 card=100)' WAIT #140731137299392: nam='SQL*Net message from client' ela= 18773 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437399987601536 select * from MY_VC_CLOB 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 4 0.00 0.00 0 209 0 100 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 6 0.00 0.00 0 209 0 100 Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 5 0.00 0.00 SQL*Net message from client 5 0.01 0.05 grep LOBREAD T11DB_ora_2148.trc | wc -l 0 ------------------------------------------------------------------------------------------------------------------------------------------------------ Extended SQL Trace with JDBC 10.2.0.4 (ojdbc14.jar) ------------------------------------------------------------------------------------------------------------------------------------------------------ PARSING IN CURSOR #140256018218672 len=24 dep=0 uid=91 oct=3 lid=91 tim=1437405685676258 hv=426457469 ad='7c4e4948' sqlid='7py431scqqfbx' select * from MY_VC_CLOB END OF STMT PARSE #140256018218672:c=0,e=114,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4046223463,tim=1437405685676190 EXEC #140256018218672:c=0,e=46,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4046223463,tim=1437405685676391 WAIT #140256018218672: nam='SQL*Net message to client' ela= 4 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685676446 WAIT #140256018218672: nam='SQL*Net message from client' ela= 21247 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685697774 WAIT #140256018218672: nam='SQL*Net message to client' ela= 6 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685697961 WAIT #140256018218672: nam='SQL*Net more data to client' ela= 75 driver id=1952673792 #bytes=2062 p3=0 obj#=-1 tim=1437405685698142 WAIT #140256018218672: nam='SQL*Net more data to client' ela= 19 driver id=1952673792 #bytes=2040 p3=0 obj#=-1 tim=1437405685698276 WAIT #140256018218672: nam='SQL*Net more data to client' ela= 13 driver id=1952673792 #bytes=2058 p3=0 obj#=-1 tim=1437405685698313 FETCH #140256018218672:c=1000,e=476,p=0,cr=6,cu=0,mis=0,r=30,dep=0,og=1,plh=4046223463,tim=1437405685698331 WAIT #140256018218672: nam='SQL*Net message from client' ela= 7960 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685706339 LOBGETLEN: c=0,e=17,p=0,cr=0,cu=0,tim=1437405685706410 WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685706450 WAIT #0: nam='SQL*Net message from client' ela= 419 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685706886 WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685706938 LOBREAD: c=0,e=31,p=0,cr=0,cu=0,tim=1437405685706954 WAIT #0: nam='SQL*Net message from client' ela= 642 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685707629 LOBGETLEN: c=0,e=7,p=0,cr=0,cu=0,tim=1437405685707680 WAIT #0: nam='SQL*Net message to client' ela= 11 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685707804 WAIT #0: nam='SQL*Net message from client' ela= 434 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685708256 .. .. LOBREAD: c=0,e=27,p=0,cr=0,cu=0,tim=1437405685824380 WAIT #0: nam='SQL*Net message from client' ela= 567 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685824980 LOBGETLEN: c=0,e=7,p=0,cr=0,cu=0,tim=1437405685825022 WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685825056 WAIT #0: nam='SQL*Net message from client' ela= 366 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685825439 WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685825487 LOBREAD: c=0,e=25,p=0,cr=0,cu=0,tim=1437405685825501 WAIT #0: nam='SQL*Net message from client' ela= 568 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685826102 LOBGETLEN: c=1000,e=64,p=0,cr=0,cu=0,tim=1437405685826251 WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685826297 WAIT #0: nam='SQL*Net message from client' ela= 317 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685826634 WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685826752 LOBREAD: c=0,e=58,p=0,cr=0,cu=0,tim=1437405685826776 WAIT #0: nam='SQL*Net message from client' ela= 942 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1437405685827776 CLOSE #140256018218672:c=0,e=24,dep=0,type=0,tim=1437405685827884 select * from MY_VC_CLOB 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 4 0.00 0.00 0 10 0 100 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 6 0.00 0.00 0 10 0 100 Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 5 0.00 0.00 SQL*Net message from client 5 0.02 0.03 SQL*Net more data to client 10 0.00 0.00 grep LOBREAD T11DB_ora_2811.trc | wc -l 100 ------------------------------------------------------------------------------------------------------------------------------------------------------