Eccezioni casuali di timeout nell'app Rails su Heroku

Question

Ospito un'app Rails 3.2 su Heroku e ricevo 2-3 timeout nell'applicazione Rails ogni giorno. Questi sono non timeout di richiesta H12, ma piuttosto i timeout che si verificano da qualche parte all'interno dello stack Rails. Pertanto, in realtà generano eccezioni sul sito e appaiono nei miei log Airbrake.

Sembra essere completamente casuale dove si verifica il timeout; a volte è all'interno di una gemma come Formtastic, o all'interno di una vista HAML, o all'interno del codice ActiveRecord. Potete vedere esempi di alcuni dei backtrace qui: https://gist.github.com/dpmccabe/5238273

Questo sito non riceve molto traffico e funziona bene su due dynos (sebbene si scalino automaticamente grazie al componente aggiuntivo Adept Scale). L'intestazione HTTP_X_HEROKU_QUEUE_WAIT_TIME è in genere bassa o uguale a zero, quindi non penso che si tratti di un problema di routing. Ho persino provato a passare da Thin a Unicorn senza alcun effetto (il mio unicorno.rb è mostrato nel precedente elenco).

Il fatto che queste eccezioni di timeout sembrano verificarsi casualmente in tutta l'applicazione non mi dà molto da fare. Ho una nuova reliquia, ma non sono sicuro di come fare il debug di questo. Qualche idea?

Answer 1

In base a Heroku Dev Center, il router interromperà la richiesta se il completamento richiede più di 30 secondi. È possibile utilizzare uno rack-timeout gem per individuare i colli di bottiglia. Basta fare il vostro timeout meno di 30 sec

Rack::Timeout.timeout = 15 # seconds 

Se si dispone di numerose richieste parallele, considera di utilizzare Unicorn

Answer 2

Ho anche stato in esecuzione nello stesso problema. Anche se non l'ho ancora risolto, ho pensato di entrare in sintonia con quello che ho visto finora. Sto usando il gioiello rack-timeout (basato sui tuoi backtrace, sembra che tu sia così) e ho il timeout impostato su 15 secondi. Guardando la nuova reliquia, il tempo medio di risposta del server delle app per ogni richiesta è ben al di sotto dei 200 ms. Eppure, come voi, ricevo 2-3 errori al giorno che assomigliano a questo:

undefined method `result' for #<Timeout::Error: execution expired> 

Gli errori si verificano su una vasta gamma di azioni, con nessuna azione che sembrano essere particolarmente suscettibili di generare uno. L'errore si verifica anche su semplici azioni CRUD DELETE. Sto usando un'applicazione per rails 3.2 sullo stack di Heroku's Cedar. Gestisco due web dynos, ognuno con 3 lavoratori di unicorno. Rimangono costantemente al di sotto del limite di 512mb.

L'unico indizio che ho trovato finora è che vedo spesso qualcosa di simile alla seguente nei pressi miei timeout nei miei ceppi:

[AMBER] LOG: process 21289 acquired ShareLock on transaction 105259 after 32366.132 ms 

vedete qualcosa di simile? Potrebbe essere possibile che un'azione DB che blocca un record stia causando il timeout, non ne sono del tutto sicuro.

Answer 3

Ho riscontrato lo stesso problema sulla mia applicazione ospitata su heroku.

Ho controllato i registri e ho riscontrato che poche richieste richiedevano più di 30 secondi per l'elaborazione, il che ha provocato errori di timeout su heroku. Nel mio caso il problema era la stampa dei log, avevo un server di staging che aveva molti dati di input e output stampati sui log del server che impiegavano più di 30 secondi per la stampa, si supponeva che la richiesta fosse ancora in corso dopo che la risposta è stata ricevuta dall'api remota poiché non ha ancora completato la stampa dei dati nei registri.

Quindi ho rimosso tutte le istruzioni di stampa che avrebbero stampato i dati di input (dati di input xml costruiti dal codice) e di output (dati xml ricevuti dagli api) nei registri.

1. Quindi, vorrei suggerire di controllare i log e vedere se le richieste sono in corso più di 30 secondi per elaborare
2. Controllare se si sta stampando i dati (per il debug scopo) che richiede tempo per stampare sui registri.

Ancora una volta, questa potrebbe non essere la risposta alla tua domanda, ma questo è il modo in cui ho risolto il mio. Spero che aiuti!