Génération de certificats discobot très lente sur notre serveur

Soutien
1

Nous avons incité nos nouveaux membres à suivre le tutoriel de discobot, et plusieurs d’entre eux rencontrent un problème que nous avions déjà observé dans une instance Discourse précédente (staging) : le certificat du dernier message prend beaucoup de temps à être généré et à s’afficher, sans aucune indication qu’il est en cours de chargement/génération. Par « beaucoup de temps », j’entends une période de 10 à 20 secondes, ce qui est suffisant pour que quelqu’un abandonne. J’ai fait un test sur meta et cela semble être instantané ici.

J’ai remarqué que le certificat peut être généré à la demande via l’URL /discobot/certificate.svg?date=Oct+28+2020&user_id=123, alors j’ai effectué quelques tests. Au début, c’était instantané. Mais dès que j’ai utilisé des identifiants d’utilisateurs qui n’avaient pas fait le tutoriel récemment, j’ai dû attendre les 10 à 20 secondes (c’est rapide une fois généré la première fois, donc je suppose qu’il y a un cache quelque part). J’ai également reçu quelques erreurs 500 pendant la période d’attente, que je suppose être un type de timeout, car cela a fonctionné au prochain rafraîchissement.

Dans /logs, je vois un avertissement dont je ne sais pas s’il est lié :

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'

Je suppose que le certificat est généré localement, sans aucune requête réseau externe ?

La machine est une t3a.medium (4 Go de mémoire) et le forum n’est pas particulièrement chargé (~0,4 de charge, encore beaucoup de mémoire libre). Pendant l’attente de la génération du certificat, le CPU ne semblait pas changer du tout, donc ce n’est probablement pas le goulot d’étranglement.

Nous ne sommes pas les seuls à rencontrer ce problème (je ne sais pas si celui-ci est lié), mais je n’y vois rien qui puisse aider.

Je ne sais pas si je suis sur la bonne voie, mais si je rafraîchis plusieurs fois l’URL du certificat, j’obtiens éventuellement une erreur me demandant de ralentir. Existe-t-il un mécanisme de limitation de débit des URL qui pourrait interférer ici si beaucoup de personnes génèrent les certificats au même chemin d’URL ? Probablement pas, mais je suis à court d’idées sur la raison pour laquelle cela se produit. Toute aide est la bienvenue.

5 « J'aime »
3

That route is indeed slow, as it is knew.

Other than trying to make it faster, maybe we can add a copy change to the message telling the user that Discobot is preparing something and that it will take a minute?

4 « J'aime »
5

I wasn’t aware that it was known to be slow — if nothing else, I guess an update on the post to make that clear may help, but I still expect some people to give up on it if the wait is long.

I must say that 10 to 20 seconds to generate seems unusually long to output a pre-existing svg (I assume?) filled with some text? As far as I can see, this doesn’t seem to be CPU bound. What’s the bottleneck here?

6

J’envisageais de modifier le texte pour inclure une phrase du type « veuillez patienter, je génère quelque chose d’incroyable pour vous ! » à l’étape précédente… mais sur try.discourse.org, la génération du certificat est TRÈS rapide :

image
image1540×881 107 KB

Dernière étape de discobot : 2 novembre, 18 h 46 1604371566089
Étape de génération de certificat de discobot : 2 novembre, 18 h 46 1604371567470

Je ne connais pas exactement les unités des horodatages sous-jacents, mais cela représente une différence de 1381.

J’ai répondu aussi vite que possible sur le même sujet et obtenu ces horodatages, séparés de quelques secondes tout au plus :

1604373488630
1604373492182

Cela représente une différence de 3552… et j’ai littéralement posté aussi vite que possible, en utilisant le collage et les raccourcis clavier !

Alors… est-ce que votre serveur est juste… nul ou quelque chose comme ça ?

7

Je pense qu’il parle de la génération de l’image du certificat, et non du post.

8

Je parle bien de la génération du certificat — et non de la réponse qui l’intègre (qui est rapide). Voici ce que ce problème cause à certains de nos membres :

image
image556×333 3.72 KB

Non, une instance t3a.medium est une instance de gamme moyenne et la charge n’est pas élevée.

Comme je l’ai dit, cela ne semble pas être limité par le CPU, car pendant que j’attends la fin d’une requête, par exemple /discobot/certificate.svg?date=Oct+28+2020&user_id=123, le CPU n’est pas plus sollicité qu’à d’autres moments (ce qui n’est déjà pas très sollicité).

Le problème semble lié à un dépassement de temps d’une requête réseau :

L’avatar sur le certificat semble être un blob data:image/png;base64. D’après ce que je vois, il y a une tentative de téléchargement d’un avatar qui expire ? Peut-être que c’est ce qui ralentit les choses ici ?

Pour contexte, ceci se passe sur un forum avec SSO et les avatars sont des URL https stockées sur S3. J’ai essayé de récupérer certains de ces avatars depuis le conteneur Docker et cela fonctionne, presque instantanément — aucun problème de pare-feu, etc. Tout le reste sur le forum fonctionne rapidement, sauf lors de la génération du certificat qui prend beaucoup de temps.

Je suis prêt à essayer de déboguer davantage si on me donne des pistes sur quoi vérifier.

9

L’image est apparue plus ou moins instantanément pour moi sur try.discourse.org… Je n’ai pas remarqué de délai significatif de plus de peut-être une demi-seconde, voire pas même cela ? Essayez par vous-même si vous ne me croyez pas !

Je reviens donc à ce que j’ai dit au début : pourquoi est-ce si lent sur votre serveur, alors que c’est si rapide sur try.discourse.org ?

11

En effet… C’est précisément à ce sujet que je cherche à obtenir de l’aide.

Je comprends qu’il s’agisse d’un cas du type « ça marche sur ma machine », qui ne devrait même pas exister avec Docker, mais hélas, nous en sommes là et il semble que je ne sois pas le seul dans ce cas.

Toute indication sur la manière de déboguer cela de mon côté serait la bienvenue.

1 « J'aime »
12

J’ai passé un certain temps à examiner ce problème et il semble que le blocage provienne du discourse-narrative-bot lors de la récupération de l’avatar de l’utilisateur à inclure sur le certificat. Voici :

Ce forum utilise l’authentification SSO et les avatars sont des URL Amazon S3 — rapides et non limitées par Amazon. Cela dit, cette fonction récupère une URL d’avatar de la forme :

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

Les erreurs de timeout qui ralentissent la génération du certificat pourraient-elles être dues au fait de déclencher les limites de débit de Discourse ? Soit parce que les avatars sont demandés trop rapidement depuis l’instance Discourse elle-même, soit parce qu’on tente de contacter Amazon S3 trop vite lorsque plusieurs utilisateurs suivent le tutoriel du bot ?

3 « J'aime »
13

Intéressant. Nous intégrons une image en base64 là-dedans. Je me demande pourquoi nous n’avons pas simplement lié la ressource externe dans la balise image SVG :thinking:

Je suis remonté dans l’historique du plugin jusqu’au moment où nous l’avons ajouté pour la première fois :

Et il semble que nous ayons toujours utilisé des avatars intégrés en base64.

EDIT : Après quelques recherches, nous intégrons en base64 car le certificat est chargé via une balise HTML img. Pour avoir des avatars moins chers, nous devrions passer à une balise object, qui est bloquée par défaut dans notre CSP. Ou intégrer l’ensemble du SVG dans le contenu du message. Je suppose qu’une iframe est notre meilleure option.

J’ai FIX: Make discobot certificate gen faster/non blocking by xfalcox · Pull Request #11344 · discourse/discourse · GitHub pour les commentaires de @tgxworld.

5 « J'aime »
14

J’ai supposé que l’encapsulation SVG de l’avatar en base64 avait la même raison que celle du logo « qu’il effectuait » : afin que le certificat puisse être un instantané dans le temps — peut-être sauvegardé par le lauréat, sans aucune dépendance externe, de sorte qu’il s’afficherait plus tard exactement de la même manière.

L’approche par iframe l’empêche d’être facilement partagé et vanté dans un message. Je ne sais pas à quel point cela est courant sur d’autres forums, mais j’ai vu certains de nos utilisateurs le faire simplement en copiant l’URL de l’image.

Si l’on opte pour un lien vers quelque chose d’externe, l’utilisation de <image> ne fonctionnerait-elle pas ici et éviterait-elle la nécessité de modifier allowed_iframes ?

15

C’est exactement ce que fait la PR ci-dessus si vous la lisez :grimace:

Mais si vous chargez le SVG avec la balise HTML img comme nous le faisons aujourd’hui, les images externes contenues dans les balises image du SVG ne seront pas chargées. Pour que cela fonctionne, il faut les charger soit avec object, soit avec iframe.

3 « J'aime »
16

Clairement, je ne sais pas assez sur SVG. L’approche iframe empêche le certificat d’être cité/copié, mais je suis néanmoins ravi que cela soit résolu d’une manière ou d’une autre, car cela règlera notre problème ainsi que le logo manquant sur le certificat. :+1:

2 « J'aime »
17

@mentalstring Je viens de fusionner le nouveau code de génération de certificats. Cela devrait être beaucoup plus rapide maintenant.

4 « J'aime »
18

Ravi de voir cela être fusionné. :+1:

Nous sommes sur stable et je n’ai pas de bon moyen de tester cela pour le moment. Mais si fetch_avatar n’est plus utilisé, je m’attends à ce que nos erreurs Net::ReadTimeout disparaissent avec cette mise à jour. Je marque cela comme résolu et je rouvrirai le ticket si, pour une raison quelconque, je rencontre à nouveau le même problème lors de notre mise à jour. Merci !

19

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