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

  • Articolo

SI APPLICA A: NoSQL

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 limitazione delle richieste è il motivo più comune delle richieste lente. Azure Cosmos DB limita le richieste se queste superano le unità richiesta allocate per il database o il contenitore. L'SDK ha una logica predefinita per la quale si effettuano altri tentativi per 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 vengono dimensionate 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 versione.
  • Non si misura la latenza durante il debug dell'applicazione (nessun debugger collegato).
  • Il volume delle operazioni è elevato, non usare operazioni bulk per meno di 1000 operazioni. La velocità effettiva di cui è stato effettuato il provisioning determina il numero di operazioni al secondo che è possibile elaborare, l'obiettivo delle operazioni bulk consiste nell'usare il maggior numero possibile di operazioni.
  • Monitorare il contenitore per gli scenari di limitazione. Se il contenitore viene notevolmente limitato, significa che il volume di dati è maggiore della velocità effettiva di cui è stato effettuato il provisioning, è necessario aumentare le prestazioni del 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 l'SDK .NET:

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 che causano un'interruzione 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 quanto segue, ad esempio:

"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 scadenza del thread (thread potenzialmente bloccati) o nel dimensionare il computer o i computer a dimensioni di risorse più elevate.
  • Se l'intervallo di tempo dateUtc tra le misurazioni non è di circa 10 secondi, indica anche la contesa nel pool di thread. La CPU viene misurata come attività indipendente, accodata 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 Descrizione
Da singola a tutte 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) Tutte le date Una singola o piccola percentuale di richieste lente può essere causata da diversi problemi temporanei e deve essere prevista.
Tutte le date Tutte le date Indica un problema con l'infrastruttura o con la rete.
Contratto di servizio violato 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 Descrizione
Da singola a tutte 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) Tutte le date Una singola o piccola percentuale di richieste lente può essere causata da diversi problemi temporanei e deve essere prevista.
Tutte le date Tutte le date Problema con l'infrastruttura o con la rete.
Contratto di servizio violato Le richieste contengono più codici di errore, ad esempio 410 Indica un problema con il servizio Azure Cosmos DB o il computer client.
Contratto di servizio violato StorePhysicalAddress sono uguali, senza codice di stato di errore. Probabilmente si è verificato un problema con Azure Cosmos DB.
Contratto di servizio violato 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.
Contratto di servizio violato 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:

  • Coerenza assoluta e coerenza con decadimento ristretto hanno sempre almeno due risultati di archivio.
  • 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.

RequestTimeline

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.
  • Un tempo Pipelined elevato potrebbe essere causato da una richiesta di grandi dimensioni.
  • Transit time è elevato, il che porta a un problema di rete. Confrontare questo numero con BELatencyInMs. Se BELatencyInMs è basso, il tempo è stato dedicato alla rete e non al servizio Azure Cosmos DB.
  • Un tempo Received elevato potrebbe essere causato da un problema di thread starvation. Questo è il tempo tra la risposta e la restituzione del risultato.

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 che causa un blocco head of line probabilmente causato da un'altra richiesta, ad esempio un'operazione di query o di feed che richiede molto tempo per l'elaborazione. 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