RE: How to get a 10053 trace on a recursive query

  • From: "Allen, Brandon" <Brandon.Allen@xxxxxxxxxxx>
  • To: "Gints Plivna" <gints.plivna@xxxxxxxxx>, "oracle-l" <oracle-l@xxxxxxxxxxxxx>
  • Date: Tue, 29 Apr 2008 15:29:39 -0700

Thanks, good idea, but I forgot to mention that I've already done that.
However, when I run the exact same query in the same database, but I run
it directly via SQL*Plus rather than having it run as a recursive query,
the CBO comes up with a much better plan that only requires 11 gets per
row, vs 471 gets/row for the plan it's using on the recursive query as
you can see below.  I don't know why it would come up with a different
plan for the recursive query than the user query - that's why I was
trying to get the 10053 trace on the recursive execution to see if it
would provide some clues.  One thing I just noticed though in reviewing
my tkprof output below is that the optimizer_mode appears to switch from
ALL_ROWS to CHOOSE for the recursive queries.  I've never noticed that
before, but maybe it's always done that?
 
Thanks,
Brandon
 
Non-recursive query:
************************************************************************
********
 
select max(nvl(option$,0))
from
 sys.sysauth$ where privilege#=:v1 connect by grantee#=prior privilege#
and
  privilege#>0 start with (grantee#=:v2 or grantee#=1) and privilege#>0
group
  by privilege#
 
call     count       cpu    elapsed       disk      query    current
rows
------- ------  -------- ---------- ---------- ---------- ----------
----------
Parse        1      0.01       0.00          0          0          0
0
Execute      1      0.01       0.01          0          0          0
0
Fetch        2      0.01       0.01          0         11          0
1
------- ------  -------- ---------- ---------- ---------- ----------
----------
total        4      0.03       0.02          0         11          0
1
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 31  
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT GROUP BY (cr=11 pr=0 pw=0 time=12521 us)
      1   FILTER  (cr=11 pr=0 pw=0 time=12324 us)
    367    CONNECT BY WITHOUT FILTERING (cr=11 pr=0 pw=0 time=11876 us)
      9     INLIST ITERATOR  (cr=6 pr=0 pw=0 time=424 us)
      9      TABLE ACCESS BY INDEX ROWID SYSAUTH$ (cr=6 pr=0 pw=0
time=317 us)
      9       INDEX RANGE SCAN I_SYSAUTH1 (cr=4 pr=0 pw=0 time=209
us)(object id 105)
    896     TABLE ACCESS FULL SYSAUTH$ (cr=5 pr=0 pw=0 time=1074 us)
 

Recursive version of same query, from same exact session (from exec
dbms_session.set_role):
************************************************************************
********

select max(nvl(option$,0)) 
from
 sysauth$ where privilege#=:1 connect by grantee#=prior privilege# and 
  privilege#>0 start with (grantee#=:2 or grantee#=1) and privilege#>0
group 
  by privilege#
 

call     count       cpu    elapsed       disk      query    current
rows
------- ------  -------- ---------- ---------- ---------- ----------
----------
Parse        1      0.01       0.00          0          0          0
0
Execute      1      0.00       0.00          0          0          0
0
Fetch        1      0.02       0.02          0        471          0
1
------- ------  -------- ---------- ---------- ---------- ----------
----------
total        3      0.03       0.02          0        471          0
1
 
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 2)
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT GROUP BY (cr=471 pr=0 pw=0 time=22308 us)
      1   FILTER  (cr=471 pr=0 pw=0 time=22191 us)
    367    CONNECT BY WITH FILTERING (cr=471 pr=0 pw=0 time=21482 us)
      9     TABLE ACCESS BY INDEX ROWID SYSAUTH$ (cr=6 pr=0 pw=0
time=365 us)
      9      INLIST ITERATOR  (cr=4 pr=0 pw=0 time=273 us)
      9       INDEX RANGE SCAN I_SYSAUTH1 (cr=4 pr=0 pw=0 time=193
us)(object id 105)
    358     NESTED LOOPS  (cr=465 pr=0 pw=0 time=12756 us)
    327      BUFFER SORT (cr=0 pr=0 pw=0 time=1896 us)
    327       CONNECT BY PUMP  (cr=0 pr=0 pw=0 time=373 us)
    358      TABLE ACCESS BY INDEX ROWID SYSAUTH$ (cr=465 pr=0 pw=0
time=9236 us)
    358       INDEX RANGE SCAN I_SYSAUTH1 (cr=333 pr=0 pw=0 time=5687
us)(object id 105)
      0     TABLE ACCESS FULL SYSAUTH$ (cr=0 pr=0 pw=0 time=0 us) 

-----Original Message-----
From: Gints Plivna [mailto:gints.plivna@xxxxxxxxx] 
Sent: Tuesday, April 29, 2008 2:35 PM
To: Allen, Brandon
Cc: oracle-l
Subject: Re: How to get a 10053 trace on a recursive query

2008/4/29 Allen, Brandon <Brandon.Allen@xxxxxxxxxxx>:
> So, back to my main
> point - I'm trying to get a 10053 trace on this recursive query to see

> what I can do about it, but can't seem to get one.  Any ideas?

How about executing this query as user sys? I've got a 10053 trace file
for that statement, however too lazy and too late to look in what and
why :)

Gints Plivna
http://www.gplivna.eu

Privileged/Confidential Information may be contained in this message or 
attachments hereto. Please advise immediately if you or your employer do not 
consent to Internet email for messages of this kind. Opinions, conclusions and 
other information in this message that do not relate to the official business 
of this company shall be understood as neither given nor endorsed by it.

--
//www.freelists.org/webpage/oracle-l


Other related posts: