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

# はじめに
[commmune Advent Calendar 2023](https://qiita.com/advent-calendar/2023/commmune) の5日目の記事です。

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

# 作成したもの
ビルドとデプロイにかかった合計時間と各ステップの時間推移のダッシュボードを作りました。
![CleanShot 2023-12-02 at 11.40.15@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/a1688418-0aa4-c456-d074-10786ec0dabf.png)
このグラフでは兆候は見られないですが、一目で時間増減の傾向が把握できます。

各ステップの時間のグラフを拡大するとこんな感じです。
![CleanShot 2023-12-02 at 11.33.57@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/ea38ae00-8c93-1951-b86b-18691265a08a.png)
y軸は時間の積算になっていますが、実際はステップを並列実行しています。
トータルは合計時間のグラフで確認できます。


以下の流れで作成しました。
1. ビルド・デプロイの時間をログへ出力する
2. ログからグラフを作成する

詳しく説明します。

# ビルド・デプロイの時間をログへ出力する
時間は以下のようにCloud Buildの履歴から確認できます。
![CleanShot 2023-12-02 at 12.00.27@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/8907174e-27ef-f652-0598-45e55576b9e4.png)
この元データを使うとグラフを作れそうです。


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

## メッセージの中身をCloud Loggingへ出力する
Cloud Functionsを使ってPub/Subトピックのメッセージを複製してCloud Loggingへ出力します。
`JSON.stringify`を使って`jsonPayload`フィールドへ出力しました。
![CleanShot 2023-12-02 at 12.18.22@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/59970854-f230-0dd0-de68-1d64ad5e8b1d.png)
ログを構造化する理由は、Log Analyticsで扱いやすくするためです。
構造化しないと`textPayload`フィールドへのっぺりとしたログが出るだけで取り扱いが大変です。

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

```sql
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
```

各ステップの時間は以下のようになりました。
```sql
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`で展開するのがポイントです。
![CleanShot 2023-12-03 at 10.59.57@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/bb5c280d-ca87-97cf-cb43-5027e6ada0da.png)



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

![CleanShot 2023-12-02 at 12.43.49@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/fd88f92c-d9bd-fb69-97de-616be5dcea76.png)


2023/12/3現在、プレビュー段階ですがクエリの結果からグラフを作成できます。
グラフの種類などを設定して保存します。
![CleanShot 2023-12-04 at 13.30.06@2x.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/172195/141d3242-8362-ba50-280d-06714d3b6556.png)

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

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

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

# 参考ドキュメント
- [ビルド通知へのサブスクリプション](https://cloud.google.com/build/docs/subscribe-build-notifications?hl=ja)
- [Cloud Functionsの構造化ログへの書き込み](https://cloud.google.com/functions/docs/monitoring/logging?hl=ja#writing_structured_logs)
- [Log Analyticsでクエリの結果をグラフ化する](https://cloud.google.com/logging/docs/analyze/charts?hl=ja)
- [JSON_VALUE関数](https://cloud.google.com/bigquery/docs/reference/standard-sql/json_functions#json_value)