From 6fa8d5cd4f0bdfbf257fae9eb2c0d65af52b0404 Mon Sep 17 00:00:00 2001 From: JUN Date: Sat, 19 Sep 2026 23:05:44 +0900 Subject: [PATCH 01/15] feat(server): opt-in bounded metrics export endpoint Add an opt-in, management-authenticated /api/metrics scrape endpoint exporting process-local aggregates (logical requests, physical sends, distinct recovery kinds per attempt, duration and TTFT histograms) in Prometheus text format v0.0.4 with closed bounded label sets. A dependency-injected recorder feeds from the existing final-request and physical-send seams (no log rescan on scrape); the owner is created once in createServeOptions and shared by all listeners. Disabled mode (the default) wires nothing and answers 404 after management authentication. Malformed config degrades to disabled at load but is rejected on management writes via a pre-schema boundary check. Documented in English and all seven locales; distinct from the durable per-request timeline work in #2366. Part of #5117 --- .../docs/fr/reference/configuration/server.md | 1 + .../docs/fr/reference/management-api.md | 1 + .../docs/ja/reference/configuration/server.md | 1 + .../docs/ja/reference/management-api.md | 1 + .../docs/ko/reference/configuration/server.md | 1 + .../docs/ko/reference/management-api.md | 1 + .../docs/reference/configuration/server.md | 2 + .../content/docs/reference/management-api.md | 15 + .../docs/ru/reference/configuration/server.md | 1 + .../docs/ru/reference/management-api.md | 1 + .../docs/tr/reference/configuration/server.md | 1 + .../docs/tr/reference/management-api.md | 1 + .../zh-cn/reference/configuration/server.md | 1 + .../docs/zh-cn/reference/management-api.md | 1 + .../zh-tw/reference/configuration/server.md | 1 + .../docs/zh-tw/reference/management-api.md | 1 + scripts/test-layout/layout.json | 1 + src/config/diagnostics.ts | 18 +- src/config/feature-flags.ts | 5 + src/config/schema/config-schema.ts | 2 + src/server/index/serve-options.ts | 27 +- src/server/index/websocket-handler.ts | 7 +- src/server/management-api.ts | 2 + src/server/management/context.ts | 3 + src/server/management/metrics-routes.ts | 20 ++ src/server/management/route-registry.ts | 4 + src/server/request-log.ts | 16 +- src/server/request-metrics.ts | 235 +++++++++++++++ src/types/config.ts | 2 + structure/config.md | 11 + structure/gui-and-management-api.md | 20 ++ tests/fixtures/test-layout-expected.json | 1 + .../server/management-metrics-export.test.ts | 276 ++++++++++++++++++ 33 files changed, 675 insertions(+), 6 deletions(-) create mode 100644 src/server/management/metrics-routes.ts create mode 100644 src/server/request-metrics.ts create mode 100644 tests/server/management-metrics-export.test.ts diff --git a/docs-site/src/content/docs/fr/reference/configuration/server.md b/docs-site/src/content/docs/fr/reference/configuration/server.md index bc5970400db..dd12ed399da 100644 --- a/docs-site/src/content/docs/fr/reference/configuration/server.md +++ b/docs-site/src/content/docs/fr/reference/configuration/server.md @@ -22,6 +22,7 @@ exécute des fonctionnalités d'assistance autour des demandes du fournisseur. | `apiKeys?` | `OcxApiKey[]` | `[]` | Identifiants `ocx_…` générés pour l'admission au plan de données sur les liaisons hors bouclage. Ils n'autorisent pas les API de gestion ; l'accès à la gestion utilise l'identifiant distinct décrit dans la [référence de l'API de gestion](/fr/reference/management-api/). Gérés depuis le tableau de bord. | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | désactivé | Politique facultative de nettoyage des sessions archivées. Elle n'est jamais activée implicitement. | | `appOwnedMemoryBudgetMb?` | `number` | `256` | Plafond en Mio pour les journaux, caches, objets binaires et charges utiles de continuation évincables qui appartiennent à l'application. Plage : 64–4096 ; il ne s'agit pas d'un plafond RSS. | +| `metricsExport.enabled?` | `boolean` | `false` | Active les métriques de requêtes agrégées, locales au processus, sur `GET /api/metrics` authentifié. Redémarrage requis ; lorsque désactivé, le chemin renvoie 404 et aucune activité d'export n'est démarrée. | | `codexAutoStart?` | `boolean` | `true` | Autorise le lanceur intermédiaire Codex à exécuter `ocx ensure` avant de démarrer Codex. Avec la valeur false, cette vérification ne fait rien. | | `codexShimAutoRestore?` | `boolean` | `true` | Restaure le lanceur intermédiaire installé après son remplacement par une mise à jour externe de Codex terminée. Désactivation par variable d'environnement : `OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`. | | `syncResumeHistory?` | `boolean` | `true` | Compatibilité historique Codex App réversible. Les métadonnées originales sont sauvegardées et restaurées par `ocx stop` / `ocx restore`. | diff --git a/docs-site/src/content/docs/fr/reference/management-api.md b/docs-site/src/content/docs/fr/reference/management-api.md index 8bd738a0c4d..9c5a23bcfed 100644 --- a/docs-site/src/content/docs/fr/reference/management-api.md +++ b/docs-site/src/content/docs/fr/reference/management-api.md @@ -145,6 +145,7 @@ Voir [Combos](/fr/guides/combos/) pour les stratégies cibles, les temps de rech | `GET /api/debug/injection-logs` | Lire un nombre limité d'entrées de débogage de l'injection du guidage | — | | `GET /api/claude/inbound-debug` | Lire l'état et les entrées du débogage entrant | — | | `GET /api/usage` | Résumer l'utilisation par période et par interface cliente ; les réponses Codex comprennent aussi une ventilation `accounts` indexée par des libellés de journalisation stables ne contenant aucune donnée personnelle | Renvoie un résumé `error: "read_failed"` si le stockage ne peut pas être lu | +| `GET /api/metrics` | Renvoyer les métriques texte Prometheus locales au processus : requêtes logiques, envois physiques, types de récupération, durée et TTFT. Les libellés sont limités au protocole, au résultat et à la classe de récupération ; aucun identifiant de requête ou d'identifiant secret n'est exporté. | 404 si `metricsExport.enabled` n'était pas vrai au démarrage ; l'authentification de gestion est obligatoire et les identifiants du plan de données ne donnent aucun accès | | `GET /api/storage` | Analyser l'utilisation du stockage Codex par catégorie | Renvoie une charge utile `error: "scan_failed"` en cas d'échec de l'analyse | | `POST /api/storage/cleanup/preview` | Prévisualiser le nettoyage des sessions archivées et renvoyer une empreinte contraignante | 400 `invalid_json` ou `invalid_percent` | | `POST /api/storage/cleanup` | Mettre en quarantaine ou supprimer définitivement l'ensemble archivé prévisualisé | 400 saisie invalide ; 409 état obsolète, occupé ou référencé ; 500 échec du système de fichiers ou de la base de données | diff --git a/docs-site/src/content/docs/ja/reference/configuration/server.md b/docs-site/src/content/docs/ja/reference/configuration/server.md index 761f7b8323c..a56c7bf9b0c 100644 --- a/docs-site/src/content/docs/ja/reference/configuration/server.md +++ b/docs-site/src/content/docs/ja/reference/configuration/server.md @@ -22,6 +22,7 @@ description: リスナー、リモート アクセス、アドミッション | `apiKeys?` | `OcxApiKey[]` | `[]` |生成された `ocx_…` データプレーン准入資格情報（非ループバック バインド向け）。管理 API の認可には使用できません。管理アクセスには [管理 API リファレンス](/ja/reference/management-api/) に記載された独立した資格情報を使用します。ダッシュボードで管理。 | | `storageCleanupPolicy?` | `StorageCleanupPolicy` |無効 |アーカイブされたセッションのクリーンアップ ポリシーをオプトインします。暗黙的に有効になることはありません。 | | `appOwnedMemoryBudgetMb?` | `number` | `256` |排除可能なアプリ所有のログ、キャッシュ、BLOB、および継続ペイロードの MiB の上限。範囲は 64 ～ 4096。 RSSキャップではありません。 | +| `metricsExport.enabled?` | `boolean` | `false` | 認証済み `GET /api/metrics` でプロセスローカルの集約リクエストメトリクスを有効にします。再起動が必要です。無効時は 404 となり、エクスポーター処理は開始されません。 | | `codexAutoStart?` | `boolean` | `true` | Codex を起動する前に、Codex シムで `ocx ensure` を実行させます。 False を指定すると、操作が行われないことが保証されます。 | | `codexShimAutoRestore?` | `boolean` | `true` |完了した外部 Codex アップデートによってインストールされたシムが置き換えられた後、インストールされているシムを復元します。環境オプトアウト: `OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`。 | | `syncResumeHistory?` | `boolean` | `true` | Codex App 履歴の互換性を元に戻すことができます。元のメタデータは `ocx stop` / `ocx restore` によってバックアップおよび復元されます。 | diff --git a/docs-site/src/content/docs/ja/reference/management-api.md b/docs-site/src/content/docs/ja/reference/management-api.md index 4398ff81180..52521cf68c4 100644 --- a/docs-site/src/content/docs/ja/reference/management-api.md +++ b/docs-site/src/content/docs/ja/reference/management-api.md @@ -124,6 +124,7 @@ Authorization: Bearer | `GET /api/debug/injection-logs` |制限付きガイダンス挿入デバッグ エントリを読み取る | — | | `GET /api/claude/inbound-debug` | Claude インバウンドのデバッグ状態とエントリを読む | — | | `GET /api/usage` |範囲とクライアント サーフェスごとの使用状況を要約する |ストレージを読み取れない場合は、`error: "read_failed"` 概要を返します。 +| `GET /api/metrics` | 論理リクエスト、物理送信、復旧種別、所要時間、TTFT のプロセスローカル Prometheus テキストメトリクスを返します。ラベルはプロトコル、結果、復旧クラスの閉じた集合のみで、リクエストや認証情報の識別子は出力しません。 | 起動時に `metricsExport.enabled` が true でなければ 404。通常の管理認証が必要で、データプレーン認証情報ではアクセスできません。 | | `GET /api/storage` |バケットごとの Codex ストレージ使用量をスキャン |スキャン失敗時に `error: "scan_failed"` ペイロードを返します。 | `POST /api/storage/cleanup/preview` |アーカイブされたセッションのクリーンアップをプレビューし、バインディング ダイジェストを返します。 400 `invalid_json` または `invalid_percent` | | `POST /api/storage/cleanup` |プレビューされたアーカイブ セットを隔離または完全に削除します。 400 無効な入力。 409 古い/ビジー/参照状態。 500 ファイルシステム/データベース障害 | diff --git a/docs-site/src/content/docs/ko/reference/configuration/server.md b/docs-site/src/content/docs/ko/reference/configuration/server.md index fcffd5690f0..72012aa7ec8 100644 --- a/docs-site/src/content/docs/ko/reference/configuration/server.md +++ b/docs-site/src/content/docs/ko/reference/configuration/server.md @@ -22,6 +22,7 @@ description: 리스너, 원격 접근, admission 키, 타임아웃, 저장소, | `apiKeys?` | `OcxApiKey[]` | `[]` | 비루프백 바인드에서 데이터 플레인 요청만 허용하는 생성된 `ocx_…` 자격 증명입니다. 관리 API는 허가하지 않으며, 관리 접근에는 [관리 API 레퍼런스](/ko/reference/management-api/)에 설명된 별도의 자격 증명을 사용합니다. 대시보드에서 관리합니다. | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | disabled | 선택적으로 활성화하는 보관 세션 정리 정책입니다. 절대 암묵적으로 활성화되지 않습니다. | | `appOwnedMemoryBudgetMb?` | `number` | `256` | 제거 가능한 앱 소유 로그, 캐시, blob, continuation payload에 대한 MiB 단위 상한입니다. 범위는 64–4096이며 RSS 상한은 아닙니다. | +| `metricsExport.enabled?` | `boolean` | `false` | 인증된 `GET /api/metrics`에서 프로세스 로컬 집계 요청 메트릭을 활성화합니다. 재시작이 필요하며, 비활성화 상태에서는 404를 반환하고 exporter 동작을 시작하지 않습니다. | | `codexAutoStart?` | `boolean` | `true` | Codex shim이 Codex를 실행하기 전에 `ocx ensure`를 돌리도록 허용합니다. `false`이면 ensure는 아무 작업도 하지 않습니다. | | `codexShimAutoRestore?` | `boolean` | `true` | 완료된 외부 Codex 업데이트가 설치된 shim을 교체한 뒤 복원합니다. 환경 변수로 끌 수 있습니다: `OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`. | | `syncResumeHistory?` | `boolean` | `true` | 되돌릴 수 있는 Codex App history 호환성입니다. 원래 메타데이터는 `ocx stop` / `ocx restore`가 백업하고 복원합니다. | diff --git a/docs-site/src/content/docs/ko/reference/management-api.md b/docs-site/src/content/docs/ko/reference/management-api.md index b2c7951e89b..0f277092406 100644 --- a/docs-site/src/content/docs/ko/reference/management-api.md +++ b/docs-site/src/content/docs/ko/reference/management-api.md @@ -128,6 +128,7 @@ Authorization: Bearer | `GET /api/debug/injection-logs` | 제한된 guidance-injection debug 항목을 읽습니다 | — | | `GET /api/claude/inbound-debug` | Claude inbound debug 상태와 항목을 읽습니다 | — | | `GET /api/usage` | 범위와 클라이언트 surface별 사용량을 요약합니다 | 저장소를 읽을 수 없으면 `error: "read_failed"` 요약을 반환합니다 | +| `GET /api/metrics` | 논리 요청, 실제 송신, 복구 종류, 소요 시간, TTFT에 대한 프로세스 로컬 Prometheus 텍스트 메트릭을 반환합니다. label은 protocol, result, recovery class의 닫힌 집합만 사용하며 요청·자격 증명 식별자는 내보내지 않습니다. | 시작 시 `metricsExport.enabled`가 true가 아니면 404; 일반 관리 인증이 필요하며 데이터 플레인 자격 증명으로는 접근할 수 없습니다 | | `GET /api/storage` | bucket별 Codex 저장소 사용량을 검사합니다 | 검사 실패 시 `error: "scan_failed"` payload를 반환합니다 | | `POST /api/storage/cleanup/preview` | archived-session cleanup을 미리 보고 binding digest를 반환합니다 | 400 `invalid_json` 또는 `invalid_percent` | | `POST /api/storage/cleanup` | 미리 본 archived set을 격리하거나 영구적으로 제거합니다 | 400 잘못된 입력; 409 오래되었음/바쁨/참조됨 상태; 500 파일 시스템/데이터베이스 실패 | diff --git a/docs-site/src/content/docs/reference/configuration/server.md b/docs-site/src/content/docs/reference/configuration/server.md index 8a596e2a966..edfe77b2a6a 100644 --- a/docs-site/src/content/docs/reference/configuration/server.md +++ b/docs-site/src/content/docs/reference/configuration/server.md @@ -27,7 +27,9 @@ runs helper features around provider requests. | `apiKeys?` | `OcxApiKey[]` | `[]` | Generated `ocx_…` data-plane admission credentials on non-loopback binds. They do not authorize management APIs; management access uses the separate credential documented in the [management reference](/reference/management-api/). Dashboard-managed. | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | disabled | Opt-in archived-session cleanup policy. Never enabled implicitly. | | `appOwnedMemoryBudgetMb?` | `number` | `256` | Cap in MiB for evictable app-owned logs, caches, blobs, and continuation payloads. Range 64–4096; not an RSS cap. | +| `metricsExport.enabled?` | `boolean` | `false` | Enable process-local aggregate request metrics at authenticated `GET /api/metrics`. Restart required; disabled mode returns 404 and starts no exporter activity. | | `spend?` | `{ root?: { maxTokens?: number }; identity?: { maxTokens?: number }; pool?: { maxTokens?: number }; retentionDays?: number }` | unset | Durable token ceilings, off unless you write one. Each scope bounds settled spend plus in-flight reservations plus unresolved spend: `root` is one task including its whole fan-out, `identity` is one account across every task it serves, and `pool` is one provider pool. They intersect, so a request is admitted only when all three have room — which is what holds a ceiling against a client that mints a new task id per request. A reservation is the request's whole input plus its enforceable output ceiling, counted as if every cached prefix misses. Observe-only mode still journals, so every server owns the state directory's single-writer lease; an explicit sibling must use a separate `OPENCODEX_HOME`. Spend survives an ordinary process restart when its writes reached the filesystem, but the journal does not promise survival across host power loss because each append is not fsynced. Raising or removing the value is what grants more. `maxTokens` must be a positive integer (0 would refuse everything), `retentionDays` is 1–365 and defaults to 7, and an unknown key in this section is rejected rather than ignored. A refusal is a local HTTP 429 carrying `x-opencodex-local-refusal: workflow_spend_exhausted`, and its message names the scope and the ceiling; no provider is contacted. | + | `codexAutoStart?` | `boolean` | `true` | Let the Codex shim run `ocx ensure` before launching Codex. False makes ensure a no-op. | | `codexShimAutoRestore?` | `boolean` | `true` | Restore an installed shim after a completed external Codex update replaces it. Environment opt-out: `OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`. | | `codexDesktopAuthless?` | `boolean` | `false` | Opt-in authless Codex Desktop routing on a loopback bind: inject the dedicated `opencodex` provider with `requires_openai_auth = false` so Desktop opens without a ChatGPT login. Ignored on non-loopback binds. `ocx system settings --desktop-authless on`. See [Codex integration](/guides/codex-integration/#authless-codex-desktop-opt-in). | diff --git a/docs-site/src/content/docs/reference/management-api.md b/docs-site/src/content/docs/reference/management-api.md index d03a78f5f42..3a30ed72c8f 100644 --- a/docs-site/src/content/docs/reference/management-api.md +++ b/docs-site/src/content/docs/reference/management-api.md @@ -220,6 +220,7 @@ by the current window size. | `GET /api/debug/injection-logs` | Read bounded guidance-injection debug entries | — | | `GET /api/claude/inbound-debug` | Read Claude inbound debug state and entries | — | | `GET /api/usage` | Scan the usage ledger into compact aggregates of readable rows, then incrementally fold verified appends; summarize by preset or inclusive custom window and client surface, with a Codex `accounts` breakdown keyed by stable non-PII log labels | 400 invalid custom bounds; returns an `error: "read_failed"` summary if storage cannot be read | +| `GET /api/metrics` | Return process-local Prometheus text metrics for logical requests, physical sends, recovery kinds, duration, and TTFT. Labels are closed to protocol, result, and recovery class; request and credential identifiers are never exported. | 404 when `metricsExport.enabled` was not true at startup; ordinary management authentication is required and data-plane credentials grant no access | | `GET /api/storage` | Scan Codex storage usage by bucket | Returns an `error: "scan_failed"` payload on scan failure | | `POST /api/storage/cleanup/preview` | Preview archived-session cleanup and return a binding digest | 400 `invalid_json` or `invalid_percent` | | `POST /api/storage/cleanup` | Quarantine or permanently remove the previewed archived set | 400 invalid input; 409 stale/busy/referenced state; 500 filesystem/database failure | @@ -230,6 +231,20 @@ by the current window size. | `POST /api/storage/cleanup-policy/run` | Start a manual cleanup-policy run | 409 `already_running`; 500 `cleanup_failed` | | `GET /api/storage/cleanup-policy/test-stream` | Test-only policy stream hook | 404 `not_found` when unavailable | +`GET /api/metrics` returns `Content-Type: text/plain;version=0.0.4`. Counters and histograms +reset when the process restarts; `opencodex_metrics_process_start_time_seconds` identifies that +boundary. Histogram buckets are cumulative and end with `le="+Inf"`, equal to the family count. + +| Metric family | Labels | Meaning | +| --- | --- | --- | +| `opencodex_logical_requests_total` | `protocol`, `result` | One observation per finalized logical request. | +| `opencodex_physical_sends_total` | `protocol` | Actual upstream sends summed from finalized attempts. | +| `opencodex_recoveries_total` | `protocol`, `recovery` | Distinct recovery kinds observed per attempt, projected to a closed class. | +| `opencodex_request_duration_seconds` | `protocol`, `result` | Fixed-bucket duration histogram for finalized requests. | +| `opencodex_ttft_seconds` | `protocol`, `result` | Fixed-bucket TTFT histogram for requests with observed first output. | +| `opencodex_ttft_missing_total` | `protocol`, `result` | Complementary count for requests without observed TTFT. | +| `opencodex_metrics_process_start_time_seconds` | none | Process-local reset boundary. | + If a scanned row exceeds the existing parser size limit, `GET /api/usage` and `GET /api/keys` keep the readable-row aggregates and add `usageIncomplete: true` with `usageIncompleteReason: "oversized_rows"` at response level. This diagnostic survives cached diff --git a/docs-site/src/content/docs/ru/reference/configuration/server.md b/docs-site/src/content/docs/ru/reference/configuration/server.md index 9239c896062..e7e5b142319 100644 --- a/docs-site/src/content/docs/ru/reference/configuration/server.md +++ b/docs-site/src/content/docs/ru/reference/configuration/server.md @@ -23,6 +23,7 @@ description: Listener, удалённый доступ, admission key, тайм | `apiKeys?` | `OcxApiKey[]` | `[]` | Сгенерированные credentials `ocx_…` для data-plane admission на не-loopback bind'ах. Они не авторизуют management API; доступ к management использует отдельный credential, описанный в [management reference](/ru/reference/management-api/). Управляются через дашборд. | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | disabled | Opt-in policy очистки архивированных сессий. Никогда не включается неявно. | | `appOwnedMemoryBudgetMb?` | `number` | `256` | Лимит в MiB для eviction-friendly app-owned log'ов, cache'ей, blob'ов и continuation payload'ов. Это не RSS-cap. Диапазон 64–4096. | +| `metricsExport.enabled?` | `boolean` | `false` | Включает локальные для процесса агрегированные метрики запросов на аутентифицированном `GET /api/metrics`. Требуется перезапуск; в выключенном состоянии маршрут возвращает 404 и экспортёр не запускает никакой активности. | | `codexAutoStart?` | `boolean` | `true` | Разрешает shim'у Codex запускать `ocx ensure` перед стартом Codex. При false `ensure` становится no-op. | | `codexShimAutoRestore?` | `boolean` | `true` | Восстанавливает установленный shim после завершённого внешнего обновления Codex, которое заменило его. Для отключения через окружение: `OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`. | | `syncResumeHistory?` | `boolean` | `true` | Обратимый режим совместимости истории Codex App. Исходные metadata резервируются и восстанавливаются через `ocx stop` / `ocx restore`. | diff --git a/docs-site/src/content/docs/ru/reference/management-api.md b/docs-site/src/content/docs/ru/reference/management-api.md index 978744bbb0d..a4c78d53288 100644 --- a/docs-site/src/content/docs/ru/reference/management-api.md +++ b/docs-site/src/content/docs/ru/reference/management-api.md @@ -146,6 +146,7 @@ GUI-сессия в стиле loopback не выпускается. | `GET /api/debug/injection-logs` | Прочитать ограниченные guidance-injection debug-записи | — | | `GET /api/claude/inbound-debug` | Прочитать состояние и записи Claude inbound debug | — | | `GET /api/usage` | Сводка usage по диапазону и client surface | При сбое чтения storage вернёт summary с `error: "read_failed"` | +| `GET /api/metrics` | Вернуть локальные для процесса текстовые метрики Prometheus: логические запросы, физические отправки, виды восстановления, длительность и TTFT. Метки ограничены закрытыми наборами protocol, result и recovery class; идентификаторы запросов и учётных данных не экспортируются. | 404, если `metricsExport.enabled` не был true при запуске; требуется обычная management-аутентификация, data-plane credentials доступа не дают | | `GET /api/storage` | Просканировать использование storage Codex по bucket'ам | При ошибке scan вернёт payload с `error: "scan_failed"` | | `POST /api/storage/cleanup/preview` | Предпросмотр cleanup archived-session и возврат binding digest | 400 `invalid_json` or `invalid_percent` | | `POST /api/storage/cleanup` | Поместить preview'нутый архивный набор в quarantine или удалить его навсегда | 400 invalid input; 409 stale/busy/referenced state; 500 filesystem/database failure | diff --git a/docs-site/src/content/docs/tr/reference/configuration/server.md b/docs-site/src/content/docs/tr/reference/configuration/server.md index 1f67f9c2aea..d55e6001e2f 100644 --- a/docs-site/src/content/docs/tr/reference/configuration/server.md +++ b/docs-site/src/content/docs/tr/reference/configuration/server.md @@ -23,6 +23,7 @@ yardımcı özellikleri nasıl çalıştıracağını kontrol eder. | `apiKeys?` | `OcxApiKey[]` | `[]` | Geri döngü olmayan bağlamalarda veri düzlemi kabulü için oluşturulmuş `ocx_…` kimlik bilgileri. Yönetim API'lerini yetkilendirmezler; yönetim erişimi [yönetim API referansında](/tr/reference/management-api/) açıklanan ayrı kimlik bilgisini kullanır. Kontrol paneli tarafından yönetilir. | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | devre dışı | İsteğe bağlı arşivlenmiş oturum temizleme politikası. Asla örtük olarak etkinleştirilmez. | | `appOwnedMemoryBudgetMb?` | `number` | `256` | Çıkarılabilir uygulamaya ait günlükler, önbellekler, bloblar ve devam yükleri için MiB cinsinden sınır. Aralık 64–4096; bir RSS sınırı değildir. | +| `metricsExport.enabled?` | `boolean` | `false` | Kimliği doğrulanmış `GET /api/metrics` üzerinde süreç yerel toplu istek metriklerini etkinleştirir. Yeniden başlatma gerekir; devre dışıyken yol 404 döndürür ve dışa aktarıcı etkinliği başlamaz. | | `codexAutoStart?` | `boolean` | `true` | Codex dolgusunun Codex'i başlatmadan önce `ocx ensure` çalıştırmasına izin verin. False, ensure'ı bir işlem yapmayan (no-op) hale getirir. | | `codexShimAutoRestore?` | `boolean` | `true` | Tamamlanan harici bir Codex güncellemesi değiştirdikten sonra kurulu bir dolguyu geri yükleyin. Ortam vazgeçmesi: `OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`. | | `syncResumeHistory?` | `boolean` | `true` | Tersine çevrilebilir Codex App geçmişi uyumluluğu. Orijinal meta veriler yedeklenir ve `ocx stop` / `ocx restore` tarafından geri yüklenir. | diff --git a/docs-site/src/content/docs/tr/reference/management-api.md b/docs-site/src/content/docs/tr/reference/management-api.md index 354310f01ef..e2c0a962787 100644 --- a/docs-site/src/content/docs/tr/reference/management-api.md +++ b/docs-site/src/content/docs/tr/reference/management-api.md @@ -153,6 +153,7 @@ Hedef stratejileri, soğuma süreleri, takma adlar ve yönlendirme hataları iç | `GET /api/debug/injection-logs` | Sınırlı rehberlik enjeksiyonu hata ayıklama girdilerini okuyun | — | | `GET /api/claude/inbound-debug` | Claude gelen hata ayıklama durumunu ve girdilerini okuyun | — | | `GET /api/usage` | Kullanımı aralığa ve istemci yüzeyine göre özetleyin; Codex yanıtları ayrıca kararlı PII olmayan günlük etiketlerine göre anahtarlanan bir `accounts` dökümü içerir | Depolama okunamıyorsa bir `error: "read_failed"` özeti döndürür | +| `GET /api/metrics` | Mantıksal istekler, fiziksel gönderimler, kurtarma türleri, süre ve TTFT için süreç yerel Prometheus metin metriklerini döndürür. Etiketler kapalı protokol, sonuç ve kurtarma sınıfı kümeleriyle sınırlıdır; istek veya kimlik bilgisi tanımlayıcıları dışa aktarılmaz. | Başlangıçta `metricsExport.enabled` true değilse 404; olağan yönetim kimlik doğrulaması gerekir ve veri düzlemi kimlik bilgileri erişim sağlamaz | | `GET /api/storage` | Sepete göre Codex depolama kullanımını tarayın | Tarama hatasında bir `error: "scan_failed"` yükü döndürür | | `POST /api/storage/cleanup/preview` | Arşivlenmiş oturum temizliğini önizleyin ve bağlayıcı bir özet döndürün | 400 `invalid_json` veya `invalid_percent` | | `POST /api/storage/cleanup` | Önizlenen arşivlenmiş kümeyi karantinaya alın veya kalıcı olarak kaldırın | 400 geçersiz girdi; 409 eski/meşgul/başvurulan durum; 500 dosya sistemi/veritabanı hatası | diff --git a/docs-site/src/content/docs/zh-cn/reference/configuration/server.md b/docs-site/src/content/docs/zh-cn/reference/configuration/server.md index 03d689861bd..618bafc1d5c 100644 --- a/docs-site/src/content/docs/zh-cn/reference/configuration/server.md +++ b/docs-site/src/content/docs/zh-cn/reference/configuration/server.md @@ -23,6 +23,7 @@ description: 监听、远程访问、准入密钥、超时、存储、侧车、 | `apiKeys?` | `OcxApiKey[]` | `[]` | 生成的 `ocx_…` 数据平面准入凭据（用于非回环绑定）。它们不授权管理 API；管理访问使用[管理 API 参考](/zh-cn/reference/management-api/)中说明的独立凭据。由仪表板管理。 | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | disabled | 可选启用的归档会话清理策略。不会被隐式启用。 | | `appOwnedMemoryBudgetMb?` | `number` | `256` | 可逐出应用自有日志、缓存、blob 和续传载荷的内存上限，单位 MiB。范围 64–4096；不是 RSS 上限。 | +| `metricsExport.enabled?` | `boolean` | `false` | 在经过认证的 `GET /api/metrics` 上启用进程本地的请求聚合指标。需要重启；禁用时该路径返回 404，且不会启动任何导出活动。 | | `codexAutoStart?` | `boolean` | `true` | 允许 Codex shim 在启动 Codex 之前运行 `ocx ensure`。设为 false 会让 ensure 变成无操作。 | | `codexShimAutoRestore?` | `boolean` | `true` | 在完成外部 Codex 更新并覆盖安装的 shim 之后恢复该 shim。环境退出开关：`OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`。 | | `syncResumeHistory?` | `boolean` | `true` | 可逆的 Codex App 历史兼容性。原始元数据会被备份，并由 `ocx stop` / `ocx restore` 恢复。 | diff --git a/docs-site/src/content/docs/zh-cn/reference/management-api.md b/docs-site/src/content/docs/zh-cn/reference/management-api.md index 480accdf331..b6fc1006e3b 100644 --- a/docs-site/src/content/docs/zh-cn/reference/management-api.md +++ b/docs-site/src/content/docs/zh-cn/reference/management-api.md @@ -128,6 +128,7 @@ Authorization: Bearer | `GET /api/debug/injection-logs` | 读取有上限的 guidance-injection 调试条目 | — | | `GET /api/claude/inbound-debug` | 读取 Claude 入站调试状态和条目 | — | | `GET /api/usage` | 按范围和客户端界面汇总使用情况 | 若无法读取存储，则返回带有 `error: "read_failed"` 的摘要 | +| `GET /api/metrics` | 返回进程本地的 Prometheus 文本指标，涵盖逻辑请求、实际发送、恢复类型、持续时间和 TTFT。标签仅使用协议、结果和恢复类别的封闭集合；绝不导出请求或凭据标识。 | 启动时 `metricsExport.enabled` 不为 true 则返回 404；需要普通管理认证，数据平面凭据不能访问 | | `GET /api/storage` | 按桶扫描 Codex 存储使用情况 | 扫描失败时返回带有 `error: "scan_failed"` 的载荷 | | `POST /api/storage/cleanup/preview` | 预览已归档会话清理并返回绑定摘要 | 400 `invalid_json` 或 `invalid_percent` | | `POST /api/storage/cleanup` | 隔离或永久移除预览出的归档集合 | 400 输入无效；409 过期/忙碌/被引用状态；500 文件系统/数据库失败 | diff --git a/docs-site/src/content/docs/zh-tw/reference/configuration/server.md b/docs-site/src/content/docs/zh-tw/reference/configuration/server.md index ab4da87099f..cfb61730e72 100644 --- a/docs-site/src/content/docs/zh-tw/reference/configuration/server.md +++ b/docs-site/src/content/docs/zh-tw/reference/configuration/server.md @@ -21,6 +21,7 @@ description: 監聽器、遠端存取、許可金鑰、逾時、儲存、sidecar | `apiKeys?` | `OcxApiKey[]` | `[]` | 生成的 `ocx_…` data-plane 准入憑證（用於非回送綁定）。它們不授權管理 API；管理存取使用[管理 API 參考](/zh-tw/reference/management-api/)中說明的獨立憑證。由儀表板管理。 | | `storageCleanupPolicy?` | `StorageCleanupPolicy` | 停用 | 選擇加入的已封存 session 清理政策。永不隱含啟用。 | | `appOwnedMemoryBudgetMb?` | `number` | `256` | 以 MiB 為單位、可被驅逐的 app 擁有日誌、快取、blob 與 continuation payload 上限。範圍 64–4096；非 RSS 上限。 | +| `metricsExport.enabled?` | `boolean` | `false` | 在已驗證的 `GET /api/metrics` 啟用程序本機的彙總請求指標。需要重新啟動；停用時路徑回傳 404，且不會啟動任何匯出活動。 | | `codexAutoStart?` | `boolean` | `true` | 讓 Codex shim 在啟動 Codex 前執行 `ocx ensure`。False 使 ensure 為 no-op。 | | `codexShimAutoRestore?` | `boolean` | `true` | 在完成的外部 Codex 更新取代已安裝的 shim 後還原它。環境退出：`OPENCODEX_CODEX_SHIM_AUTO_RESTORE=0`。 | | `syncResumeHistory?` | `boolean` | `true` | 可逆的 Codex App 歷史相容性。原始中繼資料由 `ocx stop` / `ocx restore` 備份並還原。 | diff --git a/docs-site/src/content/docs/zh-tw/reference/management-api.md b/docs-site/src/content/docs/zh-tw/reference/management-api.md index 4342a698e06..353b09305e8 100644 --- a/docs-site/src/content/docs/zh-tw/reference/management-api.md +++ b/docs-site/src/content/docs/zh-tw/reference/management-api.md @@ -124,6 +124,7 @@ Session 簽發在需要 data-plane 認證時停用，這包含遠端綁定。遠 | `GET /api/debug/injection-logs` | 讀取有界的 guidance-injection 除錯項目 | — | | `GET /api/claude/inbound-debug` | 讀取 Claude inbound 除錯狀態與項目 | — | | `GET /api/usage` | 依範圍與客戶端介面摘要用量 | 若儲存無法讀取則回傳 `error: "read_failed"` 摘要 | +| `GET /api/metrics` | 回傳程序本機的 Prometheus 文字指標，涵蓋邏輯請求、實際傳送、復原種類、持續時間與 TTFT。標籤僅使用 protocol、result 與 recovery class 的封閉集合；絕不匯出請求或憑證識別碼。 | 啟動時 `metricsExport.enabled` 不為 true 則回傳 404；需要一般管理驗證，資料平面憑證不能存取 | | `GET /api/storage` | 依 bucket 掃描 Codex 儲存用量 | 掃描失敗時回傳 `error: "scan_failed"` payload | | `POST /api/storage/cleanup/preview` | 預覽已封存 session 清理並回傳綁定摘要 | 400 `invalid_json` 或 `invalid_percent` | | `POST /api/storage/cleanup` | 隔離或永久移除預覽的已封存集合 | 400 無效輸入；409 過時／忙碌／被參照狀態；500 檔案系統／資料庫失敗 | diff --git a/scripts/test-layout/layout.json b/scripts/test-layout/layout.json index ac1a90a8c17..a5c3b6a1d69 100644 --- a/scripts/test-layout/layout.json +++ b/scripts/test-layout/layout.json @@ -924,6 +924,7 @@ "main-quota-provenance.test.ts": "codex-integration", "main-quota-window-observation.test.ts": "codex-integration", "management-api-logs-metrics.test.ts": "server", + "management-metrics-export.test.ts": "server", "management-client-config-route.test.ts": "server", "management-integration-journal-delete.test.ts": "server", "management-integration-routes.test.ts": "server", diff --git a/src/config/diagnostics.ts b/src/config/diagnostics.ts index b3904dfb0ad..1c7b1941b6a 100644 --- a/src/config/diagnostics.ts +++ b/src/config/diagnostics.ts @@ -561,6 +561,21 @@ function managementIngressConfigError(value: unknown): string | null { return null; } +/** Load degrades malformed metrics export config to off; live writes reject the same shape. */ +export function metricsExportConfigError(value: unknown): string | null { + const raw = rawConfigRecord(value); + if (!raw || !Object.hasOwn(raw, "metricsExport") || raw.metricsExport === undefined) return null; + const metricsExport = rawConfigRecord(raw.metricsExport); + if (!metricsExport) return "schema_invalid: metricsExport: must be an object or omitted"; + if (Object.keys(metricsExport).some(key => key !== "enabled")) { + return "schema_invalid: metricsExport: contains an unsupported field"; + } + if (metricsExport.enabled !== undefined && typeof metricsExport.enabled !== "boolean") { + return "schema_invalid: metricsExport.enabled: must be a boolean"; + } + return null; +} + export function validateConfigCandidate(value: unknown): { ok: true; config: OcxConfig } | { ok: false; error: string } { const boundaryError = configReasoningPinsConfigError(value) ?? blankHostnameError(value) @@ -586,7 +601,8 @@ export function validateConfigCandidate(value: unknown): { ok: true; config: Ocx ?? clientConnectionConfigError(value) ?? clientRolePairError(value) ?? loopbackListenerPortError(value) - ?? managementIngressConfigError(value); + ?? managementIngressConfigError(value) + ?? metricsExportConfigError(value); if (boundaryError) return { ok: false, error: boundaryError }; const result = configSchema.safeParse(value); if (result.success) { diff --git a/src/config/feature-flags.ts b/src/config/feature-flags.ts index 01d60adbf2b..df418ece637 100644 --- a/src/config/feature-flags.ts +++ b/src/config/feature-flags.ts @@ -12,6 +12,11 @@ export function ultraFastTierEnabled(config: Pick): return config.ultraFastTier === true; } +/** Default-off aggregate request metrics; activation is fixed for one server process lifetime. */ +export function metricsExportEnabled(config: Pick): boolean { + return config.metricsExport?.enabled === true; +} + /** * Default cadence for the opt-in catalog auto-refresh (issue #3630): one converge pass * per hour. Each pass spends a live /models call against every enabled provider, and diff --git a/src/config/schema/config-schema.ts b/src/config/schema/config-schema.ts index 94844bf4ec0..1fea16b9704 100644 --- a/src/config/schema/config-schema.ts +++ b/src/config/schema/config-schema.ts @@ -73,6 +73,8 @@ export const configSchema = z.object({ // A malformed privacy block must never be read as "unmask": .catch(undefined) drops it and // emailMaskingEnabled then falls back to masked, which is also what an absent block means. privacy: z.object({ maskEmails: z.boolean().optional() }).strict().optional().catch(undefined), + // Malformed hand edits disable this opt-in exporter. Live writes reject them in diagnostics.ts. + metricsExport: z.object({ enabled: z.boolean().optional() }).strict().optional().catch(undefined), // A malformed present client block must remain diagnosable from raw config and // fail closed through src/client/state.ts; unrelated provider state still loads. client: clientConnectionSchema.optional().catch(undefined), diff --git a/src/server/index/serve-options.ts b/src/server/index/serve-options.ts index 5bcbb60a5ef..a98cc89e757 100644 --- a/src/server/index/serve-options.ts +++ b/src/server/index/serve-options.ts @@ -37,6 +37,7 @@ import { type WsData, } from "../ws-bridge"; import { websocketsEnabled } from "../../config"; +import { metricsExportEnabled } from "../../config/feature-flags"; import { grokDefaultReasoningEffort } from "../../grok/effort"; import { OPENAI_CODEX_PROVIDER_ID } from "../../providers/openai-tiers"; import { providerCodexAccountMode } from "../../providers/registry"; @@ -84,6 +85,7 @@ import { } from "../request-log"; import { sessionLaneIdFromRequest } from "../request-log-conversation"; import { responseWithDeferredRequestLog } from "../relay"; +import { createRequestMetricsOwner } from "../request-metrics"; import { corsHeaders, managementCorsHeaders, @@ -266,6 +268,11 @@ export function createServeOptions(ctx: ServeOptionsContext) { port, } = ctx; void port; + const requestMetrics = metricsExportEnabled(config) ? createRequestMetricsOwner() : undefined; + const requestMetricsLogContext = requestMetrics ? { requestMetricsRecorder: requestMetrics } : {}; + const requestManagementApiDeps: ManagementApiDeps = requestMetrics + ? { ...managementApiDeps, requestMetrics: { snapshot: () => requestMetrics.snapshot() } } + : managementApiDeps; const serveOptions = { idleTimeout: 255, // Bun rejects an oversized body before `fetch` runs, so the listener has to be raised @@ -616,7 +623,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { }), req, config); } } - const mgmtResponse = await handleManagementAPI(req, url, config, managementApiDeps, principal, managementSessionControl); + const mgmtResponse = await handleManagementAPI(req, url, config, requestManagementApiDeps, principal, managementSessionControl); if (mgmtResponse) return withManagementCors(mgmtResponse, req, config); return withManagementCors(formatErrorResponse(404, "not_found", `Unknown endpoint: ${req.method} ${url.pathname}`), req, config); } @@ -1197,6 +1204,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "unknown", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), inboundProtocol: "responses", }; @@ -1233,6 +1241,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "image_gen", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), }; const endpoint = url.pathname.endsWith("/edits") ? "edits" as const : "generations" as const; @@ -1290,6 +1299,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "context_history", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), }; return runAdmittedHttpTurn(req, policy, async turnAdmissionLease => { @@ -1316,6 +1326,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "web_search", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), }; return runAdmittedHttpTurn(req, policy, async turnAdmissionLease => { @@ -1340,6 +1351,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "unknown", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), inboundProtocol: "responses", }; @@ -1414,6 +1426,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "unknown", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), inboundProtocol: "messages", }; @@ -1443,6 +1456,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "unknown", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), inboundProtocol: "chat", }; @@ -1466,7 +1480,12 @@ export function createServeOptions(ctx: ServeOptionsContext) { } const start = Date.now(); const requestId = nextRequestLogId(start); - const logCtx: RequestLogContext = { model: TRANSCRIPTION_MODEL, provider: "unknown", ...admissionFields(admission) }; + const logCtx: RequestLogContext = { + model: TRANSCRIPTION_MODEL, + provider: "unknown", + ...requestMetricsLogContext, + ...admissionFields(admission), + }; return runAdmittedHttpTurn(req, policy, async lease => { const response = await handleAudioTranscriptions(req, config, logCtx, admission, lease); addFinalRequestLog(requestId, start, logCtx, response.status); @@ -1497,6 +1516,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "gpt-live", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), }; return runAdmittedHttpTurn(req, policy, async turnAdmissionLease => { @@ -1544,6 +1564,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "gpt-live", provider: "unknown", + ...requestMetricsLogContext, ...admissionFields(admission), }; const turnAdmissionLease = tryAdmitTurn(sessionLaneIdFromRequest(req.headers)); @@ -1760,7 +1781,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { return withCors(formatErrorResponse(404, "not_found", `Unknown endpoint: ${req.method} ${url.pathname}`), req, config); }, - websocket: createWebsocketHandler(ctx), + websocket: createWebsocketHandler(ctx, requestMetrics), } as const; return serveOptions; } diff --git a/src/server/index/websocket-handler.ts b/src/server/index/websocket-handler.ts index 17fbb6e30be..3022e62c4a3 100644 --- a/src/server/index/websocket-handler.ts +++ b/src/server/index/websocket-handler.ts @@ -85,13 +85,17 @@ import { resolveLiveSidebandUpgrade, } from "../live"; import type { ServeOptionsContext } from "./serve-options"; +import type { RequestMetricsRecorder } from "../request-metrics"; /** * The WebSocket half of the Bun.serve options, split out of serve-options.ts to keep that file * under the 2,000-line ratchet threshold. The body is the original handler verbatim; it reads the * same startServer context the HTTP half does, so it takes the same context object. */ -export function createWebsocketHandler(ctx: ServeOptionsContext) { +export function createWebsocketHandler( + ctx: ServeOptionsContext, + requestMetricsRecorder?: RequestMetricsRecorder, +) { const { config, deps } = ctx; return { maxPayloadLength: MAX_WS_FRAME_BYTES, @@ -283,6 +287,7 @@ export function createWebsocketHandler(ctx: ServeOptionsContext) { const logCtx: RequestLogContext = { model: "unknown", provider: "unknown", + ...(requestMetricsRecorder ? { requestMetricsRecorder } : {}), ...(wsAdmission ? admissionFields(wsAdmission) : {}), inboundProtocol: "responses", }; diff --git a/src/server/management-api.ts b/src/server/management-api.ts index bf1ccd7d144..7c8766367c2 100644 --- a/src/server/management-api.ts +++ b/src/server/management-api.ts @@ -63,6 +63,7 @@ import { handleLogsUsageRoutes } from "./management/logs-usage-routes"; import { handleStorageLogGuardRoutes } from "./management/storage-log-guard-routes"; import { handleRequestHistoryRoutes } from "./management/request-history-routes"; import { handleRoutingAnalyticsRoutes } from "./management/routing-analytics-routes"; +import { handleMetricsRoutes } from "./management/metrics-routes"; import { handleProviderRoutes } from "./management/provider-routes"; import { handleModelRoutes } from "./management/model-routes"; import { handleAgentSettingsRoutes } from "./management/agent-settings-routes"; @@ -276,6 +277,7 @@ export async function handleManagementAPI( ?? (await handleQuotaResetRoutesOnDemand(ctx)) ?? (await handleWorkflowBudgetRoutesOnDemand(ctx)) ?? (await handleGrokCouponRoutesOnDemand(ctx)) + ?? handleMetricsRoutes(ctx) ?? (await handleRoutingAnalyticsRoutes(ctx)) ?? (await handleRoutingProfileRoutesOnDemand(ctx)) ?? (await handleProviderRoutes(ctx)) diff --git a/src/server/management/context.ts b/src/server/management/context.ts index cb0e1185f8a..7adee1a781c 100644 --- a/src/server/management/context.ts +++ b/src/server/management/context.ts @@ -19,6 +19,7 @@ import type { performCodexRestart, readCodexAppServerState, } from "../../codex/app-server-restart-service"; +import type { RequestMetricsSnapshotter } from "../request-metrics"; import type { RemoteWorkspaceHub } from "../../remote-control/workspace-hub"; import type { RemoteWorkspaceSessionService } from "../../remote-control/workspace-sessions"; @@ -31,6 +32,8 @@ export type RemoteWorkspaceSessionsApi = Pick; export interface ManagementApiDeps { + /** Read-only process-local aggregate metrics; absent keeps the scrape route unavailable. */ + requestMetrics?: RequestMetricsSnapshotter; remoteWorkspaceHub?: RemoteWorkspaceHubApi; remoteWorkspaceSessions?: RemoteWorkspaceSessionsApi; /** The listener retains and awaits teardown only after this optional subsystem activates. */ diff --git a/src/server/management/metrics-routes.ts b/src/server/management/metrics-routes.ts new file mode 100644 index 00000000000..5c5f867d312 --- /dev/null +++ b/src/server/management/metrics-routes.ts @@ -0,0 +1,20 @@ +import type { ManagementContext } from "./context"; + +export function handleMetricsRoutes(ctx: ManagementContext): Response | null { + if (ctx.url.pathname === "/api/metrics" && ctx.req.method === "GET") { + if (!ctx.deps.requestMetrics) { + return Response.json({ error: { code: "not_found", message: "metrics export is disabled" } }, { + status: 404, + headers: { "Cache-Control": "no-store" }, + }); + } + return new Response(ctx.deps.requestMetrics.snapshot(), { + status: 200, + headers: { + "Cache-Control": "no-store", + "Content-Type": "text/plain;version=0.0.4", + }, + }); + } + return null; +} diff --git a/src/server/management/route-registry.ts b/src/server/management/route-registry.ts index 525bb705e22..c01de4cebcd 100644 --- a/src/server/management/route-registry.ts +++ b/src/server/management/route-registry.ts @@ -38,6 +38,8 @@ export type ExemptionReason = | "test-seam" /** The CLI reaches the same data through a local transport instead of HTTP. */ | "local-transport" + /** Machine scrape target whose HTTP exposition is the operator contract. */ + | "scrape-target" /** Older clients use this alias; the current CLI drives its declared replacement. */ | "compatibility-alias" /** Unreachable in the live dispatch order; delete rather than expose. */ @@ -234,6 +236,8 @@ export const MANAGEMENT_ROUTES: readonly ManagementRoute[] = [ { method: "POST", path: "/api/storage/trash/restore", module: "server/management/logs-usage-routes", mutates: true }, { method: "PUT", path: "/api/debug", module: "server/management/logs-usage-routes", mutates: true }, { method: "PUT", path: "/api/storage/cleanup-policy", module: "server/management/logs-usage-routes", mutates: true }, + // server/management/metrics-routes + { method: "GET", path: "/api/metrics", module: "server/management/metrics-routes", mutates: false, exempt: { reason: "scrape-target", why: "This machine scrape target exposes authenticated text exposition for monitoring systems; a CLI JSON verb would be a different contract." } }, // server/management/model-routes { method: "GET", path: "/api/aliases", module: "server/management/model-routes", mutates: false }, { method: "GET", path: "/api/catalog", module: "server/management/model-routes", mutates: false }, diff --git a/src/server/request-log.ts b/src/server/request-log.ts index 6a0c7220dad..d02d9a74d78 100644 --- a/src/server/request-log.ts +++ b/src/server/request-log.ts @@ -67,10 +67,13 @@ import { inferCursorContextWindow } from "../adapters/cursor/discovery"; import { KIRO_MODEL_CONTEXT_WINDOWS, normalizeKiroModelId } from "../providers/kiro-models"; import { DEVIN_MODEL_CONTEXT_WINDOWS } from "../adapters/devin/live-models"; import { modelRecordValue } from "../reasoning-effort"; +import type { RequestMetricsRecorder } from "./request-metrics"; export interface RequestLogContext { model: string; provider: string; + /** Optional process-lifetime aggregate sink, injected by the server composition owner. */ + requestMetricsRecorder?: RequestMetricsRecorder; /** * Identity of the ONE logical request this context serves (#4546). Set from the execution * budget minted at ingress; a retry leg, a repair refetch and a combo child share it. @@ -1317,6 +1320,17 @@ export function addFinalRequestLog( const usageStatus = aggregate?.status ?? existing.status; const totalTokens = aggregate?.totalTokens ?? existing.totalTokens; const spend = requestSpendRecord(logCtx, attempts); + const durationMs = Date.now() - start; + logCtx.requestMetricsRecorder?.recordFinalRequest({ + ...(logCtx.inboundProtocol ? { protocol: logCtx.inboundProtocol } : {}), + status: effectiveStatus, + durationMs, + ...(logCtx.firstOutputMs !== undefined ? { firstOutputMs: logCtx.firstOutputMs } : {}), + ...(meta?.terminalStatus ? { terminalStatus: meta.terminalStatus } : {}), + ...(closeReason ? { closeReason } : {}), + ...(attempts !== undefined ? { attempts } : {}), + ...(spend ? { spendSends: spend.sends } : {}), + }); const cacheProvenance = classifyCacheTelemetryProvenance(loggedUsage, { wireParsed: logCtx.usageWireParsed === true, }); @@ -1364,7 +1378,7 @@ export function addFinalRequestLog( : {}), ...(logCtx.resolvedModel ? { resolvedModel: logCtx.resolvedModel } : {}), status: effectiveStatus, - durationMs: Date.now() - start, + durationMs, ...(logCtx.firstOutputMs !== undefined ? { firstOutputMs: logCtx.firstOutputMs } : {}), ...(errorCode ? { errorCode } : {}), ...(meta?.terminalStatus ? { terminalStatus: meta.terminalStatus } : {}), diff --git a/src/server/request-metrics.ts b/src/server/request-metrics.ts new file mode 100644 index 00000000000..7e132c90dde --- /dev/null +++ b/src/server/request-metrics.ts @@ -0,0 +1,235 @@ +import type { ResponsesTerminalStatus } from "../bridge"; +import type { AttemptRecoveryKind } from "../usage/log"; + +export const REQUEST_METRICS_PROTOCOLS = Object.freeze(["responses", "chat", "messages", "unknown"] as const); +export const REQUEST_METRICS_RESULTS = Object.freeze(["completed", "failed", "incomplete", "aborted"] as const); +export const REQUEST_METRICS_RECOVERY_CLASSES = Object.freeze([ + "transient", + "connection", + "credential", + "rate_limit", + "payload", + "empty_completion", + "effort_downgrade", + "other", +] as const); + +export const REQUEST_DURATION_BUCKETS_SECONDS = Object.freeze([0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60] as const); +export const REQUEST_TTFT_BUCKETS_SECONDS = Object.freeze([0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30] as const); + +export type RequestMetricsProtocol = typeof REQUEST_METRICS_PROTOCOLS[number]; +export type RequestMetricsResult = typeof REQUEST_METRICS_RESULTS[number]; +export type RequestMetricsRecoveryClass = typeof REQUEST_METRICS_RECOVERY_CLASSES[number]; + +export interface RequestMetricFinalFact { + protocol?: "responses" | "chat" | "messages"; + status: number; + durationMs: number; + firstOutputMs?: number; + terminalStatus?: ResponsesTerminalStatus; + closeReason?: "terminal" | "client_cancel" | "non_stream" | "body_stall" | "body_overflow"; + attempts?: ReadonlyArray<{ + sendCount: number; + recoveryKinds: readonly AttemptRecoveryKind[]; + }>; + spendSends?: number; +} + +export interface RequestMetricsRecorder { + recordFinalRequest(fact: RequestMetricFinalFact): void; +} + +export interface RequestMetricsSnapshotter { + snapshot(): string; +} + +export interface RequestMetricsOwner extends RequestMetricsRecorder, RequestMetricsSnapshotter { + resetForTests(): void; +} + +interface HistogramCell { + buckets: number[]; + count: number; + sum: number; +} + +const protocolCell = (value: RequestMetricsProtocol): number => REQUEST_METRICS_PROTOCOLS.indexOf(value); +const resultCell = (value: RequestMetricsResult): number => REQUEST_METRICS_RESULTS.indexOf(value); +const recoveryCell = (value: RequestMetricsRecoveryClass): number => REQUEST_METRICS_RECOVERY_CLASSES.indexOf(value); + +function matrix(rows: number, columns: number): number[][] { + return Array.from({ length: rows }, () => Array.from({ length: columns }, () => 0)); +} + +function histograms(bounds: readonly number[]): HistogramCell[][] { + return Array.from({ length: REQUEST_METRICS_PROTOCOLS.length }, () => ( + Array.from({ length: REQUEST_METRICS_RESULTS.length }, () => ({ + buckets: Array.from({ length: bounds.length + 1 }, () => 0), + count: 0, + sum: 0, + })) + )); +} + +function classifyResult(fact: RequestMetricFinalFact): RequestMetricsResult { + if (fact.closeReason === "client_cancel" || fact.status === 499) return "aborted"; + if (fact.terminalStatus === "failed") return "failed"; + if (fact.terminalStatus === "incomplete" + || fact.closeReason === "body_stall" + || fact.closeReason === "body_overflow") return "incomplete"; + if (fact.terminalStatus === "completed") return "completed"; + if (fact.terminalStatus === undefined && fact.status >= 200 && fact.status < 400) return "completed"; + return "failed"; +} + +function recoveryClass(kind: AttemptRecoveryKind): RequestMetricsRecoveryClass { + switch (kind) { + case "transient-5xx": return "transient"; + case "connection-reset": return "connection"; + case "oauth-401": + case "key-401": return "credential"; + case "key-429": + case "rate-limit-429": + case "anthropic-oauth-429": + case "oauth-account-429": return "rate_limit"; + case "image-413": + case "console-go-upload-retry": + case "opaque-blob-rejection": return "payload"; + case "empty-completion": return "empty_completion"; + case "reasoning-effort-downgrade": return "effort_downgrade"; + default: return "other"; + } +} + +function observeHistogram(cell: HistogramCell, bounds: readonly number[], value: number): void { + if (!Number.isFinite(value) || value < 0) return; + cell.count += 1; + cell.sum += value; + for (let index = 0; index < bounds.length; index += 1) { + if (value <= bounds[index]!) cell.buckets[index]! += 1; + } + cell.buckets[bounds.length]! += 1; +} + +function sampleLabels(protocol: RequestMetricsProtocol, result?: RequestMetricsResult): string { + return result === undefined + ? `{protocol="${protocol}"}` + : `{protocol="${protocol}",result="${result}"}`; +} + +function appendHistogram( + lines: string[], + name: string, + help: string, + values: HistogramCell[][], + bounds: readonly number[], +): void { + lines.push(`# HELP ${name} ${help}`, `# TYPE ${name} histogram`); + for (const protocol of REQUEST_METRICS_PROTOCOLS) { + for (const result of REQUEST_METRICS_RESULTS) { + const cell = values[protocolCell(protocol)]![resultCell(result)]!; + for (let index = 0; index < bounds.length; index += 1) { + lines.push(`${name}_bucket{protocol="${protocol}",result="${result}",le="${bounds[index]}"} ${cell.buckets[index]}`); + } + lines.push(`${name}_bucket{protocol="${protocol}",result="${result}",le="+Inf"} ${cell.buckets[bounds.length]}`); + lines.push(`${name}_sum${sampleLabels(protocol, result)} ${cell.sum}`); + lines.push(`${name}_count${sampleLabels(protocol, result)} ${cell.count}`); + } + } +} + +export function createRequestMetricsOwner( + processStartTimeSeconds = Date.now() / 1000, +): RequestMetricsOwner { + let logicalRequests = matrix(REQUEST_METRICS_PROTOCOLS.length, REQUEST_METRICS_RESULTS.length); + let physicalSends = Array.from({ length: REQUEST_METRICS_PROTOCOLS.length }, () => 0); + let recoveries = matrix(REQUEST_METRICS_PROTOCOLS.length, REQUEST_METRICS_RECOVERY_CLASSES.length); + let durations = histograms(REQUEST_DURATION_BUCKETS_SECONDS); + let ttft = histograms(REQUEST_TTFT_BUCKETS_SECONDS); + let missingTtft = matrix(REQUEST_METRICS_PROTOCOLS.length, REQUEST_METRICS_RESULTS.length); + + return { + recordFinalRequest(fact): void { + const protocol: RequestMetricsProtocol = fact.protocol ?? "unknown"; + const result = classifyResult(fact); + const protocolIndex = protocolCell(protocol); + const resultIndex = resultCell(result); + logicalRequests[protocolIndex]![resultIndex]! += 1; + + const attempts = fact.attempts; + const sends = attempts === undefined + ? (Number.isInteger(fact.spendSends) && fact.spendSends! >= 0 ? fact.spendSends! : 0) + : attempts.reduce((total, attempt) => ( + Number.isInteger(attempt.sendCount) && attempt.sendCount >= 0 ? total + attempt.sendCount : total + ), 0); + physicalSends[protocolIndex]! += sends; + + for (const attempt of attempts ?? []) { + for (const kind of new Set(attempt.recoveryKinds)) { + recoveries[protocolIndex]![recoveryCell(recoveryClass(kind))]! += 1; + } + } + + observeHistogram(durations[protocolIndex]![resultIndex]!, REQUEST_DURATION_BUCKETS_SECONDS, fact.durationMs / 1000); + if (typeof fact.firstOutputMs === "number" && Number.isFinite(fact.firstOutputMs) && fact.firstOutputMs >= 0) { + observeHistogram(ttft[protocolIndex]![resultIndex]!, REQUEST_TTFT_BUCKETS_SECONDS, fact.firstOutputMs / 1000); + } else { + missingTtft[protocolIndex]![resultIndex]! += 1; + } + }, + + snapshot(): string { + const lines: string[] = [ + "# HELP opencodex_logical_requests_total Finalized logical requests in this process.", + "# TYPE opencodex_logical_requests_total counter", + ]; + for (const protocol of REQUEST_METRICS_PROTOCOLS) { + for (const result of REQUEST_METRICS_RESULTS) { + lines.push(`opencodex_logical_requests_total${sampleLabels(protocol, result)} ${logicalRequests[protocolCell(protocol)]![resultCell(result)]}`); + } + } + lines.push( + "# HELP opencodex_physical_sends_total Upstream sends made by finalized logical requests in this process.", + "# TYPE opencodex_physical_sends_total counter", + ); + for (const protocol of REQUEST_METRICS_PROTOCOLS) { + lines.push(`opencodex_physical_sends_total${sampleLabels(protocol)} ${physicalSends[protocolCell(protocol)]}`); + } + lines.push( + "# HELP opencodex_recoveries_total Distinct recovery kinds observed per physical attempt in this process.", + "# TYPE opencodex_recoveries_total counter", + ); + for (const protocol of REQUEST_METRICS_PROTOCOLS) { + for (const recovery of REQUEST_METRICS_RECOVERY_CLASSES) { + lines.push(`opencodex_recoveries_total{protocol="${protocol}",recovery="${recovery}"} ${recoveries[protocolCell(protocol)]![recoveryCell(recovery)]}`); + } + } + appendHistogram(lines, "opencodex_request_duration_seconds", "Finalized logical request duration in seconds.", durations, REQUEST_DURATION_BUCKETS_SECONDS); + appendHistogram(lines, "opencodex_ttft_seconds", "Observed time to first output in seconds.", ttft, REQUEST_TTFT_BUCKETS_SECONDS); + lines.push( + "# HELP opencodex_ttft_missing_total Finalized logical requests without an observed time to first output.", + "# TYPE opencodex_ttft_missing_total counter", + ); + for (const protocol of REQUEST_METRICS_PROTOCOLS) { + for (const result of REQUEST_METRICS_RESULTS) { + lines.push(`opencodex_ttft_missing_total${sampleLabels(protocol, result)} ${missingTtft[protocolCell(protocol)]![resultCell(result)]}`); + } + } + lines.push( + "# HELP opencodex_metrics_process_start_time_seconds Unix time when this process metrics owner started.", + "# TYPE opencodex_metrics_process_start_time_seconds gauge", + `opencodex_metrics_process_start_time_seconds ${processStartTimeSeconds}`, + ); + return `${lines.join("\n")}\n`; + }, + + resetForTests(): void { + logicalRequests = matrix(REQUEST_METRICS_PROTOCOLS.length, REQUEST_METRICS_RESULTS.length); + physicalSends = Array.from({ length: REQUEST_METRICS_PROTOCOLS.length }, () => 0); + recoveries = matrix(REQUEST_METRICS_PROTOCOLS.length, REQUEST_METRICS_RECOVERY_CLASSES.length); + durations = histograms(REQUEST_DURATION_BUCKETS_SECONDS); + ttft = histograms(REQUEST_TTFT_BUCKETS_SECONDS); + missingTtft = matrix(REQUEST_METRICS_PROTOCOLS.length, REQUEST_METRICS_RESULTS.length); + }, + }; +} diff --git a/src/types/config.ts b/src/types/config.ts index 2c38aef8e8e..291f829f1ff 100644 --- a/src/types/config.ts +++ b/src/types/config.ts @@ -403,6 +403,8 @@ export interface OcxConfig { client?: OcxClientConnectionConfig; /** Operator-facing redaction policy for management and CLI projections. */ privacy?: OcxPrivacyConfig; + /** Opt-in process-local aggregate request metrics on the authenticated management plane. */ + metricsExport?: { enabled?: boolean }; /** Opt in to one identical-turn retry when a Responses completion has no text or tool call. */ emptyCompletionRetry?: boolean; /** Suppress allowlisted client-facing Codex transport hints; provider enforcement is unchanged. */ diff --git a/structure/config.md b/structure/config.md index a6eb45aff94..9aec675f252 100644 --- a/structure/config.md +++ b/structure/config.md @@ -483,6 +483,17 @@ The text-only consumer reads exact inputModalities declarations before legacy hi `catalogAutoRefresh` on `src/types/config.ts` stores an optional `enabled` / `intervalMinutes` section that defaults off: an absent key, an explicit false, and a malformed value all leave the scheduler dormant. `src/config/feature-flags.ts` resolves the cadence; an explicit `intervalMinutes: 0` keeps the unref'd timer idle, and any other value is clamped up to 15 minutes because upstream `/models` caches have not moved below that and a shorter tick only multiplies rate-limit exposure. `src/codex/catalog-auto-refresh.ts` is the module-singleton interval `src/server/background-lifecycle.ts` starts beside the quota reset poller; a tick that is enabled and non-dormant drives the same catalog-only converge funnel management mutations drive. The last-outcome record lives in `src/codex/catalog-refresh-status.ts` (when the tick finished, the normalized `CatalogDisposition`, whether the served model set changed, consecutive failures) and carries no provider or account detail. +## Aggregate request metrics export + +`metricsExport` on `src/types/config.ts` is an optional strict object with one optional boolean, +`enabled`. `src/config/feature-flags.ts` treats only literal `true` as enabled; absence, false, or a +malformed persisted value is off. `src/config/schema/config-schema.ts` degrades a malformed hand edit +to absence so an optional monitoring typo cannot discard providers or credentials. The live-write +boundary runs `metricsExportConfigError` in `src/config/diagnostics.ts` before the degrading schema, +so wrong types and unknown nested fields are rejected rather than silently saved. Activation is read +when the server process creates its serve options and therefore requires restart; it adds no setting +to the live `/api/settings` mutation surface. + Stored Direct substitution follows the [credential identity contract](providers/openai-tiers.md#sidecars-management-and-ui): both synchronous and asynchronous materializers discard the caller account header before applying the stored credential; ordinary native Direct passthrough is unchanged. ## SOCKS5 activation owner diff --git a/structure/gui-and-management-api.md b/structure/gui-and-management-api.md index e6226c58894..af0a991d953 100644 --- a/structure/gui-and-management-api.md +++ b/structure/gui-and-management-api.md @@ -143,6 +143,7 @@ this document owns is which module holds which area and what invariant that area | V2 / Multi-agent mode | `GET/PUT /api/v2` — reports/sets the codex `multi_agent_v2` feature flag, the 3-state `multiAgentMode` override (`v1`/`default`/`v2`), the `keepNativeChatGptOnV1` hybrid pin, and the logical maximum thread count. Selecting `v2` normally enables the native flag; with the hybrid pin it disables that global override so native rows can resolve to v1 while routed rows resolve to v2. Selecting `v1` disables the flag; `default` leaves it unchanged. PUT rejects an explicit enabled flag that conflicts with the selected mode or hybrid pin. Every transition preserves the logical thread limit, is rollback-safe, and resyncs the catalog. GET and successful PUT also return stored `multiAgentModeHintText` plus response-only `multiAgentModeHintRecommendation: { text, revision }`; the recommendation is not a writable or persisted config field. Both also return response-only `multiAgentSurfaceAdvisory: { required, mode, recommended, version, docsUrl }`, true while the resolved mode is not v1 and the stored acknowledgement version is behind; PUT accepts `multiAgentSurfaceAdvisoryAcknowledged`, where only `true` stores the current version and `false` is an explicit no-op, and it composes with a `multiAgentMode` write in the same body so the dialog's recommended answer is one request. | | Logs & Debug | One sidebar entry (`/#logs`) with two tabs. Logs tab: request/runtime logs for local diagnosis. `LogsFilterBar` owns controls over the shared `LogFilterState`; `filterLogs` composes filters over the loaded ring. The logs envelope adds `generatedAt` (proxy epoch milliseconds); the page advances that sample with monotonic elapsed time and retains a browser-clock fallback for older proxies. Reset returns focus to the stable All surface radio. Provider/model options include attempts, model choices match normalized complete identities, and relative-time filtering refreshes every 30 seconds while the Logs tab is active, independently of network auto-refresh. Debug tab (`/#logs/debug`; legacy `/#debug` deep links redirect there): provider + usage toggles, refresh/follow log viewer. `GET/PUT /api/debug`; `GET /api/debug/logs` and `GET /api/debug/usage-logs` (monotonic `after` cursor, legacy `since` accepted). CLI: `ocx debug provider|usage …` (both streams via running proxy API). | | Usage | `GET /api/usage` read-only aggregates of readable rows from `~/.opencodex/usage.jsonl`; the ledger is streamed in fixed 1 MiB chunks, so the former read-byte and parsed-row caps cannot omit its prefix. Oversized skipped rows produce positive `usageIncomplete` metadata. The response includes measured / reported / unreported / unsupported / estimated counts, a daily zero-filled grid, and model and provider breakdowns. Never exposes prompts. | +| Request metrics | `GET /api/metrics` exposes process-local Prometheus text format v0.0.4 only when `metricsExport.enabled` was true at startup. The ordinary management gate applies; data-plane credentials do not grant access, and disabled mode is 404. `src/server/request-metrics.ts` owns fixed counters/histograms and receives a narrow final-request fact from `src/server/request-log.ts`; `src/server/index/serve-options.ts` creates one owner and injects the recorder and read-only snapshot into the request and management paths. | | System | `POST /api/system/restart` restarts the proxy in place. Local CLI/tray callers first attest the exact runtime PID and port, then send a process-scoped HMAC capability bound to that method, path, PID, and port; the capability authorizes no other management route and is invalid after replacement. The caller observes one absolute deadline and accepts success only after a different runtime PID is healthy on the same port. `GET /api/system/health` is the authenticated scalar-only identity used by shared-plane Dashboard status and restart reconnect polling; its `spendLedger` block reports only ownership held/unheld, initialized/configured/degraded booleans and bounded persistence/corruption counters. Reading it never constructs, replays or prunes the ledger. Paths, scopes, accounts and request ids are absent, and the block never moves to unauthenticated `/healthz`. `GET /api/system/memory` — service-process runtime/memory identity (pid, Bun version/revision, optional `bunRuntimeSource` provenance, platform, RSS/heap/external/ArrayBuffers scalars, observed memory = max(RSS, external, ArrayBuffers), `bun:jsc` heap context, streamMode + eager-relay gate decision, watchdog snapshot sliced to the last 60 samples) plus privacy-safe `appOwnedBytes` retained-store totals/counters under static store ids. Its response-state block also reports spill-write `initial`/`healthy`/`degraded` status, a consecutive-failure streak, fixed error class, and failure/success timestamps. A successful publication clears the streak in the same process; raw error text and paths never enter this surface. Scalar-only payload; dashboard/admin callers use the standard management gate, while `ocx doctor` may use only the exact process-scoped local-read capability. It must never move to unauthenticated `/healthz`. | | Stop | `POST /api/stop` — restore native Codex, stop any installed service, and exit the proxy. | | Diagnostics/sync | `src/server/management/config-routes.ts` — `GET /api/diagnostics/project-config` reports project-level Codex config that bypasses managed routing; `POST /api/sync` re-runs catalog/config sync. The diagnostic reports the bypass; it does not rewrite the project file. | @@ -607,6 +608,25 @@ scan reports `false`, `0`, `false`, and `0`; clients must not interpret those fi > Decision record: [ADR-0079](decisions/ADR-0079-usage-accounting.md) +## Opt-in aggregate request metrics + +`metricsExport.enabled` is default-off and fixed for one process lifetime. When enabled, +`src/server/index/serve-options.ts` creates one `src/server/request-metrics.ts` owner before the +shared fetch closure, so every listener spread records into the same bounded cells. Request logging +calls the injected recorder once from `addFinalRequestLog`; the management route receives only a +snapshot capability. There is no module-global active registry, timer, outbound connection, scrape-time +log scan, or persistence. Restart creates a fresh owner, resets every counter/histogram, and changes +`opencodex_metrics_process_start_time_seconds`. + +The label vocabularies are closed: protocol is `responses`, `chat`, `messages`, or `unknown`; result +is `completed`, `failed`, `incomplete`, or `aborted`; recovery is one of eight coarse classes. A +logical request increments once, physical sends sum the finalized attempt counts, and each distinct +recovery kind already retained on an attempt contributes once to its coarse class. HTTP 200 never +overrides a failed terminal event. Duration observes every valid finalized duration; TTFT observes +only finite nonnegative first-output values, while `opencodex_ttft_missing_total` is the complementary +denominator. No request, credential, account, provider, model, conversation, raw error, prompt, tool, +body, header, or URL value enters a label or sample. + For diagnosing upstream-shape / usage-extraction issues run `ocx debug usage on` (or set `OPENCODEX_USAGE_DEBUG=1` before start). The proxy then writes a rolling debug record per finalized request to `~/.opencodex/usage-debug.jsonl` (mode `0o600`, auto-trimmed to the most-recent 100 lines diff --git a/tests/fixtures/test-layout-expected.json b/tests/fixtures/test-layout-expected.json index d677aea796a..61ec5c3b482 100644 --- a/tests/fixtures/test-layout-expected.json +++ b/tests/fixtures/test-layout-expected.json @@ -749,6 +749,7 @@ "main-quota-provenance.test.ts": "codex-integration", "main-quota-window-observation.test.ts": "codex-integration", "management-api-logs-metrics.test.ts": "server", + "management-metrics-export.test.ts": "server", "management-client-config-route.test.ts": "server", "management-google-tool-schema-policy.test.ts": "server", "management-integration-journal-delete.test.ts": "server", diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts new file mode 100644 index 00000000000..012c6094690 --- /dev/null +++ b/tests/server/management-metrics-export.test.ts @@ -0,0 +1,276 @@ +import { describe, expect, test } from "bun:test"; +import { readFileSync } from "node:fs"; +import { configDiagnosticsFromRaw, validateConfigCandidate } from "../../src/config/diagnostics"; +import { metricsExportEnabled } from "../../src/config/feature-flags"; +import { getDefaultConfig } from "../../src/config/proxy-env"; +import { handleManagementAPI } from "../../src/server/management-api"; +import { requireManagementAuth, type ManagementAuthState } from "../../src/server/management-auth"; +import { addFinalRequestLog, type RequestLogContext } from "../../src/server/request-log"; +import { createRequestMetricsOwner } from "../../src/server/request-metrics"; +import type { OcxConfig } from "../../src/types"; +import type { AttemptRecoveryKind } from "../../src/usage/log"; +import { ManagementRequest } from "../helpers/management-auth"; +import { repoPath } from "../helpers/repo-root"; + +const ADMIN_TOKEN = "ocx_admin_aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"; +const DATA_TOKEN = "ocx_data_bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb"; + +function authState(): ManagementAuthState { + return { + available: true, + token: ADMIN_TOKEN, + source: "environment", + sessions: new Map(), + pairingGrants: new Map(), + }; +} + +function config(overrides: Partial = {}): OcxConfig { + return { + ...getDefaultConfig(), + apiKeys: [{ id: "data-key", key: DATA_TOKEN, name: "data key", createdAt: "2026-09-19T00:00:00.000Z" }], + ...overrides, + }; +} + +async function metricsRoute(snapshot?: () => string): Promise { + const req = new ManagementRequest("http://localhost/api/metrics"); + const url = new URL(req.url); + const response = await handleManagementAPI(req, url, config(), snapshot ? { + requestMetrics: { snapshot }, + } : {}); + if (!response) throw new Error("metrics route was not handled"); + return response; +} + +async function authenticatedMetricsRoute(req: Request, snapshot: () => string): Promise { + const denied = requireManagementAuth(req, authState(), config()); + if (denied) return denied; + const response = await handleManagementAPI(req, new URL(req.url), config(), { + requestMetrics: { snapshot }, + }); + if (!response) throw new Error("metrics route was not handled"); + return response; +} + +function sampleValue(text: string, prefix: string): number { + const line = text.split("\n").find(candidate => candidate.startsWith(prefix)); + if (!line) throw new Error(`missing metric sample: ${prefix}`); + return Number(line.slice(line.lastIndexOf(" ") + 1)); +} + +function attempt(sendCount: number, recoveryKinds: AttemptRecoveryKind[]) { + return { + ordinal: 1, + provider: "private-provider-canary", + model: "private-model-canary", + adapter: "openai-responses", + status: 200, + durationMs: 10, + sendCount, + recoveryKinds, + usageStatus: "unreported" as const, + }; +} + +describe("request metrics aggregation", () => { + test("one finalized logical request counts once while attempts preserve physical sends and distinct recovery kinds", () => { + const metrics = createRequestMetricsOwner(123); + const logCtx: RequestLogContext = { + model: "private-model-canary", + provider: "private-provider-canary", + inboundProtocol: "responses", + requestMetricsRecorder: metrics, + attempts: [ + attempt(2, ["connection-reset", "connection-reset"]), + { ...attempt(1, ["key-429", "rate-limit-429"]), ordinal: 2 }, + ], + }; + + addFinalRequestLog("private-request-canary", Date.now() - 1_000, logCtx, 200, { + terminalStatus: "completed", + closeReason: "terminal", + }, () => {}); + + const output = metrics.snapshot(); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(1); + expect(sampleValue(output, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(3); + expect(sampleValue(output, 'opencodex_recoveries_total{protocol="responses",recovery="connection"}')).toBe(1); + expect(sampleValue(output, 'opencodex_recoveries_total{protocol="responses",recovery="rate_limit"}')).toBe(2); + }); + + test("a failed terminal carried over HTTP 200 is never counted as completed", () => { + const metrics = createRequestMetricsOwner(123); + metrics.recordFinalRequest({ + protocol: "responses", + status: 200, + durationMs: 250, + firstOutputMs: 0, + terminalStatus: "failed", + closeReason: "terminal", + }); + const output = metrics.snapshot(); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); + expect(sampleValue(output, 'opencodex_ttft_seconds_count{protocol="responses",result="failed"}')).toBe(1); + expect(sampleValue(output, 'opencodex_ttft_missing_total{protocol="responses",result="failed"}')).toBe(0); + }); + + test("incomplete, aborted, and missing TTFT denominators remain distinct", () => { + const metrics = createRequestMetricsOwner(123); + metrics.recordFinalRequest({ protocol: "chat", status: 502, durationMs: 100, terminalStatus: "incomplete" }); + metrics.recordFinalRequest({ protocol: "chat", status: 499, durationMs: 200, closeReason: "client_cancel" }); + const output = metrics.snapshot(); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="chat",result="incomplete"}')).toBe(1); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="chat",result="aborted"}')).toBe(1); + expect(sampleValue(output, 'opencodex_request_duration_seconds_count{protocol="chat",result="incomplete"}')).toBe(1); + expect(sampleValue(output, 'opencodex_request_duration_seconds_count{protocol="chat",result="aborted"}')).toBe(1); + expect(sampleValue(output, 'opencodex_ttft_missing_total{protocol="chat",result="incomplete"}')).toBe(1); + expect(sampleValue(output, 'opencodex_ttft_missing_total{protocol="chat",result="aborted"}')).toBe(1); + }); + + test("series and labels stay bounded and privacy canaries never reach exposition", () => { + const metrics = createRequestMetricsOwner(123); + const canaries = [ + "private-request-canary", + "private-logical-canary", + "private-key-canary", + "private-account-canary", + "private-model-canary", + "private-provider-canary", + "private-error-canary", + "private-prompt-canary", + "private-tool-body-canary", + ]; + const logCtx = { + model: canaries[4], + provider: canaries[5], + logicalRequestId: canaries[1], + apiKeyId: canaries[2], + accountLogLabel: canaries[3], + upstreamError: canaries[6], + inboundProtocol: "messages", + requestMetricsRecorder: metrics, + prompt: canaries[7], + toolBody: canaries[8], + } as unknown as RequestLogContext; + addFinalRequestLog(canaries[0]!, Date.now() - 1, logCtx, 400, undefined, () => {}); + for (let index = 0; index < 64; index += 1) { + addFinalRequestLog(`request-${index}`, Date.now() - 1, { + model: `model-${index}`, + provider: `provider-${index}`, + apiKeyId: `key-${index}`, + accountLogLabel: `account-${index}`, + requestMetricsRecorder: metrics, + }, 400, undefined, () => {}); + } + const output = metrics.snapshot(); + for (const canary of canaries) expect(output).not.toContain(canary); + const samples = output.split("\n").filter(line => line && !line.startsWith("#")); + expect(samples).toHaveLength(453); + }); + + test("text exposition has deterministic HELP/TYPE groups and cumulative +Inf buckets", () => { + const metrics = createRequestMetricsOwner(123); + metrics.recordFinalRequest({ protocol: "responses", status: 200, durationMs: 125, firstOutputMs: 75 }); + const output = metrics.snapshot(); + expect(output.endsWith("\n")).toBe(true); + expect(output.indexOf("# HELP opencodex_request_duration_seconds")) + .toBeLessThan(output.indexOf("opencodex_request_duration_seconds_bucket")); + expect(output.indexOf("# TYPE opencodex_request_duration_seconds histogram")) + .toBeLessThan(output.indexOf("opencodex_request_duration_seconds_bucket")); + const helpLines = output.split("\n").filter(line => line.startsWith("# HELP ")); + const typeLines = output.split("\n").filter(line => line.startsWith("# TYPE ")); + expect(helpLines).toHaveLength(7); + expect(typeLines).toHaveLength(7); + expect(new Set(helpLines.map(line => line.split(" ")[2])).size).toBe(7); + expect(new Set(typeLines.map(line => line.split(" ")[2])).size).toBe(7); + expect(sampleValue(output, 'opencodex_request_duration_seconds_bucket{protocol="responses",result="completed",le="+Inf"}')) + .toBe(sampleValue(output, 'opencodex_request_duration_seconds_count{protocol="responses",result="completed"}')); + expect(metrics.snapshot()).toBe(output); + }); + + test("a fresh owner documents process restart by resetting counters and changing start time", () => { + const first = createRequestMetricsOwner(100); + first.recordFinalRequest({ status: 200, durationMs: 1 }); + const second = createRequestMetricsOwner(200); + expect(sampleValue(first.snapshot(), "opencodex_metrics_process_start_time_seconds")).toBe(100); + expect(sampleValue(second.snapshot(), "opencodex_metrics_process_start_time_seconds")).toBe(200); + expect(sampleValue(second.snapshot(), 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + }); +}); + +describe("metrics management boundary", () => { + test("admin authentication admits the route while absent and data-plane credentials do not", async () => { + const admin = new ManagementRequest("http://localhost/api/metrics", { + headers: { "x-opencodex-api-key": ADMIN_TOKEN }, + }); + const data = new ManagementRequest("http://localhost/api/metrics", { + headers: { "x-opencodex-api-key": DATA_TOKEN }, + }); + const absent = new ManagementRequest("http://localhost/api/metrics"); + const metrics = createRequestMetricsOwner(123); + const snapshot = () => metrics.snapshot(); + const response = await authenticatedMetricsRoute(admin, snapshot); + expect(response.status).toBe(200); + expect(response.headers.get("content-type")).toBe("text/plain;version=0.0.4"); + expect(await response.text()).not.toContain(DATA_TOKEN); + expect((await authenticatedMetricsRoute(data, snapshot)).status).toBe(401); + expect((await authenticatedMetricsRoute(absent, snapshot)).status).toBe(401); + }); + + test("disabled mode wires no snapshot route and returns the locked 404", async () => { + expect(metricsExportEnabled(config())).toBe(false); + const response = await metricsRoute(); + expect(response.status).toBe(404); + expect((await response.json() as { error: { code: string } }).error.code).toBe("not_found"); + }); + + test("the metrics modules contain no timer, listener, network, or module-global owner", () => { + const source = [ + readFileSync(repoPath("src/server/request-metrics.ts"), "utf8"), + readFileSync(repoPath("src/server/management/metrics-routes.ts"), "utf8"), + ].join("\n"); + for (const forbidden of ["setInterval(", "setTimeout(", "Bun.serve(", ".listen(", "fetch("]) { + expect(source).not.toContain(forbidden); + } + expect(source).not.toMatch(/(?:let|const)\s+activeRequestMetrics/); + const composition = readFileSync(repoPath("src/server/index/serve-options.ts"), "utf8"); + expect(composition).toContain( + "metricsExportEnabled(config) ? createRequestMetricsOwner() : undefined", + ); + expect(composition).toContain("requestMetrics ? { requestMetricsRecorder: requestMetrics } : {}"); + expect(composition).toContain("createWebsocketHandler(ctx, requestMetrics)"); + expect(readFileSync(repoPath("src/server/index/websocket-handler.ts"), "utf8")) + .toContain("requestMetricsRecorder ? { requestMetricsRecorder } : {}"); + }); +}); + +describe("metricsExport config admission", () => { + test("absence and false stay disabled while true enables the process-lifetime owner", () => { + expect(metricsExportEnabled(config())).toBe(false); + expect(metricsExportEnabled(config({ metricsExport: { enabled: false } }))).toBe(false); + expect(metricsExportEnabled(config({ metricsExport: { enabled: true } }))).toBe(true); + }); + + test("live writes reject malformed and unknown fields before the degrading schema", () => { + const base = getDefaultConfig(); + expect(validateConfigCandidate({ ...base, metricsExport: { enabled: "yes" } })).toMatchObject({ + ok: false, + error: "schema_invalid: metricsExport.enabled: must be a boolean", + }); + expect(validateConfigCandidate({ ...base, metricsExport: { enabled: true, label: "private" } })).toMatchObject({ + ok: false, + error: "schema_invalid: metricsExport: contains an unsupported field", + }); + }); + + test("malformed persisted values degrade only metrics export to disabled", () => { + const base = getDefaultConfig(); + for (const metricsExport of [{ enabled: "yes" }, { enabled: true, label: "private" }]) { + const diagnostics = configDiagnosticsFromRaw(JSON.stringify({ ...base, metricsExport })); + expect(diagnostics.config.metricsExport).toBeUndefined(); + expect(diagnostics.config.providers).toEqual(base.providers); + } + }); +}); From c5cb110c1a97520383cc85d674459d0ad8714d85 Mon Sep 17 00:00:00 2001 From: JUN Date: Sat, 19 Sep 2026 23:26:56 +0900 Subject: [PATCH 02/15] fix(server): count buffered terminal failures and test real flows Review fold: a buffered HTTP 200 with response.failed/incomplete was parsed for the log but never reached metrics, counting as completed. The bounded terminal enum now propagates from buffered inspection through EOF finalization into the metric fact, while cancel (499) and read-error (502) retain priority. New server-harness coverage drives real HTTP retry, real WebSocket response.create, buffered failed/incomplete, read-error priority, SSE EOF, cancellation, and missing-vs-zero TTFT through authenticated scrapes. Part of #5117 --- src/server/relay.ts | 3 + src/server/request-log.ts | 18 + .../server/management-metrics-export.test.ts | 346 +++++++++++++++++- 3 files changed, 365 insertions(+), 2 deletions(-) diff --git a/src/server/relay.ts b/src/server/relay.ts index 1e71ea35b90..86222a97b08 100644 --- a/src/server/relay.ts +++ b/src/server/relay.ts @@ -720,6 +720,9 @@ export function responseWithDeferredRequestLog( // convention for a client cancellation or upstream read failure. const status = reason === "cancel" ? 499 : reason === "read_error" ? 502 : response.status; addFinalRequestLog(requestId, start, logCtx, status, { + ...(reason === "eof" && logCtx.observedTerminalStatus + ? { terminalStatus: logCtx.observedTerminalStatus } + : {}), closeReason: reason === "cancel" ? "client_cancel" : "non_stream", }, addLog); }, diff --git a/src/server/request-log.ts b/src/server/request-log.ts index d02d9a74d78..138675a69bf 100644 --- a/src/server/request-log.ts +++ b/src/server/request-log.ts @@ -74,6 +74,8 @@ export interface RequestLogContext { provider: string; /** Optional process-lifetime aggregate sink, injected by the server composition owner. */ requestMetricsRecorder?: RequestMetricsRecorder; + /** Bounded terminal enum observed while inspecting a buffered response body. */ + observedTerminalStatus?: ResponsesTerminalStatus; /** * Identity of the ONE logical request this context serves (#4546). Set from the execution * budget minted at ingress; a retry leg, a repair refetch and a combo child share it. @@ -769,6 +771,22 @@ export function catalogModelSupportsServiceTier(modelId: string, serviceTier: st export function applyResponseLogMetadata(logCtx: RequestLogContext, payload: unknown): void { if (!payload || typeof payload !== "object") return; + if (logCtx.observedTerminalStatus === undefined) { + const eventType = (payload as { type?: unknown }).type; + const response = (payload as { response?: unknown }).response; + const responseStatus = response && typeof response === "object" + ? (response as { status?: unknown }).status + : (payload as { status?: unknown }).status; + if (eventType === "response.completed") { + logCtx.observedTerminalStatus = "completed"; + } else if (eventType === "response.failed") { + logCtx.observedTerminalStatus = "failed"; + } else if (eventType === "response.incomplete") { + logCtx.observedTerminalStatus = "incomplete"; + } else if (responseStatus === "completed" || responseStatus === "failed" || responseStatus === "incomplete") { + logCtx.observedTerminalStatus = responseStatus; + } + } const source = "response" in payload && typeof (payload as { response?: unknown }).response === "object" ? (payload as { response?: unknown }).response : payload; diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 012c6094690..254342f659c 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -1,5 +1,8 @@ -import { describe, expect, test } from "bun:test"; -import { readFileSync } from "node:fs"; +import { afterEach, beforeEach, describe, expect, test } from "bun:test"; +import { mkdtempSync, readFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { saveConfig } from "../../src/config"; import { configDiagnosticsFromRaw, validateConfigCandidate } from "../../src/config/diagnostics"; import { metricsExportEnabled } from "../../src/config/feature-flags"; import { getDefaultConfig } from "../../src/config/proxy-env"; @@ -7,13 +10,17 @@ import { handleManagementAPI } from "../../src/server/management-api"; import { requireManagementAuth, type ManagementAuthState } from "../../src/server/management-auth"; import { addFinalRequestLog, type RequestLogContext } from "../../src/server/request-log"; import { createRequestMetricsOwner } from "../../src/server/request-metrics"; +import { startServer } from "../../src/server"; import type { OcxConfig } from "../../src/types"; import type { AttemptRecoveryKind } from "../../src/usage/log"; import { ManagementRequest } from "../helpers/management-auth"; +import { installIsolatedCodexHome, type IsolatedCodexHome } from "../helpers/isolated-codex-home"; +import { removeTreeWithRetry } from "../helpers/remove-tree"; import { repoPath } from "../helpers/repo-root"; const ADMIN_TOKEN = "ocx_admin_aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"; const DATA_TOKEN = "ocx_data_bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb"; +const METRICS_UPSTREAM = "metrics-upstream.example"; function authState(): ManagementAuthState { return { @@ -73,6 +80,125 @@ function attempt(sendCount: number, recoveryKinds: AttemptRecoveryKind[]) { }; } +function runtimeConfig( + adapter: "openai-chat" | "openai-responses", + metricsEnabled = true, +): OcxConfig { + return { + port: 0, + codexAutoStart: false, + websockets: true, + metricsExport: { enabled: metricsEnabled }, + defaultProvider: "fixture", + providers: { + fixture: { + adapter, + baseUrl: `https://${METRICS_UPSTREAM}/v1`, + apiKey: "sk-metrics-fixture", + transientRetryOn5xx: { enabled: true, attempts: 2 }, + }, + }, + } as OcxConfig; +} + +function completedResponseJson(text = "ok"): string { + return JSON.stringify({ + type: "response.completed", + response: { + id: "resp_metrics", + object: "response", + status: "completed", + output: [{ type: "message", role: "assistant", content: [{ type: "output_text", text }] }], + usage: { input_tokens: 2, output_tokens: 1, total_tokens: 3 }, + }, + }); +} + +function responseSse(options: { terminal?: "completed" | "failed" | "incomplete"; output?: string } = {}): string { + const id = "resp_metrics_sse"; + const events = [ + `event: response.created\ndata: ${JSON.stringify({ type: "response.created", response: { id, status: "in_progress", output: [] } })}`, + ]; + if (options.output !== undefined) { + events.push(`event: response.output_text.delta\ndata: ${JSON.stringify({ type: "response.output_text.delta", delta: options.output })}`); + } + if (options.terminal) { + events.push(`event: response.${options.terminal}\ndata: ${JSON.stringify({ + type: `response.${options.terminal}`, + response: { id, status: options.terminal, output: [], usage: { input_tokens: 2, output_tokens: 1, total_tokens: 3 } }, + })}`); + } + return `${events.join("\n\n")}\n\n${options.terminal ? "data: [DONE]\n\n" : ""}`; +} + +function installUpstream( + originalFetch: typeof fetch, + responder: (send: number, request: Request) => Response | Promise, +): () => number { + let sends = 0; + globalThis.fetch = (async (input: RequestInfo | URL, init?: RequestInit) => { + const request = input instanceof Request ? input : new Request(input, init); + const url = new URL(request.url); + if (url.hostname === METRICS_UPSTREAM) { + sends += 1; + return responder(sends, request); + } + return originalFetch(input, init); + }) as typeof fetch; + return () => sends; +} + +async function scrapeServer(server: ReturnType): Promise { + const response = await fetch(new URL("/api/metrics", server.url), { + headers: { "x-opencodex-api-key": ADMIN_TOKEN }, + }); + expect(response.status).toBe(200); + return response.text(); +} + +async function sendResponsesRequest(server: ReturnType, stream = false): Promise { + return fetch(new URL("/v1/responses", server.url), { + method: "POST", + headers: { "content-type": "application/json" }, + body: JSON.stringify({ model: "fixture/metrics-model", input: "hello", stream }), + }); +} + +async function sendChatRequest(server: ReturnType): Promise { + return fetch(new URL("/v1/chat/completions", server.url), { + method: "POST", + headers: { "content-type": "application/json" }, + body: JSON.stringify({ model: "fixture/metrics-model", messages: [{ role: "user", content: "hello" }] }), + }); +} + +async function runWebSocketTurn(server: ReturnType): Promise { + const url = new URL("/v1/responses", server.url); + url.protocol = "ws:"; + const socket = new WebSocket(url); + await new Promise((resolve, reject) => { + const timer = setTimeout(() => reject(new Error("metrics websocket timeout")), 5_000); + socket.addEventListener("open", () => { + socket.send(JSON.stringify({ + type: "response.create", + model: "fixture/metrics-model", + input: "hello", + })); + }, { once: true }); + socket.addEventListener("message", event => { + const text = typeof event.data === "string" ? event.data : ""; + if (!text.includes("response.completed")) return; + clearTimeout(timer); + socket.close(); + resolve(); + }); + socket.addEventListener("error", () => { + clearTimeout(timer); + reject(new Error("metrics websocket failed")); + }, { once: true }); + }); +} + describe("request metrics aggregation", () => { test("one finalized logical request counts once while attempts preserve physical sends and distinct recovery kinds", () => { const metrics = createRequestMetricsOwner(123); @@ -246,6 +372,222 @@ describe("metrics management boundary", () => { }); }); +describe("metrics through live HTTP and WebSocket server flows", () => { + const originalFetch = globalThis.fetch; + const originalWebSocket = globalThis.WebSocket; + const previousOpenCodexHome = process.env.OPENCODEX_HOME; + const previousAdminToken = process.env.OPENCODEX_ADMIN_AUTH_TOKEN; + let openCodexHome = ""; + let isolatedCodexHome: IsolatedCodexHome | null = null; + + beforeEach(() => { + openCodexHome = mkdtempSync(join(tmpdir(), "ocx-metrics-export-")); + process.env.OPENCODEX_HOME = openCodexHome; + process.env.OPENCODEX_ADMIN_AUTH_TOKEN = ADMIN_TOKEN; + isolatedCodexHome = installIsolatedCodexHome("ocx-metrics-export-codex-"); + globalThis.fetch = originalFetch; + globalThis.WebSocket = originalWebSocket; + }); + + afterEach(() => { + globalThis.fetch = originalFetch; + globalThis.WebSocket = originalWebSocket; + if (previousOpenCodexHome === undefined) delete process.env.OPENCODEX_HOME; + else process.env.OPENCODEX_HOME = previousOpenCodexHome; + if (previousAdminToken === undefined) delete process.env.OPENCODEX_ADMIN_AUTH_TOKEN; + else process.env.OPENCODEX_ADMIN_AUTH_TOKEN = previousAdminToken; + isolatedCodexHome?.restore(); + isolatedCodexHome = null; + if (openCodexHome) removeTreeWithRetry(openCodexHome); + openCodexHome = ""; + }); + + test("HTTP retry flow records one logical request and both physical sends", async () => { + const sends = installUpstream(originalFetch, send => send === 1 + ? Response.json({ error: { message: "retry" } }, { status: 500 }) + : Response.json({ + id: "chat_metrics", + object: "chat.completion", + choices: [{ index: 0, message: { role: "assistant", content: "ok" }, finish_reason: "stop" }], + usage: { prompt_tokens: 2, completion_tokens: 1, total_tokens: 3 }, + })); + saveConfig(runtimeConfig("openai-chat")); + const server = startServer(0); + try { + const response = await sendChatRequest(server); + expect(response.status).toBe(200); + await response.text(); + const metrics = await scrapeServer(server); + expect(sends()).toBe(2); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="chat",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="chat"}')).toBe(2); + expect(sampleValue(metrics, 'opencodex_recoveries_total{protocol="chat",recovery="transient"}')).toBe(1); + } finally { + await server.stop(true); + } + }); + + test("WebSocket response.create finalizes into the shared metrics owner", async () => { + const sends = installUpstream(originalFetch, () => new Response(responseSse({ + terminal: "completed", + output: "socket output", + }), { headers: { "content-type": "text/event-stream" } })); + saveConfig(runtimeConfig("openai-responses")); + const server = startServer(0); + try { + await runWebSocketTurn(server); + const metrics = await scrapeServer(server); + expect(sends()).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(1); + } finally { + await server.stop(true); + } + }); + + test("buffered HTTP 200 response.failed is classified as failed", async () => { + installUpstream(originalFetch, () => Response.json({ + type: "response.failed", + response: { + id: "resp_failed_metrics", + status: "failed", + error: { type: "server_error", code: "upstream_error", message: "bounded failure" }, + output: [], + }, + })); + saveConfig(runtimeConfig("openai-responses")); + const server = startServer(0); + try { + const response = await sendResponsesRequest(server); + expect(response.status).toBe(200); + await response.text(); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); + } finally { + await server.stop(true); + } + }); + + test("buffered HTTP 200 response.incomplete is classified as incomplete", async () => { + installUpstream(originalFetch, () => Response.json({ + type: "response.incomplete", + response: { + id: "resp_incomplete_metrics", + status: "incomplete", + incomplete_details: { reason: "max_output_tokens" }, + output: [], + }, + })); + saveConfig(runtimeConfig("openai-responses")); + const server = startServer(0); + try { + const response = await sendResponsesRequest(server); + expect(response.status).toBe(200); + await response.text(); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="incomplete"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); + } finally { + await server.stop(true); + } + }); + + test("buffered read errors stay failed even after terminal-looking partial bytes", async () => { + const bytes = new TextEncoder().encode(completedResponseJson("partial")); + installUpstream(originalFetch, () => new Response(new ReadableStream({ + start(controller) { + controller.enqueue(bytes); + controller.error(new Error("fixture read failure")); + }, + }), { headers: { "content-type": "application/json" } })); + saveConfig(runtimeConfig("openai-responses")); + const server = startServer(0); + try { + const response = await sendResponsesRequest(server); + await response.text().catch(() => ""); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); + } finally { + await server.stop(true); + } + }); + + test("terminal-free SSE EOF and downstream cancellation remain incomplete and aborted", async () => { + const encoder = new TextEncoder(); + installUpstream(originalFetch, send => { + if (send === 1) { + return new Response(responseSse(), { headers: { "content-type": "text/event-stream" } }); + } + return new Response(new ReadableStream({ + start(controller) { + controller.enqueue(encoder.encode(responseSse())); + }, + }), { headers: { "content-type": "text/event-stream" } }); + }); + saveConfig(runtimeConfig("openai-responses")); + const server = startServer(0); + try { + const incomplete = await sendResponsesRequest(server, true); + await incomplete.text(); + const cancelled = await sendResponsesRequest(server, true); + await cancelled.body?.cancel("metrics cancellation test"); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="incomplete"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="aborted"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="incomplete"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="aborted"}')).toBe(1); + } finally { + await server.stop(true); + } + }); + + test("real buffered and streaming flows distinguish missing TTFT from zero", async () => { + let send = 0; + installUpstream(originalFetch, () => { + send += 1; + return send === 1 + ? new Response(completedResponseJson(), { headers: { "content-type": "application/json" } }) + : new Response(responseSse({ terminal: "completed", output: "instant" }), { + headers: { "content-type": "text/event-stream" }, + }); + }); + saveConfig(runtimeConfig("openai-responses")); + const server = startServer(0); + const realNow = Date.now; + try { + const buffered = await sendResponsesRequest(server); + await buffered.text(); + Date.now = () => 1_900_000_000_000; + const streamed = await sendResponsesRequest(server, true); + await streamed.text(); + Date.now = realNow; + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_seconds_count{protocol="responses",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_seconds_bucket{protocol="responses",result="completed",le="0.05"}')).toBe(1); + } finally { + Date.now = realNow; + await server.stop(true); + } + }); + + test("disabled live server exposes no metrics owner and returns authenticated 404", async () => { + saveConfig(runtimeConfig("openai-responses", false)); + const server = startServer(0); + try { + const response = await fetch(new URL("/api/metrics", server.url), { + headers: { "x-opencodex-api-key": ADMIN_TOKEN }, + }); + expect(response.status).toBe(404); + expect((await response.json() as { error: { code: string } }).error.code).toBe("not_found"); + } finally { + await server.stop(true); + } + }); +}); + describe("metricsExport config admission", () => { test("absence and false stay disabled while true enables the process-lifetime owner", () => { expect(metricsExportEnabled(config())).toBe(false); From d1a1b7047b7338c31714fe383caf58a6485724ab Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 00:10:38 +0900 Subject: [PATCH 03/15] test(server): fix the real-flow fixtures and the WebSocket wiring oracle Hosted CI fold (run 35450374594): the buffered read-error stream errored in start() before a downstream body existed, and its failure leaked the spend-ledger owner into the next three cases. Streams now emit bytes first and error on pull, the client consumes/cancels bodies explicitly, every started server is tracked and fully stopped before the fixture home changes, and afterEach awaits remaining servers. The WS source oracle now expects the metrics-injected handler wiring while keeping its idle-timeout and activation guards. Production lease policy unchanged. Part of #5117 --- tests/responses/ws-endpoint.test.ts | 2 +- .../server/management-metrics-export.test.ts | 96 ++++++++++++------- 2 files changed, 64 insertions(+), 34 deletions(-) diff --git a/tests/responses/ws-endpoint.test.ts b/tests/responses/ws-endpoint.test.ts index fd9472d747a..bf90559bd92 100644 --- a/tests/responses/ws-endpoint.test.ts +++ b/tests/responses/ws-endpoint.test.ts @@ -55,7 +55,7 @@ describe("WS endpoint re-framer (120/132)", () => { "src/server/index/websocket-handler.ts", ].map(rel => readFileSync(new URL("../../" + rel, import.meta.url), "utf8")).join("\n"); expect(source).toContain("const WEBSOCKET_IDLE_TIMEOUT_SECONDS = 0;"); - expect(source).toContain("websocket: createWebsocketHandler(ctx),"); + expect(source).toContain("websocket: createWebsocketHandler(ctx, requestMetrics),"); expect(source).toContain("idleTimeout: WEBSOCKET_IDLE_TIMEOUT_SECONDS,"); expect(source).toContain("finalizeLog(httpStatusForRequestLogTerminal(status, logCtx), {"); expect(source).toContain("if (!logged) finalizeLog(turnAbort.signal.aborted ? 499 : response.status);"); diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 254342f659c..9d397b6a4f1 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -379,6 +379,21 @@ describe("metrics through live HTTP and WebSocket server flows", () => { const previousAdminToken = process.env.OPENCODEX_ADMIN_AUTH_TOKEN; let openCodexHome = ""; let isolatedCodexHome: IsolatedCodexHome | null = null; + const liveServers = new Set>(); + + const startMetricsServer = (): ReturnType => { + const server = startServer(0); + liveServers.add(server); + return server; + }; + + const stopMetricsServer = async (server: ReturnType): Promise => { + try { + await server.stop(true); + } finally { + liveServers.delete(server); + } + }; beforeEach(() => { openCodexHome = mkdtempSync(join(tmpdir(), "ocx-metrics-export-")); @@ -389,17 +404,25 @@ describe("metrics through live HTTP and WebSocket server flows", () => { globalThis.WebSocket = originalWebSocket; }); - afterEach(() => { - globalThis.fetch = originalFetch; - globalThis.WebSocket = originalWebSocket; - if (previousOpenCodexHome === undefined) delete process.env.OPENCODEX_HOME; - else process.env.OPENCODEX_HOME = previousOpenCodexHome; - if (previousAdminToken === undefined) delete process.env.OPENCODEX_ADMIN_AUTH_TOKEN; - else process.env.OPENCODEX_ADMIN_AUTH_TOKEN = previousAdminToken; - isolatedCodexHome?.restore(); - isolatedCodexHome = null; - if (openCodexHome) removeTreeWithRetry(openCodexHome); - openCodexHome = ""; + afterEach(async () => { + // The server owns the spend-ledger lease until every listener and active body settles. + // Release it before changing/removing OPENCODEX_HOME so the next fixture acquires honestly. + const stops = await Promise.allSettled([...liveServers].map(stopMetricsServer)); + try { + globalThis.fetch = originalFetch; + globalThis.WebSocket = originalWebSocket; + if (previousOpenCodexHome === undefined) delete process.env.OPENCODEX_HOME; + else process.env.OPENCODEX_HOME = previousOpenCodexHome; + if (previousAdminToken === undefined) delete process.env.OPENCODEX_ADMIN_AUTH_TOKEN; + else process.env.OPENCODEX_ADMIN_AUTH_TOKEN = previousAdminToken; + isolatedCodexHome?.restore(); + isolatedCodexHome = null; + if (openCodexHome) removeTreeWithRetry(openCodexHome); + openCodexHome = ""; + } finally { + const failure = stops.find(result => result.status === "rejected"); + if (failure?.status === "rejected") throw failure.reason; + } }); test("HTTP retry flow records one logical request and both physical sends", async () => { @@ -412,7 +435,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { usage: { prompt_tokens: 2, completion_tokens: 1, total_tokens: 3 }, })); saveConfig(runtimeConfig("openai-chat")); - const server = startServer(0); + const server = startMetricsServer(); try { const response = await sendChatRequest(server); expect(response.status).toBe(200); @@ -423,7 +446,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="chat"}')).toBe(2); expect(sampleValue(metrics, 'opencodex_recoveries_total{protocol="chat",recovery="transient"}')).toBe(1); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); @@ -433,7 +456,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { output: "socket output", }), { headers: { "content-type": "text/event-stream" } })); saveConfig(runtimeConfig("openai-responses")); - const server = startServer(0); + const server = startMetricsServer(); try { await runWebSocketTurn(server); const metrics = await scrapeServer(server); @@ -441,7 +464,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(1); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); @@ -456,7 +479,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }, })); saveConfig(runtimeConfig("openai-responses")); - const server = startServer(0); + const server = startMetricsServer(); try { const response = await sendResponsesRequest(server); expect(response.status).toBe(200); @@ -465,7 +488,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); @@ -480,7 +503,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }, })); saveConfig(runtimeConfig("openai-responses")); - const server = startServer(0); + const server = startMetricsServer(); try { const response = await sendResponsesRequest(server); expect(response.status).toBe(200); @@ -489,20 +512,27 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="incomplete"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); test("buffered read errors stay failed even after terminal-looking partial bytes", async () => { const bytes = new TextEncoder().encode(completedResponseJson("partial")); - installUpstream(originalFetch, () => new Response(new ReadableStream({ - start(controller) { - controller.enqueue(bytes); - controller.error(new Error("fixture read failure")); - }, - }), { headers: { "content-type": "application/json" } })); + installUpstream(originalFetch, () => { + let delivered = false; + return new Response(new ReadableStream({ + pull(controller) { + if (!delivered) { + delivered = true; + controller.enqueue(bytes); + return; + } + controller.error(new Error("fixture read failure")); + }, + }), { headers: { "content-type": "application/json" } }); + }); saveConfig(runtimeConfig("openai-responses")); - const server = startServer(0); + const server = startMetricsServer(); try { const response = await sendResponsesRequest(server); await response.text().catch(() => ""); @@ -510,7 +540,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); @@ -527,7 +557,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }), { headers: { "content-type": "text/event-stream" } }); }); saveConfig(runtimeConfig("openai-responses")); - const server = startServer(0); + const server = startMetricsServer(); try { const incomplete = await sendResponsesRequest(server, true); await incomplete.text(); @@ -539,7 +569,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="incomplete"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="aborted"}')).toBe(1); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); @@ -554,7 +584,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }); }); saveConfig(runtimeConfig("openai-responses")); - const server = startServer(0); + const server = startMetricsServer(); const realNow = Date.now; try { const buffered = await sendResponsesRequest(server); @@ -569,13 +599,13 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(sampleValue(metrics, 'opencodex_ttft_seconds_bucket{protocol="responses",result="completed",le="0.05"}')).toBe(1); } finally { Date.now = realNow; - await server.stop(true); + await stopMetricsServer(server); } }); test("disabled live server exposes no metrics owner and returns authenticated 404", async () => { saveConfig(runtimeConfig("openai-responses", false)); - const server = startServer(0); + const server = startMetricsServer(); try { const response = await fetch(new URL("/api/metrics", server.url), { headers: { "x-opencodex-api-key": ADMIN_TOKEN }, @@ -583,7 +613,7 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(response.status).toBe(404); expect((await response.json() as { error: { code: string } }).error.code).toBe("not_found"); } finally { - await server.stop(true); + await stopMetricsServer(server); } }); }); From c78de40d2abd526f1cd05428154dc926b371ce9e Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 00:24:06 +0900 Subject: [PATCH 04/15] fix(server): finalize failed pre-response reads before rethrow Coordinator RCA fold: a bounded upstream JSON read that rejects before handleResponses returns previously escaped addFinalRequestLog entirely. The serve-options catch now records exactly one 502 non_stream failure through the existing guarded finalizer and rethrows unchanged, so failed missing-TTFT metrics are real. The cancel race test now awaits the bounded promise resolved by the upstream stream's cancel callback (the relay records the 499 before that callback), replacing any timing assumption. Production lease behavior unchanged. Part of #5117 --- src/server/index/serve-options.ts | 43 +++++++++++-------- .../server/management-metrics-export.test.ts | 17 +++++++- 2 files changed, 41 insertions(+), 19 deletions(-) diff --git a/src/server/index/serve-options.ts b/src/server/index/serve-options.ts index a98cc89e757..58be6f03e4a 100644 --- a/src/server/index/serve-options.ts +++ b/src/server/index/serve-options.ts @@ -1359,29 +1359,38 @@ export function createServeOptions(ctx: ServeOptionsContext) { let logged = false; const finalizeNativePassthroughLog = ( status: number, - meta: { terminalStatus?: ResponsesTerminalStatus; closeReason: "terminal" | "client_cancel" }, + meta: Pick, ) => { if (logged) return; logged = true; addFinalRequestLog(requestId, start, logCtx, status, meta); }; return runAdmittedHttpTurn(req, policy, async turnAdmissionLease => { - const response = await handleResponses(req, config, logCtx, { - turnAdmissionLease, - admission, - onRequestBodyRead: () => disableResponsesRequestTimeout(req, requestServer), - abortSignal: req.signal, - onFirstOutput: () => recordFirstOutput(logCtx, start), - onNativePassthroughTerminal: status => { - finalizeNativePassthroughLog(httpStatusForRequestLogTerminal(status, logCtx), { - terminalStatus: status, - closeReason: "terminal", - }); - }, - onNativePassthroughCancel: () => { - finalizeNativePassthroughLog(499, { closeReason: "client_cancel" }); - }, - }); + let response: Response; + try { + response = await handleResponses(req, config, logCtx, { + turnAdmissionLease, + admission, + onRequestBodyRead: () => disableResponsesRequestTimeout(req, requestServer), + abortSignal: req.signal, + onFirstOutput: () => recordFirstOutput(logCtx, start), + onNativePassthroughTerminal: status => { + finalizeNativePassthroughLog(httpStatusForRequestLogTerminal(status, logCtx), { + terminalStatus: status, + closeReason: "terminal", + }); + }, + onNativePassthroughCancel: () => { + finalizeNativePassthroughLog(499, { closeReason: "client_cancel" }); + }, + }); + } catch (error) { + // A bounded upstream body can fail before handleResponses returns a client response. + // Finalize before rethrow so accounting observes the physical send while the caller + // retains the existing reset/rejection instead of receiving a synthesized response. + finalizeNativePassthroughLog(502, { closeReason: "non_stream" }); + throw error; + } return withRequestLogId( withCors(responseWithDeferredRequestLog(response, requestId, start, logCtx), req, policy), requestId, diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 9d397b6a4f1..c4837a47933 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -534,11 +534,12 @@ describe("metrics through live HTTP and WebSocket server flows", () => { saveConfig(runtimeConfig("openai-responses")); const server = startMetricsServer(); try { - const response = await sendResponsesRequest(server); - await response.text().catch(() => ""); + await expect(sendResponsesRequest(server)).rejects.toThrow(); const metrics = await scrapeServer(server); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="failed"}')).toBe(1); } finally { await stopMetricsServer(server); } @@ -546,6 +547,8 @@ describe("metrics through live HTTP and WebSocket server flows", () => { test("terminal-free SSE EOF and downstream cancellation remain incomplete and aborted", async () => { const encoder = new TextEncoder(); + let signalUpstreamCancel: (() => void) | undefined; + const upstreamCancelled = new Promise(resolve => { signalUpstreamCancel = resolve; }); installUpstream(originalFetch, send => { if (send === 1) { return new Response(responseSse(), { headers: { "content-type": "text/event-stream" } }); @@ -554,6 +557,9 @@ describe("metrics through live HTTP and WebSocket server flows", () => { start(controller) { controller.enqueue(encoder.encode(responseSse())); }, + cancel() { + signalUpstreamCancel?.(); + }, }), { headers: { "content-type": "text/event-stream" } }); }); saveConfig(runtimeConfig("openai-responses")); @@ -563,6 +569,13 @@ describe("metrics through live HTTP and WebSocket server flows", () => { await incomplete.text(); const cancelled = await sendResponsesRequest(server, true); await cancelled.body?.cancel("metrics cancellation test"); + await new Promise((resolve, reject) => { + const timeout = setTimeout(() => reject(new Error("upstream cancellation was not observed")), 5_000); + void upstreamCancelled.then(() => { + clearTimeout(timeout); + resolve(); + }, reject); + }); const metrics = await scrapeServer(server); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="incomplete"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="aborted"}')).toBe(1); From fad83a4df31e43d5cc4a6b3dfcbf79a9cd71700f Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 00:30:58 +0900 Subject: [PATCH 05/15] fix(server): classify pre-response client aborts as client_cancel Review fold: a client abort during a buffered upstream read hits the new catch before streaming cancel callbacks exist, and was misclassified as 502/non_stream. The catch now finalizes 499/client_cancel when the request signal is aborted and 502/non_stream otherwise, with the once-only guard and unchanged rethrow. A deterministic abort regression (aborted 1, failed 0, sends 1, missing TTFT) awaits the upstream cancel signal and the fetch rejection before scraping. Part of #5117 --- src/server/index/serve-options.ts | 5 +- .../server/management-metrics-export.test.ts | 53 ++++++++++++++++++- 2 files changed, 56 insertions(+), 2 deletions(-) diff --git a/src/server/index/serve-options.ts b/src/server/index/serve-options.ts index 58be6f03e4a..a67d002313d 100644 --- a/src/server/index/serve-options.ts +++ b/src/server/index/serve-options.ts @@ -1388,7 +1388,10 @@ export function createServeOptions(ctx: ServeOptionsContext) { // A bounded upstream body can fail before handleResponses returns a client response. // Finalize before rethrow so accounting observes the physical send while the caller // retains the existing reset/rejection instead of receiving a synthesized response. - finalizeNativePassthroughLog(502, { closeReason: "non_stream" }); + finalizeNativePassthroughLog( + req.signal.aborted ? 499 : 502, + { closeReason: req.signal.aborted ? "client_cancel" : "non_stream" }, + ); throw error; } return withRequestLogId( diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index c4837a47933..7186995ae49 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -156,11 +156,16 @@ async function scrapeServer(server: ReturnType): Promise, stream = false): Promise { +async function sendResponsesRequest( + server: ReturnType, + stream = false, + signal?: AbortSignal, +): Promise { return fetch(new URL("/v1/responses", server.url), { method: "POST", headers: { "content-type": "application/json" }, body: JSON.stringify({ model: "fixture/metrics-model", input: "hello", stream }), + signal, }); } @@ -545,6 +550,52 @@ describe("metrics through live HTTP and WebSocket server flows", () => { } }); + test("a client abort during buffered JSON read is counted as aborted before rethrow", async () => { + let signalReadStarted: (() => void) | undefined; + let signalUpstreamCancel: (() => void) | undefined; + const readStarted = new Promise(resolve => { signalReadStarted = resolve; }); + const upstreamCancelled = new Promise(resolve => { signalUpstreamCancel = resolve; }); + installUpstream(originalFetch, () => new Response(new ReadableStream({ + pull() { + signalReadStarted?.(); + return new Promise(() => {}); + }, + cancel() { + signalUpstreamCancel?.(); + }, + }), { headers: { "content-type": "application/json" } })); + saveConfig(runtimeConfig("openai-responses")); + const server = startMetricsServer(); + const clientAbort = new AbortController(); + try { + const request = sendResponsesRequest(server, false, clientAbort.signal); + const requestRejected = expect(request).rejects.toThrow(); + await new Promise((resolve, reject) => { + const timeout = setTimeout(() => reject(new Error("upstream buffer read did not start")), 5_000); + void readStarted.then(() => { + clearTimeout(timeout); + resolve(); + }, reject); + }); + clientAbort.abort(new DOMException("client cancelled metrics request", "AbortError")); + await new Promise((resolve, reject) => { + const timeout = setTimeout(() => reject(new Error("upstream buffered body was not cancelled")), 5_000); + void upstreamCancelled.then(() => { + clearTimeout(timeout); + resolve(); + }, reject); + }); + await requestRejected; + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="aborted"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="aborted"}')).toBe(1); + } finally { + await stopMetricsServer(server); + } + }); + test("terminal-free SSE EOF and downstream cancellation remain incomplete and aborted", async () => { const encoder = new TextEncoder(); let signalUpstreamCancel: (() => void) | undefined; From d286d936c68e64e0c6bc2c6b632a5ee013e63858 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 00:38:07 +0900 Subject: [PATCH 06/15] test(server): make the abort fixture observe the real outgoing signal Review fold: the mocked body never observed the outgoing request's signal, so a client abort did not propagate deterministically. The fixture now follows the established signal-aware pattern: the mocked outgoing request's signal errors the stream with signal.reason, every wait is event-driven with a bounded deadline (read start, abort observed, client outcome, finalized 499 row), and the metrics contract assertions are unchanged. The SSE cancel case aborts the explicit request signal after one real chunk and synchronizes on its finalized row; no upstream cancel-callback assumption remains. Part of #5117 --- .../server/management-metrics-export.test.ts | 147 ++++++++++++------ 1 file changed, 99 insertions(+), 48 deletions(-) diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 7186995ae49..bc47b6739a1 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -8,7 +8,12 @@ import { metricsExportEnabled } from "../../src/config/feature-flags"; import { getDefaultConfig } from "../../src/config/proxy-env"; import { handleManagementAPI } from "../../src/server/management-api"; import { requireManagementAuth, type ManagementAuthState } from "../../src/server/management-auth"; -import { addFinalRequestLog, type RequestLogContext } from "../../src/server/request-log"; +import { + addFinalRequestLog, + observeRequestLogsForTests, + type RequestLogContext, + type RequestLogEntry, +} from "../../src/server/request-log"; import { createRequestMetricsOwner } from "../../src/server/request-metrics"; import { startServer } from "../../src/server"; import type { OcxConfig } from "../../src/types"; @@ -66,6 +71,42 @@ function sampleValue(text: string, prefix: string): number { return Number(line.slice(line.lastIndexOf(" ") + 1)); } +function awaitBounded(promise: Promise, message: string): Promise { + return new Promise((resolve, reject) => { + const timeout = setTimeout(() => reject(new Error(message)), 5_000); + void promise.then(value => { + clearTimeout(timeout); + resolve(value); + }, error => { + clearTimeout(timeout); + reject(error); + }); + }); +} + +function nextFinalRequestLog( + predicate: (entry: RequestLogEntry) => boolean, +): { promise: Promise; dispose: () => void } { + let unsubscribe = () => {}; + let timeout: ReturnType | undefined; + const dispose = (): void => { + if (timeout) clearTimeout(timeout); + unsubscribe(); + }; + const promise = new Promise((resolve, reject) => { + timeout = setTimeout(() => { + dispose(); + reject(new Error("finalized request log was not observed")); + }, 5_000); + unsubscribe = observeRequestLogsForTests(entry => { + if (!predicate(entry)) return; + dispose(); + resolve(entry); + }); + }); + return { promise, dispose }; +} + function attempt(sendCount: number, recoveryKinds: AttemptRecoveryKind[]) { return { ordinal: 1, @@ -538,68 +579,75 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }); saveConfig(runtimeConfig("openai-responses")); const server = startMetricsServer(); + const finalized = nextFinalRequestLog(entry => entry.status === 502 && entry.inboundProtocol === "responses"); try { - await expect(sendResponsesRequest(server)).rejects.toThrow(); + const response = await sendResponsesRequest(server); + expect(response.status).toBe(500); + await response.text(); + const row = await finalized.promise; + expect(row).toMatchObject({ status: 502, closeReason: "non_stream" }); + expect(row.firstOutputMs).toBeUndefined(); const metrics = await scrapeServer(server); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="completed"}')).toBe(0); expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="failed"}')).toBe(1); } finally { + finalized.dispose(); await stopMetricsServer(server); } }); test("a client abort during buffered JSON read is counted as aborted before rethrow", async () => { let signalReadStarted: (() => void) | undefined; - let signalUpstreamCancel: (() => void) | undefined; + let signalAbortObserved: (() => void) | undefined; const readStarted = new Promise(resolve => { signalReadStarted = resolve; }); - const upstreamCancelled = new Promise(resolve => { signalUpstreamCancel = resolve; }); - installUpstream(originalFetch, () => new Response(new ReadableStream({ - pull() { - signalReadStarted?.(); - return new Promise(() => {}); - }, - cancel() { - signalUpstreamCancel?.(); - }, - }), { headers: { "content-type": "application/json" } })); + const abortObserved = new Promise(resolve => { signalAbortObserved = resolve; }); + installUpstream(originalFetch, (_send, request) => { + const signal = request.signal; + return new Response(new ReadableStream({ + start(controller) { + const abort = () => { + signalAbortObserved?.(); + try { controller.error(signal.reason); } catch { /* stream already settled */ } + }; + if (signal.aborted) abort(); + else signal.addEventListener("abort", abort, { once: true }); + }, + pull() { + signalReadStarted?.(); + return new Promise(() => {}); + }, + }), { headers: { "content-type": "application/json" } }); + }); saveConfig(runtimeConfig("openai-responses")); const server = startMetricsServer(); const clientAbort = new AbortController(); + const finalized = nextFinalRequestLog(entry => entry.status === 499 && entry.closeReason === "client_cancel"); try { const request = sendResponsesRequest(server, false, clientAbort.signal); - const requestRejected = expect(request).rejects.toThrow(); - await new Promise((resolve, reject) => { - const timeout = setTimeout(() => reject(new Error("upstream buffer read did not start")), 5_000); - void readStarted.then(() => { - clearTimeout(timeout); - resolve(); - }, reject); - }); + const requestOutcome = request.catch(error => error); + await awaitBounded(readStarted, "upstream buffer read did not start"); clientAbort.abort(new DOMException("client cancelled metrics request", "AbortError")); - await new Promise((resolve, reject) => { - const timeout = setTimeout(() => reject(new Error("upstream buffered body was not cancelled")), 5_000); - void upstreamCancelled.then(() => { - clearTimeout(timeout); - resolve(); - }, reject); - }); - await requestRejected; + await awaitBounded(abortObserved, "outgoing upstream signal did not observe client abort"); + const outcome = await awaitBounded(requestOutcome, "client abort request did not settle"); + expect(outcome).toBeInstanceOf(Error); + const row = await finalized.promise; + expect(row).toMatchObject({ status: 499, closeReason: "client_cancel" }); + expect(row.firstOutputMs).toBeUndefined(); const metrics = await scrapeServer(server); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="aborted"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="failed"}')).toBe(0); expect(sampleValue(metrics, 'opencodex_physical_sends_total{protocol="responses"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="aborted"}')).toBe(1); } finally { + finalized.dispose(); await stopMetricsServer(server); } }); test("terminal-free SSE EOF and downstream cancellation remain incomplete and aborted", async () => { const encoder = new TextEncoder(); - let signalUpstreamCancel: (() => void) | undefined; - const upstreamCancelled = new Promise(resolve => { signalUpstreamCancel = resolve; }); installUpstream(originalFetch, send => { if (send === 1) { return new Response(responseSse(), { headers: { "content-type": "text/event-stream" } }); @@ -608,9 +656,6 @@ describe("metrics through live HTTP and WebSocket server flows", () => { start(controller) { controller.enqueue(encoder.encode(responseSse())); }, - cancel() { - signalUpstreamCancel?.(); - }, }), { headers: { "content-type": "text/event-stream" } }); }); saveConfig(runtimeConfig("openai-responses")); @@ -618,20 +663,26 @@ describe("metrics through live HTTP and WebSocket server flows", () => { try { const incomplete = await sendResponsesRequest(server, true); await incomplete.text(); - const cancelled = await sendResponsesRequest(server, true); - await cancelled.body?.cancel("metrics cancellation test"); - await new Promise((resolve, reject) => { - const timeout = setTimeout(() => reject(new Error("upstream cancellation was not observed")), 5_000); - void upstreamCancelled.then(() => { - clearTimeout(timeout); - resolve(); - }, reject); - }); - const metrics = await scrapeServer(server); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="incomplete"}')).toBe(1); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="aborted"}')).toBe(1); - expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="incomplete"}')).toBe(1); - expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="aborted"}')).toBe(1); + const finalized = nextFinalRequestLog(entry => entry.status === 499 && entry.closeReason === "client_cancel"); + const clientAbort = new AbortController(); + const cancelled = await sendResponsesRequest(server, true, clientAbort.signal); + const reader = cancelled.body?.getReader(); + try { + expect(reader).toBeDefined(); + expect((await reader!.read()).done).toBe(false); + clientAbort.abort(new DOMException("client cancelled streaming metrics request", "AbortError")); + const row = await finalized.promise; + expect(row).toMatchObject({ status: 499, closeReason: "client_cancel" }); + expect(row.firstOutputMs).toBeUndefined(); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="incomplete"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="responses",result="aborted"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="incomplete"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_ttft_missing_total{protocol="responses",result="aborted"}')).toBe(1); + } finally { + await reader?.cancel().catch(() => {}); + finalized.dispose(); + } } finally { await stopMetricsServer(server); } From be7a8c2ad194bce6ffe359282edfef4a61ad6093 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 00:40:08 +0900 Subject: [PATCH 07/15] feat(server): add the test-only finalized-row observer seam Mill's deterministic fixtures synchronize on retained request-history rows; this is the observer they subscribe to. Empty by default, notified synchronously after a row enters retained history, and observer errors can never affect request logging. Required by the already-pushed real-flow tests. Part of #5117 --- src/server/request-log.ts | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/src/server/request-log.ts b/src/server/request-log.ts index 138675a69bf..176ec0c5a2c 100644 --- a/src/server/request-log.ts +++ b/src/server/request-log.ts @@ -296,6 +296,7 @@ export interface RequestLogEntry { } const requestLog: RequestLogEntry[] = []; +const requestLogObserversForTests = new Set<(entry: RequestLogEntry) => void>(); const MAX_LOG_SIZE = 2000; const requestLogEntryBytes = new WeakMap(); let requestLogBytes = 0; @@ -496,6 +497,9 @@ export function addRequestLog(entry: RequestLogEntry) { else if (retained !== entry) delete retained.claudeCompatibility; entry = retained; retainRequestLogEntry(entry); + for (const observer of requestLogObserversForTests) { + try { observer(entry); } catch { /* test observation must never fail request logging */ } + } try { // Failure diagnostics survive the 200-entry ring buffer by riding the persisted // usage entry (devlog/_plan/260716_claudecode_hardening/030). Success rows stay @@ -571,6 +575,12 @@ export function addRequestLog(entry: RequestLogEntry) { } } +/** Test-only finalized-row observation without polling the management projection. */ +export function observeRequestLogsForTests(observer: (entry: RequestLogEntry) => void): () => void { + requestLogObserversForTests.add(observer); + return () => { requestLogObserversForTests.delete(observer); }; +} + export function nextRequestLogId(_timestamp = Date.now()): string { return `ocx-${randomBytes(16).toString("hex")}`; } @@ -1841,4 +1851,5 @@ export function clearRequestLogsForTests(): void { requestLog.length = 0; requestLogBytes = 0; requestLogsHydratedFromDisk = false; + requestLogObserversForTests.clear(); } From 0b549eb6ae8d6da6696653a8dfade4ba84db6407 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 00:56:53 +0900 Subject: [PATCH 08/15] test(server): deterministic error-boundary and rejection-safe waits MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review fold: the read-error case now installs a narrow Bun.serve options spy (the existing real-server pattern) with an explicit test-only error handler that returns 500, asserts the exact expected fixture error, and fails on any unexpected error — the real fetch/routing/finalization pipeline stays active and production error behavior is unchanged. The finalized-row subscription promise is now non-rejecting; deadlines apply only at actual await sites, so an unattended subscription can never unhandled-reject between tests. Abort and SSE cancellation stay signal-aware and event-driven. Part of #5117 --- .../server/management-metrics-export.test.ts | 71 ++++++++++++++----- 1 file changed, 55 insertions(+), 16 deletions(-) diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index bc47b6739a1..a830ea76bf6 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -1,4 +1,4 @@ -import { afterEach, beforeEach, describe, expect, test } from "bun:test"; +import { afterEach, beforeEach, describe, expect, spyOn, test } from "bun:test"; import { mkdtempSync, readFileSync } from "node:fs"; import { tmpdir } from "node:os"; import { join } from "node:path"; @@ -26,6 +26,7 @@ import { repoPath } from "../helpers/repo-root"; const ADMIN_TOKEN = "ocx_admin_aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"; const DATA_TOKEN = "ocx_data_bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb"; const METRICS_UPSTREAM = "metrics-upstream.example"; +const OBSERVATION_TIMEOUT = Symbol("observation-timeout"); function authState(): ManagementAuthState { return { @@ -84,20 +85,22 @@ function awaitBounded(promise: Promise, message: string): Promise { }); } +function awaitObservation(promise: Promise): Promise { + return new Promise(resolve => { + const timeout = setTimeout(() => resolve(OBSERVATION_TIMEOUT), 5_000); + void promise.then(value => { + clearTimeout(timeout); + resolve(value); + }); + }); +} + function nextFinalRequestLog( predicate: (entry: RequestLogEntry) => boolean, ): { promise: Promise; dispose: () => void } { let unsubscribe = () => {}; - let timeout: ReturnType | undefined; - const dispose = (): void => { - if (timeout) clearTimeout(timeout); - unsubscribe(); - }; - const promise = new Promise((resolve, reject) => { - timeout = setTimeout(() => { - dispose(); - reject(new Error("finalized request log was not observed")); - }, 5_000); + const dispose = (): void => { unsubscribe(); }; + const promise = new Promise(resolve => { unsubscribe = observeRequestLogsForTests(entry => { if (!predicate(entry)) return; dispose(); @@ -433,6 +436,28 @@ describe("metrics through live HTTP and WebSocket server flows", () => { return server; }; + const startMetricsServerWithExpectedError = ( + expected: Error, + observed: unknown[], + unexpected: unknown[], + ): ReturnType => { + const nativeServe = Bun.serve.bind(Bun); + const serveSpy = spyOn(Bun, "serve").mockImplementation(options => nativeServe({ + ...options, + error(error) { + if (error === expected) observed.push(error); + else unexpected.push(error); + return new Response("expected metrics fixture server error", { status: 500 }); + }, + } as Parameters[0])); + try { + return startMetricsServer(); + } finally { + // startServer is synchronous; restore before any request or awaited cleanup. + serveSpy.mockRestore(); + } + }; + const stopMetricsServer = async (server: ReturnType): Promise => { try { await server.stop(true); @@ -564,6 +589,9 @@ describe("metrics through live HTTP and WebSocket server flows", () => { test("buffered read errors stay failed even after terminal-looking partial bytes", async () => { const bytes = new TextEncoder().encode(completedResponseJson("partial")); + const fixtureError = new Error("fixture read failure"); + const observedErrors: unknown[] = []; + const unexpectedErrors: unknown[] = []; installUpstream(originalFetch, () => { let delivered = false; return new Response(new ReadableStream({ @@ -573,18 +601,23 @@ describe("metrics through live HTTP and WebSocket server flows", () => { controller.enqueue(bytes); return; } - controller.error(new Error("fixture read failure")); + controller.error(fixtureError); }, }), { headers: { "content-type": "application/json" } }); }); saveConfig(runtimeConfig("openai-responses")); - const server = startMetricsServer(); + const server = startMetricsServerWithExpectedError(fixtureError, observedErrors, unexpectedErrors); const finalized = nextFinalRequestLog(entry => entry.status === 502 && entry.inboundProtocol === "responses"); try { const response = await sendResponsesRequest(server); expect(response.status).toBe(500); await response.text(); - const row = await finalized.promise; + expect(observedErrors).toEqual([fixtureError]); + expect(unexpectedErrors).toEqual([]); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("read-error finalization was not observed"); + const row = observedRow; expect(row).toMatchObject({ status: 502, closeReason: "non_stream" }); expect(row.firstOutputMs).toBeUndefined(); const metrics = await scrapeServer(server); @@ -632,7 +665,10 @@ describe("metrics through live HTTP and WebSocket server flows", () => { await awaitBounded(abortObserved, "outgoing upstream signal did not observe client abort"); const outcome = await awaitBounded(requestOutcome, "client abort request did not settle"); expect(outcome).toBeInstanceOf(Error); - const row = await finalized.promise; + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("buffered-abort finalization was not observed"); + const row = observedRow; expect(row).toMatchObject({ status: 499, closeReason: "client_cancel" }); expect(row.firstOutputMs).toBeUndefined(); const metrics = await scrapeServer(server); @@ -671,7 +707,10 @@ describe("metrics through live HTTP and WebSocket server flows", () => { expect(reader).toBeDefined(); expect((await reader!.read()).done).toBe(false); clientAbort.abort(new DOMException("client cancelled streaming metrics request", "AbortError")); - const row = await finalized.promise; + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("stream-cancel finalization was not observed"); + const row = observedRow; expect(row).toMatchObject({ status: 499, closeReason: "client_cancel" }); expect(row.firstOutputMs).toBeUndefined(); const metrics = await scrapeServer(server); From de951fbea4de3472193638a6255dd86922d1c604 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 01:04:50 +0900 Subject: [PATCH 09/15] test(server): make the SSE cancellation mock observe the abort signal MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Final harness fold: the second SSE responder now captures the outgoing request signal and errors its stream with signal.reason on abort, so a client abort rejects the pending inspection read and the relay finalizes 499 immediately — inside the existing 5s bound, with the production 15s post-cancel drain unchanged. Part of #5117 --- tests/server/management-metrics-export.test.ts | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index a830ea76bf6..577496934fc 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -684,12 +684,21 @@ describe("metrics through live HTTP and WebSocket server flows", () => { test("terminal-free SSE EOF and downstream cancellation remain incomplete and aborted", async () => { const encoder = new TextEncoder(); - installUpstream(originalFetch, send => { + installUpstream(originalFetch, (send, request) => { if (send === 1) { return new Response(responseSse(), { headers: { "content-type": "text/event-stream" } }); } + const signal = request.signal; return new Response(new ReadableStream({ start(controller) { + const abort = () => { + try { controller.error(signal.reason); } catch { /* stream already settled */ } + }; + if (signal.aborted) { + abort(); + return; + } + signal.addEventListener("abort", abort, { once: true }); controller.enqueue(encoder.encode(responseSse())); }, }), { headers: { "content-type": "text/event-stream" } }); From 7dbac371921eb27c9413a74b526c1d61e8c4aa36 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 01:27:00 +0900 Subject: [PATCH 10/15] fix(server): classify successful 101 upgrades as completed Review fold: a successful sideband/dictation upgrade finalizes with 101 and was counted as failed because classification only covered 200-399. 101 now classifies as completed strictly after cancellation and terminal-state precedence; a 101 with a failed or incomplete terminal still counts as failed or incomplete. Regressions cover a real upgrade flow and the precedence case. Part of #5117 --- src/server/request-metrics.ts | 3 +- .../server/management-metrics-export.test.ts | 56 ++++++++++++++++++- 2 files changed, 56 insertions(+), 3 deletions(-) diff --git a/src/server/request-metrics.ts b/src/server/request-metrics.ts index 7e132c90dde..d6126d5d9da 100644 --- a/src/server/request-metrics.ts +++ b/src/server/request-metrics.ts @@ -78,7 +78,8 @@ function classifyResult(fact: RequestMetricFinalFact): RequestMetricsResult { || fact.closeReason === "body_stall" || fact.closeReason === "body_overflow") return "incomplete"; if (fact.terminalStatus === "completed") return "completed"; - if (fact.terminalStatus === undefined && fact.status >= 200 && fact.status < 400) return "completed"; + if (fact.terminalStatus === undefined + && (fact.status === 101 || (fact.status >= 200 && fact.status < 400))) return "completed"; return "failed"; } diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 577496934fc..36f6d2db54f 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -291,6 +291,16 @@ describe("request metrics aggregation", () => { expect(sampleValue(output, 'opencodex_ttft_missing_total{protocol="responses",result="failed"}')).toBe(0); }); + test("terminal precedence keeps failed and incomplete 101 facts out of completed", () => { + const metrics = createRequestMetricsOwner(123); + metrics.recordFinalRequest({ status: 101, durationMs: 1, terminalStatus: "failed" }); + metrics.recordFinalRequest({ status: 101, durationMs: 1, terminalStatus: "incomplete" }); + const output = metrics.snapshot(); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(1); + expect(sampleValue(output, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + }); + test("incomplete, aborted, and missing TTFT denominators remain distinct", () => { const metrics = createRequestMetricsOwner(123); metrics.recordFinalRequest({ protocol: "chat", status: 502, durationMs: 100, terminalStatus: "incomplete" }); @@ -430,8 +440,10 @@ describe("metrics through live HTTP and WebSocket server flows", () => { let isolatedCodexHome: IsolatedCodexHome | null = null; const liveServers = new Set>(); - const startMetricsServer = (): ReturnType => { - const server = startServer(0); + const startMetricsServer = ( + deps?: Parameters[1], + ): ReturnType => { + const server = startServer(0, deps); liveServers.add(server); return server; }; @@ -539,6 +551,46 @@ describe("metrics through live HTTP and WebSocket server flows", () => { } }); + test("successful live sideband upgrade records HTTP 101 as completed", async () => { + const upstream = Bun.serve({ + port: 0, + fetch(req, server) { + if (req.headers.get("upgrade")?.toLowerCase() === "websocket" + && server.upgrade(req, { data: {} })) return undefined; + return new Response("upgrade required", { status: 426 }); + }, + websocket: { message() {} }, + }); + saveConfig(runtimeConfig("openai-responses")); + const upstreamUrl = new URL("/upstream", upstream.url); + upstreamUrl.protocol = "ws:"; + const server = startMetricsServer({ + liveSidebandWebSocketFactory: () => new WebSocket(upstreamUrl), + }); + const finalized = nextFinalRequestLog(entry => entry.status === 101); + const url = new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url); + url.protocol = "ws:"; + const socket = new WebSocket(url); + try { + await awaitBounded(new Promise((resolve, reject) => { + socket.addEventListener("open", () => resolve(), { once: true }); + socket.addEventListener("error", () => reject(new Error("live sideband upgrade failed")), { once: true }); + }), "live sideband client did not open"); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("101 upgrade finalization was not observed"); + expect(observedRow.status).toBe(101); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); + } finally { + socket.close(); + finalized.dispose(); + await stopMetricsServer(server); + await upstream.stop(true); + } + }); + test("buffered HTTP 200 response.failed is classified as failed", async () => { installUpstream(originalFetch, () => Response.json({ type: "response.failed", From 313dc9b862ba4366ee86a5aa24405696ee8e0f54 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 01:47:03 +0900 Subject: [PATCH 11/15] test(server): activate the live upgrade fixture through the real eligibility path Hosted CI fold: the fixture provider was ineligible for the real-time relay, which refuses before the injected factory runs. The fixture now declares a canonical openai-apikey provider with a fake key, the factory call count proves the genuine 101 path was taken, and a bounded HTTP upgrade probe captures refusal status/body on failure. Production eligibility unchanged. Part of #5117 --- .../server/management-metrics-export.test.ts | 39 +++++++++++++++++-- 1 file changed, 36 insertions(+), 3 deletions(-) diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 36f6d2db54f..7308ff8f7ee 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -95,6 +95,25 @@ function awaitObservation(promise: Promise): Promise { + const httpUrl = new URL(wsUrl); + httpUrl.protocol = "http:"; + try { + const response = await fetch(httpUrl, { + headers: { + connection: "upgrade", + upgrade: "websocket", + "sec-websocket-version": "13", + "sec-websocket-key": Buffer.from("0123456789abcdef").toString("base64"), + }, + signal: AbortSignal.timeout(1_000), + }); + return `HTTP ${response.status}: ${(await response.text()).slice(0, 512)}`; + } catch (error) { + return `HTTP refusal unavailable: ${error instanceof Error ? error.message : String(error)}`; + } +} + function nextFinalRequestLog( predicate: (entry: RequestLogEntry) => boolean, ): { promise: Promise; dispose: () => void } { @@ -561,11 +580,22 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }, websocket: { message() {} }, }); - saveConfig(runtimeConfig("openai-responses")); + const config = runtimeConfig("openai-responses"); + config.providers["openai-apikey"] = { + adapter: "openai-responses", + baseUrl: "https://api.openai.com/v1", + apiKey: "sk-metrics-fixture", + authMode: "key", + }; + saveConfig(config); const upstreamUrl = new URL("/upstream", upstream.url); upstreamUrl.protocol = "ws:"; + let factoryCalls = 0; const server = startMetricsServer({ - liveSidebandWebSocketFactory: () => new WebSocket(upstreamUrl), + liveSidebandWebSocketFactory: () => { + factoryCalls += 1; + return new WebSocket(upstreamUrl); + }, }); const finalized = nextFinalRequestLog(entry => entry.status === 101); const url = new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url); @@ -574,12 +604,15 @@ describe("metrics through live HTTP and WebSocket server flows", () => { try { await awaitBounded(new Promise((resolve, reject) => { socket.addEventListener("open", () => resolve(), { once: true }); - socket.addEventListener("error", () => reject(new Error("live sideband upgrade failed")), { once: true }); + socket.addEventListener("error", () => { + void describeUpgradeRefusal(url).then(detail => reject(new Error(`live sideband upgrade failed; ${detail}`))); + }, { once: true }); }), "live sideband client did not open"); const observedRow = await awaitObservation(finalized.promise); expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); if (observedRow === OBSERVATION_TIMEOUT) throw new Error("101 upgrade finalization was not observed"); expect(observedRow.status).toBe(101); + expect(factoryCalls).toBe(1); const metrics = await scrapeServer(server); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); From fd469fe26336bf426d5a2f478ebee40949260722 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 02:15:06 +0900 Subject: [PATCH 12/15] fix(server): finalize live-sideband exits and harden the upgrade fixture Review fold: six post-context exits in the live-sideband path skipped metrics finalization. A request-local idempotent finalizer now records exactly one row for each (503 refusal, resolver exception, acquisition cancel 499 / timeout 504 / internal 503, pre-upgrade cancel 499, upgrade throw 502, upgrade refused 426), preserving statuses, client_cancel semantics, and rethrow behavior; existing resolved/101 paths are unchanged. The upgrade fixture's upstream is now always stopped via an outer try/finally with nested socket/metrics cleanup. Part of #5117 --- src/server/index/serve-options.ts | 42 +++- .../server/management-metrics-export.test.ts | 227 +++++++++++++++--- 2 files changed, 220 insertions(+), 49 deletions(-) diff --git a/src/server/index/serve-options.ts b/src/server/index/serve-options.ts index a67d002313d..657f5f0b5b9 100644 --- a/src/server/index/serve-options.ts +++ b/src/server/index/serve-options.ts @@ -1579,8 +1579,20 @@ export function createServeOptions(ctx: ServeOptionsContext) { ...requestMetricsLogContext, ...admissionFields(admission), }; + let liveRequestFinalized = false; + const finalizeLiveRequest = ( + status: number, + meta?: Pick, + ): void => { + if (liveRequestFinalized) return; + liveRequestFinalized = true; + addFinalRequestLog(requestId, start, logCtx, status, meta); + }; const turnAdmissionLease = tryAdmitTurn(sessionLaneIdFromRequest(req.headers)); - if (!turnAdmissionLease) return serverBusyResponse(req, "active turns", policy); + if (!turnAdmissionLease) { + finalizeLiveRequest(503); + return serverBusyResponse(req, "active turns", policy); + } const audioController = audioClient ? new AbortController() : undefined; if (audioController) registerTurn(audioController, turnAdmissionLease); const acquisition = audioController @@ -1600,18 +1612,26 @@ export function createServeOptions(ctx: ServeOptionsContext) { ? await resolveLiveSidebandUpgrade(req, config, logCtx, liveSidebandTarget, turnAdmissionLease) : formatErrorResponse(401, "authentication_error", "opencodex API key required"); } catch (error) { - releaseAcquisition(); + try { releaseAcquisition(); } + finally { + finalizeLiveRequest(req.signal.aborted ? 499 : 500, + req.signal.aborted ? { closeReason: "client_cancel" } : undefined); + } throw error; } if (acquisition?.signal.aborted) { + const status = req.signal.aborted ? 499 : acquisition.didExpire() ? 504 : 503; try { if (!(resolved instanceof Response) && "finish" in resolved) resolved.finish(); } - finally { releaseAcquisition(); } - return withCors(formatErrorResponse(req.signal.aborted ? 499 : acquisition.didExpire() ? 504 : 503, + finally { + try { releaseAcquisition(); } + finally { finalizeLiveRequest(status, status === 499 ? { closeReason: "client_cancel" } : undefined); } + } + return withCors(formatErrorResponse(status, "upstream_error", acquisition.didExpire() ? "Audio connection timed out" : "Audio connection canceled"), req, policy); } if (resolved instanceof Response) { releaseAcquisition(); - addFinalRequestLog(requestId, start, logCtx, resolved.status); + finalizeLiveRequest(resolved.status); return withCors(resolved, req, policy); } const audio = "finish" in resolved ? resolved : undefined; @@ -1624,7 +1644,8 @@ export function createServeOptions(ctx: ServeOptionsContext) { else releaseAcquisition(); }; if (req.signal.aborted) { - discardUpgrade(); + try { discardUpgrade(); } + finally { finalizeLiveRequest(499, { closeReason: "client_cancel" }); } return withCors(formatErrorResponse(499, "client_closed_request", "Audio connection canceled"), req, policy); } const upstreamHandshake = await openLiveSidebandUpstream( @@ -1642,7 +1663,8 @@ export function createServeOptions(ctx: ServeOptionsContext) { } else { discardUpgrade(); } - addFinalRequestLog(requestId, start, logCtx, upstreamHandshake.status); + finalizeLiveRequest(upstreamHandshake.status, + upstreamHandshake.status === 499 ? { closeReason: "client_cancel" } : undefined); console.error("[live] sideband upstream handshake failed: " + upstreamHandshake.message); return withCors( formatErrorResponse(upstreamHandshake.status, upstreamHandshake.code, upstreamHandshake.message), @@ -1658,7 +1680,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { code: "upstream_error", message: "voice upstream closed before client upgrade", }; - addFinalRequestLog(requestId, start, logCtx, failure.status); + finalizeLiveRequest(failure.status); return withCors(formatErrorResponse(failure.status, failure.code, failure.message), req, policy); } let upgraded = false; @@ -1690,11 +1712,12 @@ export function createServeOptions(ctx: ServeOptionsContext) { /* ignore */ } closeLiveSidebandBeforeUpgrade(upstreamHandshake.socket, () => discardUpgrade()); + finalizeLiveRequest(502); return withCors(formatErrorResponse(502, "upstream_error", "Audio WebSocket upgrade failed"), req, policy); } if (upgraded) { acquisition?.clear(); - addFinalRequestLog(requestId, start, logCtx, 101); + finalizeLiveRequest(101); return undefined as unknown as Response; } try { @@ -1703,6 +1726,7 @@ export function createServeOptions(ctx: ServeOptionsContext) { /* ignore */ } closeLiveSidebandBeforeUpgrade(upstreamHandshake.socket, () => discardUpgrade()); + finalizeLiveRequest(426); return withCors(formatErrorResponse(426, "upgrade_required", "WebSocket upgrade failed"), req, policy); } diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 7308ff8f7ee..9f551796909 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -164,6 +164,38 @@ function runtimeConfig( } as OcxConfig; } +function liveMetricsConfig(): OcxConfig { + const config = runtimeConfig("openai-responses"); + config.providers["openai-apikey"] = { + adapter: "openai-responses", + baseUrl: "https://api.openai.com/v1", + apiKey: "sk-metrics-fixture", + authMode: "key", + }; + return config; +} + +function upgradeRequestHeaders(): Record { + return { + connection: "upgrade", + upgrade: "websocket", + "sec-websocket-version": "13", + "sec-websocket-key": Buffer.from("0123456789abcdef").toString("base64"), + }; +} + +function startLiveMetricsUpstream(): ReturnType { + return Bun.serve({ + port: 0, + fetch(req, server) { + if (req.headers.get("upgrade")?.toLowerCase() === "websocket" + && server.upgrade(req, { data: {} })) return undefined; + return new Response("upgrade required", { status: 426 }); + }, + websocket: { message() {} }, + }); +} + function completedResponseJson(text = "ok"): string { return JSON.stringify({ type: "response.completed", @@ -489,6 +521,47 @@ describe("metrics through live HTTP and WebSocket server flows", () => { } }; + const startMetricsServerWithLiveRequestControl = ( + control: "abort" | "upgrade-throw" | "upgrade-false", + deps?: Parameters[1], + ): ReturnType => { + const nativeServe = Bun.serve.bind(Bun); + const serveSpy = spyOn(Bun, "serve").mockImplementation(options => { + const fetchHandler = options.fetch; + if (typeof fetchHandler !== "function") return nativeServe(options); + return nativeServe({ + ...options, + fetch(req, requestServer) { + if (new URL(req.url).pathname !== "/v1/realtime") { + return Reflect.apply(fetchHandler, requestServer, [req, requestServer]); + } + let routedRequest = req; + if (control === "abort") { + const abort = new AbortController(); + abort.abort(new Error("metrics pre-upgrade cancellation")); + routedRequest = new Request(req, { signal: abort.signal }); + } + const routedServer = control === "abort" ? requestServer : new Proxy(requestServer, { + get(target, property) { + if (property === "upgrade") return () => { + if (control === "upgrade-throw") throw new Error("metrics upgrade fixture failure"); + return false; + }; + const value = Reflect.get(target, property, target); + return typeof value === "function" ? value.bind(target) : value; + }, + }); + return Reflect.apply(fetchHandler, routedServer, [routedRequest, routedServer]); + }, + } as Parameters[0]); + }); + try { + return startMetricsServer(deps); + } finally { + serveSpy.mockRestore(); + } + }; + const stopMetricsServer = async (server: ReturnType): Promise => { try { await server.stop(true); @@ -571,55 +644,129 @@ describe("metrics through live HTTP and WebSocket server flows", () => { }); test("successful live sideband upgrade records HTTP 101 as completed", async () => { - const upstream = Bun.serve({ - port: 0, - fetch(req, server) { - if (req.headers.get("upgrade")?.toLowerCase() === "websocket" - && server.upgrade(req, { data: {} })) return undefined; - return new Response("upgrade required", { status: 426 }); - }, - websocket: { message() {} }, - }); - const config = runtimeConfig("openai-responses"); - config.providers["openai-apikey"] = { - adapter: "openai-responses", - baseUrl: "https://api.openai.com/v1", - apiKey: "sk-metrics-fixture", - authMode: "key", - }; - saveConfig(config); - const upstreamUrl = new URL("/upstream", upstream.url); - upstreamUrl.protocol = "ws:"; - let factoryCalls = 0; - const server = startMetricsServer({ - liveSidebandWebSocketFactory: () => { - factoryCalls += 1; - return new WebSocket(upstreamUrl); - }, + const upstream = startLiveMetricsUpstream(); + try { + saveConfig(liveMetricsConfig()); + const upstreamUrl = new URL("/upstream", upstream.url); + upstreamUrl.protocol = "ws:"; + let factoryCalls = 0; + let server: ReturnType | undefined; + try { + server = startMetricsServer({ + liveSidebandWebSocketFactory: () => { + factoryCalls += 1; + return new WebSocket(upstreamUrl); + }, + }); + const finalized = nextFinalRequestLog(entry => entry.status === 101); + try { + const url = new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url); + url.protocol = "ws:"; + let socket: WebSocket | undefined; + try { + const activeSocket = socket = new WebSocket(url); + await awaitBounded(new Promise((resolve, reject) => { + activeSocket.addEventListener("open", () => resolve(), { once: true }); + activeSocket.addEventListener("error", () => { + void describeUpgradeRefusal(url).then(detail => reject(new Error(`live sideband upgrade failed; ${detail}`))); + }, { once: true }); + }), "live sideband client did not open"); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("101 upgrade finalization was not observed"); + expect(observedRow.status).toBe(101); + expect(factoryCalls).toBe(1); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); + } finally { + socket?.close(); + } + } finally { + finalized.dispose(); + } + } finally { + if (server) await stopMetricsServer(server); + } + } finally { + await upstream.stop(true); + } + }); + + test("pre-upgrade cancellation finalizes exactly one aborted live request", async () => { + saveConfig(liveMetricsConfig()); + const server = startMetricsServerWithLiveRequestControl("abort", { + liveSidebandWebSocketFactory: () => { throw new Error("cancelled request reached upstream dial"); }, }); - const finalized = nextFinalRequestLog(entry => entry.status === 101); - const url = new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url); - url.protocol = "ws:"; - const socket = new WebSocket(url); + const finalized = nextFinalRequestLog(entry => entry.status === 499); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); try { - await awaitBounded(new Promise((resolve, reject) => { - socket.addEventListener("open", () => resolve(), { once: true }); - socket.addEventListener("error", () => { - void describeUpgradeRefusal(url).then(detail => reject(new Error(`live sideband upgrade failed; ${detail}`))); - }, { once: true }); - }), "live sideband client did not open"); + const response = await fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: upgradeRequestHeaders(), + }); + expect(response.status).toBe(499); + await response.text(); const observedRow = await awaitObservation(finalized.promise); expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); - if (observedRow === OBSERVATION_TIMEOUT) throw new Error("101 upgrade finalization was not observed"); - expect(observedRow.status).toBe(101); - expect(factoryCalls).toBe(1); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("499 upgrade cancellation was not finalized"); + expect(observedRow.status).toBe(499); + expect(observedRow.closeReason).toBe("client_cancel"); + expect(rows.map(entry => entry.status)).toEqual([499]); const metrics = await scrapeServer(server); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(1); expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); } finally { - socket.close(); + disposeRows(); finalized.dispose(); await stopMetricsServer(server); + } + }); + + test.each([ + ["upgrade-throw", 502], + ["upgrade-false", 426], + ] as const)("%s finalizes exactly one failed live request", async (control, expectedStatus) => { + const upstream = startLiveMetricsUpstream(); + try { + saveConfig(liveMetricsConfig()); + const upstreamUrl = new URL("/upstream", upstream.url); + upstreamUrl.protocol = "ws:"; + let factoryCalls = 0; + const server = startMetricsServerWithLiveRequestControl(control, { + liveSidebandWebSocketFactory: () => { + factoryCalls += 1; + return new WebSocket(upstreamUrl); + }, + }); + const finalized = nextFinalRequestLog(entry => entry.status === expectedStatus); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + const response = await fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: upgradeRequestHeaders(), + }); + expect(response.status).toBe(expectedStatus); + await response.text(); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error(`${expectedStatus} upgrade refusal was not finalized`); + expect(observedRow.status).toBe(expectedStatus); + expect(rows.map(entry => entry.status)).toEqual([expectedStatus]); + expect(factoryCalls).toBe(1); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + } finally { + disposeRows(); + finalized.dispose(); + await stopMetricsServer(server); + } + } finally { await upstream.stop(true); } }); From 82f3660171e8ef7ace3a9e9c25bfaca6ee4df158 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 02:53:35 +0900 Subject: [PATCH 13/15] test(server): cover acquisition cancellation, deadline, and refusal paths Review fold: real-route regressions for acquisition cancellation (one 499 client_cancel row, one aborted metric), the production 120s acquisition deadline (one 504 row, timer captured via the established audio-transcriptions precedent), capacity refusal (one 503 row), and the resolver exception (one 500 row through the real error handler). Each proves once-only finalization and exactly one logical metric. Part of #5117 --- .../server/management-metrics-export.test.ts | 177 ++++++++++++++++++ 1 file changed, 177 insertions(+) diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 9f551796909..9cd89685af7 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -6,6 +6,8 @@ import { saveConfig } from "../../src/config"; import { configDiagnosticsFromRaw, validateConfigCandidate } from "../../src/config/diagnostics"; import { metricsExportEnabled } from "../../src/config/feature-flags"; import { getDefaultConfig } from "../../src/config/proxy-env"; +import * as audioUpstream from "../../src/server/audio-upstream"; +import { MAX_ACTIVE_SESSION_LANES, tryAdmitTurn } from "../../src/server/lifecycle"; import { handleManagementAPI } from "../../src/server/management-api"; import { requireManagementAuth, type ManagementAuthState } from "../../src/server/management-auth"; import { @@ -166,6 +168,7 @@ function runtimeConfig( function liveMetricsConfig(): OcxConfig { const config = runtimeConfig("openai-responses"); + config.apiKeys = [{ id: "metrics-audio", name: "metrics audio", key: DATA_TOKEN, createdAt: "2026-09-19T00:00:00Z" }]; config.providers["openai-apikey"] = { adapter: "openai-responses", baseUrl: "https://api.openai.com/v1", @@ -196,6 +199,17 @@ function startLiveMetricsUpstream(): ReturnType { }); } +function stallAudioAcquisition(started: { resolve(): void }) { + return spyOn(audioUpstream, "resolveAudioUpstream").mockImplementation(async (_headers, _config, _log, options) => { + started.resolve(); + await new Promise(resolve => { + if (options.signal?.aborted) resolve(); + else options.signal?.addEventListener("abort", () => resolve(), { once: true }); + }); + return new Response("acquisition interrupted", { status: 503 }); + }); +} + function completedResponseJson(text = "ok"): string { return JSON.stringify({ type: "response.completed", @@ -725,6 +739,169 @@ describe("metrics through live HTTP and WebSocket server flows", () => { } }); + test("client cancellation during acquisition finalizes exactly one aborted live request", async () => { + saveConfig(liveMetricsConfig()); + const acquisitionStarted = Promise.withResolvers(); + const resolver = stallAudioAcquisition(acquisitionStarted); + const server = startMetricsServer({ + liveSidebandWebSocketFactory: () => { throw new Error("cancelled acquisition reached upstream dial"); }, + }); + const finalized = nextFinalRequestLog(entry => entry.status === 499); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + const clientAbort = new AbortController(); + const clientOutcome = fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, + signal: clientAbort.signal, + }).catch(error => error); + try { + await awaitBounded(acquisitionStarted.promise, "audio acquisition did not start"); + clientAbort.abort(new Error("metrics acquisition client cancellation")); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("acquisition cancellation was not finalized"); + expect(observedRow.status).toBe(499); + expect(observedRow.closeReason).toBe("client_cancel"); + expect(rows.map(entry => entry.status)).toEqual([499]); + await awaitBounded(clientOutcome, "cancelled acquisition client did not settle"); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + clientAbort.abort(); + disposeRows(); + finalized.dispose(); + resolver.mockRestore(); + await stopMetricsServer(server); + } + }); + + test("acquisition deadline finalizes exactly one failed 504 live request", async () => { + saveConfig(liveMetricsConfig()); + const acquisitionStarted = Promise.withResolvers(); + const resolver = stallAudioAcquisition(acquisitionStarted); + const server = startMetricsServer({ + liveSidebandWebSocketFactory: () => { throw new Error("expired acquisition reached upstream dial"); }, + }); + const schedule = globalThis.setTimeout; + let expire: (() => void) | undefined; + const deadlineCaptured = Promise.withResolvers(); + const timers = spyOn(globalThis, "setTimeout").mockImplementation(((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => { + if (delay === 120_000 && !expire) { + expire = () => callback(...args); + deadlineCaptured.resolve(); + } + return schedule(callback, delay, ...args); + }) as typeof setTimeout); + const finalized = nextFinalRequestLog(entry => entry.status === 504); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + const pending = fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, + }).then(response => ({ response }), error => ({ error })); + await awaitBounded(Promise.all([acquisitionStarted.promise, deadlineCaptured.promise]), "acquisition deadline was not armed"); + expire!(); + const outcome = await awaitBounded(pending, "expired acquisition did not return"); + if (!("response" in outcome)) throw outcome.error; + const { response } = outcome; + expect(response.status).toBe(504); + await response.text(); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("acquisition deadline was not finalized"); + expect(observedRow.status).toBe(504); + expect(rows.map(entry => entry.status)).toEqual([504]); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + disposeRows(); + finalized.dispose(); + timers.mockRestore(); + resolver.mockRestore(); + await stopMetricsServer(server); + } + }); + + test("active-turn capacity refusal finalizes exactly one failed 503 live request", async () => { + saveConfig(liveMetricsConfig()); + const server = startMetricsServer({ + liveSidebandWebSocketFactory: () => { throw new Error("capacity refusal reached upstream dial"); }, + }); + const leases: Array<{ release(): void }> = []; + const finalized = nextFinalRequestLog(entry => entry.status === 503); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + for (let index = 0; index < MAX_ACTIVE_SESSION_LANES; index += 1) { + const lease = tryAdmitTurn(`metrics-capacity-${index}`); + if (!lease) throw new Error(`failed to reserve capacity lane ${index}`); + leases.push(lease); + } + const response = await fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "session-id": "metrics-capacity-overflow" }, + }); + expect(response.status).toBe(503); + await response.text(); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("capacity refusal was not finalized"); + expect(observedRow.status).toBe(503); + expect(rows.map(entry => entry.status)).toEqual([503]); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + for (const lease of leases.reverse()) lease.release(); + disposeRows(); + finalized.dispose(); + await stopMetricsServer(server); + } + }); + + test("acquisition resolver exception finalizes one 500 row before rethrow", async () => { + saveConfig(liveMetricsConfig()); + const fixtureError = new Error("metrics acquisition resolver failure"); + const resolver = spyOn(audioUpstream, "resolveAudioUpstream").mockImplementation(async () => { throw fixtureError; }); + const observedErrors: unknown[] = []; + const unexpectedErrors: unknown[] = []; + const server = startMetricsServerWithExpectedError(fixtureError, observedErrors, unexpectedErrors); + const finalized = nextFinalRequestLog(entry => entry.status === 500); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + const response = await fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, + }); + expect(response.status).toBe(500); + await response.text(); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("resolver exception was not finalized"); + expect(observedRow.status).toBe(500); + expect(rows.map(entry => entry.status)).toEqual([500]); + expect(observedErrors).toEqual([fixtureError]); + expect(unexpectedErrors).toEqual([]); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + disposeRows(); + finalized.dispose(); + resolver.mockRestore(); + await stopMetricsServer(server); + } + }); + test.each([ ["upgrade-throw", 502], ["upgrade-false", 426], From 1ab927e9041b20c21c3f70b01ac816fdcffcd416 Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 02:54:40 +0900 Subject: [PATCH 14/15] test(providers): add fixed-phase timing diagnostics to the CodeBuddy timeout case Diagnostic-only patch from campaign coordination, adjusted so the assertion measures raw elapsed time (the clamp stays only in the diagnostic string). Phase marks, classification, the 250ms comparison, and the 10/10/35 budgets are unchanged. This labels the stall phase as an observation; no root cause is claimed. Part of #5117 --- tests/providers/codebuddy-adapter.test.ts | 57 +++++++++++++++++++++-- 1 file changed, 53 insertions(+), 4 deletions(-) diff --git a/tests/providers/codebuddy-adapter.test.ts b/tests/providers/codebuddy-adapter.test.ts index fc784fe0987..c03db18ce68 100644 --- a/tests/providers/codebuddy-adapter.test.ts +++ b/tests/providers/codebuddy-adapter.test.ts @@ -615,7 +615,44 @@ describe("codebuddy runTurn streams a headless turn", () => { }); test("a timeout destroys a stalled stdout stream and returns even when close never arrives", async () => { + type TimingPhase = "entry" | "spawn" | "sigterm" | "stdout_close" | "stdout_error" | "timeout" | "return"; + type TimingClassification = + | "within_budget" + | "pre_spawn_late" + | "timeout_dispatch_missing" + | "timeout_dispatch_late" + | "timeout_event_missing" + | "stdout_settlement_missing" + | "stdout_settlement_late" + | "reap_or_return_late"; + const phaseOrder: readonly TimingPhase[] = [ + "entry", "spawn", "sigterm", "stdout_close", "stdout_error", "timeout", "return", + ]; + const phaseMs: Partial> = {}; + let startedAt = 0; + const boundedElapsed = (): number => Math.min(1_000, Math.max(0, Date.now() - startedAt)); + const mark = (phase: TimingPhase): void => { phaseMs[phase] ??= boundedElapsed(); }; + const classify = (elapsed: number): TimingClassification => { + if (elapsed < 250) return "within_budget"; + if ((phaseMs.spawn ?? 0) >= 250) return "pre_spawn_late"; + if (phaseMs.sigterm === undefined) return "timeout_dispatch_missing"; + if (phaseMs.sigterm >= 250) return "timeout_dispatch_late"; + if (phaseMs.timeout === undefined) return "timeout_event_missing"; + const streamSettledAt = Math.min( + phaseMs.stdout_close ?? Number.POSITIVE_INFINITY, + phaseMs.stdout_error ?? Number.POSITIVE_INFINITY, + ); + if (!Number.isFinite(streamSettledAt)) return "stdout_settlement_missing"; + if (streamSettledAt >= 250) return "stdout_settlement_late"; + return "reap_or_return_late"; + }; + const diagnostic = (elapsed: number): string => { + const phases = phaseOrder.map(phase => `${phase}_ms=${phaseMs[phase] ?? -1}`).join(","); + return `codebuddy_timeout_timing classification=${classify(elapsed)} total_ms=${elapsed} ${phases}`; + }; const stdoutStream = new Readable({ read() { /* stays open until timeout destroys it */ } }); + stdoutStream.once("close", () => mark("stdout_close")); + stdoutStream.once("error", () => mark("stdout_error")); const child = new EventEmitter() as FakeChild; child.stdout = stdoutStream; child.stderr = Readable.from([]); @@ -625,22 +662,34 @@ describe("codebuddy runTurn streams a headless turn", () => { child.exitCode = null; const signals: string[] = []; child.kill = (sig?: string) => { + if ((sig ?? "SIGTERM") === "SIGTERM") mark("sigterm"); child.killed = true; signals.push(sig ?? "SIGTERM"); return true; }; const adapter = createCodeBuddyAdapter(provider(), { - spawn: () => child as unknown as ChildProcess, + spawn: () => { + mark("spawn"); + return child as unknown as ChildProcess; + }, which: () => "/usr/bin/codebuddy", timeoutMs: 10, killGraceMs: 10, reapTimeoutMs: 35, }); - const startedAt = Date.now(); - const events = await run(adapter, parsed()); + startedAt = Date.now(); + mark("entry"); + const events: AdapterEvent[] = []; + await adapter.runTurn!(parsed(), incoming(), event => { + if (event.type === "error" && event.status === 504 && event.code === "timeout") mark("timeout"); + events.push(event); + }); + mark("return"); + // The measured assertion uses the raw elapsed time; clamping would hide a genuine overrun. + const elapsed = Date.now() - startedAt; - expect(Date.now() - startedAt).toBeLessThan(250); + expect(elapsed, diagnostic(elapsed)).toBeLessThan(250); expect(stdoutStream.destroyed).toBe(true); expect(signals).toContain("SIGTERM"); expect(events).toContainEqual(expect.objectContaining({ type: "error", status: 504, code: "timeout" })); From 4d9bcead8728a467c960910e38a7258357f7563b Mon Sep 17 00:00:00 2001 From: JUN Date: Sun, 20 Sep 2026 03:10:14 +0900 Subject: [PATCH 15/15] test(server): isolate acquisition fixtures with immediate try/finally Review fold: the resolver and timer spies now enter their own try/finally immediately after creation, with server cleanup nested inside, so a startup throw can no longer leak a spy across the suite. All activation and metric assertions unchanged. Part of #5117 --- .../server/management-metrics-export.test.ts | 214 ++++++++++-------- 1 file changed, 119 insertions(+), 95 deletions(-) diff --git a/tests/server/management-metrics-export.test.ts b/tests/server/management-metrics-export.test.ts index 9cd89685af7..cccc37dc546 100644 --- a/tests/server/management-metrics-export.test.ts +++ b/tests/server/management-metrics-export.test.ts @@ -743,38 +743,47 @@ describe("metrics through live HTTP and WebSocket server flows", () => { saveConfig(liveMetricsConfig()); const acquisitionStarted = Promise.withResolvers(); const resolver = stallAudioAcquisition(acquisitionStarted); - const server = startMetricsServer({ - liveSidebandWebSocketFactory: () => { throw new Error("cancelled acquisition reached upstream dial"); }, - }); - const finalized = nextFinalRequestLog(entry => entry.status === 499); - const rows: RequestLogEntry[] = []; - const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); - const clientAbort = new AbortController(); - const clientOutcome = fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { - headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, - signal: clientAbort.signal, - }).catch(error => error); try { - await awaitBounded(acquisitionStarted.promise, "audio acquisition did not start"); - clientAbort.abort(new Error("metrics acquisition client cancellation")); - const observedRow = await awaitObservation(finalized.promise); - expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); - if (observedRow === OBSERVATION_TIMEOUT) throw new Error("acquisition cancellation was not finalized"); - expect(observedRow.status).toBe(499); - expect(observedRow.closeReason).toBe("client_cancel"); - expect(rows.map(entry => entry.status)).toEqual([499]); - await awaitBounded(clientOutcome, "cancelled acquisition client did not settle"); - const metrics = await scrapeServer(server); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(1); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + const server = startMetricsServer({ + liveSidebandWebSocketFactory: () => { throw new Error("cancelled acquisition reached upstream dial"); }, + }); + try { + const finalized = nextFinalRequestLog(entry => entry.status === 499); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + const clientAbort = new AbortController(); + try { + const clientOutcome = fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, + signal: clientAbort.signal, + }).catch(error => error); + await awaitBounded(acquisitionStarted.promise, "audio acquisition did not start"); + clientAbort.abort(new Error("metrics acquisition client cancellation")); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("acquisition cancellation was not finalized"); + expect(observedRow.status).toBe(499); + expect(observedRow.closeReason).toBe("client_cancel"); + expect(rows.map(entry => entry.status)).toEqual([499]); + await awaitBounded(clientOutcome, "cancelled acquisition client did not settle"); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + clientAbort.abort(); + } + } finally { + disposeRows(); + finalized.dispose(); + } + } finally { + await stopMetricsServer(server); + } } finally { - clientAbort.abort(); - disposeRows(); - finalized.dispose(); resolver.mockRestore(); - await stopMetricsServer(server); } }); @@ -782,49 +791,58 @@ describe("metrics through live HTTP and WebSocket server flows", () => { saveConfig(liveMetricsConfig()); const acquisitionStarted = Promise.withResolvers(); const resolver = stallAudioAcquisition(acquisitionStarted); - const server = startMetricsServer({ - liveSidebandWebSocketFactory: () => { throw new Error("expired acquisition reached upstream dial"); }, - }); - const schedule = globalThis.setTimeout; - let expire: (() => void) | undefined; - const deadlineCaptured = Promise.withResolvers(); - const timers = spyOn(globalThis, "setTimeout").mockImplementation(((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => { - if (delay === 120_000 && !expire) { - expire = () => callback(...args); - deadlineCaptured.resolve(); - } - return schedule(callback, delay, ...args); - }) as typeof setTimeout); - const finalized = nextFinalRequestLog(entry => entry.status === 504); - const rows: RequestLogEntry[] = []; - const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); try { - const pending = fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { - headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, - }).then(response => ({ response }), error => ({ error })); - await awaitBounded(Promise.all([acquisitionStarted.promise, deadlineCaptured.promise]), "acquisition deadline was not armed"); - expire!(); - const outcome = await awaitBounded(pending, "expired acquisition did not return"); - if (!("response" in outcome)) throw outcome.error; - const { response } = outcome; - expect(response.status).toBe(504); - await response.text(); - const observedRow = await awaitObservation(finalized.promise); - expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); - if (observedRow === OBSERVATION_TIMEOUT) throw new Error("acquisition deadline was not finalized"); - expect(observedRow.status).toBe(504); - expect(rows.map(entry => entry.status)).toEqual([504]); - const metrics = await scrapeServer(server); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + const server = startMetricsServer({ + liveSidebandWebSocketFactory: () => { throw new Error("expired acquisition reached upstream dial"); }, + }); + try { + const schedule = globalThis.setTimeout; + let expire: (() => void) | undefined; + const deadlineCaptured = Promise.withResolvers(); + const timers = spyOn(globalThis, "setTimeout").mockImplementation(((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => { + if (delay === 120_000 && !expire) { + expire = () => callback(...args); + deadlineCaptured.resolve(); + } + return schedule(callback, delay, ...args); + }) as typeof setTimeout); + try { + const finalized = nextFinalRequestLog(entry => entry.status === 504); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + const pending = fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, + }).then(response => ({ response }), error => ({ error })); + await awaitBounded(Promise.all([acquisitionStarted.promise, deadlineCaptured.promise]), "acquisition deadline was not armed"); + expire!(); + const outcome = await awaitBounded(pending, "expired acquisition did not return"); + if (!("response" in outcome)) throw outcome.error; + const { response } = outcome; + expect(response.status).toBe(504); + await response.text(); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("acquisition deadline was not finalized"); + expect(observedRow.status).toBe(504); + expect(rows.map(entry => entry.status)).toEqual([504]); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + disposeRows(); + finalized.dispose(); + } + } finally { + timers.mockRestore(); + } + } finally { + await stopMetricsServer(server); + } } finally { - disposeRows(); - finalized.dispose(); - timers.mockRestore(); resolver.mockRestore(); - await stopMetricsServer(server); } }); @@ -870,35 +888,41 @@ describe("metrics through live HTTP and WebSocket server flows", () => { saveConfig(liveMetricsConfig()); const fixtureError = new Error("metrics acquisition resolver failure"); const resolver = spyOn(audioUpstream, "resolveAudioUpstream").mockImplementation(async () => { throw fixtureError; }); - const observedErrors: unknown[] = []; - const unexpectedErrors: unknown[] = []; - const server = startMetricsServerWithExpectedError(fixtureError, observedErrors, unexpectedErrors); - const finalized = nextFinalRequestLog(entry => entry.status === 500); - const rows: RequestLogEntry[] = []; - const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); try { - const response = await fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { - headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, - }); - expect(response.status).toBe(500); - await response.text(); - const observedRow = await awaitObservation(finalized.promise); - expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); - if (observedRow === OBSERVATION_TIMEOUT) throw new Error("resolver exception was not finalized"); - expect(observedRow.status).toBe(500); - expect(rows.map(entry => entry.status)).toEqual([500]); - expect(observedErrors).toEqual([fixtureError]); - expect(unexpectedErrors).toEqual([]); - const metrics = await scrapeServer(server); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); - expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + const observedErrors: unknown[] = []; + const unexpectedErrors: unknown[] = []; + const server = startMetricsServerWithExpectedError(fixtureError, observedErrors, unexpectedErrors); + try { + const finalized = nextFinalRequestLog(entry => entry.status === 500); + const rows: RequestLogEntry[] = []; + const disposeRows = observeRequestLogsForTests(entry => { if (entry.model === "gpt-live") rows.push(entry); }); + try { + const response = await fetch(new URL("/v1/realtime?model=fixture%2Fmetrics-model", server.url), { + headers: { ...upgradeRequestHeaders(), "x-opencodex-api-key": DATA_TOKEN }, + }); + expect(response.status).toBe(500); + await response.text(); + const observedRow = await awaitObservation(finalized.promise); + expect(observedRow).not.toBe(OBSERVATION_TIMEOUT); + if (observedRow === OBSERVATION_TIMEOUT) throw new Error("resolver exception was not finalized"); + expect(observedRow.status).toBe(500); + expect(rows.map(entry => entry.status)).toEqual([500]); + expect(observedErrors).toEqual([fixtureError]); + expect(unexpectedErrors).toEqual([]); + const metrics = await scrapeServer(server); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="failed"}')).toBe(1); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="aborted"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="incomplete"}')).toBe(0); + expect(sampleValue(metrics, 'opencodex_logical_requests_total{protocol="unknown",result="completed"}')).toBe(0); + } finally { + disposeRows(); + finalized.dispose(); + } + } finally { + await stopMetricsServer(server); + } } finally { - disposeRows(); - finalized.dispose(); resolver.mockRestore(); - await stopMetricsServer(server); } });