Calcula la latencia de solicitud de transmisión y partición de Spanner

En esta página, se describe cómo calcular la latencia de las solicitudes de transmisión y partición a la API de Spanner.

Puedes calcular las latencias de solicitud de transmisión y partición a la API de Spanner con los campos del objeto de struct metadata de una AuditLog. Los metadatos son del tipo QueryPerformanceMetadata. Para las solicitudes de transmisión y partición, el metadata no contiene un campo processingSecondsDuration. Si deseas obtener información sobre cómo usar processingSecondsDuration para calcular las latencias de solicitud de todos los demás tipos de solicitudes, consulta Duración del procesamiento.

Latencias de solicitudes para solicitudes de transmisión

Cuando un cliente envía una solicitud de transmisión y, como 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 una solicitud de transmisión es el tiempo transcurrido entre el momento en que la API de Spanner recibe la solicitud y cuando el cliente recibe la última respuesta.

Reconocer las entradas del registro de auditoría de las solicitudes de transmisión

Para calcular la latencia de la solicitud de transmisión, debes identificar las entradas de registro relacionadas con la solicitud. Las entradas de registro tienen el protoPayload.methodName configurado como 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, filtra los registros de auditoría por operation.id. La diferencia entre la protoPayload.metadata.responseTimestamp más reciente y la primera protoPayload.requestMetadata.requestAttributes.time es la latencia de la solicitud.

Registros de auditoría de muestra 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 con el operation.id de 15327696495839874591:

operation.id="15327696495839874591"

Primer registro mostrado

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

{
  "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 la última metadata.responseTimestamp menos la requestAttributes.time más antigua. 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 solicitudes para solicitudes de partición

Cuando un cliente envía una solicitud particionada, Spanner crea varios registros de auditoría. Para calcular la latencia de la 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.

Reconocer las entradas del registro de auditoría de 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 para estos métodos. Cada uno de estos registros contiene un identificador para agruparlos, llamado protoPayload.metadata.partitionBatchIdentifier. El objeto protoPayload.metadata.responseTimestamp también se propaga.

Cómo calcular la latencia de las solicitudes de partición

Para calcular la latencia de la solicitud de una partición, puedes filtrar los registros de auditoría por metadata.partitionBatchIdentifier. La diferencia entre la última metadata.responseTimestamp y la primera protoPayload.requestMetadata.requestAttributes.time es la latencia de la solicitud.

Registros de auditoría de muestra para solicitudes de particiones

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 variable PARTITION_BATCH_ID con 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"

Primer registro mostrado

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

{
  "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 puede registrar más registros que en este ejemplo.

Último registro mostrado

{
  "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 la última metadata.responseTimestamp menos la requestAttributes.time más antigua. El resultado es 2023-02-15T18:13:39.441692339Z - 2023-02-15T18:13:39.341584693Z, que equivale a 0.100107646 segundos.