Re: Strange wait for what should be a fast query

  • From: "Stefan Knecht" <knecht.stefan@xxxxxxxxx>
  • To: sacrophyte@xxxxxxxxx
  • Date: Tue, 19 Dec 2006 22:45:30 +0100

Note the quite large difference in the tim= fields between your fetch, and
the wait following it. The wait didn't occur waiting FOR the fetch, instead
simply waiting AFTER the fetch - for something else to do for example.

Stefan

On 12/19/06, Charles Schultz <sacrophyte@xxxxxxxxx> wrote:

We have an application that is consistently seeing this so-called "idle"
wait:

select user
from
 dual

call     count       cpu    elapsed       disk      query
current        rows
------- ------  -------- ---------- ---------- ---------- ----------
----------
Parse        4      0.02       0.01          0          0
0           0
Execute      4      0.00       0.00          0          0
0           0
Fetch        4      0.00       0.00          0          0
0           4
------- ------  -------- ---------- ---------- ---------- ----------
----------
total       12      0.02       0.01          0          0
0           4

Misses in library cache during parse: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 13992

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  FAST DUAL  (cr=0 pr=0 pw=0 time=13 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total
Waited
  ----------------------------------------   Waited  ----------
------------
  SQL*Net message to client                       4        0.00
0.00
  SQL*Net message from client                     4     1843.75
1851.55


I am very perplexed about this - what possible message is SQL*Net waiting
for from the client?

Here is the corresponding info from the raw trace file (from the 4th and
final fetch):

select user from dual
END OF STMT
PARSE #3:c=0,e=45,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=7923152389704
BINDS #3:
EXEC #3:c=0,e=115,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=2,tim=7923152389991
WAIT #3: nam='SQL*Net message to client' ela= 2 driver id=1413697536
#bytes=1 p3=0 obj#=58 tim=7923152390127
FETCH #3:c=0,e=42,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=2,tim=7923152390255
*** 2006-12-19 09:10:27.832
WAIT #3: nam='SQL*Net message from client' ela= 1843756325 driver
id=1413697536 #bytes=1 p3=0 obj#=58 tim=7926058417512



--
Charles Schultz

Other related posts: