Calcular a latência das solicitações de partição e do streaming do Spanner

Nesta página, descrevemos como calcular a solicitação da API Spanner latência de solicitações de streaming e de partição.

É possível calcular o streaming e a solicitação de partição da API Spanner latências com os campos no objeto struct metadata de uma AuditLog. Os metadados são do tipo QueryPerformanceMetadata. Para solicitações de streaming e partição, o metadata não contém um processingSecondsDuration. Para mais informações sobre como usar processingSecondsDuration para calcular as latências de solicitação de todos os outros tipos de solicitação, consulte Duração do processamento.

Latências de solicitações de streaming

Quando um cliente envia uma solicitação de streaming e, à medida que a API Spanner retorna conjuntos de resultados parciais, Os Registros de auditoria do Cloud gravam registros de auditoria do primeiro e do último de resposta. A latência de uma solicitação de streaming é o tempo decorrido entre o momento em que a API Spanner recebe a solicitação e recebe a última resposta.

Reconhecer entradas de registro de auditoria de solicitações de streaming

Para calcular a latência de uma solicitação de streaming, você precisa identificar as entradas de registro relacionadas à solicitação. As entradas de registro têm protoPayload.methodName foi definido como google.spanner.v1.Spanner.ExecuteStreamingSql ou google.spanner.v1.Spanner.StreamingRead Para cada solicitação de streaming, há duas entradas de registro, 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.

Calcular a latência de solicitações de streaming

Para calcular a latência de uma solicitação de streaming, filtre os registros de auditoria por operation.id. A diferença entre os registros protoPayload.metadata.responseTimestamp e os primeiros protoPayload.requestMetadata.requestAttributes.time é a latência da solicitação.

Exemplos de registros de auditoria para solicitações de streaming

Para encontrar todas as entradas de registro de uma solicitação de streaming, execute a seguinte consulta no Análise de registros, substituindo OPERATION_ID com o valor pretendido:

operation.id="OPERATION_ID"

O exemplo a seguir encontra entradas de registro para uma solicitação de streaming com o operation.id de 15327696495839874591:

operation.id="15327696495839874591"

Primeiro registro retornado

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

{
  "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 da solicitação é o metadata.responseTimestamp mais recente, menos o mais antigas 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 solicitações de partição

Quando um cliente envia uma solicitação particionada, o Spanner cria várias ou de sistemas operacionais de contêineres. Calcular a latência de uma solicitação de partição de ponta a ponta e chamadas subsequentes para as partições, identifique os registros de auditoria associados à solicitação principal.

Reconhecer entradas de registro de auditoria de solicitações de partição

Quando você faz uma solicitação PartitionRead ou PartitionQuery, um conjunto de partições são retornadas PartitionResponse. Conforme você faça chamadas Read, ExecuteSql ou ExecuteStreaming, respectivamente para cada o Spanner grava registros de auditoria para esses métodos. Cada um de esses registros contêm um identificador para agrupá-los, chamado protoPayload.metadata.partitionBatchIdentifier: O O objeto protoPayload.metadata.responseTimestamp também é preenchido.

Calcular a latência de solicitações de partição

Para calcular a latência de uma solicitação de partição, filtre o registros de auditoria do Cloud Storage por metadata.partitionBatchIdentifier. A diferença entre o os últimos metadata.responseTimestamp e os primeiros protoPayload.requestMetadata.requestAttributes.time é a latência da solicitação.

Exemplos de registros de auditoria para solicitações de partição

Para encontrar todas as entradas de registro de uma solicitação de partição, execute a seguinte consulta no Análise de registros, substituindo PARTITION_BATCH_ID com o valor pretendido:

metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"

O exemplo a seguir encontra entradas de registro para uma solicitação de partição com o metadata.partitionBatchIdentifier de 15327696495839874591:

metadata.partitionBatchIdentifier="15327696495839874591"

Primeiro registro retornado

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

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

Dependendo do número de partições, o Spanner pode registrar mais registros do que neste exemplo.

Último registro retornado

{
  "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 da solicitação é o metadata.responseTimestamp mais recente, menos o mais antigas de requestAttributes.time. O resultado é 2023-02-15T18:13:39.441692339Z - 2023-02-15T18:13:39.341584693Z, que equivale a 0,100107646 segundos.