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

Well, it's soft parse probably so shouldn't produce any trace on 10053 event. Not sure if it will produce anything even if ti's hard parsed first time but that's an idea to try at least. 

On 29-Apr-08, at 2:39 PM, Allen, Brandon wrote:


Hi List,
Does anyone know how to get a 10053 (aka _optimizer_trace) on a recursive query? I'd never noticed this before, but it seems that this event only traces user queries. The problem I'm working on is that when I run dbms_session.set_role, Oracle executes the below recursive query once for every role passed to the set_role procedure, and the application I'm working with is passing 119 roles, so this query gets executed 119 times, which takes about 2.4 seconds as you can see below. That might not sound too bad, but the problem is that this is an Oracle Forms application and for each new form the user opens, it opens a new session in the database and each time it does that, it calls the set_role procedure again, so this query is causing a 2.4 second delay for each form the user opens. In their current (8i) production system, the exact same query is called but runs much more efficiently (also shown below) so the delay isn't noticeable. It's only in their new 10g system that this problem is occurring. 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? 

Thanks,
Brandon

Slow query in 10g:
********************************************************************************

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 119 0.01 0.00 0 0 0 0 Execute 119 0.01 0.01 0 0 0 0 Fetch 119 2.36 2.34 0 56049 0 119 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 357 2.38 2.36 0 56049 0 119 

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=20423 us)
      1   FILTER  (cr=471 pr=0 pw=0 time=20301 us)
    367    CONNECT BY WITH FILTERING (cr=471 pr=0 pw=0 time=19785 us)
9 TABLE ACCESS BY INDEX ROWID SYSAUTH$ (cr=6 pr=0 pw=0 time=366 us) 
      9      INLIST ITERATOR  (cr=4 pr=0 pw=0 time=276 us)
9 INDEX RANGE SCAN I_SYSAUTH1 (cr=4 pr=0 pw=0 time=184 us)(object id 105) 
    358     NESTED LOOPS  (cr=465 pr=0 pw=0 time=12014 us)
    327      BUFFER SORT (cr=0 pr=0 pw=0 time=1903 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=8220 us) 358 INDEX RANGE SCAN I_SYSAUTH1 (cr=333 pr=0 pw=0 time=5127 us)(object id 105) 
      0     TABLE ACCESS FULL SYSAUTH$ (cr=0 pr=0 pw=0 time=0 us)

********************************************************************************

Same query much faster in 8i:
********************************************************************************
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 45 0.00 0.00 0 0 0 0 Execute 45 0.01 0.01 0 0 0 0 Fetch 45 0.03 0.00 0 2565 0 45 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 135 0.04 0.01 0 2565 0 45 

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS   (recursive depth: 2)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT GROUP BY
      1   FILTER
     23    CONNECT BY
     16     CONCATENATION
      2      INDEX RANGE SCAN (object id 102)
     15      INDEX RANGE SCAN (object id 102)
     15     TABLE ACCESS BY USER ROWID SYSAUTH$
     29     TABLE ACCESS BY INDEX ROWID SYSAUTH$
     29      INDEX RANGE SCAN (object id 102)
********************************************************************************
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.

Other related posts: