Tenho um fórum funcional e gostaria de ver algumas coisas que deram errado há alguns dias. Estou na AWS, então criei uma AMI do fórum funcional, iniciei uma nova instância e tentei restaurar um backup de alguns dias atrás. A operação falhou com as mensagens abaixo.
Não pode ser um erro de versão ou incompatibilidade de esquema, pois o servidor foi construído a partir de uma imagem fresca do fórum funcional.
Tentei reconstruir.
Tentei restaurar a partir de um backup diferente de apenas um dia atrás — mesmo resultado.
A única coisa estranha que fiz foi excluir arquivos PDF do diretório de uploads (…/uploads/original/1X/*.pdf) para liberar espaço. Vou tentar novamente sem esse passo, mas parece improvável que seja o culpado.
> [2019-11-30 01:17:44] 'admin' iniciou a restauração!
> [2019-11-30 01:17:44] Marcando restauração como em execução...
> [2019-11-30 01:17:44] Verificando se /var/www/discourse/tmp/restores/default/2019-11-30-011744 existe...
> [2019-11-30 01:17:44] Baixando o arquivo compactado para o diretório temporário...
> [2019-11-30 01:23:24] Descompactando o arquivo, isso pode levar algum tempo...
> [2019-11-30 01:27:52] Nenhum arquivo de metadados para extrair.
> [2019-11-30 01:27:52] Validando metadados...
> [2019-11-30 01:27:52] Versão atual: 20191129144706
> [2019-11-30 01:27:52] Versão restaurada: 20191120015344
> [2019-11-30 01:27:52] Extraindo o arquivo de dump...
> [2019-11-30 01:50:57] comando inválido \N
> [2019-11-30 01:50:57] comando inválido \N
>
>
> < repete cerca de 100 vezes >
>
> [2019-11-30 01:51:07] comando inválido \N
> [2019-11-30 01:54:13] comando inválido \N
> [2019-11-30 01:54:13] EXCEÇÃO: psql falhou
> [2019-11-30 01:54:14] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> etc...
Eu associaria esses erros à compatibilidade de versão do PostgreSQL, mas vi esses erros de \N outro dia em um sistema que ficou sem espaço em disco (eu estava restaurando no mesmo sistema que fez o backup). Não concluí o diagnóstico do problema (era outro problema bizarro que eu estava enfrentando, e restaurar um backup em outro servidor resolveu o problema; fiquei me perguntando se restaurar no mesmo servidor teria resolvido).
Você mencionou que estava com pouco espaço. Suspeito que esse seja o problema. A restauração consome muito espaço, pois descomprime o backup e, portanto, exige duas cópias completas dele, além do espaço necessário para realizar a restauração e permitir o revert caso ocorra falha.
Piora, mas talvez esteja mais próximo do verdadeiro problema… Na hipótese de que eu precisasse de mais espaço em disco, criei uma nova instância a partir da minha imagem, desta vez com 100 GB, em comparação com os 50 GB anteriores. (Os backups têm 5 GB cada e são armazenados no S3.) Desta vez, obtive um erro explícito: “No space left on device” (Sem espaço restante no dispositivo). No entanto, o comando df mostra bastante espaço livre.
> [2019-11-29 22:42:58] Garantindo que /var/www/discourse/tmp/restores/default/2019-11-29-224258 existe...
> [2019-11-29 22:42:58] Baixando o arquivo para o diretório tmp...
> [2019-11-29 22:45:46] Descompactando o arquivo, isso pode demorar um pouco...
> [2019-11-29 22:51:46] Nenhum arquivo de metadados para extrair.
> [2019-11-29 22:51:46] Validando metadados...
> [2019-11-29 22:51:46] Versão atual: 20191129144706
> [2019-11-29 22:51:46] Versão restaurada: 20191108000414
> [2019-11-29 22:51:46] Extraindo o arquivo dump...
> [2019-11-29 22:53:47] EXCEÇÃO: No space left on device @ io_write - /shared/tmp/restores/default/2019-11-29-224258/dump.sql
> [ec2-user@ip-172-31-47-237 discourse]$ df / -h
> Filesystem Size Used Avail Use% Mounted on
> /dev/xvda1 99G 28G 71G 28% /
Curiosamente, não há nada no diretório referenciado:
Poderia ser um problema com o arquivo de swap? A instância EC2 é uma t2.small com 2 GB de memória, então há muito tempo criei um arquivo de swap no fórum que estava funcionando. Acredito que o arquivo de swap seria replicado na nova instância. Não sou especialista, mas acho que o arquivo de swap existe, pois não me permitiu criar um novo e também porque:
> /var/www/discourse# swapon -s
> Filename Type Size Used Priority
> /swapfile file 2097148 1024 -2
‘No space left on device’ não ocorre apenas quando o dispositivo está sem gigabytes, mas também quando o sistema de arquivos está sem inodes. Mas claramente esse não é o problema aqui. (iUse% estaria em 100% então).
Ainda sem sucesso. Pensei em tentar restaurar em uma nova instância do Lightsail, em vez de lançar uma AMI da minha instância EC2 funcional. Ainda falha, mas as mensagens são um pouco diferentes.
Ambas as instâncias, antiga e nova, estão atualizadas, ambas são instalações padrão do Docker, e ambas estão executando a mesma versão do postgres:
Criando funções ausentes no esquema discourse_functions
Não é possível restaurar em um esquema diferente, restaurando no local
Poderia estar relacionado a plugins? Tenho vários plugins, tanto suportados quanto personalizados, instalados no site “origem”. Alguns usam campos de usuário personalizados. Tentei restaurar em sites “destino” limpos, com e sem plugins.
Alguma orientação sobre como começar a comparar os esquemas?
> [2019-12-07 04:51:36] 'admin' iniciou a restauração!
> [2019-12-07 04:51:36] Marcando a restauração como em andamento...
> [2019-12-07 04:51:36] Garantindo que /var/www/discourse/tmp/restores/default/2019-12-07-045136 exista...
> [2019-12-07 04:51:36] Baixando o arquivo compactado para o diretório tmp...
> [2019-12-07 04:53:49] Descompactando o arquivo, isso pode levar um tempo...
> [2019-12-07 04:57:12] Nenhum arquivo de metadados para extrair.
> [2019-12-07 04:57:12] Validando metadados...
> [2019-12-07 04:57:12] Versão atual: 20191129144706
> [2019-12-07 04:57:12] Versão restaurada: 20191120015344
> [2019-12-07 04:57:12] Extraindo o arquivo de dump...
> [2019-12-07 04:59:10] Criando funções ausentes no esquema discourse_functions
> [2019-12-07 04:59:11] Não é possível restaurar em um esquema diferente, restaurando no local
> [2019-12-07 05:05:02] ERRO: a transação atual foi abortada, comandos ignorados até o fim do bloco de transação
> [2019-12-07 05:05:03] ERRO: a transação atual foi abortada, comandos ignorados até o fim do bloco de transação
> < repete cerca de 100 vezes >
> [2019-12-07 05:05:03] ERRO: a transação atual foi abortada, comandos ignorados até o fim do bloco de transação
> [2019-12-07 05:05:03] EXCEÇÃO: psql falhou
> [2019-12-07 05:05:03] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> < resto do rastreamento >
Claramente, algo está errado dentro do PostgreSQL. Você já analisou os logs dele?
Aposta arriscada: isso pode estar relacionado à memória? Você pode tentar monitorar a saída do free -m durante a restauração e verificar se a memória (virtual) se esgota.
Sei que é uma pergunta difícil, já que não sabemos qual é o problema, mas, em geral, devo instalar os plugins no site de destino antes de tentar restaurar? Ou a restauração baixa e cria os plugins?
Sim, você deve — a restauração não fará isso por você.
Por outro lado, não acho que esse seja o seu problema, já que a restauração vai cuidar da estrutura correta do banco de dados (incluindo itens específicos de plugins).
Criei um novo Lightsail de $20 com 4 GB de memória. Acompanhei o comando ‘free -m’ durante a restauração. Sempre houve memória livre e disponível em quantidade suficiente.
Os erros específicos variam dependendo de eu ter instalado os plugins ou não, mas provavelmente têm a mesma causa raiz. Neste caso, não instalei os plugins antes do backup. Existem duas classes de erros:
Nos logs do postgres, recebo muitos desses, às vezes no caractere 34 e às vezes no caractere 41.
discourse@discourse ERROR: relação “user_auth_tokens” não existe no caractere 34
Esses não têm uma saída correspondente na página admin > backup > log, e a restauração continua por vários minutos apesar desses erros.
O segundo erro depende de os plugins estarem instalados. Neste caso, não os instalei, então recebo um erro sobre o Data Explorer, e é aí que tudo dá errado.
Em admin > backup > logs:
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] ERROR: não foi possível criar o índice único “index_plugin_store_rows_on_plugin_name_and_key”
[2019-12-07 07:38:34] DETAIL: A chave (plugin_name, key)=(discourse-data-explorer, q:-6) está duplicada.
[2019-12-07 07:38:34] ERROR: a transação atual foi abortada, comandos ignorados até o final do bloco de transação
[2019-12-07 07:38:34] ERROR: a transação atual foi abortada, comandos ignorados até o final do bloco de transação
< repete 1000X e encerra >
E a saída correspondente no log do postgres:
2019-12-07 07:38:34.718 UTC [8991] discourse@discourse LOG: duração: 165.427 ms statement: CREATE INDEX index_notifications_on_user_
id_and_topic_id_and_post_number ON public.notifications USING btree (user_id, topic_id, post_number);
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse ERROR: não foi possível criar o índice único “index_plugin_store_rows_on_plugin_name_an
d_key”
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse DETAIL: A chave (plugin_name, key)=(discourse-data-explorer, q:-6) está duplicada.
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse STATEMENT: CREATE UNIQUE INDEX index_plugin_store_rows_on_plugin_name_and_key O
N public.plugin_store_rows USING btree (plugin_name, key);
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse ERROR: a transação atual foi abortada, comandos ignorados até o final do bloco de transactio
n
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse STATEMENT: CREATE INDEX index_policy_users_on_post_policy_id_and_user_id ON pub
lic.policy_users USING btree (post_policy_id, user_id);
Acho que o #1 não é fatal e é apenas um efeito colateral da restauração no local.
Você pode considerar (exportar e) excluir todas as consultas do explorador de dados e remover o plugin do explorador de dados antes de criar seu backup.
Alternativamente, você pode postar o conteúdo relevante da tabela plugin_store_rows?
De fato, existem consultas duplicadas com pares (plugin_name, key) duplicados, por exemplo, q:-11 e q:-2, mas com IDs únicos. Não vejo nenhum padrão entre as duplicatas, como se fossem minhas consultas favoritas ou algo assim.
Portanto, meu próximo passo será remover as duplicatas, fazer um backup e tentar restaurar a partir dele.
Não consigo reproduzir isso em um site de teste limpo, mas ocorre consistentemente no meu site de produção. Instalei todos os plugins de produção no site de teste, mas ainda não consigo reproduzir.
Como posso rastrear o que está errado no meu site de produção?
Como posso remover as consultas duplicadas, já que elas pertencem ao sistema? Preciso executar sudo -u postgres psql discourse...? Parece assustador.
