RMAN - Analisando a mensagem "Bad check value found during backing up datafile" no arquivo de alerta do Oracle

Olá,

No artigo de Fevereiro/2016 foi abordado como realizar a recuperação física de um bloco corrompido em um arquivo de dados utilizando a técnica "Block Media Recovery" do RMAN. Recentemente, fazendo a análise do arquivo de alerta de um banco de dados como demonstrado abaixo, percebi uma mensagem informando que o bloco 334002 do datafile 70 estaria corrompido durante a tentativa de realização de um backup físico pelo RMAN. Se realmente o bloco estiver corrompido, poderemos recuperá-lo utilizando esta técnica.

Sat Sep 3 10:10:01 2016
Hex dump of (file 70, block 334002) in trace file /u01/app/oracle/diag/rdbms/bd01/BD01/trace/BD01_ora_26379.trc
Corrupt block relative dba: 0x118518b2 (file 70, block 334002)
Bad check value found during backing up datafile
Data in bad block:
 type: 40 format: 2 rdba: 0x118518b2
 last change scn: 0x0c69.bc39d7ea seq: 0x2 flg: 0x04
 spare1: 0x0 spare2: 0x0 spare3: 0x0
 consistency value in tail: 0xd7ea2802
 check value in block header: 0x3253
 computed block checksum: 0x0
Reread of blocknum=334002, file=/oradata/BD01/LOB_01_015.dbf. found valid data

Ao verificar o trecho acima no arquivo de alerta acima, realizei a validação do arquivo de dados pelo RMAN conforme a seguir, mas nenhuma mensagem de bloco corrompido foi emitida.

$ export ORACLE_SID=BD01
$ rman target /

Recovery Manager: Release 11.2.0.3.0 - Production on Sat Sep 3 10:19:35 2016

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

connected to target database: BD01 (DBID=1637785486)

RMAN> validate datafile 70;

Starting validate at 03/09/2016
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=485 device type=DISK
channel ORA_DISK_1: starting validation of datafile
channel ORA_DISK_1: specifying datafile(s) for validation
input datafile file number=00070 name=/oradata/BD01/LOB_01_015.dbf
channel ORA_DISK_1: validation complete, elapsed time: 00:07:46

List of Datafiles
=================
File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- --------------
70   OK     0              124289       3171840         13656377431238

  File Name: /oradata/BD01/LOB_01_015.dbf
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              0
  Index      0              2418
  Other      0              3045133

Finished validate at 03/09/2016

Ao analisar o arquivo de trace, foi identificado que uma operação de backup incremental estava em execução durante o suposto problema de corrupção de bloco corrompido. No entanto, é possível perceber que logo após o bloco ser marcado como corrompido, existe uma mensagem indicando que o bloco foi novamente lido e que o seu estado estava válido. Vale a pena salientar que esta informação também está contida no arquivo de log de alerta.

$ cat /u01/app/oracle/diag/rdbms/bd01/BD01/trace/BD01_ora_26379.trc

Trace file /u01/app/oracle/diag/rdbms/bd01/BD01/trace/BD01_ora_26379.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning option
ORACLE_HOME = /u01/app/oracle/product/11.2.0/dbhome_1
System name:    Linux
Node name:    server01
Release:    2.6.32-431.el6.x86_64
Version:    #1 SMP Fri Nov 22 03:15:09 UTC 2013
Machine:    x86_64
VM name:    Xen Version: 4.2 (HVM)
Instance name: BD01
Redo thread mounted by this instance: 1
Oracle process number: 136
Unix process pid: 26379, image: oracle@server01 (TNS V1-V3)


*** 2016-09-03 10:10:01.872
*** SESSION ID:(87.57015) 2016-09-03 10:10:01.872
*** CLIENT ID:() 2016-09-03 10:10:01.872
*** SERVICE NAME:(SYS$USERS) 2016-09-03 10:10:01.872
*** MODULE NAME:(backup incr datafile) 2016-09-03 10:10:01.872
*** ACTION NAME:(0002354 STARTED16) 2016-09-03 10:10:01.872

Hex dump of (file 70, block 334002)
Dump of memory from 0x00007F4158268000 to 0x00007F415826A000
7F4158268000 0000A228 118518B2 BC39D7EA 04020C69  [(.........9.i...]
7F4158269FB0 ACF6C7BB 701DB8EC B5F46AB4 E30FC56E  [.......p.j..n...]
7F4158269FC0 22758DDB B9452750 605107CF 39ECD3AD  [..u"P'E...Q`...9]
7F4158269FD0 387CC51C 9660182B 23606732 F1478AB3  [..|8+.`.2g`#..G.]
7F4158269FE0 1C17E72F C6082CF2 009DE777 6EABC849  [/....,..w...I..n]
7F4158269FF0 98D57134 E3D4B9E8 B511A853 D7EA2802  [4q......S....(..]
Corrupt block relative dba: 0x118518b2 (file 70, block 334002)
Bad check value found during backing up datafile
Data in bad block:
 type: 40 format: 2 rdba: 0x118518b2
 last change scn: 0x0c69.bc39d7ea seq: 0x2 flg: 0x04
 spare1: 0x0 spare2: 0x0 spare3: 0x0
 consistency value in tail: 0xd7ea2802
 check value in block header: 0x3253
 computed block checksum: 0x0
Reread of blocknum=334002, file=/oradata/BD01/LOB_01_015.dbf. found valid data

Conclusão: Inicialmente eu achei muito estranho um erro no arquivo de alerta sem associação a um erro ORA-. Durante uma operação de backup usando o RMAN, o mesmo tenta obter uma imagem consistente do bloco de dados, e caso esse bloco seja alterado durante essa operação, o RMAN tentará obter novamente uma imagem consistente do mesmo bloco. Possivelmente esta foi a causa da mensagem no arquivo de alerta. Outro ponto importante a salientar é que toda essa operação é logada no arquivo de alerta (alert log file).