sábado, 10 de janeiro de 2009

PostgreSQL - Recuperação de Erro “failed to re-find parent key” no start do processo

Esses dias um cliente ligou com problemas no start do PostgreSQL e, verificando nos logs, encontrei o seguinte:

2009-01-07 14:24:15 BRST 3939 LOG: database system was interrupted while in recovery at 2009-01-07 14:19:55 BRST
2009-01-07 14:24:15 BRST 3939 HINT: This probably means that some data is corrupted and you will have to use the last backup for recovery.
2009-01-07 14:24:15 BRST 3939 LOG: checkpoint record is at AF/90DF2348
2009-01-07 14:24:15 BRST 3939 LOG: redo record is at AF/90DF2348; undo record is at 0/0; shutdown FALSE
2009-01-07 14:24:15 BRST 3939 LOG: next transaction ID: 300561523; next OID: 3349191252
2009-01-07 14:24:15 BRST 3939 LOG: next MultiXactId: 347; next MultiXactOffset: 693
2009-01-07 14:24:15 BRST 3939 LOG: database system was not properly shut down; automatic recovery in progress
2009-01-07 14:24:15 BRST 3937 WARNING: autovacuum not started because of misconfiguration
2009-01-07 14:24:15 BRST 3937 HINT: Enable options “stats_start_collector” and “stats_row_level”.
2009-01-07 14:24:15 BRST 3939 LOG: redo starts at AF/90DF238C
2009-01-07 14:24:15 BRST 3940 [unknown] [unknown] [local] LOG: incomplete startup packet
2009-01-07 14:24:16 BRST 3943 postgres postgres [local] FATAL: the database system is starting up
2009-01-07 14:24:16 BRST 3946 postgres postgres [local] FATAL: the database system is starting up
2009-01-07 14:24:16 BRST 3939 LOG: record with zero length at AF/9115D62C
2009-01-07 14:24:16 BRST 3939 LOG: redo done at AF/9115D5D4
2009-01-07 14:24:16 BRST 3939 PANIC: failed to re-find parent key in “2658″ for split pages 173209/173210
2009-01-07 14:24:16 BRST 3937 LOG: startup process (PID 3939) was terminated by signal 6
2009-01-07 14:24:16 BRST 3937 LOG: aborting startup due to startup process failure
2009-01-07 14:24:16 BRST 3938 LOG: logger shutting down
2009-01-07 14:24:16 BRST 3938 LOG: logger shutting down

Não conseguia iniciar o postgresql nem em single-mode… o que fazer então?!?!

Com uma breve pesquisa no Google consegui detectar que era um problema em índices e para solucionar teria de rodar um reindex, etc…. também descobri que já aconteceu esse problema quando rodava o vacuum em bases, e que o mesmo já foi corrigido… até ai tudo bem, mas no meu caso não foi executado um vacuum, o que ocorreu foi alguma falha no servidor (por problemas de queda de energia) e o postgresql não conseguia iniciar de forma alguma.

Fiz algumas tentativas mas todas sem sucesso… mas não tentei usar o pg_resetxlog por não ter certeza dos dados que seriam perdidos com esse procedimento, quis tentar recuperar o máximo de informação possível. Até poderia ter obtido sucesso, mas antes fui investigar o problema dando uma examinada nos fontes do “elefantinho”.

Com um find descobri:

dbseller@dbseller-note07:~/fabrizio/downloads/postgres/src/postgresql-8.1.15$ find . -name “*.c” -exec grep -il “failed to re-find parent key in” {} \;
./src/backend/access/nbtree/nbtpage.c
./src/backend/access/nbtree/nbtinsert.c

Que sorte né (ou azar…rsrsrs)… apenas 2 fontes geram esse log… então resolvi tomar uma medida radial, alterar os fontes e recompilar, então seguem os passos:

1 - Backup Físico do Cluster (antes de qualquer tentativa… para garantir qualquer imprevisto né… heheeh);

2 - Alterei o fonte src/access/nbtree/nbtinsert.c :

de

  /* Check for error only after writing children */
if (pbuf == InvalidBuffer)
elog(ERROR, "failed to re-find parent key in \"%s\" for split pages %u/%u",
RelationGetRelationName(rel), bknum, rbknum);

/* Recursively update the parent */
_bt_insertonpg(rel, pbuf, stack->bts_parent,
0, NULL, new_item, stack->bts_offset,
is_only);

para

  /* Check for error only after writing children */
if (pbuf == InvalidBuffer)
elog(WARNING, "failed to re-find parent key in \"%s\" for split pages %u/%u",
RelationGetRelationName(rel), bknum, rbknum);
else
/* Recursively update the parent */
_bt_insertonpg(rel, pbuf, stack->bts_parent,
0, NULL, new_item, stack->bts_offset,
is_only);

Obs: Também poderia ter alterado o fonte nbtpage.c mas verifiquei que no start do postgresql ele não passa por aquele ponto. Os itens em negrito foram as alterações que efetuei.

3 - Compilar/Instalar fontes com esse Hack;

4 - Iniciar o PostgreSQL com o Hack, e desta vez o startup foi concluido com sucesso… heheheh…. quer dizer… com “um pouco mais de sucesso”;

5 - Reindexar o Catálogo do PostgreSQL (REINDEX SYSTEM postgres);

6 - Parar o PostgreSQL com o Hack e iniciar com os binários originais… aqui foi a supresa… funcionou perfeitamente… não ocorreu mais o erro pois o problema foi em índices do catálogo… e nem poderiam ser em outros índices né, uma vez que o banco não verifica índices de bases no startup, com excessão do catálogo;

7 - REINDEX nas outras bases de dados;

8 - Novo Backup das bases de dados (lógico e físico) sem problemas.

Bom pessoal, podem fazer suas críticas… dizerem que minha solução foi meio que “irresponsável”, e concordo plenamente com essa posição e não recomendo a ninguém sair alterando fontes do postgresql que nem fiz pois os resultados podem ser imprevisiveis… mas o importante é que no meu caso funcionou e gostaria de compartilhar com a comunidade essa pequena “aventura”.

Vida longa ao “elefantinho”!!!!

6 comentários:

  1. Ola Fabrizio,

    Que tamanho mais ou menos tinha essa base?

    Olhando o LOG "PANIC: failed to re-find parent key in “2658″ for split pages 173209/173210"...

    e agora um SELECTizinho:

    # SELECT relname from pg_class where oid=2658;
    relname
    ---------------------------------
    pg_attribute_relid_attnam_index


    Era problema em índice mesmo... o seu procedimento foi interessante mas fica a dúvida: Está tudo íntegro?

    Acompanhe como essa instância se comportará e nos comunique. ":)

    []s

    ResponderExcluir
  2. Amigo Dickson,

    Obrigado pelo questionamento!

    Era uma base pequena, com ~18G...

    Acredito ter ficado tudo íntegro sim... tenho acompanhado essa instância de perto e não encontrei nada de anormal...

    Verifiquei, a nível da nossa aplicação, se houve perda de informação (principais procedimentos do software) e até agora não encontrei problemas.

    Inclusive o gerente do CPD do meu cliente está monitorando com seus usuários se houveram problemas e até agora não obtive nenhum retorno negativo.

    Sugeres algum procedimento para verificação???

    []s

    ResponderExcluir
  3. Além da análise que você já está fazendo, acredito que o monitoramento de logs em busca de erros "obscuros" poderia complementar o seu relatório final do procedimento que você executou.

    No demais parabéns pelo novo blog.

    ResponderExcluir
  4. Seria interessante você citar de onde você tirou a sua solução, não?

    http://archives.postgresql.org/pgsql-admin/2007-03/msg00018.php

    ResponderExcluir
  5. Meu amigo "Anônimo",

    Eis uma feliz (ou infeliz) coincidência... mas realmente não estou plagiando a lista oficial do PostgreSQL e muito menos o Sr. Tom Lane, o qual respeito, e muito, seu trabalho...

    Sofri um dia inteiro "fuçando" nos fontes do PostgreSQL (alterando, compilando, re-compilando, etc), até porque gosto de programação e a estrutura e organização do mesmo é fantástica, uma aula de desenvolvimento...

    Confesso que fiz pouco uso do Sr. Google e inverti um pouco a ordem das coisas... se eu tivesse partido por esse caminho não teria sofrido tanto é verdade e não ficaria agora com essa sensação de ter plagiado alguém...

    Mas infelizmente aconteceu essa coincidência... a questão é que tive um problema, encontrei uma solução (que diga-se de passagem nada convencional) e publiquei exatamente o que fiz... se eu tivesse encontrado a solução mencionada com certeza a teria citado... sem problema algum...

    Não tenho porque fazer uma coisa desse tipo... quantas pessoas passam pelos mesmos problemas e as solucionam da mesma maneira sem saber como as outras procederam??? pense nisso!!!

    Peço desculpas pela demora da publicação desse comentário e desculpem a todos se "re-inventei a roda" com esse post.

    ResponderExcluir