2 письма отклонены в версии 2026.4.0-latest (5f0d95e1f1)

Внести вклад Ошибка
1

Привет! У меня возникают периодические сбои обработки входящей почты на самодостаточном сайте с использованием mail-receiver.

Что произошло

Два отдельных входящих письма:

  • были доставлены на правильный адрес Discourse
  • отображаются в разделе /admin/email/received
  • также появляются в разделе /admin/email/rejected
  • содержат общий текст отказа: «При обработке вашего письма произошла неузнаваемая ошибка, и оно не было опубликовано».

Примерно в то же время в логах зафиксировано исключение ActiveRecord::Deadlocked.

Почему я считаю, что это может быть баг

Я сравнил отклонённые письма с более поздним успешным письмом очень схожего формата:

  • одинаковый шаблон отправителя
  • одинаковый путь через Microsoft / Power Automate
  • одинаковая видимая структура поля To:
  • одинаковый получатель SMTP-конверта на адрес Discourse

Поэтому это не похоже на простую проблему конфигурации mail-receiver.

Доказательства

Для обоих отклонённых писем:

  • это были отдельные доставки с разными Message-ID
  • у них были разные идентификаторы очереди Postfix
  • оба были доставлены for <ppyem3.accomodation@discourse.domain.com>

Также в логах в тот же период я наблюдал исключение ActiveRecord::Deadlocked.

Контекст хостинга

  • самодостаточный сервер
  • используется mail-receiver
  • небольшой VPS от IONOS
  • настроен один веб-воркер

Я понимаю, что один веб-воркер может быть просто фоновым контекстом, а не причиной, поскольку проблема касается обработки входящей почты/фоновых задач, а не обработки веб-запросов.

Если нужно, я могу предоставить:

  • заголовки двух отклонённых писем (с удалёнными конфиденциальными данными)
  • заголовки успешного аналогичного письма (с удалёнными конфиденциальными данными)
  • запись лога о взаимной блокировке (deadlock)
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...
3

Привет, спасибо, что уделили время. Хочу убедиться, что я соберу правильные дополнительные данные перед запуском чего-либо шумного на сервере.

Исходя из тупика и того, как выполняется Jobs::ProcessEmail, я думаю, что следующее может помочь сузить круг поиска, но я буду признателен за подтверждение, прежде чем приступать.

1. Сравнение заголовков писем (неудачное vs успешное)

Я могу извлечь и опубликовать отредактированные сырые заголовки из:

  • /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 веб-воркером, но понимаю, что для тупика, скорее всего, более актуален параллелизм 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. Время входящих писем

Я заметил, что два неудачных письма были обработаны очень близко по времени (в одну минуту).

Я могу извлечь более точное время из логов, если это полезно.

:backhand_index_pointing_right: Помогла бы более точная корреляция по времени подтвердить, что это проблема, вызванная параллелизмом?

Если это полезно, я могу собрать и опубликовать всё вышеперечисленное в следующем сообщении — просто хотел уточнить, что было бы наиболее полезно в первую очередь.

Ещё раз спасибо :+1:

4

Стоит упомянуть, что на следующий день было получено 12 писем, отправленных вручную, с временным интервалом около 8 минут.

Вчера вечером было получено 4 таких автоматических письма, вероятно, с интервалом менее 8 минут.