ABMR – Automatic Block Media Recovery

ABMR is a cool feature; most of us know about it, so instead of talking about ABMR, want to share the issues I faced.

First one was, Oracle did not bother to start the abmr background process and attempt block recovery.   Alert log exclaimed about the block corruption and did nothing.

Fri Sep 06 19:27:30 2013

Hex dump of (file 5, block 1028) in trace file /n01/oraadmin1/diag/rdbms/oracld/oracld/trace/oracld_ora_30109.trc

Corrupt block relative dba: 0x01400404 (file 5, block 1028)

Completely zero block found during multiblock buffer read

Reading datafile '/n01/oradata1/oracld/data01.dbf' for corruption at rdba: 0x01400404 (file 5, block 1028)

Reread (file 5, block 1028) found same corrupt data (no logical check)

Fri Sep 06 19:27:30 2013

Corrupt Block Found

TSN = 5, TSNAME = DATA

RFN = 5, BLK = 1028, RDBA = 20972548

OBJN = 62328, OBJD = 62328, OBJECT = TEST, SUBOBJECT =

SEGMENT OWNER = THOMAS, SEGMENT TYPE = Table Segment

Errors in file /n01/oraadmin1/diag/rdbms/oracld/oracld/trace/oracld_ora_30109.trc  (incident=41012):

ORA-01578: ORACLE data block corrupted (file # 5, block # 1028)

ORA-01110: data file 5: '/n01/oradata1/oracld/data01.dbf'

Incident details in: /n01/oraadmin1/diag/rdbms/oracld/oracld/incident/incdir_41012/oracld_ora_30109_i41012.trc

It was my bad,  the pre-requisite for ABMR is, as per Oracle documentation

A physical standby database operating in real-time query mode can be used to repair corrupt data blocks in a primary database. If possible, any corrupt data block encountered when a primary database is accessed will be automatically replaced with an uncorrupted copy of that block from a physical standby database operating in real-time query mode. An ORA-1578 error is returned when automatic repair is not possible.

http://docs.oracle.com/cd/E11882_01/server.112/e17157/unplanned.htm#BABCECIC

So, the dataguard should be HIGH AVAILABILITY protection mode and operating in real time query mode.   That resolved my first issue.

HIGH AVAILABILITY mode, ABMR process came up, but plainly said, I do not see  a standby, while the standby DB was in sync.

Hex dump of (file 5, block 1028) in trace file /n01/oraadmin1/diag/rdbms/oracld/oracld/trace/oracld_ora_30391.trc

Corrupt block relative dba: 0x01400404 (file 5, block 1028)

Completely zero block found during multiblock buffer read

Reading datafile '/n01/oradata1/oracld/data01.dbf' for corruption at rdba: 0x01400404 (file 5, block 1028)

Reread (file 5, block 1028) found same corrupt data (no logical check)

Starting background process ABMR

Fri Sep 06 19:42:10 2013

ABMR started with pid=27, OS id=30393

Automatic block media recovery service is active.

Automatic block media recovery requested for (file# 5, block# 1028)

Fri Sep 06 19:42:11 2013

Errors in file /n01/oraadmin1/diag/rdbms/oracld/oracld/trace/oracld_bmr0_30395.trc:

ORA-17627: ORA-01017: invalid username/password; logon denied

ORA-17629: Cannot connect to the remote database server

Automatic block media recovery failed for (file# 5, block# 1028)

[No standby available]

Automatic block media recovery requested for (file# 5, block# 1028)

Fri Sep 06 19:42:11 2013

Corrupt Block Found

TSN = 5, TSNAME = DATA

RFN = 5, BLK = 1028, RDBA = 20972548

OBJN = 62328, OBJD = 62328, OBJECT = TEST, SUBOBJECT =

SEGMENT OWNER = THOMAS, SEGMENT TYPE = Table Segment

Fri Sep 06 19:43:11 2013

Automatic block media recovery failed for (file# 5, block# 1028)

[No response received]

Oracle is able to ship the log files and telling me not able login to the standby DB with an error message “ORA-17627: ORA-01017: invalid username/password; logon denied”.  I was fortunate enough to find a note from and found I am hitting an unpublished bug: 6804839

http://jhdba.wordpress.com/2008/05/12/more-problems-with-orapwd-file-and-shipping-redo-logs/

For a workaround, I have re-created the password file with the option : ignorecase=y

That resolved my  “ORA-01017: invalid username/password; logon denied” and landed in another issue.  That was more clueless one –

Fri Sep 06 20:02:01 2013

ABMR started with pid=28, OS id=30883

Automatic block media recovery service is active.

Automatic block media recovery requested for (file# 5, block# 1028)

Fri Sep 06 20:03:01 2013

Automatic block media recovery failed for (file# 5, block# 1028)

[Network call timed-out]

Automatic block media recovery requested for (file# 5, block# 1028)

Fri Sep 06 20:03:01 2013

Corrupt Block Found

TSN = 5, TSNAME = DATA

RFN = 5, BLK = 1028, RDBA = 20972548

OBJN = 62328, OBJD = 62328, OBJECT = TEST, SUBOBJECT =

SEGMENT OWNER = THOMAS, SEGMENT TYPE = Table Segment

Fri Sep 06 20:04:01 2013

Automatic block media recovery failed for (file# 5, block# 1028)

[Network call timed-out]



My Primary and Standby database – both are running in the same server, but failing with Network call timed-out.  But one more entry from alert log gave me some more information, LOG_ARCHIVE_DEST_2  is not really SYNCHORNISED with RFS processes.



LGWR: Attempting destination LOG_ARCHIVE_DEST_2 network reconnect (16086)

LGWR: Destination LOG_ARCHIVE_DEST_2 network reconnect abandoned

Error 16086 for archive log file 3 to 'oraclds'

LGWR: Failed to archive log 3 thread 1 sequence 78 (16086)

The reason I got it  from standby alert log as

Media Recovery Log /n01/oradata1/archs/1_200_819972215.dbf

Media Recovery Waiting for thread 1 sequence 201

Sat Sep 07 08:52:07 2013

Primary database is in MAXIMUM AVAILABILITY mode

Standby controlfile consistent with primary

Standby controlfile consistent with primary

RFS[262]: Assigned to RFS process 4208

RFS[262]: No standby redo logfiles created for thread 1

RFS[262]: No standby redo logfiles selected (reason:7)

Oops, by mistake I have created standby log files not under thread 1 but for thread 2.  Fixed that issue, and I was fortunate enough to see

Hex dump of (file 5, block 1028) in trace file /n01/oraadmin1/diag/rdbms/oracld/oracld/trace/oracld_ora_4628.trc

Corrupt block relative dba: 0x01400404 (file 5, block 1028)

Completely zero block found during multiblock buffer read

Reading datafile '/n01/oradata1/oracld/data01.dbf' for corruption at rdba: 0x01400404 (file 5, block 1028)

Reread (file 5, block 1028) found same corrupt data (no logical check)

Starting background process ABMR

Sat Sep 07 09:08:57 2013

ABMR started with pid=28, OS id=4630

Automatic block media recovery service is active.

Automatic block media recovery requested for (file# 5, block# 1028)

Sat Sep 07 09:08:57 2013

Automatic block media recovery successful for (file# 5, block# 1028)

Automatic block media recovery successful for (file# 5, block# 1028)

I thought to document this – hope someone will benefit!