RMAN Backup Log "Failure" in Oracle is Normal in 5.0.4 and Greater (KBA1011)
KBA
KBA#1011Issue
Delphix Engine 5.0.4.0 introduced a change to the handling of RMAN backups of archive logs ( LogSync ) which may cause customers to think that LogSync is failing, however this is a deliberate change and should not be a concern as long as there are no other errors.
Troubleshooting
Determine if the DE is version 5.0.4 or greater. If the error is "sbtclose2 returned error - failed to close file" - and there are no other errors - the system is working as intended.
The output of these views will show the following
SQL> select recid,stamp,session_recid,session_stamp,command_id,operation,status,object_type from v$rman_status where object_type = 'ARCHIVELOG';
RECID STAMP SESSION_RECID SESSION_STAMP COMMAND_ID OPERATION STATUS OBJECT_TYPE
---------- ---------- ------------- ------------- --------------------------------- --------------------------------- ----------------------- -------------
10 1101871299 9 1101871298 DLPX-LGS.2.40.03afa890-f662-45d4 BACKUP FAILED ARCHIVELOG
2 1101870014 1 1101870013 2022-04-13T03:00:12 DELETE COMPLETED ARCHIVELOG
SQL> select output from v$rman_output where session_recid = 9 and session_stamp = 1101871298 order by recid;
OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
connected to target database: TEST2 (DBID=1185886240)
echo set on
executing command: SET encryption
using target database control file instead of recovery catalog
executing command: SET NOCFAU
allocated channel: DLPX_CHANNEL_1
channel DLPX_CHANNEL_1: SID=42 device type=SBT_TAPE
channel DLPX_CHANNEL_1: Delphix SBT API
executing command: SET COMMAND ID
Starting backup at 04/13/2022 03:21:39
channel DLPX_CHANNEL_1: starting archived log backup set
channel DLPX_CHANNEL_1: specifying archived log(s) in backup set
input archived log thread=1 sequence=40 RECID=4 STAMP=1101871290
channel DLPX_CHANNEL_1: starting piece 1 at 04/13/2022 03:21:39
released channel: DLPX_CHANNEL_1
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03009: failure of backup command on DLPX_CHANNEL_1 channel at 04/13/2022 03:21:40
ORA-27192: skgfcls: sbtclose2 returned error - failed to close file
ORA-19511: non RMAN, but media manager or vendor specific failure, error text:
dlpxSbtclose: dlpxSbtclose normal LogSync exit
30 rows selected.
SQL>
Note that even if "normal LogSync exit" is displayed, this does not mean the backup was successful, further errors may have occurred, such as
RMAN-00571: =========================================================== RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS =============== RMAN-00571: =========================================================== RMAN-03009: failure of backup command on DLPX_CHANNEL_1 channel at 02/09/2016 12:58:43 ORA-27192: skgfcls: sbtclose2 returned error - failed to close file ORA-19511: Error received from media manager layer, error text: dlpxSbtclose: dlpxSbtclose normal LogSync exit ORA-19599: block number 20 is corrupt in archived log /datafile/dbdhcp2/archivelog/1_419_781393482.dbf
Any errors with fetching archive logs should still be presented in the Delphix Engine as a "fault".
Resolution
In previous Delphix versions when an archive log was successfully backed up to the Delphix tape library client from RMAN, it would mark the backup as successful. As soon as the Delphix Engine finished the archive log backup it would issue a delete for the backup we just took, however this would leave a small window of time where Oracle would see the archive log backup as valid and available for restoration. Due to the way Oracle handles multiple separate backup locations, this could cause unintended interactions with other backup providers.
The solution to this issue was for us to always return a failure when backing up archive logs. Internally the Delphix Engine knows if the archive log backup was successful or not, but to Oracle it appears the backup was unsuccessful, so the archive log backup is never valid for recovery from Oracle's point of view.
From 5.0.4.0 the failures listed above and considered normal and expected. For the majority of customers this change will be completely transparent, however if customers are monitoring v$rman_output to check for RMAN backup failures they will now see the archive log backups from Delphix as being failed. It is not required to monitor v$rman_* views for failures from Delphix Engine activity. Any failures from Delphix Engine backups in v$rman_* views can be safely ignored. Actual Delphix Engine SnapSync and LogSync failures will be presented in the Delphix Engine faults list.