Re: Unaccounted for time in 10046 trace file

  • From: Cary Millsap <cary.millsap@xxxxxxxxxxxx>
  • To: "Amir.Hameed@xxxxxxxxx" <Amir.Hameed@xxxxxxxxx>
  • Date: Fri, 13 Sep 2013 21:47:11 -0500

Amir,

To convince me that there actually is unaccounted-for time in your case, I'd 
need to see the raw trace file. I would certainly have to see the trace data to 
make any educated guess about what's causing it, if it does exist.

Cary Millsap
Method R Corporation


On Sep 13, 2013, at 2:48 PM, "Hameed, Amir" <Amir.Hameed@xxxxxxxxx> wrote:

> Hi,
> I ran a simple SELECT statement where I drove a FTS on a large table and then 
> trace it at level 8. Below is the SQL statement:
> select /*+ full(MMT) */ count(*) from  apps.mtl_material_transactions MMT ;
> Here is the output from TKPROF:
> 
> call     count       cpu    elapsed       disk      query    current        
> rows
> ------- ------  -------- ---------- ---------- ---------- ----------  
> ----------
> Parse        1      0.01       0.00          0          0          0          
>  0
> Execute      1      0.00       0.00          0          0          0          
>  0
> Fetch        2    174.21     841.44    7852466    7853454          0          
>  1
> ------- ------  -------- ---------- ---------- ---------- ----------  
> ----------
> total        4    174.22     841.44    7852466    7853454          0          
>  1
> 
> Elapsed times include waiting on following events:
>  Event waited on                             Times   Max. Wait  Total Waited
>  ----------------------------------------   Waited  ----------  ------------
>  library cache lock                              1        0.00          0.00
>  library cache pin                               1        0.00          0.00
>  SQL*Net message to client                       2        0.00          0.00
>  Disk file operations I/O                      123        0.00          0.00
>  gc current block 3-way                          1        0.00          0.00
>  enq: KO - fast object checkpoint                3        0.01          0.01
>  reliable message                                1        0.00          0.00
>  direct path read                             1919        4.48        356.76
>  gc cr block 2-way                              31        0.00          0.01
>  db file sequential read                       201        0.03          0.63
>  gc cr disk read                                 1        0.00          0.00
>  SQL*Net message from client                     2        0.00          0.00
> ********************************************************************************
> 
> I am not able to reconcile the elapsed time and the discrepancy is just too 
> much:
> elapsed - cpu = 667.22
> Total Waited = 357.4
> Unaccounted for time = 667.22 - 357.4 = 309.82
> 
> I know that Cary Milsap has talked about unaccounted for time in TKPROF 
> output but this gap is just too much. Any idea where to look for the missing 
> time?
> 
> Thanks,
> Amir
> 
> --
> //www.freelists.org/webpage/oracle-l
> 
> 
--
//www.freelists.org/webpage/oracle-l


Other related posts: