Menghitung latensi permintaan streaming dan partisi Spanner

Halaman ini menjelaskan cara menghitung latensi permintaan Spanner API untuk permintaan streaming dan partisi.

Anda dapat menghitung latensi permintaan streaming dan partisi Spanner API dengan kolom dalam objek struct metadata dari AuditLog. Metadata adalah jenis QueryPerformanceMetadata. Untuk permintaan streaming dan partisi, metadata tidak berisi kolom processingSecondsDuration. Untuk mengetahui informasi cara menggunakan processingSecondsDuration guna menghitung latensi permintaan untuk semua jenis permintaan lainnya, lihat Durasi pemrosesan.

Latensi permintaan untuk permintaan streaming

Saat klien mengirimkan permintaan streaming dan saat Spanner API menampilkan kumpulan hasil parsial, Cloud Audit Logs mencatat log audit untuk respons pertama dan terakhir. Latensi permintaan untuk permintaan streaming adalah waktu yang berlalu antara saat Spanner API menerima permintaan dan saat klien menerima respons terakhir.

Mengenali entri log audit permintaan streaming

Untuk menghitung latensi permintaan permintaan streaming, Anda perlu mengidentifikasi entri log yang terkait dengan permintaan. Entri log memiliki protoPayload.methodName yang ditetapkan ke google.spanner.v1.Spanner.ExecuteStreamingSql atau google.spanner.v1.Spanner.StreamingRead. Untuk setiap permintaan streaming, ada dua entri log, yang dikelompokkan menurut operation.id. Entri pertama memiliki operation.first yang ditetapkan ke true dan entri terakhir memiliki operation.last yang ditetapkan ke true. Objek protoPayload.metadata.responseTimestamp juga diisi.

Menghitung latensi permintaan untuk permintaan streaming

Untuk menghitung latensi permintaan permintaan streaming, filter log audit menurut operation.id. Perbedaan antara protoPayload.metadata.responseTimestamp terbaru dan protoPayload.requestMetadata.requestAttributes.time yang paling awal adalah latensi permintaan.

Contoh log audit untuk permintaan streaming

Untuk menemukan semua entri log untuk permintaan streaming, jalankan kueri berikut di Logs Explorer, dan ganti variabel OPERATION_ID dengan nilai yang diinginkan:

operation.id="OPERATION_ID"

Contoh berikut menemukan entri log untuk permintaan streaming dengan operation.id dari 15327696495839874591:

operation.id="15327696495839874591"

Ditampilkan log pertama

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

Catatan terakhir ditampilkan

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

Latensi permintaan adalah metadata.responseTimestamp terbaru dikurangi requestAttributes.time paling awal. Hasilnya adalah 2023-02-27T16:57:40.556138125Z-2023-02 - 2023-02-27T16:57:40.552952297Z, yang sama dengan 0,003185828 detik.

Latensi permintaan untuk permintaan partisi

Saat klien mengirim permintaan yang dipartisi, Spanner akan membuat beberapa log audit. Untuk menghitung latensi permintaan permintaan partisi menyeluruh dan panggilan berikutnya ke partisi, identifikasi log audit yang terkait dengan permintaan induk.

Mengenali entri log audit permintaan partisi

Saat Anda membuat permintaan PartitionRead atau PartitionQuery, kumpulan partisi akan ditampilkan di PartitionResponse. Saat Anda melakukan panggilan Read, ExecuteSql, atau ExecuteStreaming masing-masing untuk setiap partisi, Spanner akan mencatat log audit untuk metode ini. Setiap log ini berisi ID untuk mengelompokkannya, yang disebut protoPayload.metadata.partitionBatchIdentifier. Objek protoPayload.metadata.responseTimestamp juga diisi.

Menghitung latensi permintaan untuk permintaan partisi

Untuk menghitung latensi permintaan permintaan partisi, Anda dapat memfilter log audit berdasarkan metadata.partitionBatchIdentifier. Perbedaan antara metadata.responseTimestamp terbaru dan protoPayload.requestMetadata.requestAttributes.time yang paling awal adalah latensi permintaan.

Contoh log audit untuk permintaan partisi

Untuk menemukan semua entri log untuk permintaan partisi, jalankan kueri berikut di Logs Explorer, dengan mengganti variabel PARTITION_BATCH_ID dengan nilai yang diinginkan:

metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"

Contoh berikut menemukan entri log untuk permintaan partisi dengan metadata.partitionBatchIdentifier dari 15327696495839874591:

metadata.partitionBatchIdentifier="15327696495839874591"

Ditampilkan log pertama

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

Catatan kedua yang ditampilkan

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

Bergantung pada jumlah partisi, Spanner mungkin mencatat lebih banyak log daripada dalam contoh ini.

Catatan terakhir ditampilkan

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

Latensi permintaan adalah metadata.responseTimestamp terbaru dikurangi requestAttributes.time paling awal. Hasilnya adalah 2023-02-15T18:13:39.441692339Z - 2023-02-15T18:13:39.341584693Z, yang sama dengan 0,100107646 detik.