litespeedtech / litespeedtech/openlitespeed
QUIC busy loop debug-flood regression in OLS 1.8.5 (was fixed in 1.8.2 per #375)
Nobody has claimed this yet.
- Dominant language
- C++
- Stars
- 1.5k
- Forks
- 233
- Avg merge
- 2d 19h
- Merged PRs (30d)
- 5
Description
# QUIC busy loop debug-flood regression in OLS 1.8.5 (was fixed in 1.8.2 per #375)
This is a regression of the bug closed in #375 — same symptom (`Detected QUIC busy loop at 100, 200, 300, 400, 500` → `[INFO] logger: set pacer to info` → flood of `[DEBUG]` entries despite `debugLevel 0`). #375 was reported fixed in OLS 1.8.2 (Sep 2024). It is back in 1.8.5 (Jan 2026).
## Versions
| Component | Version |
|-----------|---------|
| OpenLiteSpeed | 1.8.5 (built Wed Jan 21 15:18:09 UTC 2026) |
| lsquic | 4.4.1 |
| OS | Debian, Linux 6.1.0-42-amd64 |
`logLevel WARN`, `debugLevel 0`, `quicEnable 1`. No WebAdmin debug toggles touched.
`QuicEngine::detectBusyLoop()` in v1.9.0 source on master is byte-for-byte identical to 1.8.5 — the regression should also reproduce on 1.9.0 (with lsquic 4.6.2). I haven't tested 1.9.0 because of the known production impact below.
## Reproduction
1. Enable `quicEnable 1` with otherwise-default tuning
2. Visit any HTTPS URL with a >256 KB static asset over HTTP/3 from a real browser (Chrome 147 in our case)
Reproduces on the **first** QUIC connection. The trigger we captured was a 117 KB CSS file (`tosend_off: 117253`, `remain: 160771` → ~272 KB total file).
## Trigger sequence
```
2026-04-27 02:54:24.502117 [WARN] Detected QUIC busy loop at 100
2026-04-27 02:54:24.502738 [WARN] Detected QUIC busy loop at 200
2026-04-27 02:54:24.502979 [WARN] Detected QUIC busy loop at 300
2026-04-27 02:54:24.503178 [WARN] Detected QUIC busy loop at 400
2026-04-27 02:54:24.503408 [WARN] Detected QUIC busy loop at 500
2026-04-27 02:54:24.503763 [INFO] logger: set pacer to info ← detectBusyLoop calls HttpLog::setDebugLevel(10)
2026-04-27 02:54:24.503885 [DEBUG] engine: ... ← flood begins
```
500 iterations spanned **1.4 ms** — pure CPU spin, not network/timer driven.
Engine state at loop start (from inline DEBUG dump that escalation captured):
```
sendctl: send_ctl_can_send: sc_flags: 0x20089C
b_out: 66240 = (66240 + 0)
b_retx: 66240 ← 66 KB pending, all in retransmission buffer
cwnd: 100439 ← cwnd has room
n_in_flight_all: 45
pa_burst: 0; pa_next: 2626713588234; pa_now: 2626713589622 ← pacing OK (now > next)
```
## Inner loop pattern
The same sequence repeats hundreds of times per millisecond:
```
[QUIC:CID-4] stream: dispatch_write_events ...
QuicStream::onWrite()
HttpSession::doWrite() → flush() → SendStaticFile()
LsAioReq::getRead at 262144, 262144 bytes diff: 262144
getRead(): ret: 0, read: 0, remain: 160771 ← AIO read pending, 0 bytes available
QuicStream::suspendWrite() ← suspend...
sendStaticFileAsync() returned 1
QuicStream::continueWrite() ← ...immediately resume in same callback
[QUIC:CID-4] stream: put on write queue ← stream re-armed
sendctl: send_ctl_can_send: ... b_retx: 66240 ← still nothing new to send
```
The `suspendWrite()` + `continueWrite()` pair fires synchronously inside the write callback, so by the time lsquic checks "tickable" the stream wants to write again — before the AIO completion can drive it. Loop continues until the 256 KB AIO chunk arrives (~30 ms later):
```
2026-04-27 02:54:24.538708 [WARN] End QUIC busy loop at 503
```
For the **next** AIO chunk in the same file the loop fires again. In the 60 MB log captured: 3 busy loops triggered, only 1 emitted `End QUIC busy loop`. So `setDebugLevel(s_quic_previous_debug_level)` ran once; the log level stayed escalated for the rest of the connection.
## Two distinct bugs feed each other
1. **Busy-loop while AIO is pending** — `sendStaticFileAsync()` returns 1 (async), but the chain still calls `continueWrite()` instead of letting the AIO completion callback drive the next attempt. The fix in #375 era apparently addressed this for some path but a path still exists in 1.8.5.
2. **Restore-debug-level only fires on the first clean exit** — `s_quic_restore_log_level` static is reset on the first `End QUIC busy loop`. Subsequent escalations on the same engine never restore. If the worker handles a few QUIC clients at the same time, debug level effectively pins to 10 forever.
Even if (1) is "by design" or hard to fix, (2) alone is enough to turn one busy-loop event into permanent disk flooding. A simple guard or always-restore-when-default-level-equals-escalated would prevent the GB-scale damage.
## Production impact
Before we identified the regression, a single VPS with QUIC enabled overnight produced:
- 444 numbered `error.log.YYYY_MM_DD.NNN` files
- ~100 MB each (lsquic writes outpace OLS rolling at `rollingSize 10M`)
- **32 GB in ~9 hours**, disk 96% full, server functionally down
This is what #375's reporter saw. The fix held through 1.8.2; it doesn't hold in 1.8.5.
## Suggested investigation
1. Bisect between the 1.8.2 fix commit and 1.8.5 — `QuicStream::continueWrite()` callsites and `sendStaticFileAsync` return-value handling
2. In `QuicEngine::detectBusyLoop()`, restore log level on every `End QUIC busy loop`, not only the first
3. Cap escalations per process / per minute — `setDebugLevel(10)` for a recurring write-stall is an outsized response
4. Consider exposing `quicLogLevel` (already read from config in `httpserver.cpp:4671` but its parameter is dropped on the floor inside `QuicEngine::init()`) so operators can hard-pin lsquic to `warn` regardless of escalation
## Evidence available
I have a 230 KB tarball with the first 5 MB of the captured error.log (covers trigger + 2 full busy-loop cycles), config snippet, sysctl/UDP/nstat snapshots, and version info. Happy to attach via the issue's web UI or a gist — let me know what you'd prefer.
Contributor guide
No contributing guide indexed for this repository
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with QuicEngine::detectBusyLoop(), the QuicStream::continueWrite() callsites, and sendStaticFileAsync() return-value handling; compare the 1.8.2 fix with 1.8.5. Check httpserver.cpp:4671 and QuicEngine::init() for the dropped quicLogLevel parameter. Done means an AIO-pending write no longer spins and each busy-loop exit restores the prior log level without a debug-log flood.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, linux
- Domain
- backend, networking
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Quiet
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100