How to Tune Using v$mystat
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.
8- You may need to alter the script to set your ORACLE environment variables.
Enjoy!
Marc
