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”!!!!
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.
http://archives.postgresql.org/pgsql-admin/2007-03/msg00018.php
No demais parabéns pelo novo blog.
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
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