RMAN full backup fails

Former Member · ‎08-28-2012

Hello all,

I cannot run a RMAN backup properly as it fails with the following logs:

BR0280I BRBACKUP time stamp: 2012-08-28 14.14.56

BR0202I Saving /oracle/QAS/sapdata1/sr3_45/sr3.data45 ...

BR0280I BRBACKUP time stamp: 2012-08-28 14.14.56

BR0202I Saving /oracle/QAS/sapdata1/sr3_39/sr3.data39 ...

BR0280I BRBACKUP time stamp: 2012-08-28 14.30.31

BR0521I Backup of database file save set piece - piece handle=QAS_bejhurxa.320_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

BR0280I BRBACKUP time stamp: 2012-08-28 14.30.31

BR0202I Saving /oracle/QAS/sapdata1/sr3_1/sr3.data1 ...

BR0280I BRBACKUP time stamp: 2012-08-28 14.30.31

BR0202I Saving /oracle/QAS/sapdata1/sr3_46/sr3.data46 ...

BR0280I BRBACKUP time stamp: 2012-08-28 14.30.31

BR0202I Saving /oracle/QAS/sapdata1/sr3_40/sr3.data40 ...

BR0278E Command output of 'SHELL=/bin/sh /oracle/QAS/102_64/bin/rman nocatalog':

Recovery Manager: Release 10.2.0.5.0 - Production on Tue Aug 28 12:45:35 2012

RMAN>

RMAN> connect target *

connected to target database: QAS (DBID=2999474485)

using target database control file instead of recovery catalog

RMAN> **end-of-file**

RMAN>

host command complete

RMAN>

sql statement: alter session set optimizer_mode=RULE

RMAN> 2> 3> 4> 5>

allocated channel: sbt_1

channel sbt_1: sid=1546 devtype=SBT_TAPE

channel sbt_1: Data Protection for SAP(R)

Starting backup at 28-AUG-12

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00029 name=/oracle/QAS/sapdata1/sr3_17/sr3.data17

input datafile fno=00049 name=/oracle/QAS/sapdata1/sr3_35/sr3.data35

input datafile fno=00014 name=/oracle/QAS/sapdata1/sr3700_4/sr3700.data4

channel sbt_1: starting piece 1 at 28-AUG-12

could not write to trace file

channel sbt_1: finished piece 1 at 28-AUG-12

piece handle=QAS_bejhurxa.315_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

channel sbt_1: backup set complete, elapsed time: 00:18:55

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00030 name=/oracle/QAS/sapdata1/sr3_18/sr3.data18

input datafile fno=00050 name=/oracle/QAS/sapdata1/sr3_36/sr3.data36

input datafile fno=00013 name=/oracle/QAS/sapdata1/sr3700_3/sr3700.data3

channel sbt_1: starting piece 1 at 28-AUG-12

channel sbt_1: finished piece 1 at 28-AUG-12

piece handle=QAS_bejhurxa.316_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

channel sbt_1: backup set complete, elapsed time: 00:18:15

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00031 name=/oracle/QAS/sapdata1/sr3_19/sr3.data19

input datafile fno=00055 name=/oracle/QAS/sapdata1/sr3_41/sr3.data41

input datafile fno=00011 name=/oracle/QAS/sapdata1/sr3700_1/sr3700.data1

channel sbt_1: starting piece 1 at 28-AUG-12

channel sbt_1: finished piece 1 at 28-AUG-12

piece handle=QAS_bejhurxa.317_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

channel sbt_1: backup set complete, elapsed time: 00:18:05

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00032 name=/oracle/QAS/sapdata1/sr3_20/sr3.data20

input datafile fno=00057 name=/oracle/QAS/sapdata1/sr3_43/sr3.data43

input datafile fno=00012 name=/oracle/QAS/sapdata1/sr3700_2/sr3700.data2

channel sbt_1: starting piece 1 at 28-AUG-12

channel sbt_1: finished piece 1 at 28-AUG-12

piece handle=QAS_bejhurxa.318_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

channel sbt_1: backup set complete, elapsed time: 00:16:25

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00033 name=/oracle/QAS/sapdata1/sr3_21/sr3.data21

input datafile fno=00058 name=/oracle/QAS/sapdata1/sr3_44/sr3.data44

input datafile fno=00002 name=/oracle/QAS/sapdata1/undo_1/undo.data1

channel sbt_1: starting piece 1 at 28-AUG-12

channel sbt_1: finished piece 1 at 28-AUG-12

piece handle=QAS_bejhurxa.319_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

channel sbt_1: backup set complete, elapsed time: 00:17:35

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00034 name=/oracle/QAS/sapdata1/sr3_22/sr3.data22

input datafile fno=00059 name=/oracle/QAS/sapdata1/sr3_45/sr3.data45

input datafile fno=00053 name=/oracle/QAS/sapdata1/sr3_39/sr3.data39

channel sbt_1: starting piece 1 at 28-AUG-12

channel sbt_1: finished piece 1 at 28-AUG-12

piece handle=QAS_bejhurxa.320_1 tag=BEJHURXA comment=API Version 2.0,MMS Version 6.1.0.2

channel sbt_1: backup set complete, elapsed time: 00:15:35

channel sbt_1: starting incremental level 0 datafile backupset

channel sbt_1: specifying datafile(s) in backupset

input datafile fno=00004 name=/oracle/QAS/sapdata1/sr3_1/sr3.data1

input datafile fno=00060 name=/oracle/QAS/sapdata1/sr3_46/sr3.data46

input datafile fno=00054 name=/oracle/QAS/sapdata1/sr3_40/sr3.data40

channel sbt_1: starting piece 1 at 28-AUG-12

released channel: sbt_1

RMAN-00571: ===========================================================

RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============

RMAN-00571: ===========================================================

RMAN-03009: failure of backup command on sbt_1 channel at 08/28/2012 15:31:36

ORA-27192: skgfcls: sbtclose2 returned error - failed to close file

ORA-19511: Error received from media manager layer, error text:

BKI9309E: Operation terminated due to an explicit abort request.

ORA-19502: write error on file "QAS_bejhurxa.321_1", blockno 7527937 (blocksize=512)

ORA-27030: skgfwrt: sbtwrite2 returned error

ORA-19511: Error received from media manager layer, error text:

BKI5008E: Tivoli Storage Manager Error:

RMAN>

List of Backup Sets

===================

BS Key Type LV Size Device Type Elapsed Time Completion Time

------- ---- -- ---------- ----------- ------------ ---------------

312 Incr 0 81.39G SBT_TAPE 00:18:46 28-AUG-12

BP Key: 312 Status: AVAILABLE Compressed: NO Tag: BEJHURXA

Handle: QAS_bejhurxa.315_1 Media:

List of Datafiles in backup set 312

File LV Type Ckp SCN Ckp Time Name

---- -- ---- ---------- --------- ----

14 0 Incr 5624615847 28-AUG-12 /oracle/QAS/sapdata1/sr3700_4/sr3700.data4

29 0 Incr 5624615847 28-AUG-12 /oracle/QAS/sapdata1/sr3_17/sr3.data17

49 0 Incr 5624615847 28-AUG-12 /oracle/QAS/sapdata1/sr3_35/sr3.data35

BS Key Type LV Size Device Type Elapsed Time Completion Time

------- ---- -- ---------- ----------- ------------ ---------------

313 Incr 0 81.53G SBT_TAPE 00:18:05 28-AUG-12

BP Key: 313 Status: AVAILABLE Compressed: NO Tag: BEJHURXA

Handle: QAS_bejhurxa.316_1 Media:

List of Datafiles in backup set 313

File LV Type Ckp SCN Ckp Time Name

---- -- ---- ---------- --------- ----

13 0 Incr 5624766058 28-AUG-12 /oracle/QAS/sapdata1/sr3700_3/sr3700.data3

30 0 Incr 5624766058 28-AUG-12 /oracle/QAS/sapdata1/sr3_18/sr3.data18

50 0 Incr 5624766058 28-AUG-12 /oracle/QAS/sapdata1/sr3_36/sr3.data36

BS Key Type LV Size Device Type Elapsed Time Completion Time

------- ---- -- ---------- ----------- ------------ ---------------

314 Incr 0 80.82G SBT_TAPE 00:17:58 28-AUG-12

BP Key: 314 Status: AVAILABLE Compressed: NO Tag: BEJHURXA

Handle: QAS_bejhurxa.317_1 Media:

List of Datafiles in backup set 314

File LV Type Ckp SCN Ckp Time Name

---- -- ---- ---------- --------- ----

11 0 Incr 5625033398 28-AUG-12 /oracle/QAS/sapdata1/sr3700_1/sr3700.data1

31 0 Incr 5625033398 28-AUG-12 /oracle/QAS/sapdata1/sr3_19/sr3.data19

55 0 Incr 5625033398 28-AUG-12 /oracle/QAS/sapdata1/sr3_41/sr3.data41

BS Key Type LV Size Device Type Elapsed Time Completion Time

------- ---- -- ---------- ----------- ------------ ---------------

315 Incr 0 76.46G SBT_TAPE 00:16:19 28-AUG-12

BP Key: 315 Status: AVAILABLE Compressed: NO Tag: BEJHURXA

Handle: QAS_bejhurxa.318_1 Media:

List of Datafiles in backup set 315

File LV Type Ckp SCN Ckp Time Name

---- -- ---- ---------- --------- ----

12 0 Incr 5625227991 28-AUG-12 /oracle/QAS/sapdata1/sr3700_2/sr3700.data2

32 0 Incr 5625227991 28-AUG-12 /oracle/QAS/sapdata1/sr3_20/sr3.data20

57 0 Incr 5625227991 28-AUG-12 /oracle/QAS/sapdata1/sr3_43/sr3.data43

BS Key Type LV Size Device Type Elapsed Time Completion Time

------- ---- -- ---------- ----------- ------------ ---------------

316 Incr 0 73.17G SBT_TAPE 00:17:31 28-AUG-12

BP Key: 316 Status: AVAILABLE Compressed: NO Tag: BEJHURXA

Handle: QAS_bejhurxa.319_1 Media:

List of Datafiles in backup set 316

File LV Type Ckp SCN Ckp Time Name

---- -- ---- ---------- --------- ----

2 0 Incr 5625363321 28-AUG-12 /oracle/QAS/sapdata1/undo_1/undo.data1

33 0 Incr 5625363321 28-AUG-12 /oracle/QAS/sapdata1/sr3_21/sr3.data21

58 0 Incr 5625363321 28-AUG-12 /oracle/QAS/sapdata1/sr3_44/sr3.data44

BS Key Type LV Size Device Type Elapsed Time Completion Time

------- ---- -- ---------- ----------- ------------ ---------------

317 Incr 0 70.84G SBT_TAPE 00:15:31 28-AUG-12

BP Key: 317 Status: AVAILABLE Compressed: NO Tag: BEJHURXA

Handle: QAS_bejhurxa.320_1 Media:

List of Datafiles in backup set 317

File LV Type Ckp SCN Ckp Time Name

---- -- ---- ---------- --------- ----

34 0 Incr 5625651820 28-AUG-12 /oracle/QAS/sapdata1/sr3_22/sr3.data22

53 0 Incr 5625651820 28-AUG-12 /oracle/QAS/sapdata1/sr3_39/sr3.data39

59 0 Incr 5625651820 28-AUG-12 /oracle/QAS/sapdata1/sr3_45/sr3.data45

RMAN>

Recovery Manager complete.

BR0280I BRBACKUP time stamp: 2012-08-28 15.31.39

BR0279E Return code from 'SHELL=/bin/sh /oracle/QAS/102_64/bin/rman nocatalog': 1

BR0522E 21 of 64 files / save sets processed by RMAN

BR0536E RMAN call for database instance QAS failed

BR0200I BR_TRACE: location BrRmanCall-56, commands for RMAN in: /oracle/QAS/sapbackup/.bejhurxa.cmd

@/oracle/QAS/sapbackup/..bejhurxa..cmd

host '/usr/sap/QAS/SYS/exe/run/brtools -f delete /oracle/QAS/sapbackup/..bejhurxa..cmd';

sql 'alter session set optimizer_mode=RULE';

run { allocate channel sbt_1 device type 'SBT_TAPE'

parms 'ENV=(XINT_PROFILE=/oracle/QAS/102_64/dbs/initQAS_weekly.utl,PROLE_PORT=57323)';

backup incremental level 0 tag bejhurxa format 'QAS_bejhurxa.%s_%p' filesperset 3 check logical

database;

release channel sbt_1; }

list backup of database tag bejhurxa;

exit;

BR0280I BRBACKUP time stamp: 2012-08-28 15.31.39

BR0506E Full database backup (level 0) using RMAN failed

BR0056I End of database backup: bejhurxa.fnr 2012-08-28 15.31.39

BR0280I BRBACKUP time stamp: 2012-08-28 15.31.41

BR0054I BRBACKUP terminated with errors

Any idea why this is happening ? For me it seems ORA problem, not really TSM.

Any help is highly appreciated,

Thanks,

J.

stefan_koehler · ‎08-29-2012

Hi Jordan,

ORA-27192: skgfcls: sbtclose2 returned error - failed to close file
ORA-19511: Error received from media manager layer, error text:
BKI9309E: Operation terminated due to an explicit abort request.

.. this error is usually caused by the TSM server itself. Please check the activity log of the TSM server and you should find the root cause (usually it is a tape or drive failure).

Regards

Stefan

Former Member · ‎08-29-2012

I think this is TSM error not oracle. Description of BKI9309E is

Operation terminated due to an explicit abort request.

Explanation

An operation was terminated due to customer intervention.

User response

None.

For BKI5008E

Tivoli Storage Manager Error: error_message

Is it really empty error message in log file?

Try to check errors from TSM. Also check trace files generated by oracle for more errors.

Regards

Roman