Esta página descreve como pode calcular a latência de pedidos da API Spanner de pedidos de streaming e de partições.
Pode calcular as latências de streaming e de pedidos de partição da API Spanner com os campos no objeto struct de um AuditLog.metadata Os metadados são do tipo QueryPerformanceMetadata.
Para pedidos de streaming e de partição, o metadata não contém um campo processingSecondsDuration. Para obter informações sobre como usar
processingSecondsDuration para calcular as latências de pedidos para todos os outros
tipos de pedidos, consulte Duração do processamento.
Latências de pedidos de streaming
Quando um cliente envia um pedido de streaming e a API Spanner devolve conjuntos de resultados parciais, os registos de auditoria do Cloud registam registos de auditoria para a primeira e a última respostas. A latência do pedido para um pedido de streaming é o tempo decorrido entre o momento em que a API Spanner recebe o pedido e o momento em que o cliente recebe a última resposta.
Reconheça as entradas do registo de auditoria de pedidos de streaming
Para calcular a latência do pedido de um pedido de streaming, tem de identificar as entradas de registo relacionadas com o pedido. As entradas do registo têm o
protoPayload.methodName definido como
google.spanner.v1.Spanner.ExecuteStreamingSql ou
google.spanner.v1.Spanner.StreamingRead. Para cada pedido de streaming, existem duas entradas de registo, que são agrupadas por operation.id. A primeira entrada tem operation.first definido como true e a última entrada tem operation.last definido como true. O objeto protoPayload.metadata.responseTimestamp também é preenchido.
Calcule a latência dos pedidos de streaming
Para calcular a latência de pedidos de um pedido de streaming, filtre os registos de auditoria por operation.id. A diferença entre o mais recente
protoPayload.metadata.responseTimestamp e o mais antigo
protoPayload.requestMetadata.requestAttributes.time é a latência do pedido.
Exemplo de registos de auditoria para pedidos de streaming
Para encontrar todas as entradas de registo de um pedido de streaming, execute a seguinte consulta no Explorador de registos, substituindo a variável OPERATION_ID pelo valor pretendido:
operation.id="OPERATION_ID"
O exemplo seguinte encontra entradas do registo para um pedido de streaming com o
operation.id de 15327696495839874591:
operation.id="15327696495839874591"
Devolveu o primeiro registo
{
"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"
}
Último registo devolvido
{
"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"
}
A latência do pedido é o valor mais recente de metadata.responseTimestamp menos o valor mais antigo de requestAttributes.time. O resultado é
2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z, que
é igual a 0,003185828 segundos.
Latências de pedidos para pedidos de partições
Quando um cliente envia um pedido particionado, o Spanner cria vários registos de auditoria. Para calcular a latência de pedidos de um pedido de partição ponto a ponto e chamadas subsequentes às partições, identifique os registos de auditoria associados ao pedido principal.
Reconheça as entradas do registo de auditoria de pedidos de partição
Quando faz um pedido PartitionRead ou PartitionQuery, é devolvido um conjunto de partições no PartitionResponse. À medida que faz chamadas Read, ExecuteSql ou ExecuteStreaming, respetivamente, para cada partição, o Spanner regista registos de auditoria para estes métodos. Cada um destes registos contém um identificador para os agrupar, denominado protoPayload.metadata.partitionBatchIdentifier. O objeto protoPayload.metadata.responseTimestamp também é preenchido.
Calcule a latência dos pedidos de partição
Para calcular a latência de pedidos de um pedido de partição, pode filtrar os registos de auditoria por metadata.partitionBatchIdentifier. A diferença entre o
metadata.responseTimestamp mais recente e o
protoPayload.requestMetadata.requestAttributes.time mais antigo é a latência do pedido.
Exemplo de registos de auditoria para pedidos de partição
Para encontrar todas as entradas de registo de um pedido de partição, execute a seguinte consulta no Explorador de registos, substituindo a variável PARTITION_BATCH_ID pelo valor pretendido:
metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"
O exemplo seguinte encontra entradas de registo para um pedido de partição com o
metadata.partitionBatchIdentifier de 15327696495839874591:
metadata.partitionBatchIdentifier="15327696495839874591"
Devolveu o primeiro registo
{
"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"
}
Returned second log
{
"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"
}
Consoante o número de partições, o Spanner pode registar mais registos do que neste exemplo.
Último registo devolvido
{
"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"
}
A latência do pedido é o valor mais recente de metadata.responseTimestamp menos o valor mais antigo de requestAttributes.time. O resultado é 2023-02-15T18:13:39.441692339Z
- 2023-02-15T18:13:39.341584693Z, que é igual a 0,100107646 segundos.