nsHttpChannel waits forever in `AwaitingCacheCallbacks`
Categories
(Core :: Networking: Cache, defect, P1)
Tracking
()
| Tracking | Status | |
|---|---|---|
| firefox-esr140 | --- | unaffected |
| firefox152 | --- | wontfix |
| firefox153 | --- | affected |
| firefox154 | --- | fixed |
People
(Reporter: kershaw, Assigned: jesup)
References
(Regression)
Details
(Keywords: regression, Whiteboard: [necko-triaged] [necko-priority-queue])
Attachments
(3 files)
Some loads hang permanently. The channel logs nsHttpChannel::Connect … AwaitingCacheCallbacks forces async, then never gets its OnCacheEntryAvailable callback, so the load neither proceeds nor
times out.
These turn out to be address-bar search suggestions (DuckDuckGo autocomplete,
https://ac.duckduckgo.com/ac/?type=list&q=…). The channel attaches as a consumer to a cache entry
that's READY but still flagged "write in progress (stream active)". Since the response is
Cache-Control: no-cache, the channel must revalidate, and cache2 makes it wait until the writer
finishes. But in this session the writer is gone — the entry stays "being written" with no live
transaction behind it and no writer-close event ever firing — so the wait never ends.
Details
Three channels hang end-to-end, all with the same signature (DuckDuckGo autocomplete, no-cache,
entry still "being written"):
| Channel | q= |
Cache entry | Parked at | Resolved? |
|---|---|---|---|---|
6b64011800 |
p |
6ae28f1bc0 |
line 55164, 14:38:35 | never |
6b64012500 |
po |
6ae28f25e0 |
line 55317, 14:38:35 | never |
6b64013f00 |
pou |
6ae28efe80 |
line 55434, 14:38:35 | never |
Sequence for 6b64011800 (lines 55098–55164): the entry is already in memory (AsyncOpen [state=READY]);
OnCacheEntryCheck sees cache-control: no-cache → MustValidate() TRUE → doValidation=1; but the
entry reports write in progress (stream active), so cache2 replies not the writer /
consumer will check on the entry again after write is done; the channel then parks at
AwaitingCacheCallbacks forces async. From here it can only be woken by OnWriterClosed → InvokeCallbacks.
That wake-up never comes:
- No
OnWriterClosed, output-stream close,SetValid,Doom, orOnStopRequestappears anywhere in
the 324k-line log for any of the three entries. - The
ac.duckduckgo.com:443connection entry (ent=6b2fa428d0) showsactive=0 idle=0 pending=0
the whole time — there's no live transaction writing these entries. They're effectively zombie
writers. - The Cache2 I/O thread keeps trying to
Purge6ae28f1bc0for ~50s but it never frees. - The three channels stay parked from 14:38:35 to end-of-log (~54s) and never reappear.
Most likely an earlier suggestion request for each URL became the cache writer, then got cancelled as
the user kept typing — without closing its output stream or dooming the entry. That leaves the entry
permanently "being written", and because suggestions are no-cache, every later request for the same
URL has to revalidate, can't use the pending entry, and waits on a write that never completes. There's
also no timeout on a channel stuck in the cache-wait state, so nothing breaks the deadlock.
(Note: 6af5e58600, 6ae2d8d600, 6ae2d87b00 briefly hit the same bypass around 14:39:00 but
recovered when fresh writers ran, so they aren't counted here.)
Suspected code (leads, not a confirmed fix)
netwerk/cache2/CacheEntry.cpp— the concurrent-write bypass inInvokeCallback, and the writer
teardown path (OnWriterClosed/ output-stream close) which doesn't seem to run when a writer is
cancelled, so the entry is never released or doomed.netwerk/protocol/http/nsHttpChannel.cpp— theConnect/OnCacheEntryAvailablecache-wait path
has no timeout onmCacheEntriesToWaitFor(AwaitingCacheCallbacks()), so a dead writer wedges the
consumer forever.
Appendix — key excerpt (6b64011800, entry 6ae28f1bc0, lines 55098–55164)
55098 nsHttpChannel::OpenCacheEntry [this=6b64011800]
55099 AddStorageEntry [entryKey=:https://ac.duckduckgo.com/ac/?type=list&q=p]
55101 CacheEntry::AsyncOpen [this=6ae28f1bc0, state=READY, flags=16, callback=6b64012208]
55108 CacheEntry::InvokeCallback [this=6ae28f1bc0, state=READY, cb=6b64012208]
... cached response: HTTP/2 200, cache-control: no-cache ...
55140 write in progress (stream active)
55149 Must validate since response contains 'no-cache' header
55151 OnCacheEntryCheck exit [this=6b64011800 doValidation=1 result=1]
55155 not the writer
55157 consumer will check on the entry again after write is done
55164 nsHttpChannel::Connect 6b64011800 AwaitingCacheCallbacks forces async
The q=po (6b64012500) and q=pou (6b64013f00) blocks are identical apart from IDs.
104 ConnectionEntry::TimeoutTick() host=ac.duckduckgo.com idle=0 active=0 pending=0 (same throughout)
|
Assignee | |
Comment 1•5 days ago
|
||
Bug 2030021 (FF 152, May 2026) introduced a new suspend-after-examine-response window for tracker channels that made a suspended-and-cancelled cache writer readily reachable. The LOAD_BACKGROUND flip (Bug 2046419, FF 153, Jun 2026) is a plausible aggravator of timing but is later and secondary; the 152 trigger is Bug 2030021.
nsHttpChannel::CancelInternal gates the teardown on suspension:
if (needAsyncAbort && !mCallOnResume && !mSuspendCount) {
CloseCacheEntry(false); // dooms a write-only entry
(void)AsyncAbort(status); // drives OnStopRequest -> tee closes the output stream
}
If the channel is suspended when aborted, both are deferred to Resume(). CancelNetworkRequest cancels the transaction, but the suspended pump delivers no OnStopRequest, so the cache output stream stays registered, so DataSize() keeps returning IN_PROGRESS, so the entry is stuck "being written." If Resume() never fires, it's a permanent zombie writer.
What suspends the writer mid-write: Bug 2030021, part 7 — "Allow network request to proceed while annotating trackers", landed May 11 in 152. For ETP-classified channels (a DuckDuckGo autocomplete host plausibly qualifies), ProcessResponse now calls MaybeSuspendAfterExamineResponse() which Suspend()s right after http-on-examine-response, while the async tracker annotation completes; CancelSuspendOrResumeAfterExamineResponse() later Resume()s. The synchronous unwind through ContinueProcessResponse1 still opens the cache output stream, so the writer ends up READY + stream-active and suspended -- the precondition CancelInternal fails to tear down. The user types the next character, the controller abort()s the XHR, and if the annotation Resume is lost, the writer wedges forever.
This feature is part of a rollout, so that may explain why some people never see it, and others do. We could check if users hitting the problem are part of the rollout (privacy.trackingprotection.defer_annotation.enabled = true).
The base vulnerability predates that; bug 1966494 partially patched the hole, but only WRITING/REVALIDATING, leaving the READY/DataSize path uncovered. I think the vulnerability goes way back: The RECHECK_AFTER_WRITE_FINISHED wait keyed solely on CacheFile::mOutput, with no consumer-side timeout, is from the original cache2 design. It has always been possible to wedge this; it just required a writer to vanish without closing its output stream
|
|
Assignee | |
Comment 2•5 days ago
|
||
A channel that opens a cache entry asynchronously parks in AwaitingCacheCallbacks
until OnCacheEntryAvailable fires. Nothing bounds that wait, so if the entry is
left perpetually "being written" (e.g. by a writer that was suspended or
cancelled without ever closing its output stream), the load neither proceeds nor
times out.
Add a one-shot backstop timer, armed while the channel is parked waiting for the
cache entry and cancelled once the callback arrives. When it fires the channel
stops waiting and races to the network so the load can make progress instead of
hanging forever. The timeout is controlled by network.cache.entry_wait_timeout_ms
(default 30s, 0 disables) and is kept generous so it never fires for legitimately
slow concurrent reads/writes of large resources.
|
||
Updated•5 days ago
|
|
|
Assignee | |
Comment 3•5 days ago
|
||
When a cache entry writer is suspended or stalled for too long, the suspend
timer sets the entry writer-lock bypass (SetBypassWriterLock). That already lets
new callbacks through the WRITING/REVALIDATING gate, but a consumer that has
already passed OnCacheEntryCheck and is waiting for the write to finish
(RECHECK_AFTER_WRITE_FINISHED) is gated solely on the data being complete, so it
keeps getting re-queued and never wakes -- the load hangs forever.
Honor mBypassWriterLock on that path too: when the bypass is set and the data is
still in progress, hand the consumer the entry as "not wanted"
(NS_ERROR_CACHE_KEY_NOT_FOUND) so it falls back to the network instead of
deadlocking.
Adds gtests for the cache-layer behavior (a bypassed writer lock releases a
parked consumer; dooming a being-written entry releases a parked consumer) and
an xpcshell test that reproduces the end-to-end hang: a no-cache writer stranded
mid-write must not wedge a later same-URL request.
|
|
Assignee | |
Comment 4•5 days ago
|
||
When a channel is suspended after examining the response to await asynchronous
tracking-protection annotation (bug 2030021) and is then cancelled while still
suspended, nsHttpChannel::CancelInternal defers the terminal teardown
(CloseCacheEntry / AsyncAbort) to a Resume() that may never arrive. For a cache
writer this strands the entry perpetually "being written" -- its output stream
never closed and the entry never doomed -- wedging every later same-URL
revalidating consumer.
Undo the annotation suspension in CancelInternal so the cancelled pump delivers
OnStopRequest and the write-only entry is closed/doomed through the normal path.
This is a no-op if the channel only primed but never actually suspended.
|
|
Assignee | |
Updated•5 days ago
|
|
||
Comment 5•5 days ago
|
||
Set release status flags based on info from the regressing bug 2030021
|
|
||
Updated•4 days ago
|
|
|
||
Updated•4 days ago
|
|
|
||
Updated•4 days ago
|
Backed out for causing bustages + lint failure
|
||
Comment 10•4 days ago
|
||
|
||
Comment 11•4 days ago
|
||
Backed out for causing es lint failures @ test_cache2-42-no_cache_writer_hang.js
|
||
Comment 12•4 days ago
|
||
(In reply to pstanciu from comment #11)
Backed out for causing es lint failures @ test_cache2-42-no_cache_writer_hang.js
Also xpschells failures
bc failures
|
||
Updated•2 days ago
|
|
|
||
Comment 13•2 days ago
|
||
|
||
Comment 14•2 days ago
|
||
| bugherder | ||
https://hg.mozilla.org/mozilla-central/rev/523b4bff3f68
https://hg.mozilla.org/mozilla-central/rev/37b559f94f11
https://hg.mozilla.org/mozilla-central/rev/5bf042dd3c53
|
|
Assignee | |
Updated•19 hours ago
|
Description
•