本页面介绍了如何计算流式请求和分区请求的 Spanner API 请求延迟时间。
您可以使用 AuditLog 的 metadata 结构体对象中的字段计算 Spanner API 流式传输和分区请求延迟时间。元数据的类型为 QueryPerformanceMetadata。对于流式传输请求和分区请求，metadata 不包含 processingSecondsDuration 字段。如需了解如何使用 processingSecondsDuration 计算所有其他请求类型的请求延迟时间，请参阅处理时长。
流式传输请求的请求延迟时间
当客户端发送流式传输请求并且 Spanner API 返回部分结果集时，Cloud Audit Logs 会记录首次响应和最后一次响应的审核日志。流式请求的请求延迟时间是指从 Spanner API 收到请求到客户端收到最后一个响应所经过的时间。
识别流式请求审核日志条目
如需计算流式传输请求的请求延迟时间，您需要标识与请求相关的日志条目。日志条目将 protoPayload.methodName 设置为 google.spanner.v1.Spanner.ExecuteStreamingSql 或 google.spanner.v1.Spanner.StreamingRead。每个流式传输请求都有两个日志条目，这些条目按 operation.id 分组。第一个条目将 operation.first 设置为 true，最后一个条目将 operation.last 设置为 true。此外，系统还会填充 protoPayload.metadata.responseTimestamp 对象。
计算流式请求的请求延迟时间
如需计算流式传输请求的请求延迟时间，请按 operation.id 过滤审核日志。最近 protoPayload.metadata.responseTimestamp 和最早 protoPayload.requestMetadata.requestAttributes.time 之间的差值是请求延迟时间。
流式请求的审核日志示例
如需查找流式传输请求的所有日志条目，请在日志浏览器中运行以下查询，并将 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 会创建多个审核日志。如需计算端到端分区请求的请求延迟时间以及对分区的后续调用，请确定与父请求关联的审核日志。
识别分区请求审核日志条目
当您发出 PartitionRead 或 PartitionQuery 请求时，PartitionResponse 中会返回一组分区。当您分别对每个分区执行 Read、ExecuteSql 或 ExecuteStreaming 调用时，Spanner 会记录这些方法的审核日志。每个日志都包含用于将它们组合在一起的标识符，称为 protoPayload.metadata.partitionBatchIdentifier。此外，系统还会填充 protoPayload.metadata.responseTimestamp 对象。
计算分区请求的请求延迟时间
如需计算分区请求的请求延迟时间，您可以按 metadata.partitionBatchIdentifier 过滤审核日志。最新 metadata.responseTimestamp 和最早 protoPayload.requestMetadata.requestAttributes.time 之间的差值是请求延迟时间。
分区请求的审核日志示例
如需查找分区请求的所有日志条目，请在日志浏览器中运行以下查询，将 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 秒。