はじめに

commmune Advent Calendar 2023 の5日目の記事です。

毎日行うビルドやデプロイ、改善してますか？
例えば、ビルド時間が前より5分増えていたけど誰も気づかないという事態は価値提供のスピードに関わるので避けたいところです。
そこで、Cloud LoggingのLog Analyticsを使ってCloud Buildの時間を可視化してみました。

作成したもの

ビルドとデプロイにかかった合計時間と各ステップの時間推移のダッシュボードを作りました。

このグラフでは兆候は見られないですが、一目で時間増減の傾向が把握できます。

各ステップの時間のグラフを拡大するとこんな感じです。

y軸は時間の積算になっていますが、実際はステップを並列実行しています。
トータルは合計時間のグラフで確認できます。

以下の流れで作成しました。

ビルド・デプロイの時間をログへ出力する
ログからグラフを作成する

詳しく説明します。

ビルド・デプロイの時間をログへ出力する

時間は以下のようにCloud Buildの履歴から確認できます。

この元データを使うとグラフを作れそうです。

Cloud Buildは、状態が変化したときにcloud-buildsというPub/Subトピックにメッセージをパブリッシュします。
おそらくこのメッセージを元にしているはずで、メッセージの中身をログへ出力してみます。

メッセージの中身をCloud Loggingへ出力する

Cloud Functionsを使ってPub/Subトピックのメッセージを複製してCloud Loggingへ出力します。
JSON.stringifyを使ってjsonPayloadフィールドへ出力しました。

ログを構造化する理由は、Log Analyticsで扱いやすくするためです。
構造化しないとtextPayloadフィールドへのっぺりとしたログが出るだけで取り扱いが大変です。

ログからグラフを作成する

Log Analyticsでビルド・デプロイ時間を抽出するクエリを作成します。
合計時間は終了時間ー開始時間を計算する必要があったので力技で引き算しました。

WITH 
base AS (
    SELECT
        timestamp,
        json_payload AS json
    FROM
        'cloud_logging_log_bucket'  -- Cloud Loggingのログバケット名
    WHERE
        JSON_VALUE(json_payload, '$.status') = "SUCCESS"
        AND JSON_VALUE(json_payload, '$.tags[0]') = 'cloud_build_trigger_tag' -- Cloud Buildトリガーのタグ名
),
extract_time AS (
    SELECT
        timestamp,
        JSON_VALUE(json, '$.startTime') AS startTime,
        JSON_VALUE(json, '$.finishTime') AS endTime
    FROM
        base
),
build_time AS (
    SELECT
        timestamp,
        startTime,
        endTime,
        TIMESTAMP_DIFF(
            TIMESTAMP(SUBSTR(endTime, 1, 19)),
            TIMESTAMP(SUBSTR(startTime, 1, 19)),
            SECOND) AS duration_seconds
    FROM
        extract_time
)
SELECT
    timestamp,
    duration_seconds
FROM
    build_time

各ステップの時間は以下のようになりました。

WITH 
base AS (
    SELECT
        timestamp,
        json_payload AS json
    FROM
        'cloud_logging_log_bucket'  -- Cloud Loggingのログバケット名
    WHERE
        JSON_VALUE(json_payload, '$.status') = "SUCCESS"
        AND JSON_VALUE(json_payload, '$.tags[0]') = 'cloud_build_trigger_tag' -- Cloud Buildトリガーのタグ名
),
extract_time AS (
    SELECT
        timestamp,
        JSON_VALUE(step, '$.id') AS id,
        JSON_VALUE(step, '$.timing.startTime') AS startTime,
        JSON_VALUE(step, '$.timing.endTime') AS endTime
    FROM
        base,
        UNNEST(JSON_EXTRACT_ARRAY(json, '$.steps')) AS step
),
build_time AS (
    SELECT
        timestamp,
        id,
        startTime,
        endTime,
        TIMESTAMP_DIFF(
            TIMESTAMP(SUBSTR(endTime, 1, 19)),
            TIMESTAMP(SUBSTR(startTime, 1, 19)),
            SECOND
        ) AS duration_seconds
    FROM
        extract_time
)
SELECT
    timestamp,
    MAX(CASE WHEN id = 'ステップ1の識別名' THEN duration_seconds ELSE NULL END) AS step1,
    MAX(CASE WHEN id = 'ステップ2の識別名' THEN duration_seconds ELSE NULL END) AS step2
    -- 必要なステップ数だけ記載する
FROM
    build_time
GROUP BY
    timestamp

以下のように配列stepsにステップごとの結果があるのでUNNESTで展開するのがポイントです。

クエリを実行すると各ステップの時間が抽出できます。

2023/12/3現在、プレビュー段階ですがクエリの結果からグラフを作成できます。
グラフの種類などを設定して保存します。

表示したいグラフの数だけクエリを作成してグラフをダッシュボードへまとめれば完成です！

さいごに

Log Analyticsを使ってログからさまざまなものを可視化できそうです。
ただ、可視化は確かに大事ですが、変化の兆候をキャッチするほうが重要です。

変化をキャッチしてアラートを出したかったのですが、残念なことに今回作ったグラフでは変化量ベースのアラートを設定できませんでした。
まだプレビュー段階ということでGAの際にはできるようになっていることを期待します！
なお、グラフに表示できるアイテムは5つまででした。こちらもGAで上限が増えることを期待します！

Log AnalyticsでCloud Buildの時間を可視化してみた