En esta página, se describe cómo puedes calcular la latencia de las solicitudes a la API de Spanner de las solicitudes de transmisión y partición.
Puedes calcular las latencias de transmisión y solicitud de partición de la API de Spanner con los campos del objeto de estructura metadata de un AuditLog. Los metadatos son del tipo QueryPerformanceMetadata.
En el caso de las solicitudes de transmisión y partición, el metadata no contiene un campo processingSecondsDuration. Si quieres obtener información para usar processingSecondsDuration y calcular las latencias de las solicitudes para todos los demás tipos de solicitudes, consulta Duración del procesamiento.
Latencias de las solicitudes de transmisión
Cuando un cliente envía una solicitud de transmisión y la API de Spanner muestra conjuntos de resultados parciales, los Registros de auditoría de Cloud registran los registros de auditoría de la primera y la última respuesta. La latencia de solicitud de una solicitud de transmisión es el tiempo transcurrido entre el momento en que la API de Spanner recibe la solicitud y el momento en que el cliente recibe la última respuesta.
Reconoce las entradas de registro de auditoría de solicitudes de transmisión
Para calcular la latencia de solicitud de una solicitud de transmisión, debes identificar
las entradas de registro relacionadas con la solicitud. Las entradas de registro tienen protoPayload.methodName configurado en google.spanner.v1.Spanner.ExecuteStreamingSql o google.spanner.v1.Spanner.StreamingRead. Para cada solicitud de transmisión, hay
dos entradas de registro, que se agrupan por operation.id. La primera entrada tiene operation.first configurado como true y la última entrada tiene operation.last configurado como true. También se propaga el objeto protoPayload.metadata.responseTimestamp.
Calcula la latencia de las solicitudes de transmisión
Para calcular la latencia de una solicitud de transmisión continua, filtra los registros de auditoría según operation.id. La diferencia entre el protoPayload.metadata.responseTimestamp más reciente y el protoPayload.requestMetadata.requestAttributes.time más antiguo es la latencia de la solicitud.
Ejemplos de registros de auditoría para solicitudes de transmisión
Para encontrar todas las entradas de registro de una solicitud de transmisión, ejecuta la siguiente consulta en el Explorador de registros y reemplaza la variable OPERATION_ID por el valor deseado:
operation.id="OPERATION_ID"
En el siguiente ejemplo, se encuentran entradas de registro para una solicitud de transmisión continua con el operation.id de 15327696495839874591:
operation.id="15327696495839874591"
Se devolvió el primer registro
{
"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 registro devuelto
{
"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"
}
La latencia de la solicitud es el metadata.responseTimestamp más reciente menos el requestAttributes.time más antiguo. El resultado es 2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z, que equivale a 0.003185828 segundos.
Latencias de las solicitudes de partición
Cuando un cliente envía una solicitud particionada, Spanner crea varios registros de auditoría. Para calcular la latencia de solicitud de una solicitud de partición de extremo a extremo y las llamadas posteriores a las particiones, identifica los registros de auditoría asociados con la solicitud superior.
Reconoce las entradas de registro de auditoría de las solicitudes de partición
Cuando realizas una solicitud PartitionRead o PartitionQuery, se muestra un conjunto de particiones en PartitionResponse. A medida que realizas llamadas a Read, ExecuteSql o ExecuteStreaming, respectivamente, para cada partición, Spanner registra los registros de auditoría de estos métodos. Cada uno de estos registros contiene un identificador para agruparlos, llamado protoPayload.metadata.partitionBatchIdentifier. También se propaga el objeto protoPayload.metadata.responseTimestamp.
Calcula la latencia de las solicitudes de partición
Para calcular la latencia de la solicitud de una solicitud de partición, puedes filtrar los registros de auditoría por metadata.partitionBatchIdentifier. La diferencia entre el metadata.responseTimestamp más reciente y el protoPayload.requestMetadata.requestAttributes.time más antiguo es la latencia de la solicitud.
Ejemplos de registros de auditoría para solicitudes de partición
Para encontrar todas las entradas de registro de una solicitud de partición, ejecuta la siguiente consulta en el Explorador de registros y reemplaza la variabilidad PARTITION_BATCH_ID por el valor deseado:
metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"
En el siguiente ejemplo, se encuentran entradas de registro para una solicitud de partición con el metadata.partitionBatchIdentifier de 15327696495839874591:
metadata.partitionBatchIdentifier="15327696495839874591"
Se devolvió el primer registro
{
"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"
}
Segundo registro que se muestra
{
"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"
}
Según la cantidad de particiones, Spanner podría registrar más registros que en este ejemplo.
Último registro devuelto
{
"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"
}
La latencia de la solicitud es el metadata.responseTimestamp más reciente menos el requestAttributes.time más antiguo. El resultado es 2023-02-15T18:13:39.441692339Z - 2023-02-15T18:13:39.341584693Z, que es igual a 0.100107646 segundos.