Auf dieser Seite wird beschrieben, wie Sie die Latenz von Spanner API-Anfragen von Streaming- und Partitionsanfragen berechnen können.
Sie können die Latenzen von Spanner API-Streaming- und Partitionsanfragen mit den Feldern im Strukturobjekt metadata eines AuditLog berechnen. Die Metadaten sind vom Typ QueryPerformanceMetadata.
Bei Streaming- und Partitionsanfragen enthält metadata kein Feld processingSecondsDuration. Informationen zum Verwenden von processingSecondsDuration zum Berechnen der Anfragelatenzen für alle anderen Anfragetypen finden Sie unter Verarbeitungsdauer.
Anfragelatenzen für Streaminganfragen
Wenn ein Client eine Streaminganfrage sendet und die Spanner API Teilergebnisse zurückgibt, zeichnet Cloud-Audit-Logs Audit-Logs für die erste und letzte Antwort auf. Die Anfragelatenz für eine Streaminganfrage ist die Zeit, die zwischen dem Empfang der Anfrage bei der Spanner API und dem Empfang der letzten Antwort beim Client verstrichen ist.
Audit-Logeinträge zu Streaminganfragen erkennen
Um die Anfragelatenz einer Streaminganfrage zu berechnen, müssen Sie die Logeinträge identifizieren, die sich auf die Anfrage beziehen. In den Logeinträgen ist protoPayload.methodName entweder auf google.spanner.v1.Spanner.ExecuteStreamingSql oder google.spanner.v1.Spanner.StreamingRead festgelegt. Für jede Streaminganfrage gibt es zwei Logeinträge, die nach operation.id gruppiert sind. Für den ersten Eintrag wurde operation.first auf true und für den letzten Eintrag operation.last auf true gesetzt. Das Objekt protoPayload.metadata.responseTimestamp wird ebenfalls ausgefüllt.
Anfragelatenz für Streaminganfragen berechnen
Filtern Sie die Audit-Logs nach operation.id, um die Anfragelatenz einer Streaminganfrage zu berechnen. Die Differenz zwischen dem neuesten protoPayload.metadata.responseTimestamp und dem frühesten protoPayload.requestMetadata.requestAttributes.time ist die Anfragelatenz.
Beispiele für Audit-Logs für Streaminganfragen
Führen Sie im Log-Explorer die folgende Abfrage aus, um alle Logeinträge für eine Streaminganfrage zu finden. Ersetzen Sie dabei die Variable OPERATION_ID durch den gewünschten Wert:
operation.id="OPERATION_ID"
Im folgenden Beispiel werden Logeinträge für eine Streaminganfrage mit dem operation.id von 15327696495839874591 gesucht:
operation.id="15327696495839874591"
Erstes Protokoll zurückgegeben
{
"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"
}
Letztes Log zurückgegeben
{
"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"
}
Die Anfragelatenz ist der letzte metadata.responseTimestamp abzüglich des frühesten requestAttributes.time. Das Ergebnis ist 2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z, was 0,003185828 Sekunden entspricht.
Anfragelatenzen für Partitionsanfragen
Wenn ein Client eine partitionierte Anfrage sendet, erstellt Spanner mehrere Audit-Logs. Identifizieren Sie die Audit-Logs, die mit der übergeordneten Anfrage verknüpft sind, um die Anfragelatenz einer End-to-End-Partitionsanfrage und der nachfolgenden Aufrufe der Partitionen zu berechnen.
Audit-Logeinträge für Partitionsanfragen erkennen
Wenn Sie eine PartitionRead- oder PartitionQuery-Anfrage stellen, wird eine Reihe von Partitionen im PartitionResponse zurückgegeben. Wenn Sie Read-, ExecuteSql- oder ExecuteStreaming-Aufrufe für jede Partition ausführen, zeichnet Spanner Audit-Logs für diese Methoden auf. Jedes dieser Logs enthält die ID protoPayload.metadata.partitionBatchIdentifier, um sie zu gruppieren. Das Objekt protoPayload.metadata.responseTimestamp wird ebenfalls ausgefüllt.
Anfragelatenz für Partitionsanfragen berechnen
Sie können die Audit-Logs nach metadata.partitionBatchIdentifier filtern, um die Anfragelatenz einer Partitionsanfrage zu berechnen. Die Differenz zwischen der neuesten metadata.responseTimestamp und der frühesten protoPayload.requestMetadata.requestAttributes.time ist die Anfragelatenz.
Beispiel-Audit-Logs für Partitionsanfragen
Führen Sie im Log-Explorer die folgende Abfrage aus, um alle Logeinträge für eine Partitionsanfrage zu finden. Ersetzen Sie dabei die Variable PARTITION_BATCH_ID durch den gewünschten Wert:
metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"
Im folgenden Beispiel werden Logeinträge für eine Partitionsanfrage mit dem metadata.partitionBatchIdentifier von 15327696495839874591 gesucht:
metadata.partitionBatchIdentifier="15327696495839874591"
Erstes Protokoll zurückgegeben
{
"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"
}
Zurückgegebenes zweites Protokoll
{
"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"
}
Je nach Anzahl der Partitionen zeichnet Spanner möglicherweise mehr Logs auf als in diesem Beispiel.
Letztes Log zurückgegeben
{
"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"
}
Die Anfragelatenz ist der letzte metadata.responseTimestamp abzüglich des frühesten requestAttributes.time. Das Ergebnis ist 2023-02-15T18:13:39.441692339Z
- 2023-02-15T18:13:39.341584693Z, was 0,100107646 Sekunden entspricht.