Come nel nella maggior parte dei post, è sorto un problema con un servizio distribuito, chiamiamolo Elvin. Questa volta non ho scoperto il problema da solo, me lo hanno comunicato i ragazzi del lato client.

Una volta mi sono svegliato a causa di una lettera di lamentela per le lunghe attese con Elvin, che avevamo pianificato di avviare a breve. In particolare, il cliente ha affrontato un ritardo del 99° percentile di circa 50 ms, ben al di sopra del nostro budget di latenza. Era sorprendente, dato che avevo testato accuratamente il servizio, soprattutto per quanto riguardava la latenza, argomento di frequenti lamentele.

Prima di consegnare Elvin per i test, ho condotto molti esperimenti con 40.000 richieste al secondo (QPS), tutti hanno mostrato una latenza di meno di 10 ms. Ero pronto a dichiarare che non ero d'accordo con i loro risultati. Ma guardando di nuovo la lettera, ho notato qualcosa di nuovo: non ho effettivamente testato le condizioni che hanno menzionato, il loro QPS era molto inferiore al mio. Ho testato a 40k QPS, mentre loro solo a 1k. Ho eseguito un altro esperimento, stavolta con un QPS più basso, solo per accontentarli.

Dato che sto scrivendo di questo nel blog - probabilmente lo avete già capito: i loro dati si sono rivelati corretti. Ho controllato il mio cliente virtuale ripetutamente, sempre con lo stesso risultato: un numero basso di richieste non solo aumenta la latenza, ma accresce anche il numero di richieste con latenza superiore a 10 ms. In altre parole, mentre a 40k QPS circa 50 richieste al secondo superavano i 50 ms, a 1k QPS ogni secondo c'erano 100 richieste oltre i 50 ms. Paradossale!

Stringiamo il cerchio dei sospetti

Affrontando un problema di latenza in un sistema distribuito con molti componenti, il primo passo è stilare un breve elenco di sospetti. Scaviamo un po' più a fondo nell'architettura di Elvin:

Un buon punto di partenza è la lista delle transizioni di input/output eseguite (chiamate di rete/cerca su disco, ecc.). Cerchiamo di capire dove sia la latenza. Oltre all'ovvia I/O con il cliente, Elvin fa un passaggio aggiuntivo: accede a un sistema di archiviazione dati. Tuttavia, questo sistema di archiviazione opera nello stesso cluster di Elvin, quindi lì la latenza dovrebbe essere inferiore a quella con il cliente. Quindi, l'elenco dei sospetti:

1. Chiamata di rete dal cliente a Elvin.
2. Chiamata di rete da Elvin al sistema di archiviazione dati.
3. Ricerca su disco nel sistema di archiviazione dati.
4. Chiamata di rete dal data store a Elvin.
5. Chiamata di rete da Elvin al cliente.

Proviamo a escludere alcuni punti.

Il data store non c'entra nulla

Per prima cosa ho trasformato Elvin in un server ping-ping, che non elabora richieste. Ricevuta una richiesta, restituisce una risposta vuota. Se la latenza diminuisce, è un errore nell'implementazione di Elvin o del data store - nulla di strano. Nel primo esperimento otteniamo questo grafico:

Come vediamo, utilizzando il server ping-ping non ci sono miglioramenti. Ciò significa che il data store non aumenta la latenza, e la lista dei sospettati si riduce della metà:

1. Chiamata di rete dal cliente a Elvin.
2. Chiamata di rete da Elvin al cliente.

Fantastico! La lista si accorcia rapidamente. Pensavo di aver quasi scoperto la causa.

gRPC

È ora di presentarvi un nuovo giocatore: gRPC. È una libreria open source di Google per la comunicazione interprocesso RPC. Sebbene gRPC sia ben ottimizzata e ampiamente utilizzata, io l'ho usata per la prima volta in un sistema di tale grandezza, e mi aspettavo che la mia implementazione fosse subottimale - per usare un eufemismo.

La presenza di gRPC nel stack ha sollevato una nuova domanda: può essere che sia la mia implementazione o che gRPC causi il problema della latenza? Aggiungiamo un nuovo sospettato alla lista:

1. Il cliente chiama la libreria gRPC
2. La libreria gRPC sul cliente esegue una chiamata di rete della libreria gRPC sul server
3. La libreria gRPC si rivolge a Elvin (l'operazione non è presente nel caso del server ping-pong)

Per farvi capire com'è il codice, la mia implementazione del cliente/Elvin non differisce molto dagli esempi client-server async.

Nota: la lista sopra riportata è leggermente semplificata, poiché gRPC consente l'uso di un proprio (modello?) di threading, in cui si intrecciano stack di esecuzione gRPC e implementazione dell'utente. Per semplicità, seguiremo questo modello.

Il profiling risolverà tutto

Escludendo i data store, ho pensato di essere quasi arrivato alla conclusione: «Adesso è facile! Applichiamo il profilo e vediamo dove si verifica la latenza». Io sono un grande sostenitore del profiling preciso, perché la CPU è molto veloce e raramente è il collo di bottiglia. La maggior parte delle latenze si verifica quando il processore deve fermarsi per fare altro. Il profiling preciso della CPU serve proprio a questo: registra esattamente tutti i cambi di contesto e fa capire dove si verificano le latenze.

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

Ulteriore debug

Ero in preda alla disperazione. Non sapevo quali altri strumenti poter usare, e il mio piano successivo consisteva essenzialmente nel ripetere esperimenti con varie variazioni, piuttosto che una diagnosi chiara del problema.

E se

Fin dall'inizio ero preoccupato per un tempo di latenza di 50 ms. È un tempo molto lungo. Ho deciso di ritagliare pezzi di codice finché non sarei riuscito a capire esattamente quale parte stava causando questo errore. Poi seguì un esperimento che ha funzionato.

Come al solito, a posteriori tutto sembra ovvio. Ho messo il cliente su una macchina con Alvin e ho inviato una richiesta a localhost. E la latenza aumentata è scomparsa!

C'era qualcosa che non andava con la rete.

Acquisire competenze da ingegnere di rete

Devo ammettere: la mia conoscenza delle tecnologie di rete è terribile, soprattutto considerando che ci lavoro ogni giorno. Ma la rete era il principale sospettato, e dovevo imparare come debugarla.

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

Per prima cosa, ho eseguito PsPing sulla porta TCP di Alvin. Ho utilizzato i parametri predefiniti — nulla di speciale. Su oltre mille ping, nessuno ha superato 10 ms, tranne il primo per il riscaldamento. Questo contraddice l'aumento di latenza osservato di 50 ms nel 99° percentile: per ogni 100 richieste avremmo dovuto vedere circa una richiesta con latenza di 50 ms.

Poi ho provato tracert: forse il problema era in uno dei nodi lungo il percorso tra Alvin e il cliente. Ma anche il tracer è tornato a mani vuote.

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

Ora, su quale OS ci troviamo

gRPC è ampiamente usato in Linux, ma per Windows è un'eccezione. Ho deciso di fare un esperimento, che ha avuto successo: ho creato una macchina virtuale Linux, ho compilato Alvin per Linux e l'ho distribuita.

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

L'algoritmo di Nagle

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

Quasi pronto: ho iniziato a rimuovere i flag aggiunti uno alla volta, finché non è stata ripristinata la regressione, così ho potuto identificare esattamente la causa. Era il tristemente famoso TCP_NODELAY, switch dell'algoritmo di Nagle.

L'algoritmo di Nagle cerca di ridurre il numero di pacchetti inviati sulla rete, ritardando la trasmissione dei messaggi finché la dimensione del pacchetto non supera un certo numero di byte. Anche se questo può essere vantaggioso per l'utente medio, è distruttivo per i server in tempo reale, poiché il sistema operativo ritarderà alcuni messaggi, causando ritardi a basso QPS. Su gRPC era impostato questo flag nell'implementazione Linux per le socket TCP, ma non per Windows. Ho corretto.

Conclusione

Un grande ritardo a basso QPS è stato causato dall'ottimizzazione del sistema operativo. Guardando indietro, il profiling non ha rilevato il ritardo, perché avveniva in modalità kernel, non in modalità utente. Non so se si possa osservare l'algoritmo di Nagle attraverso le acquisizioni ETW, ma sarebbe interessante.

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

La prossima volta che vedrete un aumento della latenza con una diminuzione del numero di richieste al secondo, l'algoritmo di Nagle dovrebbe essere nella vostra lista dei sospetti!

Fonte: habr.com