数日前からのアップデートで深刻なメール問題が発生 - 3.4.0.beta4-dev

サポート
24

監視対象の新しいトピックとそれらへのメール返信の小さなサンプルでは、有望に見え、メール数は今のところほとんど正確です。これが私がやったことで、問題が解決したかどうかはわかりませんが、今のところ改善されているようです。

3.5.0.beta1-dev にアップグレードし、DNS ネームサーバーを 1.1.1.1 から 8.8.8.8 に強制的に設定し、再起動しました。

これを記録しました:
docker image list --all

REPOSITORY TAG IMAGE ID CREATED SIZE
local_discourse/app latest 32adad867562 6 hours ago 3.68GB
none none 5306688e5dcb 9 days ago 2.74GB

しかし、時間が経つにつれて、私が何もしていないのに次のように変化しました。

REPOSITORY TAG IMAGE ID CREATED SIZE
local_discourse/app latest 32adad867562 26 hours ago 3.68GB
discourse/base 2.0.20250129-0720 5306688e5dcb 10 days ago 2.74GB

それで、「none」が何であったのかは確信が持てません。

これを監視し、さらにデータを評価した後、報告します。

Redis 接続エラーと nginx / postgres エラーもいくつか見られるので、調査します。

nginx:

2606 upstream prematurely closed connection while reading response header from upstream

redis:

Error fetching job: Error connecting to Redis on localhost:6379 (Errno::ECONNREFUSED)
heartbeat: Error connecting to Redis on localhost:6379 (Errno::ECONNREFUSED)
Error connecting to Redis on localhost:6379 (Errno::ECONNREFUSED) subscribe failed, reconnecting in 1 second. Call stack /var/www/discourse/vendor/bundle/ruby/3.3.0/gems/redis-4.8.1/lib/redis/client.rb:398:in `rescue in establish_connection'
Error fetching job: Error connecting to Redis on localhost:6379 (Errno::ECONNREFUSED)

postgres:

current:2025-02-08 04:24:06.133 UTC [75838] discourse@discourse ERROR:  duplicate key value violates unique constraint "index_post_reply_keys_on_user_id_and_post_id"
current:2025-02-08 04:24:20.624 UTC [75838] discourse@discourse ERROR:  duplicate key value violates unique constraint "index_post_reply_keys_on_user_id_and_post_id"
current:2025-02-08 08:05:19.485 UTC [91041] discourse@discourse LOG:  duration: 2345.289 ms  statement: COPY public.scheduler_stats (id, name, hostname, pid, duration_ms, live_slots_start, live_slots_finish, started_at, success, error) TO stdout;

/log - Job exception: execution expired:
これを見ています: SMTP Net::ReadTimeout without relation to net or login problems - SMTP host is just slow - #2 by Falco

Message (3 copies reported)

Job exception: execution expired

Backtrace

/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/net-smtp-0.5.0/lib/net/smtp.rb:663:in `initialize'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/net-smtp-0.5.0/lib/net/smtp.rb:663:in `open'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/net-smtp-0.5.0/lib/net/smtp.rb:663:in `tcp_socket'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/net-smtp-0.5.0/lib/net/smtp.rb:672:in `block in do_start'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/timeout-0.4.3/lib/timeout.rb:185:in `block in timeout'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/timeout-0.4.3/lib/timeout.rb:192:in `timeout'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/net-smtp-0.5.0/lib/net/smtp.rb:671:in `do_start'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/net-smtp-0.5.0/lib/net/smtp.rb:642:in `start'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:109:in `start_smtp_session'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:100:in `deliver!'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/mail-2.8.1/lib/mail/message.rb:269:in `deliver!'
/usr/local/lib/ruby/3.3.0/delegate.rb:87:in `method_missing'
/var/www/discourse/lib/email/sender.rb:296:in `send'
/var/www/discourse/app/jobs/regular/user_email.rb:79:in `send_user_email'
/var/www/discourse/app/jobs/regular/user_email.rb:39:in `execute'
/var/www/discourse/app/jobs/base.rb:316:in `block (2 levels) in perform'
/var/www/discourse/vendor/bundle/ruby/6.1.0/gems/rails_multisite-6.1.0/lib/rails_multisite/connection_management/null_instance.rb:49:in `with_connection'
/var/www/discourse/vendor/bundle/ruby/6.1.0/gems/rails_multisite-6.1.0/lib/rails_multisite/connection_management.rb:21:in `with_connection'
/var/www/discourse/app/jobs/base.rb:303:in `block in perform'
/var/www/discourse/app/jobs/base.rb:299:in `each'
/var/www/discourse/app/jobs/base.rb:299:in `perform'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:202:in `execute_job'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:177:in `block in invoke'
/var/www/discourse/lib/sidekiq/pausable.rb:132:in `call'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:179:in `block in invoke'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:182:in `invoke'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:169:in `block in process'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/job_retry.rb:113:in `local'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq.rb:44:in `block in <module:Sidekiq>'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:263:in `stats'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/job_logger.rb:13:in `call'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/job_retry.rb:80:in `global'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:124:in `block in dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/job_logger.rb:39:in `prepare'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:123:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:168:in `process'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:78:in `process_one'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/processor.rb:68:in `run'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/component.rb:8:in `watchdog'
/var/www/discourse/vendor/bundle/ruby/6.5.12/gems/sidekiq-6.5.12/lib/sidekiq/component.rb:17:in `block in safe_thread'
26

確定：3.5.0.beta1-dev にアップグレードし、DNS ネームサーバーを 1.1.1.1 から 8.8.8.8 に強制変更し、再起動してから、深刻なメールの問題が修正されたようです。

SMTP の open_timeout を 15 に延長しましたが、おそらく必要ありません。しかし、デフォルトの 5 に戻すつもりはありません。

「いいね！」 4
27

解決したと聞いて嬉しいです。DNS設定は、システム管理者世界の全問題の78%の原因です。

「いいね！」 3
28

過去4日間、メール送信に関して新しい問題が発生しています。このスレッドを続けるべきか、新しいスレッドを開始すべきか分かりませんが、今のところはこのスレッドを続けます。

この問題が発生した時期に、コマンドラインからサイトのフルアップデートを実行しました。

  • サイトのアクティビティに関する通知メールがユーザーに送信されていません。
  • SMTP送信は問題なく機能しているようです。メール到達可能性テストは即座に完了しました。
  • Sidekiqには数千件のエンキューされたジョブが表示されており、定期的にリトライされていますが、一貫して失敗しています。（7000件以上のジョブがエンキューされています）
  • ログには、非常に目立つ多数のエラー「Job exception: UserDestroyer::PostsExistError」が表示されています。Metaで調べましたが、2017年以来、この問題について言及しているトピックは他にありませんでした。（過去4日間で9000件以上のエラーが発生しています）
ログからの完全なスタックトレース 
/var/www/discourse/app/services/user_destroyer.rb:18:in `destroy'
/var/www/discourse/app/jobs/onceoff/fix_primary_emails_for_staged_users.rb:23:in `block (2 levels) in execute_onceoff'
activerecord-7.2.2.1/lib/active_record/relation/delegation.rb:98:in `each'
activerecord-7.2.2.1/lib/active_record/relation/delegation.rb:98:in `each'
/var/www/discourse/app/jobs/onceoff/fix_primary_emails_for_staged_users.rb:21:in `block in execute_onceoff'
/var/www/discourse/app/jobs/onceoff/fix_primary_emails_for_staged_users.rb:14:in `each_key'
/var/www/discourse/app/jobs/onceoff/fix_primary_emails_for_staged_users.rb:14:in `execute_onceoff'
/var/www/discourse/app/jobs/onceoff/onceoff.rb:35:in `execute'
/var/www/discourse/app/jobs/base.rb:316:in `block (2 levels) in perform'
rails_multisite-6.1.0/lib/rails_multisite/connection_management/null_instance.rb:49:in `with_connection'
rails_multisite-6.1.0/lib/rails_multisite/connection_management.rb:21:in `with_connection'
/var/www/discourse/app/jobs/base.rb:303:in `block in perform'
/var/www/discourse/app/jobs/base.rb:299:in `each'
/var/www/discourse/app/jobs/base.rb:299:in `perform'
sidekiq-6.5.12/lib/sidekiq/processor.rb:202:in `execute_job'
sidekiq-6.5.12/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:177:in `block in invoke'
/var/www/discourse/lib/sidekiq/pausable.rb:132:in `call'
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:179:in `block in invoke'
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:182:in `invoke'
sidekiq-6.5.12/lib/sidekiq/processor.rb:169:in `block in process'
sidekiq-6.5.12/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_retry.rb:113:in `local'
sidekiq-6.5.12/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq.rb:44:in `block in <module:Sidekiq>'
sidekiq-6.5.12/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/processor.rb:263:in `stats'
sidekiq-6.5.12/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_logger.rb:13:in `call'
sidekiq-6.5.12/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_retry.rb:80:in `global'
sidekiq-6.5.12/lib/sidekiq/processor.rb:124:in `block in dispatch'
sidekiq-6.5.12/lib/sidekiq/job_logger.rb:39:in `prepare'
sidekiq-6.5.12/lib/sidekiq/processor.rb:123:in `dispatch'
sidekiq-6.5.12/lib/sidekiq/processor.rb:168:in `process'
sidekiq-6.5.12/lib/sidekiq/processor.rb:78:in `process_one'
sidekiq-6.5.12/lib/sidekiq/processor.rb:68:in `run'
sidekiq-6.5.12/lib/sidekiq/component.rb:8:in `watchdog'
sidekiq-6.5.12/lib/sidekiq/component.rb:17:in `block in safe_thread'

デバッグと今後の進め方について、何かアドバイスはありますか？

29

アップデートのご報告です。他に思いつく対応として git pull; ./launcher rebuild app を実行したところ、問題が解決したようです。メールが送信されるようになり、Sidekiq のエンキューされたメールジョブのバックログが減り始めています。

過去数日間の discourse/discourse のコミットを確認しましたが、何が問題を解決したのかはっきりしません。しかし、さらに調査したい方がいらっしゃれば、必要に応じて追加情報を提供いたします。

「いいね！」 5
30

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