2026.4.0-latest ( 5f0d95e1f1 ) で拒否されたメールが 2 件

こんにちは、自己ホスト型のサイトで mail-receiver を使用しているところ、着信メールの処理が断続的に失敗している現象を確認しています。

発生した事象

2 件の別々の着信メールが以下の状況にあります:

  • 正しい Discourse アドレスに配信された
  • /admin/email/received に表示されている
  • 同時に /admin/email/rejected にも表示されている
  • 一般的な拒否メッセージ「メールの処理中に不明なエラーが発生し、投稿されませんでした」と表示されている

ほぼ同時刻に、ログに ActiveRecord::Deadlocked が記録されていました。

なぜバグだと考えているか

拒否されたメールと、非常に類似した形式のその後の正常に処理されたメールを比較しました:

  • 送信者パターンが同じ
  • Microsoft / Power Automate のパスが同じ
  • 表示される To: の形式が同じ
  • Discourse アドレスへの SMTP エンベロープ受信者が同じ

したがって、これは単なる mail-receiver の設定問題ではないと思われます。

証拠

両方の拒否されたメールについて:

  • 異なる Message-ID を持つ別々の配信である
  • 異なる Postfix キュー ID を持っている
  • どちらも for <ppyem3.accomodation@discourse.domain.com> として配信された

また、ほぼ同時期にログで ActiveRecord::Deadlocked を確認しました。

ホスティング環境

  • 自己ホスト型
  • mail-receiver を使用
  • 小規模な IONOS VPS
  • Web ワーカーが 1 設定

Web ワーカーが 1 つしかないことは、単なる背景情報であり原因ではないかもしれません。これは Web リクエスト処理ではなく、着信メールやバックグラウンド処理に関連しているように見えるためです。

必要であれば、以下を提供できます:

  • 2 件の拒否されたメールのヘッダー(匿名化済み)
  • 正常に処理された比較対象のメールのヘッダー(匿名化済み)
  • デッドロックのログエントリ

browsing the /logs endpoint, i see the two errors

env

hostname	ubuntu-app
process_id	2297
application_version	5f0d95e1f11a9cb5acbe8c7a61142400fc506f06
job	Jobs::ProcessEmail
db	default
time	7:48 pm
backtrace
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:218:in 'block in ActiveSupport::BroadcastLogger#dispatch' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in 'Array#map' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in 'ActiveSupport::BroadcastLogger#dispatch' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:129:in 'ActiveSupport::BroadcastLogger#error' 
/var/www/discourse/lib/email/processor.rb:126:in 'Email::Processor#handle_failure' 
/var/www/discourse/lib/email/processor.rb:31:in 'Email::Processor#process!' 
/var/www/discourse/lib/email/processor.rb:13:in 'Email::Processor.process!' 
/var/www/discourse/app/jobs/regular/process_email.rb:8:in 'Jobs::ProcessEmail#execute' 
/var/www/discourse/app/jobs/base.rb:318:in 'block (2 levels) in Jobs::Base#perform' 
rails_multisite-7.0.0/lib/rails_multisite/connection_management/null_instance.rb:49:in 'RailsMultisite::ConnectionManagement::NullInstance#with_connection'
rails_multisite-7.0.0/lib/rails_multisite/connection_management.rb:17:in 'RailsMultisite::ConnectionManagement.with_connection'
/var/www/discourse/app/jobs/base.rb:305:in 'block in Jobs::Base#perform' 
/var/www/discourse/app/jobs/base.rb:301:in 'Array#each' 
/var/www/discourse/app/jobs/base.rb:301:in 'Jobs::Base#perform' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:220:in 'Sidekiq::Processor#execute_job' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:185:in 'block (4 levels) in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:180:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
/var/www/discourse/lib/sidekiq/suppress_user_email_errors.rb:6:in 'Sidekiq::SuppressUserEmailErrors#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
/var/www/discourse/lib/sidekiq/discourse_event.rb:6:in 'Sidekiq::DiscourseEvent#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
/var/www/discourse/lib/sidekiq/pausable.rb:131:in 'Sidekiq::Pausable#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/job/interrupt_handler.rb:9:in 'Sidekiq::Job::InterruptHandler#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/metrics/tracking.rb:26:in 'Sidekiq::Metrics::ExecutionTracker#track' 
sidekiq-7.3.10/lib/sidekiq/metrics/tracking.rb:134:in 'Sidekiq::Metrics::Middleware#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:173:in 'Sidekiq::Middleware::Chain#invoke' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:184:in 'block (3 levels) in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:145:in 'block (6 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_retry.rb:118:in 'Sidekiq::JobRetry#local' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:144:in 'block (5 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/config.rb:39:in 'block in <class:Config>' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:139:in 'block (4 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:281:in 'Sidekiq::Processor#stats' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:134:in 'block (3 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_logger.rb:15:in 'Sidekiq::JobLogger#call' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:133:in 'block (2 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_retry.rb:85:in 'Sidekiq::JobRetry#global' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:132:in 'block in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_logger.rb:40:in 'Sidekiq::JobLogger#prepare' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:131:in 'Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:183:in 'block (2 levels) in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:182:in 'Thread.handle_interrupt' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:182:in 'block in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:181:in 'Thread.handle_interrupt' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:181:in 'Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:86:in 'Sidekiq::Processor#process_one' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:76:in 'Sidekiq::Processor#run' 
sidekiq-7.3.10/lib/sidekiq/component.rb:10:in 'Sidekiq::Component#watchdog' 
sidekiq-7.3.10/lib/sidekiq/component.rb:19:in 'block in Sidekiq::Component#safe_thread'
info
Unrecognized error type (ActiveRecord::Deadlocked: PG::TRDeadlockDetected: ERROR:  deadlock detected
DETAIL:  Process 1170676 waits for ShareLock on transaction 3318694; blocked by process 1169876.
Process 1169876 waits for ExclusiveLock on tuple (4,27) of relation 74547 of database 16384; blocked by process 1170546.
Process 1170546 waits for ShareLock on transaction 3318690; blocked by process 1170676.
HINT:  See server log for query details.
CONTEXT:  while updating tuple (1,54) in relation "user_stats"
) when processing incoming email

Backtrace:
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connection#exec'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connection#async_exec'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:167:in 'ActiveRecord::ConnectionAdapters::PostgreSQL::DatabaseStatements#perform_query'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract/database_statements.rb:556:in 'block (2 levels) in ActiveRecord::ConnectionAdapters::DatabaseStatements#raw_execute'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:1022:in 'block in ActiveRecord::ConnectionAdapters::AbstractAdapter#with_raw_connection'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.5/lib/active_support/concurrency/null_lock.rb:9:in 'ActiveSupport::Concurrency::NullLock#synchronize'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:991:in 'ActiveRecord::ConnectionAdapters::AbstractAdapter#with_raw_connection'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_ad...

env

hostname	ubuntu-app
process_id	2297
application_version	5f0d95e1f11a9cb5acbe8c7a61142400fc506f06
job	Jobs::ProcessEmail
db	default
time	7:48 pm
backtrace
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:218:in 'block in ActiveSupport::BroadcastLogger#dispatch' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in 'Array#map' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in 'ActiveSupport::BroadcastLogger#dispatch' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:129:in 'ActiveSupport::BroadcastLogger#error' 
/var/www/discourse/lib/email/processor.rb:126:in 'Email::Processor#handle_failure' 
/var/www/discourse/lib/email/processor.rb:31:in 'Email::Processor#process!' 
/var/www/discourse/lib/email/processor.rb:13:in 'Email::Processor.process!' 
/var/www/discourse/app/jobs/regular/process_email.rb:8:in 'Jobs::ProcessEmail#execute' 
/var/www/discourse/app/jobs/base.rb:318:in 'block (2 levels) in Jobs::Base#perform' 
rails_multisite-7.0.0/lib/rails_multisite/connection_management/null_instance.rb:49:in 'RailsMultisite::ConnectionManagement::NullInstance#with_connection'
rails_multisite-7.0.0/lib/rails_multisite/connection_management.rb:17:in 'RailsMultisite::ConnectionManagement.with_connection'
/var/www/discourse/app/jobs/base.rb:305:in 'block in Jobs::Base#perform' 
/var/www/discourse/app/jobs/base.rb:301:in 'Array#each' 
/var/www/discourse/app/jobs/base.rb:301:in 'Jobs::Base#perform' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:220:in 'Sidekiq::Processor#execute_job' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:185:in 'block (4 levels) in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:180:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
/var/www/discourse/lib/sidekiq/suppress_user_email_errors.rb:6:in 'Sidekiq::SuppressUserEmailErrors#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
/var/www/discourse/lib/sidekiq/discourse_event.rb:6:in 'Sidekiq::DiscourseEvent#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
/var/www/discourse/lib/sidekiq/pausable.rb:131:in 'Sidekiq::Pausable#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/job/interrupt_handler.rb:9:in 'Sidekiq::Job::InterruptHandler#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/metrics/tracking.rb:26:in 'Sidekiq::Metrics::ExecutionTracker#track' 
sidekiq-7.3.10/lib/sidekiq/metrics/tracking.rb:134:in 'Sidekiq::Metrics::Middleware#call' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse' 
sidekiq-7.3.10/lib/sidekiq/middleware/chain.rb:173:in 'Sidekiq::Middleware::Chain#invoke' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:184:in 'block (3 levels) in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:145:in 'block (6 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_retry.rb:118:in 'Sidekiq::JobRetry#local' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:144:in 'block (5 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/config.rb:39:in 'block in <class:Config>' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:139:in 'block (4 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:281:in 'Sidekiq::Processor#stats' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:134:in 'block (3 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_logger.rb:15:in 'Sidekiq::JobLogger#call' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:133:in 'block (2 levels) in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_retry.rb:85:in 'Sidekiq::JobRetry#global' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:132:in 'block in Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/job_logger.rb:40:in 'Sidekiq::JobLogger#prepare' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:131:in 'Sidekiq::Processor#dispatch' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:183:in 'block (2 levels) in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:182:in 'Thread.handle_interrupt' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:182:in 'block in Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:181:in 'Thread.handle_interrupt' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:181:in 'Sidekiq::Processor#process' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:86:in 'Sidekiq::Processor#process_one' 
sidekiq-7.3.10/lib/sidekiq/processor.rb:76:in 'Sidekiq::Processor#run' 
sidekiq-7.3.10/lib/sidekiq/component.rb:10:in 'Sidekiq::Component#watchdog' 
sidekiq-7.3.10/lib/sidekiq/component.rb:19:in 'block in Sidekiq::Component#safe_thread' 
info
Unrecognized error type (ActiveRecord::Deadlocked: PG::TRDeadlockDetected: ERROR:  deadlock detected
DETAIL:  Process 1170678 waits for ShareLock on transaction 3318690; blocked by process 1170676.
Process 1170676 waits for ShareLock on transaction 3318694; blocked by process 1169876.
Process 1169876 waits for ExclusiveLock on tuple (4,27) of relation 74547 of database 16384; blocked by process 1170678.
HINT:  See server log for query details.
CONTEXT:  while locking tuple (4,27) in relation "categories"
) when processing incoming email

Backtrace:
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connection#exec'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connection#async_exec'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:167:in 'ActiveRecord::ConnectionAdapters::PostgreSQL::DatabaseStatements#perform_query'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract/database_statements.rb:556:in 'block (2 levels) in ActiveRecord::ConnectionAdapters::DatabaseStatements#raw_execute'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:1022:in 'block in ActiveRecord::ConnectionAdapters::AbstractAdapter#with_raw_connection'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.5/lib/active_support/concurrency/null_lock.rb:9:in 'ActiveSupport::Concurrency::NullLock#synchronize'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:991:in 'ActiveRecord::ConnectionAdapters::AbstractAdapter#with_raw_connection'
  /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_ada...

こんにちは、確認いただきありがとうございます。サーバー上でノイズの多い処理を実行する前に、必要な追加データを正確に収集したいと考えています。

デッドロックと Jobs::ProcessEmail の実行状況に基づき、以下の情報を収集することで原因を特定できる可能性がありますが、進める前にご確認いただければ幸いです。


1. メールヘッダーの比較(失敗と成功)

以下の場所からヘッダー情報をマスキングして抽出し、投稿できます。

  • /admin/email/received → 「元を表示」

対象:

  • 失敗したメール 1 通

または、以下の通り両方

  • 同じパターンで成功したメール 1 通

以下の通り

含まれる項目:

  • Message-ID
  • From
  • To
  • Delivered-To
  • Return-Path
  • 上位の Received:

:backhand_index_pointing_right: この比較はここで役立ちますか?


2. Sidekiq ジョブの結果(リトライ / デッドセット)

これは Jobs::ProcessEmail 内で発生しているため、以下のジョブの状態を確認できます。

  • リトライされたか
  • 最終的に成功したか
  • デッドセットに入ったか

確認方法:

./launcher enter app
rails c
Sidekiq::RetrySet.new.select { |j| j.klass == "Jobs::ProcessEmail" }
Sidekiq::DeadSet.new.select { |j| j.klass == "Jobs::ProcessEmail" }

:backhand_index_pointing_right: リトライ/デッドセットの挙動を確認することが診断に役立ちますか?


  1. 並行処理設定

私は 1 つの Web ワーカーで実行していると述べましたが、デッドロックに関しては Sidekiq の並行処理設定の方がより重要である可能性があると認識しています。

app.yml からの関連値を共有できます。例:

UNICORN_WORKERS:
SIDEKIQ_CONCURRENCY:

現時点では SIDEKIQ_CONCURRENCY が app.yml に明示的に設定されていないため、デフォルトの並行処理(つまり複数の Sidekiq スレッド)で実行されていると考えています。

:backhand_index_pointing_right: これはデッドロックの解釈にとって重要な文脈になりますか?


  1. PostgreSQL バージョン

これは PG::TRDeadlockDetected であるため、使用されている正確な PostgreSQL バージョンも確認できます。

:backhand_index_pointing_right: これを含める価値はありますか?


  1. 受信メールのタイミング

2 通の失敗したメールは非常に近いタイミング(同じ分内)で処理されたことを確認しました。

必要であれば、ログからより正確なタイミングを抽出できます。

:backhand_index_pointing_right: より厳密なタイミングの相関関係は、これが並行処理に起因する問題かどうかの確認に役立ちますか?


もしよろしければ、上記のすべてをフォローアップで収集して投稿することもできますが、まず何が最も役立つかを確認したく思います。

ありがとうございました :+1: