Teste de heartbeat do Sidekiq falhou, reiniciando

Olá! Encontrei um erro estranho na minha página de administração: o Sidekiq não está em execução.

Abri os logs e encontrei centenas de erros como:

/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.5.1/lib/logster/logger.rb:112:in `report_to_store'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.5.1/lib/logster/logger.rb:103:in `add_with_opts'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.5.1/lib/logster/logger.rb:54:in `add'
/usr/local/lib/ruby/2.6.0/logger.rb:534:in `warn'
config/unicorn.conf.rb:147:in `check_sidekiq_heartbeat'
config/unicorn.conf.rb:164:in `master_sleep'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.2/lib/unicorn/http_server.rb:296:in `join'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.2/bin/unicorn:128:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `<main>'

Aqui estão os erros do aplicativo:

run-parts: executando /etc/runit/1.d/00-ensure-links
run-parts: executando /etc/runit/1.d/00-fix-var-logs
run-parts: executando /etc/runit/1.d/anacron
run-parts: executando /etc/runit/1.d/cleanup-pids
Limpeza de arquivos PID obsoletos
run-parts: executando /etc/runit/1.d/copy-env
run-parts: executando /etc/runit/1.d/letsencrypt
[Qua 01 Jan 2020 10:40:41 AM UTC] Domínios não alterados.
[Qua 01 Jan 2020 10:40:41 AM UTC] Ignorado, próxima data de renovação: Ter 25 Fev 00:52:11 UTC 2020
[Qua 01 Jan 2020 10:40:41 AM UTC] Adicione '--force' para forçar a renovação.
[Qua 01 Jan 2020 10:40:41 AM UTC] Instalando chave em: /shared/ssl/discourse.example.com.key
[Qua 01 Jan 2020 10:40:41 AM UTC] Instalando cadeia completa em: /shared/ssl/discourse.example.com.cer
[Qua 01 Jan 2020 10:40:41 AM UTC] Executando comando de recarregamento: sv reload nginx
aviso: nginx: não foi possível abrir supervise/ok: arquivo inexistente
[Qua 01 Jan 2020 10:40:41 AM UTC] Erro de recarregamento para :
[Qua 01 Jan 2020 10:40:42 AM UTC] Domínios não alterados.
[Qua 01 Jan 2020 10:40:42 AM UTC] Ignorado, próxima data de renovação: Qua 08 Jan 00:39:10 UTC 2020
[Qua 01 Jan 2020 10:40:42 AM UTC] Adicione '--force' para forçar a renovação.
[Qua 01 Jan 2020 10:40:42 AM UTC] Instalando chave em: /shared/ssl/discourse.example.com_ecc.key
[Qua 01 Jan 2020 10:40:42 AM UTC] Instalando cadeia completa em: /shared/ssl/discourse.example.com_ecc.cer
[Qua 01 Jan 2020 10:40:42 AM UTC] Executando comando de recarregamento: sv reload nginx
aviso: nginx: não foi possível abrir supervise/ok: arquivo inexistente
[Qua 01 Jan 2020 10:40:42 AM UTC] Erro de recarregamento para :
runsvdir iniciado, PID é 628
chgrp: grupo inválido: 'syslog'
rsyslogd: imklog: não foi possível abrir o log do kernel (/proc/kmsg): Operação não permitida.
rsyslogd: falha na ativação do módulo imklog [v8.1901.0 tente https://www.rsyslog.com/e/2145 ]
pid do supervisor: 633 pid do unicorn: 647

Tentei limpar o banco de dados Redis, mas isso não ajudou.

Tenho containers separados para o aplicativo, PostgreSQL e Redis.

Alguma ideia de como corrigir isso?

O Sidekiq está pausado? A fila de jobs está acumulando?

Ele mostra 2 jobs na fila padrão, ambos são Jobs::VersionCheck.
Após limpar o banco de dados do Redis, ele mostra 0 jobs concluídos, 0 falhos e 2 na fila.

A página do agendador mostra que alguns jobs estão na fila ou em execução, mas esses jobs não são contabilizados nas estatísticas da página do Sidekiq. Todos os jobs na página do agendador têm duração vazia ou -1ms.

Portanto, os números não se acumulam; literalmente nada muda.
Como verificar se o Sidekiq está pausado?

Mesmo problema aqui com a última atualização, sem alterações além de apenas atualizar via rebuild. O painel administrativo diz que o Sidekiq não está em execução. Tenho o PostgreSQL e o Redis em um container e o aplicativo em outro; reiniciei todos novamente. As filas têm algumas centenas de itens, mas nada está sendo processado.

EDIT1: Limpar todas as filas não corrigiu nem ajudou em nada; elas estão sendo reabastecidas e ainda não estão processando.

EDIT2: E reconstruí o fórum com toda a indisponibilidade que isso implica, e ainda tenho esta mensagem:

E as filas não estão sendo processadas em /sidekiq. Tudo isso funcionava sem problemas antes da atualização para a versão 2.4.0.beta9 a partir da beta7.

EDIT3: Mais de 50 GB de espaço livre. Executar manualmente um backup (um pouco menos de 300 MB) funciona com sucesso, e ele diz que pausa e retoma o Sidekiq, sem erros relatados no log, mas o Sidekiq ainda parece não estar em execução?

EDIT4: O único log relevante em /logs é o Sidekiq heartbeat test failed, restarting que continua se repetindo.

EDIT5: O Redis parece estar ativo e funcionando corretamente; pelo menos seu arquivo de log está ocupado dizendo que não tem muito o que fazer… E para maior clareza:

[3] pry(main)> Sidekiq.paused?
=> false

EDIT6: Limpei as filas há um tempo atrás, e agora estão de volta a 10 tarefas enfileiradas, mas não processadas.

EDIT7: Descobri que bundle exec sidekiq é a maneira usual de iniciar o Sidekiq em um projeto normal, então vamos tentar executá-lo para ver o que acontece:

root@vps198273-forum:/var/www/discourse# bundle exec sidekiq
2020-01-06T05:10:18.814Z pid=31242 tid=gn383wxbu INFO: Booting Sidekiq 6.0.4 with redis options {:host=>"forum-data", :port=>6379, :namespace=>"sidekiq", :id=>"Sidekiq-server-PID-31242", :url=>nil}
You are connecting to Redis v3.0.6, Sidekiq requires Redis v4.0.0 or greater
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/lib/sidekiq/cli.rb:62:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/bin/sidekiq:12:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/lib/sidekiq/cli.rb:62:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/bin/sidekiq:12:in `<top (required)>'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli/exec.rb:63:in `load'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli/exec.rb:63:in `kernel_load'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli/exec.rb:28:in `run'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli.rb:476:in `exec'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli.rb:30:in `dispatch'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/vendor/thor/lib/thor/base.rb:476:in `start'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/cli.rb:24:in `start'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/exe/bundle:46:in `block in <top (required)>'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/lib/bundler/friendly_errors.rb:123:in `with_friendly_errors'
/usr/local/lib/ruby/gems/2.6.0/gems/bundler-2.1.1/exe/bundle:34:in `<top (required)>'
/usr/local/bin/bundle:23:in `load'
/usr/local/bin/bundle:23:in `<main>'

You are connecting to Redis v3.0.6, Sidekiq requires Redis v4.0.0 or greater

Bem, isso parece interessante? Vamos tentar reconstruir o container de dados e rezar para não estragar os dados, lol…

EDIT8: Bem, parece que está rodando o Redis 5.0.5 (por que não usamos o pubsub do PostgreSQL para isso?), que definitivamente é 4.0.0 ou superior… e a reconstrução terminou. Testei o fórum, os dados parecem ainda estar lá, e temos um pico!


Parece que está consertado! Talvez este post seja útil para alguém. Gostaria que os fóruns me mostrassem o erro que o Sidekiq estava relatando sobre o Redis desatualizado, mas imagino que esses logs estejam indo para algum lugar no abismo, já que não os vi em lugar nenhum. ^.^

Isso é um ótimo trabalho de detetive, espero que ajude outros.

Como você conseguiu um Redis antigo? Você está usando uma instalação não padrão?

Uso uma configuração de múltiplos contêineres e nunca reconstruí o Redis.
Vou tentar reconstruir o Redis.

ATUALIZAÇÃO.
@OvermindDL1, obrigado pelas soluções. Reconstruí o contêiner do Redis e agora tudo está funcionando.

O Sidekiq é uma biblioteca de tarefas em segundo plano e depende do Redis. É super otimizado e maduro, mas suporta apenas o backend do Redis.
Também acho que o message_bus (recursos em tempo real do Discourse) usa o Redis internamente.

Instalação padrão com contêineres separados via Docker, conforme as instruções (para que eu possa criar uma nova versão do Discourse e trocá-las rapidamente sem tempo de inatividade), mas não toco no contêiner de dados, que é onde o Redis está rodando, aparentemente (eu achei que estaria no contêiner principal; fiquei surpreso ao não encontrá-lo rodando nele).

Sim, exatamente a mesma coisa que o @arrowcircle aqui. :slight_smile:

Em uma configuração com 2 contêineres, você ainda precisa reconstruir o contêiner de dados. Recomendo agendar essa reconstrução pelo menos uma vez por ano.

Há alguma maneira de fazer isso sem tempo de inatividade? Esse era o ponto de separá-los inicialmente.

Com tempo de inatividade zero, você precisaria executar réplicas do Redis e do banco de dados. Ainda haveria uma fase curta de somente leitura durante a failover.

Sim, tudo isso é possível, mas você precisaria contratar uma equipe de infraestrutura.

Tudo aqui é de código aberto, sem dinheiro. ^.^;