おいしい健康　開発者ブログ

株式会社おいしい健康で働くエンジニア・デザイナーが社内の様子をお伝えします。

Xcodeのビルド時間計測の取り組み

弊社iOSチームにおける、Xcodeのビルド速度改善の取り組みの一端について紹介したいとおもいます。
おいしい健康のiOSアプリでは、機能開発を重ねていく過程で、コードベース量に比例してビルド時間が長くなり、数行の変更で1分近くビルド時間を要するなど、開発効率に難がある状態が続いていました。 ビルド時間は、ビルドキャッシュがほぼない状態でのクリーンビルドか、一定のビルドキャッシュの効いたインクリメンタルビルドかによって大きく異なります。
日々の開発への影響度が大きいのはインクリメンタルビルドであるため、これを計測・可視化し、開発生産性の観点で問題の大きさを定量的に把握したいと考え、チーム内のビルド時間に関する簡易的な統計データを収集することにしました。今回はその計測と可視化のアプローチについてご紹介します。

最終的な成果物となるXcodeビルド時間を可視化したダッシュボードは以下のようなものです。
チームにおけるビルド速度改善の必要性を判断するための指標の1つとして活用しています。

内容としては、クリーンビルドとインクリメンタルビルドそれぞれに要する時間、日毎の総ビルド実行回数・総ビルド時間などを可視化したものになります。
ダッシュボードはLookerを使用しており、簡易的なシステム構成としては以下のようなものです。

Xcodeで、あるスキームに対するビルドが行われると、.xcactivitylog形式のビルドログ情報を含むファイルが~/Library/Developer/Xcode/DerivedData/下に出力されます。
これを解析し、フォーマット化したビルドメトリクスを、Amazon S3にアップロードするスクリプトがビルド毎に実行されます。(Run Script Phase)
最終的にLookerで可視化を行う上で、S3にアップロードされたビルドログをBigQueryにロードする必要があるため、日毎に指定のBigQueryへ同期するためのデータ転送設定をスケジューリングします。Xcodeが出力したビルドログをS3にアップロードするまでのより詳細な流れとしては以下になります。

  • 1.) ビルドを開始
  • 2.) ビルド後、Post Build Scriptとしてlauncherスクリプトを実行
  • 3.) XcodeがxcactivityログをDeviredDataへ出力
  • 4.,5.) xcactivityログを解析・フォーマット化し、S3へスキーマJSONをアップロード

ポイントとしては、2.)のビルド後のRus Script Phaseで実行するlauncherスクリプトで、Xcodeによるxcactivityログ出力をバックグラウンドで待ち受ける処理を挟んだ上で、本体となるスクリプトを実行するようにしています。 launcherスクリプトの内容は以下のようなものです。

#!/bin/sh

executable=$1
shift;
$executable "$@" <&- >&- 2>&- &

Xcodeによるビルドログ出力はRun Script Phase後に行われる為、launcherスクリプトを挟まずに本体スクリプトを実行すると、直近のビルドログを得られなくなってしまいます。 これを回避するために、不要な入出力を遮断した上で、バックグラウンドで指定コマンドを実行する形で本体スクリプトの実行をトリガします。 弊社iOSチームでは、XcodeGenでXcodeプロジェクト管理を行なっており、具体的なRun Script Phase設定内容を表すproject.ymlは以下のようなものになります。

...
targets:
  xxx:
    ...
    postBuildScripts:
      - name: Upload xclogparser result JSON to S3
        script: |
          cd "$PROJECT_DIR" && \
          S3_BUCKET=s3://xcbuildmetrics.example.com \
          scripts/post_build_script_launcher.sh \ # 先述のlauncherスクリプト
          python3 scripts/xcbuildmetrics_uploader.py # s3にビルドログをuploadする本体スクリプト

DerivedDataに出力された.xcactivitylogを解析・フォーマット化し、スキーマJSONをS3へアップロードする本体スクリプトは以下のようなPythonスクリプトです。

import inspect
import json
import os
import pathlib
import subprocess
import tempfile
import time
import typing as t
from copy import deepcopy
from dataclasses import asdict, dataclass
from datetime import datetime
from enum import Enum

JSON = t.Dict[str, t.Any]

@dataclass
class BuildStep:
    startTimestamp: float
    compilationDuration: float
    schema: str
    fetchedFromCache: bool
    subSteps: list[BuildStep]
    machineName: str
    type: str
    schema: str

    def __post_init__(self):
        self.subSteps = [BuildStep.from_dict(x) for x in self.subSteps]

    @classmethod
    def from_dict(cls, data: JSON) -> BuildStep:
        attrs = inspect.signature(cls).parameters
        return cls(**{k: v for k, v in data.items() if k in attrs})

    def flatten(self) -> list[BuildStep]:
        steps: list[BuildStep] = []
        no_sub_steps = deepcopy(self)
        no_sub_steps.subSteps = []
        steps.append(no_sub_steps)
        for subStep in self.subSteps:
            steps.extend(self._flattenSubStep(subStep))
        return steps

    def _flattenSubStep(self, subStep: BuildStep) -> list[BuildStep]:
        details: list[BuildStep] = []
        no_sub_steps = deepcopy(subStep)
        no_sub_steps.subSteps = []
        details.append(no_sub_steps)
        for detail in subStep.subSteps:
            no_sub_steps = deepcopy(detail)
            no_sub_steps.subSteps = []
            details.append(no_sub_steps)
            if detail.subSteps:
                details.extend(detail.subSteps)
        return details


class BuildCategory(Enum):
    NOOP = "noop"
    CLEAN = "clean"
    INCREMENTAL = "incremental"


@dataclass
class BQRecord:
    start_time: float
    compilation_duration: float
    machine_name: str
    build_category: str
    scheme: str


def tweak_parse_result(data: JSON) -> JSON:
    """
    To prevent schema inconsistencies,
    unify the data types of the 'duration' like fields with float.
    """
    for k in data:
        if isinstance(data[k], list):
            for d in data[k]:
                if isinstance(d, dict):
                    tweak_parse_result(d)
        elif isinstance(data[k], dict):
            tweak_parse_result(data[k])
        elif "duration" in k.lower():
            data[k] = float(data[k])
    return data


def get_xclogparse_json() -> JSON:
    """
    Generate a JSON of XCLogParser's parse result
    """
    parse_output = subprocess.check_output(["xclogparser", "parse", "--workspace", "xxx.xcworkspace", "--reporter", "json"])
    parse_result_json = json.loads(parse_output.decode("utf-8"))
    tweak_parse_result(parse_result_json)
    return parse_result_json


def parse_build_category(build_step: BuildStep) -> BuildCategory:
    """
    Determine whether the build is clean or incremental

    ref. https://github.com/spotify/XCMetrics/blob/main/Sources/XCMetricsBackendLib/UploadMetrics/LogProcessing/LogParser.swift
    """
    steps = build_step.flatten()
    detail_steps = [s for s in steps if s.type == "detail"]
    n_fetched_from_cache = len([s for s in detail_steps if s.fetchedFromCache])
    if n_fetched_from_cache == len(detail_steps):
        return BuildCategory.NOOP
    elif n_fetched_from_cache / len(detail_steps) > 0.5:
        return BuildCategory.INCREMENTAL
    else:
        return BuildCategory.CLEAN


def gen_bq_record(parse_result_json: JSON) -> BQRecord:
    """
    Generate data corresponding to BigQuery table record
    """
    build_step = BuildStep.from_dict(parse_result_json)
    build_category = parse_build_category(build_step)
    return BQRecord(
        build_step.startTimestamp,
        build_step.compilationDuration,
        build_step.machineName,
        build_category.value,
        build_step.schema,
    )


def upload_to_s3(json_path: pathlib.Path):
    """
    Upload the build metrics data to AWS S3
    """
    subprocess.run(
        [
            "aws",
            "s3",
            "cp",
            str(json_path.absolute()),
            os.environ["S3_BUCKET"],
        ]
    )


def main():
    # Since Xcode will take a while to finish writing the log to the file,
    # ensuring build log file is created by waiting for a seconds
    time.sleep(3)
    os.environ["PATH"] += os.pathsep + "/opt/homebrew/bin"
    if not os.getenv("S3_BUCKET"):
        return
    dir_path = os.path.dirname(os.path.realpath(__file__))
    prj_root_dir = os.path.join(dir_path, "..")
    os.chdir(prj_root_dir)

    with tempfile.TemporaryDirectory() as tmpdir:
        suffix = datetime.now().strftime("%Y-%m-%dT%H:%M:%S")
        fpath = pathlib.Path(tmpdir) / f"xclogparser_{suffix}.json"
        with open(fpath, "w") as tmpf:
            parsed_json = get_xclogparse_json()
            bq_record = gen_bq_record(parsed_json)
            tmpf.write(json.dumps(asdict(bq_record)))
        upload_to_s3(fpath)

if __name__ == "__main__":
    main()

かいつまんでポイントを解説していくと、.xcactivitylogの解析にはXCLogParserを使用しています。 XCLogParserの解析結果をもとに、BigQueryテーブルへロードするための独自のスキーマJSONを生成します。 最終的に生成されるスキーマJSONは以下のようなものです。

{
  "start_time": 1734076111.189341,
  "compilation_duration": 148.36851501464844,
  "machine_name": "johndoe",
  "build_category": "clean",
  "scheme": "development",
  "cache_hit_ratio": 0.3643167972149695
}

"build_category"は(clean|incremental|noop)いずれかの値をとります。クリーンビルドかインクリメンタルビルドか、あるいはほぼコンパイル不要なビルドかを判定するフィールドで、これはXCLogParserの解析結果から直接得ることはできず、独自に判定しています。以下がスクリプトの抜粋になります。

def parse_build_category(build_step: BuildStep) -> BuildCategory:
    """
    Determine whether the build is clean or incremental

    ref. https://github.com/spotify/XCMetrics/blob/main/Sources/XCMetricsBackendLib/UploadMetrics/LogProcessing/LogParser.swift
    """
    steps = build_step.flatten()
    detail_steps = [s for s in steps if s.type == "detail"]
    n_fetched_from_cache = len([s for s in detail_steps if s.fetchedFromCache])
    if n_fetched_from_cache == len(detail_steps):
        return BuildCategory.NOOP
    elif n_fetched_from_cache / len(detail_steps) > 0.5:
        return BuildCategory.INCREMENTAL
    else:
        return BuildCategory.CLEAN

コードコメント内にあるように、この辺りはXCMetricsの実装を参考にしています。 XCLogParserによる解析結果は、複数のビルドステップから構成され、各ビルドステップ毎にビルドキャッシュがどれだけキャッシュヒットしているかを表す情報を含んでいます。 これを下に、「指定スキームをビルドする上で、依存するビルドターゲットの内、半数以上がキャッシュヒットしているかどうか」をもってクリーンビルドかインクリメンタルビルドかを判定するようにしています。
先ほどみてきたS3へアップロードするスキーマJSONに対応するBigQueryのテーブルスキーマは以下のようなものです。

このテーブルに対し、最終的にLookerで可視化したい内容をビューとして定義します。以下は一例です。

-- インクリメンタルビルド時間(sec)の7日間平均
WITH incremental_builds AS (
  SELECT
    DATE(start_time) AS date,
    compilation_duration
  FROM
    `<gcp_prj_id>.<bq_dataset>.<bq_table>`
  WHERE
    build_category = 'incremental'
),
daily_average AS (
  SELECT
    date,
    AVG(compilation_duration) AS daily_avg_duration
  FROM
    incremental_builds
  GROUP BY
    date
),
moving_average AS (
  SELECT
    date,
    daily_avg_duration,
    AVG(daily_avg_duration) OVER (ORDER BY date ROWS BETWEEN 6 PRECEDING AND CURRENT ROW) AS moving_avg_7d
  FROM
    daily_average
)

SELECT
  date,
  moving_avg_7d AS avg_compilation_duration_7d
FROM
  moving_average
ORDER BY
  date desc
;

-- 日毎のビルド実行回数・総ビルド時間
WITH
  daily_build_compilations AS (
    SELECT
      FORMAT_TIMESTAMP("%Y-%m-%d", start_time, "Asia/Tokyo") AS `date`
      , compilation_duration
    FROM
      `<gcp_prj_id>.<bq_dataset>.<bq_table>`
    WHERE
      compilation_duration > 0
  )

SELECT
    PARSE_DATETIME("%Y-%m-%d", date) AS `date`
    , COUNT(*) AS num_builds
    , SUM(compilation_duration) AS total_compilation_duration
FROM
    daily_build_compilations
GROUP BY
    `date`
ORDER BY
    `date`

おわりに

弊社iOSチームにおけるXcodeのビルド時間可視化の取り組みについて紹介させていただきました。 比較的ニッチなテーマだったかもしれませんが、今回の記事内容が少しでも誰かのお役に立てれば幸いです。

ところで、冒頭ご紹介したダッシュボードの中で、2024/08頃から平均インクリメンタルビルド時間が削減されている様子が伺えるかとおもいます。 この辺りのビルド時間短縮の具体的な取り組み内容についても、別の機会でご紹介できればとおもいます。