CIの実行時間が伸びたり、タイムアウトでジョブが失敗したりすると、タイムアウト延長やresource_classのスケールアップで対処したくなります。ただしそれだけでは、テストやアプリケーション側の本当のボトルネックを見落とすことがあります。
今回は、デモ用にAIコーディングしていたアプリで実際に起きたCI遅延を例に、CircleCI CLI（同等のデータはCircleCI MCPでも取得可能）で実測し、仮説を検証しながら修正した手順を紹介します。
本稿のコマンドはCircleCI CLIを前提とします。事前にcircleci auth login、または環境変数CIRCLE_TOKENの設定が必要です。ジョブUUIDはジョブ詳細ページからコピーできます。
テストジョブが CPU 100%に張り付き、遅延し始める
アプリをAIコーディングしていたところ、CIの実行時間が伸び始めていることに気づきました。CircleCIのCPU利用状況を確認すると、ほとんどの時間でCPU Usageが100%に張り付いていました。
見た目だけだと、「Docker small」のようなコスト優先のリソースクラスでvCPUが足りず、アプリ成長に伴いCPUを使い切っている、という説明が自然に見えます。
CircleCI CLIでデータを取得する
より詳細に分析するため、CircleCI CLIでリソース使用状況を取得しました。同じ系統のデータはCircleCI MCP（CLI連携版）からも取得できます。
circleci job resource-usage get 7c19e993-b6eb-458d-8799-8eec4ee50e7a --json
引数のIDはジョブUUIDです。ジョブ詳細ページからコピーできます。
--jsonを付けると、次のようなJSONが得られます。
{
"id": "7c19e993-b6eb-458d-8799-8eec4ee50e7a",
"resource_class": {
"name": "small",
"cpu_count": 1,
"memory_limit_bytes": 2147483648
},
"executions": [
{
"cpu": {
"max": 1.0006455333333333,
"peak_percent_of_limit": 100.06455333333332
},
"memory": {
"max": 1802809344,
"peak_percent_of_limit": 83.9498519897461
},
"duration_seconds": 540
}
]
}
CPU使用率のピークは100.06%、メモリ使用率のピークは約84%です。メモリには余裕がある一方、CPUは上限付近まで使い切っており、負荷がCPU側に偏っています。duration_seconds: 540はジョブ全体の長さで、このあとのテストステップ単体の約378秒とは別の指標です。
続いてテストステップのログも確認します。ステップ番号はcircleci job getの結果から分かり、このジョブではTestステップが110でした。
circleci job output get 7c19e993-b6eb-458d-8799-8eec4ee50e7a --step-num 110
ログを見ると、pnpm run test（約378秒）の内側で動く3コマンドの実行時間に大きな差がありました。
PASS cdk test/vibes-wp-content-enrichment.test.ts (356.188 s)
...
Duration 4.30s (import 54%, transform 27%, tests 15%, worker 3%)
...
Duration 12.98s (import 40%, tests 39%, transform 14%, worker 6%)
コマンド別にまとめると、次のとおりです。
| コマンド | テストランナー | 実行時間 |
|---|---|---|
test:cdk |
Jest（CDK synthを含む） | 356.19秒 |
test:lambda |
Vitest | 4.30秒 |
test:unit |
Vitest | 12.98秒 |
monorepoのため、テストはランナーを分けて実行しています。内訳を見ると、壁時計時間の大半はAWS CDK向けのJestテストに集中しています。
Jestの設定を確認し、テストコードを調べる
ジョブはresource_class: small（1 vCPU）なので、まずJestが割当以上のワーカーを立ててCPU競合している可能性を疑いました。別リポジトリでVitestがワーカーを過剰に割り当てていた事例もあり、今回も同様ではないかと考えて調査しました。
しかしjest.config.jsではmaxWorkers: 2が既に固定されていました。加えてtest:cdkが実行するテストファイルは1つだけなので、Jestは実質1ワーカーしか使っておらず、この仮説には当たりませんでした。
そこでテストコード自体を見ました。対象ファイルには54個のtest()があり、各テスト直前のbeforeEachが1つ定義されています。その中ではCDKスタックのビルドを定義しています。スタックにはNodejsFunction Constructが含まれ、ビルド時にLambda関数のコードをesbuildでバンドルする処理も走ります。templateの内容を検証するだけのテストでも、beforeEachのたびにこのビルドが繰り返されていました。
beforeEachをbeforeAllに変え、効果を実測する
各test()はapp/stackを変更せず、ビルド済みtemplateを読むだけだと確認できました。一度スタックをビルドすれば足りる設計なので、beforeEachをbeforeAllへ変更します。
- beforeEach(() => {
+ beforeAll(() => {
app = new cdk.App();
stack = new VibesWpContentEnrichmentStack(app, 'TestStack');
template = Template.fromStack(stack);
});
beforeEachは各test()の直前に呼ばれ、beforeAllはそのブロック内で最初の1回だけ呼ばれます。スタックを変更しないテストなら、置き換えても判定結果は変わりません。
変更後のCIで、同じCLIコマンドを使って再計測しました。
circleci job resource-usage get ad224a03-906c-4247-8aa7-ee292d46ff9a --json
circleci job output get ad224a03-906c-4247-8aa7-ee292d46ff9a --step-num 110
pnpm run testステップは約378秒から約37秒に短縮され、内訳は次のとおりでした。
PASS cdk test/vibes-wp-content-enrichment.test.ts (14.715 s)
...
Duration 4.61s (import 56%, transform 27%, tests 14%, worker 4%)
...
Duration 13.54s (import 41%, tests 39%, transform 15%, worker 5%)
| コマンド | 修正前 | 修正後 |
|---|---|---|
test:cdk |
356.19秒 | 14.72秒 |
test:lambda |
4.30秒 | 4.61秒 |
test:unit |
12.98秒 | 13.54秒 |
ボトルネックだったtest:cdkが大きく短縮されました。
まとめ
CIが長く、CPU使用率が100%に張り付いていると、ランナーのスペック（resource_classなど）不足を疑いたくなります。今回の主因はそこではなく、beforeEachでのCDK synth（と付随するesbuildバンドル）が54回繰り返されていたことでした。AIコーディングでは、要件の抜けや認識のずれから、こうしたテスト設計が入り込むこともあります。
ジョブのリソース使用状況とステップログをCircleCI CLI（または同等のMCP）で確認すれば、思い込みをデータで反証しやすくなります。同じ手順で、スケールアップの前に実測から原因を絞り込めます。
関連リンク