Test heartbeat di Sidekiq fallito, riavvio in corso

Ciao! Ho trovato un errore strano nella mia pagina di amministrazione: Sidekiq non è in esecuzione.
Ho aperto i log e ho trovato centinaia di errori come questo:

/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>'

Ecco gli errori dell’applicazione:

run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
run-parts: executing /etc/runit/1.d/letsencrypt
[Wed 01 Jan 2020 10:40:41 AM UTC] Domains not changed.
[Wed 01 Jan 2020 10:40:41 AM UTC] Skip, Next renewal time is: Tue Feb 25 00:52:11 UTC 2020
[Wed 01 Jan 2020 10:40:41 AM UTC] Add '--force' to force to renew.
[Wed 01 Jan 2020 10:40:41 AM UTC] Installing key to:/shared/ssl/discourse.example.com.key
[Wed 01 Jan 2020 10:40:41 AM UTC] Installing full chain to:/shared/ssl/discourse.example.com.cer
[Wed 01 Jan 2020 10:40:41 AM UTC] Run reload cmd: sv reload nginx
warning: nginx: unable to open supervise/ok: file does not exist
[Wed 01 Jan 2020 10:40:41 AM UTC] Reload error for :
[Wed 01 Jan 2020 10:40:42 AM UTC] Domains not changed.
[Wed 01 Jan 2020 10:40:42 AM UTC] Skip, Next renewal time is: Wed Jan  8 00:39:10 UTC 2020
[Wed 01 Jan 2020 10:40:42 AM UTC] Add '--force' to force to renew.
[Wed 01 Jan 2020 10:40:42 AM UTC] Installing key to:/shared/ssl/discourse.example.com_ecc.key
[Wed 01 Jan 2020 10:40:42 AM UTC] Installing full chain to:/shared/ssl/discourse.example.com_ecc.cer
[Wed 01 Jan 2020 10:40:42 AM UTC] Run reload cmd: sv reload nginx
warning: nginx: unable to open supervise/ok: file does not exist
[Wed 01 Jan 2020 10:40:42 AM UTC] Reload error for :
Started runsvdir, PID is 628
chgrp: invalid group: ‘syslog’
rsyslogd: imklog: cannot open kernel log (/proc/kmsg): Operation not permitted.
rsyslogd: activation of module imklog failed [v8.1901.0 try https://www.rsyslog.com/e/2145 ]
supervisor pid: 633 unicorn pid: 647

Ho provato a svuotare il database Redis, ma non ha aiutato.
Ho container separati per l’app, PostgreSQL e Redis.
Avete qualche idea su come risolvere questo problema?

Sidekiq è in pausa? Le code dei job si stanno accumulando?

Mostra 2 lavori nella coda predefinita, entrambi sono Jobs::VersionCheck.
Dopo aver svuotato il database Redis, mostra 0 lavori completati, 0 falliti, 2 in coda.

La pagina dello scheduler mostra che alcuni lavori sono in coda o in esecuzione, ma questi lavori non vengono conteggiati nelle statistiche della pagina di Sidekiq. Tutti i lavori nella pagina dello scheduler hanno una durata vuota o di -1 ms.

Quindi i numeri non aumentano, letteralmente nulla cambia.
Come verificare se Sidekiq è in pausa?

Stesso problema qui con l’ultima aggiornamento, nessun cambiamento se non l’aggiornamento tramite un rebuild. La dashboard di amministrazione indica che Sidekiq non è in esecuzione. Ho PostgreSQL e Redis in un container e l’app in un altro; li ho riavviati tutti di nuovo. Le code hanno alcune centinaia di elementi, ma nulla viene elaborato.

EDIT1: Svuotare tutte le code non ha risolto né aiutato in alcun modo; si stanno ripopolando e continuano a non essere elaborate.

EDIT2: Ho anche ricostruito il forum, con tutti i tempi di inattività che ciò comporta, e ricevo ancora questo messaggio:

Le code non vengono elaborate in /sidekiq. Tutto funzionava senza problemi prima dell’aggiornamento alla versione 2.4.0.beta9 partendo dalla beta7.

EDIT3: Oltre 50 GB di spazio libero. Eseguire manualmente un backup (appena sotto i 300 MB) ha avuto successo; viene indicato che Sidekiq viene messo in pausa e ripreso, senza errori riportati nei log, ma Sidekiq sembra comunque non essere in esecuzione?

EDIT4: L’unico log rilevante in /logs è Sidekiq heartbeat test failed, restarting, che continua a ripetersi.

EDIT5: Redis sembra essere attivo e funzionante correttamente; almeno il suo file di log è occupato a dire che non ha molto da fare… Per chiarezza:

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

EDIT6: Ho svuotato le code un po’ fa, ora sono tornate a 10 elementi in coda ma non elaborati.

EDIT7: Ho scoperto che bundle exec sidekiq è il modo usuale per avviare Sidekiq in un progetto normale, quindi proviamo a eseguirlo per vedere cosa succede:

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/bin/sidekiq:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/sidekiq-6.0.4/bin/sidekiq:23: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

Beh, questo sembra interessante? Proviamo a ricostruire il container dei dati e preghiamo per non toccare i dati, lol…

EDIT8: Sembra che ora stia eseguendo Redis 5.0.5 (perché non viene usato il pubsub di PostgreSQL per questo?), che è sicuramente 4.0.0 o superiore… e il rebuild è completato. Sto testando il forum, i dati sembrano ancora presenti e abbiamo un picco!


Sembra risolto! Forse questo post sarà utile a qualcuno. Vorrei che il forum mi mostrasse l’errore che Sidekiq stava dando riguardo a una versione obsoleta di Redis, ma immagino che quei log vadano semplicemente nel nulla, dato che non li ho trovati da nessuna parte. ^.^

Questo è un ottimo lavoro di investigazione, spero che aiuti anche altri.

Come hai ottenuto una versione antica di Redis? Stai utilizzando un’installazione non standard?

Utilizzo un setup multicontainer e non ho mai ricostruito Redis.
Proverò a ricostruire il container Redis.

AGGIORNAMENTO.
@OvermindDL1, grazie per le soluzioni. Ho ricostruito il container Redis e ora tutto funziona.

Sidekiq è una libreria per task in background e dipende da Redis. È super ottimizzata e matura, ma supporta solo il backend Redis.
Penso anche che message_bus (le funzionalità in tempo reale di Discourse) utilizzi Redis sotto il cofano.

Installazione standard con container Docker separati, come da istruzioni (così posso costruire una nuova versione di Discourse e poi scambiarle rapidamente senza downtime), ma non tocco il container dei dati, dove apparentemente gira Redis (pensavo fosse nel container principale, mi sono sorpreso quando non sono riuscito a trovarlo in esecuzione nel container principale).

Sì, esattamente la stessa cosa di @arrowcircle qui. :slight_smile:

In una configurazione a 2 container è comunque necessario ricreare il container dei dati; ti consiglio di pianificarlo almeno una volta all’anno.

C’è un modo per farlo senza downtime? Questo era il punto di separarli inizialmente.

Per avere zero tempi di inattività, dovresti eseguire un replica di Redis e un replica del database. Avresti comunque una breve fase di sola lettura durante il failover.

Sì, tutto questo è possibile, ma dovresti assumere un team di infrastruttura.

Tutto qui è open source, niente soldi. ^.^;