Come in gran parte dei post, è emerso un problema con il servizio distribuito, chiameremo questo servizio Elvin. Questa volta non ho scoperto il problema da solo, ma me lo hanno segnalato i ragazzi della parte cliente.

Un giorno mi sono svegliato a causa di un'email di lamentele per l'elevata latenza di Elvin, che avevamo in programma di lanciare a breve. In particolare, il cliente ha riscontrato una latenza del 99° percentile intorno ai 50 ms, ben oltre il nostro limite di latenza. È stato sorprendente, perché avevo testato a fondo il servizio, in particolare per la latenza, che è oggetto di frequenti lamentele.

Prima di consegnare Elvin per il collaudo, ho condotto molti esperimenti con 40.000 richieste al secondo (QPS), tutti hanno mostrato una latenza inferiore ai 10 ms. Ero pronto a dichiarare che non ero d'accordo con i loro risultati. Ma guardando di nuovo l'email, ho notato qualcosa di nuovo: non avevo testato le condizioni che avevano menzionato, il loro QPS era molto più basso del mio. Ho testato a 40k QPS, mentre loro solo a 1k. Ho avviato un altro esperimento, questa volta con un QPS più basso, solo per accontentarli.

Poiché ne parlo nel blog, è probabile che tu l'abbia già capito: i loro numeri si sono rivelati corretti. Ho controllato il mio cliente virtuale più e più volte, ottenendo sempre lo stesso risultato: un basso numero di richieste non solo aumenta la latenza, ma anche il numero di richieste con latenza superiore a 10 ms. In altre parole, se a 40k QPS circa 50 richieste al secondo superavano i 50 ms, a 1k QPS c'erano 100 richieste superiori a 50 ms ogni secondo. Paradossale!

Raffiniamo la ricerca

Di fronte a un problema di latenza in un sistema distribuito con molti componenti, il primo passo è stilare un breve elenco di sospetti. Approfondiamo un po' l'architettura di Alvin:

Un buon punto di partenza è l'elenco delle transazioni di input/output eseguite (chiamate di rete / ricerca su disco, ecc.). Cerchiamo di capire dove sia la latenza. Oltre all'evidente input/output con il cliente, Alvin compie un passo aggiuntivo: si rivolge allo storage dei dati. Tuttavia, questo storage opera in un cluster con Alvin, quindi la latenza lì dovrebbe essere inferiore rispetto a quella con il cliente. Quindi, l'elenco dei sospetti:

1. Chiamata di rete dal cliente ad Alvin.
2. Chiamata di rete da Alvin al data center.
3. Ricerca sul disco nel data center.
4. Chiamata di rete dal data center ad Alvin.
5. Chiamata di rete da Alvin al cliente.

Proviamo a escludere alcuni punti.

Il data center non centra niente.

Per prima cosa ho trasformato Alvin in un server ping-ping che non gestisce le richieste. Una volta ricevuta una richiesta, restituisce una risposta vuota. Se il ritardo diminuisce, allora c'è un errore nella nostra implementazione di Alvin o nel data center — nulla di anomalo. Nel primo esperimento otteniamo questo grafico:

Come si può vedere, non ci sono miglioramenti nell'uso del server ping-ping. Ciò significa che il data center non aumenta il ritardo, e la lista dei sospetti si riduce della metà:

1. Chiamata di rete dal cliente ad Alvin.
2. Chiamata di rete da Alvin al cliente.

Ottimo! La lista si sta riducendo rapidamente. Pensavo di aver quasi capito la causa.

gRPC

È il momento di presentarvi un nuovo attore: gRPC. Si tratta di una libreria open source di Google per la comunicazione interprocesso. richiesta RPC. Anche se gRPC ben ottimizzato e ampiamente utilizzato, è la prima volta che lo utilizzo in un sistema di tale scala, e mi aspettavo che la mia implementazione non fosse ottimale — per dirla in modo gentile.

Disponibilità gRPC nel stack ha sollevato una nuova domanda: forse è la mia implementazione o è essa stessa gRPC che causa il problema di latenza? Aggiungiamo alla lista un nuovo sospettato:

1. Il client chiama la libreria gRPC
2. Libreria gRPC sul client effettua una chiamata di rete alla libreria gRPC sul server
3. Libreria gRPC si rivolge a Elvin (non ci sono operazioni nel caso del server ping-pong)

Per farvi capire come appare il codice, la mia implementazione client/Elvin non è molto diversa da esempi client-server di async.

Nota: l'elenco sopra riportato è leggermente semplificato, poiché gRPC consente l'uso di un proprio (templato?) modello di flusso, in cui si intrecciano lo stack di esecuzione gRPC e l'implementazione dell'utente. Per semplicità, ci atteniamo a questo modello.

Il profiling sistemerà tutto

Escludendo i repository di dati, pensavo di essere quasi alla fine: "Ora è facile! Applichiamo il profilo e scopriamo dove si verifica la latenza". Sono un grande sostenitore del profiling preciso, perché la CPU è molto veloce e di solito non è un collo di bottiglia. La maggior parte dei ritardi si verifica quando il processore deve interrompere l'elaborazione per fare qualcos'altro. Il profilo CPU accurato è stato creato proprio per questo: registra esattamente tutto i cambi di contesto e permette di capire dove si verificano i ritardi.

Ho preso quattro profili: sotto un alto QPS (bassa latenza) e con un server ping-pong a basso QPS (alta latenza), sia dal lato client che dal lato server. E giusto per sicurezza, ho anche preso un campione del profilo della CPU. Quando confronto i profili, di solito cerco uno stack di chiamate anomalo. Ad esempio, sul lato negativo con alta latenza ci sono molti più cambi di contesto (10 volte o più). Ma nel mio caso, il numero di cambi di contesto era praticamente identico. Con mia grande sorpresa, non c'era nulla di significativo.

Ulteriore debug

Ero disperato. Non sapevo quali altri strumenti poter utilizzare, e il mio prossimo piano era essenzialmente ripetere esperimenti con diverse varianti, piuttosto che diagnosticare chiaramente il problema.

Cosa succede se

Fin dall'inizio, mi preoccupava il tempo di latenza specifico di 50 ms. È un tempo molto elevato. Ho deciso di rimuovere parti del codice fino a quando non sono riuscito a capire esattamente quale parte stesse causando l'errore. Poi è seguito un esperimento che ha funzionato.

Come al solito, col senno di poi sembra che fosse tutto ovvio. Ho messo il cliente su una macchina con Alvin e ho inviato una richiesta a localhost. E l'aumento della latenza è scomparso!

C'era qualcosa che non andava nella rete.

Acquisendo le competenze di un ingegnere di rete

Devo ammettere: le mie conoscenze delle tecnologie di rete sono orribili, soprattutto considerando che ci lavoro ogni giorno. Ma la rete era il principale sospettato e dovevo imparare come debuggarla.

Fortunatamente, Internet premia coloro che vogliono imparare. La combinazione di ping e tracert sembrava un buon inizio per risolvere i problemi di trasporto di rete.

Per prima cosa, ho avviato PsPing sulla porta TCP di Alvin. Ho utilizzato le impostazioni predefinite — nulla di particolare. Su oltre mille ping, nessuno ha superato i 10 ms, tranne il primo per il riscaldamento. Questo contrasta con l'aumento osservato della latenza di 50 ms nel 99° percentile: lì, su ogni 100 richieste, avremmo dovuto vedere circa una richiesta con latenza di 50 ms.

Poi ho provato tracert: forse il problema si trova su uno dei nodi lungo il percorso tra Alvin e il client. Ma anche il tracer è tornato a mani vuote.

Quindi, la causa della latenza non era il mio codice, né l'implementazione di gRPC né la rete. Avevo già cominciato a preoccuparmi di non capirlo mai.

Ora, su quale sistema operativo ci troviamo

gRPC è ampiamente utilizzato in Linux, ma per Windows è un'eccezione. Ho deciso di condurre un esperimento che ha funzionato: ho creato una macchina virtuale Linux, ho compilato Alvin per Linux e l'ho distribuito.

Ecco cosa ho scoperto: nel server ping-pong Linux non c'erano ritardi come nel nodo Windows equivalente, anche se la sorgente dei dati non era diversa. Si rivela che il problema è nell'implementazione di gRPC per Windows.

L'algoritmo di Nagle

Tutto questo tempo ho pensato che mi mancasse il flag gRPC. Ora ho capito che in realtà è nella gRPC manca un flag di Windows. Ho trovato una libreria interna RPC di cui ero sicuro che funzionasse bene per tutti i flag installati Winsock. Poi ho aggiunto tutti questi flag in gRPC e ho distribuito Alvin su Windows, con il server ping-pong corretto sotto Windows!

Quasi completo: ho iniziato a rimuovere i flag aggiunti uno alla volta, finché non è riemersa la regressione, così ho potuto identificare con precisione la sua causa. Era il TCP_NODELAY, commutatore dell'algoritmo di Nagle.

L'algoritmo di Nagle cerca di ridurre il numero di pacchetti inviati sulla rete ritardando la trasmissione dei messaggi fino a quando la dimensione del pacchetto non supera un certo numero di byte. Sebbene questo possa essere piacevole per l'utente medio, è devastante per i server in tempo reale, poiché il sistema operativo ritarderà alcuni messaggi, causando ritardi a bassa QPS. Ho gRPC impostato questo flag nell'implementazione Linux per i socket TCP, ma non per Windows. L'ho corretto.

Conclusione

Un grande ritardo a bassa QPS era causato dall'ottimizzazione del sistema operativo. Guardando indietro, il profiling non ha rilevato il ritardo, perché era fatto in modalità kernel, e non in modalità utente. Non so se sia possibile osservare l'algoritmo di Nagle attraverso le catture ETW, ma sarebbe interessante.

Per quanto riguarda l'esperimento localhost, probabilmente non ha interessato il codice di rete effettivo, e l'algoritmo di Nagle non è stato attivato, quindi i problemi di latenza sono svaniti quando il client ha contattato Alvin tramite localhost.

La prossima volta che noterai un aumento della latenza con la diminuzione delle richieste al secondo, l'algoritmo di Nagle dovrebbe essere nella tua lista dei sospetti!

Fonte: habr.com