Auf dieser Seite wird beschrieben, wie Sie die Spanner API-Anfragelatenz von Streaming- und Partitionsanfragen berechnen.
Sie können die Latenzen von Spanner API-Streams und Partitionsanfragen mit den Feldern im metadata-Strukturobjekt einer AuditLog berechnen. Die Metadaten haben den Typ QueryPerformanceMetadata.
Bei Streaming- und Partitionsanfragen enthält der metadata kein processingSecondsDuration-Feld. Informationen dazu, wie Sie mit processingSecondsDuration die Anfragelatenz für alle anderen Anfragetypen berechnen, finden Sie unter Verarbeitungsdauer.
Latenzen für Streaminganfragen anfordern
Wenn ein Client eine Streaminganfrage sendet und die Spanner API Teilergebnismengen zurückgibt, werden in Cloud Audit Logs Protokolle für die erste und letzte Antwort protokolliert. Die Anfragelatenz für eine Streaminganfrage ist die Zeit, die vergeht, zwischen dem Zeitpunkt, an dem die Spanner API die Anfrage empfängt, und dem Zeitpunkt, an dem der Client die letzte Antwort empfängt.
Audit-Logeinträge für Streaminganfragen erkennen
Um die Anfragelatenz einer Streaminganfrage zu berechnen, müssen Sie die zugehörigen Logeinträge ermitteln. In den Logeinträgen ist protoPayload.methodName 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 ist operation.first auf true und für den letzten Eintrag ist operation.last auf true festgelegt. Das Objekt protoPayload.metadata.responseTimestamp ist ebenfalls ausgefüllt.
Anfragelatenz für Streaminganfragen berechnen
Wenn Sie die Anfragelatenz einer Streaminganfrage berechnen möchten, filtern Sie die Prüfprotokolle nach operation.id. Die Differenz zwischen dem spätesten protoPayload.metadata.responseTimestamp und dem frühesten protoPayload.requestMetadata.requestAttributes.time ist die Anfragelatenz.
Beispiel-Audit-Logs für Streaminganfragen
Wenn Sie alle Logeinträge für eine Streaminganfrage finden möchten, führen Sie die folgende Abfrage im Log-Explorer aus. 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 der operation.id 15327696495839874591 gefunden:
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 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",
"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 die letzte metadata.responseTimestamp abzüglich der 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.
Latenzen für Partitionsanfragen anfordern
Wenn ein Client eine partitionierte Anfrage sendet, erstellt Spanner mehrere Prüfprotokolle. Um die Anfragelatenz einer End-to-End-Partitionsanfrage und nachfolgender Aufrufe der Partitionen zu berechnen, identifizieren Sie die Prüfprotokolle, die mit der übergeordneten Anfrage verknüpft sind.
Audit-Logeinträge für Partitionsanfragen erkennen
Wenn Sie eine PartitionRead- oder PartitionQuery-Anfrage stellen, werden in der PartitionResponse mehrere Partitionen zurückgegeben. Wenn Sie für jede Partition Read-, ExecuteSql- oder ExecuteStreaming-Aufrufe ausführen, zeichnet Spanner Audit-Logs für diese Methoden auf. Jedes dieser Protokolle enthält eine Kennung, mit der sie gruppiert werden können: protoPayload.metadata.partitionBatchIdentifier. Das Objekt protoPayload.metadata.responseTimestamp ist ebenfalls ausgefüllt.
Anfragelatenz für Partitionsanfragen berechnen
Wenn Sie die Anfragelatenz einer Partitionsanfrage berechnen möchten, können Sie die Prüfprotokolle nach metadata.partitionBatchIdentifier filtern. Die Differenz zwischen dem letzten metadata.responseTimestamp und dem frühesten protoPayload.requestMetadata.requestAttributes.time ist die Anfragelatenz.
Beispiel-Audit-Logs für Partitionsanfragen
Wenn Sie alle Logeinträge für eine Partitionsanfrage finden möchten, führen Sie die folgende Abfrage im Log-Explorer aus. 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 der metadata.partitionBatchIdentifier 15327696495839874591 gefunden:
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 Protokolle auf als in diesem Beispiel.
Letztes Protokoll 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 die letzte metadata.responseTimestamp abzüglich der frühesten requestAttributes.time. Das Ergebnis ist 2023-02-15T18:13:39.441692339Z – 2023-02-15T18:13:39.341584693Z, was 0,100107646 Sekunden entspricht.