Re: Question about the 'A-Time' in dbms_xplan.display_cursor's output
- From: gengmao <gengmao@xxxxxxxxx>
- To: 조동욱 <ukja.dion@xxxxxxxxx>
- Date: Tue, 24 Feb 2009 11:03:21 +0800
The A-Time in display_cursor is same as the time in tkprof.
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows |
A-Time | Buffers | Reads |
------------------------------
-----------------------------------------------------------------------
|* 1 | COUNT STOPKEY | | 1 | | 9999
|00:00:00.24 | 791 | 127 |
| 2 | TABLE ACCESS FULL| LARGE_TABLE | 1 | 9999 | 9999
|00:00:00.22 | 791 | 127 |
Rows Row Source Operation
------- ---------------------------------------------------
9999 COUNT STOPKEY (cr=791 pr=127 pw=0 time=243582 us)
9999 TABLE ACCESS FULL LARGE_TABLE (cr=791 pr=127 pw=0 time=222295 us)
Can I think A-Time is the db time excluding any wait time?
Thanks,
Eric
On Mon, Feb 23, 2009 at 10:31 AM, 조동욱 <ukja.dion@xxxxxxxxx> wrote:
> My thought:
>
> Time in sql*plus = client-tier time which includes network delay time +
> database time
> Time in plan statistics = database-tier time
>
>
> One way to verify it is to compare the plan statistics and sql trace.
>
>
> ================================
> Dion Cho - Oracle Performance Storyteller
>
> http://dioncho.wordpress.com (english)
> http://ukja.tistory.com (korean)
> ================================
>
>
>
> On Mon, Feb 23, 2009 at 11:01 AM, gengmao <gengmao@xxxxxxxxx> wrote:
>
>> Hi,
>> I use /*+ gather_plan_statistics */ and dbms_xplan.display_cursor(null,
>> null, 'ALLSTATS LAST')) to show a query's plan statistics.
>>
>> There's a A-Time column in the output. Is it the actual time taken in an
>> operation? Does it equal to last_elapsed_time column in
>> v$sql_plan_statistics?
>>
>> I believe so, but I observed that for some long queries, A-Times are
>> little. It doesn't match the real wall clock time. For example,
>>
>> SQL> set timing on
>>
>> SQL> select /*+ gather_plan_statistics */ * from large_table where rownum
>> < 10000;
>> ....
>>
>> 9999 rows selected.
>>
>> Elapsed: *00:01:11.59*
>>
>> SQL> select * from table(dbms_xplan.display_cursor(null,null,'ALLSTATS
>> LAST'));
>>
>> PLAN_TABLE_OUTPUT
>>
>> --------------------------------------------------------------------------------
>>
>> SQL_ID 5gpp067wgrtsp, child number 0
>> -------------------------------------
>> select /*+ gather_statistics */ * from large_table where rownum <
>> :"SYS_B_0"
>>
>> Plan hash value: 9990311
>>
>> -----------------------------------------------------------------------------------------------------
>>
>> | Id | Operation | Name | Starts |
>> E-Rows | A-Rows | A-Time | Buffers | Reads |
>>
>> PLAN_TABLE_OUTPUT
>>
>> -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> |* 1 | COUNT STOPKEY | | 1 |
>> | 9999 |*00:00:00.21* | 791 | 127 |
>>
>> | 2 | TABLE ACCESS FULL| LARGE_TABLE | 1 | 11170 | 9999
>> |*00:00:00.19* | 791 | 127 |
>>
>>
>> Predicate Information (identified by operation id):
>> ---------------------------------------------------
>>
>> 1 - filter(ROWNUM<:SYS_B_0)
>>
>> Note
>> -----
>> - dynamic sampling used for this statement
>>
>>
>> 22 rows selected.
>>
>> Elapsed: 00:00:00.46
>>
>>
>> I am wondering why the A-Time does not match the wall clock time? Is there
>> any way to get the actual time taken in each step of an execution plan?
>>
>>
>> The database is 10.2.0.4.
>>
>> Thanks,
>> Eric Geng
>>
>>
>
Other related posts:
