AWR reports: Measuring CPU

 

Introduction

AWR is a wonderful tool oracle has provided for database health checkup. It deals with a lot of things necessary to tune the database like TOP 5 wait events, SQL ordered by elapsed time/CPU time/Buffer gets/Physical reads etc. Among other things, the most crucial information in AWR is the amount of CPU used by the system i.e. how much of the CPU time oracle processes took for the elapsed time. When AWR deals with time, it deals with several kinds of time.

 

ELAPSED TIME: This is the time between start and end snapshots time of AWR.

Here the elapsed time is 30 mins.

 

DB TIME:  This is the time Oracle has spent responding user calls. On a busy system, this time usually greater than ELAPSED TIME. This time is the sum of total time spent in CPU and total time waiting for various non-idle events such as I/O, Enqueue etc

DB Time in the AWR printed above is 8488 mins.

 

CPU TIME:  This is the time Oracle spent on CPU i.e. using the CPU. This can also exceed ELAPSED TIME as if we have many CPUs then oracle can use each of them. For 46 CPUs, we have 46s of CPU time per sec elapsed time.

 

When it comes to CPU time, AWR refers to it by three different names:

1) CPU TIME

2) DB CPU

3) CPU USED BY THIS SESSION

 

Measuring CPU

If the CPU TIME occurs in the TOP 5 wait event, this does not necessarily indicate a problem. For example:

Here the CPU TIME is 35938s which is just 7.1 % of DB TIME.

Even if it was high, this might not indicate a problem.

It could be that the database is busy in utilizing the CPU.

 To know whether CPU TIME is a problem, we need to compare it with the available CPU power we have. If the usage is high in comparison to total CPU power, then it is serious problem and need to be addressed.

 

The formula to calculate total CPU power in seconds is:

 TOTAL CPU= NUM_CPUS*ELAPSED_TIME*60,

 where NUM_CPUs can be found from Operative system statistics section.

If we use this formula in our current scenario, we have:

Total CPU=46 *30*60=82800s.

So, we have 82800 seconds of CPU time for 1800 seconds of DB TIME.

Therefore, % of CPU used by Oracle processes= 35938/82800*100=43%.

 

i.e. CPU time/ Total CPU

This means oracle processes used 43% of total CPU power available in the system.

AWR also provides CPU consumption from OS perspective. In the Operating System Statistics, we have BUSY TIME AND IDLE TIME.

We can calculate the % CPU busy time by the formula:

 

% BUSY TIME= {BUSY_TIME/ (BUSY_TIME+IDLE_TIME)}*100

                           = {5788280/8365936}*100

                            = 69%

 

This means that the system was overall 69% was busy utilizing the CPU.

BUSY_TIME can further be divided into SYS_TIME+USER_TIME.

 

BUSY_TIME=SYS_TIME+USER_TIME

We can also calculate % of SYS_TIME and % of USER_TIME.

 

% SYS_TIME = (SYS_TIME/BUSY_TIME)*100

 

%USER_TIME = (USER_TIME/BUSY_TIME)*100

 

Applying the above formula in our present case, we have:

 

%SYS_TIME = (1487507/5788280)*100

                        = 25.7%

 

%USER_TIME = (4300773/5788280)*100

                          = 74%

   

As we can see approx 74% of CPU was accounted for USER_TIME. But this 74% is actually 74% of %BUSY_TIME i.e. 69%.

 

Therefore, 74% of 69% = 51%

This is the actual USER_TIME.

 

Similarly, for SYS_TIME 25.7% of 69%= 17.7%

This is the actual SYS_TIME.    

         

Now if we see, CPU_TIME and USER_TIME differ by 51-43=8%.

 

This means, apart from oracle processes, 8% of CPU was utilized by non oracle non system processes. It could also be that 8% of time was spent in run queue i.e. waiting for CPU. The difference could also be attributed to some bugs in kernel code as well

 

Once we find out High CPU usage is the issue, we need to find out where the maximum CPU time is getting used. If there is high CPU, then essentially, we will have to find where the CPU is spent, either in SQL execution or SQL Parsing.

If the database is doing lots of hard parse it means lack of cursor sharing resulting in thousands of statements spreading across shared pool which only differ with literal values.

We can look for SQL statements consuming High CPU.

We can look in SQL statements ordered by CPU, SQL statements ordered by Buffer gets.

However, while examining sql statements our metric value should be per execution basis.

Once the SQL is identified then it’s easy to tune it.

 

 A couple of caveats

 Analyzing CPU usage from AWR can be tricky as well. For example, if we need to calculate the CPU usage for a particular time lets say from 7:15 to 7:30, then to gather CPU information from a 60 minute report is useless. Fortunately, in 10g and above, oracle provides us with another amazing utility, the ASH which stands for active session history. By using ASH, we can go to any time period we want and see how much of the CPU was consumed for that time period.

 

Conclusion:-

AWR provides a lot of information regarding CPU utilization. But it can be tricky to get the exact details of time spent in CPU.AWR in coordination with ASH becomes power pact performance analyzer tool that put before us all the artifacts necessary to troubleshoot CPU utilization issues. What differentiates CPU TIME from other wait events is that other wait events can be measured with respect to DB TIME but CPU TIME should be measured w .r .t.  the total CPU capacity of the system.

But the question that may arise is: how much accurate does AWR report CPU usage from OS perspective. Does the output from vmstat/SAR/mpstat matches with the AWR statistic? Well it should because Oracle takes CPU from OS itself. My next effort would be to sample CPU usage from both perspective and see how much of it matches.

ADDM (Automatic Database Diagnostic Monitor) Report Generates a Three-Day Report

 

ADDM (Automatic Database Diagnostic Monitor) Report Does Not Ask for Number Of Days to Report Upon and Automatically Generates a Three-Day Report (Doc ID 2059948.1)

 

You can do this as follows:

Note: you will need suitable operating system permissions on the $ORACLE_HOME/rdbms/admin/ directory to write the files, alternatively copy them to a different location.

1. Make a backup copy of the original script which resides in $ORACLE_HOME/rdbms/admin/addmrpt.sql using a suitable operating system command e.g.:

$ cp $ORACLE_HOME/rdbms/admin/addmrpt.sql $ORACLE_HOME/rdbms/admin/addmrpt.sql.bak

2. Open the $ORACLE_HOME/rdbms/admin/addmrpt.sql script for editing
3. Modify the customer configurable variable num_days so that it reflects the number of days worth of snapshots that you want to see. For example, to see 5 days change the value to 5:

define num_days = 5;

 
Alternatively, commenting the line out will result in all snapshots being displayed (caution: this may be a long list):

-- define num_days = 3;

 

4. Save the file
5. Execute the customized report

Check the SQL having high version count in Oracle

 

SQL query having high version count in Oracle

Check the highest version count queries

-- Fetch top 10 queries causing high version count
select * from (
select  sql_text,
        version_count,
        executions,
        address
from    v$sqlarea 
order by version_count desc) where rownum <= 10;

Check the cursor shared view and reason to describe type of mismatch

select  reason
from    v$sql_shared_cursor
where   address in (
        select address from (
select address
from    v$sqlarea 
order by version_count desc) where rownum <= 10 );

Query to check excessive child cursors:

select a.cursors, a.sql_id,b.sql_text
from
(
select count(*) as cursors, ssc.sql_id
from v$sql_shared_cursor ssc
group by ssc.sql_id
order by cursors desc
) a,
(
select sa.sql_id, sa.sql_text from v$sqlarea sa
) b
where a.sql_id=b.sql_id;

Script for Purge the version count statement
Script will purge from shared pool if the version count is greater than 100. you can change the value according to your need.

set serveroutput on
DECLARE
V_SQL_ADDRESS VARCHAR2(100) := '';
BEGIN
For x_cur in (select sql_id,address,hash_Value,version_count from v$sqlarea where version_count >= 100 order by version_count desc)
loop
v_sql_address := ''''||x_cur.address||','||x_cur.hash_value||'''';
dbms_output.put_line(x_cur.sql_id||','||v_sql_address||','||x_cur.version_count);
sys.dbms_shared_pool.purge (''||x_cur.address||','||x_cur.hash_value||'','C');
end loop;
END;
/

Note:
Use dbms_shared pool package for purge from shared pool.

dbms_shared_pool.purge('ADDRESS,HASH_VALUE','C'); 
example:
EXEC sys.DBMS_SHARED_POOL.purge('000000010182AE70,1862304678', 'C');

Wait events AWR,ASH Time model scripts

Wait event for a SID:

To find currently waiting:

col WAIT_CLASS for a10
SELECT sw.inst_id,NVL(s.username, '(oracle)') AS username,
s.sid,
s.serial#,
sw.event,
sw.wait_class,
sw.wait_time,
sw.seconds_in_wait,
sw.state
FROM gv$session_wait sw,
gv$session s
WHERE s.sid = sw.sid and s.inst_id=sw.inst_id and s.sid=&sid
ORDER BY sw.seconds_in_wait DESC;

Overall waits:

COLUMN username FORMAT A20
COLUMN sid FORMAT 9999
COLUMN serial# FORMAT 9999
COLUMN event FORMAT A40
SELECT NVL(s.username, '(oracle)') AS username, s.sid,s.serial#,se.event,se.total_waits,se.total_timeouts,se.time_waited,
se.average_wait,se.max_wait,se.time_waited_micro FROM v$session_event se,v$session s WHERE s.sid = se.sid AND s.sid = &Session_ID ORDER BY se.time_waited DESC
/

Time Model:

select stat_name, value from V$SESS_TIME_MODEL where sid = &sid order by value desc;

Stats:

select vsn.name, vst.value from v$sesstat vst, v$statname vsn where vsn.statistic# = vst.statistic# and vst.value != 0 and vst.sid = &sid order by vst.value;

RealTime Monitoring for sid:

Elapsed/CPU/Read/Write MB:

SELECT *
FROM
(SELECT status,
--username,
sql_id,
sql_exec_id,
TO_CHAR(sql_exec_start,'dd-mon-yyyy hh24:mi:ss') AS sql_exec_start,
ROUND(elapsed_time/1000000) AS "Elapsed (s)",
ROUND(cpu_time /1000000) AS "CPU (s)",
buffer_gets,
ROUND(physical_read_bytes /(10241024)) AS "Phys reads (MB)",
ROUND(physical_write_bytes/(10241024)) AS "Phys writes (MB)"
FROM gv$sql_monitor where sid=&sid and inst_id=&inst_id
ORDER BY elapsed_time DESC
)
WHERE rownum<=20;

To find Each layer Time spend:

SELECT ROUND(elapsed_time /1000000) AS "Elapsed (s)",
ROUND(cpu_time /1000000,3) AS "CPU (s)",
ROUND(queuing_time /1000000,3) AS "Queuing (s)",
ROUND(user_io_wait_time /1000000,3) AS "I/O wait (s)",
ROUND(application_wait_time/1000000,3) AS "Appli wait (s)",
ROUND(concurrency_wait_time/1000000,3) AS "Concurrency wait (s)",
ROUND(cluster_wait_time /1000000,3) AS "Cluster wait (s)",
ROUND(physical_read_bytes /(10241024)) AS "Phys reads (MB)",
ROUND(physical_write_bytes /(10241024)) AS "Phys writes (MB)",
buffer_gets AS "Buffer gets",
ROUND(plsql_exec_time/1000000,3) AS "Plsql exec (s)",
ROUND(java_exec_time /1000000,3) AS "Java exec (s)"
FROM gv$sql_monitor
WHERE sid=&sid and inst_id=&inst_id;

To Find Explain plan waiting steps:

col PLAN for a150
SELECT
RPAD('(' || p.plan_line_ID || ' ' || NVL(p.plan_parent_id,'0') || ')',8) || '|' ||
RPAD(LPAD (' ', 2*p.plan_DEPTH) || p.plan_operation || ' ' || p.plan_options,60,'.') ||
NVL2(p.plan_object_owner||p.plan_object_name, '(' || p.plan_object_owner|| '.' || p.plan_object_name || ') ', '') ||
NVL2(p.plan_COST,'Cost:' || p.plan_COST,'') || ' ' ||
NVL2(p.plan_bytes||p.plan_CARDINALITY,'(' || p.plan_bytes || ' bytes, ' || p.plan_CARDINALITY || ' rows)','') || ' ' ||
NVL2(p.plan_partition_start || p.plan_partition_stop,' PStart:' || p.plan_partition_start || ' PStop:' || p.plan_partition_stop,'') ||
NVL2(p.plan_time, p.plan_time || '(s)','') AS PLAN
FROM gv$sql_plan_monitor p
WHERE sid=&sid
ORDER BY p.plan_line_id, p.plan_parent_id;

To find list the top 20 SQL having the longest elapsed time:

SELECT * FROM (SELECT status, --username, sql_id, sql_exec_id, TO_CHAR(sql_exec_start,'dd-mon-yyyy hh24:mi:ss') AS sql_exec_start, ROUND(elapsed_time/1000000) AS "Elapsed (s)", ROUND(cpu_time /1000000) AS "CPU (s)", buffer_gets, ROUND(physical_read_bytes /(1024*1024)) AS "Phys reads (MB)", ROUND(physical_write_bytes/(1024*1024)) AS "Phys writes (MB)" FROM v$sql_monitor ORDER BY elapsed_time DESC ) WHERE rownum<=20;

Currently running SQL query’s:

v$sqlarea/v$sql:

set lines 1500 pages 9999
column sid format 9999
column username format a15
column PARSING_SCHEMA_NAME format a15
column SQL_EXEC_START for a21
column sql_text format a50
column module format a35
select a.inst_id,a.sid,a.username,b.PARSING_SCHEMA_NAME,a.module,a.sql_id,a.sql_child_number child,b.plan_hash_value,to_char (a.sql_exec_start, 'dd-Mon-yyyy hh24:mi:ss') sql_exec_start,(sysdate-sql_exec_start)2460*60 SECS,b.rows_processed,a.status,substr(b.sql_text,1,50) sql_text
from gv$session a,gv$sqlarea b
where a.sql_hash_value = b.hash_value
and a.sql_address = b.address
and a.module not like '%emagent%'
and a.module not like '%oraagent.bin%'
and sql_text not like '%b.PARSING_SCHEMA_NAME%'
and a.username is not null
order by a.status;

ASH:

column my_sid format 999
column my_ser format 99999
column my_state format a30
column my_blkr format 999
select to_char(a.sample_time, 'HH24:MI:SS') MY_TIME,a.session_id MY_SID,a.session_serial# MY_SER,
DECODE(a.session_state, 'WAITING' ,a.event, a.session_state) MY_STATE,a.xid, a.sql_id,
a.blocking_session MY_BLKR
from gv$active_session_history a, dba_users u
where u.user_id = a.user_id
and a.sql_id = '&sql_id'
and a.sample_time > SYSTIMESTAMP-(2/1440);

AWR:

set lines 1000 pages 9999
SELECT s.snap_id,TO_CHAR(s.begin_interval_time, 'DD-MON HH24:MI') snap_time,ss.sql_id,ss.plan_hash_value,
ss.ROWS_PROCESSED_TOTAL,
ss.executions_delta execs,
(ss.elapsed_time_delta/1000000)/DECODE(ss.executions_delta,0,1,ss.executions_delta) ela_per_exec,
(ss.cpu_time_delta /1000000)/DECODE(ss.executions_delta,0,1,ss.executions_delta) cpu_per_exec,
ss.buffer_gets_delta /DECODE(ss.executions_delta,0,1,ss.executions_delta) lio_per_exec,
ss.disk_reads_delta /DECODE(ss.executions_delta,0,1,ss.executions_delta) pio_per_exec
FROM dba_hist_snapshot s,
dba_hist_sqlstat ss
WHERE ss.dbid = s.dbid
AND ss.instance_number = s.instance_number
AND ss.snap_id = s.snap_id
AND ss.sql_id = nvl('&sql_id','4dqs2k5tynk61')
/* and ss.executions_delta > 0 /
/ check executions_delta for 1 , if it is 0 just consider only rows proceesed and calculate total execution time = sum ( executions_delta 1 + executions_delta 0 ) */
ORDER BY s.snap_id;

TIME BASED REPORT:

select s.sql_id, sum(case when begin_interval_time = to_date('14-nov-2017 1100','dd-mon-yyyy hh24mi') then s.executions_total else 0 end) sum_after, (sum(case when begin_interval_time >= to_date('14-nov-2020 1100','dd-mon-yyyy hh24mi') then s.executions_total
else 0 end) - sum(case when begin_interval_time < to_date('14-nov-2020 1100','dd-mon-yyyy hh24mi') then s.executions_total else 0 end)) difference from dba_hist_sqlstat s,
dba_hist_snapshot sn where sn.begin_interval_time between to_date('05-nov-2020 0001','dd-mon-yyyy hh24mi') and to_date('05-nov-2020 2359','dd-mon-yyyy hh24mi') and sn.snap_id=s.snap_id group by s.sql_id order by difference desc;

select * from ( select sql_id,sql_plan_hash_value,event,sql_exec_id,sql_exec_start,current_obj#,sql_plan_line_id,sql_plan_operation,sql_plan_options,SUM (delta_read_io_requests) lio_read ,SUM (delta_read_io_bytes) pio_read ,count(*) count_1
from dba_hist_active_sess_history where sql_id='&sql_id' group by
sql_id, sql_plan_hash_value, event,sql_exec_id, sql_exec_start,
current_obj#, sql_plan_line_id, sql_plan_operation, sql_plan_options )
order by count_1 desc;

RealTime Monitoring for sql_id:

Sql monitor report:

set pagesize 0 echo off timing off linesize 1000 trimspool on trim on long 2000000 longchunksize 2000000
select
DBMS_SQLTUNE.REPORT_SQL_MONITOR(
sql_id=>'&sql_id',
report_level=>'ALL',
type=>'TEXT')
from dual;

Elapsed/CPU/Read/Write MB:

SELECT *
FROM
(SELECT status,
--username,
sql_id,
sql_exec_id,
TO_CHAR(sql_exec_start,'dd-mon-yyyy hh24:mi:ss') AS sql_exec_start,
ROUND(elapsed_time/1000000) AS "Elapsed (s)",
ROUND(cpu_time /1000000) AS "CPU (s)",
buffer_gets,
ROUND(physical_read_bytes /(10241024)) AS "Phys reads (MB)",
ROUND(physical_write_bytes/(10241024)) AS "Phys writes (MB)"
FROM gv$sql_monitor where sql_id='&sql_id' and inst_id=&inst_id
ORDER BY elapsed_time DESC
)
WHERE rownum<=20;

Restore and Recovery - Tips & Tricks

In this post I’ll share a few Tips and Tricks when managing Backup and Recovery for an Oracle Database.

When an instance abnormally terminates, the thread status (v$thread) remains OPEN because Oracle didn’t get a chance to update the status to CLOSED. On start-up, when Oracle detects that an instance thread was abnormally left open, the system monitor process will automatically perform crash recovery. This is how SMON will determine what to do:-

1 2 3 4 5 6 7 8 9 10 11 12

SELECT a.thread#, b.open_mode, a.status, CASE WHEN ((b.open_mode='MOUNTED') AND (a.status='OPEN')) THEN 'Crash Recovery Required.' WHEN ((b.open_mode='MOUNTED') AND (a.status='CLOSED')) THEN 'No Crash Recovery Required.' WHEN ((b.open_mode='READ WRITE') AND (a.status='OPEN')) THEN 'Instance is already open' ELSE 'Oh God, Please give me strength to deal with it !!' END STATUS FROM v$thread a, v$database b, v$instance c WHERE a.thread# = c.thread#;

You might have always heard/read about how SMON Process compares the SCN information in the controlfile and in the corresponding datafiles, theoretically its perfect but how about taking a peek into how SMON does that, from where and then what decision it makes, to demonstrate this:-

1 2 3 4 5 6 7 8 9 10 11 12 13

SELECT a.name, a.checkpoint_change#, b.checkpoint_change#, CASE WHEN ((a.checkpoint_change# - b.checkpoint_change#) = 0) THEN 'Startup the database normally - Check successful for this datafile' WHEN ((a.checkpoint_change# - b.checkpoint_change#) > 0) THEN 'Media Recovery is required' WHEN ((a.checkpoint_change# - b.checkpoint_change#) < 0) THEN 'Old Control File is in use, restore a newer controlfile' ELSE 'Oh God, Please give me strength to deal with it !!' END STATUS FROM v$datafile a, -- control file SCN for datafile v$datafile_header b -- datafile header SCN WHERE a.file# = b.file#;

Now the time for some tips, if you are not aware of the options preview, validate and test:-

Ever thought about PREVIEWING which backup will be required for the restore operation, here it is the preview clause.

• RMAN> restore database preview;                                             —– full listing
• RMAN> restore database preview summary;                                    —– summarize the full listing

You can use preview with any restore command, all you have to do is add preview clause at the end of restore command, it will not restore it will just give you the backup files which will be required for the restore by querying the repository ONLY it does not check that these files are physically accessible. TRY it you’ll like it.

Several times when a scenario comes where someone asks you whether this recovery is possible, at that time you would be sure about the recovery process but still I strongly suggest to validate that the backup pieces are available and structurally sound before you actually restore any datafiles, cause its really embarrassing when after committing its possible, you figure out that the backup pieces are corrupted , so for those times, here it is the validate clause.

• RMAN> restore database validate;                                            —– Checks for Physical Corruption.
• RMAN> restore database validate check logical;                    —– Checks for Physical & Logical Corruption.

You can use the validate (check logical) clause with any restore command, all you have to do is to add validate (check logical)  clause at the end of restore command, it will not restore it will just validate the backupsets/archived redo log against any physical or logical corruption, It is recommended to regularly check your backups via validate clause to check against any physical or logical corruption.

Now comes another scenario wherein you need to perform a database recovery, but you suspect one of your archived redo log files is bad. You want to perform a test to see whether all of the redo is available and can be applied. for this, here it is the test clause.

• RMAN> connect target /
• RMAN> startup mount;
• RMAN> restore database;
• RMAN> recover database test;

You can use the test clause with any recover command, all you have to do it to add test clause at the end of recover command. The test clause instructs Oracle to apply the redo necessary to perform recovery but does not make the changes permanent in the datafiles. When you recover in test mode, Oracle applies the required redo but rolls back the changes at the end of the process.