Requests take minutes to start responding, even for small prompts

[jay-tau]

Environment

• copilot-api 1.14.18
• Node v26.4.0, Linux, run as a systemd service: cao start --port 4141
• Clients: Codex Desktop and Codex CLI — model_provider = copilot_api, wire_api = "responses"
• Models: gpt-5.6-sol / gpt-5.6-terra / gpt-5.6-luna
• useResponsesApiWebSocket: false
• Usually 4–8 Codex sessions active at once

What happens

Codex sits on "thinking" for a long time before any output appears. It happens even for small prompts — a short follow-up takes about as long as a large context turn.

Over one day (955 requests):

• 223 (23%) took over 1 minute
• 58 (6%) took over 5 minutes

Wait time is roughly flat regardless of request size:

request body	requests	median wait
<100 KB	24	26s
100–400 KB	249	28s
400–800 KB	267	25s
>800 KB	225	34s

The gateway stays up throughout — no crash, no restart. It clears on its own and returns later, and is noticeably worse when several Codex sessions are active at once.

What I think is happening

I think most of the wait is spent inside the gateway before the request is sent upstream, rather than the model being slow. I may be misreading this.

I attached a read-only listener to undici's diagnostics_channel via NODE_OPTIONS=--require, so copilot-api's own code is unmodified. Per upstream request it records:

• ms_to_wire — fetch() called → request bytes written
• ms_upstream — request bytes written → response headers received

Across 833 requests: median 25s before the request is sent, versus median 6s waiting on the response — roughly 80% of total time spent before anything goes out.

Worst cases seen:

body=515KB  ms_to_wire=217s  ms_upstream= 7s
body=869KB  ms_to_wire=205s  ms_upstream=19s
body=390KB  ms_to_wire=203s  ms_upstream= 6s
body=139KB  ms_to_wire=177s  ms_upstream= 3s

Small requests are affected the same way:

body=33KB  ms_to_wire=22s  ms_upstream=1s
body=62KB  ms_to_wire=44s  ms_upstream=1s
body=67KB  ms_to_wire=62s  ms_upstream=2s

Data

https://gist.github.com/jay-tau/085b77a1cf11d1f161d02872ab54b7e3

• observer.cjs.txt — the listener used
• cao-timings.txt — 859 requests, per-request timings
• cao-gateway-log.txt — gateway log with verbose off (request/response lines only, no payloads)

Happy to run different measurements or test a patch.

[caozhiyuan]

Is your outbound network proxying or intercepting your requests, causing the stream to return synchronously? You can check the actual event return time and end time in copilot-api/logs, search for the keyword "created_at". @jay-tau

[caozhiyuan]

The message API interface in your log seems to be abnormal as well

[jay-tau]

Thanks for the prompt reply @caozhiyuan
My outbound network is not proxying or intercepting my requests. The stream does not return all at once, it does stream the response in.
My logs do not have "created_at" present at all. Should I use the --verbose flag, in order for it to appear in the logs?

[caozhiyuan]

@jay-tau bun run start start -v . logs at copilot-api logs dir

[jay-tau]

cao-verbose-gaps.txt
PFA the log, @caozhiyuan

[caozhiyuan]

@jay-tau search created_at

[jay-tau]

Command I ran: cat <log-file> | rg created_at
Output of that: https://p.ip.fi/ULXO

Anything else, I can do, @caozhiyuan?

[caozhiyuan]

@jay-tau Check which traceid has slow response; the log records the log printing time, event creation time, and event completion time. You can simply compare these time differences yourself.

[jay-tau]

@caozhiyuan this is for one of the traces that was slow, mskjg86c-vvt62o.

Command I ran: cat <log-file> | rg mskjg86c-vvt62o
Output of that: https://p.ip.fi/zGoo

The three times you asked about:

• log print time: Translated Responses payload at 21:08:28, Forwarding native Responses stream at 21:10:06, all 9 stream chunks at 21:10:06
• created_at = 1786203605 = 21:10:05
• completed_at = 1786203606 = 21:10:06

21:08:28 -> 21:10:05 is 97s. created_at -> completed_at is 1s.

[caozhiyuan]

@jay-tau You could use AI to analyze the situation, or try using a VPN to see if that helps. It might be a network issue; everything is working fine on my end.

[jay-tau]

@caozhiyuan are you unable to reproduce it even with many Codex sessions running at the same time and useResponsesApiWebSocket: false?

I hit it with 30 parallel codex exec sessions, but I was facing the issue with as few as 4-5 sessions as well.

[caozhiyuan]

@jay-tau i set useResponsesApiWebSocket false , use luna, it's ok , but just one parallel . If your concurrency is very high, I suspect it's being rate-limited by Copilot.

[jay-tau]

@caozhiyuan I spent some time digging into this with AI assistance, and I think I've found the cause.

What I think is happening

Copilot CLI runs one process per session, so each session gets its own upstream connection. copilot-api is a single process, so every session shares one connection — under load that behaves like head-of-line blocking. Matching the Copilot CLI behaviour (one connection per session) seems to solve it.

A/B test

Tested on v1.16.1: 60 parallel codex exec sessions, ~411KB payloads, same load run twice back to back under node.

	upstream connections	requests completed	median	max
stock v1.16.1	1	83	331s	599s
one undici Agent per session	53	449	8s	27s

Measured as the gap between Translated Responses payload and Forwarding native Responses stream in the handler log.

The request counts differ because each session runs many turns. Both arms launched the same 60 sessions, but in the stock run most were still queued on early turns — 83 requests completed in ~11 minutes. The patched run got through 456 in 3m42s, so sessions progressed much further in less time.

The patch was 3 lines in createHttpResponses — a Map<sessionId, Agent> passed as dispatcher to fetch. Throwaway, only to test the idea.

Minimal repro, without copilot-api

Open one long-lived streaming POST on an h2 connection, then probe the same connection:

GET  probe (idempotent)     : 6ms
POST probe (non-idempotent) : >10000ms STALLED

That matches undici's behaviour: request.idempotent is false for POST (lib/core/request.js:177), and the h2 client reports the connection busy for non-idempotent requests while one is in flight (lib/dispatcher/client-h2.js:194). So later POSTs wait. It also explains why a single session never shows it — there's nothing to queue behind.

Next steps

I have some ideas on how this could be done in a way that's more production ready than the small reproduction I put together for testing — how connections are keyed, how they get released once a session goes idle, and how to bound the number of them so a burst of sessions can't run away. Happy to share those, and I'm willing to open a PR once the design is settled.

[jay-tau]

@caozhiyuan I tried this on a few different runtimes — node 26.4.0, node 26.7.0, bun 1.3.14 and deno 2.9.5 — and the root cause turns out to be upstream in undici rather than anything in copilot-api. No code change is needed, but the node version requirement probably needs to be stricter.

Runtimes tested

Same stock v1.16.1 dist, same 60-session codex exec load, same ~411KB payloads, each arm run back to back:

runtime	upstream connections	requests completed	median	max
node 26.4.0 (undici 8.5.0)	1	83	331s	599s
node 26.4.0 + per-session dispatcher	53	449	8s	27s
node 26.7.0 (undici 8.9.0)	1	393	6s	96s
bun 1.3.14	61	359	9s	40s
deno 2.9.5	1	490	7s	44s

bun and deno both ran the unmodified dist, no code changes.

The interesting rows are node 26.7.0 and deno: both were fast while holding a single upstream connection, same as the slow node 26.4.0 arm. So the number of connections was never the real variable — my earlier per-session dispatcher patch worked, but only by side-stepping the actual problem.

What's actually happening

undici enabled HTTP/2 by default in 8.x. Its h2 client then refused to dispatch a request carrying a body while another request was still in flight:

// undici 8.5.0 lib/dispatcher/client-h2.js busy()
if (util.bodyLength(request.body) !== 0 &&
  (util.isStream(request.body) || util.isAsyncIterable(request.body) || util.isFormDataLike(request.body))) return true

fetch() wraps any request body as a stream, so every body-bearing request hits this — which for copilot-api means every /responses call. With long-lived SSE responses, one in-flight request blocks the others behind it.

Probing a connection that already has a streaming POST open, each probe in a separate process so a stalled one can't affect the next:

node v26.4.0 (undici 8.5.0)        node v26.7.0 (undici 8.9.0)
post-body   >8000ms STALLED        post-body   5ms
put-body    >8000ms STALLED        put-body    5ms

Same script, same server, only the node version differs.

This is nodejs/undici#5524 — "HTTP/2: fetch POST hangs while an SSE stream is open" — fixed in undici 8.8.0 by #5538.

Affected versions

	undici	affected
node 26.0 – 26.5.0	8.0 – 8.7	yes
node >= 26.5.1	8.9.0	no
node 24 LTS and older	7.x	no — h2 is off by default there

So upgrading node to >= 26.5.1 fixes it with no change to copilot-api. The only thing worth changing on your side is the node version requirement — engines currently allows >=20, and anyone landing on node 26.0–26.5.0 with several concurrent sessions will hit this without any obvious sign of where the delay comes from.

Correction to my earlier comment

I cited request.idempotent and client-h2.js:194 as the mechanism. That was from the undici 7.29.0 copy in node_modules, but the /responses call uses global fetch, which uses node's bundled undici. The idempotency rule was deliberately removed in 8.x — the body condition above is what was actually causing it.