Sidekiq ha molti errori e lavori in coda

Abbiamo ricevuto un avviso nella console di amministrazione riguardo ai nostri processi accodati Sidekiq: abbiamo quasi 200.000 processi accodati e non siamo sicuri di come risolvere il problema. Stiamo eseguendo la versione 3.2.0.

I processi sono tutti nella coda ultra_low e sembrano essere il processo Jobs::ProcessPost. Sembrano tutti simili a questo:

	[{"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"}

Come possiamo far elaborare questi processi e come possiamo farlo in modo da garantire che non influiscano significativamente sulle prestazioni (o è inevitabile)?

2 Mi Piace

Due giorni fa erano circa 195.000; ora sono fino a 211.000. Avrei davvero bisogno di qualche consiglio su cosa controllare e come risolvere questo problema.

Abbiamo notato 5 processi terminati che si presentano così (indirizzi IP offuscati):

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)

L’indirizzo è di un server che fa parte dell’infrastruttura ma non è utilizzato dai forum (è un server di repository di codice sorgente). Non vedo da nessuna parte nella configurazione dove questo host sia anche solo referenziato, quindi non sono sicuro del perché pensi di dover connettersi a quell’host. Ma mi chiedo se questo sia correlato al numero crescente di processi in coda nella coda ultra_low.

2 Mi Piace

Altre 7.000 attività sono state aggiunte alla coda nelle ultime ~23 ore.

Questo sta anche ritardando alcune modifiche di implementazione: chiusura automatica e aggiunta del plugin delle soluzioni (semplicemente non voglio apportare modifiche che potrebbero essere influenzate da questo, o quando questo potrebbe essere aggravato dalla modifica di un elemento così significativo nella configurazione del sistema).

Le 7.000 attività aggiunte non sono in linea con il numero di nuovi post che abbiamo avuto nell’ultimo giorno, quindi non sono sicuro di cosa stia causando questo problema.

Quali altre informazioni sarebbero utili per risolvere questo problema?

2 Mi Piace

Non posso aiutarti, se non suggerendo che più risposte e più “mi piace” ai post su questo thread potrebbero attirare l’attenzione che sembra meritare!

Modifica: Ho anche menzionato questo problema nel thread sull’ordinamento predefinito per popolarità, che credo stia nascondendo questo thread in modo molto efficace e molto poco utile.

2 Mi Piace

Puoi condividere il backtrace completo? Presumo che provenga dal nostro codice onebox, ma vorrei esserne sicuro.

3 Mi Piace

Presumo che dobbiamo farlo dalla console - dovrò chiedere a qualcuno con accesso di farlo; puoi dirmi da dove recuperarlo in modo che possa passarlo alla persona con accesso?

Grazie!

No, no, il backtrace viene mostrato in una scheda nella pagina /logs quando selezioni l’errore.

1 Mi Piace

Ah, grazie per il suggerimento. Ecco cosa mostra (indirizzo IP offuscato):

Messaggio (10 copie segnalate)

Eccezione di lavoro: Impossibile aprire la connessione TCP a x.x.x.x:443 (Rete irraggiungibile - connect(2) per "x.x.x.x" porta 443)


Backtrace

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

Ho notato che questo è diverso dall’output nella scheda “backtrace”, ma quell’output non sembra un backtrace, mentre quello che è qui come copia (usando il pulsante copia) lo è. Fammi sapere se sono necessarie altre informazioni per questo.

Vedrò anche se riesco a ottenere maggiori informazioni sui 220K+ task in coda in questo modo: non ero a conoscenza dell’endpoint /logs.

Nessuna riga extra nella parte inferiore del backtrace?

Questo è tutto ciò che il pulsante Copia ha catturato: ecco l’output completo dalla scheda backtrace:

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' 

Mi dispiace di non aver catturato l’intero output. Pensavo fosse strano che il pulsante Copia non avesse catturato di più, ma ho fatto una supposizione errata che catturasse ciò che era necessario.

Molto meglio!

Ciò significa che c’è uno o più collegamenti inline con un URL che si risolve nell’indirizzo IP del tuo server. Se quel server non è raggiungibile, registriamo l’errore, ma il processo di elaborazione del markdown dovrebbe procedere senza eseguire la “formattazione del link” che attiverebbe l’onebox inline.

Un’altra cosa è come hai installato Discourse? Questo non sembra un’installazione che ha seguito la nostra guida ufficiale all’installazione.

2 Mi Piace

In realtà non ho eseguito l’installazione: credo che il nostro team dell’infrastruttura l’abbia distribuita utilizzando una pipeline CI/CD, ma non conosco i dettagli.

Sembra che i messaggi non riusciti non siano un problema: il gran numero di attività in coda nella coda ultra_low sembra essere il problema più grande qui. Non trovo nulla nei log (in realtà ha senso per me, perché il job non è ancora stato eseguito).

Se forzi manualmente l’esecuzione di alcune, cosa succede?

Non vedo un’opzione per forzarne l’esecuzione nell’interfaccia utente web: ho un’opzione per “mostrare tutti” gli argomenti o per eliminare le attività singolarmente.

Hm. Non ne abbiamo nessuna in coda nel forum che gestisco, quindi mi scuso per aver cercato di suggerire un pulsante che non c’è.

Riferimento alla pagina dei tentativi, per quello che pensavo fosse nella pagina in coda

Nessun problema, sì, questi vengono visualizzati nella pagina Enqueued (su /sidekiq/queues/ultra_low).

Guardando la pagina delle code stessa, vedo che la latenza della coda ultra_low è di circa un anno. Quindi questo è apparentemente in corso da un po’ e solo di recente abbiamo ricevuto un avviso al riguardo nella dashboard.

1 Mi Piace

Scavando un po’ più a fondo in ciò che vedo nei job Jobs::ProcessPost, sembra che i valori di post_id stiano contando all’indietro: ho estratto gli ID dei post dai primi e dagli ultimi job in coda, e le date corrispondono a un post del 2012 (pre-migrazione a Discourse - ma con un timestamp ‘updated_at’ del 2022, che potrebbe essere stata la nostra data di migrazione - dovrò verificarlo) e il più recente era di gennaio 2023.

Vedo occasionali job per la generazione di miniature di argomenti, ma sono piuttosto rari. Con oltre 8.800 pagine di coda, non posso controllare tutto, ma sembra che sia per lo più materiale di Jobs::ProcessPost che viene aggiunto, e sta tornando indietro nel tempo attraverso quello che sembra essere ogni singola risposta e post iniziale di un argomento (il più vecchio era a metà thread, l’ultimo era un post principale in un argomento).

1 Mi Piace

Ho estratto un backup dal sistema di produzione e l’ho caricato in un ambiente di test configurato localmente. La coda non sembra affatto accumularsi; infatti, non vedo Job::ProcessPost apparire in quella coda mentre la osservo (la configurerò e lascerò che il sistema funzioni da solo registrando lo schermo della coda per vedere se me la sto solo perdendo).

Questo mi porta a due domande:

  1. Cosa causa l’attivazione del job ProcessPost?
  2. Cosa causerebbe la mancata elaborazione della coda ultra_low?

Non sono un esperto di nessuna delle tecnologie utilizzate in Discourse (redis, sidekiq o rails), ma sono molto a mio agio nell’imparare e provare cose nel mio ambiente sandbox per capire cosa devo far esaminare in produzione.

La buona notizia è che questo problema non sembra causare alcun problema ai nostri utenti (ancora). Una terza domanda sarebbe se la semplice eliminazione di quella coda aiuterebbe, o se non permettere l’esecuzione di tali job potrebbe danneggiare il sistema in qualche modo.

ETA: Ho appena visto un batch di job arrivare nel mio ambiente di test e vengono elaborati lì. Quindi sembra solo che la coda non venga elaborata sul server di produzione per qualche motivo.

Sembra che siamo giunti a una risoluzione. L’installazione che stiamo utilizzando proviene dal pacchetto creato per openSUSE (l’istanza di cui abbiamo parlato è l’istanza per i forum di openSUSE), quindi utilizza essenzialmente il processo di installazione “build from source”.

Abbiamo un ambiente di sviluppo e uno di produzione, e la coda ultra_low è stata erroneamente esclusa dalla configurazione sidekiq dell’ambiente di produzione. Questo è stato corretto e sembra che la coda si stia svuotando e la latenza sia scesa da 1 anno a 4 settimane.

Penso che possiamo considerare questo problema risolto. Apprezzo il contributo delle persone che hanno fornito alcuni suggerimenti: mi hanno aiutato a capire qual era il problema.

2 Mi Piace

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