RMAN is designed to complete a backup or restore as quikly and efficiently as possible. But if a job takes longer than expected to complete it can be confusing trying to determine:
- What precisely is RMAN doing at any particular time?
- Is RMAN hung or just slow?
- How far into the backup/restore has it got?
- How much more work is there to go?
Knowing just how much processing has been done so far is often crucial when trying to decide whether or not to wait for job completion.
RMAN script to monitor Backup and restore operation progress
The following script will allow you to monitor progress of an RMAN backup or Restore from 4 different perspectives (channel, session wait events,
datafiles, backuppieces). The script is run from SQLPlus and takes a date input value in the format ‘dd-mon-rr hh24:mi:ss’. The date supplied does not have to be precise and can be taken from the rman log of the job that is running e.g.
From log: Recovery Manager: Release 11.2.0.2.0 - Production on Wed Aug 22 11:01:37 2012 So you could use: SQL>@monitor '22-aug-12 11:00:00'
You can run this script at any time if you suspect that rman is taking longer than expected – simply spool the results to a file and rerun the script periodically
to check that the job is progressing.
REM -------------------------------
REM Script to monitor rman backup/restore operations
REM To run from sqlplus: @monitor '[dd-mon-rr hh24:mi:ss]'
REM Example:
--SQL>spool monitor.out
--SQL>@monitor '06-aug-12 16:38:03'
REM where [date] is the start time of your rman backup or restore job
REM Run monitor script periodically to confirm rman is progessing
REM -------------------------------
alter session set nls_date_format='dd-mon-rr hh24:mi:ss';
set lines 1500
set pages 100
col CLI_INFO format a10
col spid format a5
col ch format a20
col seconds format 999999.99
col filename format a65
col bfc format 9
col "% Complete" format 999.99
col event format a40
set numwidth 10
select sysdate from dual;
REM gv$session_longops (channel level)
prompt
prompt Channel progress - gv$session_longops:
prompt
select s.inst_id, o.sid, CLIENT_INFO ch, context, sofar, totalwork,
round(sofar/totalwork*100,2) "% Complete"
FROM gv$session_longops o, gv$session s
WHERE opname LIKE 'RMAN%'
AND opname NOT LIKE '%aggregate%'
AND o.sid=s.sid
AND totalwork != 0
AND sofar <> totalwork;
REM Check wait events (RMAN sessions) - this is for CURRENT waits only
REM use the following for 11G+
prompt
prompt Session progess - CURRENT wait events and time in wait so far:
prompt
select inst_id, sid, CLIENT_INFO ch, seq#, event, state, wait_time_micro/1000000 seconds
from gv$session where program like '%rman%' and
wait_time = 0 and
not action is null;
REM use the following for 10G
--select inst_id, sid, CLIENT_INFO ch, seq#, event, state, seconds_in_wait secs
--from gv$session where program like '%rman%' and
--wait_time = 0 and
--not action is null;
REM gv$backup_async_io
prompt
prompt Disk (file and backuppiece) progress - includes tape backuppiece
prompt if backup_tape_io_slaves=TRUE:
prompt
select s.inst_id, a.sid, CLIENT_INFO Ch, a.STATUS,
open_time, round(BYTES/1024/1024,2) "SOFAR Mb" , round(total_bytes/1024/1024,2)
TotMb, io_count,
round(BYTES/TOTAL_BYTES*100,2) "% Complete" , a.type, filename
from gv$backup_async_io a, gv$session s
where not a.STATUS in ('UNKNOWN')
and a.sid=s.sid and open_time > to_date('&1', 'dd-mon-rr hh24:mi:ss') order by 2,7;
REM gv$backup_sync_io
prompt
prompt Tape backuppiece progress (only if backup_tape_io_slaves=FALSE):
prompt
select s.inst_id, a.sid, CLIENT_INFO Ch, filename, a.type, a.status, buffer_size bsz, buffer_count bfc,
open_time open, io_count
from gv$backup_sync_io a, gv$session s
where
a.sid=s.sid and
open_time > to_date('&1', 'dd-mon-rr hh24:mi:ss') ;
REM -------------------------------
Sample output
Here’s sample output from running the script.
SQL>@monitor '02-aug-12 17:12:00'
SYSDATE
------------------
02-aug-12 17:12:27
Channel progress - v$session_longops
SID CH CONTEXT SOFAR TOTALWORK % Complete
---------- -------------------- ---------- ---------- ---------- ----------
16 rman channel=t1 1 35068 1186752 2.95
148 rman channel=t2 1 117242 422400 27.76
Session progess - CURRENT wait events and time in wait
SID CH SEQ# EVENT STATE SECONDS
---------- -------------------- ---------- ---------------------------------------- ------------------- ----------
143 8200 SQL*Net message from client WAITING 207.01
Disk (file and backuppiece) progress - v$backup_async_io
SID CH STATUS OPEN_TIME SOFAR Mb TOTMB % Complete TYPE FILENAME
---------- -------------------- ----------- ------------------ ---------- ---------- ---------- --------- -----------------------------------------------------------------
16 rman channel=t1 IN PROGRESS 02-aug-12 17:12:20 137.99 8704 1.59 INPUT /ora_data/app/oracle/oradata/orcl/sh.dbf
16 rman channel=t1 IN PROGRESS 02-aug-12 17:12:20 136.99 567.5 24.14 INPUT /ora_data/app/oracle/oradata/orcl/users01.dbf
148 rman channel=t2 IN PROGRESS 02-aug-12 17:12:15 305.99 1680 18.21 INPUT /ora_data/app/oracle/oradata/orcl/undotbs01.dbf
148 rman channel=t2 IN PROGRESS 02-aug-12 17:12:15 305.99 880 34.77 INPUT /ora_data/app/oracle/oradata/orcl/sysaux01.dbf
148 rman channel=t2 IN PROGRESS 02-aug-12 17:12:15 304.99 740 41.22 INPUT /ora_data/app/oracle/oradata/orcl/system01.dbf
Tape backuppiece progress - v$backup_sync_io
SID CH FILENAME TYPE STATUS BSZ BFC OPEN IO_COUNT
---------- -------------------- ----------------------------------------------------------------- --------- ----------- ---------- --- ------------------ ----------
16 rman channel=t1 ksnhla1b_1_1 OUTPUT IN PROGRESS 262144 4 02-aug-12 17:12:20 1092
148 rman channel=t2 ktnhla1c_1_1 OUTPUT IN PROGRESS 262144 4 02-aug-12 17:12:15 2968
SQL>@monitor '02-aug-12 17:12:00'
SYSDATE
------------------
02-aug-12 17:13:19
Channel progress - v$session_longops
SID CH CONTEXT SOFAR TOTALWORK % Complete
---------- -------------------- ---------- ---------- ---------- ----------
16 rman channel=t1 1 181950 1186752 15.33
148 rman channel=t2 1 249722 422400 59.12
Session progess - CURRENT wait events and time in wait
SID CH SEQ# EVENT STATE SECONDS
---------- -------------------- ---------- ---------------------------------------- ------------------- ----------
.10
143 8200 SQL*Net message from client WAITING 258.83
148 rman channel=t2 7941 RMAN backup & recovery I/O WAITING .05
Disk (file and backuppiece) progress - v$backup_async_io
SID CH STATUS OPEN_TIME SOFAR Mb TOTMB % Complete TYPE FILENAME
---------- -------------------- ----------- ------------------ ---------- ---------- ---------- --------- -----------------------------------------------------------------
16 rman channel=t1 IN PROGRESS 02-aug-12 17:12:20 854.99 8704 9.82 INPUT /ora_data/app/oracle/oradata/orcl/sh.dbf
16 rman channel=t1 FINISHED 02-aug-12 17:12:20 567.5 567.5 100.00 INPUT /ora_data/app/oracle/oradata/orcl/users01.dbf
148 rman channel=t2 IN PROGRESS 02-aug-12 17:12:15 650.99 1680 38.75 INPUT /ora_data/app/oracle/oradata/orcl/undotbs01.dbf
148 rman channel=t2 IN PROGRESS 02-aug-12 17:12:15 650.99 880 73.98 INPUT /ora_data/app/oracle/oradata/orcl/sysaux01.dbf
148 rman channel=t2 IN PROGRESS 02-aug-12 17:12:15 649.99 740 87.84 INPUT /ora_data/app/oracle/oradata/orcl/system01.dbf
Tape backuppiece progress - v$backup_sync_io
SID CH FILENAME TYPE STATUS BSZ BFC OPEN IO_COUNT
------ ---------- --- ------------------ ----------
16 rman channel=t1 ksnhla1b_1_1 OUTPUT IN PROGRESS 262144 4 02-aug-12 17:12:20 4575
148 rman channel=t2 ktnhla1c_1_1 OUTPUT IN PROGRESS 262144 4 02-aug-12 17:12:15 6957
Tips for interpretting the results
Channel progress – v$session_longops
– only ACTIVE channels are reported
– check that % Complete is increasing
Session progress – CURRENT wait events and time in wait
– Waits on ‘RMAN backup & recovery I/O‘ events are considered normal during backup and restore operations and indicate IO to disk.
– Use this query to identify excessive waits on any Oracle or Media manager related resources.
– only CURRENT wait events are reported.
– The session with NULL CH value is the RMAN client – this is always idle when the physical backup or restore is in progress.
– if SEQ# and EVENT do not change this is the same wait, check seconds in wait.
– if EVENT does not change and SEQ# has increased this is a different wait on the same event.
Disk (file and backuppiece) progress – v$backup_async_io
– all datafiles are listed here plus any DISK backuppieces
– if backup_tape_io_slaves=TRUE then stats for the tape backuppiece will also be listed here
Tape backuppiece progress – v$backup_sync_io
– if you find that this query returns stats for any DISK files then RMAN is using synchronous io.
– check if the IO_COUNT is increasing.
– if IO_COUNT does NOT increase and status is ‘IN PROGRESS’ check the IO_COUNT for the corresponding datafiles. For this channel as this may simply be that we are scanning the datafiles and finding nothing to write