Re: Query hangs suddenly

  • From: "Ram Raman" <veeeraman@xxxxxxxxx>
  • To: daniel.fink@xxxxxxxxxxxxxx
  • Date: Thu, 1 Mar 2007 18:35:34 -0600

I tried running the 10046 on the good results and the hanging query. The
trace file generated for the hanging query gets written to in the first
minute of kicking off the query. After that it does not get updated at all,
even after 1.5 hrs. I killed the query.

Here is the last few lines from the trace file:

WAIT #3: nam='db file sequential read' ela= 325 p1=71 p2=42927 p3=1
WAIT #3: nam='db file scattered read' ela= 744 p1=71 p2=42929 p3=4
WAIT #3: nam='db file scattered read' ela= 733 p1=71 p2=42933 p3=6
WAIT #3: nam='db file sequential read' ela= 22 p1=71 p2=42940 p3=1
WAIT #3: nam='db file sequential read' ela= 323 p1=71 p2=42942 p3=1
WAIT #3: nam='db file sequential read' ela= 317 p1=71 p2=42944 p3=1
WAIT #3: nam='db file scattered read' ela= 79393 p1=71 p2=42946 p3=2
WAIT #3: nam='db file sequential read' ela= 2118 p1=71 p2=42948 p3=1
WAIT #3: nam='db file scattered read' ela= 41 p1=71 p2=42950 p3=2
WAIT #3: nam='db file scattered read' ela= 6953 p1=71 p2=42953 p3=10
WAIT #3: nam='db file scattered read' ela= 5416 p1=71 p2=42978 p3=15
WAIT #3: nam='db file scattered read' ela= 2531 p1=71 p2=42993 p3=15
WAIT #3: nam='db file scattered read' ela= 19086 p1=71 p2=43008 p3=15
WAIT #3: nam='db file scattered read' ela= 17044 p1=71 p2=43023 p3=15
WAIT #3: nam='db file scattered read' ela= 11060 p1=71 p2=43038 p3=15
WAIT #3: nam='db file sequential read' ela= 32 p1=71 p2=43054 p3=1
WAIT #3: nam='db file scattered read' ela= 825 p1=71 p2=43056 p3=12
WAIT #3: nam='db file scattered read' ela= 66 p1=71 p2=43068 p3=2 <<<--- It
was hanging here for 1.5 hrs, I killed the query at this point
*** 2007-03-01 18:28:08.774
FETCH
#3:c=3460150000,e=3485042478,p=2211,cr=4712259,cu=0,mis=0,r=0,dep=0,og=4,ti
m=1706202437810
WAIT #3: nam='SQL*Net break/reset to client' ela= 335 p1=1650815232 p2=0
p3=0
WAIT #3: nam='SQL*Net message to client' ela= 4 p1=1650815232 p2=1 p3=0




On 2/28/07, Daniel W. Fink <daniel.fink@xxxxxxxxxxxxxx> wrote:

Ram,

Run 10046 traces on good and bad sessions. While running, extract the
actual execution plan as it may be different than what autotrace is saying.

Simply put, the session can be doing one of 4 things
1) Performing CPU activity
2) Waiting on available CPU cycles
3) Waiting on the completion of Oracle instrumented wait/timed event
4) Waiting on the completion of Oracle uninstrumented wait/timed event

The information in v$session_wait indicates that it is not in #3 (WAITED
KNOWN TIME says that the event completed). Increasing CPU time and logical
i/o (there is not necessarily a direct correlation) indicates that there is
likely a large amount of logical i/o (memory reads) going on. Unfortunately,
there is not an Oracle supported facility to always diagnose what is
happening. However...

*** DO NOT DO THIS ON A PRODUCTION SYSTEM ***
There are a couple of events that you can set that will dump logical i/o
related information into a trace file. You can find a paper and some
examples at http://www.optimaldba.com/papers/TracingLogicalIOs.zip
*** DO NOT DO THIS ON A PRODUCTION SYSTEM ***

--
Daniel Fink

Oracle Performance, Diagnosis and Training

OptimalDBA    http://www.optimaldba.com
Oracle Blog   http://optimaldba.blogspot.com

Join me at Miracle Scotland DB 
Forum!http://www.miracleltd.com/index.asp?page=167&page2=343



Ram Raman wrote:

Thanks.

If it has not waited for anything since then should it not be producing
the results. What is it doing then? Sorry I dont get it.


On 2/28/07, Wolfgang Breitling <breitliw@xxxxxxxxxxxxx> wrote:
>
> At 12:13 PM 2/28/2007, Ram Raman wrote:
> >Hi all,
> >
> >We have a query which is run everyday and was running OK till last
> >week. The query starts hanging for the past 2 days when run. Oracle
> >is 9.2.  We run this query for today's date ("audit_stamp" - See the
> >comment on the query) or yesterday's date and it returns data
> >quickly. But when the audit_stamp is older than the past 2 days, it
> >hangs. The cost from the plan in all the cases is the almost the
> >same using autotrace traceonly.
> >
> >Here is select from V$session_wait for the session:
> >
> >        SID EVENT
> >----------
> ----------------------------------------------------------------
> >P1TEXT
> P1
> >----------------------------------------------------------------
> ----------
> >P2TEXT
> P2
> >----------------------------------------------------------------
> ----------
> >P3TEXT
> >P3  WAIT_TIME
> >----------------------------------------------------------------
> >---------- ----------
> >SECONDS_IN_WAIT STATE
> >--------------- -------------------
> >         51 SQL*Net message to client
> >driver
> id                                                        1413697536
>
> >#bytes                                                                    1
> >
> >0         -1
> >             543 WAITED KNOWN TIME
> >
> >I do not understand why it waits for "SQL*Net message to client".
> >Thanks.
>
> It is not waiting. The status is "waited known time". The last known
> wait event was "SQL*Net message to client" and it hasn't waited for
> anything (instrumented) since.
>
> >
>
> Regards
>
> Wolfgang Breitling
> Centrex Consulting Corporation
> www.centrexcc.com
>
>
>


Other related posts: