Sidekiq tiene muchos errores y trabajos en cola

Hemos recibido un aviso en la consola de administración sobre nuestros trabajos en cola de Sidekiq: tenemos casi 200.000 trabajos en cola y no estamos seguros de cómo resolver el problema. Estamos ejecutando la versión 3.2.0.

Los trabajos están todos en la cola ultra_low y parecen ser el trabajo Jobs::ProcessPost. Todos parecen ser similares a esto:

	[{"bypass_bump"=>true, "cooking_options"=>nil, "new_post"=>false, "post_id"=>729508, "skip_pull_hotli... 
{"bypass_bump"=>true, "cooking_options"=>nil, "new_post"=>false, "post_id"=>729508, "skip_pull_hotlinked_images"=>false, "current_site_id"=>"default"}

¿Cómo podemos hacer que estos trabajos se procesen y cómo lo hacemos de manera que garantice que no afecten significativamente el rendimiento (¿o es inevitable)?

2 Me gusta

Hace dos días, eran alrededor de 195K; ahora son 211K. Realmente agradecería algunos consejos sobre qué revisar y cómo resolver este problema.

Hemos notado 5 trabajos fallidos que se ven así (direcciones IP ofuscadas):

Jobs::HandledExceptionWrapper: Wrapped Errno::ENETUNREACH: Failed to open TCP connection to x.x.x.x:443 (Network is unreachable - connect(2) for "x.x.x.x" port 443)

La dirección es de un servidor que está en la infraestructura pero no es utilizado por los foros (es un servidor de repositorio de código fuente). No veo en ninguna parte de la configuración dónde se hace referencia a este host, así que no estoy seguro de por qué cree que necesita conectarse a ese host. Pero me pregunto si esto está relacionado con el creciente número de trabajos en cola en la cola ultra_low.

2 Me gusta

Se han añadido otros 7.000 trabajos a la cola en las últimas ~23 horas.

Esto también está retrasando algunos cambios de implementación: cierre automático y adición del plugin de soluciones (simplemente no quiero hacer cambios que puedan verse afectados por esto, o cuando esto pueda verse agravado por un cambio tan significativo en la configuración del sistema).

Los 7.000 trabajos añadidos no se alinean con la cantidad de nuevas publicaciones que hemos tenido en el último día, por lo que no estoy seguro de qué está impulsando esto en absoluto.

¿Qué otra información sería útil para resolver este problema?

2 Me gusta

No puedo ayudar, excepto sugiriendo que más respuestas y más “me gusta” a las publicaciones en este hilo podrían darle la atención que parece merecer.

Editar: También he mencionado este problema en el hilo sobre el orden por defecto de “más popular”, que creo que está ocultando este hilo de manera muy efectiva y muy poco útil.

2 Me gusta

¿Puedes compartir el backtrace completo? Supongo que proviene de nuestro código onebox, pero me gustaría estar seguro.

3 Me gusta

Supongo que tenemos que hacerlo desde la consola. Tendré que pedirle a alguien con acceso que lo haga; ¿puede decirme de dónde sacarlo para que pueda pasárselo a la persona con acceso?

¡Gracias!

No, no, la traza de pila se muestra en una pestaña en la página /logs cuando seleccionas el error.

1 me gusta

Ah, gracias por la indicación. Aquí está lo que muestra (dirección IP ofuscada):

Mensaje (se informaron 10 copias)

Excepción de trabajo: No se pudo abrir la conexión TCP a x.x.x.x:443 (La red no está disponible - connect(2) para "x.x.x.x" puerto 443)


Rastreo de pila

/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `initialize'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `open'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1603:in `block in connect'
/usr/lib64/ruby/gems/3.2.0/gems/timeout-0.4.1/lib/timeout.rb:186:in `block in timeout'
/usr/lib64/ruby/gems/3.2.0/gems/timeout-0.4.1/lib/timeout.rb:193:in `timeout'
/usr/lib64/ruby/gems/3.2.0/gems/net-http-0.4.1/lib/net/http.rb:1601:in `connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:27:in `block in connect'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each_with_index'
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `connect'

Noté que esto es diferente de la salida en la pestaña “rastreo de pila”, pero esa salida no parece un rastreo de pila, sino lo que está aquí como una copia (usando el botón de copiar) sí lo es. Avísame si se necesita más información para esto.

También veré si puedo obtener más información sobre las más de 220K tareas en cola de esta manera, ya que desconocía el punto final /logs.

¿No hay líneas adicionales en la parte inferior del backtrace?

Eso fue todo lo que el botón Copiar capturó; aquí está la salida completa de la pestaña de rastreo de pila:

net-http-0.4.1/lib/net/http.rb:1603:in `initialize' 
net-http-0.4.1/lib/net/http.rb:1603:in `open' 
net-http-0.4.1/lib/net/http.rb:1603:in `block in connect' 
timeout-0.4.1/lib/timeout.rb:186:in `block in timeout' 
timeout-0.4.1/lib/timeout.rb:193:in `timeout' 
net-http-0.4.1/lib/net/http.rb:1601:in `connect' 
/srv/www/vhosts/discourse/lib/final_destination/http.rb:27:in `block in connect' 
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each' 
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `each_with_index' 
/srv/www/vhosts/discourse/lib/final_destination/http.rb:17:in `connect' 
net-http-0.4.1/lib/net/http.rb:1580:in `do_start' 
net-http-0.4.1/lib/net/http.rb:1569:in `start' 
net-http-0.4.1/lib/net/http.rb:1029:in `start' 
/srv/www/vhosts/discourse/lib/final_destination.rb:551:in `safe_session' 
/srv/www/vhosts/discourse/lib/final_destination.rb:486:in `safe_get' 
/srv/www/vhosts/discourse/lib/final_destination.rb:170:in `get' 
/srv/www/vhosts/discourse/lib/retrieve_title.rb:90:in `fetch_title' 
/srv/www/vhosts/discourse/lib/retrieve_title.rb:12:in `crawl' 
/srv/www/vhosts/discourse/lib/inline_oneboxer.rb:76:in `lookup' 
/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:310:in `process_inline_onebox' 
/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:39:in `block in post_process_oneboxes' 
/srv/www/vhosts/discourse/lib/oneboxer.rb:214:in `block in apply' 
/srv/www/vhosts/discourse/lib/oneboxer.rb:162:in `block in each_onebox_link' 
nokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:235:in `block in each' 
nokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:234:in `upto' 
nokogiri-1.16.0/lib/nokogiri/xml/node_set.rb:234:in `each' 
/srv/www/vhosts/discourse/lib/oneboxer.rb:162:in `each_onebox_link' 
/srv/www/vhosts/discourse/lib/oneboxer.rb:213:in `apply' 
/srv/www/vhosts/discourse/lib/cooked_processor_mixin.rb:9:in `post_process_oneboxes' 
/srv/www/vhosts/discourse/lib/cooked_post_processor.rb:42:in `block in post_process' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:53:in `block in synchronize' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:34:in `synchronize' 
/srv/www/vhosts/discourse/lib/cooked_post_processor.rb:38:in `post_process' 
/srv/www/vhosts/discourse/app/jobs/regular/process_post.rb:28:in `block in execute' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:53:in `block in synchronize' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:49:in `synchronize' 
/srv/www/vhosts/discourse/lib/distributed_mutex.rb:34:in `synchronize' 
/srv/www/vhosts/discourse/app/jobs/regular/process_post.rb:8:in `execute' 
/srv/www/vhosts/discourse/app/jobs/base.rb:297:in `block (2 levels) in perform' 
/srv/www/vhosts/discourse/lib/rails_multisite/connection_management.rb:82:in `with_connection'
/srv/www/vhosts/discourse/app/jobs/base.rb:284:in `block in perform' 
/srv/www/vhosts/discourse/app/jobs/base.rb:280:in `each' 
/srv/www/vhosts/discourse/app/jobs/base.rb:280: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' 
/srv/www/vhosts/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/rails.rb:14:in `block in call' 
activesupport-7.0.8/lib/active_support/execution_wrapper.rb:92:in `wrap' 
activesupport-7.0.8/lib/active_support/reloader.rb:72:in `block in wrap' 
activesupport-7.0.8/lib/active_support/execution_wrapper.rb:92:in `wrap' 
activesupport-7.0.8/lib/active_support/reloader.rb:71:in `wrap' 
sidekiq-6.5.12/lib/sidekiq/rails.rb:13:in `call' 
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' 

Lamento no haber capturado toda la salida. Pensé que era extraño que el botón Copiar no capturara más, pero hice una suposición errónea de que capturaba lo necesario.

¡Eso es mucho mejor!

Esto significa que hay uno/varios enlaces en línea con una URL que se resuelve en la dirección IP de tu servidor. Si no se puede acceder a ese servidor, registramos el error, pero el proceso de cocción de markdown debería continuar sin realizar el “enlace bonito” que activaría el onebox en línea.

Otra cosa, ¿cómo instalaste Discourse? Esto no parece una instalación que haya seguido nuestra guía de instalación oficial.

2 Me gusta

En realidad, no realicé la instalación; creo que nuestro equipo de infraestructura la implementó utilizando un pipeline de CI/CD, pero no conozco los detalles.

Parece que los mensajes fallidos no son un problema; el gran número de tareas en cola en la cola ultra_low parece ser el problema mayor aquí. No encuentro nada en los registros (tiene sentido para mí, de hecho, porque el trabajo aún no se ha ejecutado).

Si fuerzas manualmente que se ejecuten algunas, ¿qué sucede?

No veo una opción para forzarlos a ejecutarse en la interfaz de usuario web; tengo una opción para “mostrar todos” los argumentos o para eliminar las tareas individualmente.

Hm. No tenemos ninguno en cola en el foro que administro, así que me disculpo por intentar sugerir un botón que no está ahí.

Referencia de la página de reintentos, para lo que pensé que estaba en la página de cola

No te preocupes, sí, estos aparecen en la página Enqueued (en /sidekiq/queues/ultra_low).

Mirando la página de colas en sí, veo que la latencia de la cola ultra_low es de aproximadamente un año. Así que aparentemente esto ha estado sucediendo por un tiempo, y solo recientemente recibimos una alerta sobre ello en el panel de control.

1 me gusta

Profundizando un poco más en lo que veo en los trabajos de Jobs::ProcessPost, parece que los valores de post_id están contando hacia atrás. Extraje los IDs de post de los primeros y últimos trabajos en la cola, y las fechas corresponden con un post de 2012 (antes de la migración a Discourse, pero con una marca de tiempo ‘updated_at’ de 2022, que podría haber sido nuestra fecha de migración, tendré que comprobarlo) y el más reciente fue de enero de 2023.

Veo trabajos ocasionales para generar miniaturas de temas, pero son bastante raros. Con más de 8.800 páginas de cola, no puedo comprobar todo, pero parece que la mayoría son cosas de Jobs::ProcessPost las que se están añadiendo, y está retrocediendo en el tiempo a través de lo que parece ser cada respuesta y post inicial de un tema (el más antiguo estaba a mitad de hilo, el más reciente era un post raíz en un tema).

1 me gusta

He extraído una copia de seguridad del sistema de producción y la he cargado en un entorno de prueba configurado localmente. La cola no parece acumularse en absoluto; de hecho, no veo que Job::ProcessPost aparezca en esa cola mientras la observo (voy a configurarla y dejar que el sistema funcione solo mientras grabo la pantalla de la cola para ver si simplemente no la veo llegar).

Esto me lleva a dos preguntas:

  1. ¿Qué causa que se active el trabajo ProcessPost?
  2. ¿Qué causaría que la cola ultra_low no se procese?

No soy un experto en ninguna de las tecnologías utilizadas en Discourse (redis, sidekiq o rails), pero me siento muy cómodo aprendiendo y probando cosas en mi entorno aislado para comprender lo que necesito que alguien revise en producción.

La buena noticia es que este problema no parece estar causando ningún problema a nuestros usuarios (todavía). Una tercera pregunta sería si simplemente purgar esa cola ayudaría, o si no permitir que esos trabajos se ejecuten perjudicaría al sistema de alguna manera.

ETA: Acabo de ver que un lote de trabajos ha llegado a mi entorno de prueba y se están procesando allí. Así que parece que la cola no se está procesando en el servidor de producción por alguna razón.

Parece que hemos llegado a una resolución. La instalación que estamos utilizando es del paquete creado para openSUSE (la instancia de la que hemos estado hablando es la instancia para los foros de openSUSE), por lo que esencialmente utiliza el proceso de instalación de “compilación desde el código fuente”.

Tenemos un entorno de desarrollo y producción, y la cola ultra_low fue excluida por error de la configuración de sidekiq del entorno de producción. Esto se ha corregido, y parece que la cola se está vaciando y la latencia ha bajado de 1 año a 4 semanas.

Creo que podemos considerar esto resuelto ahora. Agradezco los comentarios de las personas que proporcionaron algunos, eso me ayudó a encontrar el camino correcto para descubrir cuál era el problema.

2 Me gusta

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