Restauração de backup falhou, sidekiq não para e depois foge

Fiz uma reconstrução esta manhã e tentei restaurar um backup no container. Estou na versão 2.6.0.beta5 (75a893fd61), com tudo dentro do container.

Normalmente, a restauração do backup funcionaria (já funcionou anteriormente), mas hoje falhou assim:

Starting restore: app-2020-11-06-033740-v20201009190955.tar.gz
[STARTED]
'system' has started the restore!
Marking restore as running...
Making sure /var/www/discourse/tmp/restores/default/2020-11-06-084354 exists...
Copying archive to tmp directory...
Unzipping archive, this may take a while...
Extracting dump file...
Validating metadata...
  Current version: 20201103103401
  Restored version: 20201009190955
Enabling readonly mode...
Pausing sidekiq...
Waiting up to 60 seconds for Sidekiq to finish running jobs...
Waiting for sidekiq to finish running jobs... #2
Waiting for sidekiq to finish running jobs... #3
Waiting for sidekiq to finish running jobs... #4
Waiting for sidekiq to finish running jobs... #5
Waiting for sidekiq to finish running jobs... #6
Waiting for sidekiq to finish running jobs... #7
Waiting for sidekiq to finish running jobs... #8
Waiting for sidekiq to finish running jobs... #9
Waiting for sidekiq to finish running jobs... #10
EXCEPTION: Sidekiq did not finish running all the jobs in the allowed time!
/var/www/discourse/lib/backup_restore/system_interface.rb:89:in `block in wait_for_sidekiq'
/var/www/discourse/lib/backup_restore/system_interface.rb:84:in `loop'
/var/www/discourse/lib/backup_restore/system_interface.rb:84:in `wait_for_sidekiq'
/var/www/discourse/lib/backup_restore/restorer.rb:47:in `run'
script/discourse:143:in `restore'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/thor-1.0.1/lib/thor/command.rb:27:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/thor-1.0.1/lib/thor/invocation.rb:127:in `invoke_command'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/thor-1.0.1/lib/thor.rb:392:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/thor-1.0.1/lib/thor/base.rb:485:in `start'
script/discourse:284:in `<top (required)>'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/cli/exec.rb:63:in `load'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/cli/exec.rb:63:in `kernel_load'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/cli/exec.rb:28:in `run'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/cli.rb:476:in `exec'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/cli.rb:30:in `dispatch'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor/base.rb:476:in `start'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/cli.rb:24:in `start'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/exe/bundle:46:in `block in <top (required)>'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/lib/bundler/friendly_errors.rb:123:in `with_friendly_errors'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.4/exe/bundle:34:in `<top (required)>'
/usr/local/bin/bundle:23:in `load'
/usr/local/bin/bundle:23:in `<main>'
Trying to rollback...
There was no need to rollback
Cleaning stuff up...
Removing tmp '/var/www/discourse/tmp/restores/default/2020-11-06-084354' directory...
Unpausing sidekiq...
Disabling readonly mode...
Marking restore as finished...
Notifying 'system' of the end of the restore...
Finished!
[FAILED]
Restore done.

Depois disso, tenho um processo Ruby usando 100% da CPU há horas. Esse processo é descrito como:

# ps aux | grep sidekiq
discour+    141  100  5.0 9302596 401484 ?      SNl  06:34 127:46 sidekiq 6.1.2 discourse [5 of 5 busy]

Se eu parar e reiniciar o container, esse Sidekiq volta a usar 100% da CPU. O sidekiq.log está vazio e o production.log não mostra muito.

Como posso descobrir o que esse Sidekiq está fazendo? Alguém mais já encontrou problemas na restauração de backups com essa versão?

Um gentil gentileza me indicou o console do Sidekiq e parece que o Sidekiq está ocupado com a geração de miniaturas:

Os backups que utilizo não incluem miniaturas, então isso pode ser esperado, exceto que eu já havia executado rake posts:rebake e, em seguida, rake posts:rebake_uncooked_posts após a restauração do backup de teste anterior, então pensei que isso teria feito toda a geração de miniaturas (o rebake levou cerca de 1 hora para algo como 100.000 posts, e o rebake_uncooked não fez nada, pois imagino que o rebake completo já tivesse resolvido tudo).

Supondo que essa carga de trabalho seja o que impede o backup de ter sucesso, restaurar um backup não deveria purgar as filas de tarefas primeiro?

Além disso, por que o Sidekiq está gerando miniaturas quando aparentemente não há nada a fazer, ou os comandos rebake apenas colocam o trabalho na fila?

# rake posts:rebake_uncooked_posts
Rebaking uncooked posts on default

0 posts done!

Isso mesmo. O rebake enfileira um monte de coisas em vez de executá-las todas de fato.

Provavelmente. Mas geralmente parte-se do pressuposto de que, se você sabe o suficiente para restaurar um backup, também sabe o suficiente para limpar a fila do Sidekiq primeiro; normalmente, você restauraria para um site vazio.

Acredito que seja esse o caso.

Obrigado, isso está começando a fazer muito mais sentido.

Então, a sequência correta seria primeiro destruir, depois (re)criar o container, entrar nele e restaurar o backup?

Se for esse o caso, ótimo, embora talvez o Discourse pudesse fornecer essa dica/aviso ao iniciar uma restauração em um container não vazio.

Essa é a opção nuclear (e você provavelmente só precisaria apagar os dados do Redis e, em seguida, reconstruir). Geralmente, não há um milhão de tarefas em execução e isso simplesmente não é um problema. Mas como você aparentemente está executando duas restaurações seguidas e a primeira ainda não terminou completamente quando você inicia novamente, você é um caso especial.

A outra coisa a fazer seria ir até /sidekiq e excluir todas as tarefas enfileiradas. Leva apenas alguns cliques.

Um bom teste para recuperação de desastres então :smiley:

Você tem razão de que provavelmente é um caso um pouco especial. Tenho tentado reduzir o tempo de rebake, então estou restaurando backups e cronometrando em diferentes circunstâncias (restaurar sem miniaturas leva de 2 a 3 dias para concluir o rebake por padrão!). Tudo isso é trabalho preliminar para uma migração de site.

Acho que entendo muito mais agora, obrigado. Mas para algo tão crítico quanto backups, acho que seria sensato que o Discourse garantisse que seja o mais confiável possível (por exemplo, esvaziar as filas do Sidekiq antes de iniciar) ou emita avisos claros de que outras etapas são necessárias se detectar problemas potenciais para a restauração.

Apenas você sabe qual fazer.

Sugiro que crie um backup com miniaturas (configuração do site include_thumbnails_in_backups) ao migrar para um servidor diferente.

Obrigado! Essa é uma opção que também tentei, mas o backup, embora seja apenas cerca de 6 GB maior, leva aproximadamente uma hora a mais para ser criado. Parece que é a etapa do tar que está consumindo o tempo — talvez haja algo no meu hardware mais antigo, onde muitos arquivos pequenos são lentos para acessar. O nível de compressão gzip está definido como 1, então acredito que o gargalo seja de E/S, e não de CPU. O novo host consegue fazer o mesmo backup em 30 a 40 minutos.

Talvez eu esteja apenas um pouco impaciente com isso e deveria aceitar que o backup leve mais tempo, mas, como o site principal fica no modo somente leitura durante esse processo, estou bastante interessado em minimizar esse tempo.