Sidekiq のハートビートテストに失敗し、再起動中

サポート インストール
1

こんにちは！管理ページで奇妙なエラーを見つけました。Sidekiq が実行されていないようです。
ログを開くと、以下のような数百件のエラーが見つかりました：

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

アプリからのエラーは以下の通りです：

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

Redis DB をフラッシュしてみましたが、効果はありませんでした。
アプリ、PostgreSQL、Redis にはそれぞれ別のコンテナを使用しています。
この問題を解決する方法について、何かアイデアはありますか？

2

Sidekiqは一時停止されていますか？ジョブキューの数が蓄積していますか？

3

デフォルトキューに 2 つのジョブが表示されますが、どちらも Jobs::VersionCheck です。
Redis DB をフラッシュした後、完了したジョブが 0、失敗したジョブが 0、キューイング中のジョブが 2 と表示されます。

スケジューラーページにはいくつかのジョブがキューイング中または実行中と表示されていますが、これらのジョブは Sidekiq ページの統計にはカウントされません。スケジューラーページ上のすべてのジョブの継続時間は空または -1ms です。

そのため、数値が増加せず、実際には何も変化しません。
Sidekiq が一時停止されているかを確認するにはどうすればよいですか？

4

最新のアップデートで同じ問題が発生しています。再ビルドによる更新以外に変更はありませんが、管理ダッシュボードには Sidekiq が実行されていないと表示されています。Postgres と Redis はコンテナ内で、アプリは別のコンテナで実行されており、すべて再起動しました。キューには数百件溜まっていますが、処理は進んでいません。

EDIT1: キューをすべてクリアしても解決せず、何も改善されませんでした。キューは再び溜まり続け、処理されません。

EDIT2: forum を再ビルドし、それに伴うダウンタイムを経験しましたが、まだこのメッセージが表示されます：

image
image1084×160 14.4 KB

また、/sidekiq においてキューは処理されていません。これは beta7 から 2.4.0.beta9 へのアップデート前は問題なく動作していました。

EDIT3: 空き容量は 50GB 以上あります。バックアップを手動で実行（約 300MB 未満）すると正常に完了し、Sidekiq の一時停止と再開が行われたと表示されますが、ログにエラーは報告されません。それでも Sidekiq は実行されていないようです。

EDIT4: /logs で注目すべきログは、「Sidekiq heartbeat test failed, restarting」というメッセージが繰り返し表示されるものだけです。

EDIT5: Redis は正常に動作しているようです。少なくともログファイルは「やるべきことがあまりない」と忙しく書き込んでいます… 明確にするために：

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

EDIT6: 数分前にキューをクリアしましたが、再び 10 件のタスクがキューに溜まり、処理されません。

EDIT7: 通常のプロジェクトでは bundle exec sidekiq が Sidekiq を起動する一般的な方法だと分かりました。実際に実行して何が起こるか試してみましょう：

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

これは興味深いですね？データコンテナを再ビルドして、データをいじる恐怖から祈りながら試してみましょう… lol…

EDIT8: どうやら Redis 5.0.5 が実行されているようです（なぜこのために PostgreSQL の pubsub が使われないのでしょうか？）。これは確かに 4.0.0 以上です… 再ビルドが完了し、forum をテストしたところ、データは残っており、スパイクが発生しました！

image
image367×572 61.8 KB

修正されたようです！この投稿が誰かの役に立つかもしれません。forum が Sidekiq の古い Redis に関するエラーを表示してくれればよかったのですが、おそらくそのログはどこか虚空に消えているのでしょう。どこにも見つからなかったので。:slight_smile:

5

これは非常に優れた調査結果です。他の人々にも役立つことを願っています。

6

どのようにして古い Redis を入手されたのですか？標準的ではないインストールを使用されていますか？

7

私はマルチコンテナ構成を使用しており、Redis は再構築したことがありません。Redis を再構築してみます。

追記。
@OvermindDL1 さん、解決策をありがとうございます。Redis コンテナを再構築したところ、すべて正常に動作するようになりました。

Sidekiq はバックグラウンドタスクライブラリであり、Redis に依存しています。非常に最適化され成熟していますが、Redis バックエンドのみをサポートしています。
また、message_bus（Discourse のリアルタイム機能）も内部的に Redis を使用していると考えています。

8

ドキュメントに従った標準的な Docker の分割コンテナインストールを行っています（新しい Discourse バージョンを構築し、ダウンタイムなしで素早く切り替えるため）。ただし、データコンテナには手を加えていません。Redis はおそらくそちらで動作しているようです（メインコンテナで動作していると思い込んでいたため、メインコンテナ内で見つからなかった時は驚きました）。

はい、@arrowcircle と全く同じ状況です。 :slight_smile:

9

2コンテナ構成の場合でも、データコンテナの再ビルドが必要です。年1回以上の実施をお勧めします。

10

では、ダウンタイムなしにこれを行う方法はありませんか？それは当初、それらを分離した理由でした。

11

ダウンタイムゼロを実現するには、Redis のレプリカとデータベースのレプリカを運用する必要があります。フェイルオーバー時には、短時間だけ読み取り専用モードになる可能性があります。

はい、これらはいずれも可能ですが、インフラチームを雇う必要があります。

12

ここにあるのはすべてオープンソースで、お金はかかりません。^ ^;