计算 Spanner 流式传输和分区请求延迟时间

本页面介绍了如何计算 Spanner API 请求, 流式传输和分区请求的延迟时间

您可以计算 Spanner API 流式传输和分区请求 metadata 结构体对象中字段的延迟时间。 AuditLog.元数据的类型为 QueryPerformanceMetadata。 对于流式请求和分区请求,metadata 不包含 processingSecondsDuration 字段。关于如何使用 processingSecondsDuration,用于计算所有其他服务的请求延迟时间 请求类型,请参阅处理时长

流式请求的请求延迟时间

当客户端发送流式传输请求时 由于 Spanner API 会返回部分结果集 Cloud Audit Logs 会记录第一条和最后一条审核日志 响应。流式传输请求的请求延迟时间是经过的时间 从 Spanner API 收到请求到 客户端收到最后一个响应。

识别流式传输请求审核日志条目

要计算流式传输请求的请求延迟时间,您需要确定 与请求相关的日志条目。日志条目包含 protoPayload.methodName 设置为 google.spanner.v1.Spanner.ExecuteStreamingSqlgoogle.spanner.v1.Spanner.StreamingRead.对于每个流式传输请求 两个日志条目,按 operation.id 分组。第一个条目包含 operation.first 设置为 true,最后一个条目 operation.last 设置为 true.系统还会填充 protoPayload.metadata.responseTimestamp 对象。

计算流式请求的请求延迟时间

如需计算流式传输请求的请求延迟时间,请过滤审核日志 上传者:operation.id。最新 protoPayload.metadata.responseTimestamp及最早 protoPayload.requestMetadata.requestAttributes.time 是请求延迟时间。

流式请求审核日志示例

如需查找流式传输请求的所有日志条目,请在以下位置运行以下查询: Logs Explorer,替换了 将 OPERATION_ID 变量替换为所需的值:

operation.id="OPERATION_ID"

以下示例查找带有 第 operation.id 个(共 15327696495839874591 个):

operation.id="15327696495839874591"

返回了第一个日志

{
  "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"
}

返回了上一个日志

{
  "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"
}

请求延迟时间是最新的 metadata.responseTimestamp 减去 最早 requestAttributes.time。结果是 2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z,其中 等于 0.003185828 秒。

分区请求的请求延迟时间

当客户端发送分区请求时,Spanner 会创建多个审核 日志。计算端到端分区请求的请求延迟时间,并 对分区的后续调用,确定与 请求。

识别分区请求审核日志条目

当您发出 PartitionReadPartitionQuery 请求时, 分区是在 PartitionResponse。您 分别进行 ReadExecuteSqlExecuteStreaming 调用 分区,Spanner 会记录这些方法的审核日志。每个 这些日志包含用于将它们组合在一起的标识符,称为 protoPayload.metadata.partitionBatchIdentifier.通过 protoPayload.metadata.responseTimestamp 对象也会填充。

计算分区请求的请求延迟时间

如需计算分区请求的请求延迟时间,您可以过滤 metadata.partitionBatchIdentifier 创建的审核日志。两者的区别在于 最新的 metadata.responseTimestamp 和最早的 protoPayload.requestMetadata.requestAttributes.time 是请求延迟时间。

分区请求审核日志示例

如需查找分区请求的所有日志条目,请在以下位置运行以下查询: Logs Explorer,替换了 将 PARTITION_BATCH_ID 变量替换为所需的值:

metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"

以下示例查找包含 第 metadata.partitionBatchIdentifier 个(共 15327696495839874591 个):

metadata.partitionBatchIdentifier="15327696495839874591"

返回了第一个日志

{
  "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"
}

返回了第二个日志

{
  "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"
}

根据分区数量,Spanner 可能会记录 日志数量比本示例多。

返回了上一个日志

{
  "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"
}

请求延迟时间是最新的 metadata.responseTimestamp 减去 最早 requestAttributes.time。结果是 2023-02-15T18:13:39.441692339Z - 2023-02-15T18:13:39.341584693Z,等于 0.100107646 秒。