Sunday, December 9, 2012

Hash Join Buffered


Introduction


A few years ago Jonathan Lewis published a blog post that described one of the interesting side effects of Oracle's Parallel Execution implementation: Sometimes operations that usually are non-blocking will be turned into blocking ones. Mostly these are represented by additional BUFFER SORT operation that show up in the parallel version of an execution plan from 10g on (pre-10g does the same internally but doesn't show in the execution plan), but there is a special case which is the HASH JOIN BUFFERED operation that gets used with the HASH data distribution of the join row sources.

Jonathan came to the conclusion that the HASH JOIN BUFFERED turns into a blocking operation by buffering the result set of the join by looking at different trace files (the 10104 hash join trace file and 10046 extended trace) and the fact that when the join produced no result (no matches between the two row sources) the obvious spill to disk didn't happen anymore.

He showed this using an example that simply joined two tables using Parallel Execution returning the result of the join to the client. Another interesting point of this example is that the BUFFERed operation takes place although it is not entirely obvious why if you follow the explanation that "at most two Parallel Slave Sets can be active per Data Flow Operation" and hence sometimes both sets are busy and a third set would be required to receive the data produced by the other two. This is however not the case with this simple example, as the data produced by the two sets simply needs to be returned to the client by sending it to the Query Coordinator.

While I prepared my "Parallel Execution" seminar I wanted to demonstrate this via a simple test case where two rather small tables are joined but result in a quite large result set. Since the HASH JOIN BUFFERED is supposed to buffer this large result set before returning it to the client this should make this special behaviour quite obvious.


Test Case Results


However the test case showed some interesting results that seemed to suggest that Jonathan's conclusions weren't entirely correct:

1. Although the 10104 hash join trace file reads "BUFFER(Compile) output of the join for Parallel Query" and "BUFFER(Execution) output of the join for PQ" it looks like the HASH JOIN BUFFERED operation in fact does buffer the second row source rather than the result of the join operation. I'll demonstrate below why I believe this is so

2. Although I could reproduce Jonathan's test case, in particular that no spill to disk takes place when the two row sources do not match, I believe that the point of the HASH JOIN BUFFERED is that it can take advantage of the fact that the hash table for the first row source is already built when the second row source is accessed. So in principle it looks like the operation only buffers data from the second row source that has a match in the hash table. Data that doesn't match isn't buffered - that's the special functionality of the HASH JOIN BUFFERED that makes it different from separate BUFFER SORT operations that buffer unconditionally and allows to explain why no obvious buffering takes place if the two row sources don't match.

3. When looking into the 10104 HASH JOIN trace file it becomes obvious that the spilling to disk of the odd 9th partition as described in Jonathan's post takes place before the actual probe phase seems to begin (kxhfSetPhase: phase=PROBE_2), which again I believe suggests that it cannot be the result set that gets buffered, since this will only be produced as soon as the probe phase begins

4. The implementation restriction of Oracle's Parallel Execution that requires these additional, artificial blocking operations does not seem to be "at most two Parallel Slave Sets can be active at the same time", but more precisely it seems to be

"At most one data distribution can be active at the same time"

This includes the final data distribution to the Query Coordinator process in case of queries and explains why the simple case of a two table join using HASH distribution results in a BUFFERED operation: The PX SEND HASH operation for the second row source would have to be active at the same time as the PX SEND QC operation returning data to the Query Coordinator as the HASH JOIN by default is only blocking when consuming the first row source to build the hash table but it isn't blocking when processing the second row source probing the hash table.

Since it doesn't seem to be supported to have two PX SEND operations active at the same time, some artificial blocking operation needs to be introduced, in this case the HASH JOIN BUFFERED, that first consumes the second row source completely before starting the actual probe phase. By doing so, the PX SEND operation used to distribute the second row source to the Parallel Slaves performing the hash join is no longer active when the actual probe phase starts and therefore the result set can be produced and sent to the Query Coordinator using the then only active PX SEND QC operation.

The following formatted execution plan highlights the two PX SEND operations that would have to be active at the same time if there wasn't a blocking operation in between:

-------------------------------------------------------------------------------------
| Id  | Operation                  | Name     | Starts |    TQ  |IN-OUT| PQ Distrib |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |          |      1 |        |      |            |
|   1 |  COUNT                     |          |      1 |        |      |            |
|*  2 |   FILTER                   |          |      1 |        |      |            |
|   3 |    PX COORDINATOR          |          |      1 |        |      |            |
|   4 |     PX SEND QC (RANDOM)    | :TQ10002 |      0 |  Q1,02 | P->S | QC (RAND)  | <---------
|   5 |      VIEW                  |          |      2 |  Q1,02 | PCWP |            |
|*  6 |       HASH JOIN BUFFERED   |          |      2 |  Q1,02 | PCWP |            | <--------- Artificial blocking
|   7 |        PX RECEIVE          |          |      2 |  Q1,02 | PCWP |            |
|   8 |         PX SEND HASH       | :TQ10000 |      0 |  Q1,00 | P->P | HASH       |
|   9 |          PX BLOCK ITERATOR |          |      2 |  Q1,00 | PCWC |            |
|* 10 |           TABLE ACCESS FULL| T2       |     26 |  Q1,00 | PCWP |            |
|  11 |        PX RECEIVE          |          |      2 |  Q1,02 | PCWP |            |
|  12 |         PX SEND HASH       | :TQ10001 |      0 |  Q1,01 | P->P | HASH       | <---------
|  13 |          PX BLOCK ITERATOR |          |      2 |  Q1,01 | PCWC |            |
|* 14 |           TABLE ACCESS FULL| T4       |     26 |  Q1,01 | PCWP |            |
-------------------------------------------------------------------------------------


Test Case Details


Here are the preparation steps for the simple test case I used:

create table t2
compress
as
select
        rownum as id
      , mod(rownum, 1000) + 1 as fk
      , rpad('x', 100) as filler
from
        dual
connect by
        level <= 1000000
;

exec dbms_stats.gather_table_stats(null, 't2')

-- Create a copy of T2
create table t4
compress as
select * from t2;

-- Add rows to T4 that don't match T2
-- This shows that the BUFFERED operation discards those non-matching rows
-- rather than buffering them when using T4 as second row source
insert /*+ append */
into t4
select
        1000000 + rownum as id
      , 1000 + mod(rownum, 1000) + 1 as fk
      , rpad('x', 100) as filler
from
        dual
connect by
        level <= 1000000
;

commit;

exec dbms_stats.gather_table_stats(null, 't4')

alter table t2 parallel 2;

alter table t4 parallel 2;
And this is basically the simple script that gets executed:
set echo on timing on time on

alter session set workarea_size_policy = manual;

alter session set hash_area_size = 80000000;
alter session set sort_area_size = 80000000;

alter session set statistics_level = all;

alter session set tracefile_identifier = 'HJ_trace1';

alter session set events '10104 trace name context forever, level 10';

--explain plan for
--select max(a_filler), max(b_filler) from (
select /* HJ_trace1 */ * from (
select  /*+ no_merge use_hash(a b) no_cpu_costing leading(a b) pq_distribute(b, hash, hash) */
        a.filler as a_filler, b.filler as b_filler
from
        t2 a
      , t4 b
where
--        a.id = b.id
        a.fk = b.fk
)
where rownum > 1
;

alter session set events '10104 trace name context off';

set linesize 200 pagesize 0

select * from table(dbms_xplan.display_cursor(null, null, 'ALLSTATS ALL ADVANCED'));

I've used manual workarea sizing to make the test repeatable.
Note that I've added a comment to the query that should make the query text unique in order to generate a new parent cursor for each test run (so you would need to modify this comment for each test run). The only reason for this is the limitation of DBMS_XPLAN.DISPLAY_CURSOR with Parallel Execution as outlined in one of my previous posts, otherwise the "ALLSTATS ALL" option of DISPLAY_CURSOR would aggregate the statistics over all executions rather than only the last parallel execution.

Because I also tested some other costing related issues I disabled CPU costing for this test, however the results should be exactly the same when enabling CPU costing.

So there are basically two sets of data: T2 is 1,000K rows and approx. 100MB in size, and T4 is twice the size and rows, however only 100MB out of the 200MB represent data that matches T2 on either ID or FK.

The result set is approx. 200 bytes per row, so for example 200MB if 1,000K rows are produced.

The tables are compressed using BASIC compression, which results in this case in a very good compression ratio as the FILLER column is 100 bytes in size but only has one distinct value and therefore can benefit a lot from the symbol replacement performed by BASIC compression.

The point of this compression is that it makes in this particular case very obvious that while you can benefit a lot from compression at storage, I/O level and Buffer Cache in general, at SQL execution time Oracle has to process uncompressed row sources (and not compressed blocks), so all the workareas that have to be used for hash tables, sorts or simple buffering won't benefit from the compression but have to be big enough for the uncompressed row source data. Likewise any data that gets distributed using PX SEND also represents uncompressed data volume.

There are two important variations possible to this test case query:

1. Instead of joining on ID which produces 1,000K rows join the two tables on the FK column which results in a huge result set of 1,000M rows (each row matches 1,000 rows from the other row source)

2. Use this variation of the query that doesn't require an artificial blocking due to the fact that a true blocking operation gets used:

select max(a_filler), max(b_filler) from (
select  /*+ no_merge use_hash(a b) no_cpu_costing leading(a b) pq_distribute(b, hash, hash) */
        a.filler as a_filler, b.filler as b_filler
from
        t2 a
      , t4 b
where
--        a.id = b.id
        a.fk = b.fk
)
;

This way the impact of the BUFFERED operation can be easily separated from other potential activity like a too small workarea for an optimal hash join. If the operation completes without TEMP I/O activity when using a true blocking operation but spills to TEMP when running in BUFFERED mode then the I/O activity very likely comes from the additional buffering of data.


Detailed Analysis


Small Result Set

Running the variation in BUFFERED mode where only 1,000K rows get produced, the following can be seen from the DBMS_XPLAN.DISPLAY_CURSOR output (assuming you don't run this cross-instance in RAC as DBMS_XPLAN can only show relevant statistics for the local instance), using a block size of 8KB and a 32bit version of Oracle:

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                  | Name     | Starts | E-Rows |E-Bytes| Cost  |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |          |      1 |        |       |  3053 |        |      |            |      0 |00:00:27.10 |      10 |      0 |      0 |       |       |          |         |
|   1 |  COUNT                     |          |      1 |        |       |       |        |      |            |      0 |00:00:27.10 |      10 |      0 |      0 |       |       |          |         |
|*  2 |   FILTER                   |          |      1 |        |       |       |        |      |            |      0 |00:00:27.10 |      10 |      0 |      0 |       |       |          |         |
|   3 |    PX COORDINATOR          |          |      1 |        |       |       |        |      |            |   1000K|00:00:25.45 |      10 |      0 |      0 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)    | :TQ10002 |      0 |   1001K|    99M|  3053 |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   5 |      VIEW                  |          |      2 |   1001K|    99M|  3053 |  Q1,02 | PCWP |            |   1000K|00:00:48.29 |       0 |  13208 |  13208 |       |       |          |         |
|*  6 |       HASH JOIN BUFFERED   |          |      2 |   1001K|   203M|  3053 |  Q1,02 | PCWP |            |   1000K|00:00:44.91 |       0 |  13208 |  13208 |   130M|  8379K|     2/0/0|   54272 |
|   7 |        PX RECEIVE          |          |      2 |   1000K|   101M|   171 |  Q1,02 | PCWP |            |   1000K|00:00:04.07 |       0 |      0 |      0 |       |       |          |         |
|   8 |         PX SEND HASH       | :TQ10000 |      0 |   1000K|   101M|   171 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   9 |          PX BLOCK ITERATOR |          |      2 |   1000K|   101M|   171 |  Q1,00 | PCWC |            |   1000K|00:00:06.15 |    2066 |   2014 |      0 |       |       |          |         |
|* 10 |           TABLE ACCESS FULL| T2       |     26 |   1000K|   101M|   171 |  Q1,00 | PCWP |            |   1000K|00:00:02.29 |    2066 |   2014 |      0 |       |       |          |         |
|  11 |        PX RECEIVE          |          |      2 |   2000K|   204M|   352 |  Q1,02 | PCWP |            |   1000K|00:00:16.85 |       0 |      0 |      0 |       |       |          |         |
|  12 |         PX SEND HASH       | :TQ10001 |      0 |   2000K|   204M|   352 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  13 |          PX BLOCK ITERATOR |          |      2 |   2000K|   204M|   352 |  Q1,01 | PCWC |            |   2000K|00:00:12.68 |    4212 |   4158 |      0 |       |       |          |         |
|* 14 |           TABLE ACCESS FULL| T4       |     26 |   2000K|   204M|   352 |  Q1,01 | PCWP |            |   2000K|00:00:05.09 |    4212 |   4158 |      0 |       |       |          |         |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

The statement got executed with a Parallel Degree of 2. Notice that only 2K (16MB) resp. 4K (32MB) blocks were processed for reading the two row sources, but the hash join had to read/write two times 50MB (100MB uncompressed data volume in total). If it was the result set that got buffered I would expect it to read/write 200MB in total.

If you repeat this variation with the true blocking operation then it shouldn't spill to disk at all, as indicated above by the O=2 (two optimal hash joins) in the column "O/1/M", which is interesting on its own, since it confirms that the HASH JOIN operated in optimal mode albeit the fact that it spilled to disk due to the BUFFERED operation.

Large Result Set

Running the variation in BUFFERED mode that joins on FK and therefore produces a huge result set looks like this (cancelled after a short while, so not run to completion in this case here):

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                  | Name     | Starts | E-Rows |E-Bytes| Cost  |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |          |      1 |        |       | 58314 |        |      |            |      0 |00:00:00.01 |      10 |      0 |      0 |       |       |          |
|   1 |  COUNT                     |          |      1 |        |       |       |        |      |            |      0 |00:00:00.01 |      10 |      0 |      0 |       |       |          |
|*  2 |   FILTER                   |          |      1 |        |       |       |        |      |            |      0 |00:00:00.01 |      10 |      0 |      0 |       |       |          |
|   3 |    PX COORDINATOR          |          |      1 |        |       |       |        |      |            |   3694K|00:00:35.06 |      10 |      0 |      0 |       |       |          |
|   4 |     PX SEND QC (RANDOM)    | :TQ10002 |      0 |   1000M|    96G| 58314 |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |
|   5 |      VIEW                  |          |      2 |   1000M|    96G| 58314 |  Q1,02 | PCWP |            |   3694K|00:01:03.14 |       0 |    508 |  12827 |       |       |          |
|*  6 |       HASH JOIN BUFFERED   |          |      2 |   1000M|   195G| 58314 |  Q1,02 | PCWP |            |   3694K|00:00:49.43 |       0 |    508 |  12827 |   133M|  8387K|     2/0/0|
|   7 |        PX RECEIVE          |          |      2 |   1000K|   100M|   171 |  Q1,02 | PCWP |            |   1000K|00:00:09.37 |       0 |      0 |      0 |       |       |          |
|   8 |         PX SEND HASH       | :TQ10000 |      0 |   1000K|   100M|   171 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |
|   9 |          PX BLOCK ITERATOR |          |      2 |   1000K|   100M|   171 |  Q1,00 | PCWC |            |   1000K|00:00:06.77 |    2066 |   2014 |      0 |       |       |          |
|* 10 |           TABLE ACCESS FULL| T2       |     26 |   1000K|   100M|   171 |  Q1,00 | PCWP |            |   1000K|00:00:02.87 |    2066 |   2014 |      0 |       |       |          |
|  11 |        PX RECEIVE          |          |      2 |   2000K|   200M|   352 |  Q1,02 | PCWP |            |   2000K|00:00:16.63 |       0 |      0 |      0 |       |       |          |
|  12 |         PX SEND HASH       | :TQ10001 |      0 |   2000K|   200M|   352 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |
|  13 |          PX BLOCK ITERATOR |          |      2 |   2000K|   200M|   352 |  Q1,01 | PCWC |            |   2000K|00:00:12.80 |    4212 |   4158 |      0 |       |       |          |
|* 14 |           TABLE ACCESS FULL| T4       |     26 |   2000K|   200M|   352 |  Q1,01 | PCWP |            |   2000K|00:00:05.25 |    4212 |   4158 |      0 |       |       |          |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

There are a few interesting points to mention:

1. If the query is executed without the outer query that filters all data, the first rows are returned pretty quickly. If it was the result set that got buffered, this shouldn't be the case here, instead a huge TEMP space usage should be observed until finally the result set is returned to the parent operation/client

2. The second row source is consumed completely before the join operation is completed and a steady TEMP read activity can be observed while the data is returned to the client

3. The data volume written to TEMP corresponds roughly to what was written to TEMP in the first example, and stays like that during the whole execution. It doesn't increase any more during the join operation.
The difference in TEMP usage of the first example might come from the fact that I've used 75000000 as workarea size for some of my initial test runs and therefore the output above comes from such an early run.

So this variation pretty clearly shows that it is not the result set that gets buffered. It looks like the second row source is what gets buffered, as it is already consumed completely before the join is completed.

Large Result Set, true blocking operation

Repeating the same variant with a true blocking operation that doesn't require the BUFFERED mode of the HASH JOIN, looks like that (again not run to completion here):

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                  | Name     | Starts | E-Rows |E-Bytes| Cost  |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem |  O/1/M   |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |          |      1 |        |       | 58441 |        |      |            |      0 |00:00:00.05 |      10 |      0 |       |       |          |
|   1 |  SORT AGGREGATE            |          |      1 |      1 |   104 |       |        |      |            |      0 |00:00:00.05 |      10 |      0 |       |       |          |
|   2 |   PX COORDINATOR           |          |      1 |        |       |       |        |      |            |      0 |00:00:00.05 |      10 |      0 |       |       |          |
|   3 |    PX SEND QC (RANDOM)     | :TQ10002 |      0 |      1 |   104 |       |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|   4 |     SORT AGGREGATE         |          |      2 |      1 |   104 |       |  Q1,02 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|   5 |      VIEW                  |          |      2 |   1000M|    96G| 58441 |  Q1,02 | PCWP |            |     11M|00:01:14.09 |       0 |      0 |       |       |          |
|*  6 |       HASH JOIN            |          |      2 |   1000M|   195G| 58441 |  Q1,02 | PCWP |            |     11M|00:00:37.73 |       0 |      0 |   133M|  8133K|     2/0/0|
|   7 |        PX RECEIVE          |          |      2 |   1000K|   100M|   171 |  Q1,02 | PCWP |            |   1000K|00:00:09.03 |       0 |      0 |       |       |          |
|   8 |         PX SEND HASH       | :TQ10000 |      0 |   1000K|   100M|   171 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|   9 |          PX BLOCK ITERATOR |          |      2 |   1000K|   100M|   171 |  Q1,00 | PCWC |            |   1000K|00:00:06.69 |    2066 |   2014 |       |       |          |
|* 10 |           TABLE ACCESS FULL| T2       |     26 |   1000K|   100M|   171 |  Q1,00 | PCWP |            |   1000K|00:00:02.89 |    2066 |   2014 |       |       |          |
|  11 |        PX RECEIVE          |          |      2 |   2000K|   200M|   352 |  Q1,02 | PCWP |            |  11309 |00:00:00.05 |       0 |      0 |       |       |          |
|  12 |         PX SEND HASH       | :TQ10001 |      0 |   2000K|   200M|   352 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|  13 |          PX BLOCK ITERATOR |          |      2 |   2000K|   200M|   352 |  Q1,01 | PCWC |            |  12602 |00:00:00.13 |      29 |     46 |       |       |          |
|* 14 |           TABLE ACCESS FULL| T4       |      2 |   2000K|   200M|   352 |  Q1,01 | PCWP |            |  12602 |00:00:00.09 |      29 |     46 |       |       |          |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Notice the difference: No TEMP activity, and the second row source gets gradually consumed as the join processes and data is returned to the parent operations.

BUFFERED vs. BUFFER SORT

In order to demonstrate the cunning optimization the HASH JOIN BUFFERED can perform, let's use a different distribution method that results in the second row source getting distributed via BROADCAST and therefore requires in this case here an artificial, separate BUFFER SORT operation when receiving the broadcasted data (as otherwise again two PX SEND operations would be active at the same time):

select /* HJ_trace1 */ * from (
select  /*+ no_merge use_hash(a b) no_cpu_costing leading(a b) pq_distribute(b, none, broadcast) */
        a.filler as a_filler, b.filler as b_filler
from
        t2 a
      , t4 b
where
        a.id = b.id
--        a.fk = b.fk
)
where rownum > 1

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name     | Starts | E-Rows |E-Bytes| Cost  |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |          |      1 |        |       |  2922 |        |      |            |      0 |00:00:51.64 |      10 |      0 |      0 |       |       |          |         |
|   1 |  COUNT                      |          |      1 |        |       |       |        |      |            |      0 |00:00:51.64 |      10 |      0 |      0 |       |       |          |         |
|*  2 |   FILTER                    |          |      1 |        |       |       |        |      |            |      0 |00:00:51.64 |      10 |      0 |      0 |       |       |          |         |
|   3 |    PX COORDINATOR           |          |      1 |        |       |       |        |      |            |   1000K|00:00:50.10 |      10 |      0 |      0 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)     | :TQ10001 |      0 |   1001K|    99M|  2922 |  Q1,01 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   5 |      VIEW                   |          |      2 |   1001K|    99M|  2922 |  Q1,01 | PCWP |            |   1000K|00:01:37.72 |    2070 |  58364 |  56350 |       |       |          |         |
|*  6 |       HASH JOIN             |          |      2 |   1001K|   203M|  2922 |  Q1,01 | PCWP |            |   1000K|00:01:34.58 |    2070 |  58364 |  56350 |   129M|  8125K|     2/0/0|         |
|   7 |        PX BLOCK ITERATOR    |          |      2 |   1000K|   101M|   171 |  Q1,01 | PCWC |            |   1000K|00:00:05.48 |    2066 |   2014 |      0 |       |       |          |         |
|*  8 |         TABLE ACCESS FULL   | T2       |     26 |   1000K|   101M|   171 |  Q1,01 | PCWP |            |   1000K|00:00:02.30 |    2066 |   2014 |      0 |       |       |          |         |
|   9 |        BUFFER SORT          |          |      2 |        |       |       |  Q1,01 | PCWC |            |   4000K|00:01:02.00 |       4 |  56350 |  56350 |   495M|  7329K|     2/0/0|     221K|
|  10 |         PX RECEIVE          |          |      2 |   2000K|   204M|   352 |  Q1,01 | PCWP |            |   4000K|00:00:21.14 |       0 |      0 |      0 |       |       |          |         |
|  11 |          PX SEND BROADCAST  | :TQ10000 |      0 |   2000K|   204M|   352 |  Q1,00 | P->P | BROADCAST  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  12 |           PX BLOCK ITERATOR |          |      2 |   2000K|   204M|   352 |  Q1,00 | PCWC |            |   2000K|00:00:12.81 |    4212 |   4158 |      0 |       |       |          |         |
|* 13 |            TABLE ACCESS FULL| T4       |     26 |   2000K|   204M|   352 |  Q1,00 | PCWP |            |   2000K|00:00:04.83 |    4212 |   4158 |      0 |       |       |          |         |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Notice how now the complete T4 row source was buffered twice (that's the side effect of broadcasting it to each Parallel Slave, in this case with degree 2), resulting in more than four times more TEMP space usage than in the BUFFERED variant. So the separate BUFFER SORT operation obviously wasn't able to avoid the buffering of the data from T4 that doesn't match T2 (in which case it should have buffered only approx. 100MB of data twice), whereas the HASH JOIN BUFFERED simply discarded that data from T4 immediately without bothering to buffer it.
It is also interesting to note that the BUFFER SORT operation was reported as "optimal", although it obviously spilled to disk (roughly two times 221MB, the 221K is the old defect of DBMS_XPLAN.DISPLAY_CURSOR to report the TEMP usage using the wrong unit)

Very Small Result Set

I also did a complementary test where the result set generated is much smaller than the second row source, just in case there is another cunning optimization in place that could decide to buffer either the second row source or the result set depending on which is estimated to be smaller.

select /* HJ_trace2 */ * from (
select  /*+ no_merge use_hash(a b) no_cpu_costing leading(a b) pq_distribute(b, hash, hash) */
        a.id as a_id, b.id as b_id
from
        t2 a
      , t4 b
where
        a.id = b.id
        a.filler = b.filler
)
where rownum > 1

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                  | Name     | Starts | E-Rows |E-Bytes| Cost  |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |          |      1 |        |       |  2922 |        |      |            |      0 |00:00:27.73 |      10 |      0 |      0 |       |       |          |         |
|   1 |  COUNT                     |          |      1 |        |       |       |        |      |            |      0 |00:00:27.73 |      10 |      0 |      0 |       |       |          |         |
|*  2 |   FILTER                   |          |      1 |        |       |       |        |      |            |      0 |00:00:27.73 |      10 |      0 |      0 |       |       |          |         |
|   3 |    PX COORDINATOR          |          |      1 |        |       |       |        |      |            |   1000K|00:00:26.08 |      10 |      0 |      0 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)    | :TQ10002 |      0 |   1001K|    24M|  2922 |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   5 |      VIEW                  |          |      2 |   1001K|    24M|  2922 |  Q1,02 | PCWP |            |   1000K|00:00:51.28 |       0 |  12319 |  12319 |       |       |          |         |
|*  6 |       HASH JOIN BUFFERED   |          |      2 |   1001K|   203M|  2922 |  Q1,02 | PCWP |            |   1000K|00:00:47.69 |       0 |  12319 |  12319 |   130M|  8379K|     2/0/0|   51200 |
|   7 |        PX RECEIVE          |          |      2 |   1000K|   101M|   171 |  Q1,02 | PCWP |            |   1000K|00:00:09.69 |       0 |      0 |      0 |       |       |          |         |
|   8 |         PX SEND HASH       | :TQ10000 |      0 |   1000K|   101M|   171 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   9 |          PX BLOCK ITERATOR |          |      2 |   1000K|   101M|   171 |  Q1,00 | PCWC |            |   1000K|00:00:06.87 |    2066 |   2014 |      0 |       |       |          |         |
|* 10 |           TABLE ACCESS FULL| T2       |     26 |   1000K|   101M|   171 |  Q1,00 | PCWP |            |   1000K|00:00:02.91 |    2066 |   2014 |      0 |       |       |          |         |
|  11 |        PX RECEIVE          |          |      1 |   2000K|   204M|   352 |  Q1,02 | PCWP |            |   2000K|00:00:16.74 |       0 |      0 |      0 |       |       |          |         |
|  12 |         PX SEND HASH       | :TQ10001 |      0 |   2000K|   204M|   352 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  13 |          PX BLOCK ITERATOR |          |      2 |   2000K|   204M|   352 |  Q1,01 | PCWC |            |   2000K|00:00:12.43 |    4212 |   4158 |      0 |       |       |          |         |
|* 14 |           TABLE ACCESS FULL| T4       |     26 |   2000K|   204M|   352 |  Q1,01 | PCWP |            |   2000K|00:00:04.77 |    4212 |   4158 |      0 |       |       |          |         |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

So although the result set is estimated only to be 24MB in size in this case the amount of data that spilled to disk is still roughly 100MB, which seems to suggest that it is always the second row source that gets buffered.


10104 Trace File Snippet

Finally, a sample extract from the 10104 hash join trace file showing that spilling to disk takes place before the PROBE_2 phase begins:

.
.
.
kxhfWrite: hash-join is spilling to disk
kxhfWrite: Writing dba=130176 slot=56 part=8
kxhfIsDone: waiting slot=56 lbs=000000001CCB7308
kxhfWrite: Writing dba=129920 slot=57 part=8
kxhfIsDone: waiting slot=57 lbs=000000001CCB7308
.
.
.
kxhfIsDone: waiting slot=61 lbs=000000001CD37308
kxhfWrite: Writing dba=118528 slot=62 part=8

*** 2012-11-15 18:27:12.706
qerhjFetch: max probe row length (mpl=0)
kxhfSetPhase: phase=PROBE_2
qerhjFetch: PQ Partition rows:500826     clusters:56    in-memory slots      9
kxhfIsDone: waiting slot=62 lbs=000000001CD37308
kxhfWrite: Writing dba=118272 slot=63 part=8
kxhfWrite: Writing dba=118144 slot=64 part=8
kxhfRead(): Reading dba=130432 into slot=62
kxhfIsDone: waiting slot=62 lbs=000000001CD37308
kxhfIsDone: waiting slot=63 lbs=000000001CD37308
kxhfRead(): Reading dba=130304 into slot=63
.
.
.


Footnote


The tests were performed on recent (11.2) releases as well as 10.2.0.3 which is one of the versions Jonathan used for testing in his original post. All versions tested showed the same behaviour, so it doesn't look like the buffering of the second row source is a change that got introduced in recent releases.

Furthermore please note that my OTN mini series on Parallel Execution that I wrote already a couple of months ago but was only published recently doesn't include this knowledge here and therefore explains the BUFFERED operation and the reasons for the blocking operations partially incorrectly.


Summary


The test case results show that the HASH JOIN BUFFERED operation seems to buffer the second row source. In principle it operates like a BUFFER SORT operation on the second row source but takes advantage of the fact that it only needs to buffer data that matches data in the first row source.

The limitation why the artificial blocking operations are introduced seems to revolve around the fact that at most a single PX SEND operation can be active concurrently.

Friday, December 7, 2012

DBMS_XPLAN.DISPLAY_CURSOR And Parallel Execution


Introduction


DBMS_XPLAN.DISPLAY_CURSOR can be used to get more insights into the actual resource consumption on execution plan operation level when using the GATHER_PLAN_STATISTICS hint (from 10g on), or increasing the STATISTICS_LEVEL parameter to ALL (on session level, on system level the overhead is probably prohibitive).

As soon as a SQL execution is done (either successfully, cancelled or with error) the corresponding extended data in the child cursor gets populated/updated and the additional information about the actual runtime profile can be accessed via V$SQL_PLAN_STATISTICS resp. V$SQL_PLAN_STATISTICS_ALL - this is what DISPLAY_CURSOR uses to populate the additional columns in the formatted output of the execution plan.

This works well for normal, serial execution where a single session performs the SQL execution and allows gathering extended information about the following statistics on execution plan line level:

- Actual cardinalities vs. estimated cardinalities
- Actual time spent on each operation (only reliable when using STATISTICS_LEVEL = ALL or setting "_rowsource_sample_freq" to 1 which can have a significant impact on runtime due to overhead)
- Logical I/O
- Physical I/O
- Memory usage of workareas
- TEMP space usage

One crucial information that is not available via this interface is how the actual time was spent (CPU vs. Wait Events).


Parallel Execution


However getting information about these Rowsource Statistics by default doesn't work well with Parallel Execution. When using the formatting option "ALLSTATS LAST" that is usually recommended to obtain the extended statistics for the last execution of the SQL statement you'll only see the statistics related to the work performed by the Query Coordinator, but no information related to the work performed by the Parallel Slaves.

Here is an example DBMS_XPLAN.DISPLAY_CURSOR output for a Parallel Execution using the "ALLSTATS LAST" option:

-------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name     | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem | Used-Tmp|
-------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |          |      1 |        |      0 |00:02:41.57 |      10 |       |       |          |         |
|   1 |  COUNT                    |          |      1 |        |      0 |00:02:41.57 |      10 |       |       |          |         |
|*  2 |   FILTER                  |          |      1 |        |      0 |00:02:41.57 |      10 |       |       |          |         |
|   3 |    PX COORDINATOR         |          |      1 |        |   2000K|00:02:29.30 |      10 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)   | :TQ10002 |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|*  5 |      HASH JOIN BUFFERED   |          |      0 |   2000K|      0 |00:00:00.01 |       0 |    56M|  7910K|   14M (0)|   30720 |
|   6 |       PX RECEIVE          |          |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|   7 |        PX SEND HASH       | :TQ10000 |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|   8 |         PX BLOCK ITERATOR |          |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|*  9 |          TABLE ACCESS FULL| T4       |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|  10 |       PX RECEIVE          |          |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|  11 |        PX SEND HASH       | :TQ10001 |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|  12 |         PX BLOCK ITERATOR |          |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
|* 13 |          TABLE ACCESS FULL| T2       |      0 |   2000K|      0 |00:00:00.01 |       0 |       |       |          |         |
-------------------------------------------------------------------------------------------------------------------------------------

You can partially work around this limitation by using the format option "ALLSTATS ALL" instead. This option means that the information provided by DBMS_XPLAN.DISPLAY_CURSOR is based on a different column set of V$SQL_PLAN_STATISTICS_ALL that aggregates across all executions of the SQL statement. For Parallel Exection the statistics representing the work performed by the Parallel Slaves will be added to these columns, so using "ALLSTATS ALL" includes that information.

However, you need to be careful, since this means that you can't distinguish between the last and previous executions of the same cursor. So if you execute the same cursor multiple times in parallel, "ALLSTATS ALL" will show statistics that cover all these executions. You can work around this in a test case scenario by deliberately modifying the SQL text, for example by using a corresponding comment, that leads to the creation of a separate, unique parent cursor. This way it is ensured that "ALLSTATS ALL" effectively only displays information related to the last execution, since there is only a single (parallel) execution of that cursor.

Here is again the same Parallel Execution as above, this time using the "ALLSTATS ALL" option:

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |          |      1 |        |       |   831 (100)|          |        |      |            |      0 |00:02:41.57 |      10 |      2 |      0 |       |       |          |         |
|   1 |  COUNT                    |          |      1 |        |       |            |          |        |      |            |      0 |00:02:41.57 |      10 |      2 |      0 |       |       |          |         |
|*  2 |   FILTER                  |          |      1 |        |       |            |          |        |      |            |      0 |00:02:41.57 |      10 |      2 |      0 |       |       |          |         |
|   3 |    PX COORDINATOR         |          |      1 |        |       |            |          |        |      |            |   2000K|00:02:29.30 |      10 |      2 |      0 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)   | :TQ10002 |      0 |   2000K|   223M|   831   (2)| 00:00:01 |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|*  5 |      HASH JOIN BUFFERED   |          |      8 |   2000K|   223M|   831   (2)| 00:00:01 |  Q1,02 | PCWP |            |   2000K|00:16:51.21 |     815 |  29239 |  29202 |    56M|  7910K|     8/0/0|   30720 |
|   6 |       PX RECEIVE          |          |      8 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,02 | PCWP |            |   2000K|00:05:23.83 |       0 |      0 |      0 |       |       |          |         |
|   7 |        PX SEND HASH       | :TQ10000 |      0 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   8 |         PX BLOCK ITERATOR |          |      8 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | PCWC |            |   2000K|00:05:44.20 |    4838 |   4735 |      0 |       |       |          |         |
|*  9 |          TABLE ACCESS FULL| T4       |    103 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | PCWP |            |   2000K|00:04:50.92 |    4838 |   4735 |      0 |       |       |          |         |
|  10 |       PX RECEIVE          |          |      8 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,02 | PCWP |            |   2000K|00:07:16.22 |       0 |      0 |      0 |       |       |          |         |
|  11 |        PX SEND HASH       | :TQ10001 |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  12 |         PX BLOCK ITERATOR |          |      8 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | PCWC |            |   2000K|00:02:05.78 |    4748 |   4228 |      0 |       |       |          |         |
|* 13 |          TABLE ACCESS FULL| T2       |    104 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | PCWP |            |   2000K|00:01:29.86 |    4748 |   4228 |      0 |       |       |          |         |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Notice the difference - the work performed by the Parallel Slaves is (mostly) visible now. Apart from that the "ALL" formatting option added some columns that are not shown when using the "LAST" option, which you can customize using the more granular formatting options of DBMS_XPLAN.

Reading the output is not that simple as for serial executions, in particular because there is a mixture of wall-clock / DB Time time for the activities related to the Query Coordinator and the aggregated DB Time for the Parallel Slaves.

Furthermore the rule that applies to serial execution plans that the values for time / work are cumulative is not adhered to for Parallel Execution, at least not across Parallel Slave Sets / Table Queues and the Query Coordinator.


Multiple DFOs And Cross-Instance


However, depending on the exact details of the execution plan and the actual execution of the SQL statement, V$SQL_PLAN_STATISTICS_ALL respectively DISPLAY_CURSOR still might miss information about the Parallel Execution even when using "ALLSTATS ALL".

In particular the following two points are important to consider:

1. If the Parallel Execution is cross-instance (runs on multiple nodes of a RAC) then DBMS_XPLAN.DISPLAY_CURSOR will only show information about the work performed on the local instance, since it only gathers information from the local V$SQL_PLAN_STATISTICS_ALL dynamic performance view. DBMS_XPLAN.DISPLAY_CURSOR doesn't show the complete picture in such cases.

Here is again the same execution plan as above, this time executed cross instance on two nodes participating in the execution:

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |          |      1 |        |       |   831 (100)|          |        |      |            |      0 |00:01:42.95 |      10 |      0 |      0 |       |       |          |         |
|   1 |  COUNT                    |          |      1 |        |       |            |          |        |      |            |      0 |00:01:42.95 |      10 |      0 |      0 |       |       |          |         |
|*  2 |   FILTER                  |          |      1 |        |       |            |          |        |      |            |      0 |00:01:42.95 |      10 |      0 |      0 |       |       |          |         |
|   3 |    PX COORDINATOR         |          |      1 |        |       |            |          |        |      |            |   2000K|00:01:29.20 |      10 |      0 |      0 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)   | :TQ10002 |      0 |   2000K|   223M|   831   (2)| 00:00:01 |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|*  5 |      HASH JOIN BUFFERED   |          |      4 |   2000K|   223M|   831   (2)| 00:00:01 |  Q1,02 | PCWP |            |   1000K|00:04:30.07 |       0 |  14601 |  14601 |    56M|  7910K|     4/0/0|   30720 |
|   6 |       PX RECEIVE          |          |      4 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,02 | PCWP |            |   1000K|00:01:17.90 |       0 |      0 |      0 |       |       |          |         |
|   7 |        PX SEND HASH       | :TQ10000 |      0 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   8 |         PX BLOCK ITERATOR |          |      4 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | PCWC |            |   1038K|00:01:27.13 |    2585 |   2530 |      0 |       |       |          |         |
|*  9 |          TABLE ACCESS FULL| T4       |     55 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | PCWP |            |   1038K|00:01:07.22 |    2585 |   2530 |      0 |       |       |          |         |
|  10 |       PX RECEIVE          |          |      4 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,02 | PCWP |            |   1000K|00:02:11.36 |       0 |      0 |      0 |       |       |          |         |
|  11 |        PX SEND HASH       | :TQ10001 |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  12 |         PX BLOCK ITERATOR |          |      4 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | PCWC |            |   1011K|00:00:46.56 |    2402 |      0 |      0 |       |       |          |         |
|* 13 |          TABLE ACCESS FULL| T2       |     53 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | PCWP |            |   1011K|00:00:26.53 |    2402 |      0 |      0 |       |       |          |         |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Note how only "half" of the work is reported (except for the Query Coordinator work). When running DBMS_XPLAN.DISPLAY_CURSOR for the corresponding cursor on the second participating node, I get the other "half":

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |          |      0 |        |       |   831 (100)|          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   1 |  COUNT                    |          |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|*  2 |   FILTER                  |          |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   3 |    PX COORDINATOR         |          |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   4 |     PX SEND QC (RANDOM)   | :TQ10002 |      0 |   2000K|   223M|   831   (2)| 00:00:01 |  Q1,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|*  5 |      HASH JOIN BUFFERED   |          |      4 |   2000K|   223M|   831   (2)| 00:00:01 |  Q1,02 | PCWP |            |    999K|00:04:30.16 |     215 |  14590 |  14570 |    56M|  7910K|     4/0/0|   30720 |
|   6 |       PX RECEIVE          |          |      4 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,02 | PCWP |            |    999K|00:01:17.35 |       0 |      0 |      0 |       |       |          |         |
|   7 |        PX SEND HASH       | :TQ10000 |      0 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   8 |         PX BLOCK ITERATOR |          |      4 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | PCWC |            |    961K|00:01:29.64 |    2253 |   2205 |      0 |       |       |          |         |
|*  9 |          TABLE ACCESS FULL| T4       |     48 |   2000K|    11M|   180   (2)| 00:00:01 |  Q1,00 | PCWP |            |    961K|00:01:10.14 |    2253 |   2205 |      0 |       |       |          |         |
|  10 |       PX RECEIVE          |          |      4 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,02 | PCWP |            |    999K|00:01:51.26 |       0 |      0 |      0 |       |       |          |         |
|  11 |        PX SEND HASH       | :TQ10001 |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  12 |         PX BLOCK ITERATOR |          |      4 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | PCWC |            |    988K|00:00:51.52 |    2346 |      0 |      0 |       |       |          |         |
|* 13 |          TABLE ACCESS FULL| T2       |     51 |   2000K|   211M|   647   (2)| 00:00:01 |  Q1,01 | PCWP |            |    988K|00:00:30.00 |    2346 |      0 |      0 |       |       |          |         |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

2. If the parallel execution plan consists of multiple so called "Data Flow Operations" (DFOs, you can read more about those DFOs in my OTN mini series about Parallel Execution), indicated by multiple PX COORDINATOR operations, then these different DFOs will be represented by multiple child cursors at execution time. So each DFO ends up with a separate child cursor.

Since DBMS_XPLAN.DISPLAY_CURSOR cannot aggregate information across multiple child cursors the information displayed again will be incomplete in such cases.

You can run DISPLAY_CURSOR for each of the child cursor generated, but this doesn't give you the same level of information. Furthermore, depending on the version and actual circumstances, the additional child cursors might not inherit the corresponding rowsource statistics setting, so these child cursors might not even contain any additional information in V$SQL_PLAN_STATISTICS_ALL

Here is again a similar execution plan as above, this time using a parallel TEMP table transformation that automatically results in a separate DFO and therefore a separate child cursor at runtime. The execution in this case was using a degree of 2 and was single instance:

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name                      | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   | Max-Tmp |
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                           |      1 |        |       |  1635 (100)|          |        |      |            |      0 |00:02:23.91 |     229 |      1 |    127 |       |       |          |         |
|   1 |  TEMP TABLE TRANSFORMATION  |                           |      1 |        |       |            |          |        |      |            |      0 |00:02:23.91 |     229 |      1 |    127 |       |       |          |         |
|   2 |   PX COORDINATOR            |                           |      1 |        |       |            |          |        |      |            |      2 |00:00:34.99 |      33 |      0 |      0 |       |       |          |         |
|   3 |    PX SEND QC (RANDOM)      | :TQ10000                  |      0 |   2000K|    11M|   721   (2)| 00:00:01 |  Q1,00 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   4 |     LOAD AS SELECT          |                           |      0 |        |       |            |          |  Q1,00 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |   256K|   256K|          |         |
|   5 |      PX BLOCK ITERATOR      |                           |      0 |   2000K|    11M|   721   (2)| 00:00:01 |  Q1,00 | PCWC |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|*  6 |       TABLE ACCESS FULL     | T4                        |      0 |   2000K|    11M|   721   (2)| 00:00:01 |  Q1,00 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|   7 |   COUNT                     |                           |      1 |        |       |            |          |        |      |            |      0 |00:01:48.83 |      13 |      0 |      0 |       |       |          |         |
|*  8 |    FILTER                   |                           |      1 |        |       |            |          |        |      |            |      0 |00:01:48.83 |      13 |      0 |      0 |       |       |          |         |
|   9 |     PX COORDINATOR          |                           |      1 |        |       |            |          |        |      |            |   2000K|00:01:35.86 |      13 |      0 |      0 |       |       |          |         |
|  10 |      PX SEND QC (RANDOM)    | :TQ20002                  |      0 |   2000K|   236M|   914   (4)| 00:00:01 |  Q2,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|* 11 |       HASH JOIN BUFFERED    |                           |      2 |   2000K|   236M|   914   (4)| 00:00:01 |  Q2,02 | PCWP |            |   2000K|00:03:01.81 |     160 |  29295 |  29295 |    55M|  7910K|     2/0/0|     123K|
|  12 |        PX RECEIVE           |                           |      2 |   2000K|    24M|   254   (4)| 00:00:01 |  Q2,02 | PCWP |            |   2000K|00:01:07.27 |       0 |      0 |      0 |       |       |          |         |
|  13 |         PX SEND HASH        | :TQ20000                  |      0 |   2000K|    24M|   254   (4)| 00:00:01 |  Q2,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  14 |          VIEW               |                           |      2 |   2000K|    24M|   254   (4)| 00:00:01 |  Q2,00 | PCWP |            |   2000K|00:01:34.53 |    3355 |   3328 |      0 |       |       |          |         |
|  15 |           PX BLOCK ITERATOR |                           |      2 |   2000K|    11M|   254   (4)| 00:00:01 |  Q2,00 | PCWC |            |   2000K|00:01:09.08 |    3355 |   3328 |      0 |       |       |          |         |
|* 16 |            TABLE ACCESS FULL| SYS_TEMP_0FD9D6603_158141 |     26 |   2000K|    11M|   254   (4)| 00:00:01 |  Q2,00 | PCWP |            |   2000K|00:00:43.39 |    3355 |   3328 |      0 |       |       |          |         |
|  17 |        PX RECEIVE           |                           |      2 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,02 | PCWP |            |   2000K|00:01:16.59 |       0 |      0 |      0 |       |       |          |         |
|  18 |         PX SEND HASH        | :TQ20001                  |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |         |
|  19 |          PX BLOCK ITERATOR  |                           |      2 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,01 | PCWC |            |   2000K|00:00:47.97 |    4358 |      0 |      0 |       |       |          |         |
|* 20 |           TABLE ACCESS FULL | T2                        |     26 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,01 | PCWP |            |   2000K|00:00:17.82 |    4358 |      0 |      0 |       |       |          |         |
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Notice how the output suggests that the parallel execution part of the TEMP table transformation didn't start at all and didn't perform any work. If however the second child cursor related to the other DFO is analyzed, the following information gets reported:

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------          
| Id  | Operation                   | Name                      | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem |  O/1/M   |          
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------          
|   0 | SELECT STATEMENT            |                           |      0 |        |       |  1635 (100)|          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|   1 |  TEMP TABLE TRANSFORMATION  |                           |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|   2 |   PX COORDINATOR            |                           |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|   3 |    PX SEND QC (RANDOM)      | :TQ10000                  |      0 |   2000K|    11M|   721   (2)| 00:00:01 |  Q1,00 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|   4 |     LOAD AS SELECT          |                           |      2 |        |       |            |          |  Q1,00 | PCWP |            |      0 |00:01:07.92 |    8027 |   4737 |   3198 |  1058K|  1058K|     2/0/0|          
|   5 |      PX BLOCK ITERATOR      |                           |      2 |   2000K|    11M|   721   (2)| 00:00:01 |  Q1,00 | PCWC |            |   2000K|00:00:33.10 |    4761 |   4735 |      0 |       |       |          |          
|*  6 |       TABLE ACCESS FULL     | T4                        |     26 |   2000K|    11M|   721   (2)| 00:00:01 |  Q1,00 | PCWP |            |   2000K|00:00:11.27 |    4761 |   4735 |      0 |       |       |          |          
|   7 |   COUNT                     |                           |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|*  8 |    FILTER                   |                           |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|   9 |     PX COORDINATOR          |                           |      0 |        |       |            |          |        |      |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  10 |      PX SEND QC (RANDOM)    | :TQ20002                  |      0 |   2000K|   236M|   914   (4)| 00:00:01 |  Q2,02 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|* 11 |       HASH JOIN BUFFERED    |                           |      0 |   2000K|   236M|   914   (4)| 00:00:01 |  Q2,02 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |    83M|  5864K|          |          
|  12 |        PX RECEIVE           |                           |      0 |   2000K|    24M|   254   (4)| 00:00:01 |  Q2,02 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  13 |         PX SEND HASH        | :TQ20000                  |      0 |   2000K|    24M|   254   (4)| 00:00:01 |  Q2,00 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  14 |          VIEW               |                           |      0 |   2000K|    24M|   254   (4)| 00:00:01 |  Q2,00 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  15 |           PX BLOCK ITERATOR |                           |      0 |   2000K|    11M|   254   (4)| 00:00:01 |  Q2,00 | PCWC |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|* 16 |            TABLE ACCESS FULL| SYS_TEMP_0FD9D6603_158141 |      0 |   2000K|    11M|   254   (4)| 00:00:01 |  Q2,00 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  17 |        PX RECEIVE           |                           |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,02 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  18 |         PX SEND HASH        | :TQ20001                  |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,01 | P->P | HASH       |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|  19 |          PX BLOCK ITERATOR  |                           |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,01 | PCWC |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
|* 20 |           TABLE ACCESS FULL | T2                        |      0 |   2000K|   211M|   647   (2)| 00:00:01 |  Q2,01 | PCWP |            |      0 |00:00:00.01 |       0 |      0 |      0 |       |       |          |          
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------          

Here you can see the missing parallel execution work actually performed.


Real-Time SQL Monitoring And XPLAN_ASH


If you are on 11g already and have the corresponding Diagnostic + Tuning Pack license, the best way to get a complete picture about Parallel Execution is using the "active" Real-Time SQL Monitoring report. It shows information already while the statement executes and doesn't have above mentioned limitations, so can work with cross-instance executions and execution plans using multiple DFOs (although there are bugs in the current versions related to such plans), besides that offers even more insights into the execution details than DBMS_XPLAN.DISPLAY_CURSOR / V$SQL_PLAN_STATISTICS_ALL.

It is interesting to note that Real-Time SQL Monitoring doesn't show the actual time consumed on execution plan line level as extended Rowsource Statistics does, which explains why it doesn't come with the same overhead. Since Real-Time SQL Monitoring analyzes ASH data instead, it can still come up with some reasonable execution plan line level work distribution information (including the differentation between CPU time and waits), although not as accurate as the actual timing information that can be gathered via Rowsource Statistics.

If you don't have a Tuning Pack license but at least Diagnostic Pack, or you're still on 10g (+ Diagnostic Pack license) then you can use my XPLAN_ASH tool to gather some interesting information about Parallel Execution. Since Active Session History is available cross instance and isn't limited to particular child cursors, it doesn't have above limitations and therefore can provide the full picture about a SQL execution based on ASH data. In 10g however, the ASH data doesn't have a relation to execution plan lines and misses some other information available from 11g on, so some important analysis on execution plan line level that can be done with 11g ASH data is not available in 10g.


Footnote


If you look carefully at above execution plans you'll notice the HASH JOIN BUFFERED operations that are reported as "Optimal" Hash Joins. This in principle means that the Hash Join operation itself could be done completely in memory. Why does DBMS_XPLAN.DISPLAY_CURSOR then show Read/Write/TEMP activity for the HASH JOIN BUFFERED operation? I'll cover this in detail in my next post - I believe the explanations (including my own) published so far for that type of operation are incorrect.


Summary


DBMS_XPLAN.DISPLAY_CURSOR doesn't work very well with Parallel Execution. For simple execution plans consisting only of a single DFO, and single-instance executions the "ALLSTATS ALL" option can be used as a workaround.

If available, Real-Time SQL Monitoring is the tool to use for Parallel Execution analysis. My XPLAN_ASH tool also offers some unique insights, in particular regarding systematic analysis of Parallel Execution work distribution skew.

Monday, November 19, 2012

DOAG 2012 Conference

This is just a friendly reminder that I'll be talking at this year's DOAG Oracle conference about "Cost-Based Optimizer Basics" on Thursday, the 22nd of November, "Raum 1" at 13:00.

Additionally, I've reserved a slot at the "Unconference" (15:00 the same day) where I plan to present some of the interesting stuff that I cover as part of my "Parallel Execution Masterclass".

And soon the technical content will be back at this blog where I have lots of interesting stuff in the pipeline, mainly covering Parallel Execution topics.

Friday, November 9, 2012

OTN Mini Series "Understanding Parallel Execution"

As already announced previously OTN has now managed to publish my two part series called "Understanding Parallel Execution".

Part 1
Part 2

Thanks to Bob Rhubart from Oracle for his support in getting the articles published.

The articles should give you also an idea of what I cover in my "Mastering Oracle Parallel Execution" one day Oracle Expert seminar. More information can be found here.

Wednesday, October 24, 2012

New Version Of XPLAN_ASH Utility

A new version 2.0 of the XPLAN_ASH utility introduced here is available for download.

You can download the latest version here.

The change log tracks the following changes:
- Access check
- Conditional compilation for different database versions
- Additional activity summary
- Concurrent activity information (what is/was going on at the same time)
- Experimental stuff: Additional I/O summary
- More pretty printing
- Experimental stuff: I/O added to Average Active Session Graph (renamed to Activity Timeline)
- Top Execution Plan Lines and Top Activities added to Activity Timeline
- Activity Timeline is now also shown for serial execution when TIMELINE option is specified
- From 11.2.0.2 on: We get the ACTUAL DOP from the undocumented PX_FLAGS column added to ASH
- All relevant XPLAN_ASH queries are now decorated with comments so it should be easy to identify them in the Library Cache
- More samples are now covered and a kind of "read consistency" across queries on ASH is introduced
- From 11.2.0.2 on: Executions plans are now pulled from the remote RAC instance Library Cache if necessary
- Separate Parallel Slave activity overview (similar to "Parallel" tab of Real-Time SQL Monitoring)
- Support for the limited ASH capabilities of Oracle 10.2

So that's quite a big list of changes. In particular noteworthy is that the script now supports the limited capabilities of 10gR2 ASH. Although the coolest features of the script (Activity and Parallel Distribution information on Execution Plan line level) are not available with 10g, the remaining stuff still can be very useful - in particular the Parallel Slave and Activity Timeline information for Parallel Execution analysis - so that I believe this is a nice addition for those not yet on 11g and one of most powerful ways of analysing Parallel Execution on 10g.

When enabling Rowsource Statistics you can even get actual Rowsource cardinalities, however not all Parallel Execution plans are supported via DBMS_XPLAN.DISPLAY_CURSOR - Parallel Execution plans using multiple Data Flow Operations (DFOs, see the previous post about XPLAN_ASH for a little bit more info about DFOs) will generate multiple child cursors (one per DFO) and DISPLAY_CURSOR cannot "aggregate" the statistics information across multiple child cursors (besides that the "Rowsource Statistics" attribute is not preserved when enabling it on session level and those multiple child cursors get generated).

Functionality-wise I believe the most important stuff is now covered by this version of the script, and therefore the next releases will focus on fixing the numerous bugs that certainly have been introduced by this new version, and in particular on an improved representation of the information.
Very likely a HTML report similar to the HTML version of Real-Time SQL Monitoring would allow getting a much better overview of the information provided rather than the messy output of the current SQL*Plus query results.

Due to the way the queries on the ASH data are now written, it should be possible to come up with a version that also supports S-ASH, the free ASH implementation.

Summary Of Changes


1. It runs a reasonable pre-check and informs if any of the objects potentially required by the script aren't accessible. You'll see an output similar to the following in such cases:

----------------------------------------------------------------------------------------------
!!Access Check failed!!
----------------------------------------------------------------------------------------------
Error ORA-00942 when accessing GV$SESSION
Error ORA-00942 when accessing V$DATABASE
Error ORA-00942 when accessing GV$ACTIVE_SESSION_HISTORY
Error ORA-00942 when accessing GV$SQL_PLAN_STATISTICS_ALL
Error ORA-00942 when accessing GV$SQL_MONITOR
Error ORA-00942 when accessing DBA_HIST_ACTIVE_SESS_HISTORY
Error ORA-00942 when accessing DBA_HIST_SQL_PLAN

2. Furthermore the script no longer appears to "hang" if privileges are missing or anything else unexpected happens. Actually the script wasn't hanging but usually waited for input with termout set to OFF, since some of the defines populated under regular conditions weren't properly populated when things went wrong. This has been corrected and you should now see the above privilege check output along with regular follow-up error messages, but no hanging script any longer.

3. The output has been re-aligned and further sections have been added. In particular the various "Activity" / "Concurrent Activity" summaries should be helpful to get a better understanding of the overall activity profile of the query and concurrently ongoing database activity. See below for more details about these new sections.

Note that in case of a cross-instance Parallel Execution the summaries will also be provided on instance level in addition.

10.2 Support


Except for a few sections that simply aren't available when running on pre-11g the script shows quite similar information when used with 10.2

The biggest difference when using the script with 10.2 is caused by the fact that 10.2 ASH neither has a clear indicator of a SQL execution instance (the SQL_EXEC_START / SQL_EXEC_ID columns added in 11g) nor is there a relation to the execution plan lines (SQL_PLAN_LINE_ID etc.)

Therefore the SQL_EXEC_START parameter with 10.2 is mandatory, and simply specifies the lower sample time of ASH data to query. Instead of the non-existing SQL_EXEC_ID the script expects a SQL_EXEC_END date input similar to SQL_EXEC_START that obviously determines the upper sample time for ASH data and is also mandatory.

Likewise in 10.2 the script doesn't support searching for the most recent execution like it does on 11g, so - as already outlined - it is up to you to determine what ASH data should be searched for a particular SQL_ID by specifying both SQL_EXEC_START and SQL_EXEC_END.
Note that if the ASH samples at SQL_EXEC_START don't include samples for the SQL_ID in question, then the script uses the "closest" samples to SQL_EXEC_START found within the range SQL_EXEC_START / SQL_EXEC_END to determine the session information that will be used to limit the ASH data.


Short Introduction


Since the initial post what a bit lengthy, allow me to use this opportunity to summarize what the main purpose of the script is:

1. It provides an output that to a significant degree is similar to information provided by the Real-Time SQL Monitoring even in cases where the Real-Time SQL Monitoring report is no longer available.

In particular it allows pulling this information even from the DBA_HIST* views, something that is not possible with Real-Time SQL Monitoring, and therefore allows pulling detailed reports about SQL executions as long as ago as the configured AWR retention.

Note that this is applicable to both serial and Parallel Execution, and the tool can also provide information about currently executing SQL statements.

2. For Parallel Execution, it offers some important clues. Some of them aren't provided elsewhere, even not by Real-Time SQL Monitoring (At least not up to version 11.2):

- It shows information about the Average Active Sessions (AVERAGE_AS column below) with different granularity. This information is crucial in understanding how well the work was distributed among the Parallel Slaves. When looking at the sample report below it becomes immediately obvious that the AVERAGE_AS figures are way below the Parallel degree used.

Global ASH Summary
-----------------------------------------------

INSTANCE_COUNT|FIRST_SAMPLE       |LAST_SAMPLE        |DURATION_SECS|STATUS  |SAMPLE_COUNT|CPU_SAMPLE_COUNT|PERCENTAGE_CPU|SLAVE_COUNT|AVERAGE_AS|MODULE                                                          |ACTION
--------------|-------------------|-------------------|-------------|--------|------------|----------------|--------------|-----------|----------|----------------------------------------------------------------|----------------------------------------------------------------
             2|2012-10-16 10:52:00|2012-10-16 10:52:36|           38|INACTIVE|         190|             182|            96|         59|         5|SQL*Plus                                                        |




Global ASH Summary per Instance
-----------------------------------------------

INSTANCE_ID|FIRST_SAMPLE       |LAST_SAMPLE        |START_ACTIVE|DURATION_SECS|SAMPLE_COUNT|PROCESS_COUNT|AVERAGE_AS|TIME_ACTIVE_GRAPH
-----------|-------------------|-------------------|------------|-------------|------------|-------------|----------|--------------------
          5|2012-10-16 10:52:01|2012-10-16 10:52:36|           2|           36|         111|           30|      3,08| @@@@@@@@@@@@@@@@@@@
          6|2012-10-16 10:52:00|2012-10-16 10:52:31|           1|           32|          79|           30|      2,47| @@@@@@@@@@@@@@@@@




Information on Parallel Degree based on ASH
-----------------------------------------------

INSTANCE_ID|DFO   |START_ACTIVE|DURATION_SECS|SAMPLE_COUNT|PROCESS_COUNT| SET_COUNT|ASSUMED_DEGREE|ACTUAL_DEGREE|AVERAGE_AS|TIME_ACTIVE_GRAPH
-----------|------|------------|-------------|------------|-------------|----------|--------------|-------------|----------|--------------------
          5|Q1    |           2|           36|         111|           30|         2|            15|           16|      3,08| @@@@@@@@@@@@@@@@@@@
          6|Q1    |           2|           31|          78|           29|         2|            15|           16|      2,52| @@@@@@@@@@@@@@@@

In particular the "Parallel Slave activity", which corresponds to the "Parallel" tab of the Real-Time SQL Monitoring and the "Activity Timeline", which corresponds to a mixture of the "Activity" and "Metrics" tab of the Real-Time SQL Monitoring, allows spotting any anomalies regarding skew (both temporal and data distribution skew).

Below example shows that one Parallel Slave is sampled much more than the others. The Activity Timeline (scroll to the right to see the relevant columns) shows that only for a short period of time the expected number of slaves where active at the same time, and a long period of only one average active session.

Parallel Slave activity overview based on ASH
-----------------------------------------------

           |                                                                |          |                    |    SAMPLE|    SAMPLE|          |      |      |TOP                                     |
           |                                                                |    SAMPLE|                    |     COUNT|     COUNT|   PERCENT|MAX   |MAX   |ACTIVE                                  |TOP
INSTANCE_ID|PROCESS                                                         |     COUNT|ACTIVITY_GRAPH      |       CPU|     OTHER|       CPU|PGA   |TEMP  |PLAN LINES                              |ACTIVITIES
-----------|----------------------------------------------------------------|----------|--------------------|----------|----------|----------|------|------|----------------------------------------|----------------------------------------------------------------------
          5|5-P000                                                          |         3|                    |         3|         0|       100| 2026K|      |20(3)                                   |ON CPU(3)
           |5-P001                                                          |         4|                    |         4|         0|       100| 2289K|      |20(4)                                   |ON CPU(4)
           |5-P002                                                          |         4|                    |         4|         0|       100| 2140K|      |20(4)                                   |ON CPU(4)
           |5-P003                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P004                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P005                                                          |         4|                    |         4|         0|       100| 2026K|      |20(3),22(1)                             |ON CPU(4)
           |5-P006                                                          |         4|                    |         4|         0|       100| 2009K|      |20(4)                                   |ON CPU(4)
           |5-P007                                                          |        36|@@@@                |        36|         0|       100| 4451K|      |5(28),20(4),4(2),...                    |ON CPU(36)
           |5-P008                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P009                                                          |         4|                    |         4|         0|       100| 2075K|      |20(4)                                   |ON CPU(4)
           |5-P010                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
.
.
.




Activity Timeline based on ASH
-----------------------------------------------

           |             |      |      |          |          |   AVERAGE|TOP                                     |                                                                      |                                                            |AVERAGE
           |             |      |      |          |          |    ACTIVE|ACTIVE                                  |TOP                                                                   |TOP                                                         |ACTIVE SESSIONS
INSTANCE_ID|DURATION_SECS|PGA   |TEMP  |       CPU|     OTHER|  SESSIONS|PLAN LINES                              |ACTIVITIES                                                            |PROCESSES                                                   |GRAPH
-----------|-------------|------|------|----------|----------|----------|----------------------------------------|----------------------------------------------------------------------|------------------------------------------------------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
          5|            1|      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            2|      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          6              | 1699K|      |         0|         1|         1|2(1)                                    |PX Nsq: PQ load info query(1)                                         |6-sqlplus.exe(1)                                            |*
          5|            3|  122M|   15M|        28|         2|        30|20(16),14(14)                           |ON CPU(28),enq: XL - fault extent map(1),os thread startup(1)         |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@@@@@@@@@@@@@**
          6              |   99M|   14M|        24|         5|        29|20(16),14(13)                           |ON CPU(24),enq: XL - fault extent map(4),os thread startup(1)         |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@@@@@@@@@*****
          5|            4|   50M| 6291K|        17|         0|        17|20(15),14(2)                            |ON CPU(17)                                                            |5-P001(1),5-P002(1),5-P003(1),5-P004(1),5-P005(1),...       |@@@@@@@@@@@@@@@@@
          6              |   32M|      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@
          5|            5|   33M|      |        16|         0|        16|20(15),22(1)                            |ON CPU(16)                                                            |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@
          6              |   32M|      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@
          5|            6|   33M|      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@
          6              |   38M| 7340K|        16|         0|        16|20(15),14(1)                            |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P004(1),6-P005(1),...       |@@@@@@@@@@@@@@@@
          5|            7| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            8| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            9| 4451K|      |         1|         0|         1|6(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           10| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           11| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           12| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           13| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           14| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           15| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           16| 4451K|      |         1|         0|         1|11(1)                                   |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           17| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           18| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           19| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
.
.
.

Note that it is important to understand that this information doesn't tell you anything about the efficiency of the execution plan performed, it just tells you how many Parallel Slaves were active concurrently on average. Whether the operation performed is efficient or not is a different question, however even an otherwise efficient execution plan might run much longer than necessary if the work isn't distributed well among the Parallel Slaves.

- Furthermore it allows systematic troubleshooting of data distribution skew by showing the number of samples per process on exection plan line level. This makes it easy to spot those execution plan operations that were affected by data distribution skew. Armed with this knowledge it can be systematically evaluated if changing the data distribution method of the corresponding join operations allows influencing this reasonably.

The "Parallel Distribution ASH" and "Parallel Distribution Graph ASH" columns added to the DBMS_XPLAN.DISPLAY* output provide that information.

The "Parallel Distribution ASH" shows the process names along with the number of samples found (in descending order). For Parallel Slaves, this is Pxxx, for all other process names it is the actual name found in the PROCESS column. If the execution is cross-instance, the name is prefixed with the instance number:

--------------------------------------------------------------------------------------------
| Parallel Distribution ASH                             | Parallel Distribution Graph ASH  |
--------------------------------------------------------------------------------------------
|                                                       |                                  |
|                                                       |                                  |
| 6-sqlplus.exe(1)                                      | 0                                |
|                                                       |                                  |
| 5-P007(2)                                             | 0                                |
| 5-P007(28)                                            | 0000000                          |
| 5-P007(1)                                             | 0                                |
|                                                       |                                  |
|                                                       |                                  |
|                                                       |                                  |
|                                                       |                                  |
| 5-P007(1)                                             | 0                                |
|                                                       |                                  |
|                                                       |                                  |
| 5-P021(2),5-P031(2),6-P016(2),6-P031(2),5-P016(1),... | 0123456789ABCDEF0123456789A      |
|                                                       |                                  |
|                                                       |                                  |
|                                                       |                                  |
|                                                       |                                  |
|                                                       |                                  |
| 5-P001(4),5-P002(4),5-P003(4),5-P004(4),5-P006(4),... | 0123456789ABCDEF0123456789ABCDEF |
|                                                       |                                  |
| 5-P005(1)                                             | 0                                |
--------------------------------------------------------------------------------------------

Ideally the number of samples per process should be quite similar, if there is a significant difference, then very likely the underlying cause is an uneven data distribution among the Parallel Slaves.

This is how it should look like ideally:
--------------------------------------------------------------------------------------------
| Parallel Distribution ASH                             | Parallel Distribution Graph ASH  |
--------------------------------------------------------------------------------------------
| 5-P001(4),5-P002(4),5-P003(4),5-P004(4),5-P006(4),... | 0123456789ABCDEF0123456789ABCDEF |

This is how it should not look like:
--------------------------------------------------------------------------------------------
| Parallel Distribution ASH                             | Parallel Distribution Graph ASH  |
--------------------------------------------------------------------------------------------
| 5-P007(28)                                            | 0000000                          |
The "Parallel Distribution Graph ASH" attempts a graphical representation of the information that you see in the "Parallel Distribution ASH" column.

The idea of the "Graph" is that you don't need to work through all the rows of the execution plan in the "Parallel Distribution ASH" column and look at the actual sample numbers, but simply can sweep through the "Graph" in order to easily identify the potential skew candidates.

So, if you have a uniform distribution of work among the Parallel Slaves, you'll see something like this:

0123456789ABCDEF... (it's just 16 repeating hex-characters if you have more than 16 slaves sampled for an execution plan line)

But, if you have a non-uniform distribution of work among the Parallel Slaves, you'll see something like this:

000000000001111223

or in extreme cases

0000000000000

which means that only a few slaves (or only one in the last example) had to do the all of work.

If the graph doesn't correspond to what you think to see in the "Parallel Distribution ASH" column - the distribution of work looks skewed, but the graph doesn't correspond to what I've just explained, then try the "ASH,DISTRIB,TIMELINE" option instead.

In this case even a single sample of a single Parallel Slave will show up as a very wide (so this option might produce false positives):

0000000000000000000000000

which you then need to cross-check with the "Parallel Distribution ASH" column for relevance: If you have only have a few samples per line, then it is probably not relevant since you simply haven't spend significant time there.

But the advantage of this representation is that skew becomes more visible that might not be obvious when using the default DISTRIB_REL option.

The underlying reason is that the default option shows the distribution graph relative to the operation with the greatest number of samples assigned to. So if there are execution plan lines with a much higher sample number than the remaining lines (but these samples are not skewed), the graph might be so compressed that the skew doesn't become obvious.


Section Overview For Version 2.0



General Information


General information
-----------------------------------------------

SQL_ID       |CHILD_NUMBER|SQL_EXEC_START     |SQL_EXEC_ID|FORMAT_OPTION            |LAST_EXEC_SOURCE|ASH_OPTIONS             |ASH_SOURCE
-------------|------------|-------------------|-----------|-------------------------|----------------|------------------------|----------
3pfa4kgc92z10|           1|2012-10-16 10:51:59|  100663297|ADVANCED                 |SID=446@6       |ASH,DISTRIB_REL,TIMELINE|CURR

This section as in the previous version shows some general info and the options used so that it can be verified that the report is about the intended SQL execution.

Global ASH Summary


Global ASH Summary
-----------------------------------------------

INSTANCE_COUNT|FIRST_SAMPLE       |LAST_SAMPLE        |DURATION_SECS|STATUS  |SAMPLE_COUNT|CPU_SAMPLE_COUNT|PERCENTAGE_CPU|SLAVE_COUNT|AVERAGE_AS|MODULE                                                          |ACTION
--------------|-------------------|-------------------|-------------|--------|------------|----------------|--------------|-----------|----------|----------------------------------------------------------------|----------------------------------------------------------------
             2|2012-10-16 10:52:00|2012-10-16 10:52:36|           38|INACTIVE|         190|             182|            96|         59|         5|SQL*Plus                                                        |




Global ASH Summary per Instance
-----------------------------------------------

INSTANCE_ID|FIRST_SAMPLE       |LAST_SAMPLE        |START_ACTIVE|DURATION_SECS|SAMPLE_COUNT|PROCESS_COUNT|AVERAGE_AS|TIME_ACTIVE_GRAPH
-----------|-------------------|-------------------|------------|-------------|------------|-------------|----------|--------------------
          5|2012-10-16 10:52:01|2012-10-16 10:52:36|           2|           36|         111|           30|      3,08| @@@@@@@@@@@@@@@@@@@
          6|2012-10-16 10:52:00|2012-10-16 10:52:31|           1|           32|          79|           30|      2,47| @@@@@@@@@@@@@@@@@

Similar to the previous version this section shows a general summary of the ASH samples found for this SQL execution. If a cross-instance execution is detected, the summary will also be shown on instance level in addition which allows understanding to what extend the instances where involved in the execution.

Global ASH Summary for concurrent activity


Global ASH Summary for concurrent activity
-----------------------------------------------

INSTANCE_ID|SAMPLE_COUNT|CPU_SAMPLE_COUNT|PERCENTAGE_CPU|AVERAGE_AS|FOREGROUND_COUNT|BACKGROUND_COUNT|SLAVE_COUNT|CLIENT_COUNT|PROCESS_COUNT|TRANSACT_COUNT|SQL_ID_COUNT|SQL_EXECUTION_COUNT|MODULE_COUNT|ACTION_COUNT
-----------|------------|----------------|--------------|----------|----------------|----------------|-----------|------------|-------------|--------------|------------|-------------------|------------|------------
          5|           6|               2|            33|       ,16|               1|               5|          0|           1|            4|             0|           0|                  1|           1|           0
          6|           4|               1|            25|       ,11|               0|               4|          0|           1|            4|             0|           0|                  1|           0|           0

This is a new section that takes advantage of the fact that ASH data covers all activity and therefore shows a summary of the ASH samples found during the execution that do not belong to this SQL execution. This can provide important clues why you might see variations in runtime although execution plans and data are similar. Note that for cross-instance executions the concurrent activity covered is limited to the instances participating in the execution. Although in principle the activity on instances not participating can also influence this SQL execution for various reasons I have decided to exclude that information - which can of course easily be changed in the corresponding queries.

Concurrent Activity Summary (not this execution)


Concurrent Activity Summary (not this execution)
-----------------------------------------------

INSTANCE_ID|ACTIVITY                                          |ACTIVITY_CLASS      |SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
-----------|--------------------------------------------------|--------------------|------------|----------|--------------------
          5|reliable message                                  |Other               |           3|        30|@@@@@@
           |ON CPU                                            |ON CPU              |           2|        20|@@@@
           |SQL*Net break/reset to client                     |Application         |           1|        10|@@
          6|ASM file metadata operation                       |Other               |           1|        10|@@
           |enq: PV - syncstart                               |Other               |           1|        10|@@
           |control file parallel write                       |System I/O          |           1|        10|@@
           |ON CPU                                            |ON CPU              |           1|        10|@@

This is again a new section with a more detailed breakdown of the concurrent activity. For cross-instance executions this will be on instance level.

Information on Parallel Degree based on ASH


Information on Parallel Degree based on ASH
-----------------------------------------------

INSTANCE_ID|DFO   |START_ACTIVE|DURATION_SECS|SAMPLE_COUNT|PROCESS_COUNT| SET_COUNT|ASSUMED_DEGREE|ACTUAL_DEGREE|AVERAGE_AS|TIME_ACTIVE_GRAPH
-----------|------|------------|-------------|------------|-------------|----------|--------------|-------------|----------|--------------------
          5|Q1    |           2|           36|         111|           30|         2|            15|           16|      3,08| @@@@@@@@@@@@@@@@@@@
          6|Q1    |           2|           31|          78|           29|         2|            15|           16|      2,52| @@@@@@@@@@@@@@@@

This section is more or less unchanged to the previous version and only shows up if Parallel Execution gets used, you're running 11g+ and an execution plan could be found for the SQL statement.

It will show details about the different Data Flow Operations (DFOs) a Parallel Execution could consist of, in particular the activity related to each DFO, the Parallel Degree per DFO (could be different per DFO) and if the DFOs were active at the same time or not. In case of a cross-instance Parallel Execution this information will be broken down per participating instance.

Note that from 11.2.0.2 on the actual Parallel Degree is stored in the newly added PX_FLAGS column of the ASH data, so you get an additional column ACTUAL_DEGREE, whereas the ASSUMED_DEGREE uses the number of sampled slaves and the execution plan operations from the corresponding execution plan section for an educated guess about the degree.

Parallel Slave activity overview based on ASH


Parallel Slave activity overview based on ASH
-----------------------------------------------

           |                                                                |          |                    |    SAMPLE|    SAMPLE|          |      |      |TOP                                     |
           |                                                                |    SAMPLE|                    |     COUNT|     COUNT|   PERCENT|MAX   |MAX   |ACTIVE                                  |TOP
INSTANCE_ID|PROCESS                                                         |     COUNT|ACTIVITY_GRAPH      |       CPU|     OTHER|       CPU|PGA   |TEMP  |PLAN LINES                              |ACTIVITIES
-----------|----------------------------------------------------------------|----------|--------------------|----------|----------|----------|------|------|----------------------------------------|----------------------------------------------------------------------
          5|5-P000                                                          |         3|                    |         3|         0|       100| 2026K|      |20(3)                                   |ON CPU(3)
           |5-P001                                                          |         4|                    |         4|         0|       100| 2289K|      |20(4)                                   |ON CPU(4)
           |5-P002                                                          |         4|                    |         4|         0|       100| 2140K|      |20(4)                                   |ON CPU(4)
           |5-P003                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P004                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P005                                                          |         4|                    |         4|         0|       100| 2026K|      |20(3),22(1)                             |ON CPU(4)
           |5-P006                                                          |         4|                    |         4|         0|       100| 2009K|      |20(4)                                   |ON CPU(4)
           |5-P007                                                          |        36|@@@@                |        36|         0|       100| 4451K|      |5(28),20(4),4(2),...                    |ON CPU(36)
           |5-P008                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P009                                                          |         4|                    |         4|         0|       100| 2075K|      |20(4)                                   |ON CPU(4)
           |5-P010                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P011                                                          |         4|                    |         4|         0|       100| 2009K|      |20(4)                                   |ON CPU(4)
           |5-P012                                                          |         4|                    |         4|         0|       100| 2009K|      |20(4)                                   |ON CPU(4)
           |5-P013                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |5-P014                                                          |         4|                    |         4|         0|       100| 2009K|      |20(4)                                   |ON CPU(4)
           |5-P015                                                          |         4|                    |         4|         0|       100| 2009K|      |20(4)                                   |ON CPU(4)
           |5-P016                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|14(1)                                   |ON CPU(1)
           |5-P017                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|14(1)                                   |ON CPU(1)
           |5-P018                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|14(1)                                   |ON CPU(1)
           |5-P019                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|14(1)                                   |ON CPU(1)
           |5-P020                                                          |         1|                    |         0|         1|         0| 7007K| 1049K|14(1)                                   |enq: XL - fault extent map(1)
           |5-P021                                                          |         2|                    |         2|         0|       100| 9170K| 3146K|14(2)                                   |ON CPU(2)
           |5-P024                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|14(1)                                   |ON CPU(1)
           |5-P025                                                          |         1|                    |         1|         0|       100| 6680K| 1049K|14(1)                                   |ON CPU(1)
           |5-P026                                                          |         1|                    |         0|         1|         0| 6352K| 1049K|14(1)                                   |os thread startup(1)
           |5-P027                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|14(1)                                   |ON CPU(1)
           |5-P028                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|14(1)                                   |ON CPU(1)
           |5-P029                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|14(1)                                   |ON CPU(1)
           |5-P030                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|14(1)                                   |ON CPU(1)
           |5-P031                                                          |         2|                    |         2|         0|       100| 9956K| 3146K|14(2)                                   |ON CPU(2)
          6|6-P000                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P001                                                          |         4|                    |         4|         0|       100| 1961K|      |20(4)                                   |ON CPU(4)
           |6-P002                                                          |         4|                    |         4|         0|       100| 1895K|      |20(4)                                   |ON CPU(4)
           |6-P003                                                          |         3|                    |         3|         0|       100| 1961K|      |20(3)                                   |ON CPU(3)
           |6-P004                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P005                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P006                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P007                                                          |         4|                    |         4|         0|       100| 1961K|      |20(4)                                   |ON CPU(4)
           |6-P008                                                          |         4|                    |         4|         0|       100| 1961K|      |20(4)                                   |ON CPU(4)
           |6-P009                                                          |         4|                    |         4|         0|       100| 1961K|      |20(4)                                   |ON CPU(4)
           |6-P010                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P011                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P012                                                          |         4|                    |         4|         0|       100| 1895K|      |20(4)                                   |ON CPU(4)
           |6-P013                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P014                                                          |         4|                    |         4|         0|       100| 2026K|      |20(4)                                   |ON CPU(4)
           |6-P015                                                          |         4|                    |         4|         0|       100| 1961K|      |20(4)                                   |ON CPU(4)
           |6-P016                                                          |         2|                    |         1|         1|        50| 8056K| 7340K|14(2)                                   |ON CPU(1),os thread startup(1)
           |6-P017                                                          |         1|                    |         0|         1|         0| 5107K| 1049K|14(1)                                   |enq: XL - fault extent map(1)
           |6-P019                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|14(1)                                   |ON CPU(1)
           |6-P020                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|14(1)                                   |ON CPU(1)
           |6-P021                                                          |         1|                    |         1|         0|       100| 5172K| 1049K|14(1)                                   |ON CPU(1)
           |6-P022                                                          |         1|                    |         0|         1|         0| 5107K| 1049K|14(1)                                   |enq: XL - fault extent map(1)
           |6-P025                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|14(1)                                   |ON CPU(1)
           |6-P026                                                          |         1|                    |         1|         0|       100| 5172K| 1049K|14(1)                                   |ON CPU(1)
           |6-P027                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|14(1)                                   |ON CPU(1)
           |6-P028                                                          |         1|                    |         0|         1|         0| 5172K| 1049K|14(1)                                   |enq: XL - fault extent map(1)
           |6-P029                                                          |         1|                    |         0|         1|         0| 5172K| 1049K|14(1)                                   |enq: XL - fault extent map(1)
           |6-P030                                                          |         1|                    |         1|         0|       100| 5172K| 1049K|14(1)                                   |ON CPU(1)
           |6-P031                                                          |         2|                    |         2|         0|       100| 7007K| 8389K|14(2)                                   |ON CPU(2)
           |6-sqlplus.exe                                                   |         1|                    |         0|         1|         0| 1699K|      |2(1)                                    |PX Nsq: PQ load info query(1)

This new section corresponds to the "Parallel" tab of the Real-Time SQL Monitoring and only shows up if Parallel Execution was detected. In particular for 10g it is very helpful for Parallel Execution analysis since the even more helpful analysis on Execution Plan line level is not available.

It will show the activities found in the ASH data per every process sampled as part of the Parallel Execution.

The most useful information in this section is very likely the "Activity Graph" column as it allows easily spotting distribution problems, although it doesn't allow the systematic troubleshooting of such issues that the execution plan line level information does, as explained above.
Depending on the version also the "Top Activities" and "Top Active Plan Lines" will also be shown per process. As usual the N of the Top N can be configured in the configuration section of the script.

Activity Class Summary


Activity Class Summary
-----------------------------------------------

ACTIVITY_CLASS      |SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
--------------------|------------|----------|--------------------
ON CPU              |         182|        96|@@@@@@@@@@@@@@@@@@@
Other               |           6|         3|@
Concurrency         |           2|         1|




Activity Class Summary per Instance
-----------------------------------------------

INSTANCE_ID|ACTIVITY_CLASS      |SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
-----------|--------------------|------------|----------|--------------------
          5|ON CPU              |         109|        57|@@@@@@@@@@@
           |Other               |           1|         1|
           |Concurrency         |           1|         1|
          6|ON CPU              |          73|        38|@@@@@@@@
           |Other               |           5|         3|@
           |Concurrency         |           1|         1|

This is again a new section that summarizes the activity found for this SQL execution and in principle corresponds to some part of the header information shown in Real-Time SQL Monitoring.

The activity is broken down between CPU and non-CPU, and for non-CPU the different Activity Classes will be shown. In case of a cross-instance Parallel Execution this section will be repeated, this time broken down per instance.

Activity Summary


Activity Summary
-----------------------------------------------

ACTIVITY                                          |ACTIVITY_CLASS      |SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
--------------------------------------------------|--------------------|------------|----------|--------------------
ON CPU                                            |ON CPU              |         182|        96|@@@@@@@@@@@@@@@@@@@
enq: XL - fault extent map                        |Other               |           5|         3|@
os thread startup                                 |Concurrency         |           2|         1|
PX Nsq: PQ load info query                        |Other               |           1|         1|




Activity Summary per Instance
-----------------------------------------------

INSTANCE_ID|ACTIVITY                                          |ACTIVITY_CLASS      |SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
-----------|--------------------------------------------------|--------------------|------------|----------|--------------------
          5|ON CPU                                            |ON CPU              |         109|        57|@@@@@@@@@@@
           |os thread startup                                 |Concurrency         |           1|         1|
           |enq: XL - fault extent map                        |Other               |           1|         1|
          6|ON CPU                                            |ON CPU              |          73|        38|@@@@@@@@
           |enq: XL - fault extent map                        |Other               |           4|         2|
           |os thread startup                                 |Concurrency         |           1|         1|
           |PX Nsq: PQ load info query                        |Other               |           1|         1|

This new section corresponds to the previous one but shows a more granular breakdown of the activity on wait event level rather than wait class. Apart from that the same applies as above, also it will be repeated in case of a cross-instance Parallel Execution on instance level.

Activity Timeline based on ASH


Activity Timeline based on ASH
-----------------------------------------------

           |             |      |      |          |          |   AVERAGE|TOP                                     |                                                                      |                                                            |AVERAGE
           |             |      |      |          |          |    ACTIVE|ACTIVE                                  |TOP                                                                   |TOP                                                         |ACTIVE SESSIONS
INSTANCE_ID|DURATION_SECS|PGA   |TEMP  |       CPU|     OTHER|  SESSIONS|PLAN LINES                              |ACTIVITIES                                                            |PROCESSES                                                   |GRAPH
-----------|-------------|------|------|----------|----------|----------|----------------------------------------|----------------------------------------------------------------------|------------------------------------------------------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
          5|            1|      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            2|      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          6              | 1699K|      |         0|         1|         1|2(1)                                    |PX Nsq: PQ load info query(1)                                         |6-sqlplus.exe(1)                                            |*
          5|            3|  122M|   15M|        28|         2|        30|20(16),14(14)                           |ON CPU(28),enq: XL - fault extent map(1),os thread startup(1)         |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@@@@@@@@@@@@@**
          6              |   99M|   14M|        24|         5|        29|20(16),14(13)                           |ON CPU(24),enq: XL - fault extent map(4),os thread startup(1)         |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@@@@@@@@@*****
          5|            4|   50M| 6291K|        17|         0|        17|20(15),14(2)                            |ON CPU(17)                                                            |5-P001(1),5-P002(1),5-P003(1),5-P004(1),5-P005(1),...       |@@@@@@@@@@@@@@@@@
          6              |   32M|      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@
          5|            5|   33M|      |        16|         0|        16|20(15),22(1)                            |ON CPU(16)                                                            |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@
          6              |   32M|      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@
          5|            6|   33M|      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@
          6              |   38M| 7340K|        16|         0|        16|20(15),14(1)                            |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P004(1),6-P005(1),...       |@@@@@@@@@@@@@@@@
          5|            7| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            8| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            9| 4451K|      |         1|         0|         1|6(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           10| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           11| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           12| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           13| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           14| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           15| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           16| 4451K|      |         1|         0|         1|11(1)                                   |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           17| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           18| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           19| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           20| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           21| 4451K|      |         1|         0|         1|4(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           22| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           23| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           24| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           25| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           26| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           27| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           28| 4451K|      |         1|         0|         1|4(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           29| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           30| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           31| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           32| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           33| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              | 7007K| 8389K|         1|         0|         1|14(1)                                   |ON CPU(1)                                                             |6-P031(1)                                                   |@
          5|           34| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           35| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           36| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           37| 4451K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           38| 4386K|      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |         0|         0|         0|                                        |                                                                      |                                                            |

This section was previously called "Average Active Session Graph", but since a lot of information has been added it is now called "Activity Timeline" and will also be shown for serial execution if the "TIMELINE" option was specified.

In addition to the already previously available information about the average active sessions and their activity (CPU or non-CPU) plus PGA/TEMP now the top active plan lines (11g+), activities and processes per bucket will be shown. Note that the N of the "Top N sections" can be configured in the "configuration" section of the script.


Activity on execution plan line level


Activity on execution plan line level
-----------------------------------------------
Wrote file .xplan_ash_temp
SQL_ID  3pfa4kgc92z10, child number 1
-------------------------------------
select max(t1_id), max(t1_filler), max(t2_id), max(t2_filler),
max(t3_id), max(t3_filler) from ( select /*+ monitor no_merge
parallel(t1 16 2) PQ_DISTRIBUTE(T1 HASH HASH) */        t1.id     as
t1_id      , regexp_replace(t3_filler, '^\s+([[:alnum:]]+)\s+$',
lpad('\1', 10), 1, 1, 'c') as t1_filler      , v1.* from   (
select /*+ no_merge parallel(t2 16 2) parallel(t3 16 2)
PQ_DISTRIBUTE(T2 HASH HASH) */               t2.id     as t2_id
    , t2.filler as t2_filler             , t2.id2    as t2_id2
   , t3.id     as t3_id             , t3.filler as t3_filler
from               t1 t2             , t2 t3         where
 t3.id = t2.id (+)         and   regexp_replace(t3.filler,
'^([[:alnum:]]+)\s+$', lpad('\1', 10), 1, 1, 'c') =
regexp_replace(t2.filler (+), '^([[:alnum:]]+)\s+$', lpad('\1', 10), 1,
1, 'c')        ) v1      , t1 where        v1.t2_id2 = t1.id2 (+) +
2001 ) --where rownum > 1

Plan hash value: 1110592967

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Pid | Ord | Operation                               | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib | Start | Dur | Time Active Graph    | Parallel Distribution ASH                             | Parallel Distribution Graph ASH  | Activity Graph ASH  | Top 5 Activity ASH                                            |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 |     |  23 | SELECT STATEMENT                        |          |       |       |    32 (100)|          |        |      |            |       |     |                      |                                                       |                                  |                     |                                                               |
|   1 |   0 |  22 |  SORT AGGREGATE                         |          |     1 |  2145 |            |          |        |      |            |       |     |                      |                                                       |                                  |                     |                                                               |
|   2 |   1 |  21 |   PX COORDINATOR                        |          |       |       |            |          |        |      |            |    +1 |   1 |  @                   | 6-sqlplus.exe(1)                                      | 0                                |                     | PX Nsq: PQ load info query(1)                                 |
|   3 |   2 |  20 |    PX SEND QC (RANDOM)                  | :TQ10004 |     1 |  2145 |            |          |  Q1,04 | P->S | QC (RAND)  |       |     |                      |                                                       |                                  |                     |                                                               |
|   4 |   3 |  19 |     SORT AGGREGATE                      |          |     1 |  2145 |            |          |  Q1,04 | PCWP |            |   +20 |   8 |            @@@@      | 5-P007(2)                                             | 0                                |                     | ON CPU(2)                                                     |
|   5 |   4 |  18 |      VIEW                               |          |  2000K|  4091M|    32   (7)| 00:00:01 |  Q1,04 | PCWP |            |    +6 |  32 |    @@@@@@@@@@@@@@@@@ | 5-P007(28)                                            | 0000000                          | @@@                 | ON CPU(28)                                                    |
|*  6 |   5 |  17 |       HASH JOIN RIGHT OUTER             |          |  2000K|   288M|    32   (7)| 00:00:01 |  Q1,04 | PCWP |            |    +8 |   1 |     @                | 5-P007(1)                                             | 0                                |                     | ON CPU(1)                                                     |
|   7 |   6 |   4 |        PX RECEIVE                       |          |  2000 | 16000 |     2   (0)| 00:00:01 |  Q1,04 | PCWP |            |       |     |                      |                                                       |                                  |                     |                                                               |
|   8 |   7 |   3 |         PX SEND HASH                    | :TQ10002 |  2000 | 16000 |     2   (0)| 00:00:01 |  Q1,02 | P->P | HASH       |       |     |                      |                                                       |                                  |                     |                                                               |
|   9 |   8 |   2 |          PX BLOCK ITERATOR              |          |  2000 | 16000 |     2   (0)| 00:00:01 |  Q1,02 | PCWC |            |       |     |                      |                                                       |                                  |                     |                                                               |
|* 10 |   9 |   1 |           TABLE ACCESS STORAGE FULL     | T1       |  2000 | 16000 |     2   (0)| 00:00:01 |  Q1,02 | PCWP |            |       |     |                      |                                                       |                                  |                     |                                                               |
|  11 |   6 |  16 |        PX RECEIVE                       |          |  2000K|   272M|    29   (4)| 00:00:01 |  Q1,04 | PCWP |            |   +15 |   1 |         @            | 5-P007(1)                                             | 0                                |                     | ON CPU(1)                                                     |
|  12 |  11 |  15 |         PX SEND HASH                    | :TQ10003 |  2000K|   272M|    29   (4)| 00:00:01 |  Q1,03 | P->P | HASH       |       |     |                      |                                                       |                                  |                     |                                                               |
|  13 |  12 |  14 |          VIEW                           |          |  2000K|   272M|    29   (4)| 00:00:01 |  Q1,03 | PCWP |            |       |     |                      |                                                       |                                  |                     |                                                               |
|* 14 |  13 |  13 |           HASH JOIN RIGHT OUTER BUFFERED|          |  2000K|   411M|    29   (4)| 00:00:01 |  Q1,03 | PCWP |            |    +2 |  31 |  @@@@@@@@@@@@@@@@    | 5-P021(2),5-P031(2),6-P016(2),6-P031(2),5-P016(1),... | 0123456789ABCDEF0123456789A      | @@@                 | ON CPU(24),enq: XL - fault extent map(5),os thread startup(2) |
|  15 |  14 |   8 |            PX RECEIVE                   |          |  2000 |   212K|     2   (0)| 00:00:01 |  Q1,03 | PCWP |            |       |     |                      |                                                       |                                  |                     |                                                               |
|  16 |  15 |   7 |             PX SEND HASH                | :TQ10000 |  2000 |   212K|     2   (0)| 00:00:01 |  Q1,00 | P->P | HASH       |       |     |                      |                                                       |                                  |                     |                                                               |
|  17 |  16 |   6 |              PX BLOCK ITERATOR          |          |  2000 |   212K|     2   (0)| 00:00:01 |  Q1,00 | PCWC |            |       |     |                      |                                                       |                                  |                     |                                                               |
|* 18 |  17 |   5 |               TABLE ACCESS STORAGE FULL | T1       |  2000 |   212K|     2   (0)| 00:00:01 |  Q1,00 | PCWP |            |       |     |                      |                                                       |                                  |                     |                                                               |
|  19 |  14 |  12 |            PX RECEIVE                   |          |  2000K|   204M|    27   (4)| 00:00:01 |  Q1,03 | PCWP |            |       |     |                      |                                                       |                                  |                     |                                                               |
|  20 |  19 |  11 |             PX SEND HASH                | :TQ10001 |  2000K|   204M|    27   (4)| 00:00:01 |  Q1,01 | P->P | HASH       |    +2 |   4 |  @@                  | 5-P001(4),5-P002(4),5-P003(4),5-P004(4),5-P006(4),... | 0123456789ABCDEF0123456789ABCDEF | @@@@@@@@@@@@@       | ON CPU(125)                                                   |
|  21 |  20 |  10 |              PX BLOCK ITERATOR          |          |  2000K|   204M|    27   (4)| 00:00:01 |  Q1,01 | PCWC |            |       |     |                      |                                                       |                                  |                     |                                                               |
|* 22 |  21 |   9 |               TABLE ACCESS STORAGE FULL | T2       |  2000K|   204M|    27   (4)| 00:00:01 |  Q1,01 | PCWP |            |    +4 |   1 |   @                  | 5-P005(1)                                             | 0                                |                     | ON CPU(1)                                                     |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1
   5 - SEL$2 / from$_subquery$_001@SEL$1
   6 - SEL$2
  10 - SEL$2 / T1@SEL$2
  13 - SEL$3 / V1@SEL$2
  14 - SEL$3
  18 - SEL$3 / T2@SEL$3
  22 - SEL$3 / T3@SEL$3

Outline Data
-------------

  /*+
      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('11.2.0.2')
      DB_VERSION('11.2.0.2')
      ALL_ROWS
      OUTLINE_LEAF(@"SEL$3")
      OUTLINE_LEAF(@"SEL$2")
      OUTLINE_LEAF(@"SEL$1")
      NO_ACCESS(@"SEL$1" "from$_subquery$_001"@"SEL$1")
      NO_ACCESS(@"SEL$2" "V1"@"SEL$2")
      FULL(@"SEL$2" "T1"@"SEL$2")
      LEADING(@"SEL$2" "V1"@"SEL$2" "T1"@"SEL$2")
      USE_HASH(@"SEL$2" "T1"@"SEL$2")
      PQ_DISTRIBUTE(@"SEL$2" "T1"@"SEL$2" HASH HASH)
      SWAP_JOIN_INPUTS(@"SEL$2" "T1"@"SEL$2")
      FULL(@"SEL$3" "T3"@"SEL$3")
      FULL(@"SEL$3" "T2"@"SEL$3")
      LEADING(@"SEL$3" "T3"@"SEL$3" "T2"@"SEL$3")
      USE_HASH(@"SEL$3" "T2"@"SEL$3")
      PQ_DISTRIBUTE(@"SEL$3" "T2"@"SEL$3" HASH HASH)
      SWAP_JOIN_INPUTS(@"SEL$3" "T2"@"SEL$3")
      END_OUTLINE_DATA
  */

Predicate Information (identified by operation id):
---------------------------------------------------

   6 - access("V1"."T2_ID2"="T1"."ID2"+2001)
  10 - storage(:Z>=:Z AND :Z<=:Z)
  14 - access("T3"."ID"="T2"."ID" AND  REGEXP_REPLACE ("T3"."FILLER",'^([[:alnum:]]+)\s+$','        \1',1,1,'c',)
  18 - storage(:Z>=:Z AND :Z<=:Z)
  22 - storage(:Z>=:Z AND :Z<=:Z)

Column Projection Information (identified by operation id):
-----------------------------------------------------------

   1 - (#keys=0) MAX()[22], MAX()[22], MAX()[22], MAX()[100], MAX()[100], MAX()[4000]
   2 - SYS_OP_MSR()[4280]
   3 - (#keys=0) SYS_OP_MSR()[4280]
   4 - (#keys=0) SYS_OP_MSR()[4280]
   5 - "T1_ID"[NUMBER,22], "T1_FILLER"[VARCHAR2,4000], "T2_ID"[NUMBER,22], "T2_FILLER"[VARCHAR2,100],
       "T3_ID"[NUMBER,22], "T3_FILLER"[VARCHAR2,100]
   6 - (#keys=1) "T1"."ID"[NUMBER,22], "V1"."T2_ID"[NUMBER,22], "V1"."T2_FILLER"[VARCHAR2,100],
       "T3_FILLER"[VARCHAR2,100], "V1"."T3_ID"[NUMBER,22]
   7 - "T1"."ID2"+2001[22], "T1"."ID"[NUMBER,22], "T1"."ID2"[NUMBER,22]
   8 - (#keys=1) "T1"."ID2"+2001[22], "T1"."ID"[NUMBER,22], "T1"."ID2"[NUMBER,22]
   9 - "T1"."ID"[NUMBER,22], "T1"."ID2"[NUMBER,22]
  10 - "T1"."ID"[NUMBER,22], "T1"."ID2"[NUMBER,22]
  11 - "V1"."T2_ID2"[NUMBER,22], "V1"."T2_ID"[NUMBER,22], "V1"."T2_FILLER"[VARCHAR2,100], "T3_FILLER"[VARCHAR2,100],
       "V1"."T3_ID"[NUMBER,22]
  12 - (#keys=1) "V1"."T2_ID2"[NUMBER,22], "V1"."T2_ID"[NUMBER,22], "V1"."T2_FILLER"[VARCHAR2,100],
       "T3_FILLER"[VARCHAR2,100], "V1"."T3_ID"[NUMBER,22]
  13 - "V1"."T2_ID"[NUMBER,22], "V1"."T2_FILLER"[VARCHAR2,100], "V1"."T2_ID2"[NUMBER,22], "V1"."T3_ID"[NUMBER,22],
       "T3_FILLER"[VARCHAR2,100]
  14 - (#keys=2) "T2"."ID"[NUMBER,22], "T3"."ID"[NUMBER,22], "T2"."FILLER"[VARCHAR2,100], "T2"."ID2"[NUMBER,22],
       "T3"."FILLER"[VARCHAR2,100]
  15 - "T2"."ID"[NUMBER,22],  REGEXP_REPLACE ("T2"."FILLER",'^([[:alnum:]]+)\s+$','        \1',1,1,'c',[4000], "T2"."FILLER"[VARCHAR2,100], "T2"."ID2"[NUMBER,22]
  16 - (#keys=2) "T2"."ID"[NUMBER,22],  REGEXP_REPLACE ("T2"."FILLER",'^([[:alnum:]]+)\s+$','        \1',1,1,'c',[4000], "T2"."FILLER"[VARCHAR2,100], "T2"."ID2"[NUMBER,22]
  17 - "T2"."ID"[NUMBER,22], "T2"."ID2"[NUMBER,22], "T2"."FILLER"[VARCHAR2,100]
  18 - "T2"."ID"[NUMBER,22], "T2"."ID2"[NUMBER,22], "T2"."FILLER"[VARCHAR2,100]
  19 - "T3"."ID"[NUMBER,22],  REGEXP_REPLACE ("T3"."FILLER",'^([[:alnum:]]+)\s+$','        \1',1,1,'c',[4000], "T3"."FILLER"[VARCHAR2,100]
  20 - (#keys=2) "T3"."ID"[NUMBER,22],  REGEXP_REPLACE ("T3"."FILLER",'^([[:alnum:]]+)\s+$','        \1',1,1,'c',[4000], "T3"."FILLER"[VARCHAR2,100]
  21 - "T3"."ID"[NUMBER,22], "T3"."FILLER"[VARCHAR2,100]
  22 - "T3"."ID"[NUMBER,22], "T3"."FILLER"[VARCHAR2,100]

This section is pretty much unchanged to the previous version and shows the execution plan (if available) along with the activity per execution plan line, as explained in the original post for version 1.0 of the script. Note that the script detects whether an execution plan is available or not and shows the activity per execution plan line in a different format if no execution plan could be found.

A note to RAC users: In versions prior to 11.2.0.2 the execution plan can only be pulled from the local instance - in worst case this execution plan is an incorrect one, since for the same SQL_ID and CHIlD_CURSOR different plans could be in the different Library Caches of the RAC instances.

From 11.2.0.2 on the correct execution plan will be pulled from the corresponding RAC instance by using an (undocumented) function that allows a "remote" instance execution of a query.

Experimental Stuff


There is a global switch _EXPERIMENTAL at the beginning of the configuration section.

By default this is disabled because the stuff shown could be called "unreliable" and potentially "misleading" information.

If you enable it by setting the configuration switch to an empty string, the I/O figures from the ASH data (only from 11.2+ on) will be shown at various places of the report. Note that this data is unreliable and usually falls short of the actual activity (I've never seen it reporting more than the actual activities). Since sometimes unreliable figures can be much better than nothing at all you can enable it in such cases where you want for example get an idea if the I/O was in the range of MBs or GBs - this is something you should be able to tell from the ASH data.

Likewise the average and median wait times from ASH will be shown at different places of the report if experimental is turned on.

It is important to understand what these wait times are: These are waits that were "in-flight", not completed when the sampling took place.

Doing statistical analysis based on such sampled, in-flight wait times is sometimes called "Bad ASH math", but again, if you know what you are doing and keep telling yourself what you're looking at, there might be cases where this information could be useful, for example, if you see that hundreds or thousands of those "in-flight" waits were sampled with a typical wait time of 0.5 secs (for example a multiblock read) where you expect a typical wait time of 0.005 secs. This might be an indication that something was broken or went wrong and could be worth further investigation.

This is what the affected sections look like with experimental turned on:

Concurrent Activity Summary (not this execution)


Concurrent Activity Summary (not this execution)
-----------------------------------------------

INSTANCE_ID|ACTIVITY                                          |ACTIVITY_CLASS      |AVG_TIM_WAIT_MS|MED_TIM_WAIT_MS|SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
-----------|--------------------------------------------------|--------------------|---------------|---------------|------------|----------|--------------------
          5|reliable message                                  |Other               |          978,8|           1001|           3|        30|@@@@@@
           |ON CPU                                            |ON CPU              |               |               |           2|        20|@@@@
           |SQL*Net break/reset to client                     |Application         |            102|            102|           1|        10|@@
          6|ASM file metadata operation                       |Other               |          350,6|          350,6|           1|        10|@@
           |enq: PV - syncstart                               |Other               |          259,2|          259,2|           1|        10|@@
           |control file parallel write                       |System I/O          |           92,1|           92,1|           1|        10|@@
           |ON CPU                                            |ON CPU              |               |               |           1|        10|@@

Note again that the wait times shown (average and median) are not true wait times since the wait was ongoing when the sample of the session was taken, which means that it wasn't completed yet, so the actual wait time for that wait will have been longer, and most of the waits won't be covered by the sampling anyway, so as already explained, you need to be very catious with that information.

Global I/O Summary based on ASH


Global I/O Summary based on ASH
-----------------------------------------------

          |TOTAL |TOTAL |READ  |WRITE |TOTAL |TOTAL |TOTAL |READ  |WRITE |IO    |AVG   |MEDIAN|AVG   |MEDIAN|
          |READ  |WRITE |IO    |IO    |READ  |WRITE |IO    |IO    |IO    |LAYER |READ  |READ  |WRITE |WRITE |CELL
DURATION  |IO    |IO    |REQS  |REQS  |IO    |IO    |LAYER |BYTES |BYTES |BYTES |REQ   |REQ   |REQ   |REQ   |OFFL
SECS      |REQS  |REQS  |PERSEC|PERSEC|BYTES |BYTES |BYTES |PERSEC|PERSEC|PERSEC|SIZE  |SIZE  |SIZE  |SIZE  |EFF
----------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|-----
        38|   27 |   49 |    1 |    1 | 6857K|   12M|   32M|  180K|  327K|  835K|  254K|  254K|  254K|  254K| -64%




Global I/O Summary per Instance based on ASH
-----------------------------------------------

           |          |TOTAL |TOTAL |READ  |WRITE |TOTAL |TOTAL |TOTAL |READ  |WRITE |IO    |AVG   |MEDIAN|AVG   |MEDIAN|
           |          |READ  |WRITE |IO    |IO    |READ  |WRITE |IO    |IO    |IO    |LAYER |READ  |READ  |WRITE |WRITE |CELL
           |DURATION  |IO    |IO    |REQS  |REQS  |IO    |IO    |LAYER |BYTES |BYTES |BYTES |REQ   |REQ   |REQ   |REQ   |OFFL
INSTANCE_ID|SECS      |REQS  |REQS  |PERSEC|PERSEC|BYTES |BYTES |BYTES |PERSEC|PERSEC|PERSEC|SIZE  |SIZE  |SIZE  |SIZE  |EFF
-----------|----------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|-----
          5|        38|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |   0%
          6|        33|   27 |   49 |    1 |    1 | 6857K|   12M|   32M|  208K|  377K|  962K|  254K|  254K|  254K|  254K| -64%

This section, only available from 11.2 on, and only shown when the so called "experimental" mode is enabled (disabled by default, see the configuration section of the script).

From 11.2 on Oracle enriches the ASH data with accumulated statistics related to DB Time, CPU Time and I/O activity. This is a new approach since the data is not truly sampled, but accumulated from sample to sample, so in theory represents exact delta figures.

Note that this also means that the historic ASH data written to AWR (all samples every tenth second) requires these values to be aggregated for all samples in between that are not written to AWR in order to have meaningful information in these columns of the historic ASH data.

However, as it turns out, at least in 11.2, obviously not all I/O is covered by these statistics, for example I/O to the TEMP tablespace is not represented correctly and usually falls short of the actual I/O performed.

Furthermore there seem to be inconsistencies in the data that could indicate that it is not necessarily a reliable data source (the script to some extent attempts to detect such outliers and filter them out). Hence that information can be quite incorrect and therefore it is marked as "experimental". Nevertheless it can be much better than no I/O related information at all, therefore I decided to add it as a separate section.

Note that the I/O layer figures can be more than simply read plus write I/O, because these values include any software mirroring performed by Oracle via the ASM layer. So for example any write to ASM with ASM normal redundancy will be doubled in the I/O layer figures.

Please note furthermore that the Cell Offload Efficiency figure is only relevant to Exadata environments where the smart scan capabilities can reduce the actual amount of I/O. Of course you can easily end up with negative efficiency percentages if a lot of mirroring during writing takes place, or HCC compressed data gets uncompressed in the cells and sent to the compute nodes.

Parallel Slave activity overview based on ASH


Parallel Slave activity overview based on ASH
-----------------------------------------------

           |                                                                |          |                    |    SAMPLE|    SAMPLE|          |      |      |      |      |READ  |WRITE |      |      |IO    |READ  |WRITE |IO_LAY|AVG   |MEDIAN|AVG   |MEDIAN|TOP                                     |
           |                                                                |    SAMPLE|                    |     COUNT|     COUNT|   PERCENT|MAX   |MAX   |READ  |WRITE |REQ   |REQ   |READ  |WRITE |LAYER |BYTES |BYTES |BYTES |RE_REQ|RE_REQ|WR_REQ|WR_REQ|ACTIVE                                  |TOP
INSTANCE_ID|PROCESS                                                         |     COUNT|ACTIVITY_GRAPH      |       CPU|     OTHER|       CPU|PGA   |TEMP  |REQS  |REQS  |PERSEC|PERSEC|BYTES |BYTES |BYTES |PERSEC|PERSEC|PERSEC|SIZE  |SIZE  |SIZE  |SIZE  |PLAN LINES                              |ACTIVITIES
-----------|----------------------------------------------------------------|----------|--------------------|----------|----------|----------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|----------------------------------------|----------------------------------------------------------------------
          5|5-P000                                                          |         3|                    |         3|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(3)                                   |ON CPU(3)
           |5-P001                                                          |         4|                    |         4|         0|       100| 2289K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P002                                                          |         4|                    |         4|         0|       100| 2140K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P003                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P004                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P005                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(3),22(1)                             |ON CPU(4)
           |5-P006                                                          |         4|                    |         4|         0|       100| 2009K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P007                                                          |        36|@@@@                |        36|         0|       100| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |5(28),20(4),4(2),...                    |ON CPU(36)
           |5-P008                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P009                                                          |         4|                    |         4|         0|       100| 2075K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P010                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P011                                                          |         4|                    |         4|         0|       100| 2009K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P012                                                          |         4|                    |         4|         0|       100| 2009K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P013                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P014                                                          |         4|                    |         4|         0|       100| 2009K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P015                                                          |         4|                    |         4|         0|       100| 2009K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |5-P016                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P017                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P018                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P019                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P020                                                          |         1|                    |         0|         1|         0| 7007K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |enq: XL - fault extent map(1)
           |5-P021                                                          |         2|                    |         2|         0|       100| 9170K| 3146K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(2)                                   |ON CPU(2)
           |5-P024                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P025                                                          |         1|                    |         1|         0|       100| 6680K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P026                                                          |         1|                    |         0|         1|         0| 6352K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |os thread startup(1)
           |5-P027                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P028                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P029                                                          |         1|                    |         1|         0|       100| 6286K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P030                                                          |         1|                    |         1|         0|       100| 6221K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |5-P031                                                          |         2|                    |         2|         0|       100| 9956K| 3146K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(2)                                   |ON CPU(2)
          6|6-P000                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P001                                                          |         4|                    |         4|         0|       100| 1961K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P002                                                          |         4|                    |         4|         0|       100| 1895K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P003                                                          |         3|                    |         3|         0|       100| 1961K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(3)                                   |ON CPU(3)
           |6-P004                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P005                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P006                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P007                                                          |         4|                    |         4|         0|       100| 1961K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P008                                                          |         4|                    |         4|         0|       100| 1961K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P009                                                          |         4|                    |         4|         0|       100| 1961K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P010                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P011                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P012                                                          |         4|                    |         4|         0|       100| 1895K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P013                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P014                                                          |         4|                    |         4|         0|       100| 2026K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P015                                                          |         4|                    |         4|         0|       100| 1961K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |20(4)                                   |ON CPU(4)
           |6-P016                                                          |         2|                    |         1|         1|        50| 8056K| 7340K|    0 |   18 |    0 |    9 |    0 | 4571K| 9142K|    0 | 2286K| 4571K|      |      |  254K|  254K|14(2)                                   |ON CPU(1),os thread startup(1)
           |6-P017                                                          |         1|                    |         0|         1|         0| 5107K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |enq: XL - fault extent map(1)
           |6-P019                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P020                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P021                                                          |         1|                    |         1|         0|       100| 5172K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P022                                                          |         1|                    |         0|         1|         0| 5107K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |enq: XL - fault extent map(1)
           |6-P025                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P026                                                          |         1|                    |         1|         0|       100| 5172K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P027                                                          |         1|                    |         1|         0|       100| 5107K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P028                                                          |         1|                    |         0|         1|         0| 5172K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |enq: XL - fault extent map(1)
           |6-P029                                                          |         1|                    |         0|         1|         0| 5172K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |enq: XL - fault extent map(1)
           |6-P030                                                          |         1|                    |         1|         0|       100| 5172K| 1049K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |14(1)                                   |ON CPU(1)
           |6-P031                                                          |         2|                    |         2|         0|       100| 7007K| 8389K|   27 |   31 |   14 |   16 | 6857K| 7873K|   23M| 3428K| 3936K|   11M|  254K|  254K|  254K|  254K|14(2)                                   |ON CPU(2)
           |6-sqlplus.exe                                                   |         1|                    |         0|         1|         0| 1699K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |2(1)                                    |PX Nsq: PQ load info query(1)

If on 11.2 and the already explained "experimental" mode is enabled this will also include the (possibly unreliable) I/O figures per process.

Activity Class Summary


Activity Class Summary
-----------------------------------------------

ACTIVITY_CLASS      |AVG_TIM_WAIT_MS|MED_TIM_WAIT_MS|SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
--------------------|---------------|---------------|------------|----------|--------------------
ON CPU              |               |               |         182|        96|@@@@@@@@@@@@@@@@@@@
Other               |          373,6|          392,7|           6|         3|@
Concurrency         |          358,9|          358,9|           2|         1|




Activity Class Summary per Instance
-----------------------------------------------

INSTANCE_ID|ACTIVITY_CLASS      |AVG_TIM_WAIT_MS|MED_TIM_WAIT_MS|SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
-----------|--------------------|---------------|---------------|------------|----------|--------------------
          5|ON CPU              |               |               |         109|        57|@@@@@@@@@@@
           |Other               |          461,7|          461,7|           1|         1|
           |Concurrency         |            382|            382|           1|         1|
          6|ON CPU              |               |               |          73|        38|@@@@@@@@
           |Other               |          355,9|          347,7|           5|         3|@
           |Concurrency         |          335,8|          335,8|           1|         1|

Note that the same applies as above - the average and median wait times shown are not true wait times and therefore shouldn't be taken as such - these are sampled, "in-flight" waits not completed yet.

Activity Summary


Activity Summary
-----------------------------------------------

ACTIVITY                                          |ACTIVITY_CLASS      |AVG_TIM_WAIT_MS|MED_TIM_WAIT_MS|SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
--------------------------------------------------|--------------------|---------------|---------------|------------|----------|--------------------
ON CPU                                            |ON CPU              |               |               |         182|        96|@@@@@@@@@@@@@@@@@@@
enq: XL - fault extent map                        |Other               |            408|          437,7|           5|         3|@
os thread startup                                 |Concurrency         |          358,9|          358,9|           2|         1|
PX Nsq: PQ load info query                        |Other               |          201,3|          201,3|           1|         1|




Activity Summary per Instance
-----------------------------------------------

INSTANCE_ID|ACTIVITY                                          |ACTIVITY_CLASS      |AVG_TIM_WAIT_MS|MED_TIM_WAIT_MS|SAMPLE_COUNT|PERCENTAGE|ACTIVITY_GRAPH
-----------|--------------------------------------------------|--------------------|---------------|---------------|------------|----------|--------------------
          5|ON CPU                                            |ON CPU              |               |               |         109|        57|@@@@@@@@@@@
           |os thread startup                                 |Concurrency         |            382|            382|           1|         1|
           |enq: XL - fault extent map                        |Other               |          461,7|          461,7|           1|         1|
          6|ON CPU                                            |ON CPU              |               |               |          73|        38|@@@@@@@@
           |enq: XL - fault extent map                        |Other               |          394,6|          392,7|           4|         2|
           |os thread startup                                 |Concurrency         |          335,8|          335,8|           1|         1|
           |PX Nsq: PQ load info query                        |Other               |          201,3|          201,3|           1|         1|

Same as above, at activity granularity.

Activity Timeline based on ASH


Activity Timeline based on ASH
-----------------------------------------------

           |             |      |      |      |      |READ  |WRITE |      |      |IO    |READ  |WRITE |IO_LAY|AVG   |MEDIAN|AVG   |MEDIAN|          |          |   AVERAGE|TOP                                     |                                                                      |                                                            |AVERAGE
           |             |      |      |READ  |WRITE |REQ   |REQ   |READ  |WRITE |LAYER |BYTES |BYTES |BYTES |RE_REQ|RE_REQ|WR_REQ|WR_REQ|          |          |    ACTIVE|ACTIVE                                  |TOP                                                                   |TOP                                                         |ACTIVE SESSIONS
INSTANCE_ID|DURATION_SECS|PGA   |TEMP  |REQS  |REQS  |PERSEC|PERSEC|BYTES |BYTES |BYTES |PERSEC|PERSEC|PERSEC|SIZE  |SIZE  |SIZE  |SIZE  |       CPU|     OTHER|  SESSIONS|PLAN LINES                              |ACTIVITIES                                                            |PROCESSES                                                   |GRAPH
-----------|-------------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|------|----------|----------|----------|----------------------------------------|----------------------------------------------------------------------|------------------------------------------------------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
          5|            1|      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            2|      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          6              | 1699K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         0|         1|         1|2(1)                                    |PX Nsq: PQ load info query(1)                                         |6-sqlplus.exe(1)                                            |*
          5|            3|  122M|   15M|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        28|         2|        30|20(16),14(14)                           |ON CPU(28),enq: XL - fault extent map(1),os thread startup(1)         |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@@@@@@@@@@@@@**
          6              |   99M|   14M|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        24|         5|        29|20(16),14(13)                           |ON CPU(24),enq: XL - fault extent map(4),os thread startup(1)         |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@@@@@@@@@*****
          5|            4|   50M| 6291K|    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        17|         0|        17|20(15),14(2)                            |ON CPU(17)                                                            |5-P001(1),5-P002(1),5-P003(1),5-P004(1),5-P005(1),...       |@@@@@@@@@@@@@@@@@
          6              |   32M|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@
          5|            5|   33M|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        16|         0|        16|20(15),22(1)                            |ON CPU(16)                                                            |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@
          6              |   32M|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P003(1),6-P004(1),...       |@@@@@@@@@@@@@@@@
          5|            6|   33M|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |        16|         0|        16|20(16)                                  |ON CPU(16)                                                            |5-P000(1),5-P001(1),5-P002(1),5-P003(1),5-P004(1),...       |@@@@@@@@@@@@@@@@
          6              |   38M| 7340K|    0 |   18 |    0 |   18 |    0 | 4571K| 9142K|    0 | 4571K| 9142K|      |      |  254K|  254K|        16|         0|        16|20(15),14(1)                            |ON CPU(16)                                                            |6-P000(1),6-P001(1),6-P002(1),6-P004(1),6-P005(1),...       |@@@@@@@@@@@@@@@@
          5|            7| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            8| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|            9| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|6(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           10| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           11| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           12| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           13| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           14| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           15| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           16| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|11(1)                                   |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           17| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           18| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           19| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           20| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           21| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|4(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           22| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           23| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           24| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           25| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           26| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           27| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           28| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|4(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           29| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           30| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           31| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           32| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           33| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              | 7007K| 8389K|   27 |   31 |   27 |   31 | 6857K| 7873K|   23M| 6857K| 7873K|   23M|  254K|  254K|  254K|  254K|         1|         0|         1|14(1)                                   |ON CPU(1)                                                             |6-P031(1)                                                   |@
          5|           34| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           35| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           36| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           37| 4451K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |
          5|           38| 4386K|      |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |    0 |      |      |      |      |         1|         0|         1|5(1)                                    |ON CPU(1)                                                             |5-P007(1)                                                   |@
          6              |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |      |         0|         0|         0|                                        |                                                                      |                                                            |

From 11.2 on, and if the "experimental" mode is enabled (as explained above already), the I/O figures per bucket will also be shown. Although not part of the experimental stuff, please note that in particular the TEMP figures have turned out not to be very reliable, furthermore short peaks in PGA / TEMP usage are not well represented in the ASH data.