Home » RDBMS Server » Performance Tuning » where the second fetch data ? (oracle 10g 10.2.03)
where the second fetch data ? [message #562518] Wed, 01 August 2012 22:23 Go to next message
zengmuansha
Messages: 24
Registered: April 2012
Junior Member
SQL> create table t_all_objects as select * from dba_objects;
SQL> analyze table t_all_objects compute statistics;
SQL> select table_name,blocks,empty_blocks,num_rows from user_tables;

TABLE_NAME BLOCKS EMPTY_BLOCKS NUM_ROWS
------------------------------ ---------- ------------ ----------
T_ALL_OBJECTS 711 57 50315


SQL> alter system set "_trace_pin_time"=1 scope=spfile;
SQL> SELECT SYS_CONTEXT ('USERENV', 'SID') sid FROM DUAL;
SQL> alter session set events '10046 trace name context forever,level 12';

declare
type type_owner is table of t_all_objects.owner%type index by binary_integer;
type type_object_name is table of t_all_objects.object_name%type index by binary_integer;
type type_object_id is table of t_all_objects.object_id%type index by binary_integer;
type type_object_type is table of t_all_objects.object_type%type index by binary_integer;
type type_last_ddl_time is table of t_all_objects.last_ddl_time%type index by binary_integer;


l_ary_owner type_owner;
l_ary_object_name type_object_name;
l_ary_object_id type_object_id;
l_ary_object_type type_object_type;
l_ary_last_ddl_time type_last_ddl_time;

cursor cur_object is
select owner,object_name,object_id,object_type,last_ddl_time
from t_all_objects
order by owner,object_name,object_type,last_ddl_time;
begin
open cur_object;
dbms_lock.sleep(10);
loop
fetch cur_object bulk collect into
l_ary_owner,
l_ary_object_name,
l_ary_object_id,
l_ary_object_type,
l_ary_last_ddl_time
limit 10000;
dbms_lock.sleep(10);
exit when cur_object%notfound or cur_object%notfound is null;
end loop;
end;

alter session set events '10046 trace name context off';


tkpof trc:
********************************************************************************

SELECT OWNER,OBJECT_NAME,OBJECT_ID,OBJECT_TYPE,LAST_DDL_TIME
FROM
T_ALL_OBJECTS ORDER BY OWNER,OBJECT_NAME,OBJECT_TYPE,LAST_DDL_TIME


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 6 0.12 0.18 692 696 0 50315
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 8 0.12 0.18 692 696 0 50315

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61 (recursive depth: 1)

Rows Row Source Operation
------- ---------------------------------------------------
50315 SORT ORDER BY (cr=696 pr=692 pw=0 time=108924 us)
50315 TABLE ACCESS FULL T_ALL_OBJECTS (cr=696 pr=692 pw=0 time=209974 us)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1 0.00 0.00
db file scattered read 35 0.01 0.05
********************************************************************************


trc file source:

=====================
PARSING IN CURSOR #4 len=132 dep=1 uid=61 oct=3 lid=61 tim=2088173298 hv=273040489 ad='27e62380'
SELECT OWNER,OBJECT_NAME,OBJECT_ID,OBJECT_TYPE,LAST_DDL_TIME FROM T_ALL_OBJECTS ORDER BY OWNER,OBJECT_NAME,OBJECT_TYPE,LAST_DDL_TIME
END OF STMT
PARSE #4:c=15625,e=79120,p=10,cr=132,cu=0,mis=1,r=0,dep=1,og=1,tim=2088173296
BINDS #4:
EXEC #4:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=2088173359
*** 2012-08-02 09:53:01.359
WAIT #3: nam='PL/SQL lock timer' ela= 10000299 duration=1000 p2=0 p3=0 obj#=10209 tim=2098173754
WAIT #4: nam='db file sequential read' ela= 8048 file#=4 block#=411 blocks=1 obj#=52544 tim=2098182123
pin ktewh25: kteinicnt dba 100019b:4 time 2098182185
pin ktewh26: kteinpscan dba 100019b:4 time 2098182223
pin ktewh27: kteinmap dba 100019b:4 time 2098182241
WAIT #4: nam='db file scattered read' ela= 280 file#=4 block#=412 blocks=5 obj#=52544 tim=2098182583
pin kdswh01: kdstgr dba 100019c:1 time 2098182615
pin kdswh01: kdstgr dba 100019d:1 time 2098182702
pin kdswh01: kdstgr dba 100019e:1 time 2098182764
pin kdswh01: kdstgr dba 100019f:1 time 2098182798
pin kdswh01: kdstgr dba 10001a0:1 time 2098182843
WAIT #4: nam='db file scattered read' ela= 425 file#=4 block#=417 blocks=8 obj#=52544 tim=2098183321
pin kdswh01: kdstgr dba 10001a1:1 time 2098183343
pin kdswh01: kdstgr dba 10001a2:1 time 2098183384
pin kdswh01: kdstgr dba 10001a3:1 time 2098183417
pin kdswh01: kdstgr dba 10001a4:1 time 2098183451
pin kdswh01: kdstgr dba 10001a5:1 time 2098183485
pin kdswh01: kdstgr dba 10001a6:1 time 2098183533
pin kdswh01: kdstgr dba 10001a7:1 time 2098183570
pin kdswh01: kdstgr dba 10001a8:1 time 2098183620
WAIT #4: nam='db file scattered read' ela= 1370 file#=4 block#=1195 blocks=32 obj#=52544 tim=2098265897
pin kdswh01: kdstgr dba 10004ab:1 time 2098265944
pin kdswh01: kdstgr dba 10004ac:1 time 2098265995
..........................................................
WAIT #4: nam='db file scattered read' ela= 244 file#=4 block#=1227 blocks=5 obj#=52544 tim=2098267164
pin kdswh01: kdstgr dba 10004cb:1 time 2098267195
pin kdswh01: kdstgr dba 10004cc:1 time 2098267246
pin kdswh01: kdstgr dba 10004cd:1 time 2098267296
pin kdswh01: kdstgr dba 10004ce:1 time 2098267348
pin kdswh01: kdstgr dba 10004cf:1 time 2098267395
FETCH #4:c=62500,e=127231,p=692,cr=696,cu=0,mis=0,r=10000,dep=1,og=1,tim=2098301132
*** 2012-08-02 09:53:11.484
WAIT #3: nam='PL/SQL lock timer' ela= 9999874 duration=1000 p2=0 p3=0 obj#=52544 tim=2108301094
FETCH #4:c=15625,e=12506,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2108314116
*** 2012-08-02 09:53:21.500
WAIT #3: nam='PL/SQL lock timer' ela= 9999983 duration=1000 p2=0 p3=0 obj#=52544 tim=2118314180
FETCH #4:c=15625,e=12784,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2118327436
*** 2012-08-02 09:53:31.515
WAIT #3: nam='PL/SQL lock timer' ela= 9999738 duration=1000 p2=0 p3=0 obj#=52544 tim=2128327259
FETCH #4:c=15625,e=12449,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2128340197
*** 2012-08-02 09:53:41.531
WAIT #3: nam='PL/SQL lock timer' ela= 10000148 duration=1000 p2=0 p3=0 obj#=52544 tim=2138340423
FETCH #4:c=15625,e=17133,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2138358015
*** 2012-08-02 09:53:51.546
WAIT #3: nam='PL/SQL lock timer' ela= 10000195 duration=1000 p2=0 p3=0 obj#=52544 tim=2148358309
FETCH #4:c=0,e=900,p=0,cr=0,cu=0,mis=0,r=315,dep=1,og=1,tim=2148359809
*** 2012-08-02 09:54:01.546
WAIT #3: nam='PL/SQL lock timer' ela= 9999756 duration=1000 p2=0 p3=0 obj#=52544 tim=2158359672
EXEC #3:c=140625,e=70266159,p=702,cr=828,cu=0,mis=0,r=1,dep=0,og=1,tim=2158360286
WAIT #3: nam='SQL*Net message to client' ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2158360654
WAIT #3: nam='SQL*Net message from client' ela= 4510 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2158365188
STAT #4 id=1 cnt=50315 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=696 pr=692 pw=0 time=108924 us)'
STAT #4 id=2 cnt=50315 pid=1 pos=1 obj=52544 op='TABLE ACCESS FULL T_ALL_OBJECTS (cr=696 pr=692 pw=0 time=209974 us)'
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2158365322
*** 2012-08-02 09:54:25.375
WAIT #0: nam='SQL*Net message from client' ela= 23820886 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2182186228
=====================
Re: where the second fetch data ? [message #562519 is a reply to message #562518] Wed, 01 August 2012 22:27 Go to previous messageGo to next message
zengmuansha
Messages: 24
Registered: April 2012
Junior Member
Where the Second Fetch from data?

FETCH #4:c=62500,e=127231,p=692,cr=696,cu=0,mis=0,r=10000,dep=1,og=1,tim=2098301132
*** 2012-08-02 09:53:11.484
WAIT #3: nam='PL/SQL lock timer' ela= 9999874 duration=1000 p2=0 p3=0 obj#=52544 tim=2108301094
FETCH #4:c=15625,e=12506,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2108314116
*** 2012-08-02 09:53:21.500
WAIT #3: nam='PL/SQL lock timer' ela= 9999983 duration=1000 p2=0 p3=0 obj#=52544 tim=2118314180
FETCH #4:c=15625,e=12784,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2118327436
*** 2012-08-02 09:53:31.515
WAIT #3: nam='PL/SQL lock timer' ela= 9999738 duration=1000 p2=0 p3=0 obj#=52544 tim=2128327259
FETCH #4:c=15625,e=12449,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2128340197
*** 2012-08-02 09:53:41.531
WAIT #3: nam='PL/SQL lock timer' ela= 10000148 duration=1000 p2=0 p3=0 obj#=52544 tim=2138340423
FETCH #4:c=15625,e=17133,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2138358015
*** 2012-08-02 09:53:51.546
WAIT #3: nam='PL/SQL lock timer' ela= 10000195 duration=1000 p2=0 p3=0 obj#=52544 tim=2148358309
FETCH #4:c=0,e=900,p=0,cr=0,cu=0,mis=0,r=315,dep=1,og=1,tim=2148359809
*** 2012-08-02 09:54:01.546

Thank you !
Re: where the second fetch data ? [message #562520 is a reply to message #562518] Wed, 01 August 2012 22:33 Go to previous messageGo to next message
zengmuansha
Messages: 24
Registered: April 2012
Junior Member
SQL> create table t_all_objects as select * from dba_objects;
SQL> analyze table t_all_objects compute statistics;
SQL> select table_name,blocks,empty_blocks,num_rows from user_tables;

TABLE_NAME                         BLOCKS EMPTY_BLOCKS   NUM_ROWS
------------------------------ ---------- ------------ ----------
T_ALL_OBJECTS                         711           57      50315


SQL> alter system set "_trace_pin_time"=1 scope=spfile;
SQL> SELECT SYS_CONTEXT ('USERENV', 'SID') sid FROM DUAL;
SQL> alter session set events '10046 trace name context forever,level 12';


declare
type type_owner is table of t_all_objects.owner%type index by binary_integer;
type type_object_name is table of t_all_objects.object_name%type index by binary_integer;
type type_object_id is table of t_all_objects.object_id%type index by binary_integer;
type type_object_type is table of t_all_objects.object_type%type index by binary_integer;
type type_last_ddl_time is table of t_all_objects.last_ddl_time%type index by binary_integer;
 

l_ary_owner type_owner;
l_ary_object_name type_object_name;
l_ary_object_id type_object_id;
l_ary_object_type type_object_type;
l_ary_last_ddl_time type_last_ddl_time;

cursor cur_object is 
   select owner,object_name,object_id,object_type,last_ddl_time
   from t_all_objects
   order by owner,object_name,object_type,last_ddl_time;
begin
  open cur_object;
  dbms_lock.sleep(10);
  loop
    fetch  cur_object bulk collect into
      l_ary_owner,
      l_ary_object_name,
      l_ary_object_id,
      l_ary_object_type,
      l_ary_last_ddl_time
   limit 10000;
   dbms_lock.sleep(10);
   exit when cur_object%notfound or cur_object%notfound is null;   
 end loop;   
end; 


alter session set events '10046 trace name context off';


tkpof trc:
********************************************************************************

SELECT OWNER,OBJECT_NAME,OBJECT_ID,OBJECT_TYPE,LAST_DDL_TIME
FROM
T_ALL_OBJECTS ORDER BY OWNER,OBJECT_NAME,OBJECT_TYPE,LAST_DDL_TIME


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 6 0.12 0.18 692 696 0 50315
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 8 0.12 0.18 692 696 0 50315

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61 (recursive depth: 1)

Rows Row Source Operation
------- ---------------------------------------------------
50315 SORT ORDER BY (cr=696 pr=692 pw=0 time=108924 us)
50315 TABLE ACCESS FULL T_ALL_OBJECTS (cr=696 pr=692 pw=0 time=209974 us)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1 0.00 0.00
db file scattered read 35 0.01 0.05
********************************************************************************


trc file source:

=====================
PARSING IN CURSOR #4 len=132 dep=1 uid=61 oct=3 lid=61 tim=2088173298 hv=273040489 ad='27e62380'
SELECT OWNER,OBJECT_NAME,OBJECT_ID,OBJECT_TYPE,LAST_DDL_TIME FROM T_ALL_OBJECTS ORDER BY OWNER,OBJECT_NAME,OBJECT_TYPE,LAST_DDL_TIME
END OF STMT
PARSE #4:c=15625,e=79120,p=10,cr=132,cu=0,mis=1,r=0,dep=1,og=1,tim=2088173296
BINDS #4:
EXEC #4:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=2088173359
*** 2012-08-02 09:53:01.359
WAIT #3: nam='PL/SQL lock timer' ela= 10000299 duration=1000 p2=0 p3=0 obj#=10209 tim=2098173754
WAIT #4: nam='db file sequential read' ela= 8048 file#=4 block#=411 blocks=1 obj#=52544 tim=2098182123
pin ktewh25: kteinicnt dba 100019b:4 time 2098182185
pin ktewh26: kteinpscan dba 100019b:4 time 2098182223
pin ktewh27: kteinmap dba 100019b:4 time 2098182241
WAIT #4: nam='db file scattered read' ela= 280 file#=4 block#=412 blocks=5 obj#=52544 tim=2098182583
pin kdswh01: kdstgr dba 100019c:1 time 2098182615
pin kdswh01: kdstgr dba 100019d:1 time 2098182702
pin kdswh01: kdstgr dba 100019e:1 time 2098182764
pin kdswh01: kdstgr dba 100019f:1 time 2098182798
pin kdswh01: kdstgr dba 10001a0:1 time 2098182843
WAIT #4: nam='db file scattered read' ela= 425 file#=4 block#=417 blocks=8 obj#=52544 tim=2098183321
pin kdswh01: kdstgr dba 10001a1:1 time 2098183343
pin kdswh01: kdstgr dba 10001a2:1 time 2098183384
pin kdswh01: kdstgr dba 10001a3:1 time 2098183417
pin kdswh01: kdstgr dba 10001a4:1 time 2098183451
pin kdswh01: kdstgr dba 10001a5:1 time 2098183485
pin kdswh01: kdstgr dba 10001a6:1 time 2098183533
pin kdswh01: kdstgr dba 10001a7:1 time 2098183570
pin kdswh01: kdstgr dba 10001a8:1 time 2098183620
WAIT #4: nam='db file scattered read' ela= 1370 file#=4 block#=1195 blocks=32 obj#=52544 tim=2098265897
pin kdswh01: kdstgr dba 10004ab:1 time 2098265944
pin kdswh01: kdstgr dba 10004ac:1 time 2098265995
..........................................................
WAIT #4: nam='db file scattered read' ela= 244 file#=4 block#=1227 blocks=5 obj#=52544 tim=2098267164
pin kdswh01: kdstgr dba 10004cb:1 time 2098267195
pin kdswh01: kdstgr dba 10004cc:1 time 2098267246
pin kdswh01: kdstgr dba 10004cd:1 time 2098267296
pin kdswh01: kdstgr dba 10004ce:1 time 2098267348
pin kdswh01: kdstgr dba 10004cf:1 time 2098267395
FETCH #4:c=62500,e=127231,p=692,cr=696,cu=0,mis=0,r=10000,dep=1,og=1,tim=2098301132
*** 2012-08-02 09:53:11.484
WAIT #3: nam='PL/SQL lock timer' ela= 9999874 duration=1000 p2=0 p3=0 obj#=52544 tim=2108301094
FETCH #4:c=15625,e=12506,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2108314116
*** 2012-08-02 09:53:21.500
WAIT #3: nam='PL/SQL lock timer' ela= 9999983 duration=1000 p2=0 p3=0 obj#=52544 tim=2118314180
FETCH #4:c=15625,e=12784,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2118327436
*** 2012-08-02 09:53:31.515
WAIT #3: nam='PL/SQL lock timer' ela= 9999738 duration=1000 p2=0 p3=0 obj#=52544 tim=2128327259
FETCH #4:c=15625,e=12449,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2128340197
*** 2012-08-02 09:53:41.531
WAIT #3: nam='PL/SQL lock timer' ela= 10000148 duration=1000 p2=0 p3=0 obj#=52544 tim=2138340423
FETCH #4:c=15625,e=17133,p=0,cr=0,cu=0,mis=0,r=10000,dep=1,og=1,tim=2138358015
*** 2012-08-02 09:53:51.546
WAIT #3: nam='PL/SQL lock timer' ela= 10000195 duration=1000 p2=0 p3=0 obj#=52544 tim=2148358309
FETCH #4:c=0,e=900,p=0,cr=0,cu=0,mis=0,r=315,dep=1,og=1,tim=2148359809
*** 2012-08-02 09:54:01.546
WAIT #3: nam='PL/SQL lock timer' ela= 9999756 duration=1000 p2=0 p3=0 obj#=52544 tim=2158359672
EXEC #3:c=140625,e=70266159,p=702,cr=828,cu=0,mis=0,r=1,dep=0,og=1,tim=2158360286
WAIT #3: nam='SQL*Net message to client' ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2158360654
WAIT #3: nam='SQL*Net message from client' ela= 4510 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2158365188
STAT #4 id=1 cnt=50315 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=696 pr=692 pw=0 time=108924 us)'
STAT #4 id=2 cnt=50315 pid=1 pos=1 obj=52544 op='TABLE ACCESS FULL T_ALL_OBJECTS (cr=696 pr=692 pw=0 time=209974 us)'
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2158365322
*** 2012-08-02 09:54:25.375
WAIT #0: nam='SQL*Net message from client' ela= 23820886 driver id=1111838976 #bytes=1 p3=0 obj#=52544 tim=2182186228

Re: where the second fetch data ? [message #562573 is a reply to message #562520] Thu, 02 August 2012 06:25 Go to previous message
cookiemonster
Messages: 10845
Registered: September 2008
Location: Rainy Manchester
Senior Member
There's six fetches.
What exactly is the problem?
Previous Topic: connect database
Next Topic: Not exists inside exists is having very low performence
Goto Forum:
  


Current Time: Wed Jul 23 07:10:28 CDT 2014

Total time taken to generate the page: 0.19470 seconds