Home » RDBMS Server » Performance Tuning » Elapsed Time in Trace file output (2 Merged) (Oracle 11g R2 on Windows 7)
Elapsed Time in Trace file output (2 Merged) [message #531600] Wed, 16 November 2011 23:52 Go to next message
orapratap
Messages: 134
Registered: November 2011
Location: Canada
Senior Member
Hi

I executed a query which executed quickly (1.7 seconds) but since its output took time in displaying on the console the time shown by 'set timing on was 39.5 seconds

also I took trace (tkprof) for the same - see below

My query is why the timings under 'Total Waited' (43.19 and 1.69) are not added to the elapsed time 1.83 seconds

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.06          0         10        	  0           0
Fetch      758      0.03       1.77          0          0          0       11345
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      760      0.03       1.83          0         10          0       11345

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 5  

Rows     Row Source Operation
-------  ---------------------------------------------------
  11345  PX COORDINATOR  (cr=10 pr=0 pw=0 time=29262 us)
      0   PX SEND QC (RANDOM) :TQ10001 (cr=0 pr=0 pw=0 time=0 us cost=1622 size=406504 card=8296)
      0    HASH JOIN  (cr=0 pr=0 pw=0 time=0 us cost=1622 size=406504 card=8296)
      0     PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us cost=810 size=157624 card=8296)
      0      PX SEND BROADCAST :TQ10000 (cr=0 pr=0 pw=0 time=0 us cost=810 size=157624 card=8296)
      0       PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us cost=810 size=157624 card=8296)
      0        TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us cost=810 size=157624 card=8296)
      0     PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us cost=811 size=535080 card=17836)
      0      TABLE ACCESS FULL T1 (cr=0 pr=0 pw=0 time=0 us cost=811 size=535080 card=17836)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  os thread startup                               4        0.01          0.04
  PX Deq: Join ACK                                2        0.00          0.00
  PX Deq: Parse Reply                             4        0.01          0.01
  SQL*Net message to client                     758        0.00          0.00
  PX Deq: Execute Reply                          61        0.09          1.69
  SQL*Net message from client                   758        8.47         43.29
  PX Deq: Table Q Normal                          2        0.00          0.00
  PX Deq: Signal ACK RSG                          1        0.00          0.00
  PX Deq: Signal ACK EXT                          8        0.00          0.00
  PX Deq: Slave Session Stats                     2        0.00          0.00
********************************************************************************



Thanks in Advance
Pratap
Re: Elapsed Time in Trace file output (2 Merged) [message #532544 is a reply to message #531600] Wed, 23 November 2011 05:29 Go to previous message
dee_bee_eh
Messages: 6
Registered: November 2011
Junior Member
the parse, execute, fetch is how long it took the server to do its bits, the SQLnet time is the time it took your client to get the data out from the server and give it to your client. investigate the network. what happens when you do any select at all? how long does it take your SQL client to connect? tracert the hops to host of the server.
Previous Topic: Temp Tablespace running out of space (68 GB)
Next Topic: MVIEW huge temp space
Goto Forum:
  


Current Time: Thu Apr 25 01:52:27 CDT 2024