Início / dba / Perguntas / 119766
Accepted
Josip Rodin
Asked: 2015-11-02 07:57:15 +0800 CST

Como verificar se um backup base PostgreSQL + WAL foi restaurado corretamente

  • 772

Os colegas de trabalho estavam tentando extrair uma cópia do banco de dados PostgreSQL de um backup feito em hot standby na versão 9.1, mas não era confiável - nós o executávamos diariamente, mas geralmente acabava com vários erros durante a execução de consultas na cópia.

Infelizmente, não consegui encontrar uma resposta definitiva sobre o motivo na web e precisei de uma boa alma no canal IRC do PostgreSQL para me esclarecer - fazer um backup como esse de um modo de espera não é suportado fora de -the-box nessa versão.

Portanto, para o benefício de outras pessoas que podem ter o mesmo problema e tentar pesquisá-lo no Google, escreverei nossas notas em uma resposta abaixo.

postgresql backup

1 respostas

  1. Best Answer

    A resposta conterá duas seções - primeiro, o que é aceitável ver nos logs após a restauração e, segundo, alguns exemplos do que não é. A primeira seção deve ser bastante determinística, enquanto a segunda é basicamente uma variedade aleatória de tudo o que aconteceu conosco que indica que tivemos um problema.

    Saída de registro aceitável

    no começo:

    2015-07-23 06:51:24 UTC LOG: database system was interrupted; last known up at 2015-07-23 02:10:42 UTC

    É importante ver que o PostgreSQL restaurador sabe quando foi a última vez. Acho que é assim porque significa que está começando de um posto de controle.

    pedido de recuperação xlog min ... passou do ponto atual

    Logo no início, alguns destes podem acontecer:

    2015-07-23 06:51:30 UTC WARNING:  xlog min recovery request 1027/B0A28D98 is past current point 1027/2BE36DA8
2015-07-23 06:51:30 UTC CONTEXT:  writing block 0 of relation base/117264/9551898_vm
       xlog redo insert: rel 1663/117264/8310261; tid 68622/40

    Mas de acordo com http://www.postgresql.org/message-id/CAB7nPqTd43hqpuC+M8fo+xkqHv1WtFe_16NUttu1pHcBtZhZmw@mail.gmail.com isso é inofensivo

    FATAL: o sistema de banco de dados está inicializando

    Qualquer número destes pode acontecer:

    2015-07-23 06:51:24 UTC FATAL:  the database system is starting up

    Na verdade, isso deve ser inofensivo porque, em nosso caso, foi o resultado de SELECT 1consultas automatizadas do tipo ping que os scripts executam para verificar se o PostgreSQL está pronto.

    pageaddr inesperado ... no arquivo de log ..., segmento ..., deslocamento ...

    No final tem isso:

    2015-07-23 06:52:21 UTC LOG:  restored log file "0000000100001027000000B2" from archive
2015-07-23 06:52:21 UTC LOG:  consistent recovery state reached at 1027/B2F8F2F8
sh: 1: cannot open ../../../wal_backup/0000000100001027000000B3: No such file
2015-07-23 06:52:21 UTC LOG:  unexpected pageaddr 1027/AA000000 in log file 4135, segment 179, offset 0
2015-07-23 06:52:21 UTC LOG:  redo done at 1027/B2F8F2F8
2015-07-23 06:52:21 UTC LOG:  last completed transaction was at log time 2015-07-23 02:17:33.842307+00

    Mas de acordo com http://www.postgresql.org/message-id/CAGrpgQ-BbXUNErrAtToYhRyUef9_GdUQz1T3CXbpTMLTnuKANQ@mail.gmail.com isso também é inofensivo

    Observe que pode haver mais restaurações WAL após esse ponto:

    2015-07-23 06:52:21 UTC LOG:  restored log file "0000000100001027000000B2" from archive

    Isso significaria apenas que você forneceu mais arquivos WAL por meio recovery.confdo que o estritamente necessário.

    00000002.history: Esse arquivo não existe

    Bem no final do processo de desenrolamento do WAL, há o seguinte:

    sh: 1: cannot open ../../../wal_backup/00000002.history: No such file
2015-07-23 06:52:21 UTC LOG:  selected new timeline ID: 2
sh: 1: cannot open ../../../wal_backup/00000001.history: No such file
2015-07-23 06:52:21 UTC LOG:  archive recovery complete

    Isso é aparentemente/esperançosamente irrelevante, porque é aí que o banco de dados restaurado (clone) começa uma nova vida (linha do tempo).

    Saída de registro inaceitável

    no começo:

    2015-07-20 12:38:31 UTC LOG: database system was interrupted while in recovery at log time 2015-07-20 01:41:22 UTC

    Isso é crítico - significa que o processo de backup não foi iniciado no momento certo - após um ponto de pg_start_backup(...)verificação - em vez disso, o banco de dados estava funcionando normalmente e estava em algum ponto aleatório, o que significa que essa restauração é mais semelhante à restauração de um banco de dados com falha.

    pedaço faltando em pg_toast...

    Isso indica que a restauração não estava correta. Como uma solução rápida, tentamos a receita de http://postgresql.nabble.com/select-table-indicate-missing-chunk-number-0-for-toast-value-96635-in-pg-toast-2619- td5682176.html

    mydb=# vacuum analyze mytable; -- trigger the error to see the problem toast
ERROR:  missing chunk number 0 for toast value 13044178 in pg_toast_2619
mydb=# reindex table pg_toast.pg_toast_2619;
REINDEX

    Às vezes, isso pode colocar a tabela de volta em um estado de funcionamento, mas às vezes também não tem esse efeito. Depois disso, cutucamos um pouco mais e pensamos que descobrimos que é apenas pg_statistic, que é descartável:

    mydb=# reindex table pg_statistic;
ERROR:  could not create unique index "pg_statistic_relid_att_inh_index"
DETAIL:  Key (starelid, staattnum, stainherit)=(884792, 34, f) is duplicated.
mydb=# delete from pg_statistic;
DELETE 188540
mydb=# reindex table pg_statistic;
REINDEX
mydb=# vacuum analyze mytable;
VACUUM

    o link esquerdo do irmão direito não corresponde

    CREATE TABLE "myschema"."mytable" ( ... )
ERROR: right sibling's left-link doesn't match: block 27 links to 21379 instead of expected 21393 in index "pg_depend_reference_index"

    Tentamos contornar isso rapidamente fazendo:

    mydb=# set zero_damaged_pages=on;
SET
mydb=# reindex table pg_depend;
REINDEX
mydb=# set zero_damaged_pages=off;
SET

    não foi possível ler o bloco no arquivo...

    2015-05-12 13:32:53 UTC ERROR:  could not read block 76408 in file "pg_tblspc/4606764/PG_9.1_201105231/117264/4614269": read only 0 of 8192 bytes

    Isso foi obviamente uma chatice. Não poderíamos contornar isso rapidamente:

    mydb=# select cl.relfilenode, nsp.nspname as schema_name, cl.relname, cl.relkind from pg_class cl join pg_namespace nsp on cl.relnamespace = nsp.oid where relfilenode = 4614269;
 relfilenode | schema_name | relname | relkind
-------------+-------------+---------+---------
     4614269 | myschema    | mytable | r
(1 row)

mydb=# select pg_relation_filepath('myschema.mytable');
               pg_relation_filepath
---------------------------------------------------
 pg_tblspc/4606764/PG_9.1_201105231/117264/4614269
(1 row)

% sudo ls -lah /var/lib/postgresql/9.1/main/pg_tblspc/4606764/PG_9.1_201105231/117264/4614269
-rw------- 1 postgres postgres 597M May 11 19:22 /var/lib/postgresql/9.1/main/pg_tblspc/4606764/PG_9.1_201105231/117264/4614269

    Esse foi um bom indicador de que muitos dados estavam sendo "perdidos".

    o valor da chave duplicada viola a restrição exclusiva "pg_type_typname_nsp_index"

    Este foi outro indicador de que a restauração foi interrompida:

    CREATE TABLE "myschema"."mytable" ( ... )
ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index" DETAIL: Key (typname, typnamespace)=(mytable_mycolumn_seq, 3780903) already exists.

    O truque rápido para isso foi mover a posição da sequência:

    SELECT setval('mytable_id_seq', (SELECT MAX(id) FROM mytable));
    • 9

relate perguntas