TKPROF for PQ
Date: Wed, 6 Feb 2008 18:25:39 -0800 (PST)
Message-ID: <fd523d0c-b903-4343-856a-3f5ab864dd42@i7g2000prf.googlegroups.com>
Hello,
Please review the following TKPROF output and tell me where the time for 480804 physical read is accounted for in the wait. The largest wait is "PX Deq: Execute Reply" for 64 seconds out of 66 seconds of elapsed time.. This leads me to guess that time may be consumed by Parallel slaves... Is that correct? If so where I/Os incurred by slaves are recorded? I just got one trace file for the entire session. So I guess everything may be recorded in the same trace file..
CREATE TABLE TEST NOLOGGING PARALLEL(DEGREE 5) AS
SELECT DISTINCT CM_DRIVER.TRGT_KEY FROM
((CM_DRIVER INNER JOIN CM_PREMISE ON
(CM_DRIVER.PRMS_KEY = CM_PREMISE.PRMS_KEY AND
CM_DRIVER.ORG_KEY = CM_PREMISE.ORG_KEY)) INNER JOIN CM_SERVICEABILITY ON (CM_PREMISE.PRMS_KEY = CM_SERVICEABILITY.PRMS_KEY AND CM_PREMISE.ORG_KEY = CM_SERVICEABILITY.ORG_KEY)) WHERE
(CM_SERVICEABILITY.ORG_PART_KEY > 0)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.05 0.04 0 0 0 0 Execute 1 0.26 65.96 480804 327870 42080 27120374 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------
total 2 0.31 66.00 480804 327870 42080 27120374
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 108
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
- Waited ----------
library cache lock 1 0.00 0.00 library cache pin 1 0.00 0.00 rdbms ipc reply 4 0.00 0.00 row cache lock 16 0.00 0.00 gc current block 3-way 175 0.00 0.12 gc cr multi block request 21 0.00 0.00 db file sequential read 71 0.07 0.46 gc cr grant 2-way 70 0.00 0.01 gc current block 2-way 150 0.00 0.07 db file scattered read 15 0.01 0.09 db file parallel read 1 0.01 0.01 enq: KO - fast object checkpoint 3 0.00 0.00 KJC: Wait for msg sends to complete 1 0.00 0.00 reliable message 3 0.00 0.00 enq: IR - contention 5 0.00 0.00 enq: PS - contention 16 0.00 0.00 PX Deq: reap credit 982 0.00 0.01 PX Deq: Join ACK 12 0.00 0.01 PX Deq: Parse Reply 12 0.10 0.10 name-service call wait 1 0.08 0.08 PX Deq: Execute Reply 596 3.59 64.57 enq: TS - contention 5 0.00 0.00 enq: TT - contention 1 0.00 0.00 gc current grant busy 288 0.00 0.14 DFS lock handle 18 0.00 0.01 gc current grant 2-way 2 0.00 0.00 log file sync 1 0.00 0.00 PX Deq: Signal ACK 6 0.00 0.00 SQL*Net message to client 1 0.00 0.00 SQL*Net message from client 1 0.00 0.00