Generazione del certificato discobot molto lenta sul nostro server

Stiamo spingendo i nuovi membri a completare il tutorial di discobot e diversi hanno riscontrato un problema che avevamo già sperimentato in una precedente istanza Discourse (di staging): il certificato nell’ultimo post impiega molto tempo per essere generato e visualizzato, senza alcuna indicazione che sia in fase di caricamento/generazione. Per “molto tempo” intendo un intervallo di 10-20 secondi, sufficiente per far desistere qualcuno. Ho provato su meta e lì sembra essere istantaneo.

Ho notato che il certificato può essere generato on-demand utilizzando l’URL /discobot/certificate.svg?date=Oct+28+2020&user_id=123, quindi ho effettuato alcuni test. All’inizio era istantaneo. Ma non appena ho utilizzato ID utente che non avevano completato il tutorial di recente, ho dovuto attendere quel periodo di 10-20 secondi (una volta generato la prima volta è veloce, quindi presumo ci sia una cache da qualche parte). Ho anche ricevuto alcuni errori 500 durante il periodo di attesa, che presumo siano stati dei timeout di qualche tipo, dato che ha funzionato al prossimo aggiornamento della pagina.

Nei /logs, vedo un avvertimento di cui non so se sia correlato:

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'

Presumo che il certificato venga generato localmente, senza alcuna richiesta di rete esterna?

La macchina è una t3a.medium (4 GB di memoria) e il forum non è particolarmente attivo (~0.4 di carico, ancora molta memoria libera). Durante l’attesa per la generazione del certificato, la CPU non sembrava cambiare per nulla, quindi non sembra essere il collo di bottiglia.

Non siamo gli unici a riscontrare questo problema (non sono sicuro se questo sia correlato), ma non vedo nulla lì che possa aiutare.

Non sono sicuro di aver centrato qualcosa, ma se aggiorno l’URL del certificato alcune volte, alla fine ottengo un errore che mi dice di rallentare. Esiste qualche meccanismo di limitazione della velocità (throttling) per gli URL che potrebbe interferire qui se molte persone stanno generando i certificati allo stesso percorso URL? Probabilmente no, ma sono a un punto morto sul perché ciò stia accadendo. Qualsiasi suggerimento è benvenuto.

Quella rotta è effettivamente lenta, dato che è nuova.

Oltre a cercare di renderla più veloce, forse possiamo aggiungere una modifica al testo del messaggio per informare l’utente che Discobot sta preparando qualcosa e che richiederà un minuto?

Non ero a conoscenza che fosse noto per essere lento — se non altro, immagino che un aggiornamento al post per chiarirlo potrebbe aiutare, ma mi aspetto comunque che alcune persone rinuncino se l’attesa è lunga.

Devo dire che 10-20 secondi per generare sembrano un tempo insolitamente lungo per produrre un’immagine SVG preesistente (immagino?) riempita con del testo? Per quanto posso vedere, questo non sembra essere limitato dalla CPU. Qual è il collo di bottiglia qui?

Stavo pensando di modificare il testo qui per includere una frase come “per favore attendi, sto generando qualcosa di fantastico per te!” nel passaggio precedente… ma su try.discourse.org la generazione del certificato è MOLTO veloce:

Timestamp dell’ultimo passaggio di discobot: 2 nov, 18:46 1604371566089
Timestamp del passaggio di generazione certificato di discobot: 2 nov, 18:46 1604371567470

Non so esattamente quali siano le unità di misura dei timestamp sottostanti, ma questa è una differenza di 1381.

Ho risposto il più velocemente possibile sullo stesso argomento e ho ottenuto questi timestamp, chiaramente distanti tra loro di pochi secondi al massimo:

1604373488630
1604373492182

Questa è una differenza di 3552… e ho letteralmente pubblicato il più velocemente possibile, incollando e usando le scorciatoie da tastiera!

Quindi… il tuo server fa semplicemente schifo o qualcosa del genere?

Credo che si stia riferendo alla generazione dell’immagine del certificato, non al post.

Sto effettivamente parlando della generazione del certificato — non del post di risposta che lo incorpora (che è veloce). Questo è quanto sta causando il problema ad alcuni dei nostri membri:

No, un’istanza t3a.medium è un’istanza di fascia media e il carico non è elevato.

Come ho detto, questo non sembra essere limitato dalla CPU perché, mentre aspetto che termini una richiesta, ad esempio /discobot/certificate.svg?date=Oct+28+2020&user_id=123, la CPU non è più impegnata rispetto ad altri momenti (e non è molto impegnata in generale).

Il problema sembra essere legato a un timeout di una richiesta di rete:

L’avatar sul certificato sembra essere un blob data:image/png;base64. Da quanto riesco a vedere, c’è un tentativo di scaricare un avatar che va in timeout? Forse è questo che sta rallentando le cose?

Per contestualizzare, questo avviene in un forum con SSO e gli avatar sono URL HTTPS memorizzati su S3. Ho provato a recuperare alcuni di questi avatar dall’interno del container Docker e funziona, ed è quasi istantaneo — nessun problema di firewall, ecc. Tutto il resto nel forum funziona velocemente, tranne quando si genera il certificato, che richiede molto tempo.

Sono disponibile a provare a diagnosticare ulteriormente il problema se mi fornite indicazioni su cosa controllare.

L’immagine è apparsa più o meno istantaneamente per me su try.discourse.org.. Non ho notato un ritardo significativo superiore a forse mezzo secondo, se non di più! Provalo tu stesso se non mi credi!

Quindi torno a ciò che ho detto all’inizio: perché è così lento sul tuo server, e così veloce su try.discourse.org?

Perché, davvero… È proprio per questo che sto cercando assistenza.

So che si tratta di un caso del tipo “funziona sulla mia macchina”, che non dovrebbe nemmeno esistere con Docker, ma ecco che ci troviamo qui e sembra che non sia l’unico.

Qualsiasi suggerimento su come risolvere il problema dal mio lato sarebbe apprezzato.

Ho dedicato del tempo a indagare e sembra che il problema sia che discourse-narrative-bot si blocca durante il recupero dell’avatar dell’utente da includere nel certificato. Qui:

Questo forum utilizza l’SSO e gli avatar sono URL Amazon S3, che sono veloci e non sottoposti a limitazioni di velocità da parte di Amazon. Detto questo, quella funzione sta recuperando un URL avatar del tipo:

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

Potrebbero gli errori di timeout che stanno rallentando la generazione del certificato essere causati dal raggiungimento dei limiti di velocità di Discourse? O perché gli avatar vengono richiesti troppo rapidamente dall’istanza di Discourse stessa, oppure perché si tenta di accedere ad Amazon S3 troppo velocemente quando più utenti stanno completando il tutorial del bot?

Interessante. Inseriamo un’immagine in base64 lì dentro. Mi chiedo perché non abbiamo semplicemente collegato la risorsa esterna nel tag image SVG :thinking:

Ho scavato nella cronologia del plugin fino al punto in cui l’abbiamo aggiunta per la prima volta:

E sembra che abbiamo sempre utilizzato avatar in base64 incorporati.

EDIT: Dopo alcune ricerche, incorporiamo in base64 perché il certificato viene caricato tramite un tag HTML img. Per ottenere avatar più economici dovremmo passare a un tag object, che è bloccato di default nella nostra CSP. Oppure incorporare l’intero SVG nel contenuto del post. Immagino che un iframe sia la nostra migliore opzione.

Ho FIX: Make discobot certificate gen faster/non blocking by xfalcox · Pull Request #11344 · discourse/discourse · GitHub per i commenti di @tgxworld.

Ho ipotizzato che l’SVG che incorpora l’avatar in base64 fosse utilizzato per lo stesso motivo per cui il logo “lo faceva”: in modo che il certificato potesse essere un’istantanea nel tempo — magari salvata dal destinatario, senza dipendenze esterne, così da essere visualizzata esattamente allo stesso modo anche in seguito.

L’approccio con l’iframe impedisce che sia facilmente condiviso e mostrato con orgoglio in un post. Non so quanto sia comune questo su altri forum, ma ho visto alcuni dei nostri utenti farlo semplicemente copiando l’URL dell’immagine.

Se si optasse per il collegamento a qualcosa di esterno, non funzionerebbe qui l’uso di <image>, evitando così la necessità di modificare allowed_iframes?

È esattamente ciò che fa la PR sopra, se la leggi :grimacing:

Tuttavia, se carichi il file SVG con il tag HTML img come facciamo oggi, le immagini esterne contenute nei tag SVG image non verranno caricate. Per far sì che ciò funzioni, è necessario utilizzarli tramite object o iframe.

È chiaro che non conosco abbastanza l’SVG. L’approccio con l’iframe impedisce che il certificato venga citato/copiato, ma sono comunque contento che ci si stia occupando della questione in qualche modo, poiché risolverà il nostro problema e anche il logo mancante sul certificato. :+1:

@mentalstring Ho appena unito il nuovo codice per la generazione dei certificati. Dovrebbe essere molto più veloce ora.

È ottimo vedere che questo venga unito. :+1:

Siamo sulla versione stable e al momento non ho un buon modo per testarlo. Ma se fetch_avatar non è più utilizzato, mi aspetto che gli errori Net::ReadTimeout scompaiano con questa modifica. Contrassegno come risolto e lo riaprirò se, per qualche motivo, dovessi riscontrare lo stesso problema quando aggiorneremo. Grazie!