# npmの脆弱性APIが遅いとpnpm/action-setup v6が5分止まる

## 概要

pnpm/action-setup v6のSet up pnpmは、npmの脆弱性APIの応答が遅れると、遅れた末に503が返る場合も含めて、エラーを出さずに最大5分止まる。
action内部の`npm ci`が実行するaudit（依存の脆弱性の照会）が、APIの応答を待つためである。
待ちかどうかは`npm ci`の最後の行とverboseのログで判別でき、`npm_config_audit=false`を渡すか、事前に導入したpnpmを使用してaction-setupを削除すれば解消する。

## 背景

自社のself-hosted runnerで、PRのチェックの1つが約1分半から約6分に伸びた。
遅かったのはSet up pnpmで、普段は数秒から十数秒のステップが最大で約5分かかっていた。
ログにエラーはなく、`npm ci`の最後の行は`added 1 package in 5m`だった。

## action-setup v6はnpm ciでbootstrapのpnpmを導入する

この待機がv6で発生するのは、v6がpnpmの導入の途中で`npm ci`を実行するためである。
v4とv5は`npm ci`を使用しないので、bulk APIの応答の影響を受けない。

action-setup v6は、[pnpmを次の順で導入する](https://github.com/pnpm/action-setup/blob/v6.0.10/src/install-pnpm/run.ts)。

1. 作業用のディレクトリに、pnpmだけを依存とする`package.json`と`package-lock.json`を作成する。pnpm 11以下を導入する場合、Node.jsが22.13未満か`standalone: true`なら、pnpmの代わりに`@pnpm/exe`を依存にする
2. そのディレクトリで`npm ci`を実行し、一時的に使用するpnpm（以下bootstrapのpnpm）を導入する
3. v6.0.7以降はbootstrapのpnpmの`pnpm self-update <version>`で、`packageManager`などで指定したバージョンに置換する

v5までは[action自体に同梱したpnpmで`install --no-lockfile`を実行しており](https://github.com/pnpm/action-setup/blob/v5.0.0/src/install-pnpm/run.ts)、npmを使用しなかった。
v6以降はnpmの設定と挙動がこのステップの所要時間を左右する。

v6.0.7以降では手順3があるため、bootstrapのpnpmは`packageManager`のバージョンと異なれば直後に置換される。
自社の例では300秒かけて導入したbootstrapのpnpmは使用されず、`packageManager`で固定した別のバージョンに置換されていた。

## npm ciはauditの応答を待機してから終了する

bulk APIの応答が遅いとき、ステップの所要時間を左右するのはpnpmのダウンロードではなく、auditのリクエストへの応答である。
応答の内容に関係なく`npm ci`は成功扱いになる。
auditは依存の一覧（パッケージ名とバージョン）をnpmの脆弱性APIに送信し、既知の脆弱性を照会する処理だ。
送信先のエンドポイントは`/-/npm/v1/security/advisories/bulk`（以下bulk API）である。

npmの設定項目`audit`の[デフォルト値はtrue](https://docs.npmjs.com/cli/v11/using-npm/config#audit)で、auditが有効なら、`npm ci`と`npm install`はインストールのたびに依存の一覧をregistryのbulk APIへPOSTする。
このリクエストはインストールと並行して送信され、npmが応答を待機するのは[インストールの最後](https://github.com/npm/cli/blob/latest/workspaces/arborist/lib/arborist/reify.js)。
応答のヘッダを受信できない場合の上限は[`fetch-timeout`のデフォルト値の300000ms](https://docs.npmjs.com/cli/v11/using-npm/config#fetch-timeout)で、ログの`in 5m`はこの値と一致する。

auditのリクエストが失敗しても、[npmはエラーをverboseのログに記録するだけで、インストールの結果を変更しない](https://github.com/npm/cli/blob/latest/workspaces/arborist/lib/audit-report.js)。
依存が1個のインストールでも、APIの応答が遅ければその分だけ終了が遅延する。
auditのリクエストの失敗が503の応答と時間切れのどちらであっても、`npm ci`の終了コードは0になる。

```mermaid
sequenceDiagram
  participant A as pnpm/action-setup
  participant N as npm ci
  participant R as registry<br/>（tarball）
  participant B as registry<br/>（bulk API）
  participant P as bootstrapのpnpm
  A->>N: npm ci
  par インストール
    N->>R: GET tarball
    R-->>N: 200（1秒未満）
  and audit（デフォルトで有効）
    N->>B: POST 依存の一覧
  end
  alt bulk APIが健全
    B-->>N: 200（1秒未満）
    N-->>A: 終了コード0。added 1 package, and audited 2 packages in 1s
  else 遅れて応答する
    B-->>N: 200 か 503（応答までの時間だけ待つ）
    N-->>A: 終了コード0。503ならauditedの句が出ない
  else 応答のヘッダが返らない
    Note over N,B: fetch-timeout（300秒）で打ち切る
    N-->>A: 終了コード0。added 1 package in 5m
  end
  A->>P: pnpm self-update <version>（v6.0.7以降）
  Note over P: 導入したbootstrapのpnpmは<br/>packageManagerのバージョンに置換される
```

bulk APIの応答が上の3つのどの分岐でも終了コードは0で、変化するのはステップの所要時間と、最後の行の`and audited`の有無である。

bulk APIの状態ごとの`npm ci`の所要時間とログは次のとおり。

| bulk APIの応答 | npmの設定 | npm ciの所要時間 | bulk APIへのPOST | 最後の行 |
| --- | --- | ---: | ---: | --- |
| 6秒後に200 | デフォルト | 6秒 | 1回 | `added 1 package, and audited 2 packages in 6s` |
| 6秒後に503 | デフォルト | 6秒 | 1回（再試行なし） | `added 1 package in 6s` |
| 60秒後に200 | `--fetch-timeout=2000` | 2秒 | 1回 | `added 1 package in 2s` |
| 6秒後に200 | `--no-audit` | 1秒未満 | 0回 | `added 1 package in 126ms` |
| 6秒後に200 | 環境変数`npm_config_audit=false` | 1秒未満 | 0回 | `added 1 package in 125ms` |

いずれも終了コードは0である。
auditが成功したときだけ、最後の行に`and audited N packages`が付加される。

## 最後の行とverboseのログでauditの待機を判別する

遅延の原因がauditの待機かどうかは、`npm ci`の最後の行で見当がつき、verboseのログで確定する。
原因がnpm側か社内のproxyかは、runnerとproxyを経由しない場所からの計測で区別できる。

### action-setupのログでauditの待機を判別する

ログで判別する手順は`npm ci`の末尾の`and audited`の確認である。
ない場合はverboseのログの`audit error`の行、ある場合はhttpの行のbulk APIの所要時間を確認する。

Set up pnpmのログで`npm ci`の最後の行に`and audited`がなく、所要時間が数分なら、auditの待機の可能性が高い。
確定にはaction-setupのstepに環境変数`npm_config_loglevel: verbose`を設定する。
actionは[`process.env`を引き継いだ環境で`npm ci`を実行する](https://github.com/pnpm/action-setup/blob/v6.0.10/src/install-pnpm/run.ts)ため、stepの`env`に指定したnpmの設定が反映される。
リポジトリの`.npmrc`はv6では作業用のディレクトリにコピーされないので、効果がない。

```yaml
- uses: pnpm/action-setup@<sha> # v6
  env:
    npm_config_loglevel: verbose
```

bulk APIが時間切れになると、verboseのログに次の行が出力される。

```text
npm verbose audit error FetchError: network timeout at: https://registry.npmjs.org/-/npm/v1/security/advisories/bulk
```

bulk APIから応答があった場合は、ステータスと所要時間の行が出力される。
たとえば503の場合は次の行が出力される（所要時間は例）。
時間切れの場合はこの行が出力されないため、`audit error`の行で判別する。

```text
npm http fetch POST 503 https://registry.npmjs.org/-/npm/v1/security/advisories/bulk 3012ms
```

### runnerからbulk APIの所要時間を直接計測する

runnerからpackument、tarball、bulk APIの3つの所要時間を計測すると、bulk APIだけが遅いかを確認できる。
proxyを経由しない場所の計測と比較すれば、npm側か社内のproxyかも区別できる。

runnerから直接計測する場合は、npmが実際に使用するregistryを宛先として、3種類のリクエストの所要時間を比較する。
社内のミラーやproxyを経由する環境では、npmはそのregistry経由でbulk APIにPOSTする。
`registry.npmjs.org`に直接送信しても、npmと同じ条件にはならない。

```bash
REG="$(npm config get registry)"
REG="${REG%/}/"   # 末尾の / をそろえる
# packument（パッケージのメタデータ）
curl -o /dev/null -s -w '%{http_code} %{time_total}\n' "${REG}pnpm"
# tarball
curl -o /dev/null -s -w '%{http_code} %{time_total}\n' "$(npm view pnpm dist.tarball)"
# bulk API
curl -o /dev/null -s -w '%{http_code} %{time_total}\n' -X POST \
  -H 'content-type: application/json' -d "{\"pnpm\":[\"$(npm view pnpm version)\"]}" \
  "${REG}-/npm/v1/security/advisories/bulk"
```

自社のrunnerからの計測では、packument（パッケージのバージョン一覧などのメタデータ）とtarball（パッケージ本体のアーカイブ）は0.2秒前後で応答した。
bulk APIは約4分後に200で応答するか、503で応答した。
bulk APIだけが遅い状態は、npm側の障害でも、POSTだけを遅延させる社内のproxyでも起こりうる。
proxyを経由する環境では、proxyを経由しない場所からも同じリクエストを計測する。

[npmのステータスページ](https://status.npmjs.org/)にも、bulk APIの障害（「npm audits endpoint is having issues」）が掲載された。
掲載は自社での遅延の観測開始から半日ほど後で、遅延の開始時点では、ステータスページは判断材料にならなかった。

```mermaid
flowchart TD
  A[Set up pnpmが数分かかる] --> B{npm ciの最後の行に<br/>and auditedがあるか}
  B -->|ない| C{verboseのログに<br/>audit errorがあるか}
  B -->|ある| D{http の行の bulk API の<br/>所要時間が長いか}
  C -->|ある| E[auditの待ち]
  C -->|ない| F[auditが無効か照会されていない<br/>tarballの取得を調べる]
  D -->|長い| E
  D -->|短い| G{tarballの取得が遅いか}
  G -->|遅い| H[registry・proxyとの間のネットワーク]
  G -->|遅くない| I[self-update以降の処理<br/>pnpm installやキャッシュの復元]
  F --> G
  E --> J{proxyを通さない場所でも<br/>bulk APIが遅いか}
  J -->|遅い| K[npm側の障害]
  J -->|遅くない| L[社内のproxyやミラー]
```

### ジョブがtimeout-minutesでcancelledになった場合

`timeout-minutes`でジョブが先に停止すると、上の手がかりはログに出力されない。
この場合の手がかりは停止したstepの位置である。

`timeout-minutes`が短いジョブは、Set up pnpmの途中でcancelledになる。
`fetch-timeout`より前のcancelledでは、npmの最後の行もverboseの`audit error`の行も出力されない。
手がかりはcancelledになったstepがSet up pnpmであることだ。
前述のverboseのログを有効にしていれば、ログの最後の行がtarballの取得になる。

## auditの停止かaction-setupの削除で待機を解消する

対処の方法は4つあり、主にイメージの管理の有無で選択し、pnpmのバージョンとauditを維持するかも考慮する。
自社はイメージを管理しているため、同梱したpnpmを使用してaction-setupを削除した。

### auditの待機を避ける4つの方法

4つの方法の内容はauditの停止、待機時間の上限の設定、Workflowでのnpm経由の導入の回避のいずれかである。

| 方法 | 変更 | 適する場合 | 注意 |
| --- | --- | --- | --- |
| 事前に導入したpnpmを使用し、action-setupを削除する | runnerのイメージにNode.jsとpnpmを導入し、Workflowではバージョンの一致だけを検証する | runnerのイメージを自分で管理している（self-hosted runner） | イメージ、`packageManager`、検証のstepの3か所のバージョンを一致させ続ける |
| action-setupのstepに`npm_config_audit: "false"`を設定する | stepの`env`に1行追加する | イメージを管理していない（GitHub-hosted runnerなど） | action-setupを使用するすべてのstepで設定が必要（jobやworkflowの`env`でもよい）。リポジトリの`.npmrc`では停止しない |
| [pnpm/setup](https://github.com/pnpm/setup)のv2以降に移行する | actionを置換する | pnpm 11以降を使用する | v2以降はnpmを使用せず、単体のバイナリをダウンロードする。v1はnpm経由で導入する。[Intel macOS向けのpnpm 11の単体のバイナリは公開されていない](https://github.com/pnpm/action-setup#readme) |
| `npm_config_fetch_timeout`を短縮する | stepの`env`に1行追加する | auditを維持し、待機時間の上限だけを設定したい | すべてのリクエストの上限になる。tarballの取得が遅い環境では、再試行を含めて時間切れになりインストールが失敗する |

自社のWorkflowに適用したのは1番目だけである。
2番目と4番目は前節の表のとおり、bulk APIへのPOSTを停止するか、時間で中断する。
2番目で停止するのはbootstrapのpnpmの導入時のauditだけで、プロジェクトの依存の脆弱性の確認には影響しない。
action-setupの[README](https://github.com/pnpm/action-setup)は、pnpm 11以降の選択肢として3番目のpnpm/setupを案内している。

### イメージに同梱したpnpmへの切り替え

イメージがすでにpnpmを同梱していたため、変更は切り替えの条件とsetupのstepの削除だけで、ジョブの所要時間は元の水準に回復した。

1番目を採用したのはrunnerのイメージがNode.js 24と、`packageManager`と同じバージョンのpnpmをすでに同梱していたためである。
イメージでは次のDockerfileでpnpmを導入している。

```dockerfile
ARG PNPM_VERSION=<version>
RUN npm install --global "pnpm@${PNPM_VERSION}"
```

同梱のpnpmへの切り替えはRepositoryの変数を条件にしていたが、その変数が未設定で、すべてのrunでaction-setupとsetup-nodeが実行されていた。
この条件と両方のstepを削除し、次の検証のstepを無条件に実行するよう変更した。

```yaml
- name: Verify preinstalled Node.js and pnpm
  run: |
    test "$(node --version | cut -d. -f1)" = v24
    test "$(cd "$RUNNER_TEMP" && pnpm --version)" = <version>
```

変更後、遅くなっていたジョブの所要時間の中央値は約1分半に回復した。
Set up pnpmのステップが存在しないため、bulk APIの状態とは無関係になった。

### pnpm auditのstepの削除

`pnpm audit`も同じAPIに依存するため、PRのチェックからは削除し、脆弱性の確認は別の仕組みで継続する。

同じWorkflowにあった`pnpm audit --prod --audit-level=high`のstepも削除した。
pnpm 11の`pnpm audit`は[同じbulk APIを使用する](https://pnpm.io/cli/audit)ため、APIの応答が遅いとこのstepも応答を待機する（上限はpnpmの`fetchTimeout`）。
対象のproduction依存は少ない。
同じlockfileはDependabot security updatesが継続して監視しており、出荷するイメージはビルド時にTrivyでスキャンしている。
このため、PRの待ち時間を左右するジョブからは削除した。
確認を継続するならPRの待ち時間と無関係な別のジョブか定期実行への移行も選択肢になる。

## 検証のstepはpackageManagerのないディレクトリで実行する

action-setupの削除後は、イメージのpnpmのバージョンの不一致を検出できるよう、検証のstepを`packageManager`のないディレクトリで実行する。

action-setupを削除すると、pnpmのバージョンはrunnerのイメージで確定する。
ただし`packageManager`のあるディレクトリで`pnpm`を実行すると、pnpmは[`pmOnFail`のデフォルトの`download`](https://pnpm.io/settings/cli#pmonfail)に従い、宣言されたバージョンをダウンロードして実行する。
このため、そのディレクトリで`pnpm --version`を実行すると、イメージのバージョンではなく宣言されたバージョンが出力され、不一致を検出できない。
不一致があれば宣言されたバージョンのpnpmはregistryから取得される。

```mermaid
flowchart LR
  A[pnpm --version] --> B{packageManagerの<br/>ある場所か}
  B -->|ない| G[イメージの版を出力<br/>ずれを検出可能]
  B -->|ある| C{イメージの版と<br/>一致するか}
  C -->|する| D[イメージの版を出力]
  C -->|しない| E[宣言された版を<br/>取得して出力<br/>ずれは隠れる]
```

図のとおり、`packageManager`のあるディレクトリでは、イメージのバージョンがずれていても宣言どおりの値が出力される。

上の検証のstepも当初はプロジェクトのディレクトリで実行しており、不一致を検出できるよう後から`$RUNNER_TEMP`での実行に変更した。
`packageManager`のない場所で出力されるのはイメージに導入したバージョンで、stepの比較対象はこの値だ。
プロジェクトのディレクトリで実行するコマンド自体を不一致で失敗させたい場合は、`pnpm_config_pm_on_fail: error`を設定する。

### バージョンの更新の順序

検証のstepは1つのバージョンと完全一致で比較するので、更新の途中では新旧どちらのバージョンも通す形に一時的に変える。

バージョンはrunnerのイメージのDockerfile、プロジェクトの`package.json`の`packageManager`、Workflowの検証のstepの3か所に記述する。
イメージだけを先に配布すると、Workflowが旧バージョンを期待したまま新しいpnpmと比較するため、検証のstepが失敗する。
自社では、イメージの変更と同時に検証のstepを新旧両方のバージョンを受け付ける形に変え、新しいイメージの反映を確認した後で、検証のstepを新しいバージョンだけに戻した。
`packageManager`は、新しいイメージの反映後に新しいバージョンへ更新する。

```yaml
- name: Verify preinstalled Node.js and pnpm
  run: |
    test "$(node --version | cut -d. -f1)" = v24
    case "$(cd "$RUNNER_TEMP" && pnpm --version)" in
      11.5.3|11.28.5) ;;  # 旧バージョン|新バージョン
      *) echo "Unexpected pnpm version" >&2; exit 1 ;;
    esac
```