Error de reintento en sidekiq

Esta es la primera vez que veo este error después de la reciente actualización a 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

Si intento reintentarlo, falla de nuevo. Esto parece ser en referencia a un nuevo tema que fue creado por un usuario.

¿Qué significa esto y cómo lo soluciono?

2 Me gusta

Veo que el servidor envió con éxito una gran cantidad de correos electrónicos sobre este nuevo tema a todos los que estaban siguiendo esa categoría. Tampoco veo ningún error en los registros de correo electrónico ni en el servidor de correo electrónico.

Entonces, ¿a qué se refiere esto?

Aquí también ocurre el mismo error por primera vez, reintentar no ayuda, todos los demás correos se entregan:

Jobs::UserEmail

{"type"=>"user_private_message", "user_id"=>1513, "notification_id"=>871360, "notification_data_hash"=>{"topic_title"=>"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

Backtrace

/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!'

También noté los registros de discourse:

Mensaje (21 copias reportadas)

Excepción de trabajo: Falló la validación: El post ya ha sido tomado

Backtrace

/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!'

Moviendo esto a errores en lugar de soporte

1 me gusta

Hola @RBoy :slight_smile:

¿Sigues viendo este error?

Para esa entrada, sí, todavía estaba atascada en un bucle de reintentos hasta ayer, cuando después de cientos de reintentos, finalmente me harté y la eliminé. Espero no haber roto algo.

No la he vuelto a ver, pero tampoco ha habido un evento que desencadenara cientos de correos electrónicos en una sola publicación. Sin embargo, sería bueno entender de dónde vino esto y qué significa.

Hace unos días, vi este error en tres mensajes, y no eran críticos, así que eliminé los trabajos después de que un reintento no tuviera éxito.

Ahora tengo 2001 de ellos, y mi cuenta de prueba no recibió un resumen semanal que debería haber recibido.

Ejecutando 8695449cfc ahora mismo.

2 Me gusta

Me actualicé a bf987af3ca y volví a intentar todo y todavía tengo al menos 38 de Jobs::HandledExceptionWrapper: Wrapped ActiveRecord::RecordInvalid: Validation failed: Post has already been taken que se muestran en mi consola de sidekiq.

2 Me gusta

Sin más actualizaciones, ahora me quedan 30. Supongo que están fallando por tiempo de espera, excepto que mi cuenta de prueba recibió el resumen semanal (retrasado), y supongo que esto está relacionado. No estoy seguro de dónde buscar en los registros para saber si alguno realmente se está rindiendo.

Parecen fallar la mayoría de las veces pero ocasionalmente tienen éxito, lo que definitivamente huele a una condición de carrera en algún lugar.

Mis backtraces se ven igual que lo que vieron @RBoy y @md-misko, pero aquí está el backtrace completo, no solo el truncado del botón “Copiar”:

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'
/var/www/discourse/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'

¿Hay alguna información más que pueda proporcionar para ayudar a depurar esto?

4 Me gusta

3 publicaciones se fusionaron en un tema existente: Email Hostname Certificate Mismatch Causing sidekiq Queue Overload, Severe Site Instability

¡Yo también estoy experimentando este problema!

Descubrí que mi servidor de correo estaba utilizando un certificado para otro servidor en su round-robin, y esperaba que la discrepancia de nombre de host fuera el problema. Actualicé a b850c12793 en el proceso de cambiar a un servidor que no tenía una discrepancia de certificado, pero no resolvió el problema. Volví a intentar algunos de los trabajos, pero ninguno se completó con éxito. Por lo tanto, este error no es un síntoma de discrepancias de certificados ocultas.

Esto se compiló con discourse_docker 2a9faf7e5680b9.

Actualizar discourse_docker a 241a42ce718, y con ello discourse a 95e7e10417, tampoco resolvió el problema. Todavía tengo 30 de estos fallos siendo reintentados.

1 me gusta

Por lo que describes y al ver esta publicación, puede haber varios problemas aquí:

El servidor puede no estar limitando sus reintentos de correos electrónicos, lo que provoca que caduque o sea rechazado por el servidor de correo. Pero hay algún otro problema subyacente si sus certificados y configuración son válidos y aún así no envía los correos electrónicos. Para algunos, también parece estar consumiendo espacio en disco. Revisé el mío pero no noté eso aquí.

No me quedé sin espacio, y esto sucede incluso cuando selecciono exactamente un trabajo para volver a ejecutar, por lo que no parece una condición de carrera. Claramente hay más de un problema aquí, y lo que estoy viendo aquí no está relacionado con ese tema vinculado.

(Resulta que después de todo no tuve un problema de certificado; los nombres de los servidores estaban en el nombre alternativo del servidor. Pero me cambié a usar el nombre de host que coincide con el SN de todos modos, y no hizo ninguna diferencia).

Estoy enviando con éxito una gran cantidad de correos electrónicos, solo estos pocos trabajos están atascados. No sé, por ejemplo, qué entradas de registro buscar para ayudar al diagnóstico.

2 Me gusta

He creado una PR provisional por ahora que añade una prueba fallida que replica este problema:

Ahora que sabemos qué línea de código está causando el problema, esperemos que podamos encontrar una buena solución pronto.

5 Me gusta

Revisé mis 29 correos electrónicos fallidos para asegurarme de que no había nada crítico que enviar y, por lo que pude determinar, no lo había, así que eliminé todos los trabajos en sidekiq, en caso de que esto se debiera a un problema transitorio debido a que los trabajos de correo electrónico abarcan actualizaciones. Sin embargo, sin aplicar más actualizaciones, ahora tengo otro caso de la misma falla.

Solo comparto esto como información de que es un problema en curso y no algo transitorio extraño.

2 Me gusta

La corrección del código anterior se ha fusionado, ¿puedes hacer git pull de los últimos cambios y reconstruir tu contenedor cuando tengas oportunidad?

4 Me gusta

La actualización y el reintento del trabajo tuvieron éxito en el envío del correo; he comprobado los registros de correo y se informó que se envió.

¡Gracias!

4 Me gusta