OraFAQ Forum: Performance Tuning » Query Regarding Nested Loop

Home » RDBMS Server » Performance Tuning » Query Regarding Nested Loop (Oracle 9i R2 on RHEL)

Show: Today's Messages :: Polls :: Message Navigator
E-mail to friend

Query Regarding Nested Loop [message #490759]

Thu, 27 January 2011 03:48

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello

Please refer the following execution plan

select /*+ use_nl(t2) */ t1.object_name,t1.object_type,t1.owner,t2.created
from
 t1,t2 where t1.id=t2.id


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       68      0.00       0.00          0       3149          0         999
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       70      0.00       0.01          0       3149          0         999

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 5

Rows     Row Source Operation
-------  ---------------------------------------------------
    999  NESTED LOOPS
    999   TABLE ACCESS FULL T2
    999   TABLE ACCESS BY INDEX ROWID T1
    999    INDEX UNIQUE SCAN T1_PK (object id 4456163)

Why the step 'TABLE ACCESS BY INDEX ROWID T1' is showing 999 rows?

I was expecting it will get 1 row in each iteration for total of 999 iterations

Also please refer the step

999  NESTED LOOPS

Can we say the value 999 in this step always matches with the count of previous step ('TABLE ACCESS FULL T2' in this case) and that is the number of iterations of 'Nested Loop'?

Thanks and Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490765 is a reply to message #490759]

Thu, 27 January 2011 04:04

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Post the raw trace file AND the command you exevuted to generate what you posted.

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #490768 is a reply to message #490759]

Thu, 27 January 2011 04:27

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Thanks Michel

I started trace using

SQL> alter session set events '10046 trace name context forever, level 12';
SQL> select t1.object_name,t1.object_type,t1.owner,t2.created
from t1,t2 where t1.id=t2.id;

SQL> select /*+ use_nl(t2) */ t1.object_name,t1.object_type,t1.owner,t2.created
from t1,t2 where t1.id=t2.id;

exit

Following is the content of raw trace file (unable to attach it here)

/opt/oracle/admin/PGU1/udump/pgu1_ora_30600.trc
Oracle9i Enterprise Edition Release 9.2.0.8.0 - 64bit Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.8.0 - Production
ORACLE_HOME = /opt/oracle/product/920
System name:	Linux
Node name:	dev-pgu1
Release:	2.6.9-42.EL
Version:	#1 Wed Jul 12 23:15:20 EDT 2006
Machine:	x86_64
Instance name: PGU1
Redo thread mounted by this instance: 1
Oracle process number: 11
Unix process pid: 30600, image: oracle@dev-pgu1 (TNS V1-V3)

*** 2011-01-27 08:50:50.734
*** SESSION ID:(20.14491) 2011-01-27 08:50:50.733
APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240
=====================
PARSING IN CURSOR #3 len=69 dep=0 uid=5 oct=42 lid=5 tim=1265740479232572 hv=2004533713 ad='88ff5168'
alter session set events '10046 trace name context forever, level 12'
END OF STMT
EXEC #3:c=1000,e=125,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1265740479232217
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
*** 2011-01-27 08:52:22.029
WAIT #3: nam='SQL*Net message from client' ela= 89155301 p1=1650815232 p2=1 p3=0
=====================
PARSING IN CURSOR #3 len=85 dep=0 uid=5 oct=3 lid=5 tim=1265740568391013 hv=2293548751 ad='88c9a6d0'
select t1.object_name,t1.object_type,t1.owner,t2.created from t1,t2 where t1.id=t2.id
END OF STMT
PARSE #3:c=3000,e=2688,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=1265740568391008
BINDS #3:
EXEC #3:c=0,e=128,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1265740568391235
WAIT #3: nam='SQL*Net message to client' ela= 3 p1=1650815232 p2=1 p3=0
FETCH #3:c=4999,e=4153,p=0,cr=22,cu=0,mis=0,r=1,dep=0,og=4,tim=1265740568395442
WAIT #3: nam='SQL*Net message from client' ela= 500 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=42,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568396146
WAIT #3: nam='SQL*Net message from client' ela= 912 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=43,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568397149
WAIT #3: nam='SQL*Net message from client' ela= 880 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=76,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568398149
WAIT #3: nam='SQL*Net message from client' ela= 771 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=38,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568399000
WAIT #3: nam='SQL*Net message from client' ela= 651 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=77,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568399767
WAIT #3: nam='SQL*Net message from client' ela= 610 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568400453
WAIT #3: nam='SQL*Net message from client' ela= 720 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=38,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568401247
WAIT #3: nam='SQL*Net message from client' ela= 775 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=21,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568402080
WAIT #3: nam='SQL*Net message from client' ela= 787 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568402924
WAIT #3: nam='SQL*Net message from client' ela= 777 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=41,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568403784
WAIT #3: nam='SQL*Net message from client' ela= 825 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=41,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568404691
WAIT #3: nam='SQL*Net message from client' ela= 568 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=41,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568405395
WAIT #3: nam='SQL*Net message from client' ela= 744 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=62,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568406238
WAIT #3: nam='SQL*Net message from client' ela= 699 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=48,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568407012
WAIT #3: nam='SQL*Net message from client' ela= 802 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568407875
WAIT #3: nam='SQL*Net message from client' ela= 589 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=39,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568408547
WAIT #3: nam='SQL*Net message from client' ela= 664 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=38,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568409290
WAIT #3: nam='SQL*Net message from client' ela= 639 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=47,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568410126
WAIT #3: nam='SQL*Net message from client' ela= 705 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=3,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568410870
WAIT #3: nam='SQL*Net message from client' ela= 831 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=37,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568411761
WAIT #3: nam='SQL*Net message from client' ela= 619 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=37,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568412456
WAIT #3: nam='SQL*Net message from client' ela= 530 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568413057
WAIT #3: nam='SQL*Net message from client' ela= 700 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=4,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568413797
WAIT #3: nam='SQL*Net message from client' ela= 799 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568414654
WAIT #3: nam='SQL*Net message from client' ela= 746 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=37,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568415475
WAIT #3: nam='SQL*Net message from client' ela= 788 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568416335
WAIT #3: nam='SQL*Net message from client' ela= 475 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=71,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568416949
WAIT #3: nam='SQL*Net message from client' ela= 707 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=1000,e=122,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568417882
WAIT #3: nam='SQL*Net message from client' ela= 711 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568418670
WAIT #3: nam='SQL*Net message from client' ela= 750 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=39,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568419532
WAIT #3: nam='SQL*Net message from client' ela= 765 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=36,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568420372
WAIT #3: nam='SQL*Net message from client' ela= 588 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=49,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568421047
WAIT #3: nam='SQL*Net message from client' ela= 648 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=39,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568421876
WAIT #3: nam='SQL*Net message from client' ela= 701 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=0,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568422593
WAIT #3: nam='SQL*Net message from client' ela= 745 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568423409
WAIT #3: nam='SQL*Net message from client' ela= 694 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=48,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568424189
WAIT #3: nam='SQL*Net message from client' ela= 547 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568424813
WAIT #3: nam='SQL*Net message from client' ela= 730 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=5,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568425569
WAIT #3: nam='SQL*Net message from client' ela= 807 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568426435
WAIT #3: nam='SQL*Net message from client' ela= 746 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=33,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568427250
WAIT #3: nam='SQL*Net message from client' ela= 530 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=47,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568427864
WAIT #3: nam='SQL*Net message from client' ela= 695 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=60,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568428658
WAIT #3: nam='SQL*Net message from client' ela= 697 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=65,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568429460
WAIT #3: nam='SQL*Net message from client' ela= 714 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=37,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568430275
WAIT #3: nam='SQL*Net message from client' ela= 557 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=47,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568430916
WAIT #3: nam='SQL*Net message from client' ela= 589 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568431595
WAIT #3: nam='SQL*Net message from client' ela= 726 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=3,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568432355
WAIT #3: nam='SQL*Net message from client' ela= 794 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=38,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568433258
WAIT #3: nam='SQL*Net message from client' ela= 778 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=37,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568434153
WAIT #3: nam='SQL*Net message from client' ela= 489 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=71,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568434750
WAIT #3: nam='SQL*Net message from client' ela= 645 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=40,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568435499
WAIT #3: nam='SQL*Net message from client' ela= 732 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=0,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568436260
WAIT #3: nam='SQL*Net message from client' ela= 758 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568437074
WAIT #3: nam='SQL*Net message from client' ela= 584 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=60,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568437755
WAIT #3: nam='SQL*Net message from client' ela= 591 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568438420
WAIT #3: nam='SQL*Net message from client' ela= 739 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=3,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568439185
WAIT #3: nam='SQL*Net message from client' ela= 814 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568440057
WAIT #3: nam='SQL*Net message from client' ela= 763 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568440893
WAIT #3: nam='SQL*Net message from client' ela= 737 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=42,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568441708
WAIT #3: nam='SQL*Net message from client' ela= 739 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568442520
WAIT #3: nam='SQL*Net message from client' ela= 696 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=61,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568443315
WAIT #3: nam='SQL*Net message from client' ela= 708 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=25,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568444115
WAIT #3: nam='SQL*Net message from client' ela= 753 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=44,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568444938
WAIT #3: nam='SQL*Net message from client' ela= 558 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568445569
WAIT #3: nam='SQL*Net message from client' ela= 584 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=50,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568446239
WAIT #3: nam='SQL*Net message from client' ela= 723 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=2,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=4,tim=1265740568447002
WAIT #3: nam='SQL*Net message from client' ela= 762 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=154977,e=154136,p=0,cr=7805,cu=0,mis=0,r=8,dep=0,og=4,tim=1265740568602014
*** 2011-01-27 09:34:27.963
WAIT #3: nam='SQL*Net message from client' ela= 2466518095 p1=1650815232 p2=1 p3=0
STAT #3 id=1 cnt=999 pid=0 pos=1 obj=0 op='HASH JOIN  '
STAT #3 id=2 cnt=999 pid=1 pos=1 obj=4456161 op='TABLE ACCESS FULL T2 '
STAT #3 id=3 cnt=563904 pid=1 pos=2 obj=4456156 op='TABLE ACCESS FULL T1 '
=====================
PARSING IN CURSOR #3 len=103 dep=0 uid=5 oct=3 lid=5 tim=1265743035124750 hv=2335263760 ad='88b10510'
select /*+ use_nl(t2) */ t1.object_name,t1.object_type,t1.owner,t2.created from t1,t2 where t1.id=t2.id
END OF STMT
PARSE #3:c=2999,e=3046,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=1265743035124750
BINDS #3:
EXEC #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1265743035124750
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=483,p=0,cr=8,cu=0,mis=0,r=1,dep=0,og=4,tim=1265743035125380
WAIT #3: nam='SQL*Net message from client' ela= 451 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=7,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035125932
WAIT #3: nam='SQL*Net message from client' ela= 1017 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=221,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035127201
WAIT #3: nam='SQL*Net message from client' ela= 799 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=90,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035128140
WAIT #3: nam='SQL*Net message from client' ela= 726 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=109,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035129015
WAIT #3: nam='SQL*Net message from client' ela= 677 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=171,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035129905
WAIT #3: nam='SQL*Net message from client' ela= 734 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=85,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035130767
WAIT #3: nam='SQL*Net message from client' ela= 731 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=27,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035131564
WAIT #3: nam='SQL*Net message from client' ela= 854 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=38,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035132484
WAIT #3: nam='SQL*Net message from client' ela= 915 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=38,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035133487
WAIT #3: nam='SQL*Net message from client' ela= 811 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=170,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035134503
WAIT #3: nam='SQL*Net message from client' ela= 747 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=84,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035135358
WAIT #3: nam='SQL*Net message from client' ela= 807 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=91,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035136300
WAIT #3: nam='SQL*Net message from client' ela= 1261 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=388,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035138031
WAIT #3: nam='SQL*Net message from client' ela= 807 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=277,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035139228
WAIT #3: nam='SQL*Net message from client' ela= 714 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=93,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035140094
WAIT #3: nam='SQL*Net message from client' ela= 1341 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=211,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035141755
WAIT #3: nam='SQL*Net message from client' ela= 892 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=113,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035142830
WAIT #3: nam='SQL*Net message from client' ela= 772 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=273,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035143923
WAIT #3: nam='SQL*Net message from client' ela= 748 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=222,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035144943
WAIT #3: nam='SQL*Net message from client' ela= 624 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=184,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035145798
WAIT #3: nam='SQL*Net message from client' ela= 1063 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=179,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035147155
WAIT #3: nam='SQL*Net message from client' ela= 968 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=4,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035148163
WAIT #3: nam='SQL*Net message from client' ela= 859 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=1000,e=223,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035149266
WAIT #3: nam='SQL*Net message from client' ela= 750 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=31,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035150099
WAIT #3: nam='SQL*Net message from client' ela= 863 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=35,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035151028
WAIT #3: nam='SQL*Net message from client' ela= 791 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=84,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035151979
WAIT #3: nam='SQL*Net message from client' ela= 728 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=101,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035152846
WAIT #3: nam='SQL*Net message from client' ela= 752 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=83,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035153721
WAIT #3: nam='SQL*Net message from client' ela= 787 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=191,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035154740
WAIT #3: nam='SQL*Net message from client' ela= 496 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=87,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035155373
WAIT #3: nam='SQL*Net message from client' ela= 765 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=21,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035156197
WAIT #3: nam='SQL*Net message from client' ela= 718 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=234,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035157335
WAIT #3: nam='SQL*Net message from client' ela= 717 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=21,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035158145
WAIT #3: nam='SQL*Net message from client' ela= 723 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=88,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035159112
WAIT #3: nam='SQL*Net message from client' ela= 717 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=1000,e=199,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035160060
WAIT #3: nam='SQL*Net message from client' ela= 707 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=28,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035160840
WAIT #3: nam='SQL*Net message from client' ela= 1852 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 12 p1=1650815232 p2=1 p3=0
FETCH #3:c=1000,e=206,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035162999
WAIT #3: nam='SQL*Net message from client' ela= 1094 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=90,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035164224
WAIT #3: nam='SQL*Net message from client' ela= 772 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=84,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035165125
WAIT #3: nam='SQL*Net message from client' ela= 806 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=149,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035166103
WAIT #3: nam='SQL*Net message from client' ela= 803 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=270,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035167199
WAIT #3: nam='SQL*Net message from client' ela= 763 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=99,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035168112
WAIT #3: nam='SQL*Net message from client' ela= 766 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=86,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035169082
WAIT #3: nam='SQL*Net message from client' ela= 825 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=96,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035170046
WAIT #3: nam='SQL*Net message from client' ela= 801 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=228,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035171118
WAIT #3: nam='SQL*Net message from client' ela= 754 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=85,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035172004
WAIT #3: nam='SQL*Net message from client' ela= 786 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=85,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035172917
WAIT #3: nam='SQL*Net message from client' ela= 808 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=129,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035173919
WAIT #3: nam='SQL*Net message from client' ela= 727 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=33,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035174723
WAIT #3: nam='SQL*Net message from client' ela= 839 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=228,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035175830
WAIT #3: nam='SQL*Net message from client' ela= 804 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=2,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035176719
WAIT #3: nam='SQL*Net message from client' ela= 903 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=30,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035177675
WAIT #3: nam='SQL*Net message from client' ela= 799 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=104,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035178728
WAIT #3: nam='SQL*Net message from client' ela= 861 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=238,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035179878
WAIT #3: nam='SQL*Net message from client' ela= 794 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=179,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035180902
WAIT #3: nam='SQL*Net message from client' ela= 733 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=96,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035181787
WAIT #3: nam='SQL*Net message from client' ela= 857 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=88,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035182776
WAIT #3: nam='SQL*Net message from client' ela= 830 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=95,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035183743
WAIT #3: nam='SQL*Net message from client' ela= 818 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=149,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035184753
WAIT #3: nam='SQL*Net message from client' ela= 781 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=158,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035185754
WAIT #3: nam='SQL*Net message from client' ela= 731 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=83,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035186614
WAIT #3: nam='SQL*Net message from client' ela= 779 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=113,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035187544
WAIT #3: nam='SQL*Net message from client' ela= 782 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 0 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=182,p=0,cr=48,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035188552
WAIT #3: nam='SQL*Net message from client' ela= 827 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=277,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035189688
WAIT #3: nam='SQL*Net message from client' ela= 762 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=147,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035190645
WAIT #3: nam='SQL*Net message from client' ela= 757 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=165,p=0,cr=47,cu=0,mis=0,r=15,dep=0,og=4,tim=1265743035191625
WAIT #3: nam='SQL*Net message from client' ela= 795 p1=1650815232 p2=1 p3=0
WAIT #3: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0
FETCH #3:c=0,e=102,p=0,cr=26,cu=0,mis=0,r=8,dep=0,og=4,tim=1265743035192572
WAIT #3: nam='SQL*Net message from client' ela= 2240188 p1=1650815232 p2=1 p3=0
STAT #3 id=1 cnt=999 pid=0 pos=1 obj=0 op='NESTED LOOPS  '
STAT #3 id=2 cnt=999 pid=1 pos=1 obj=4456161 op='TABLE ACCESS FULL T2 '
STAT #3 id=3 cnt=999 pid=1 pos=2 obj=4456156 op='TABLE ACCESS BY INDEX ROWID T1 '
STAT #3 id=4 cnt=999 pid=3 pos=1 obj=4456163 op='INDEX UNIQUE SCAN T1_PK '
XCTEND rlbk=0, rd_only=1

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490806 is a reply to message #490768]

Thu, 27 January 2011 07:54

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello Michel

Isn't this (trace file contents in earlier post) what you were expecting from me?

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490830 is a reply to message #490806]

Thu, 27 January 2011 10:22

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Be patient, if you have a look at my posts you will see I was offline during 5-6 hours. You know I have also to do the job I am paid for.
I will have a look at your trace file as soon as I have a moment.
In the meantime, post the TKPROF command you executed to get what you posted above.

Regards
Michel

[Updated on: Thu, 27 January 2011 10:24]

Report message to a moderator

Re: Query Regarding Nested Loop [message #490834 is a reply to message #490759]

Thu, 27 January 2011 10:30

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello Michel

Sorry for that

In fact it is really unusual not getting your in few minutes

I have already posted the tkprof command, I have used to get the trace mentioned

SQL> alter session set events '10046 trace name context forever, level 12';

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490837 is a reply to message #490834]

Thu, 27 January 2011 10:35

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

No, this is the command to get the trace file not the TKPROF command that generates, from this trace file, what you posted in first.

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #490838 is a reply to message #490837]

Thu, 27 January 2011 10:59

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Oh No

I misunderstood it

it was as following :

tkprof pgu1_ora_30600.trc pgu1_ora_30600.txt sys=no

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490843 is a reply to message #490838]

Thu, 27 January 2011 12:01

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

"cnt" gives the total number of rows returned by each execution operation, not the number of rows returned for each execution of the operation (that could be a different number at each time).

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #490881 is a reply to message #490759]

Fri, 28 January 2011 00:16

hkchital
Messages: 128
Registered: September 2008
Location: Singapore

Senior Member

The tkprof output shows the *run* statistics, not the execution plan (i.e. estimate).

Here it did a FullTableScan of table T2 and fetched 999 rows.
For each from T2, it did an Index Lookup on T1. Thus, it did 999 index lookups. Each index lookup returned 1 row -- resulting in 999 rows being returned from T1. These are run statistics --- actual counts.

T2 drove 999 iteration lookup on T1. That doesn't necessarily always mean that T1 will return 999 rows. There may be a 1-to-1 correspondence, which we see in this case. However, it can be that for every T2 row, there are 10 rows in T1. Therefore, there would be 999 index lookups on T1 but 999x10 = 9990 rows fetched from T1. Conversely, some of the rows may fail to join in T1. There may be 999 calls to read the T1 index but, say, only 400 may have returned ROWIDs to retrieve rows from T1.

Hemant K Chitale

Report message to a moderator

Re: Query Regarding Nested Loop [message #490888 is a reply to message #490881]

Fri, 28 January 2011 01:05

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Quote:

The tkprof output shows the *run* statistics, not the execution plan (i.e. estimate).

Of course, it shows the execution plan, the actual execution plan not an estimated one.

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #490911 is a reply to message #490888]

Fri, 28 January 2011 02:58

hkchital
Messages: 128
Registered: September 2008
Location: Singapore

Senior Member

What OraKaran has posted is
Rows Row Source Operation
------- ---------------------------------------------------

which is runtime statistics *NOT* an Execution Plan (whether estimated or actual).

If tkprof is run with the explain option, the Execution Plan is presented with this title :
Rows Execution Plan
------- ---------------------------------------------------

Hemant K Chitale

Report message to a moderator

Re: Query Regarding Nested Loop [message #490912 is a reply to message #490888]

Fri, 28 January 2011 02:58

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello Michel and Hemant

Thanks for your replies

Your answers convince me for this plan but I am still not confident if I observed same bahaviour other times. May be I shall prepare test case with different data and table

Could you please comment on my question no. 2?

Quote:

Can we say the value 999 in this step always matches with the count of previous step ('TABLE ACCESS FULL T2' in this case) and that is the number of iterations of 'Nested Loop'?

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490917 is a reply to message #490911]

Fri, 28 January 2011 03:03

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Quote:

which is runtime statistics *NOT* an Execution Plan

I think you miss a point, "row source" IS the actual execution plan. It is the plan that Oracle used when it executed the statement, and this is what I call an execution plan.
If you think otherwise then explain what is "row source" and what is an "execution plan" for you.

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #490927 is a reply to message #490917]

Fri, 28 January 2011 03:27

hkchital
Messages: 128
Registered: September 2008
Location: Singapore

Senior Member

>"row source" IS the actual execution plan

OK. I see your point of view. Although I prefer to interpret Row Source Operation information as Execution *Statistics* not Plan.

The documentation here :
http://download.oracle.com/docs/cd/B19306_01/server.102/b14211/sqltrace.htm#i8894
is :
SQL Trace also provides row source information that includes:

Row operations showing the actual execution plan of each SQL statement

Number of rows, number of consistent reads, number of physical reads, number of physical writes, and time elapsed for each operation on a row

"actual execution plan" part of what is presented. The statistics are more important to me. I don't focus on "execution plan" but on "statistics".

In that manner, I prefer to say that "row source operation" is not "Execution Plan" but "Runtime Statistics".

But, Of course : You are right.

Hemant K Chitale

[Updated on: Fri, 28 January 2011 03:33]

Report message to a moderator

Re: Query Regarding Nested Loop [message #490954 is a reply to message #490912]

Fri, 28 January 2011 04:42

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

OraKaran wrote on Fri, 28 January 2011 09:58

Could you please comment on my question no. 2?

Quote:

Can we say the value 999 in this step always matches with the count of previous step ('TABLE ACCESS FULL T2' in this case) and that is the number of iterations of 'Nested Loop'?

No it is the number of rows returned not the number of executions of the step.

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #490962 is a reply to message #490954]

Fri, 28 January 2011 05:05

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Thanks Michel

You are Right

But for the innner table wont the "number of executions = number of rows returned by outer table"?

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #490979 is a reply to message #490962]

Fri, 28 January 2011 06:14

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Each execution may return several lines (not in your case as it seems to be the
primary key but we have not the statement you use to create and parametrize the tables).

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #491025 is a reply to message #490962]

Fri, 28 January 2011 08:47

hkchital
Messages: 128
Registered: September 2008
Location: Singapore

Senior Member

See my earlier answer to the question :

T2 drove 999 iteration lookup on T1. That doesn't necessarily always mean that T1 will return 999 rows. There may be a 1-to-1 correspondence, which we see in this case. However, it can be that for every T2 row, there are 10 rows in T1. Therefore, there would be 999 index lookups on T1 but 999x10 = 9990 rows fetched from T1. Conversely, some of the rows may fail to join in T1. There may be 999 calls to read the T1 index but, say, only 400 may have returned ROWIDs to retrieve rows from T1.

Hemant K Chitale

Report message to a moderator

Re: Query Regarding Nested Loop [message #492438 is a reply to message #490759]

Mon, 31 January 2011 04:19

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello Michel and Hemant

Thanks for your replies

I think my question was not clear

I would like to rephrase it

If T2 returns 999 rows upon FTS can we say that T1 will have 999 iterations only i.e. there will 999 iterations for the nested loop?

I am not concerned about how many rows of T1 will match with rows of T2. Just "how many times" T1 will be queries with T2 values.

It seems this is the case as per Hemant's reply

Quote:

T2 drove 999 iteration lookup on T1

Sorry for not being clear enough

Rows     Row Source Operation
-------  ---------------------------------------------------
    999  NESTED LOOPS
    999   TABLE ACCESS FULL T2
    999   TABLE ACCESS BY INDEX ROWID T1
    999    INDEX UNIQUE SCAN T1_PK (object id 4456163)

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #492442 is a reply to message #492438]

Mon, 31 January 2011 04:51

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Try with a query that does not join on a primary or unique key, then you will see the difference.

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #492763 is a reply to message #490759]

Wed, 02 February 2011 05:46

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello Michel

Thanks for your patience

As you were expecting I observe the difference when checked without Primary / Unique key

In this execution plan there were 1999 iterations

With the understanding that Row Source gives what actually happened, it does not fit in the following concept of 'Nested Loop'

cursor c1 is select
loop
cursor c2 is select
loop
 match and return output rows

Here our outer cursor (TABLE ACCESS FULL T22) has 999 rows so I was expecting there has to be 999 iterations (not 1999) if the 'row source' is showing what actually happened!

SQL> select constraint_name,constraint_type from user_constraints  where table_name='T1';

CONSTRAINT_NAME                C
------------------------------ -
T1_PK                          P

SQL> select constraint_name,constraint_type from user_constraints  where table_name='T2';

CONSTRAINT_NAME                C
------------------------------ -
SYS_C0059194                   C

SQL> create table t11 as select * from t1;

Table created.

SQL> create table t22 as select * from t2;

Table created.

SQL> select constraint_name,constraint_type from user_constraints  where table_name='T11';

no rows selected

SQL> select constraint_name,constraint_type from user_constraints  where table_name='T22';

CONSTRAINT_NAME                C
------------------------------ -
SYS_C0059202                   C


SQL> select count(1) from t1;

  COUNT(1)
----------
    563904

SQL> select count(1) from t11;

  COUNT(1)
----------
    563904

SQL> select count(1) from t2;

  COUNT(1)
----------
       999

SQL> select count(1) from t22;

  COUNT(1)
----------
       999

SQL>

SQL> exec dbms_stats.gather_table_stats(user,'T11',cascade=>true);

PL/SQL procedure successfully completed.

SQL> exec dbms_stats.gather_table_stats(user,'T22',cascade=>true);

PL/SQL procedure successfully completed.

Now I traced the session and tkprof'ed using

tkprof pgu1_ora_26859.trc pgu1_ora_26859.txt sys=no

Here is the traced file

select /*+ use_nl(t2) */ t1.object_name,t1.object_type,t1.owner,t2.created
from
 t1,t2 where t1.id=t2.id


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       68      0.00       0.00          0       3149          0         999
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       70      0.00       0.01          0       3149          0         999

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 5

Rows     Row Source Operation
-------  ---------------------------------------------------
    999  NESTED LOOPS
    999   TABLE ACCESS FULL T2
    999   TABLE ACCESS BY INDEX ROWID T1
    999    INDEX UNIQUE SCAN T1_PK (object id 4456163)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      68        0.00          0.00
  SQL*Net message from client                    68       27.80         28.00
********************************************************************************

select /*+ use_nl(t22) */ t11.object_name,t11.object_type,t11.owner,
  t22.created
from
 t11,t22 where t11.id=t22.id


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       68      0.01       0.01          0       2300          0         999
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       70      0.01       0.01          0       2300          0         999

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 5

Rows     Row Source Operation
-------  ---------------------------------------------------
    999  TABLE ACCESS BY INDEX ROWID T11
   1999   NESTED LOOPS
    999    TABLE ACCESS FULL T22
    999    INDEX RANGE SCAN T11_I (object id 4456204)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      68        0.00          0.00
  SQL*Net message from client                    68        1.91          2.19

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #492765 is a reply to message #492763]

Wed, 02 February 2011 06:00

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

When I say there is no primary/unique key I do not mean the database object, I mean in the data themselves, that is a row from a table matches with several rows in the other one. For instance, double the rows in t11 using "insert into t11 select * from t11;".

How does it come you have an "INDEX RANGE SCAN T11_I" with the script you gave when there is no index on this table?

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #492768 is a reply to message #492765]

Wed, 02 February 2011 06:11

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Sorry my mistake

I created indices and thats why used cascade in dbms_stats

Since I am connecting and disconnecting I forgot to copy the sqls for 'create index'

SQL> col TABLE_NAME form a20
SQL> col column_name form a20
SQL> col index_name form a10

SQL> select INDEX_NAME,TABLE_NAME,COLUMN_NAME,COLUMN_POSITION 
from user_ind_columns where table_name in('T11','T22');

INDEX_NAME TABLE_NAME           COLUMN_NAME          COLUMN_POSITION
---------- -------------------- -------------------- ---------------
T11_I      T11                  ID                                 1
T22_I      T22                  ID                                 1

BTW will try inserting duplicate rows and again tracing the session

Regards,
OraKaran

[Updated on: Wed, 02 February 2011 06:19] by Moderator

Report message to a moderator

Re: Query Regarding Nested Loop [message #492871 is a reply to message #490759]

Thu, 03 February 2011 05:19

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Michel

before my test to insert duplicate data and check the plan again

I would like to ask, what is the count "1999" here

Sorry to bother you on this but if we are saying "row source operation" is actually what happened then following plan indicates that
1) T22 was Full scanned
2) Index on T11 was range scanned
For every joining results of above, records of T11 were returned for matching rowid (or values) and that too 1999 times!

However there are only 999 matching values in T1 and T2

So does this 1999 is rows scanned or rows returned or rows expected to be scanned (in which case 'row source operation' is not actual)

Rows     Row Source Operation
-------  ---------------------------------------------------
    999  TABLE ACCESS BY INDEX ROWID T11
   1999   NESTED LOOPS
    999    TABLE ACCESS FULL T22
    999    INDEX RANGE SCAN T11_I (object id 4456204)

In fact Autotrace is like following which does not show this 1999


SQL> set autotrace traceonly explain
SQL> select /*+ use_nl(t22) */ t11.object_name,t11.object_type,t11.owner,
  t22.created
from
 t11,t22 where t11.id=t22.id
  2    3    4    5  ;

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=CHOOSE (Cost=2999 Card=999 Bytes=
          52947)

   1    0   TABLE ACCESS (BY INDEX ROWID) OF 'T11' (Cost=3 Card=1 Byte
          s=41)

   2    1     NESTED LOOPS (Cost=2999 Card=999 Bytes=52947)
   3    2       TABLE ACCESS (FULL) OF 'T22' (Cost=2 Card=999 Bytes=11
          988)

   4    2       INDEX (RANGE SCAN) OF 'T11_I' (NON-UNIQUE) (Cost=2 Car
          d=1)

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #492877 is a reply to message #492871]

Thu, 03 February 2011 06:13

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

If you duplicate the rows how can you have the same number of rows in the result?

Regards
Michel

Report message to a moderator

Re: Query Regarding Nested Loop [message #492880 is a reply to message #490759]

Thu, 03 February 2011 06:23

OraKaran
Messages: 183
Registered: March 2008
Location: United Kingdom

Senior Member

Hello Michel

I said
Quote:

before my test to insert duplicate data and check the plan again

I have not yet duplicated the rows

I was referring to pint that just changing the keys (in fact removing it) is showing count 1999 from 999 which is rows scanned or returned or estimated to be scanned!
And my question was if "row source operation" is shows us "what actually hapenned" then why we are seeing this count of 1999?

Regards,
OraKaran

Report message to a moderator

Re: Query Regarding Nested Loop [message #492881 is a reply to message #492880]

Thu, 03 February 2011 06:34

Michel Cadot
Messages: 68645
Registered: March 2007
Location: Nanterre, France, http://...

Senior Member
Account Moderator

Please do it with the duplicated rows.

And please post a complete test case I can reproduce.

Regards
Michel

[Updated on: Thu, 03 February 2011 06:35]

Report message to a moderator

Previous Topic:	No Snapshot Avaliable for AWR Report
Next Topic:	tunning

Goto Forum:

-=] Back to Top [=-

[ Syndicate this forum (XML) ] [

]

Current Time: Fri Apr 26 01:07:27 CDT 2024