[BUG] SSE delivery is throttled to ~11 tokens/s regardless of generation speed; the response accumulates and flushes when generation ends

[raikensan]

OS

Linux

GPU Library

CUDA 12.x

Python version

3.12

Describe the bug

Note: English is not my first language and I used an AI assistant to write this up. All measurements below were taken on my own setup — please tell me if anything is unclear or if you need different data.

When streaming ("stream": true), tokens are delivered to the client at a rate that is capped independently of the generation speed. With generation running at ~73 T/s, the client receives ~11 SSE frames/s. The remainder accumulates in the AsyncJob queue and is flushed all at once when generation finishes, so from the client's point of view most of the response arrives as a single burst at the end — the stream behaves like a non-streaming response for the majority of its length.

The cap is not a buffering artifact. Measured with curl --trace-time (which cannot lag), frames arrive at an almost perfectly constant 89-90 ms interval (p10 88.6 ms, p90 91.2 ms, zero frames arriving in clusters).

Root cause appears to be DisconnectHandler.poll() in common/networking.py, which is awaited once per generated token from generate_gen():

async for result in job:
    await disconnect_handler.poll()      # backends/exllamav3/model.py

poll() rate-limits itself to 20 checks/s, and on the slow path it awaits request.is_disconnected(). In Starlette that awaits receive() inside a cancel scope, which is a real suspension point.

That alone would be harmless, but exllamav3's generator.iterate() is a synchronous call that occupies the event loop, so the loop only gets to run about once per generation step. How often it actually gets to switch tasks within that window is gated by poll()'s own rate limit. I don't have a precise account of why checking less often frees up delivery rather than costing it — only the isolation below, where this one variable produces and removes the effect with nothing else changed.

I instrumented both sides of the AsyncJob queue (put_result and the await queue.get() in AsyncJob.__aiter__) and counted events per second for one request:

second   put (produced)   get (consumed)   queue backlog
     0               60               11              48
     5               62               11             288
    10               74               11             524
    15               90               11             833
    17               70               11             955
    18               41              996             989   <- generation ends, drain

Production tracks the generation rate; consumption is pinned at 11/s for the whole run.

Raising only the poll interval (0.05 -> 0.2, i.e. 20 checks/s -> 5 checks/s) removes the cap completely, with nothing else changed:

poll interval   produced   consumed   share of frames arriving in the final second
        0.05      72.8/s     11.1/s   85 %
        0.20      72.5/s     72.5/s    1 %
        0.50      67.4/s     67.4/s    9 %

The same happens with speculative decoding disabled; generation is slower (30 T/s) so the backlog grows more slowly, but delivery is still capped (~15/s) and ~51 % of frames still arrive in the final second.

I am not proposing 0.2 s as the fix — it is the smallest change that isolates the cause. Doing the disconnect check off the hot path (a separate task, or a non-suspending check) would be a more principled fix. I noticed #428 (a similar disconnect-handling deadlock) was closed after being fixed in exllamav3 v1.0.0 — since I'm on 1.4.2, that failure mode should already be covered, but I haven't stress-tested disconnect edge cases against a change here myself, so I did not want to guess at the right shape.

Reproduction steps

1. Load any model with exllamav3 (I used Qwen3.8-27B EXL3 4.0bpw, 2x GPU split, MTP draft).

2. Send a streaming chat completion long enough to see the effect:

curl -sN --no-buffer --trace-time --trace-ascii trace.txt -o /dev/null \
  -X POST http://127.0.0.1:5000/v1/chat/completions \
  -H 'content-type: application/json' \
  -d '{"model":"x","max_tokens":1200,"stream":true,
       "messages":[{"role":"user","content":"Describe three tables an inventory system needs, and explain the columns of each."}]}'

3. Count SSE frames per second in trace.txt (lines <= Recv data) and compare with the Generate: N T/s figure that TabbyAPI logs for the same request.

   Observed: generation 73.36 T/s, delivery ~11 frames/s, ~86 % of frames in the last second.

4. Restart with the poll interval raised (I patched the constant locally) and repeat: delivery matches generation and the final-second burst disappears.

Expected behavior

SSE frames should reach the client at roughly the generation rate, so a streaming response is actually streamed rather than accumulating server-side and flushing at completion.

Logs

TabbyAPI metrics for the request measured above:

Metrics (ID: 3e6ee954332845d9ab56a01c04341395): 810 tokens generated in 11.24 seconds
(Queue: 0.02 s, Process: 0 cached tokens and 68 new tokens at 377.78 T/s,
 Generate: 73.36 T/s, Context: 68 tokens)

Frame arrival, same request, from curl --trace-time (frames per second, by delta type):

second   reasoning_content   content
     0                  12         0
     1                  11         0
     2                  11         0
     3                  11         0
     4                  11         0
     5                  11         0
     6                   8         1
     7                   0        12
     8                   0        11
     9                   0        11
    10                   0       696   <- generation ends

Inter-arrival of frames during generation: median 90.1 ms, p10 88.6 ms, p90 91.2 ms.

Additional context

• TabbyAPI commit e909f7e ("ExLlamaV3: Respect device split when loading draft model")
• exllamav3 1.4.2, torch 2.12.0rc3, CUDA 13.1
• fastapi 0.141.1, uvicorn 0.52.3, starlette 1.6.0
• Python 3.14.3 (the template only offers up to 3.12), Linux Mint 22.3
• 2x GPU (RTX 5060 Ti + RTX 5070 Ti), tensor split, cache_mode 6,6

The template's GPU library and Python version options do not cover CUDA 13.1 / Python 3.14, so I selected the closest available values.

e909f7e is from 2026-04-25; current main has moved 111 commits since. I checked, and DisconnectHandler.poll() and its call site in backends/exllamav3/model.py are unchanged on current main (checked 2026-08-24), and main pins the same exllamav3 1.4.2 I'm on, so this shouldn't be stale.

I first suspected exllamav3's AsyncGenerator._run_iteration, which yields to the event loop exactly once per iteration (await asyncio.sleep(0)). Increasing that yield count also removes the cap. I don't have a precise account of why either lever works, but two independent changes on two different code paths producing the same effect is corroborating evidence that scheduling opportunities are the scarce resource here. The change that actually addresses the cause is on the TabbyAPI side, and I reverted my exllamav3 patch.

Acknowledgements

• I have looked for similar issues before submitting this one.
• I have read the disclaimer, and this issue is related to a code bug. If I have a question, I will use the Discord server.
• I understand that the developers have lives and my issue will be answered when possible.
• I understand the developers of this program are human, and I will ask my questions politely.

[frost555]

I have seen cases when in single sse frame arrives both thinking and content tokens (on single GPU, no splitting). That confuses ZooCode/RooCode for example, had to create proxy wrapper that splits them to 2 frames, maybe related to the issue?

[raikensan]

Update after re-testing on the latest master — the issue I reported is already
fixed, and @frost555's observation turns out to be directly related to that fix.

The throttling is gone

My local checkout was e909f7e (2026-04-25), four months behind. I updated to
fcc1a10 (2026-08-26) and re-ran the exact repro from the original report, same
model, same config:

	e909f7e (old)	fcc1a10 (current)
SSE frames	807	95
avg characters per frame	4.1	43.6
median inter-arrival gap	0.0 ms	129.7 ms
characters delivered in the last 1.0 s	83.6 %	12.5 %

The median gap of 0 ms on the old build is the tell: frames were not arriving
spaced out, they were arriving in one burst at the end. On current master they
are spread across the whole generation.

1d2477a ("Model: Merge streamed results from generator (prevent backlog...)")
addresses exactly this. The consumer now drains everything already queued and
merges it into one result, so delivery keeps pace with generation instead of
backing up. The poll() interval is untouched at 0.05 s, which is fine — the
backlog was the symptom, and draining the queue removes it without having to
loosen the disconnect check.

Sorry for the noise of reporting an already-fixed bug. My analysis of the
mechanism was right, but I should have checked master first.

@frost555's report is a side effect of that same fix — and I could reproduce it

You asked whether it was related. It is, and I don't think it existed before
1d2477a.

Because the merge concatenates the text of several results into one, a single
chunk can now span a </think> boundary. On the old build I could not produce
this at all — I re-analysed my four curl --trace-ascii captures from the
original report, 3,678 SSE frames total, and found zero frames carrying both
fields. On current master it shows up immediately, in the very first request I
tried:

{"content": "\n\nAn inventory system typically", "reasoning_content": ".\nNeed final only.\n"}

(Qwen3.8-27B EXL3 4.0bpw, MTP draft enabled. Speculative decoding makes it more
likely, since more results are queued per iteration and get merged.)

The parser itself looks fine — it's whatever consumes its output that folds
reasoning and content back into one delta.