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

From: Alex Gorbachev <ag_at_oracloid.com>
Date: Tue, 29 Apr 2008 17:35:31 -0400
Message-Id: <6586EAE8-02D2-4FDA-8845-D8BAE6042F06@oracloid.com>


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.
>

--
http://www.freelists.org/webpage/oracle-l
Received on Tue Apr 29 2008 - 16:35:31 CDT

Original text of this message