Questa pagina descrive come calcolare la latenza delle richieste API Spanner delle richieste di flusso e di partizione.
Puoi calcolare le latenze delle richieste di flusso e di partizione e di flusso dell'API Spanner con i campi nell'oggetto struct metadata di un AuditLog. I metadati sono di tipo QueryPerformanceMetadata.
Per le richieste di flusso e di partizione, metadata non contiene un
campo processingSecondsDuration. Per informazioni su come utilizzare processingSecondsDuration per calcolare le latenze delle richieste per tutti gli altri tipi di richieste, consulta Durata di elaborazione.
Latenze di richiesta per le richieste di streaming
Quando un client invia una richiesta di flusso di dati e poiché l'API Spanner restituisce set di risultati parziali, Cloud Audit Logs registra gli audit log per la prima e l'ultima risposta. La latenza della richiesta per una richiesta di flusso di dati è il tempo che intercorre tra il momento in cui l'API Spanner riceve la richiesta e il momento in cui il client riceve l'ultima risposta.
Riconoscere le voci di audit log per le richieste di flussi di dati
Per calcolare la latenza di una richiesta di flusso di dati, devi identificare le voci di log relative alla richiesta. Le voci di log hanno protoPayload.methodName impostato su google.spanner.v1.Spanner.ExecuteStreamingSql o google.spanner.v1.Spanner.StreamingRead. Per ogni richiesta di inserimento di flussi di dati,
sono presenti due voci di log raggruppate per operation.id. La prima voce ha
operation.first impostato su true e l'ultima ha operation.last impostato su
true. Viene compilato anche l'oggetto protoPayload.metadata.responseTimestamp.
Calcola la latenza delle richieste per le richieste di flussi di dati
Per calcolare la latenza di una richiesta in modalità flusso, filtra gli audit log per operation.id. La differenza tra l'ultimo
protoPayload.metadata.responseTimestamp e il primo
protoPayload.requestMetadata.requestAttributes.time è la latenza della richiesta.
Audit log di esempio per le richieste di flussi di dati
Per trovare tutte le voci di log per una richiesta di inserimento di flussi di dati, esegui questa query in Esplora log, sostituendo la variabile OPERATION_ID con il valore desiderato:
operation.id="OPERATION_ID"
L'esempio seguente trova le voci di log per una richiesta di flussi di dati con operation.id di 15327696495839874591:
operation.id="15327696495839874591"
Primo log restituito
{
"protoPayload": {
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {...},
"requestMetadata": {
"requestAttributes": {
"time": "2023-02-27T16:57:40.552952297Z",
},
"destinationAttributes": {}
},
"serviceName": "spanner.googleapis.com",
"methodName": "google.spanner.v1.Spanner.ExecuteStreamingSql",
"authorizationInfo": [{...}],
"resourceName": "projects/example-project/instances/example-instance/databases/example-database/sessions/example-session",
"request": {
"session": "projects/example-project/instances/example-instance/databases/example-database/sessions/example-session",
"requestOptions": {},
"sql": "SELECT COUNT(*) as count FROM Example_table WHERE Example_Column > @timestamp",
"@type": "type.googleapis.com/google.spanner.v1.ExecuteSqlRequest",
"queryOptions": {}
},
"metadata": {
"@type": "type.googleapis.com/spanner.cloud.instance_v1.QueryPerformanceMetadata",
"responseTimestamp": "2023-02-27T16:57:40.555730699Z"
}
},
"insertId": "h7fj0jei6597",
"resource": {...},
"timestamp": "2023-02-27T16:57:40.552391554Z",
"severity": "INFO",
"logName": "projects/example-project/logs/cloudaudit.googleapis.com%2Fdata_access",
"operation": {
"id": "15327696495839874591",
"producer": "spanner.googleapis.com",
"first": true
},
"receiveTimestamp": "2023-02-27T16:57:41.507770020Z"
}
Ultimo log restituito
{
"protoPayload": {
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {...},
"requestMetadata": {
"requestAttributes": {
"time": "2023-02-27T16:57:40.552952297Z",
},
"destinationAttributes": {}
},
"serviceName": "spanner.googleapis.com",
"methodName": "google.spanner.v1.Spanner.ExecuteStreamingSql",
"authorizationInfo": [{...}],
"resourceName": "projects/example-project/instances/example-instance/databases/example-database/sessions/example-session",
"metadata": {
"responseTimestamp": "2023-02-27T16:57:40.556138125Z",
"@type": "type.googleapis.com/spanner.cloud.instance_v1.QueryPerformanceMetadata"
}
},
"insertId": "h7fj0jei6598",
"resource": {...},
"timestamp": "2023-02-27T16:57:40.552391554Z",
"severity": "INFO",
"logName": "projects/example-project/logs/cloudaudit.googleapis.com%2Fdata_access",
"operation": {
"id": "15327696495839874591",
"producer": "spanner.googleapis.com",
"last": true
},
"receiveTimestamp": "2023-02-27T16:57:41.507770020Z"
}
La latenza della richiesta è l'intervallo più recente di metadata.responseTimestamp meno
il meno recente (requestAttributes.time). Il risultato è
2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z, ossia
0,003185828 secondi.
Latenze delle richieste per le richieste di partizione
Quando un client invia una richiesta partizionata, Spanner crea più audit log. Per calcolare la latenza di richiesta di una richiesta di partizione end-to-end e le chiamate successive alle partizioni, identifica gli audit log associati alla richiesta padre.
Riconoscere le voci del log di controllo delle richieste di partizione
Quando effettui una richiesta PartitionRead o PartitionQuery, viene restituito un insieme di partizioni in PartitionResponse. Quando effettui chiamate Read, ExecuteSql o ExecuteStreaming rispettivamente per ogni partizione, Spanner registra gli audit log per questi metodi. Ciascuno di questi log contiene un identificatore per raggrupparli, chiamato protoPayload.metadata.partitionBatchIdentifier. Viene compilato
anche l'oggetto protoPayload.metadata.responseTimestamp.
Calcola la latenza delle richieste per le richieste di partizione
Per calcolare la latenza di una richiesta di partizione, puoi filtrare gli audit log per metadata.partitionBatchIdentifier. La differenza tra l'ultimo metadata.responseTimestamp e il primo protoPayload.requestMetadata.requestAttributes.time è la latenza della richiesta.
Audit log di esempio per le richieste di partizione
Per trovare tutte le voci di log per una richiesta di partizione, esegui questa query in Esplora log, sostituendo la variabile PARTITION_BATCH_ID con il valore desiderato:
metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"
L'esempio seguente trova le voci di log per una richiesta di partizione con metadata.partitionBatchIdentifier di 15327696495839874591:
metadata.partitionBatchIdentifier="15327696495839874591"
Primo log restituito
{
"protoPayload": {
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {...},
"requestMetadata": {
"requestAttributes": {
"time": "2023-02-15T18:13:39.341584693Z",
},
},
"serviceName": "spanner.googleapis.com",
"methodName": "google.spanner.v1.Spanner.ExecuteStreamingSql",
"authorizationInfo": [{...}],
"resourceName": "projects/example-project/instances/example-instance/databases/example-db/sessions/example-session",
"request": {...},
"metadata": {
"@type": "type.googleapis.com/spanner.cloud.instance_v1.QueryPerformanceMetadata",
"partitionBatchIdentifier": "4841471066190013455",
"responseTimestamp": "2023-02-15T18:13:39.343693061Z"
}
},
"insertId": "4fug42dqke5",
"resource": {...},
"timestamp": "2023-02-15T18:13:39.341069413Z",
"severity": "INFO",
"logName": "projects/example-project/logs/cloudaudit.googleapis.com%2Fdata_access",
"operation": {...},
"receiveTimestamp": "2023-02-15T18:13:39.983812511Z"
}
Secondo log restituito
{
"protoPayload": {
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {...},
"requestMetadata": {
"requestAttributes": {
"time": "2023-02-15T18:13:39.341584693Z",
},
},
"serviceName": "spanner.googleapis.com",
"methodName": "google.spanner.v1.Spanner.ExecuteStreamingSql",
"authorizationInfo": [{...}],
"resourceName": "projects/example-project/instances/example-instance/databases/example-db/sessions/example-session",
"metadata": {
"responseTimestamp": "2023-02-15T18:13:39.344256101Z",
"partitionBatchIdentifier": "4841471066190013455",
"@type": "type.googleapis.com/spanner.cloud.instance_v1.QueryPerformanceMetadata"
}
},
"insertId": "4fug42dqke6",
"resource": {...},
"timestamp": "2023-02-15T18:13:39.341069413Z",
"severity": "INFO",
"logName": "projects/example-project/logs/cloudaudit.googleapis.com%2Fdata_access",
"operation": {...},
"receiveTimestamp": "2023-02-15T18:13:39.983812511Z"
}
A seconda del numero di partizioni, Spanner potrebbe registrare più log rispetto a questo esempio.
Ultimo log restituito
{
"protoPayload": {
"@type": "type.googleapis.com/google.cloud.audit.AuditLog",
"authenticationInfo": {...},
"requestMetadata": {
"requestAttributes": {
"time": "2023-02-15T18:13:39.439207331Z",
},
},
"serviceName": "spanner.googleapis.com",
"methodName": "google.spanner.v1.Spanner.ExecuteStreamingSql",
"authorizationInfo": [{...}],
"resourceName": "projects/example-project/instances/example-instance/databases/example-db/sessions/example-session",
"metadata": {
"partitionBatchIdentifier": "4841471066190013455",
"@type": "type.googleapis.com/spanner.cloud.instance_v1.QueryPerformanceMetadata",
"responseTimestamp": "2023-02-15T18:13:39.441692339Z"
}
},
"insertId": "4fug42dqkec",
"resource": {...},
"timestamp": "2023-02-15T18:13:39.438607931Z",
"severity": "INFO",
"logName": "projects/example-project/logs/cloudaudit.googleapis.com%2Fdata_access",
"operation": {...},
"receiveTimestamp": "2023-02-15T18:13:39.983812511Z"
}
La latenza della richiesta è l'intervallo più recente di metadata.responseTimestamp meno
il meno recente (requestAttributes.time). Il risultato è 2023-02-15T18:13:39.441692339Z
- 2023-02-15T18:13:39.341584693Z, che equivale a 0,100107646 secondi.