Question about the 'A-Time' in dbms_xplan.display_cursor's output

From: gengmao <gengmao_at_gmail.com>
Date: Mon, 23 Feb 2009 10:01:36 +0800
Message-ID: <afe23fd50902221801m351b7db8mc19be5b6e587e078_at_mail.gmail.com>

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

--
http://www.freelists.org/webpage/oracle-l

Received on Sun Feb 22 2009 - 20:01:36 CST