Showing posts with label 10gR2. Show all posts
Showing posts with label 10gR2. Show all posts

Sunday, June 29, 2014

New Version Of XPLAN_ASH Utility

A new version 4.1 of the XPLAN_ASH utility is available for download.

As usual the latest version can be downloaded here.

This version in particular supports now the new 12c "Adaptive" plan feature - previous versions don't cope very well with those if you don't add the "ADAPTIVE" formatting option manually.

Here are the notes from the change log:

- GV$SQL_MONITOR and GV$SQL_PLAN_MONITOR can now be customized in the
settings as table names in case you want to use your own custom monitoring repository that copies data from GV$SQL_MONITOR and GV$SQL_PLAN_MONITOR in order to keep/persist monitoring data. The tables need to have at least those columns that are used by XPLAN_ASH from the original views

- The "Activity Timeline based on ASH" for RAC Cross Instance Parallel Execution shows an additional line break for the GLOBAL summary

- Fixed various bugs related to some figures when analyzing Cross Instance RAC Parallel Execution

- The new "GLOBAL" aggregation level for Cross Instance RAC Parallel Execution (see version 4.0 change log below) is now also shown in the "Information on Parallel Degree based on ASH" section

- The "Parallel Distribution ASH" column on execution plan line level now can show process information taken from Real-Time SQL Monitoring for those processes that are not found in ASH samples.
This effectively means that with monitoring information available for every plan line every involved process will now be shown along with its ASH sample count and rows produced

So some processes will show up now with a sample count of 0.

The idea behind this is to provide more information about row distribution even for those lines/processes that are not covered by the ASH samples.
Previously the rowcount produced was only shown for those processes covered in ASH samples

The new behaviour is default - if you find the output messy you can return to previous behaviour (show only rowcounts for processes found in ASH samples) by setting the new configuration switch "show_monitor_rowcount" to any other value than the default of "YES"

- The "Real-Time SQL Monitoring" information on execution plan line level now includes the read and write request information ("ReadReq", "WriteReq")

- The I/O figures based on ASH now include the new "DELTA_READ_MEM_BYTES" information that was added in 12c. This applies to the following sections:
  - SQL Statement I/O Summary based on ASH
  - Parallel Worker activity overview based on ASH
  - Activity Timeline based on ASH

The "Read Mem Bytes" seems to correspond to the "logical read bytes from cache" statistics, so any direct path reads are not covered by this value

- Added some more verbose description in the "Note" sections how to handle long lines. XPLAN_ASH now does a SET TRIMSPOOL ON if you want to spool the output to a file

- Whenever the output referred to DFOs this was changed to "DFO TREE", which is the correct term

- The "Parallel Worker activity overview based on ASH" section now shows a blank line between the sections which should make this section more readable

- Adaptive plans are now supported by XPLAN_ASH

Note they don't work well with previous versions, the formatting of the inactive lines breaks and the overall information can be misleading if you don't add manually the "ADAPTIVE" formatting option

If XPLAN_ASH detects an adaptive plan, it will always force the ADAPTIVE formatting option.
This also means that Adaptive plans for the time being won't work with SASH as SASH doesn't collect the OTHER_XML column from GV$SQL_PLAN
You could manually add that column to SASH_SQLPLANS and add the column to the "sash_pkg.get_sqlplans" procedure - this is a CLOB column, but INSERT / SELECT should work I think
The view SASH_PLAN_TABLE needs also to be modified to select the OTHER_XML column instead of a dummy NULL

Although this output is less readable than the "faked" output that shows only the plan operations that are actually in use, it is the only simple way how ASH/MONITOR data can be related to execution plan lines, as these hold the information with the actual plan line, not the one that is made up by DBMS_XPLAN.DISPLAY* based on the DISPLAY_MAP information in the OTHER_XML column

Hence I decided for the time being to use the same approach as 12c Real-Time SQL Monitoring and always show the full/adaptive shape of the plan

Another challenge for XPLAN_ASH with adaptive plans is the possibly changing PLAN_HASH_VALUE during execution.

XPLAN_ASH extracts the PLAN_HASH_VALUE from ASH/MONITOR when trying to get the plan from DBA_HIST_SQL_PLAN.

Hence XPLAN_ASH now needs to take care to extract the most recent PLAN_HASH_VALUE, previously it didn't matter as it wasn't supposed to change during execution. This seems to work based on my tests, but it's something to keep in mind

- The new "gather stats on load" 12c feature implies for INSERT...SELECT statements that the cursor will immediately be invalidated/removed from the Library Cache after (successful) execution. So now such
INSERT...SELECT behave like CTAS which also gets removed immediately. This is a pity as you won't be able to pick up the plan from the Library Cache after the execution completes using XPLAN_ASH (or any other tool using DBMS_XPLAN.DISPLAY*).

Although V$SQL_PLAN_MONITOR might keep plan for some time after the execution, it can't be used as input to DBMS_XPLAN.DISPLAY*, hence this isn't a viable workaround. In principle however this isn't a good thing as the SQL and plan information might be missing from AWR / STATSPACK reports due to the
immediate invalidation/removal.

At the time being the only viable workaround known to me for this is to prevent the "gather stats on load" feature either via parameter "_optimizer_gather_stats_on_load" or hint "no_gather_optimizer_statistics", or via using pre-12c optimizer feature settings which implicitly disables the feature which is of course not
really a good workaround as the feature itself might be rather desirable

Saturday, March 29, 2014

New Version Of XPLAN_ASH Utility

A minor update 4.01 to the XPLAN_ASH utility is available for download.

As usual the latest version can be downloaded here.

These are the notes from the change log:

- More info for RAC Cross Instance Parallel Execution: Many sections now show a GLOBAL aggregate info in addition to instance-specific data

- The Parallel Execution Server Set detection and ASSUMED_DEGREE info now makes use of the undocumented PX_STEP_ID and PX_STEPS_ARG info (bit mask part of the PX_FLAGS column) on 11.2.0.2+

- Since version 4.0 added from 11.2.0.2 on the PX *MAX* DOP in the "SQL statement execution ASH Summary" based on the new PX_FLAGS column of ASH it makes sense to add a PX *MIN* DOP in the summary to see at one glance if different DOPs were used or not

- The "Active DOPs" column in the "Activity Timeline based on ASH" was extended/modified: The number in parantheses is no longer the simple count of samples but the Average Active Sessions (AAS) per DFO / bucket.

From 11.2.0.2 it now shows also the DOP of the DFO in brackets, so the
output could look now like this:

1[16] (14.5)

which means DFO 1 at a DOP of 16 had an AAS value of 14.5 for this time
bucket. If there are multiple DFOs active in the time bucket, they are
separated by commas:

1[16] (3.5),2[4] (1.5)

which means DFO 1 at a DOP of 16 had an AAS value of 3.5 and DFO 2 at a
DOP of 4 had an AAS value of 1.5 for this time bucket

A new version 4.1 is already underway that includes new 12c features, so stay tuned.

Monday, December 2, 2013

New Version Of XPLAN_ASH Utility

A new version of the XPLAN_ASH tool (detailed analysis of a single SQL statement execution) is available for download. The previous post includes links to video tutorials explaining what the tool is about.

As usual the latest version can be downloaded here.

The new version comes with numerous improvements and new features. The most important ones are:

  • Real-Time SQL Monitoring info included
  • Complete coverage including recursive SQL
  • Improved performance
  • 12c compatible
  • Simplified usage

Although I unfortunately haven't managed yet to publish the remaining parts of the video tutorial based on the previous version, I hope now that the new version is out to come up with the most interesting parts soon.

You can watch this short video that demonstrates the most important improvements:


Friday, October 11, 2013

View Data Volume Estimates

When the optimizer has to estimate the data volume (the BYTES column in the plan output), it usually bases this information on the column statistics, if applicable and available (think of complex expressions).

However, whenever there is a VIEW operator in an execution plan, that represents an unmerged view, the optimizer obviously "loses" this information and starts applying defaults that are based on the column definition.

Depending on the actual content of the columns this can lead to dramatic differences in data volume estimates.

Both, under- and overestimates are possible, because for character based columns these defaults seem to be based on an assumed 50% fill grade, so a VARCHAR2(100 BYTE) column counts as 50 bytes data volume.

For multi-byte character sets the same rule applies based on the maximum width of a column using the "char" semantics, so a VARCHAR2(1000 CHAR) column counts as 2000 bytes data volume when using the AL32UTF8 character set, which is 50% of the 4000 bytes such a column could require at maximum - so with multi-byte character set this effect can be exaggerated.

The cost calculation of data access operations like full table scans isn't influenced by these different data volume estimates, but the decision for hash joins which of the two rowsources will used as hash and probe are basically driven by the estimated data volume.

Of course the cost estimates of other operations like sorts or aggregates are also based on the data volumes.

But for hash joins particularly the possible difference in data volume estimates can lead to bad decisions, using the effectively larger row source for building the hash table, and therefore leading to slower, less efficient join processing with increased memory, TEMP and CPU usage.

Here is a simple sample demonstrating the point.

First, create two tables, both using VARCHAR2(4000 BYTE) fields, but one has these fields only populated using a single character, whereas the other one fills them completely:

create table t1
as
select
        rownum as t1_id
      , cast('x' as varchar2(4000)) as large_vc1_not_filled
      , cast('x' as varchar2(4000)) as large_vc2_not_filled
      , cast('x' as varchar2(4000)) as large_vc3_not_filled
      , cast('x' as varchar2(4000)) as large_vc4_not_filled
from
        dual
connect by
        level <= 1e5
;

exec dbms_stats.gather_table_stats(null, 't1')

create table t2
as
select
        rownum as t2_id
      , rpad('x', 4000) as large_vc1_filled
      , rpad('x', 4000) as large_vc2_filled
      , rpad('x', 4000) as large_vc3_filled
      , rpad('x', 4000) as large_vc4_filled
from
        dual
connect by
        level <= 1e4
;

exec dbms_stats.gather_table_stats(null, 't2')

So what do we get if we simply join these two tables:

select * from t1, t2 where t1_id = t2_id;

-----------------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      | 10000 |   152M|       | 13773   (1)| 00:02:46 |
|*  1 |  HASH JOIN         |      | 10000 |   152M|  2448K| 13773   (1)| 00:02:46 |
|   2 |   TABLE ACCESS FULL| T1   |   100K|  1269K|       |    70   (2)| 00:00:01 |
|   3 |   TABLE ACCESS FULL| T2   | 10000 |   152M|       |  6011   (1)| 00:01:13 |
-----------------------------------------------------------------------------------

So we can see that the optimizer understands that the table with more rows actually results in a much smaller row source in terms of data volume as the character columns are only holding only a single character.

What happens if we now deliberately turn the tables into views?

select * from (select /*+ no_merge */ * from t1), (select /*+ no_merge */ * from t2) where t1_id = t2_id;

------------------------------------------------------------------------------------
| Id  | Operation           | Name | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |      | 10000 |   152M|       | 47850   (1)| 00:09:35 |
|*  1 |  HASH JOIN          |      | 10000 |   152M|    76M| 47850   (1)| 00:09:35 |
|   2 |   VIEW              |      | 10000 |    76M|       |  6011   (1)| 00:01:13 |
|   3 |    TABLE ACCESS FULL| T2   | 10000 |   152M|       |  6011   (1)| 00:01:13 |
|   4 |   VIEW              |      |   100K|   764M|       |    70   (2)| 00:00:01 |
|   5 |    TABLE ACCESS FULL| T1   |   100K|  1269K|       |    70   (2)| 00:00:01 |
------------------------------------------------------------------------------------

You can now spot what I've described above: The table T2 row source is actually 50% underestimated by the VIEW operator, (152M vs. 76M Bytes), because the character columns are actually filled to their maximum size, whereas the table T1 is heavily overestimated in size now (1269K vs. 764M (!) Bytes), and these differences mean that the hash join now uses the actually much larger row source T2 to build the hash table. You can see the effect already in the estimates of the optimizer - it assumes now a 76M TEMP space usage of the hash join instead of 2448K when simply joining the tables.

As a side note, this is one of the areas where Dynamic Sampling has a severe shortcoming when comparing the estimates to those based on actual statistics.

This is what I get when deleting the stats from both tables and running the simple join again:

exec dbms_stats.delete_table_stats(null, 't1')

exec dbms_stats.delete_table_stats(null, 't2')

select * from t1, t2 where t1_id = t2_id;

-----------------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      | 10909 |   166M|       | 49209   (1)| 00:09:51 |
|*  1 |  HASH JOIN         |      | 10909 |   166M|    83M| 49209   (1)| 00:09:51 |
|   2 |   TABLE ACCESS FULL| T2   | 10909 |    83M|       |  6011   (1)| 00:01:13 |
|   3 |   TABLE ACCESS FULL| T1   |   102K|   785M|       |    70   (2)| 00:00:01 |
-----------------------------------------------------------------------------------

Since Dynamic Sampling doesn't evaluate the average row size it uses a similar (but somewhat different) assumption as the VIEW operator, and again the hash join due to these estimates uses the "wrong" row source as source for the hash table.

And finally: It gets even worse when using the VIEW variant with Dynamic Sampling:

select * from (select /*+ no_merge */ * from t1), (select /*+ no_merge */ * from t2) where t1_id = t2_id;

------------------------------------------------------------------------------------
| Id  | Operation           | Name | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |      |   102K|  1570M|       | 49209   (1)| 00:09:51 |
|*  1 |  HASH JOIN          |      |   102K|  1570M|    83M| 49209   (1)| 00:09:51 |
|   2 |   VIEW              |      | 10909 |    83M|       |  6011   (1)| 00:01:13 |
|   3 |    TABLE ACCESS FULL| T2   | 10909 |    83M|       |  6011   (1)| 00:01:13 |
|   4 |   VIEW              |      |   102K|   785M|       |    70   (2)| 00:00:01 |
|   5 |    TABLE ACCESS FULL| T1   |   102K|   785M|       |    70   (2)| 00:00:01 |
------------------------------------------------------------------------------------

The VIEW operator now doesn't change the data volume estimate based on Dynamic Sampling information, but the hash join suddenly changes the estimated data volume to 1570M (!) bytes, because the join cardinality estimate is now 102K rows instead of the more realistic 10.000 - so the cardinality estimate is now screwed due to the VIEW operator.

Summary


If you happen to have a large discrepancy between the column definitions and the actual column usage, which is particularly relevant for character based columns, the data volume estimates can vary significantly between merged and non-merged views. The usage of multi-byte character sets can exaggerate this effect in case of char semantics.

Most significantly this can lead to bad decisions regarding hash joins, using the larger rowsource as hash table.

Whether this effect of the VIEW operator is a feature or a bug I can't tell, there might good reasons why the information about the column statistics gets lost, but it certainly can lead to performance problems in particular with hash joins.

The effect can be reproduced across all currently supported versions including 12.1.

Friday, June 14, 2013

TIMESTAMP WITH TIME ZONE Aggregation

The TIMESTAMP WITH TIME ZONE data type that got introduced a long time ago is known for some oddities, for example Tony Hasler has a nice summary of some of them here.

Here is another oddity that shows up when trying to aggregate on such a data type. Have a look at the following simple example:

create table t
as
select
        rownum as id
      , date '2000-01-01' + rownum - 1 as some_date
      , cast(date '2000-01-01' + rownum - 1 as timestamp) as some_timestamp
      , cast(date '2000-01-01' + rownum - 1 as timestamp with local time zone) as some_timestamp_with_local_tz
      , cast(date '2000-01-01' + rownum - 1 as timestamp with time zone) as some_timestamp_with_timezone
from
        dual
connect by
        level <= 1e6
;

exec dbms_stats.gather_table_stats(null, 't')

explain plan for
select count(*), some_date from t group by some_date;

explain plan for
select count(*), some_timestamp from t group by some_timestamp;

explain plan for
select count(*), some_timestamp_with_local_tz from t group by some_timestamp_with_local_tz;

explain plan for
select count(*), some_timestamp_with_timezone from t group by some_timestamp_with_timezone;

The first three all will return the same execution plan:
-----------------------------------
| Id  | Operation          | Name |
-----------------------------------
|   0 | SELECT STATEMENT   |      |
|   1 |  HASH GROUP BY     |      |
|   2 |   TABLE ACCESS FULL| T    |
-----------------------------------
 
Notice the HASH GROUP BY operation selected by default by the optimizer (which can be influenced using the [NO_]USE_HASH_AGGREGATION hint to switch between a SORT and HASH GROUP BY).

But for the TIMESTAMP WITH TIME ZONE column, the following execution plan will be shown:
-----------------------------------
| Id  | Operation          | Name |
-----------------------------------
|   0 | SELECT STATEMENT   |      |
|   1 |  SORT GROUP BY     |      |
|   2 |   TABLE ACCESS FULL| T    |
-----------------------------------
Notice the SORT GROUP BY instead - and this cannot be influenced using the above mentioned hint. So when using TIMESTAMP WITH TIME ZONE, the hash aggregation obviously isn't supported, but for all other TIMEZONE data types it is.

Depending on the scenario this might already influence the performance as the HASH based aggregation in many cases is more efficient than the sort based aggregation (bugs aside).

Things however get really bad when using Parallel Execution:

explain plan for
select /*+ parallel(t 4) */ count(*), some_date from t group by some_date;

explain plan for
select /*+ parallel(t 4) */ count(*), some_timestamp from t group by some_timestamp;

explain plan for
select /*+ parallel(t 4) */ count(*), some_timestamp_with_local_tz from t group by some_timestamp_with_local_tz;

explain plan for
select /*+ parallel(t 4) */ count(*), some_timestamp_with_timezone from t group by some_timestamp_with_timezone;

Again for the first three, we get the same execution plan:
-------------------------------------------------------------------------
| Id  | Operation               | Name     |    TQ  |IN-OUT| PQ Distrib |
-------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |          |        |      |            |
|   1 |  PX COORDINATOR         |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)   | :TQ10001 |  Q1,01 | P->S | QC (RAND)  |
|   3 |    HASH GROUP BY        |          |  Q1,01 | PCWP |            |
|   4 |     PX RECEIVE          |          |  Q1,01 | PCWP |            |
|   5 |      PX SEND HASH       | :TQ10000 |  Q1,00 | P->P | HASH       |
|   6 |       PX BLOCK ITERATOR |          |  Q1,00 | PCWC |            |
|   7 |        TABLE ACCESS FULL| T        |  Q1,00 | PCWP |            |
-------------------------------------------------------------------------

Notice how the (hash) aggregation is performed as a parallel operation (and you might even see a so called GROUP BY PUSHDOWN from 11g on represented by a second GROUP BY operation before re-distributing the data depending on the cardinalities or the usage of the [NO_]GPY_PUSHDOWN hint).

Now look closely at the execution plan of the last statement using the TIMESTAMP WITH TIME ZONE data type:
-----------------------------------------------------------------------
| Id  | Operation             | Name     |    TQ  |IN-OUT| PQ Distrib |
-----------------------------------------------------------------------
|   0 | SELECT STATEMENT      |          |        |      |            |
|   1 |  SORT GROUP BY        |          |        |      |            |
|   2 |   PX COORDINATOR      |          |        |      |            |
|   3 |    PX SEND QC (RANDOM)| :TQ10000 |  Q1,00 | P->S | QC (RAND)  |
|   4 |     PX BLOCK ITERATOR |          |  Q1,00 | PCWC |            |
|   5 |      TABLE ACCESS FULL| T        |  Q1,00 | PCWP |            |
-----------------------------------------------------------------------

So the (sort) aggregation is no longer performed in parallel and this means that the single Query Coordinator process has to perform the aggregation on its own, which clearly can be a threat when dealing with larger data sets that need to be aggregated.

Footnote


Since internally the DISTINCT / UNIQUE operator uses the same implementation as the GROUP BY operator, exactly the same limitations apply when trying to do a DISTINCT / UNIQUE on a TIMESTAMP WITH TIME ZONE data type.

I could reproduce the described behaviour on all versions tested, starting from 10.2.0.4 and including the latest 11.2.0.3.

Wednesday, May 8, 2013

New Version Of XPLAN_ASH Tool - Video Tutorial

A new major release (version 3.0) of my XPLAN_ASH tool is available for download.

You can download the latest version here.

In addition to many changes to the way the information is presented and many other smaller changes to functionality there is one major new feature: XPLAN_ASH now also supports S-ASH, the free ASH implementation.

If you run XPLAN_ASH in a S-ASH repository owner schema, it will automatically detect that and adjust accordingly.

XPLAN_ASH was tested against the latest stable version of S-ASH (2.3). There are some minor changes required to that S-ASH release in order to function properly with XPLAN_ASH. Most of them will be included in the next S-ASH release as they really are only minor and don't influence the general S-ASH functionality at all.

If you're interested in using XPLAN_ASH with an existing S-ASH installation get in touch with me so I can provide the necessary scripts that apply the necessary changes.

Rather than writing another lengthy blog post about the changes and new features introduced I thought I start a multi-part video tutorial where I explain the purpose of the tool and how to use it based on the new version - some parts of the tutorial will focus on specific functionality of the tool and are therefore probably also quite useful as some kind of general tutorial on that Oracle feature and SQL execution troubleshooting guide in general.

The tutorial will consist of six parts initially, the first two are already available - the next ones to follow over time.

Part 1: Introduction, Overview



Part 2: Usage, Parameters, Invocation



Part 3: Rowsource Statistics: TBD

Part 4: Active Session History: TBD

Part 5: Systematic Parallel Execution Skew Analysis & Troubleshooting: Coming Soon

Part 6: Experimental Stuff, Script Configuration And Internals: TBD

Feel free to post questions/requests for clarification that are not covered in the tutorials in the comments section - if there are topics of general interest I might publish a seventh part addressing those questions.

 
In future I might use that video style more often since it's a nicer way of conveying certain kind of information.

Wednesday, March 13, 2013

"Cost-free" joins - 2

In the previous post I've demonstrated an unexpected Nested Loop Join caused by an extreme data distribution. Although unexpected at first sight, the performance of the execution plan selected by the optimizer is decent - provided the estimates are in the right ballpark.

Here is another case of an unexpected execution plan, this time about Merge Joins.

Merge Joins


In order to appreciate why the execution plan encountered is unexpected, first a quick summary about how Merge Joins work:

A Merge Join is essentially a Nested Loop operation from one sorted row source into another sorted row source. In contrast to a Nested Loop the join condition is not used for a possible index-driven lookup from the driving, outer row source into the inner row source, simply because Oracle usually first needs to run separate operations on each rowsource for sorting.

This means that in most cases the Merge Join requires to sort both row sources and therefore a Hash Join is usually preferred where possible (for example, Hash Joins are only suitable for Equi-Joins, whereas a Merge Join also supports non-Equi Joins), because it only needs to "prepare" one row source for building the hash table, and can then process the second row source as it is without any further start-up cost / preparation steps.

Let's have a look at some common execution plans using Merge Joins. Consider this simple setup:

create table t1
as
select
        rownum as id
      , rpad('x', 100) as filler
from
        dual
connect by
        level <= 1e3
;

exec dbms_stats.gather_table_stats(null, 't1')

create unique index t1_idx on t1 (id);

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

exec dbms_stats.gather_table_stats(null, 't2')

So this is what a Merge Join usually looks like:

select  /*+ use_merge(t1 t2) */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id (+) = t2.fk
;

------------------------------------------------------------------------------------
| Id  | Operation           | Name | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |      |  1000K|   199M|       | 28075   (1)| 00:05:37 |
|   1 |  MERGE JOIN OUTER   |      |  1000K|   199M|       | 28075   (1)| 00:05:37 |
|   2 |   SORT JOIN         |      |  1000K|    99M|   217M| 28067   (1)| 00:05:37 |
|   3 |    TABLE ACCESS FULL| T2   |  1000K|    99M|       |  4333   (1)| 00:00:52 |
|*  4 |   SORT JOIN         |      |  1000 |   102K|       |     7  (15)| 00:00:01 |
|   5 |    TABLE ACCESS FULL| T1   |  1000 |   102K|       |     6   (0)| 00:00:01 |
------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   4 - access("T1"."ID"(+)="T2"."FK")
       filter("T1"."ID"(+)="T2"."FK")

As usual I had to force the Merge Join via a hint, since in my (default 11.2.0.1) setup a Hash Join would be preferred. Notice the two SORT JOIN operations that first create two (ideally in-memory) sorted/indexed tables from the two row sources to be joined and how the SORT JOIN on the larger row source basically determines the overall cost of this MERGE JOIN.

A corresponding Hash Join could use the smaller row source as hash table and therefore very likely would be much more efficient.

Since the MERGE JOIN usually needs to SORT both row sources it doesn't make such a big difference which of the two row sources comes first, but it is interesting to note that the MERGE JOIN is not able to "swap" the join inputs as the HASH JOIN is able to, which, in particular for outer joins, makes the MERGE JOIN less flexible.

Here is a variation of a MERGE JOIN that avoids a SORT JOIN operation. This is only supported for the "driving" row source:

select  /*+ use_merge(t1 t2) */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id = t2.fk
and     t1.id between 1 and 10
;

-----------------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |   909K|   181M|       | 28081   (1)| 00:05:37 |
|   1 |  MERGE JOIN                  |        |   909K|   181M|       | 28081   (1)| 00:05:37 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1     |    10 |  1050 |       |     3   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | T1_IDX |    10 |       |       |     2   (0)| 00:00:01 |
|*  4 |   SORT JOIN                  |        |  1000K|    99M|   217M| 28078   (1)| 00:05:37 |
|*  5 |    TABLE ACCESS FULL         | T2     |  1000K|    99M|       |  4344   (2)| 00:00:53 |
-----------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   3 - access("T1"."ID">=1 AND "T1"."ID"<=10)
   4 - access("T1"."ID"="T2"."FK")
       filter("T1"."ID"="T2"."FK")
   5 - filter("T2"."FK">=1 AND "T2"."FK"<=10)

The MERGE JOIN knows that the driving row source will be accessed in sorted order due to the suitable INDEX RANGE SCAN operation and therefore doesn't add a SORT operation on top.

If we now run the same statement using Parallel Execution (note that the statement level PARALLEL hint used in the example is only supported from 11g on), we'll see the following:

select  /*+ use_merge(t1 t2) parallel */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id = t2.fk
and     t1.id between 1 and 10
;

------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name     | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |          |   909K|   181M|       | 15594   (1)| 00:03:08 |        |      |            |
|   1 |  PX COORDINATOR                    |          |       |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)              | :TQ10001 |   909K|   181M|       | 15594   (1)| 00:03:08 |  Q1,01 | P->S | QC (RAND)  |
|   3 |    MERGE JOIN                      |          |   909K|   181M|       | 15594   (1)| 00:03:08 |  Q1,01 | PCWP |            |
|   4 |     SORT JOIN                      |          |    10 |  1050 |       |     3   (0)| 00:00:01 |  Q1,01 | PCWP |            |
|   5 |      BUFFER SORT                   |          |       |       |       |            |          |  Q1,01 | PCWC |            |
|   6 |       PX RECEIVE                   |          |    10 |  1050 |       |     3   (0)| 00:00:01 |  Q1,01 | PCWP |            |
|   7 |        PX SEND BROADCAST           | :TQ10000 |    10 |  1050 |       |     3   (0)| 00:00:01 |        | S->P | BROADCAST  |
|   8 |         TABLE ACCESS BY INDEX ROWID| T1       |    10 |  1050 |       |     3   (0)| 00:00:01 |        |      |            |
|*  9 |          INDEX RANGE SCAN          | T1_IDX   |    10 |       |       |     2   (0)| 00:00:01 |        |      |            |
|* 10 |     SORT JOIN                      |          |  1000K|    99M|   217M| 15591   (1)| 00:03:08 |  Q1,01 | PCWP |            |
|  11 |      PX BLOCK ITERATOR             |          |  1000K|    99M|       |  2407   (1)| 00:00:29 |  Q1,01 | PCWC |            |
|* 12 |       TABLE ACCESS FULL            | T2       |  1000K|    99M|       |  2407   (1)| 00:00:29 |  Q1,01 | PCWP |            |
------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   9 - access("T1"."ID">=1 AND "T1"."ID"<=10)
  10 - access("T1"."ID"="T2"."FK")
       filter("T1"."ID"="T2"."FK")
  12 - filter("T2"."FK">=1 AND "T2"."FK"<=10)

So usually, due to the way things run in parallel, Oracle assumes it cannot guarantee the order of the row source and includes a SORT operation for both row sources joined.

Although there are special cases where this could be avoided even for Parallel Execution, it looks like the code adds this SORT operation unconditionally in case of Parallel Execution. We'll see how this can become a threat in a moment.

The Special Case


Now back to the special case I want to demonstrate here. Let's have a look at the following query:

select  
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id (+) = t2.fk
and     t2.fk = 1

----------------------------------------------------------------------------------------
| Id  | Operation                     | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |        |  1000K|   199M|  4342   (1)| 00:00:53 |
|   1 |  MERGE JOIN OUTER             |        |  1000K|   199M|  4342   (1)| 00:00:53 |
|*  2 |   TABLE ACCESS FULL           | T2     |  1000K|    99M|  4339   (1)| 00:00:53 |
|*  3 |   SORT JOIN                   |        |     1 |   105 |     3  (34)| 00:00:01 |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1     |     1 |   105 |     2   (0)| 00:00:01 |
|*  5 |     INDEX UNIQUE SCAN         | T1_IDX |     1 |       |     1   (0)| 00:00:01 |
----------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   2 - filter("T2"."FK"=1)
   3 - access("T1"."ID"(+)="T2"."FK")
       filter("T1"."ID"(+)="T2"."FK")
   5 - access("T1"."ID"(+)=1)

Notice that I now got a MERGE JOIN although I haven't provided any hints to do so, so this execution plan was automatically favored by optimizer. Why?

This is a special case, because the optimizer understands that the join key is actually a single value, due to the predicate on T2.FK. So for a serial execution it doesn't bother to SORT the large row source (since it knows there will only be the value "1") and hence the MERGE JOIN comes out with a (slightly) lower cost estimate than a corresponding HASH JOIN.

It's interesting to note that in this particular case here it could even be avoided to SORT the second row source, since it, too, can only return a single value. But obviously the MERGE JOIN always runs a SORT JOIN operation on the second row source, as already outlined above.

Due to the way the data is designed and the direction of the outer join a NESTED LOOP join isn't a reasonable alternative either here.

Note that at runtime a HASH JOIN seems to be slightly more efficient in this particular case here, so this is already an indication that the cost estimates do not reflect the efficiency at runtime very well, in particular the CPU overhead of the actual join operation seems to be underestimated for the MERGE JOIN.

Now let's see what happens if we run this query using Parallel Execution:

select  /*+ parallel */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id (+) = t2.fk
and     t2.fk = 1

-----------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
-----------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |          |  1000K|   199M|  2406   (1)| 00:00:29 |        |      |            |
|   1 |  MERGE JOIN OUTER             |          |  1000K|   199M|  2406   (1)| 00:00:29 |        |      |            |
|   2 |   SORT JOIN                   |          |  1000K|    99M|  2403   (1)| 00:00:29 |        |      |            |
|   3 |    PX COORDINATOR             |          |       |       |            |          |        |      |            |
|   4 |     PX SEND QC (RANDOM)       | :TQ10000 |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,00 | P->S | QC (RAND)  |
|   5 |      PX BLOCK ITERATOR        |          |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,00 | PCWC |            |
|*  6 |       TABLE ACCESS FULL       | T2       |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,00 | PCWP |            |
|*  7 |   SORT JOIN                   |          |     1 |   105 |     3  (34)| 00:00:01 |        |      |            |
|   8 |    TABLE ACCESS BY INDEX ROWID| T1       |     1 |   105 |     2   (0)| 00:00:01 |        |      |            |
|*  9 |     INDEX UNIQUE SCAN         | T1_IDX   |     1 |       |     1   (0)| 00:00:01 |        |      |            |
-----------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   6 - filter("T2"."FK"=1)
   7 - access("T1"."ID"(+)="T2"."FK")
       filter("T1"."ID"(+)="T2"."FK")
   9 - access("T1"."ID"(+)=1)

Look very carefully at the order of the operations, and what part of the execution plan runs in parallel and what is executed serially.

This is where things become pretty weird and threatening: The TABLE ACCESS to the large row source T2 runs in parallel (with the corresponding lower cost), but the data is then handed over to the Query Coordinator for a SORT JOIN operation - which wasn't there in serial execution and is in fact unnecessary since we still have a single value in the join key.

After sorting the large row source, the MERGE JOIN operation itself is performed by the Query Coordinator, so no Parallel Execution is involved here either.

Both the serial SORT JOIN of the large row source and the MERGE JOIN operation itself are literally free of cost here, which is clearly unreasonable, in particular if the row source is very large.

Although the SORT JOIN will basically turn into a simple "BUFFER SORT" operation, since there is effectively nothing to sort, it still means that a potentially very big volume of data will have to be handed over from the Parallel Worker processes scanning the row source to the Query Coordinator - in this particular case by definition an inefficient operation, because a large data volume has to be passed from multiple Parallel Processes to the single Query Coordinator - and then this potentially very big volume of data will have to be SORTED by the Query Coordinator, which very likely means that this operation won't fit into PGA memory of that single process, hence spill to TEMP causing potentially significant additional (and unnecessary) read and write I/O, all to be done serially by the Query Coordinator.

This is a textbook example of a Parallel Execution plan that is deemed to take longer than the corresponding serial execution plan, and it is the execution plan that is preferred by the optimizer when left unhinted.

Let's have a look at the Parallel Execution plan when using a HASH JOIN:

select  /*+ parallel use_hash(t1 t2) */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id (+) = t2.fk
and     t2.fk = 1

---------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
---------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |          |  1000K|   199M|  2411   (1)| 00:00:29 |        |      |            |
|   1 |  PX COORDINATOR                   |          |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)             | :TQ10001 |  1000K|   199M|  2411   (1)| 00:00:29 |  Q1,01 | P->S | QC (RAND)  |
|*  3 |    HASH JOIN RIGHT OUTER          |          |  1000K|   199M|  2411   (1)| 00:00:29 |  Q1,01 | PCWP |            |
|   4 |     BUFFER SORT                   |          |       |       |            |          |  Q1,01 | PCWC |            |
|   5 |      PX RECEIVE                   |          |     1 |   105 |     2   (0)| 00:00:01 |  Q1,01 | PCWP |            |
|   6 |       PX SEND BROADCAST           | :TQ10000 |     1 |   105 |     2   (0)| 00:00:01 |        | S->P | BROADCAST  |
|   7 |        TABLE ACCESS BY INDEX ROWID| T1       |     1 |   105 |     2   (0)| 00:00:01 |        |      |            |
|*  8 |         INDEX UNIQUE SCAN         | T1_IDX   |     1 |       |     1   (0)| 00:00:01 |        |      |            |
|   9 |     PX BLOCK ITERATOR             |          |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,01 | PCWC |            |
|* 10 |      TABLE ACCESS FULL            | T2       |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,01 | PCWP |            |
---------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   3 - access("T1"."ID"(+)="T2"."FK")
   8 - access("T1"."ID"(+)=1)
  10 - filter("T2"."FK"=1)

Looking at the child operations' cost estimates of the HASH JOIN it becomes obvious that it is the costing of the HASH JOIN itself that makes the whole operation more costly than the MERGE JOIN, which is clearly questionable.

So the strange thing about the MERGE JOIN Parallel Execution plan is that the join operation itself is done serially, whereas the HASH JOIN execution plan, although it uses the same access to the row sources (INDEX UNIQUE SCAN and FULL TABLE SCAN), happily runs in parallel.

What causes this strange execution plan shape? Obviously it is the UNIQUE index on the other, smaller row source. Somehow the MERGE JOIN code is mislead by the UNIQUE index scan, which causes the join operation to run serially.

Replacing the UNIQUE index with a NON-UNIQUE index (and using a UNIQUE constraint on top to achieve the same uniqueness) gives this execution plan:

drop index t1_idx;

create index t1_idx on t1 (id);

alter table t1 add constraint t1_uq unique (id) using index t1_idx;

select  /*+ parallel */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id (+) = t2.fk
and     t2.fk = 1

----------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
----------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |          |  1000K|   199M|  2406   (1)| 00:00:29 |        |      |            |
|   1 |  PX COORDINATOR                    |          |       |       |            |          |        |      |            |
|   2 |   PX SEND QC (RANDOM)              | :TQ10001 |  1000K|   199M|  2406   (1)| 00:00:29 |  Q1,01 | P->S | QC (RAND)  |
|   3 |    MERGE JOIN OUTER                |          |  1000K|   199M|  2406   (1)| 00:00:29 |  Q1,01 | PCWP |            |
|   4 |     SORT JOIN                      |          |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,01 | PCWP |            |
|   5 |      PX BLOCK ITERATOR             |          |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,01 | PCWC |            |
|*  6 |       TABLE ACCESS FULL            | T2       |  1000K|    99M|  2403   (1)| 00:00:29 |  Q1,01 | PCWP |            |
|*  7 |     SORT JOIN                      |          |     1 |   105 |     3  (34)| 00:00:01 |  Q1,01 | PCWP |            |
|   8 |      BUFFER SORT                   |          |       |       |            |          |  Q1,01 | PCWC |            |
|   9 |       PX RECEIVE                   |          |     1 |   105 |     2   (0)| 00:00:01 |  Q1,01 | PCWP |            |
|  10 |        PX SEND BROADCAST           | :TQ10000 |     1 |   105 |     2   (0)| 00:00:01 |        | S->P | BROADCAST  |
|  11 |         TABLE ACCESS BY INDEX ROWID| T1       |     1 |   105 |     2   (0)| 00:00:01 |        |      |            |
|* 12 |          INDEX RANGE SCAN          | T1_IDX   |     1 |       |     1   (0)| 00:00:01 |        |      |            |
----------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   6 - filter("T2"."FK"=1)
   7 - access("T1"."ID"(+)="T2"."FK")
       filter("T1"."ID"(+)="T2"."FK")
  12 - access("T1"."ID"(+)=1)

So now we still have the unnecessary SORT JOIN operation of the large row source, but at least the SORT JOIN and MERGE JOIN operations are now executed in parallel, which should make it far less threatening.

Of course, a corresponding HASH JOIN will still be much more efficient for larger row sources, but needs to be hinted in this special case here.

Summary


For MERGE JOINs there are some special cases where the current costing model doesn't properly reflect the actual work - together with some strange behaviour of the MERGE JOIN code when using Parallel Execution this can lead to questionable execution plans preferred by the optimizer.

Carefully check the resulting execution plans when using Parallel Execution and MERGE JOINs get preferred by the optimizer.

Wednesday, February 27, 2013

"Cost-free" joins - 1

Recently I came across some interesting edge cases regarding the costing of joins. They all have in common that they result in (at first sight) unexpected execution plans, but only some of them are actual threats to performance.

Outer Joins


The first one is about outer joins with an extreme data distribution. Consider the following data setup:

create table t1
as
select
        rownum as id
      , rpad('x', 100) as filler
      , case when rownum > 1e6 then rownum end as null_fk
from
        dual
connect by
        level <= 1e6
;

exec dbms_stats.gather_table_stats(null, 't1')

create table t2
as
select
        rownum as id
      , rpad('x', 100) as filler
from
        dual
connect by
        level <= 1e6
;

exec dbms_stats.gather_table_stats(null, 't2')

create /*unique*/ index t2_idx on t2 (id);

The following query is a simple outer join between T1 and T2 and the default, unhinted execution plan that I get from 11.2.0.1 (11.1.0.7 and 10.2.0.4 show similar results):

select
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.null_fk = t2.id (+)
;

---------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |  1000K|   202M|  4204   (1)| 00:00:51 |
|   1 |  NESTED LOOPS OUTER          |        |  1000K|   202M|  4204   (1)| 00:00:51 |
|   2 |   TABLE ACCESS FULL          | T1     |  1000K|   101M|  4202   (1)| 00:00:51 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T2     |     1 |   106 |     2   (0)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN          | T2_IDX |     1 |       |     2   (0)| 00:00:01 |
---------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   4 - access("T1"."NULL_FK"="T2"."ID"(+))

The optimizer preferred a Nested Loop join albeit the fact that the number of estimated loop iterations is pretty large. Notice in particular the cost column: Although the inner rowsource is estimated to be started 1000K times, the cost of doing so corresponds to just a single execution.

For reference here is a cost estimate for a similar operation that corresponds to the expected costing model:

select  /*+ use_nl(t1 t2) */
        t1.filler as t1_filler
      , t2.filler as t2_filler
from
        t1
      , t2
where
        t1.id = t2.id (+)
;

---------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |  1000K|   202M|  3006K  (1)| 10:01:21 |
|   1 |  NESTED LOOPS OUTER          |        |  1000K|   202M|  3006K  (1)| 10:01:21 |
|   2 |   TABLE ACCESS FULL          | T1     |  1000K|   101M|  4200   (1)| 00:00:51 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T2     |     1 |   106 |     3   (0)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN          | T2_IDX |     1 |       |     2   (0)| 00:00:01 |
---------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
 
   4 - access("T1"."ID"="T2"."ID"(+))

I now had to force the Nested Loop join via a hint, because by default other join methods were preferred by the optimizer. The cost of a single iteration of the loop has now increased to 3, although the access is exactly the same as before (T2 random table access via index lookup of T2.ID), and the cost of the Nested Loop join corresponds to the known formula: Estimated starts times the cost of a single iteration, which is 3000K in this case here, plus the 4200 of the Full Table Scan for accessing the outer row source, plus CPU costing overhead.

So what makes the difference between the two? It's the data. The column name chosen for the column in T1 already reveals what's so special: The join column used (NULL_FK) is actually NULL for all rows.

The optimizer takes this into account and assumes that none of those rows from the driving row source will actually match a row of the inner row source - in fact the lookup to the inner row source could be short-circuited in some way, since a NULL value by definition isn't supposed to find a match for this join. I haven't investigated to what extent the runtime engine does this, however in the Rowsource Statistics the inner row source is started the expected number of times, although no logical I/O is recorded for it, but some CPU time, so at least some work seems to be done there.

Modifying the test case so that more of the FKs are actually non-null shows that the cost calculation is scaled accordingly. In fact the cost calculation is more or less the same than that of a corresponding inner join that could filter out those driving rows with NULL values in the join column.

The overall performance of the execution plan is quite decent, so although it looks quite unusual it performs pretty well.

In the second part I'll show another interesting, unexpected join execution plan that however can cause real performance problems.

Wednesday, February 20, 2013

QB_NAME hint query block name length limitation

Oracle 10g introduced the QB_NAME hint that can come handy in case hints need to be applied to more complex statements, in particular when possibly multiple layers of views / subqueries are involved.

Jonathan Lewis has a older blog post that describes more details.

Just in case you wonder why sometimes apparently the QB_NAME hint - along with all other hints that refer to the assigned query block name - seems to be ignored: One possible reason is that it looks like there is an undocumented length limitation of the query block names that can be assigned - 20 characters seem to be the maximum possible (I haven't checked the effect of multi-byte database character sets).

Consider this simple example:

drop table t1;

purge table t1;

create table t1
as
select
        rownum as id
      , rpad('x', 100) as filler
from
        dual
connect by
        level <= 100
;

exec dbms_stats.gather_table_stats(null, 't1')

By default Oracle 11.2.0.1 unnests the correlated subquery and runs an anti-join for the following simple query:

select 
       *
from
       t1
where
       not exists
       (
         select 
                null
         from
                t1 t1_inner
         where
                t1_inner.id = t1.id
       );

-----------------------------------
| Id  | Operation          | Name |
-----------------------------------
|   0 | SELECT STATEMENT   |      |
|*  1 |  HASH JOIN ANTI    |      |
|   2 |   TABLE ACCESS FULL| T1   |
|   3 |   TABLE ACCESS FULL| T1   |
-----------------------------------
 
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
 
   1 - SEL$5DA710D3
   2 - SEL$5DA710D3 / T1@SEL$1
   3 - SEL$5DA710D3 / T1_INNER@SEL$2

Notice the aliases and query block names assigned, like SEL$1, SEL$2 etc.

Using the QB_NAME hint the NO_UNNEST hint can be applied to the correlated subquery from the outer query block:

select /*+ no_unnest(@nested_query) */
       *
from
       t1
where
       not exists
       (
         select /*+ qb_name(nested_query) */
                null
         from
                t1 t1_inner
         where
                t1_inner.id = t1.id
       );

-----------------------------------
| Id  | Operation          | Name |
-----------------------------------
|   0 | SELECT STATEMENT   |      |
|*  1 |  FILTER            |      |
|   2 |   TABLE ACCESS FULL| T1   |
|*  3 |   TABLE ACCESS FULL| T1   |
-----------------------------------
 
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
 
   1 - SEL$1       
   2 - SEL$1        / T1@SEL$1
   3 - NESTED_QUERY / T1_INNER@NESTED_QUERY

The correlated subquery is now executed using a FILTER operator as requested. Notice the aliases and query block names, in particular for the instance of T1 at operation id = 3

Now if I repeat the same query, but use a longer query block name, the hints are effectively ignored and the default unnesting takes place again:

select /*+ no_unnest(@nested_query_longer_name) */
       *
from
       t1
where
       not exists
       (
         select /*+ qb_name(nested_query_longer_name) */
                null
         from
                t1 t1_inner
         where
                t1_inner.id = t1.id
       );

-----------------------------------
| Id  | Operation          | Name |
-----------------------------------
|   0 | SELECT STATEMENT   |      |
|*  1 |  HASH JOIN ANTI    |      |
|   2 |   TABLE ACCESS FULL| T1   |
|   3 |   TABLE ACCESS FULL| T1   |
-----------------------------------
 
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
 
   1 - SEL$5DA710D3
   2 - SEL$5DA710D3 / T1@SEL$1
   3 - SEL$5DA710D3 / T1_INNER@SEL$2

Notice how the default aliases and query block names get used although explicitly hinted.

It is probably rather uncommon to use such lengthy query block names, nevertheless it can be puzzling when hitting such an undocumented limitation.

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.