How to Tune Using v$mystat

by Pythian Marketing on Mar 21, 2013 12:00:00 AM

When reviewing the performance of some queries, it is sometimes useful to review the session statistics for each execution of the query. These session statistics complement the wait events found in ASH and trace files. The wait events do not show this information. Many of these session level statistics can be quite revealing. They can show some execution differences that are otherwise difficult, if not impossible for some, to see with trace files and ASH data.

I had a situation that required to look at these stats so I could see why one query would run fast at times and much slower at others. ASH data was not exposing this issue clearly. In order to facilitate the comparison of data from run to run, I wrote a simple wrapper ksh shell script for the query. It saves the session statistics in a table before and after the execution of the query and then prints out the statistics in a pivot report. This turned out to be very handy for me, and therefore, I chose to share it with the world. :)

Below is a sample output of the report. It prints only statistics that have changed and shows all execution stats in separate columns. The executions are labeled like “run#-HH:MI:SS.ssss”. These labels show the query’s execution sequence and elapsed time.

NAME                                  '1-00:00:00.0107' '2-00:00:00.0085' '3-00:00:00.0050' '4-00:00:00.0051' '5-00:00:00.0053'
------------------------------------- ----------------- ----------------- ----------------- ----------------- -----------------
CPU used by this session                              1                                   2                 1                 1
calls to get snapshot scn: kcmgss                     2                 3                 2                 2                 2
calls to kcmgcs                                                         4
consistent gets                                                        17
consistent gets from cache                                             17
consistent gets from cache (fastpath)                                  17
cursor authentications                                                                    1
enqueue releases                                      1                 1
enqueue requests                                      1                 1
execute count                                         2                 3                 2                 2                 2
global enqueue gets sync                              2                 2                 2
global enqueue releases                               2                 2                 2
logical read bytes from cache                                      139264
no work - consistent read gets                                         13
non-idle wait count                                   1
opened cursors cumulative                             2                 3                 2                 2                 2
opened cursors current                                1                 1                 1                 1                 1
parse count (hard)                                    1                 1
parse count (total)                                   2                 2                 2                 2                 2
pinned cursors current                                1                 1                 1                 1                 1
recursive calls                                       6                 9                 5                 5                 5
recursive cpu usage                                   1                                   2                 1                 1
session cursor cache hits                                               1
session logical reads                                                  17
session pga memory                                65536            196608            196608            196608            131072
session pga memory max                            65536            196608            196608            196608            131072
session uga memory                                                  65488             65488             65488             65488
session uga memory max                           123512            123512            123512            123512            123512
table scan blocks gotten                                               13
table scan rows gotten                                               1276
table scans (short tables)                                              1
workarea executions - optimal                         1                 1                 1                 1                 1
workarea memory allocated                                              50                37                37                37

Note that the execution time in the labels is the elapsed time difference between the capture of the before and after session stats, not the real query execution elapse. The difference should be very low, like less than 0.01s as you can see from the above durations. Also note that the PLSQL block that runs the query does not fetch the data. It only opens the cursor, which executes the query. This shows you how long the query takes to get the resultset ready and remove the network and application related overhead.

Here is the code:

#!/bin/sh

export v_sql_text=$(cat sql_runstat_source_query.sql)

echo 'Enter username:';read username
echo 'Please enter your password: ';stty -echo;read passwd;stty echo

sqlplus -S /nolog<
prompt connecting...
connect $username/$passwd

set echo off feed off verify off
set serveroutput on size 2000
col name for a50

prompt verifying the existence of the table query_stats...
declare
 table_exists number;
begin
 select count(*) into table_exists from dba_tables where owner = user and table_name='QUERY_STATS';
 if table_exists = 0 then
    execute immediate 'CREATE TABLE '||user||'.query_stats AS SELECT systimestamp as timestamp, '' '' before, 0 run, name, value FROM v\$statname NATURAL JOIN v\$mystat where 1=2';
    dbms_output.put_line('Table '||user||'.query_stats created.');
 else
    dbms_output.put_line('Warning! Table '||user||'.query_stats exists already. Appending...');
 end if;
end;
/
drop type query_stats_table_type;
create or replace type query_stats_type
as object
(TIMESTAMP TIMESTAMP(6) WITH TIME ZONE,
 BEFORE    CHAR(1),
 RUN       NUMBER,
 NAME      VARCHAR2(64),
 VALUE     NUMBER
);
/
create or replace type query_stats_table_type
as table of query_stats_type;
/
prompt executing the query and saving pre and post session stats...
declare
  next_run     number;
  stats_before query_stats_table_type;
  stats_after  query_stats_table_type;
  type cur_type is ref cursor;
  c            cur_type;
begin
  -- capturing pre-stats
  select nvl(max(run),-1)+1 into next_run from query_stats;
  SELECT query_stats_type(systimestamp, 'Y', next_run, name, value) bulk collect into stats_before FROM v\$statname NATURAL JOIN v\$mystat;
  -- executing the query from the var v_sql_text, which is loaded from file sql_runstat_source_query.sql
  open c for $v_sql_text;
  -- capturing post-stats
  next_run := next_run + 1;
  SELECT query_stats_type(systimestamp, 'N', next_run, name, value) bulk collect into stats_after FROM v\$statname NATURAL JOIN v\$mystat;
  -- saving stats
  insert into query_stats 
  select * from table(cast(stats_before as query_stats_table_type))
  union all
  select * from table(cast(stats_after as query_stats_table_type))
  ;
  commit;
end;
/

prompt getting the run id list...
col max_run new_value run noprint
select max(run) max_run from query_stats;

-- get the run ids and their durations and join them as CSVs to pass to the pivot query
col runlist new_value runs noprint
select listagg(run,',') within group (order by run) runlist
  from
       (select ''''||ceil(run/2)||'-'||duration_H_M_S||'''' run
          from ( SELECT distinct run,
                        to_char(extract(HOUR   FROM timestamp-lag(timestamp) OVER (ORDER BY name, run)),'FM00')||':'||
                        to_char(extract(MINUTE FROM timestamp-lag(timestamp) OVER (ORDER BY name, run)),'FM00')||':'||
                        to_char(extract(SECOND FROM timestamp-lag(timestamp) OVER (ORDER BY name, run)),'FM00.0000') AS duration_H_M_S
                   FROM query_stats
               )
         where duration_H_M_S is not null
           and mod(run,2)<>0
         order by 1
       )
;

prompt pivoting the run statistics where there is a value difference...
set linesize 200 trim on
select *
  from (
   select ceil(run/2)||'-'||duration_H_M_S as run,
          name,
          value_diff
     from (
           SELECT run,
                  name,
                  value,
                  value-lag(value) OVER (partition by name ORDER BY name, run) as value_diff,
                  to_char(extract(HOUR   FROM timestamp-lag(timestamp) OVER (ORDER BY name, run)),'FM00')||':'||
                  to_char(extract(MINUTE FROM timestamp-lag(timestamp) OVER (ORDER BY name, run)),'FM00')||':'||
                  to_char(extract(SECOND FROM timestamp-lag(timestamp) OVER (ORDER BY name, run)),'FM00.0000') AS duration_H_M_S
             FROM query_stats
           )
   where mod(run,2)<>0
     and value_diff > 0
   )
pivot (sum(value_diff) for run in (&runs))
order by name
;
prompt done!
exit
EOF

Some notes about it:

1- The ksh script runs an anonymous plsql block that gets dynamically modified to incorporate the statement you want to test.

2- The statement you want to test needs to be stored in a file called “sql_runstat_source_query.sql” located in the same folder as the ksh script.

3- Do not add a semi-colon at the end of your statement in the sql_runstat_source_query.sql file.

4- The query_stats table contains all the session statistics before and after each execution, not just those that changed and got printed by the pivot table. It also has the timestamp of the captures. You can therefore get more information from this data if needed. For example, you could tailor the column label to show you the full timestamp, or write your own analytics query to suit your needs.

5- The run numbers in the query_stats table are actually a serial number for the statistics capture, starting at 0. 0=first “before” capture, 1=first “after” capture, 2=second “before” capture, and so on.

6- The script will create the query_stats table if it is missing,; otherwise, it appends to it. Two user TYPEs are also created. None of these get dropped after execution so it’s up to you to remove them if you don’t want to keep them in your schema.

7- Remember to either truncate, rename, or drop the query_stats table before testing a different statement.

How to Tune Using v$mystat

No Comments Yet

Subscribe by email

Share this

How to Tune Using v$mystat

Share this

No Comments Yet

Subscribe by email