Pythian Blog: Technical Track

Viewing RMAN jobs status and output

by Rohith Kumar on Aug 26, 2011 12:00:00 AM

Yesterday I was discussing with a fellow DBA about ways to check the status of existing and/or past RMAN jobs. Good backup scripts usually write their output to some sort of log file so, checking the output is usually a straight-forward task. However, backup jobs can be scheduled in many different ways (crontab, Grid Control, Scheduled Tasks, etc) and finding the log file may be tricky if you don’t know the environment well.
Furthermore, log files may also have already been overwritten by the next backup or simply just deleted. An alternative way of accessing that information, thus, may come handy.

Fortunately, RMAN keeps the backup metadata around for some time and it can be accessed through the database’s V$ views. Obviously, if you need this information because your database just crashed and needs to be restored, the method described here is useless.

Backup jobs’ status and metadata

A lot of metadata about the RMAN backup jobs can be found in the V$RMAN_% views. These views show past RMAN jobs as well as jobs currently running. Once the jobs complete backup sets, metadata about the sets and pieces are also added to the control file and can be accessed through the V$BACKUP_% views.

For the queries in this post I need only four of those views:

V$BACKUP_SET
V$BACKUP_SET_DETAILS
V$RMAN_BACKUP_JOB_DETAILS
GV$RMAN_OUTPUT

NOTE: I haven’t tested the below in Oracle 10g or earlier.

In the query below I used these views to combine in a single query the information I’m usually interested in when verifying backup jobs:

set lines 220
set pages 1000
col cf for 9,999
col df for 9,999
col elapsed_seconds heading "ELAPSED|SECONDS"
col i0 for 9,999
col i1 for 9,999
col l for 9,999
col output_mbytes for 9,999,999 heading "OUTPUT|MBYTES"
col session_recid for 999999 heading "SESSION|RECID"
col session_stamp for 99999999999 heading "SESSION|STAMP"
col status for a10 trunc
col time_taken_display for a10 heading "TIME|TAKEN"
col output_instance for 9999 heading "OUT|INST"
select
j.session_recid, j.session_stamp,
to_char(j.start_time, 'yyyy-mm-dd hh24:mi:ss') start_time,
to_char(j.end_time, 'yyyy-mm-dd hh24:mi:ss') end_time,
(j.output_bytes/1024/1024) output_mbytes, j.status, j.input_type,
decode(to_char(j.start_time, 'd'), 1, 'Sunday', 2, 'Monday',
3, 'Tuesday', 4, 'Wednesday',
5, 'Thursday', 6, 'Friday',
7, 'Saturday') dow,
j.elapsed_seconds, j.time_taken_display,
x.cf, x.df, x.i0, x.i1, x.l,
ro.inst_id output_instance
from V$RMAN_BACKUP_JOB_DETAILS j
left outer join (select
d.session_recid, d.session_stamp,
sum(case when d.controlfile_included = 'YES' then d.pieces else 0 end) CF,
sum(case when d.controlfile_included = 'NO'
and d.backup_type||d.incremental_level = 'D' then d.pieces else 0 end) DF,
sum(case when d.backup_type||d.incremental_level = 'D0' then d.pieces else 0 end) I0,
sum(case when d.backup_type||d.incremental_level = 'I1' then d.pieces else 0 end) I1,
sum(case when d.backup_type = 'L' then d.pieces else 0 end) L
from
V$BACKUP_SET_DETAILS d
join V$BACKUP_SET s on s.set_stamp = d.set_stamp and s.set_count = d.set_count
where s.input_file_scan_only = 'NO'
group by d.session_recid, d.session_stamp) x
on x.session_recid = j.session_recid and x.session_stamp = j.session_stamp
left outer join (select o.session_recid, o.session_stamp, min(inst_id) inst_id
from GV$RMAN_OUTPUT o
group by o.session_recid, o.session_stamp)
ro on ro.session_recid = j.session_recid and ro.session_stamp = j.session_stamp
where j.start_time > trunc(sysdate)-&NUMBER_OF_DAYS
order by j.start_time;

The output of the query above looks like the one below:

SESSION SESSION OUTPUT ELAPSED TIME OUT
RECID STAMP START_TIME END_TIME MBYTES STATUS INPUT_TYPE DOW SECONDS TAKEN CF DF I0 I1 L INST
------- ------------ ------------------- ------------------- ---------- ---------- ------------- --------- ---------- ---------- ------ ------ ------ ------ ------ -----
35877 759180320 2011-08-14 19:25:29 2011-08-14 19:26:09 213 COMPLETED ARCHIVELOG Saturday 40 00:00:40
35880 759180438 2011-08-14 19:27:28 2011-08-14 19:28:02 217 COMPLETED ARCHIVELOG Saturday 34 00:00:34
35883 759180496 2011-08-14 19:28:25 2011-08-14 19:28:57 219 COMPLETED ARCHIVELOG Saturday 32 00:00:32
35886 759182786 2011-08-14 20:06:26 2011-08-14 20:24:30 14,100 FAILED DB FULL Saturday 1084 00:18:04
35888 759184489 2011-08-14 20:34:50 0 FAILED DB FULL Saturday
35890 759189013 2011-08-14 21:50:13 0 FAILED ARCHIVELOG Saturday
35892 759203414 2011-08-15 01:50:14 2011-08-15 01:53:55 875 COMPLETED ARCHIVELOG Sunday 221 00:03:41
35895 759207985 2011-08-15 03:08:15 0 FAILED ARCHIVELOG Sunday
35899 759213359 2011-08-15 04:36:27 2011-08-15 04:38:53 3,335 COMPLETED DATAFILE FULL Sunday 146 00:02:26
35907 759217815 2011-08-15 05:50:15 2011-08-15 05:50:52 229 COMPLETED ARCHIVELOG Sunday 37 00:00:37
35911 759218083 2011-08-15 05:54:43 2011-08-15 10:15:49 193,016 COMPLETED DB FULL Sunday 15666 04:21:06
35913 759232215 2011-08-15 09:50:15 2011-08-15 09:51:39 628 COMPLETED ARCHIVELOG Sunday 84 00:01:24
...
36209 760053012 2011-08-24 21:50:13 2011-08-24 21:53:21 2,422 COMPLETED ARCHIVELOG Tuesday 188 00:03:08 1
36212 760067412 2011-08-25 01:50:12 2011-08-25 01:54:17 2,514 COMPLETED ARCHIVELOG Wednesday 245 00:04:05 1
36215 760081812 2011-08-25 05:50:12 2011-08-25 05:51:40 907 COMPLETED ARCHIVELOG Wednesday 88 00:01:28 1
36218 760096215 2011-08-25 09:50:15 2011-08-25 09:51:36 737 COMPLETED ARCHIVELOG Wednesday 81 00:01:21 0 0 0 0 9 1
36221 760110617 2011-08-25 13:50:17 2011-08-25 13:54:58 3,524 COMPLETED ARCHIVELOG Wednesday 281 00:04:41 0 0 0 0 9 1
36224 760114813 2011-08-25 15:00:13 2011-08-25 19:34:55 209,491 COMPLETED DB FULL Wednesday 16482 04:34:42 3 203 0 0 17 1
36228 760125016 2011-08-25 17:50:16 2011-08-25 17:52:33 1,464 COMPLETED ARCHIVELOG Wednesday 137 00:02:17 0 0 0 0 9 1
36237 760139412 2011-08-25 21:50:12 2011-08-25 21:52:44 1,879 COMPLETED ARCHIVELOG Wednesday 152 00:02:32 1 0 0 0 8 1
36240 760153813 2011-08-26 01:50:13 2011-08-26 01:57:04 5,123 COMPLETED ARCHIVELOG Thursday 411 00:06:51 1 0 0 0 17 1

Most of the columns above have either a obvious meaning or derive directly from the the V$ views, so they are explained in the Oracle documentation. The few columns I added to the output that need some additional explaination are the aggregations below:

CF:

    • Number of controlfile backups included in the backup set

DF:

    • Number of datafile full backups included in the backup set

I0:

    • Number of datafile incremental level-0 backups included in the backup set

I1:

    • Number of datafile incremental level-1 backups included in the backup set

L:

    • Number of archived log backups included in the backup set

OUT INST:

    Instance where the job was executed and the output is available (see below)

Please note that the aggregations are only shown for the recent backup jobs in the example above, since they are purged from the catalog after a few days.

Another important thing to note is that in a RAC environment some fields for a RUNNING backup job may contain invalid information until the backup job is finished. To get consistent information, run this query on the node where the backup is running.

Backup set details

Once you found the general information about the backup sets available, you may need to get more information about the backup sets for one particular backup job. Each backup job is uniquely identified by (SESSION_RECID, SESSION_STAMP), which are listed by the query above.

The query below retrieves details for a backup job, given a pair of values for (SESSION_RECID, SESSION_STAMP):

set lines 220
set pages 1000
col backup_type for a4 heading "TYPE"
col controlfile_included heading "CF?"
col incremental_level heading "INCR LVL"
col pieces for 999 heading "PCS"
col elapsed_seconds heading "ELAPSED|SECONDS"
col device_type for a10 trunc heading "DEVICE|TYPE"
col compressed for a4 heading "ZIP?"
col output_mbytes for 9,999,999 heading "OUTPUT|MBYTES"
col input_file_scan_only for a4 heading "SCAN|ONLY"
select
d.bs_key, d.backup_type, d.controlfile_included, d.incremental_level, d.pieces,
to_char(d.start_time, 'yyyy-mm-dd hh24:mi:ss') start_time,
to_char(d.completion_time, 'yyyy-mm-dd hh24:mi:ss') completion_time,
d.elapsed_seconds, d.device_type, d.compressed, (d.output_bytes/1024/1024) output_mbytes, s.input_file_scan_only
from V$BACKUP_SET_DETAILS d
join V$BACKUP_SET s on s.set_stamp = d.set_stamp and s.set_count = d.set_count
where session_recid = &SESSION_RECID
and session_stamp = &SESSION_STAMP
order by d.start_time;

And the output is:

ELAPSED DEVICE OUTPUT SCAN
BS_KEY TYPE CF? INCR LVL PCS START_TIME COMPLETION_TIME SECONDS TYPE ZIP? MBYTES ONLY
---------- ---- --- ---------- ---- ------------------- ------------------- ---------- ---------- ---- ---------- ----
33429 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:25 181 DISK YES 812 NO
33428 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:08 164 DISK YES 812 NO
33429 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:25 181 DISK YES 1,187 NO
33429 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:25 181 DISK YES 812 NO
33429 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:25 181 DISK YES 1,187 NO
33428 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:08 164 DISK YES 1,187 NO
33428 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:08 164 DISK YES 1,187 NO
33428 L NO 1 2011-08-25 15:00:24 2011-08-25 15:03:08 164 DISK YES 812 NO
33430 L NO 1 2011-08-25 15:03:11 2011-08-25 15:03:28 17 DISK YES 89 NO
33436 D NO 45 2011-08-25 15:03:38 2011-08-25 19:05:51 14533 DISK YES 91,898 NO
33436 D NO 45 2011-08-25 15:03:38 2011-08-25 19:05:51 14533 DISK YES 91,898 NO
33443 D NO 52 2011-08-25 15:03:38 2011-08-25 19:31:51 16093 DISK YES 106,166 NO
33443 D NO 52 2011-08-25 15:03:38 2011-08-25 19:31:51 16093 DISK YES 106,166 NO
33437 D NO 2 2011-08-25 19:05:58 2011-08-25 19:16:24 626 DISK YES 2,999 NO
33438 D NO 3 2011-08-25 19:16:28 2011-08-25 19:29:51 803 DISK YES 4,948 NO
33439 D NO 1 2011-08-25 19:29:52 2011-08-25 19:29:52 0 DISK YES 0 NO
33440 D NO 1 2011-08-25 19:29:53 2011-08-25 19:29:53 0 DISK YES 0 NO
33441 D NO 1 2011-08-25 19:29:54 2011-08-25 19:29:54 0 DISK YES 0 NO
33442 D NO 1 2011-08-25 19:29:55 2011-08-25 19:29:55 0 DISK YES 0 NO
33445 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:11 116 DISK YES 677 NO
33445 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:11 116 DISK YES 618 NO
33445 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:11 116 DISK YES 677 NO
33446 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:18 123 DISK YES 618 NO
33446 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:18 123 DISK YES 677 NO
33446 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:18 123 DISK YES 618 NO
33445 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:11 116 DISK YES 618 NO
33446 L NO 1 2011-08-25 19:32:15 2011-08-25 19:34:18 123 DISK YES 677 NO
33447 D YES 1 2011-08-25 19:34:19 2011-08-25 19:34:20 1 DISK NO 24 NO
33448 D YES 1 2011-08-25 19:34:48 2011-08-25 19:34:49 1 DISK YES 3 NO
33449 D YES 1 2011-08-25 19:34:49 2011-08-25 19:34:50 1 DISK NO 24 NO

Backup job output

And finally, sometimes it may be helpful to retrieve the job’s output from the metadata kept by the instance.
It might be that the original log on disk, if any, may have been overwritten by a more recent backup, or just that selecting it from a V$ view may be easier than connecting to a server to find out were the log file is.

The tricky thing here, though, is that the view that contains the output, V$RMAN_OUTPUT, exists in memory only; the job’s output is not stored in the controlfile or anywhere else in the database. Thus, if the instance gets restarted, the contents of that view are reset.

To retrieve the job output for a specific backup job, identified by the (SESSION_RECID, SESSION_STAMP) pair, you can use the following query:

set lines 200
set pages 1000
select output
from GV$RMAN_OUTPUT
where session_recid = &SESSION_RECID
and session_stamp = &SESSION_STAMP
order by recid;

Which shows:

OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
connected to target database: ORCL (DBID=4132479105)
using target database control file instead of recovery catalog
echo set on
backup archivelog all not backed up delete all input;
Starting backup at 26-AUG-11
current log archived
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=233 instance=ORCL devtype=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: sid=261 instance=ORCL devtype=DISK
channel ORA_DISK_1: starting compressed archive log backupset
channel ORA_DISK_1: specifying archive log(s) in backup set
...
...
archive log filename=+ALOGS/ORCL/archivelog/2011_08_26/thread_2_seq_23561.462.933333703 recid=213400 stamp=933333707
archive log filename=+ALOGS/ORCL/archivelog/2011_08_26/thread_2_seq_23562.412.933335505 recid=213402 stamp=933335506
archive log filename=+ALOGS/ORCL/archivelog/2011_08_26/thread_2_seq_23563.632.933337017 recid=213404 stamp=933337020
Finished backup at 26-AUG-11
Starting Control File and SPFILE Autobackup at 26-AUG-11
piece handle=/fra/ORCL/autobackup/2011_08_26/o1_mf_s_933337284_34h856x2_.bkp comment=NONE
Finished Control File and SPFILE Autobackup at 26-AUG-11
exit;

No Comments Yet

Let us know what you think

See all

See all

Subscribe by email
Follow us
Love Your Data
Pythian Logo

© 2024 All rights reserved.