Generación de certificados de discobot muy lenta en nuestro servidor

Soporte
1

Hemos estado animando a nuestros nuevos miembros a completar el tutorial de discobot y varios de ellos están encontrando un problema que ya habíamos experimentado en una instancia anterior (de staging) de Discourse: el certificado en el último post tarda mucho en generarse y aparecer, sin ninguna indicación de que se esté cargando o generando. Por mucho tiempo me refiero a un periodo de 10-20 segundos, suficiente para que alguien se rinda. Probé en meta y allí parece ser instantáneo.

Noté que el certificado se puede generar bajo demanda usando la URL /discobot/certificate.svg?date=Oct+28+2020&user_id=123, así que realicé algunas pruebas. Al principio fue instantáneo. Pero tan pronto como usé IDs de usuarios que no habían completado el tutorial recientemente, tuve que esperar el periodo de 10-20 segundos (una vez generado por primera vez es rápido, así que asumo que hay una caché en algún lugar). También obtuve algunos errores 500 durante el periodo de espera, lo cual asumo fue algún tipo de timeout, ya que funcionó en la siguiente actualización.

En /logs, veo una advertencia que no sé si está relacionada:

Failed to process hijacked response correctly : Net::ReadTimeout

traceback 
/usr/local/lib/ruby/2.6.0/net/protocol.rb:217:in `rbuf_fill'

/usr/local/lib/ruby/2.6.0/net/protocol.rb:191:in `readuntil'

/usr/local/lib/ruby/2.6.0/net/protocol.rb:201:in `readline'

/usr/local/lib/ruby/2.6.0/net/http/response.rb:40:in `read_status_line'

/usr/local/lib/ruby/2.6.0/net/http/response.rb:29:in `read_new'

/usr/local/lib/ruby/2.6.0/net/http.rb:1509:in `block in transport_request'

/usr/local/lib/ruby/2.6.0/net/http.rb:1506:in `catch'

/usr/local/lib/ruby/2.6.0/net/http.rb:1506:in `transport_request'

/usr/local/lib/ruby/2.6.0/net/http.rb:1479:in `request'

rack-mini-profiler-2.0.2/lib/patches/net_patches.rb:9:in `block in request_with_mini_profiler'

rack-mini-profiler-2.0.2/lib/mini_profiler/profiling_methods.rb:39:in `step'

rack-mini-profiler-2.0.2/lib/patches/net_patches.rb:8:in `request_with_mini_profiler'

/var/www/discourse/lib/final_destination.rb:370:in `block in safe_get'

/var/www/discourse/lib/final_destination.rb:414:in `block in safe_session'

/usr/local/lib/ruby/2.6.0/net/http.rb:920:in `start'

/usr/local/lib/ruby/2.6.0/net/http.rb:605:in `start'

/var/www/discourse/lib/final_destination.rb:411:in `safe_session'

/var/www/discourse/lib/final_destination.rb:362:in `safe_get'

/var/www/discourse/lib/final_destination.rb:131:in `get'

/var/www/discourse/lib/final_destination.rb:152:in `get'

/var/www/discourse/lib/file_helper.rb:55:in `download'

/var/www/discourse/plugins/discourse-narrative-bot/plugin.rb:113:in `fetch_avatar'

/var/www/discourse/plugins/discourse-narrative-bot/plugin.rb:98:in `block in generate'

/var/www/discourse/lib/hijack.rb:56:in `instance_eval'

/var/www/discourse/lib/hijack.rb:56:in `block in hijack'

/var/www/discourse/lib/scheduler/defer.rb:94:in `block in do_work'

rails_multisite-2.3.0/lib/rails_multisite/connection_management.rb:68:in `with_connection'

/var/www/discourse/lib/scheduler/defer.rb:89:in `do_work'

/var/www/discourse/lib/scheduler/defer.rb:79:in `block (2 levels) in start_thread'

Entiendo que el certificado se genera localmente, sin solicitudes de red externas.

La máquina es t3a.medium (4 GB de memoria) y el foro no está particularmente activo (~0.4 de carga, todavía hay mucha memoria libre). Durante la espera para que se genere el certificado, el CPU no pareció cambiar en absoluto, así que eso no parece ser el cuello de botella.

No somos los únicos que experimentamos esto (no estoy seguro si esto está relacionado), pero no veo nada allí que pueda ayudar.

No estoy seguro si estoy en algo, pero si actualicé la URL del certificado varias veces, finalmente obtuve un error que me decía que me calmara. ¿Existe algún mecanismo de limitación de velocidad de URL que pueda estar interfiriendo aquí si muchas personas están generando certificados en esa misma ruta de URL? Posiblemente no, pero no tengo idea de por qué está ocurriendo esto. Cualquier pista será bienvenida.

3

Esa ruta es, de hecho, lenta, ya que es nueva.

Aparte de intentar hacerla más rápida, ¿tal vez podríamos cambiar el texto del mensaje para informar al usuario de que Discobot está preparando algo y que tardará un minuto?

5

No sabía que se sabía que era lento. Si nada más, supongo que una actualización en la publicación para aclararlo podría ayudar, pero aún así espero que algunas personas lo abandonen si la espera es larga.

Debo decir que 10 a 20 segundos para generar parece un tiempo inusualmente largo para generar un SVG preexistente (¿asumo?) relleno con algo de texto? Por lo que puedo ver, esto no parece estar limitado por la CPU. ¿Cuál es el cuello de botella aquí?

6

Estaba pensando en editar el texto aquí para incluir una frase como “por favor espera, ¡estoy generando algo genial para ti!” en el paso anterior… pero en try.discourse.org la generación del certificado es MUY rápida:

image
image1540×881 107 KB

Último paso de discobot: 2 de nov, 6:46 PM 1604371566089
Paso de generación de certificado de discobot: 2 de nov, 6:46 PM 1604371567470

No sé exactamente cuáles son las unidades de las marcas de tiempo subyacentes, pero eso es una diferencia de 1381.

Respondí lo más rápido que pude sobre el mismo tema y obtuve estas marcas de tiempo, claramente separadas por menos de unos segundos:

1604373488630
1604373492182

Eso es una diferencia de 3552… y literalmente publiqué lo más rápido que pude, usando pegar y atajos de teclado.

Así que… ¿tu servidor simplemente… falla… o algo así?

7

Creo que está hablando de la generación de la imagen del certificado, no de la publicación.

8

De hecho, estoy hablando de la generación del certificado, no de la respuesta del post que lo incrusta (que es rápida). Esto es lo que este problema está causando a algunos de nuestros miembros:

image
image556×333 3.72 KB

No, una instancia t3a.medium es de gama media y la carga no es alta.

Como dije, esto no parece estar limitado por la CPU, ya que mientras espero a que termine una solicitud, por ejemplo /discobot/certificate.svg?date=Oct+28+2020&user_id=123, la CPU no está más ocupada que en cualquier otro momento (lo cual no es muy ocupado).

El problema parece estar relacionado con un tiempo de espera agotado en una solicitud de red:

La imagen de perfil en el certificado parece ser un blob data:image/png;base64. Por lo que puedo ver, hay un intento de descargar una imagen de perfil que está agotando el tiempo de espera. ¿Quizás eso es lo que está ralentizando las cosas aquí?

Para contextualizar, esto ocurre en un foro con SSO y las imágenes de perfil son URLs HTTPS almacenadas en S3. He intentado obtener algunas de esas imágenes de perfil desde dentro del contenedor Docker y funciona, es casi instantáneo: no hay problemas de firewall, etc. Todo lo demás en el foro funciona rápido, excepto al generar el certificado, lo cual tarda mucho.

Estoy dispuesto a intentar depurar esto más a fondo si me dan indicaciones sobre qué revisar.

9

La imagen apareció más o menos al instante para mí en try.discourse.org… ¡No noté un retraso significativo de más de medio segundo, si es que hubo alguno! Pruébalo tú mismo si no me crees.

Así que vuelvo a lo que dije originalmente: ¿por qué es tan lento en tu servidor, y tan rápido en try.discourse.org?

11

¿Por qué, en efecto…? Eso es precisamente por lo que estoy intentando obtener soporte.

Entiendo que se trata de un escenario del tipo “funciona en mi máquina”, algo que ni siquiera debería existir con Docker, pero, por desgracia, aquí estamos y parece que no soy el único.

Cualquier pista sobre cómo depurar esto de mi lado sería muy apreciada.

12

He dedicado un tiempo a investigar esto y el problema parece ser que discourse-narrative-bot se bloquea al obtener el avatar del usuario para incluirlo en el certificado. Aquí:

Este foro utiliza SSO y los avatares son URLs de Amazon S3, que son rápidas y no tienen límite de velocidad por parte de Amazon. Dicho esto, esa función está obteniendo una URL de avatar con el siguiente formato:

https://forum.tld/user_avatar/forum.tld/username/240/18705_2.png

¿Podrían los errores de tiempo de espera que están ralentizando la generación del certificado deberse a que se activa el límite de velocidad de Discourse de alguna manera? Ya sea porque los avatares se solicitan demasiado rápido desde la propia instancia de Discourse, o porque se intenta acceder a Amazon S3 demasiado rápido cuando varios usuarios están realizando el tutorial del bot?

13

Interesante. Incrustamos una imagen en base64 allí. Me pregunto por qué no simplemente vinculamos al recurso externo en la etiqueta image del SVG :thinking:

Me sumergí en el historial del plugin hasta el punto en que lo agregamos por primera vez:

Y parece que siempre hemos utilizado avatares incrustados en base64.

EDIT: Tras algunas investigaciones, incrustamos en base64 porque el certificado se carga mediante una etiqueta HTML img. Para obtener avatares más económicos, tendríamos que cambiar a una etiqueta object, la cual está bloqueada por defecto en nuestra CSP. O bien incrustar todo el SVG en el contenido del post. Supongo que un iframe es nuestra mejor opción.

Tengo FIX: Make discobot certificate gen faster/non blocking by xfalcox · Pull Request #11344 · discourse/discourse · GitHub para los comentarios de @tgxworld.

14

Asumí que el SVG que incrustaba el avatar en base64 era por la misma razón por la que “hacía lo mismo” con el logotipo: para que el certificado pudiera ser una instantánea en el tiempo, quizás guardada por el galardonado, sin dependencias externas, de modo que seguiría renderizándose exactamente igual más adelante.

El enfoque del iframe impide que se comparta y presuma fácilmente en una publicación. No sé qué tan común sea esto en otros foros, pero he visto a algunos de nuestros usuarios hacerlo simplemente copiando la URL de la imagen.

Si vamos a enlazar a algo externo, ¿no funcionaría aquí usar <image> y evitar la necesidad de cambiar allowed_iframes?

15

Eso es exactamente lo que hace la PR anterior si la lees :grimacing:

Pero si cargas el SVG con la etiqueta HTML img como hacemos hoy, las imágenes externas contenidas en las etiquetas image del SVG no se cargarán. Para que eso funcione, debe cargarse mediante object o iframe.

16

Claramente no sé lo suficiente sobre SVG. El enfoque del iframe evita que el certificado sea citado/copiado, pero de todos modos me alegra que se esté abordando de alguna manera, ya que solucionará nuestro problema y también el logotipo faltante en el certificado. :+1:

17

@mentalstring Acabo de fusionar el nuevo código de generación de certificados. Debería ser mucho más rápido ahora.

18

Genial ver que esto se está fusionando. :+1:

Estamos en stable y en este momento no tengo una buena manera de probarlo. Pero si fetch_avatar ya no se usa, espero que nuestros errores Net::ReadTimeout desaparezcan con esto. Lo marco como resuelto y lo volveré a abrir si, por alguna razón, vuelvo a encontrarme con el mismo problema al actualizar. ¡Gracias!