Sidekiqには多くのエラーとキューされたジョブがあります

管理コンソールに Sidekiq キューに入れられたジョブに関するアドバイスが表示されました。約 200,000 件のジョブがエンキューされており、問題の解決方法がわかりません。バージョン 3.2.0 を実行しています。

ジョブはすべて ultra_low キューにあり、Jobs::ProcessPost ジョブのようです。すべて次のようなものに見えます。

	[{"bypass_bump"=>true, "cooking_options"=>nil, "new_post"=>false, "post_id"=>729508, "skip_pull_hotli... 
{"bypass_bump"=>true, "cooking_options"=>nil, "new_post"=>false, "post_id"=>729508, "skip_pull_hotlinked_images"=>false, "current_site_id"=>"default"}

これらのジョブを処理するにはどうすればよいですか。また、パフォーマンスに大きな影響を与えないようにするにはどうすればよいですか (それとも避けられないことですか)。

2日前は約195Kでしたが、現在は211Kに増加しています。何を確認し、この問題をどのように解決すればよいか、いくつかアドバイスをいただけると大変助かります。

以下のような、停止したジョブが5件見つかりました（IPアドレスは難読化されています）。

Jobs::HandledExceptionWrapper: Wrapped Errno::ENETUNREACH: Failed to open TCP connection to x.x.x.x:443 (Network is unreachable - connect(2) for \"x.x.x.x\" port 443)

このアドレスはインフラ内にあるサーバーのものですが、フォーラムでは使用されていません（ソースコードリポジトリサーバーです）。設定のどこにもこのホストが参照されている箇所が見当たらないため、なぜこのホストに接続する必要があると考えているのか不明です。しかし、これがultra_lowキューでエンキューされているジョブ数の増加に関連しているのではないかと疑問に思っています。

過去約23時間で、さらに7,000件のジョブがキューに追加されました。

これにより、自動クローズやソリューションプラグインの追加といったいくつかの実装変更も遅延しています（この問題の影響を受ける可能性のある変更、またはシステム設定の非常に重要な変更と同時に変更される可能性を考慮したくないためです）。

追加された7,000件のジョブは、過去1日間の新しい投稿数と一致しないため、何が原因で発生しているのか全く分かりません。

この問題を解決するために、他にどのような情報が役立ちますか？

お手伝いできることはありませんが、このスレッドへの投稿にさらに多くの返信や「いいね！」を増やすことで、当然受けるべき注目を集めることができるかもしれません！

編集：デフォルトの「人気順」に関するスレッドでもこの問題に言及しました。これは、このスレッドを非常に効果的かつ非常に不親切に隠しているのだと思います。

完全なバックトレースを共有していただけますか？ワンボックスコードからのものだと推測しますが、確証を得たいです。

コンソールから行う必要があると想定しています。アクセス権を持つ人に依頼する必要があります。アクセス権を持つ人に渡せるように、どこから取得すればよいか教えていただけますか？

よろしくお願いします！

いいえ、いいえ、バックトレースは、エラーを選択したときに /logs ページのタブに表示されます。

Ah、ヒントをありがとうございます。表示されているのは次のとおりです（IPアドレスは難読化されています）。

メッセージ（10件報告あり）

ジョブ例外：TCP接続を開けませんでした x.x.x.x:443（ネットワークに到達できません - "x.x.x.x" ポート 443 への接続(2)）


バックトレース

/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `initialize'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `open'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `block in connect'
/usr/lib64/ruby/gems/3.2.0/gems/timeout-0.4.1/lib/timeout.rb:186:in `block in timeout'
/usr/lib64/ruby/gems/3.2.0/gems/timeout-0.4.1/lib/timeout.rb:193:in `timeout'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1601:in `connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:27:in `block in connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each_with_index'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `connect'

これは「バックトレース」タブの出力とは異なることに気づきましたが、そちらの出力はバックトレースのようには見えず、コピーボタンでコピーしたこちらの方がバックトレースのようです。この件で他に情報が必要な場合はお知らせください。

また、この方法で 220K 件以上のエンキューされたタスクに関する追加情報を取得できるかどうかも確認します。/logs エンドポイントについては知りませんでした。

バックトレースの下部に余分な行はありませんか？

コピーボタンで取得できたのはこれだけでした。バックトレースタブからの完全な出力は以下のとおりです。\n\n\nnet-http-0.4.1/lib/net/http.rb:1603:in `initialize' \nnet-http-0.4.1/lib/net/http.rb:1603:in `open' \nnet-http-0.4.1/lib/net/http.rb:1603:in `block in connect' \ntimeout-0.4.1/lib/timeout.rb:186:in `block in timeout' \ntimeout-0.4.1/lib/timeout.rb:193:in `timeout' \nnet-http-0.4.1/lib/net/http.rb:1601:in `connect' \n/srv/www/vhosts/discourse/lib/final_destination/http.rb:27:in `block in connect' \n/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each' \n/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each_with_index' \n/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `connect' \nnet-http-0.4.1/lib/net/http.rb:1580:in `do_start' \nnet-http-0.4.1/lib/net/http.rb:1569:in `start' \nnet-http-0.4.1/lib/net/http.rb:1029:in `start' \n/srv/www/vhosts/discourse/lib/final_destination.rb:551:in `safe_session' \n/srv/www/vhosts/discourse/lib/final_destination.rb:486:in `safe_get' \n/srv/www/vhosts/discourse/lib/final_destination.rb:170:in `get' \n/srv/www/vhosts/discourse/lib/retrieve_title.rb:90:in `fetch_title' \n/srv/www/vhosts/discourse/lib/retrieve_title.rb:12:in `crawl' \n/srv/www/vhosts/discourse/lib/inline_oneboxer.rb:76:in `lookup' \n/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:310:in `process_inline_onebox' \n/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:39:in `block in post_process_oneboxes' \n/srv/www/vhosts/discourse/lib/oneboxer.rb:214:in `block in apply' \n/srv/www/vhosts/discourse/lib/oneboxer.rb:162:in `block in each_onebox_link' \nnokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:235:in `block in each' \nnokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:234:in `upto' \nnokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:234:in `each' \n/srv/www/vhosts/discourse/lib/oneboxer.rb:162:in `each_onebox_link' \n/srv/www/vhosts/discourse/lib/oneboxer.rb:213:in `apply' \n/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:9:in `post_process_oneboxes' \n/srv/www/vhosts/discourse/lib/cooked_post_processor.rb:42:in `block in post_process' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:53:in `block in synchronize' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:34:in `synchronize' \n/srv/www/vhosts/discourse/lib/cooked_post_processor.rb:38:in `post_process' \n/srv/www/vhosts/discourse/app/jobs/regular/process_post.rb:28:in `block in execute' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:53:in `block in synchronize' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' \n/srv/www/vhosts/discourse/lib/distributed_mutex.rb:34:in `synchronize' \n/srv/www/vhosts/discourse/app/jobs/regular/process_post.rb:8:in `execute' \n/srv/www/vhosts/discourse/app/jobs/base.rb:297:in `block (2 levels) in perform' \nrails_multisite-5.0.0/lib/rails_multisite/connection_management.rb:82:in `with_connection'\n/srv/www/vhosts/discourse/app/jobs/base.rb:284:in `block in perform' \n/srv/www/vhosts/discourse/app/jobs/base.rb:280:in `each' \n/srv/www/vhosts/discourse/app/jobs/base.rb:280:in `perform' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:202:in `execute_job' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:170:in `block (2 levels) in process' \nsidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:177:in `block in invoke' \n/srv/www/vhosts/discourse/lib/sidekiq/pausable.rb:132:in `call' \nsidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:179:in `block in invoke' \nsidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:182:in `invoke' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:169:in `block in process' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch' \nsidekiq-6.5.12/lib/sidekiq/job_retry.rb:113:in `local' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch' \nsidekiq-6.5.12/lib/sidekiq/rails.rb:14:in `block in call' \nactivesupport-7.0.8/lib/active_support/execution_wrapper.rb:92:in `wrap' \nactivesupport-7.0.8/lib/active_support/reloader.rb:72:in `block in wrap' \nactivesupport-7.0.8/lib/active_support/execution_wrapper.rb:92:in `wrap' \nactivesupport-7.0.8/lib/active_support/reloader.rb:71:in `wrap' \nsidekiq-6.5.12/lib/sidekiq/rails.rb:13:in `call' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:263:in `stats' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch' \nsidekiq-6.5.12/lib/sidekiq/job_logger.rb:13:in `call' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch' \nsidekiq-6.5.12/lib/sidekiq/job_retry.rb:80:in `global' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:124:in `block in dispatch' \nsidekiq-6.5.12/lib/sidekiq/job_logger.rb:39:in `prepare' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:123:in `dispatch' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:168:in `process' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:78:in `process_one' \nsidekiq-6.5.12/lib/sidekiq/processor.rb:68:in `run' \nsidekiq-6.5.12/lib/sidekiq/component.rb:8:in `watchdog' \nsidekiq-6.5.12/lib/sidekiq/component.rb:17:in `block in safe_thread' \n\n\n出力の全体を取得できなかったことをお詫びします。コピーボタンがもっと多くを取得しないのは奇妙だと思いましたが、必要なものを取得したという誤った仮定をしてしまいました。

それはずっと良いですね！

これは、サーバーのIPアドレスに解決されるURLを持つインラインリンクが1つ以上あることを意味します。そのサーバーに到達できない場合、エラーは記録されますが、インラインワンボックスがトリガーする「リンクの整形」を行わずに、マークダウンの処理は続行されるはずです。

他に、Discourseをどのようにインストールしましたか？これは、公式のインストールガイドに従ったインストールには見えません。

実際には私がインストールを実行したわけではありません。インフラチームがCI/CDパイプラインを使用してデプロイしたと思いますが、詳細は把握していません。

失敗したメッセージは問題ではないようです。ultra_lowキューに多数のタスクがエンキューされていることが、ここでのより大きな問題のようです。ログに何も見つからないのは、実際にはジョブがまだ実行されていないため、当然のことだと思います。

手動でいくつか実行を強制すると、どうなりますか？

Web UI で強制的に実行するオプションが表示されません。「すべて表示」または個別にタスクを削除するオプションがあります。

申し訳ありませんが、私が管理しているフォーラムにはキューに入っているものはありません。そのため、存在しないボタンを提案しようとしたことをお詫びします。

リトライページへの参照（キューページにあると思ったもの）

image1077×365 99.5 KB

心配いりません。これらはエンキューされたページ（/sidekiq/queues/ultra_low）に表示されます。

キューページ自体を見ると、ultra_lowキューのレイテンシが約1年であることがわかります。したがって、これは明らかにしばらく前から続いており、最近になってダッシュボードでアラートを受け取ったばかりです。

Jobs::ProcessPost ジョブをもう少し詳しく見てみると、post_id の値がカウントダウンしているようです。キュー内の最初と最後のジョブから post ID を取得したところ、日付は 2012 年の投稿 (Discourse への移行前ですが、2022 年の ‘updated_at’ タイムスタンプが付いています。これは移行日だったかもしれません。確認する必要があります) に対応しており、最も新しいものは 2023 年 1 月のものでした。

時折、トピックサムネイルを生成するジョブも見られますが、それはかなり稀です。8,800 ページを超えるキューをすべて確認することはできませんが、追加されているのは主に Jobs::ProcessPost のもので、投稿への返信や最初の投稿すべてを時系列で遡っているように見えます (最も古いものはスレッドの途中、最も新しいものはトピックのルート投稿でした)。

本番システムからバックアップを取得し、ローカルにセットアップしたテスト環境にロードしました。キューがまったくバックアップされていないようです。実際、キュー画面を監視している際に、Job::ProcessPost がそのキューにまったく表示されません（セットアップして、システムを単独で実行させ、キュー画面を記録して、見逃しているだけかどうかを確認するつもりです）。

これにより、2つの質問が生じます。

1. ProcessPost ジョブはどのようにトリガーされますか？
2. ultra_low キューが処理されない原因は何でしょうか？

私は Discourse（redis、sidekiq、rails）で使用されているテクノロジーのエキスパートではありませんが、本番環境で誰かに見てもらう必要があることを理解するために、サンドボックス環境で学習したり試したりすることに非常に慣れています。

良いニュースは、この問題が（まだ）ユーザーに問題を引き起こしていないようです。3つ目の質問は、そのキューを単にパージしても役立つかどうか、またはそれらのジョブを実行させないことがシステムに何らかの害を及ぼすかどうかです。

追記：テスト環境でジョブのバッチが表示され、そこで処理されています。したがって、本番サーバーでキューが何らかの理由で処理されていないだけのようです。

解決に至ったようです。使用しているインストールはopenSUSE用にビルドされたパッケージからのものです（話題になっているインスタンスはopenSUSEフォーラムのインスタンスです）ので、基本的に「ソースからビルド」のインストールプロセスを使用しています。

開発環境と本番環境があり、ultra_low キューが本番環境の sidekiq 設定から誤って除外されていました。これは修正され、キューは空になりつつあり、レイテンシは1年から4週間に低下しました。

これで解決したと考えてよいでしょう。提供された皆様からのインプットに感謝します。それが問題特定への正しい道筋を示してくれました。

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.