Drill down to sql_id execution details in ASH

Some times ago I explained how we can link a huge PGA or TEMP consumption to a sql_id over a period of time into this blog post.

Now I need to extract this information not only per sql_id but also per execution. This is not so simple to extract from ash as the same session could execute many times the same sql_id over a period of time.

Hopefully, since 11g the sql_exec_id column has been added to the v$active_session_history and dba_hist_active_sess_history views. You can find a very useful description of this column into this blog post from Tanel Poder.

Basically, the sql_exec_id is a unique identifier of a sql_id execution on the database. That way we are now able to know if an ash entry for this sql_id is linked to a new execution (means new sql_exec_id) or is showing a long running execution (means same sql_exec_id).

We are also able to retrieve some useful metrics as avg, min, max execution time: You can see some good examples of sql_exec_id usage into Kyle Hailey’s blog post or Karl Arao’s one.

Back to my need:

Let’s suppose that I found (Thanks to the sql provided into this post) that the sql_id “btvk5dzpdmadh” is responsible of about 2Gb of pga over allocation during a period of time:

SQL_ID            PGA_MB         %
------------- ---------- --------- ----------
btvk5dzpdmadh       2394    100.00 **********

Now I can drill down to details to get the pga over allocation per execution that way:

alter session set nls_date_format='YYYY/MM/DD HH24:MI:SS';
alter session set nls_timestamp_format='YYYY/MM/DD HH24:MI:SS';

select sql_id,
      starting_time,
      end_time,
 (EXTRACT(HOUR FROM run_time) * 3600
                    + EXTRACT(MINUTE FROM run_time) * 60
                    + EXTRACT(SECOND FROM run_time)) run_time_sec,
      READ_IO_BYTES,
      PGA_ALLOCATED PGA_ALLOCATED_BYTES,
      TEMP_ALLOCATED TEMP_ALLOCATED_BYTES
from  (
select
       sql_id,
       max(sample_time - sql_exec_start) run_time,
       max(sample_time) end_time,
       sql_exec_start starting_time,
       sum(DELTA_READ_IO_BYTES) READ_IO_BYTES,
       sum(DELTA_PGA) PGA_ALLOCATED,
       sum(DELTA_TEMP) TEMP_ALLOCATED
       from
       (
       select sql_id,
       sample_time,
       sql_exec_start,
       DELTA_READ_IO_BYTES,
       sql_exec_id,
       greatest(PGA_ALLOCATED - first_value(PGA_ALLOCATED) over (partition by sql_id,sql_exec_id order by sample_time rows 1 preceding),0) DELTA_PGA,
       greatest(TEMP_SPACE_ALLOCATED - first_value(TEMP_SPACE_ALLOCATED) over (partition by sql_id,sql_exec_id order by sample_time rows 1 preceding),0) DELTA_TEMP
       from
       dba_hist_active_sess_history
       where
       sample_time >= to_date ('2013/04/16 00:00:00','YYYY/MM/DD HH24:MI:SS')
       and sample_time < to_date ('2013/04/16 03:10:00','YYYY/MM/DD HH24:MI:SS')
       and sql_exec_start is not null
       and IS_SQLID_CURRENT='Y'
       )
group by sql_id,SQL_EXEC_ID,sql_exec_start
order by sql_id
)
where sql_id = 'btvk5dzpdmadh'
order by sql_id, run_time_sec desc;

It will produces this kind of output:

SQL_ID        STARTING_TIME       END_TIME            RUN_TIME_SEC READ_IO_BYTES PGA_ALLOCATED_BYTES TEMP_ALLOCATED_BYTES
------------- ------------------- ------------------- ------------ ------------- ------------------- --------------------
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 03:09:56    11095.559    2.0417E+10           240123904           2642411520
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 03:09:56    11095.559    2.2207E+10           181993472           2233466880
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 03:09:56    11095.559    2.4342E+10           192610304           2453667840
btvk5dzpdmadh 2013/04/16 00:13:43 2013/04/16 03:09:56    10573.559    1.3095E+10           212074496           1142947840
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 02:10:10     7509.398    1.9374E+10           200540160           2076180480
btvk5dzpdmadh 2013/04/16 00:26:32 2013/04/16 02:05:19     5927.907    6603603968           226099200            251658240
btvk5dzpdmadh 2013/04/16 01:37:19 2013/04/16 03:09:56     5557.559    7589232640           245497856            639631360
btvk5dzpdmadh 2013/04/16 00:05:22 2013/04/16 01:36:57     5495.072    4285022208           237371392            125829120
btvk5dzpdmadh 2013/04/16 02:12:54 2013/04/16 03:09:56     3422.559    7433412608           237371392            209715200
btvk5dzpdmadh 2013/04/16 02:29:17 2013/04/16 03:09:56     2439.559    2776473600           288489472            146800640
btvk5dzpdmadh 2013/04/16 02:05:43 2013/04/16 02:29:02     1399.436    1841930240           126484480             62914560
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 00:22:59     1078.508    1548386304            19333120
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 00:13:38      517.558     652337152            19202048
btvk5dzpdmadh 2013/04/16 00:23:08 2013/04/16 00:26:29      201.867     439246848            29425664
btvk5dzpdmadh 2013/04/16 02:10:57 2013/04/16 02:12:50      113.706      97910784            53673984
btvk5dzpdmadh 2013/04/16 00:05:01 2013/04/16 00:05:17       16.703      22503424                   0

As you can see we retrieved:

  • Start time of the execution
  • End time of the execution
  • The run time of the execution
  • The number of READ_IO_BYTES of the execution
  • The PGA and TEMP over allocation of the execution

Remarks:

  1. The dba_hist_active_sess_history view is no so accurate as only a subset of the rows coming from v$active_session_history are flushed into the dba_hist_active_sess_history view.
  2. This SQL works as of 11.2.0.1.
  3. You need to purchase the Diagnostic Pack in order to be allowed to query the “v$active_session_history” view.
  4. This query is useful to diagnose “huge” PGA or TEMP consumption. It is not so helpful to find out which execution used exactly how much PGA or TEMP (As it may used already pre-allocated PGA or TEMP space and did not need over allocation: See the columns definition in the beginning of this post)
About these ads
  1. Leave a comment

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Follow

Get every new post delivered to your Inbox.

Join 657 other followers

%d bloggers like this: