このページでは、ストリーミング リクエストとパーティション リクエストの Spanner API リクエスト レイテンシを計算する方法について説明します。
Spanner API ストリーミングとパーティション リクエストのレイテンシは、AuditLog の metadata 構造体オブジェクトのフィールドを使用して計算できます。メタデータのタイプは QueryPerformanceMetadata です。ストリーミングとパーティションのリクエストの場合、metadata には processingSecondsDuration フィールドは含まれません。processingSecondsDuration を使用して他のすべてのリクエスト タイプのリクエスト レイテンシを計算する方法については、処理期間をご覧ください。
ストリーミング リクエストのレイテンシ
クライアントがストリーミング リクエストを送信し、Spanner API が部分的な結果セットを返すと、Cloud 監査ログ最初と最後のレスポンスの監査ログを記録します。ストリーミング リクエストのリクエスト レイテンシは、Spanner API がリクエストを受信してからクライアントが最後のレスポンスを受信するまでの経過時間です。
ストリーミング リクエストの監査ログエントリを認識する
ストリーミング リクエストのリクエスト レイテンシを計算するには、リクエストに関連するログエントリを特定する必要があります。ログエントリの protoPayload.methodName が google.spanner.v1.Spanner.ExecuteStreamingSql または google.spanner.v1.Spanner.StreamingRead に設定されている。ストリーミング リクエストごとに 2 つのログエントリがあり、これらは operation.id でグループ化されています。最初のエントリは operation.first を true に設定し、最後のエントリは operation.last を true に設定します。protoPayload.metadata.responseTimestamp オブジェクトも入力されます。
ストリーミング リクエストのレイテンシを計算する
ストリーミング リクエストのリクエスト レイテンシを計算するには、監査ログを operation.id でフィルタリングします。最新の protoPayload.metadata.responseTimestamp と最も古い protoPayload.requestMetadata.requestAttributes.time の違いは、リクエストのレイテンシです。
ストリーミング リクエストのサンプル監査ログ
ストリーミング リクエストのすべてのログエントリを検索するには、ログ エクスプローラで次のクエリを実行し、OPERATION_ID 変数を目的の値に置き換えます。
operation.id="OPERATION_ID"
次の例では、operation.id が 15327696495839874591 であるストリーミング リクエストのログエントリを検索します。
operation.id="15327696495839874591"
最初のログが返されました
{
"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"
}
返された最後のログ
{
"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"
}
リクエストのレイテンシは、最新の metadata.responseTimestamp から最も古い requestAttributes.time を引いた値になります。結果は 2023-02-27T16:57:40.556138125Z-2023-02 ～ 2023-02-27T16:57:40.552952297Z になります。これは 0.003185828 秒に相当します。
パーティション リクエストのリクエスト レイテンシ
クライアントがパーティション分割リクエストを送信すると、Spanner は複数の監査ログを作成します。エンドツーエンドのパーティション リクエストと後続のパーティションへの呼び出しのリクエスト レイテンシを計算するには、親リクエストに関連付けられた監査ログを特定します。
パーティション リクエストの監査ログエントリを認識する
PartitionRead または PartitionQuery リクエストを行うと、PartitionResponse でパーティションのセットが返されます。パーティションごとに Read、ExecuteSql、ExecuteStreaming の呼び出しを行うと、Spanner はこれらのメソッドの監査ログを記録します。これらのログにはそれぞれ、protoPayload.metadata.partitionBatchIdentifier というグループ化するための識別子が含まれています。protoPayload.metadata.responseTimestamp オブジェクトも入力されます。
パーティション リクエストのリクエスト レイテンシを計算する
パーティション リクエストのリクエスト レイテンシを計算するには、監査ログを metadata.partitionBatchIdentifier でフィルタします。最新の metadata.responseTimestamp と最も古い protoPayload.requestMetadata.requestAttributes.time の違いは、リクエストのレイテンシです。
パーティション リクエスト用の監査ログの例
パーティション リクエストのすべてのログエントリを検索するには、ログ エクスプローラで次のクエリを実行し、PARTITION_BATCH_ID 変数を目的の値に置き換えます。
metadata.partitionBatchIdentifier="PARTITION_BATCH_ID"
次の例では、metadata.partitionBatchIdentifier が 15327696495839874591 であるパーティション リクエストのログエントリを検索します。
metadata.partitionBatchIdentifier="15327696495839874591"
最初のログが返されました
{
"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"
}
返された 2 番目のログ
{
"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"
}
パーティションの数によっては、Spanner がこの例よりも多くのログを記録する場合があります。
返された最後のログ
{
"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"
}
リクエストのレイテンシは、最新の metadata.responseTimestamp から最も古い requestAttributes.time を引いた値になります。結果は 2023-02-15T18:13:39.441692339Z ～ 2023-02-15T18:13:39.341584693Z になります。これは 0.100107646 秒に相当します。