macOS統合ログでクラウドMacのビルドと署名障害を調査する

深夜の自動ビルドが突然失敗し、ターミナルには Command PhaseScriptExecution failed だけが残っていたものの、再実行すると正常に完了することがあります。この状況で最後の1行を追い続けても意味はありません。クラウドMacでは、ビルドツール、署名サービス、ネットワークプロセス、システム権限に関するイベントが、それぞれmacOS統合ログへ記録されます。これらを同じ時間軸で照合すれば、原因がプロジェクトのスクリプト、システムサービス、リモート接続の切断のいずれにあるかを判断しやすくなります。

まず障害の発生時刻と再現条件を固定する

最初に、ノードの時刻、コマンドの開始時刻、失敗時刻、終了コードを記録します。リモートクライアントに表示されるローカル時刻はノードのタイムゾーンと異なる場合があるため、調査ではノード上の時刻に統一してください。

date -u '+%Y-%m-%dT%H:%M:%SZ'
set -o pipefail
xcodebuild \
  -workspace Demo.xcworkspace \
  -scheme Demo \
  -configuration Release \
  build 2>&1 | tee "$HOME/build-output.log"
printf 'exit=%s
' "${PIPESTATUS[0]}"

すぐにDerivedDataを削除したり、プロセスを再起動したり、元のログを上書きしたりしないでください。まずビルド出力をコピーし、その後で障害が安定して再現するかを確認します。断続的に発生する問題では、少なくとも2回分の実行結果を記録し、使用したコミット、Xcodeのパス、Shell環境、作業ディレクトリが両方の実行で同一だったかも明記します。

統合ログはターミナル出力の代わりにはなりません。統合ログはシステムやサービスで何が起きたかを示し、ターミナル出力はビルドコマンドがどの段階まで実行されたかを示します。両方の記録で同じ時間範囲を使用する必要があります。

述語で統合ログの対象を絞り込む

log show は、すでに発生したイベントの確認に適しています。最初から数時間分のログをすべて書き出すと、大量のノイズが混入し、機密情報の除去にも余計な手間がかかります。失敗時刻の前後10分を対象に、まずプロセス名で絞り込みます。

log show \
  --last 20m \
  --style compact \
  --info \
  --debug \
  --predicate 'process == "xcodebuild" OR process == "codesign"'

ターミナルに署名エラーしか表示されない場合は、セキュリティサービスが返した拒否メッセージを追加で検索します。ビルド処理がリモートセッションの影響を受けている場合は、sshd と、実際にスクリプトを実行しているプロセスを確認します。述語には、できるだけ process、subsystem、category、eventMessage を使用し、ログ本文全体に対する広範な文字列検索だけに頼らないようにします。

log show --last 15m --style compact \
  --predicate '(process == "sshd") OR (eventMessage CONTAINS[c] "denied")'

代表的なシグナルは次のように解釈できますが、最終的な判断には終了コードと再現手順も含める必要があります。

再現中に重要なイベントをリアルタイムで監視する

安定して再現できる場合は、別のSSHセッションを開いて log stream を実行します。リアルタイムストリームは監視専用とし、フィルター条件を広げすぎないでください。出力が流れ続けると、重要なイベントが埋もれてしまいます。

log stream \
  --style compact \
  --level info \
  --predicate 'process == "xcodebuild" OR process == "codesign" OR process == "securityd"'

その後、元のセッションでビルドを開始し、最初の異常ログからビルド失敗までの時間差を記録します。署名エラーが先に発生し、その後ビルドツールによって一般的な失敗としてまとめられている場合は、署名処理を優先して調査します。SSHが先に切断されてもビルドプロセスが動作し続けている場合は、コンパイルエラーと誤認せず、タスクが対話型ターミナルに紐付けられていないかを確認する必要があります。

スクリプトに相関用マーカーを追加する

自社管理のスクリプトでは、開始時と終了時に統合ログへ記録を残し、固定のsubsystemと実行ごとに一意なジョブIDを使用できます。これにより、曖昧なファイル名検索に頼る必要がなくなります。

job_id="$(date -u '+%Y%m%dT%H%M%SZ')"
logger -p user.notice -t minid-build "job=$job_id phase=start"
./scripts/build.sh
status=$?
logger -p user.notice -t minid-build "job=$job_id phase=end status=$status"
exit "$status"

logger が書き込んだタグは、process またはメッセージ本文から検索できます。ジョブIDは1回の実行を関連付けるためだけに使用し、トークン、リポジトリの認証情報、顧客データを含めてはいけません。

再検証でき、安全に共有できる証拠をエクスポートする

コマンドラインのテキストは迅速な分析に適していますが、複雑な問題では .logarchive も保存してください。アーカイブを作成する前に時間範囲を再確認し、障害と無関係な過去の記録を収集しないようにします。

mkdir -p "$HOME/diagnostics"
sudo log collect \
  --last 15m \
  --output "$HOME/diagnostics/build-incident.logarchive"

cp "$HOME/build-output.log" "$HOME/diagnostics/"

ディレクトリ全体をそのまま送信してはいけません。ビルドログを確認し、展開された環境変数、プロジェクトの絶対パス、ノードのアドレス、リポジトリのアドレス、証明書名、スクリプト引数が含まれていないかを調べます。機密値を一括置換する場合は、一貫した対応関係を維持してください。たとえば、同じユーザー名は常に <USER> に置き換えます。対応関係が変わると、複数のイベントが同じアカウントに属するかを後から判断できなくなります。

UTC時刻、実行コマンド、終了コード、期待した結果、実際の結果、再現の可否、障害前に最後に成功したコミットを記載したプレーンテキストの説明も用意することを推奨します。ログは何が起きたかを証明し、説明ファイルは調査範囲を明確にします。

証拠に基づいて次の対応を決める

情報収集が完了したら、まず問題をプロジェクト、環境、接続、リソースの4種類に分類します。プロジェクトの問題は、同じコミットをクリーンな作業ディレクトリで検証できます。環境の問題では、選択されているXcode、Shellの初期化、キーチェーンの可視性を確認します。接続の問題では、セッションの切断とタスク自体の終了を区別します。リソースの問題では、ディスク空き容量、メモリプレッシャー、並行実行中のプロセスを確認します。

調査を終了する前に、最低限の受け入れ確認を実施します。同じコミットを2回連続でビルドし、終了コードがゼロであることを確認してください。署名済み成果物は codesign --verify --deep --strict で検証します。バックグラウンドタスクがSSH切断後も想定どおり完了すること、診断ディレクトリに平文のトークンが残っていないことも確認します。これらの条件がすべて同時に満たされて初めて、障害対応が完了したと判断できます。

よくある質問