Diagnosticare e risolvere i problemi relativi alle richieste lente in .NET SDK di Azure Cosmos DB

In Azure Cosmos DB, si potrebbero notare richieste lente. I ritardi possono verificarsi per diversi motivi, ad esempio la limitazione delle richieste o la modalità di progettazione dell'applicazione. Questo articolo illustra le diverse cause radice di questo problema.

La frequenza delle richieste è troppo elevata

La restrizione delle richieste è il motivo più comune delle richieste rallentate. Azure Cosmos DB limita le richieste se queste superano le unità richiesta allocate per il database o il contenitore. L'SDK ha una logica integrata per ritentare queste richieste. L'articolo sulla risoluzione dei problemi legati alla frequenza troppo elevata delle richieste spiega come verificare se le richieste vengono limitate. L'articolo illustra anche come dimensionare l'account per evitare questi problemi in futuro.

Progettazione di applicazioni

Quando si progetta l'applicazione, seguire le procedure consigliate per l'SDK .NET per ottenere prestazioni ottimali. Se l'applicazione non segue le procedure consigliate per l'SDK, è possibile che si verifichino richieste lente o non riuscite.

Quando si sviluppa l'applicazione, tenere presente quanto segue:

Operazioni sui metadati

Se è necessario verificare la presenza di un database o di un contenitore, non farlo chiamando Create...IfNotExistsAsync o Read...Async prima di eseguire un'operazione sugli elementi. La convalida deve essere eseguita solo all'avvio dell'applicazione quando è necessario, se si prevede che verrà eliminata. Queste operazioni sui metadati generano una latenza aggiuntiva, non hanno contratti di servizio e presentano limitazioni separate. Non scalano come le operazioni sui dati.

Richieste lente in modalità bulk

La modalità bulk è una modalità ottimizzata per la velocità effettiva, destinata alle operazioni su volumi di dati elevati, non una modalità ottimizzata per la latenza. È destinata a saturare la velocità effettiva disponibile. Se si verificano richieste lente quando si usa la modalità bulk, assicurarsi che:

  • L'applicazione viene compilata in configurazione di rilascio.
  • Non si misura la latenza durante il debug dell'applicazione (nessun debugger collegato).
  • Il volume delle operazioni è elevato, non utilizzare operazioni di massa per meno di 1000 operazioni. Il throughput fornito determina quante operazioni al secondo puoi elaborare, il tuo obiettivo con il bulk è di utilizzarne il più possibile.
  • Monitorare il contenitore per gli scenari di limitazione. Se il contenitore subisce un forte throttling, significa che il volume di dati è maggiore del throughput fornito; è necessario scalare il contenitore o ridurre il volume di dati, ad esempio creando batch di dati più piccoli alla volta.
  • Si sta usando correttamente il modello async/await per elaborare tutte le attività simultanee e non bloccare alcuna operazione asincrona.

Acquisire la diagnostica

Tutte le risposte nell'SDK, inclusa CosmosException, hanno una proprietà Diagnostics. Questa proprietà registra tutte le informazioni correlate alla singola richiesta, inclusi i tentativi effettuati o eventuali errori temporanei.

La diagnostica viene restituita come stringa. La stringa cambia con ogni versione, perché viene migliorata per la risoluzione dei problemi relativi a scenari diversi. Con ogni versione dell'SDK, la stringa include modifiche alla formattazione che causano un'interruzione. Non analizzare la stringa per evitare modifiche che causano interruzioni. L'esempio di codice seguente illustra come leggere i log di diagnostica usando .NET SDK:

try
{
    ItemResponse<Book> response = await this.Container.CreateItemAsync<Book>(item: testItem);
    if (response.Diagnostics.GetClientElapsedTime() > ConfigurableSlowRequestTimeSpan)
    {
        // Log the response.Diagnostics.ToString() and add any additional info necessary to correlate to other logs 
    }
}
catch (CosmosException cosmosException)
{
    // Log the full exception including the stack trace with: cosmosException.ToString()
    
    // The Diagnostics can be logged separately if required with: cosmosException.Diagnostics.ToString()
}

// When using Stream APIs
ResponseMessage response = await this.Container.CreateItemStreamAsync(partitionKey, stream);
if (response.Diagnostics.GetClientElapsedTime() > ConfigurableSlowRequestTimeSpan || !response.IsSuccessStatusCode)
{
    // Log the diagnostics and add any additional info necessary to correlate to other logs with: response.Diagnostics.ToString()
}

Diagnostica nella versione 3.19 e successive

La struttura JSON presenta modifiche non retrocompatibili con ogni versione dell'SDK. Ciò ne rende l'analisi non sicura. Il codice JSON rappresenta una struttura ad albero della richiesta che passa attraverso l'SDK. Le sezioni seguenti illustrano alcuni aspetti chiave da esaminare.

Cronologia della CPU

L'utilizzo elevato della CPU è la causa più comune delle richieste lente. Per una latenza ottimale, l'utilizzo della CPU deve essere approssimativamente del 40%. Usare 10 secondi come intervallo per monitorare l'utilizzo massimo (non medio) della CPU. I picchi di CPU sono più comuni con query tra partizioni in cui le richieste potrebbero effettuare più connessioni per una singola query.

I timeout includono la diagnostica, che contiene ad esempio, quanto segue:

"systemHistory": [
{
"dateUtc": "2021-11-17T23:38:28.3115496Z",
"cpu": 16.731,
"memory": 9024120.000,
"threadInfo": {
"isThreadStarving": "False",
....
}

},
{
"dateUtc": "2021-11-17T23:38:38.3115496Z",
"cpu": 16.731,
"memory": 9024120.000,
"threadInfo": {
"isThreadStarving": "False",
....
}

},
...
]
  • Se i valori cpu sono superiori al 70%, è probabile che il timeout sia causato dall'esaurimento della CPU. In questo caso la soluzione consiste nel ricercare l'origine dell'utilizzo elevato della CPU e ridurre l'uso o nel ridimensionare il computer a dimensioni di risorse più elevate.
  • Se i nodi threadInfo/isThreadStarving hanno valori True, la causa è la scadenza dei thread. In questo caso, la soluzione consiste nel ricercare l'origine o le origini della saturazione dei thread (potenzialmente bloccati) o nell'aumentare le risorse del/dei computer.
  • Se l'intervallo di tempo dateUtc tra le misurazioni non è di circa 10 secondi, questo indica una contesa nel pool di thread. La CPU viene misurata come attività indipendente, inserita nel pool di thread ogni 10 secondi. Se l'intervallo di tempo tra le misurazioni è più lungo, significa che le attività asincrone non possono essere elaborate in modo tempestivo. Lo scenario più comune è quando il codice dell'applicazione blocca le chiamate su codice asincrono.

Soluzione

L'applicazione client che usa l'SDK deve essere ridimensionata o ridotta.

HttpResponseStats

HttpResponseStats sono richieste che arrivano al gateway. Anche in modalità diretta, l'SDK ottiene tutte le informazioni sui metadati dal gateway.

Se la richiesta è lenta, verificare prima che nessuno dei suggerimenti precedenti restituisca i risultati desiderati. Se è ancora lenta, modelli diversi puntano a problemi diversi. La tabella seguente fornisce informazioni più dettagliate.

Numero di richieste Scenario Description
Da singolo a tutti Timeout richiesta o HttpRequestExceptions Punta all'esaurimento delle porte SNAT o alla mancanza di risorse nel computer necessarie per elaborare la richiesta in tempo.
Singola o piccola percentuale (il contratto di servizio non viene violato) All Una singola o piccola percentuale di richieste lente può essere causata da diversi problemi temporanei e deve essere prevista.
All All Indica un problema con l'infrastruttura o con la rete.
Violazione dello SLA Nessuna modifica all'applicazione e il contratto di servizio è stato eliminato. Indica un problema con il servizio Azure Cosmos DB.
"HttpResponseStats": [
    {
        "StartTimeUTC": "2021-06-15T13:53:09.7961124Z",
        "EndTimeUTC": "2021-06-15T13:53:09.7961127Z",
        "RequestUri": "https://127.0.0.1:8081/dbs/347a8e44-a550-493e-88ee-29a19c070ecc/colls/4f72e752-fa91-455a-82c1-bf253a5a3c4e",
        "ResourceType": "Collection",
        "HttpMethod": "GET",
        "ActivityId": "e16e98ec-f2e3-430c-b9e9-7d99e58a4f72",
        "StatusCode": "OK"
    }
]

StoreResult

StoreResult rappresenta una singola richiesta ad Azure Cosmos DB, usando la modalità diretta con il protocollo TCP.

Se è ancora lenta, modelli diversi puntano a problemi diversi. La tabella seguente fornisce informazioni più dettagliate.

Numero di richieste Scenario Description
Da singolo a tutti StoreResult contiene TransportException Punta all'esaurimento delle porte SNAT o alla mancanza di risorse nel computer necessarie per elaborare la richiesta in tempo.
Singola o piccola percentuale (il contratto di servizio non viene violato) All Una singola o piccola percentuale di richieste lente può essere causata da diversi problemi temporanei e deve essere prevista.
All All Problema con l'infrastruttura o con la rete.
Violazione dello SLA Le richieste contengono più codici di errore, ad esempio 410 Indica un problema con il servizio Azure Cosmos DB o il computer client.
Violazione dello SLA StorePhysicalAddress sono uguali, senza codice di stato di errore. Probabilmente si è verificato un problema con Azure Cosmos DB.
Violazione dello SLA StorePhysicalAddress hanno lo stesso ID di partizione, ma ID replica diversi, senza codice di stato di errore. Probabilmente si è verificato un problema con Azure Cosmos DB.
Violazione dello SLA StorePhysicalAddress è casuale, senza codice di stato di errore. Indica un problema con il computer.

Per più risultati dell'archivio per una singola richiesta, tenere presente quanto segue:

  • La coerenza forte e la coerenza di staleness limitata hanno sempre almeno due risultati di memorizzazione.
  • Controllare il codice di stato di ogni StoreResult. L'SDK esegue automaticamente nuovi tentativi su più errori temporanei diversi. L'SDK viene costantemente migliorato per affrontare altri scenari.

CronologiaRichiesta

Mostra l'ora delle diverse fasi di invio e ricezione di una richiesta nel livello di trasporto.

  • ChannelAcquisitionStarted: ora di ottenere o creare una nuova connessione. Le connessioni possono essere create per diversi motivi, ad esempio: la connessione precedente è stata chiusa a causa dell'inattività usando CosmosClientOptions.IdleTcpConnectionTimeout, il volume di richieste simultanee supera CosmosClientOptions.MaxRequestsPerTcpConnection, la connessione è stata chiusa a causa di un errore di rete, oppure l'applicazione non segue il criterio singleton e vengono create costantemente nuove istanze. Una volta stabilita una connessione, questa viene riutilizzata per le richieste successive, pertanto questa operazione non dovrebbe influire sulla latenza P99, a meno che non si verifichino i problemi menzionati in precedenza.
  • Pipelined: tempo impiegato per scrivere la richiesta nel socket TCP. La richiesta può essere scritta solo su un socket TCP uno alla volta, un valore di grandi dimensioni indica un collo di bottiglia sul socket TCP, comunemente associato ai thread bloccati dal codice dell'applicazione o dalle dimensioni delle richieste di grandi dimensioni.
  • Transit time: tempo trascorso in rete dopo la scrittura della richiesta sul socket TCP. Confrontare questo numero con BELatencyInMs. Se BELatencyInMs è basso, il tempo è stato dedicato alla rete e non al servizio Azure Cosmos DB. Se la richiesta non è riuscita con un timeout, indica per quanto tempo il client ha aspettato senza risposta e l'origine è latenza di rete.
  • Received: tempo tra la ricezione e l'elaborazione della risposta da parte dell'SDK. Un valore elevato è solitamente causato da un esaurimento dei thread o da thread bloccati.

ServiceEndpointStatistics

Informazioni su un server back-end specifico. L'SDK può aprire più connessioni a un singolo server back-end a seconda del numero di richieste in sospeso e di MaxConcurrentRequestsPerConnection.

  • inflightRequests Numero di richieste in sospeso a un server back-end (ad esempio da partizioni diverse). Un numero elevato può causare un maggior traffico e latenze più elevate.
  • openConnections è il numero totale di connessioni aperte a un singolo server back-end. Questo può essere utile per mostrare l'esaurimento delle porte SNAT, se il valore è molto elevato.

ConnectionStatistics

Informazioni sulla connessione specifica (nuova o precedente) a cui viene assegnata la richiesta.

  • waitforConnectionInit: la richiesta corrente era in attesa del completamento della nuova inizializzazione della connessione. Ciò comporterà latenze più elevate.
  • callsPendingReceive: numero di chiamate in sospeso ricevute prima dell'invio di questa chiamata. Un numero elevato può mostrarci che ci sono state molte chiamate prima di questa chiamata e può portare a latenze più elevate. Se questo numero è elevato indica un problema di blocco della linea di testa probabilmente causato da un'altra richiesta, ad esempio un'operazione di query o di feed che richiede molto tempo per essere elaborata. Provare ad abbassare CosmosClientOptions.MaxRequestsPerTcpConnection per aumentare il numero di canali.
  • LastSentTime: ora dell'ultima richiesta inviata al server. Insieme a LastReceivedTime, questo valore può essere usato per visualizzare i problemi di connettività o endpoint. Ad esempio, se sono presenti molti timeout di ricezione, l'ora di invio sarà un valore molto più elevato rispetto all'ora di ricezione.
  • lastReceive: ora dell'ultima richiesta ricevuta dal server
  • lastSendAttempt: ora dell'ultimo tentativo di invio

Dimensioni della richiesta e della risposta

  • requestSizeInBytes: dimensioni totali della richiesta inviata ad Azure Cosmos DB
  • responseMetadataSizeInBytes: dimensioni delle intestazioni restituite da Azure Cosmos DB
  • responseBodySizeInBytes: dimensioni del contenuto restituito da Azure Cosmos DB
"StoreResult": {
    "ActivityId": "bab6ade1-b8de-407f-b89d-fa2138a91284",
    "StatusCode": "Ok",
    "SubStatusCode": "Unknown",
    "LSN": 453362,
    "PartitionKeyRangeId": "1",
    "GlobalCommittedLSN": 0,
    "ItemLSN": 453358,
    "UsingLocalLSN": true,
    "QuorumAckedLSN": -1,
    "SessionToken": "-1#453362",
    "CurrentWriteQuorum": -1,
    "CurrentReplicaSetSize": -1,
    "NumberOfReadRegions": 0,
    "IsValid": true,
    "StorePhysicalAddress": "rntbd://127.0.0.1:10253/apps/DocDbApp/services/DocDbServer92/partitions/a4cb49a8-38c8-11e6-8106-8cdcd42c33be/replicas/1s/",
    "RequestCharge": 1,
    "RetryAfterInMs": null,
    "BELatencyInMs": "0.304",
    "transportRequestTimeline": {
        "requestTimeline": [
            {
                "event": "Created",
                "startTimeUtc": "2022-05-25T12:03:36.3081190Z",
                "durationInMs": 0.0024
            },
            {
                "event": "ChannelAcquisitionStarted",
                "startTimeUtc": "2022-05-25T12:03:36.3081214Z",
                "durationInMs": 0.0132
            },
            {
                "event": "Pipelined",
                "startTimeUtc": "2022-05-25T12:03:36.3081346Z",
                "durationInMs": 0.0865
            },
            {
                "event": "Transit Time",
                "startTimeUtc": "2022-05-25T12:03:36.3082211Z",
                "durationInMs": 1.3324
            },
            {
                "event": "Received",
                "startTimeUtc": "2022-05-25T12:03:36.3095535Z",
                "durationInMs": 12.6128
            },
            {
                "event": "Completed",
                "startTimeUtc": "2022-05-25T12:03:36.8621663Z",
                "durationInMs": 0
            }
        ],
        "serviceEndpointStats": {
            "inflightRequests": 1,
            "openConnections": 1
        },
        "connectionStats": {
            "waitforConnectionInit": "False",
            "callsPendingReceive": 0,
            "lastSendAttempt": "2022-05-25T12:03:34.0222760Z",
            "lastSend": "2022-05-25T12:03:34.0223280Z",
            "lastReceive": "2022-05-25T12:03:34.0257728Z"
        },
        "requestSizeInBytes": 447,
        "responseMetadataSizeInBytes": 438,
        "responseBodySizeInBytes": 604
    },
    "TransportException": null
}

Il tasso di errore viola il contratto di servizio di Azure Cosmos DB

Contattare il supporto tecnico di Azure.

Passaggi successivi