Latenz von Spanner-Streaming- und Partitionsanfragen berechnen

Auf dieser Seite wird beschrieben, wie Sie die Spanner API-Anfrage berechnen können Latenz von Streaming- und Partitionsanfragen.

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 metadata keinen processingSecondsDuration. 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 von Streaminganfragen erkennen

Um die Anfragelatenz einer Streaminganfrage zu berechnen, müssen Sie die zugehörigen Logeinträge ermitteln. Die Logeinträge haben die protoPayload.methodName festgelegt auf google.spanner.v1.Spanner.ExecuteStreamingSql oder google.spanner.v1.Spanner.StreamingRead 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

Sie können die Audit-Logs filtern, um die Anfragelatenz einer Streaminganfrage zu berechnen von 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

Um alle Logeinträge für eine Streaminganfrage zu ermitteln, führen Sie die folgende Abfrage in der Log-Explorer, wobei die Klasse OPERATION_ID mit dem gewünschten Wert:

operation.id="OPERATION_ID"

Im folgenden Beispiel werden Logeinträge für eine Streaminganfrage mit dem Parameter operation.id von 15327696495839874591:

operation.id="15327696495839874591"

Erstes 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",
    "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 beträgt die letzten metadata.responseTimestamp abzüglich der frühestens requestAttributes.time. Das Ergebnis: 2023-02-27T16:57:40.556138125Z-2023-02 – 2023-02-27T16:57:40.552952297Z, die 0,003185828 Sekunden.

Anfragelatenzen für Partitionsanfragen

Wenn ein Client eine partitionierte Anfrage sendet, erstellt Spanner mehrere Audit-Logs Logs. Um die Anfragelatenz einer End-to-End-Partitionsanfrage zu berechnen bei nachfolgenden Aufrufen der Partitionen prüfen Sie die Audit-Logs, die Parent-Anfrage aus.

Audit-Logeinträge für Partitionsanfragen erkennen

Wenn Sie eine PartitionRead- oder PartitionQuery-Anfrage stellen, werden im 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. Jede von enthalten diese Protokolle 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

Um die Anfragelatenz einer Partitionsanfrage zu berechnen, können Sie Audit-Logs von metadata.partitionBatchIdentifier. Der Unterschied zwischen den letzte metadata.responseTimestamp und früheste 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 Log 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"
}

Zweites Log 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",
    "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 kann Spanner mehr Logs 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 lautet 2023-02-15T18:13:39.441692339Z – 2023-02-15T18:13:39.341584693Z, was 0,100107646 Sekunden entspricht.