Ошибка повторной попытки в Sidekiq

Это первый раз, когда я вижу эту ошибку после недавнего обновления до версии 2.9.0beta4

Jobs::UserEmail

{“type”=>“user_watching_first_post”, “user_id”=>1735, “notification_id”=>33246, “notification_data_hash”=>{“topic_title”=>“Some new notes”, “original_post_id”=>11592, “original_post_type”=>1, “original_username”=>“xfactor”, “revision_number”=>nil, “display_username”=>“xfactor”}, “notification_type”=>“watching_first_post”, “post_id”=>11592, “current_site_id”=>“default”}

Jobs::HandledExceptionWrapper: Wrapped ActiveRecord::RecordInvalid: Validation failed: Post has already been taken

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

Что это означает и как это исправить?

2 лайка

Я вижу, что сервер успешно отправил множество писем по этой новой теме всем, кто следил за этой категорией. В логах отправки писем и на почтовом сервере ошибок также не обнаружено.

Так что же здесь имеется в виду?

Та же ошибка первого типа здесь. Повторная попытка не помогает, все остальные письма доставлены:

Jobs::UserEmail

{"type"=>"user_private_message", "user_id"=>1513, "notification_id"=>871360, "notification_data_hash"=>{"topic_title"=>"Название темы", "original_post_id"=>220174, "original_post_type"=>1, "original_username"=>"username", "revision_number"=>nil, "display_username"=>"user", "group_name"=>nil}, "notification_type"=>"private_message", "post_id"=>220174, "current_site_id"=>"default"}

Jobs::HandledExceptionWrapper: Wrapped ActiveRecord::RecordInvalid: Validation failed: Post has already been taken

Трассировка стека

/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/validations.rb:80:in `raise_validation_error'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/validations.rb:53:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:302:in `block in save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:354:in `block in with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/connection_adapters/abstract/database_statements.rb:318:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:302:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/suppressor.rb:48:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/persistence.rb:55:in `create!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/relation.rb:799:in `_create!'

Я тоже заметил логи Discourse:

Сообщение (21 копия)

Исключение в задаче: Ошибка проверки: Пост уже существует

Трассировка стека

/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/validations.rb:80:in `raise_validation_error'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/validations.rb:53:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:302:in `block in save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:354:in `block in with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/connection_adapters/abstract/database_statements.rb:318:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/transactions.rb:302:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/suppressor.rb:48:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/persistence.rb:55:in `create!'
/var/www/discourse/vendor/bundle/ruby/2.7.0/gems/activerecord-6.1.4.7/lib/active_record/relation.rb:799:in `_create!'

Перемещаю это в раздел багов, а не поддержки

1 лайк

Привет, @RBoy :slight_smile:

Вы всё ещё видите эту ошибку?

Да, для той записи она действительно застряла в цикле повторных попыток до вчерашнего дня, когда после сотен попыток я наконец сдался и удалил её. Надеюсь, я ничего не сломал.

Я больше этого не видел, но и события, которое вызвало сотни писем на одном посте, не было. Было бы неплохо понять, откуда это взялось и что это означает.

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

Теперь у меня накопилось 2001 такое сообщение, и мой тестовый аккаунт не получил еженедельную сводку, которую должен был получить.

Сейчас запущена версия 8695449cfc.

2 лайка

Я обновился до bf987af3ca, перепроверил всё, но в консоли Sidekiq по-прежнему отображается как минимум 38 ошибок Jobs::HandledExceptionWrapper: Wrapped ActiveRecord::RecordInvalid: Validation failed: Post has already been taken.

2 лайка

Без дополнительных обновлений я сейчас опустился до 30. Я предполагаю, что они истекают по тайм-ауту, за исключением того, что мой тестовый аккаунт получил (задержанную) еженедельную сводку, и я предполагаю, что это связано. Не уверен, где искать в логах, чтобы узнать, действительно ли какие-то из них сдаются.

Они, похоже, в основном терпят неудачу, но иногда успешно завершаются, что определенно пахнет состоянием гонки где-то.

Мои трассировки стека выглядят так же, как и у @RBoy и @md-misko, но вот полная трассировка стека, а не только усеченная версия из кнопки «Копировать»:

activerecord-7.0.3/lib/active_record/validations.rb:80:in `raise_validation_error'
activerecord-7.0.3/lib/active_record/validations.rb:53:in `save!'
activerecord-7.0.3/lib/active_record/transactions.rb:302:in `block in save!'
activerecord-7.0.3/lib/active_record/transactions.rb:354:in `block in with_transaction_returning_status'
activerecord-7.0.3/lib/active_record/connection_adapters/abstract/database_statements.rb:314:in `transaction'
activerecord-7.0.3/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
activerecord-7.0.3/lib/active_record/transactions.rb:302:in `save!'
activerecord-7.0.3/lib/active_record/suppressor.rb:54:in `save!'
activerecord-7.0.3/lib/active_record/persistence.rb:55:in `create!'
activerecord-7.0.3/lib/active_record/relation.rb:869:in `_create!'
activerecord-7.0.3/lib/active_record/relation.rb:115:in `block in create!'
activerecord-7.0.3/lib/active_record/relation.rb:880:in `_scoping'
activerecord-7.0.3/lib/active_record/relation.rb:428:in `scoping'
activerecord-7.0.3/lib/active_record/relation.rb:115:in `create!'
activerecord-7.0.3/lib/active_record/relation.rb:219:in `block in create_or_find_by!'
activerecord-7.0.3/lib/active_record/connection_adapters/abstract/transaction.rb:319:in `block in within_new_transaction'
activesupport-7.0.3/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
activesupport-7.0.3/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
activesupport-7.0.3/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
activesupport-7.0.3/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
activerecord-7.0.3/lib/active_record/connection_adapters/abstract/transaction.rb:317:in `within_new_transaction'
activerecord-7.0.3/lib/active_record/connection_adapters/abstract/database_statements.rb:316:in `transaction'
activerecord-7.0.3/lib/active_record/transactions.rb:209:in `transaction'
activerecord-7.0.3/lib/active_record/relation/delegation.rb:67:in `block in transaction'
activerecord-7.0.3/lib/active_record/relation.rb:880:in `_scoping'
activerecord-7.0.3/lib/active_record/relation.rb:428:in `scoping'
activerecord-7.0.3/lib/active_record/relation/delegation.rb:67:in `transaction'
activerecord-7.0.3/lib/active_record/relation.rb:219:in `create_or_find_by!'
activerecord-7.0.3/lib/active_record/querying.rb:22:in `create_or_find_by!'
/var/www/discourse/lib/email/sender.rb:498:in `get_reply_key'
/var/www/discourse/lib/email/sender.rb:105:in `send'
/var/www/discourse/app/jobs/regular/user_email.rb:83:in `send_user_email'
/var/www/discourse/app/jobs/regular/user_email.rb:38:in `execute'
/var/www/discourse/app/jobs/base.rb:232:in `block (2 levels) in perform'
rails_multisite-4.0.1/lib/rails_multisite/connection_management.rb:80:in `with_connection'
/var/www/discourse/app/jobs/base.rb:221:in `block in perform'
/var/www/discourse/app/jobs/base.rb:217:in `each'
/var/www/discourse/app/jobs/base.rb:217:in `perform'
sidekiq-6.4.2/lib/sidekiq/processor.rb:196:in `execute_job'
sidekiq-6.4.2/lib/sidekiq/processor.rb:164:in `block (2 levels) in process'
sidekiq-6.4.2/lib/sidekiq/middleware/chain.rb:138:in `block in invoke'
/var/www/discourse/lib/sidekiq/pausable.rb:138:in `call'
sidekiq-6.4.2/lib/sidekiq/middleware/chain.rb:140:in `block in invoke'
sidekiq-6.4.2/lib/sidekiq/middleware/chain.rb:143:in `invoke'
sidekiq-6.4.2/lib/sidekiq/processor.rb:163:in `block in process'
sidekiq-6.4.2/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch'
sidekiq-6.4.2/lib/sidekiq/job_retry.rb:114:in `local'
sidekiq-6.4.2/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch'
sidekiq-6.4.2/lib/sidekiq.rb:40:in `block in <module:Sidekiq>'
sidekiq-6.4.2/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch'
sidekiq-6.4.2/lib/sidekiq/processor.rb:257:in `stats'
sidekiq-6.4.2/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch'
sidekiq-6.4.2/lib/sidekiq/job_logger.rb:13:in `call'
sidekiq-6.4.2/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch'
sidekiq-6.4.2/lib/sidekiq/job_retry.rb:81:in `global'
sidekiq-6.4.2/lib/sidekiq/processor.rb:124:in `block in dispatch'
sidekiq-6.4.2/lib/sidekiq/job_logger.rb:39:in `prepare'
sidekiq-6.4.2/lib/sidekiq/processor.rb:123:in `dispatch'
sidekiq-6.4.2/lib/sidekiq/processor.rb:162:in `process'
sidekiq-6.4.2/lib/sidekiq/processor.rb:78:in `process_one'
sidekiq-6.4.2/lib/sidekiq/processor.rb:68:in `run'
sidekiq-6.4.2/lib/sidekiq/util.rb:56:in `watchdog'
sidekiq-6.4.2/lib/sidekiq/util.rb:65:in `block in safe_thread'

Есть ли какая-то дополнительная информация, которую я мог бы предоставить, чтобы помочь в отладке этого?

4 лайка

3 сообщения были объединены в существующую тему: Несоответствие сертификата имени хоста почтового сервера вызвало перегрузку очереди Sidekiq и серьезную нестабильность сайта

У меня тоже эта проблема!

Я обнаружил, что мой почтовый сервер использовал сертификат для другого сервера в своей конфигурации round-robin, и надеялся, что проблема заключается в несоответствии имени хоста. В процессе перехода на сервер, у которого не было несоответствия сертификата, я обновился до версии b850c12793, но это не решило проблему. Я повторил запуск некоторых задач, но ни одна из них не завершилась успешно. Следовательно, этот баг не является симптомом скрытых несоответствий сертификатов.

Сборка была выполнена с использованием discourse_docker версии 2a9faf7e5680b9.

Обновление discourse_docker до версии 241a42ce718, а вместе с ним и discourse до версии 95e7e10417, также не решило проблему. У меня всё ещё есть 30 таких неудачных попыток, которые повторяются.

1 лайк

Исходя из вашего описания и анализа этого поста, здесь может быть несколько проблем:

Возможно, сервер не ограничивает повторные попытки отправки писем, из-за чего они истекают по тайм-ауту или отклоняются почтовым сервером. Однако, если ваши сертификаты и конфигурация корректны, а письма всё равно не отправляются, это указывает на какую-то другую скрытую проблему. У некоторых пользователей это также приводило к заполнению дискового пространства. Я проверил свой сервер, но у меня такой проблемы не наблюдалось.

Место на диске не закончилось, и это происходит даже при выборе ровно одной задачи для повторного запуска, так что это не похоже на состояние гонки. Очевидно, что здесь несколько проблем, и то, что я наблюдаю, не связано с темой по ссылке.

(Оказалось, что у меня вообще не было проблемы с сертификатом; имена серверов были указаны в поле альтернативных имён сервера. Но я всё равно перешёл на использование имени хоста, совпадающего с SN, и это ничего не изменило.)

Я успешно отправляю огромное количество писем, застряли лишь эти несколько задач. Я не знаю, например, какие записи в логах искать для диагностики.

2 лайка

Я пока создал черновик PR, в который добавил тест, демонстрирующий эту проблему:

Теперь, когда мы знаем, какая строка кода вызывает проблему, надеюсь, мы скоро сможем найти хорошее решение.

5 лайков

Я просмотрел свои 29 неудачных писем, чтобы убедиться, что нет ничего критичного для отправки, и, насколько я мог судить, такого не было, поэтому я удалил все задачи в Sidekiq на случай, если это было вызвано временной проблемой из-за того, что задачи отправки писем пересекались с обновлениями. Однако, не применяя дальнейших обновлений, я теперь столкнулся ещё с одним случаем той же ошибки.

Просто делюсь этой информацией, чтобы показать, что это продолжающаяся проблема, а не странное временное явление.

2 лайка

Исправление кода выше уже внесено в репозиторий. Не могли бы вы, когда будет возможность, выполнить git pull для получения последних изменений и пересобрать свой контейнер?

4 лайка

Обновление и повторная попытка выполнения задачи позволили успешно отправить письмо; я проверил журналы электронной почты, и там указано, что оно отправлено.

Спасибо!

4 лайка