חישוב זמן האחזור של בקשות סטרימינג ומחיצות ב-Spanner

בדף הזה מוסבר איך לחשב את זמן האחזור של בקשות ל-Spanner API להזרמה ולחלוקה למחיצות.

אפשר לחשב את זמן האחזור של בקשות סטרימינג וחלוקה למחיצות של Spanner API באמצעות השדות באובייקט המבנה metadata של AuditLog. המטא-נתונים הם מסוג QueryPerformanceMetadata. בבקשות סטרימינג ובבקשות חלוקה למחיצות, השדה metadata לא מכיל את השדה processingSecondsDuration. מידע על אופן השימוש ב-processingSecondsDuration כדי לחשב את זמן האחזור של בקשות מכל הסוגים האחרים זמין במאמר משך העיבוד.

בקשת השהיות לבקשות סטרימינג

כשלקוח שולח בקשת סטרימינג וממשק Spanner API מחזיר קבוצות חלקיות של תוצאות, יומני ביקורת של Cloud מתעדים יומני ביקורת לתגובות הראשונה והאחרונה. זמן האחזור של בקשה להזרמת נתונים הוא הזמן שחלף בין הרגע שבו Spanner API מקבל את הבקשה לבין הרגע שבו הלקוח מקבל את התגובה האחרונה.

זיהוי רשומות ביומן הביקורת של בקשות סטרימינג

כדי לחשב את זמן האחזור של בקשת סטרימינג, צריך לזהות את רשומות היומן שקשורות לבקשה. הערך של protoPayload.methodName ברשומות ביומן הוא google.spanner.v1.Spanner.ExecuteStreamingSql או google.spanner.v1.Spanner.StreamingRead. לכל בקשת סטרימינג יש שתי רשומות ביומן, שמקובצות לפי operation.id. הערך של operation.first ברשומה הראשונה הוא true, והערך של operation.last ברשומה האחרונה הוא true. גם האובייקט protoPayload.metadata.responseTimestamp מאוכלס.

חישוב זמן האחזור של בקשות לסטרימינג

כדי לחשב את זמן האחזור של בקשת סטרימינג, מסננים את יומני הביקורת לפי operation.id. ההפרש בין protoPayload.metadata.responseTimestamp האחרון לבין protoPayload.requestMetadata.requestAttributes.time הראשון הוא זמן האחזור של הבקשה.

דוגמה ליומני ביקורת של בקשות סטרימינג

כדי למצוא את כל רשומות היומן של בקשת סטרימינג, מריצים את השאילתה הבאה ב-Logs Explorer ומחליפים את המשתנה 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, which equals 0.003185828 seconds.

בקשת השהיות (latencies) לבקשות של מחיצות

כשלקוח שולח בקשה מחולקת, ‏ Spanner יוצר כמה יומני ביקורת. כדי לחשב את זמן האחזור של בקשה למחיצה מקצה לקצה ואת הקריאות הבאות למחיצות, צריך לזהות את יומני הביקורת שמשויכים לבקשת האב.

זיהוי רשומות ביומן הביקורת של בקשות למחיצות

כשמבצעים בקשת PartitionRead או PartitionQuery, מוחזרת קבוצה של מחיצות ב-PartitionResponse. כשמבצעים קריאות ל-methods‏ Read, ExecuteSql או ExecuteStreaming בהתאמה לכל מחיצה, Spanner מתעד יומני ביקורת עבור ה-methods האלה. כל אחד מהיומנים האלה מכיל מזהה שמאפשר לקבץ אותם יחד, שנקרא protoPayload.metadata.partitionBatchIdentifier. גם האובייקט protoPayload.metadata.responseTimestamp מתמלא.

חישוב זמן האחזור של בקשות למחיצות

כדי לחשב את זמן האחזור של בקשת מחיצה, אפשר לסנן את יומני הביקורת לפי metadata.partitionBatchIdentifier. ההפרש בין metadata.responseTimestamp האחרון לבין protoPayload.requestMetadata.requestAttributes.time הראשון הוא זמן האחזור של הבקשה.

דוגמאות ליומני ביקורת של בקשות למחיצות

כדי למצוא את כל רשומות היומן של בקשת חלוקה, מריצים את השאילתה הבאה ב-Logs Explorer, ומחליפים את המשתנה 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"
}

היומן השני הוחזר

{
  "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 שניות.