Re: Reverse engineer SQL_TEXT from SQL_ID?

From: joel garry <joel-garry_at_home.com>
Date: Wed, 24 Feb 2010 13:34:54 -0800 (PST)
Message-ID: <6e6c0c13-78cc-47ab-9ec7-705bca92941d_at_u19g2000prh.googlegroups.com>



On Feb 24, 12:07 pm, Steve Howard <stevedhow..._at_gmail.com> wrote:
> On Feb 24, 2:50 pm, Steve Howard <stevedhow..._at_gmail.com> wrote:
>
>
>
> > On Feb 23, 9:25 am, Steve Howard <stevedhow..._at_gmail.com> wrote:
>
> > > 10.2.0.3 64 bit Standard on SLES 10 two node RAC
>
> > > Hi All,
>
> > > Does anyone know if it is possible to reverse engineer the SQL_TEXT
> > > for a given SQL_ID?  We had large waits yesterday afternoon on 'enq:
> > > HW contention'.  I found the SQL_ID in DBA_HIST_ACTIVE_SESS_HISTORY
> > > that was being executed when the event was posted.  I also found the
> > > current_obj# for the sessions in the same view, but I don't know why
> > > it would be waiting on this event.  However, there is no SQL recorded
> > > in DBA_HIST_SQLTEXT, which makes me wonder if it was DDL.  However,
> > > there is nothing in DBA_OBJECTS with a DDL time in the last 24 hours.
>
> > > I would really like to look at the SQL if possible.  Is there any way
> > > to do this?
>
> > > Thanks,
>
> > > Steve
>
> > The plot thickens.  I have a 10046 trace on the affected sessions, and
> > can see the event being posted.  There is no SQL in the trace file
> > (no, I couldn't properly scope it per Cary Milsap, although I may have
> > to to now).  I can get the object as that is posted as part of the
> > event.
>
> > However, even taking that into consideration, the tablespace id and
> > block noted do not exist??  Or maybe I have the wrong assumption that
> > block= means a database block??
>
> > 14:39:29 oracle_at_esbdb02pxdu /u02/admin/dledb/udump> grep -n HW *20691*
> > 585:WAIT #8: nam='enq: HW - contention' ela= 2 name|mode=1213661190
> > table space #=6 block=25167811 obj#=21948 tim=1237342826601801
> > 586:WAIT #8: nam='enq: HW - contention' ela= 196741 name|
> > mode=1213661190 table space #=6 block=25167811 obj#=21948
> > tim=1237342826798559
>
> > <<snip>>
>
> > 518507:WAIT #8: nam='enq: HW - contention' ela= 13377 name|
> > mode=1213661190 table space #=6 block=25167811 obj#=21898
> > tim=1237344106584665
> > 518509:WAIT #8: nam='enq: HW - contention' ela= 110350 name|
> > mode=1213661190 table space #=6 block=25167811 obj#=-1
> > tim=1237344106696135
> > 14:40:04 oracle_at_esbdb02pxdu /u02/admin/dledb/udump> grep -n HW *20691*
> > | awk '{print $12,$13}' | sort -n | uniq -c
> >       8
> >     138 #=6 block=25167811
> > 14:40:15 oracle_at_esbdb02pxdu /u02/admin/dledb/udump> sp
>
> > SQL*Plus: Release 10.2.0.3.0 - Production on Wed Feb 24 14:40:21 2010
>
> > Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.
>
> > SQL> select segment_name from dba_extents where file_id in (select
> > file# from v$datafile where ts# = 6) and 25167811 between block_id and
> > block_id + blocks;
>
> > no rows selected
>
> > SQL>
>
> > The tables noted as being the object= do have LOB's in them, so maybe
> > there could be some sorting internally?...yes, I know that's
> > reaching....
>
> > Thanks,
>
> > Steve
>
> This was useful for my base problem, and got me at least to where I
> can definitively state the problem is with the LOB.
>
> http://pauloferreiraportugal.blogspot.com/2009/10/lob-segments-and-en...
>
> However, I still can't figure out why I can't see the SQL.
>
> Thanks John and Joel,
>
> Steve

Between that and http://www.freelists.org/post/oracle-l/10046-trace-unaccounted-for-time,5 I would hypothesize you are seeing a defect in instrumentation, perhaps related to hot index blocks. And/or a bug where lob index blocks really ought to have added another extent but haven't gotten to it yet... see Jonathan's index explosion blog post for the type of thing I'm imagining. You're on not-the-latest-RAC, so exponentiate the possibilities :-O

That's the thing about looking under the hood with trace files - you see the sausage factory, through a glass darkly. I hope one of the Oakies can help illuminate this, very interesting.

Is there anything about recursive calls in your trace? Maybe what is happening is, you are doing something to the lob index, Oracle has to recursively handle that, so the SQL you are not seeing is that recursive sql.

jg

--
_at_home.com is bogus.
http://www.signonsandiego.com/news/2010/feb/24/cameras-change-focus-on-crime-watch/
Received on Wed Feb 24 2010 - 15:34:54 CST

Original text of this message