Questa pagina descrive come calcolare la latenza delle richieste API Spanner delle richieste di flussi di dati e di partizione.
Puoi calcolare le latenze delle richieste di partizionamento e dei flussi di dati dell'API Spanner con i campi nell'oggetto struct metadata di un AuditLog. I metadati sono di tipo QueryPerformanceMetadata.
Per le richieste di flussi di dati 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 flussi di dati
Quando un client invia una richiesta di flusso e quando l'API Spanner restituisce set di risultati parziali, Cloud Audit Logs registra gli audit log per la prima e l'ultima risposta. La latenza di richiesta per una richiesta di inserimento di flussi è il tempo trascorso tra il momento in cui l'API Spanner riceve la richiesta e il momento in cui il client riceve l'ultima risposta.
Riconoscimento delle voci degli audit log delle richieste di flussi di dati
Per calcolare la latenza di una richiesta in modalità flusso, 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 flusso sono presenti due voci di log, raggruppate per operation.id. La prima voce
operation.first è stata impostata su true e l'ultima ha operation.last impostato su
true. Viene compilato anche l'oggetto protoPayload.metadata.responseTimestamp.
Calcolare la latenza delle richieste per le richieste di flussi di dati
Per calcolare la latenza di richiesta di una richiesta di flussi di dati, filtra gli audit log per operation.id. La differenza tra le versioni più recenti di protoPayload.metadata.responseTimestamp e protoPayload.requestMetadata.requestAttributes.time è la latenza della richiesta.
Audit log di esempio per richieste di flussi di dati
Per trovare tutte le voci di log per una richiesta di inserimento di flussi, esegui la seguente 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 delle richieste è il più recente (metadata.responseTimestamp) meno il
requestAttributes.time più recente. Il risultato è
2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z, che
equivale a 0,003185828 secondi.
Latenze di richiesta per le richieste di partizione
Quando un client invia una richiesta partizionata, Spanner crea più audit log. Per calcolare la latenza della richiesta di una richiesta di partizione end-to-end e delle chiamate successive alle partizioni, identifica gli audit log associati alla richiesta padre.
Riconoscere le voci degli audit log delle richieste di partizione
Quando effettui una richiesta PartitionRead o PartitionQuery, viene restituito un insieme di partizioni nella PartitionResponse. Quando
effettui rispettivamente le chiamate Read, ExecuteSql o ExecuteStreaming
per ogni partizione, Spanner registra gli audit log per questi metodi. Ciascuno di questi log contiene un identificatore che li raggruppa, chiamato protoPayload.metadata.partitionBatchIdentifier. Viene compilato anche l'oggetto protoPayload.metadata.responseTimestamp.
Calcolare la latenza delle richieste di partizione
Per calcolare la latenza di una richiesta di partizione, puoi filtrare gli audit log in base a metadata.partitionBatchIdentifier. La differenza tra il
metadata.responseTimestamp più recente e il più recente
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 la seguente 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 delle richieste è il più recente (metadata.responseTimestamp) meno il
requestAttributes.time più recente. Il risultato è 2023-02-15T18:13:39.441692339Z
- 2023-02-15T18:13:39.341584693Z, che equivale a 0,100107646 secondi.