Olá DBAs, a vida tá boa?
Lembram-se do meu último artigo? Onde eu estava travando uma intensa batalha com um cliente para que aplicássemos patch em seu DB 19c Base Release? Pois é, ele se esquivou o quanto pode, mas agora finalmente o convenci após o problema que relato para voces abaixo.
Para referencia, seguem informações básicas sobre Primário e Standby:
| Sistema Operacional | Windows Server 2022 Standard |
| Versão Database | 19.3.0.0.0 |
Há algumas semanas atrás, o Standby após uma queda abrupta do servidor, passou a requerer um archive datado de 22 de Outubro. Sim, um archive de mais de 1 mes atrás, que já não existia no servidor primário e que já não tinha backup disponível para restauração. Detalhe é que este e todos os archives posteriores já haviam sido aplicados ao Standby, pois não habia gap anteriomente e mesmo após o MRP solicitar este archive, era possível vê-lo como “applied” no standby.
Analisando o servidor secundário, relutante em acreditar e com problemas para entender o que estava acontecendo, comecei a checar todas as informações disponíveis sobre o banco. Primeiro passo era saber o que o alertlog me mostrava, qual archive estava pedindo, qual era o “gap” e de qual data este seria:
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE DISCONNECT NODELAY
Starting background process MRP0
2023-11-27T09:04:55.634568-06:00
MRP0 started with pid=50, OS id=6576
2023-11-27T09:05:00.643097-06:00
Started logmerger process
2023-11-27T09:05:00.658773-06:00
PR00 (PID:8728): Managed Standby Recovery starting Real Time Apply
max_pdb is 3
2023-11-27T09:05:01.371083-06:00
Parallel Media Recovery started with 32 slaves
2023-11-27T09:05:01.435221-06:00
stopping change tracking
PR00 (PID:8728): Media Recovery Waiting for T-1.S-527
PR00 (PID:8728): Fetching gap from T-1.S-527 to T-1.S-602
2023-11-27T09:05:01.673588-06:00
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE DISCONNECT NODELAY
2023-11-27T09:07:57.107512-06:00
PR00 (PID:8728): FAL: Failed to request gap sequence
PR00 (PID:8728): GAP - thread 1 sequence 527-602
PR00 (PID:8728): DBID 3055344498 branch 1147598327
PR00 (PID:8728): FAL: All defined FAL servers have been attempted
PR00 (PID:8728): -------------------------------------------------------------------------
PR00 (PID:8728): Check that the CONTROL_FILE_RECORD_KEEP_TIME initialization
PR00 (PID:8728): parameter is defined to a value that's sufficiently large
PR00 (PID:8728): enough to maintain adequate log switch information to resolve
PR00 (PID:8728): archived redo log gaps.
PR00 (PID:8728): -------------------------------------------------------------------------
Ao iniciar o processo MRP no standby, ele requisita a sequencia 527 e aponta que faltam ser aplicados deste até o 602. OK! Quem nunca precisou recupar alguns archives. Mas vamos checar de que data são:
2023-10-22T01:45:52.574509-05:00
PR00 (PID:3744): Media Recovery Waiting for T-1.S-527 (in transit)
2023-10-22T01:45:52.590104-05:00
Media Recovery of Online Log [Thread=1, Seq=527]
2023-10-22T01:45:52.605724-05:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 527 Reading mem 0
Mem# 0: J:\ORACLE\ORADATA\PROD_22\ONLINELOG\O1_MF_4_LL1WORGH_.LOG
Mem# 1: L:\ORACLE\FAST_RECOVERY_AREA\PROD_22\ONLINELOG\O1_MF_4_LL1WORSP_.LOG
2023-10-22T05:13:19.066839-05:00
PR00 (PID:5612): Media Recovery Waiting for T-1.S-528
2023-10-22T05:13:19.129336-05:00
ARC3 (PID:8648): Archived Log entry 205 added for T-1.S-527 ID 0xb63b8f52 LAD:1
2023-10-22T05:13:19.160588-05:00
rfs (PID:7980): Primary database is in MAXIMUM PERFORMANCE mode
2023-10-22T05:13:19.223086-05:00
rfs (PID:7980): Selected LNO:4 for T-1.S-528 dbid 3055344498 branch 1147598327
2023-10-22T05:13:20.644963-05:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 528 Reading mem 0
Mem# 0: J:\ORACLE\ORADATA\PROD_22\ONLINELOG\O1_MF_4_LL1WORGH_.LOG
Mem# 1: L:\ORACLE\FAST_RECOVERY_AREA\PROD_22\ONLINELOG\O1_MF_4_LL1WORSP_.LOG
2023-10-22T06:00:13.582581-05:00
rfs (PID:7980): Selected LNO:5 for T-1.S-529 dbid 3055344498 branch 1147598327
2023-10-22T06:00:13.676326-05:00
PR00 (PID:5612): Media Recovery Waiting for T-1.S-529 (in transit)
2023-10-22T06:00:13.691956-05:00
Recovery of Online Redo Log: Thread 1 Group 5 Seq 529 Reading mem 0
Mem# 0: J:\ORACLE\ORADATA\PROD_22\ONLINELOG\O1_MF_5_LL1WOSD1_.LOG
Mem# 1: L:\ORACLE\FAST_RECOVERY_AREA\PROD_22\ONLINELOG\O1_MF_5_LL1WOSNB_.LOG
2023-10-22T06:00:13.832575-05:00
Após uma queda abrupta do servidor em 22 de Outubro, ao voltar, o database requisitou o archive 527, aplicou e passou adiante.
O mesmo é constatado na query abaixo:
Como é possível ver, foram todos aplicados no standby.
Então, por que cargas d´água o standby database está requerindo um archive de sequencia tão antigo? Porque após a tentativa de recuperação padrão (aplicação de incremental) o MRP ainda não conseguia seguir adiante? Diversos porques me assombraram, e bem, após pesquisa sobre o assunto encontrei algo interessante:
Bug 29056767 : DATAFILES CHECKPOINT NOT UPDATED AT STANDBY DATABASE WHEN MRP IS ENABLED
Pois é! Base Release é isso. Encontramos um BUG. Após contato com a Oracle via SR e diversos (quando digo diversos, digo muitos, infindáveis) pedidos de upload de informação, alertlogs, drlogs, análises, confirmou-se que realmente caímos neste bug.
Basicamente o bug afeta o cabeçalho dos datafiles, que podem ser afetados após uma queda abrupta do database (no meu caso o Windows reinicia toda quarta semana do mes para aplicação de updates de segurança sem fazer corretamente o shutdown database) e faz com o que o MRP não saiba que os archives foram aplicados devido a essa inconsistencia nos cabeçalhos. Este bug afeta as versões 18 e 19, sendo corrigida na 18.8(correção esta que só foi apresentada após o lançamento do 19 Base Release) e depois no BP 19.4.
Segue a descrição do BUG:
Description
On a Physical Standby database, media recovery not regularly updating the checkpoint scn and time stored in each datafile header.
This problem only happens in oracle version 18.1 onwards.
Standby media recovery is running, and it's applying successive log seq#'s,
but the checkpoint scn and time stored each datafile header doesn't change.
NOTE: the checkpoint in the datafile headers can be monitored by:
select to_char(sysdate,'HH24:MI:SS'), file#, checkpoint_change#,
to_char(checkpoint_time,'HH24:MI:SS') from v$datafile_header;
A level 1 incremental backup on the standby may skip all the datafiles.
Another impact of this bug is that if media recovery suddenly aborts for some other reason (eg due to a "shutdown abort" of the instance)
then the next media recovery session may try to start scanning redo from much further back in time than necessary, and if that redo is
unavailable, V$MANAGED_STANDBY would show MRP0 status is WAIT_FOR_GAP, alert log file will show 'FAL: Failed to request gap sequence'
Workaround
On the standby,
set: alter system set "_time_based_rcv_ckpt_target"=0;
NOTE: restart media recovery for it to pick up the new parameter value.
NOTE: this parameter can also be proactively set on the primary, so it
is ready in case it becomes the standby in the future
Atentem-se ao workaround descrito. Devo informar que tentei a execução do mesmo e não foi possível seguir adiante com o MRP mesmo após o procedimento. Questionei a Oracle sobre e recebi a seguinte devolutiva:
The corrective action plan would be to have fix for Bug 29056767 – STANDBY: Datafiles Checkpoint not Updated at Standby Database when Media Recover is running
Oracle Support
in your environment and then roll forward the standby database to sync with Primary database.
The workaround/fix only applicable on next subsequent attempt, It doesn’t resolve the issues if already GAP exists.
Ou seja, o workaround não é uma correção, pois só funciona se voce estiver com seu standby em sincronismo. Sendo assim o plano seria reconstruir o standby, e só então aplicar o workaround (que é basicamente a alteração de um parametro oculto e este parametro faz com que o MRP defina um checkpoint em segundos definidos pelo parametro e não somente a cada archive aplicado). Me parece mais uma segurança, caso voce não tenha uma quantidade grande de archives sendo aplicados, para que possa manter os cabeçalhos dos datafiles em sincronia. Encontrei a seguinte definição em:
In 18.1 onward, timebased media recovery checkpoint is the default style of checkpoint (it’s enabled via the hidden parameter _time_based_rcv_ckpt_target=180) meaning that by default, media recovery will perform a checkpoint every 180 seconds, instead of at every log boundary.
Freelists.org site
Sendo assim, após todos os meu argumentos anteriores com o cliente não terem surtido efeito, finalmente encontrei um que o fez mudar de ideia, e iremos aplicar o Bundle Patch neste database. É um BP que pode ser aplicado primeiramente só no standby e depois então ser levado ao primário.
Provavelmente iremos para o “Patch 35681552: WINDOWS DATABASE BUNDLE PATCH 19.21.0.0.231017” que é o ultimo lançado. Como ele já tem praticamente dois meses de lançamento, aplicaremos nas versões de DEV/QA, esperarei os testes e então levarei para secundário e só então ao primário.
Sendo assim, compartilho aqui minha experiencia de ter e NÃO ter um standby. Tudo estava em sincronismo e sem gap até um shutdown abrupto. E ao meu entender, este pode vir a ser um problema no primário também, caso tenhamos um problema de energia ou algo do tipo, o que me garante que mesmo não tendo o MRP explícito, eu ná vá enfrentar isso caso precise de uma recuperação para sincronizar meus datafiles antes de abrir a base?
Fiquem a vontade para fazer quaisquer pontuações caso já tenham vivenciado algo do tipo.
Essa é a dica 0800 pra voces desta vez.
“Saber das coisas vale ouro. Compartilhar esse conhecimento não tem preço.”
