2051415 - Assertion failure: !foundInPendingQ, at checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:4058

Status: RESOLVED FIXED

(Core :: Networking: HTTP, defect, P2)

Description

[Tyson Smith [:tsmith]]

Found with m-c 20260627-cd8b93a107ef (--enable-debug)

This was found by visiting a live website with a debug build.

STR:

• Launch browser and visit site

This issue was triggered by visiting http://www.bonitas.co.za/. A Pernosco session is available here: https://pernos.co/debug/DxkwkbGC1HrGolu_RB-ueQ/index.html

Assertion failure: !foundInPendingQ, at checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:4058

7|0|libxul.so|mozilla::net::nsHttpConnectionMgr::CheckTransInPendingQueue(mozilla::net::nsHttpTransaction*)|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/nsHttpConnectionMgr.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|4058|0x110
7|1|libxul.so|mozilla::net::nsHttpConnectionMgr::AddTransaction(mozilla::net::HttpTransactionShell*, int)|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/nsHttpConnectionMgr.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|354|0x42
7|2|libxul.so|mozilla::net::HappyEyeballsConnectionAttempt::ProcessTCPConn(mozilla::net::HttpConnectionBase*, mozilla::net::ConnectionEntry*, bool)|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/HappyEyeballsConnectionAttempt.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|1202|0x37a
7|3|libxul.so|mozilla::net::HappyEyeballsConnectionAttempt::EnterSucceeded()|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/HappyEyeballsConnectionAttempt.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|1425|0x420
7|4|libxul.so|mozilla::net::HappyEyeballsConnectionAttempt::ProcessHappyEyeballsOutput()|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/HappyEyeballsConnectionAttempt.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|601|0x252
7|5|libxul.so|mozilla::net::HappyEyeballsConnectionAttempt::ProcessConnectionResult(mozilla::net::NetAddr const&, nsresult, unsigned long)|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/HappyEyeballsConnectionAttempt.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|397|0x1cd
7|6|libxul.so|mozilla::net::HappyEyeballsConnectionAttempt::HandleConnectionResult(mozilla::Result<RefPtr<mozilla::net::HttpConnectionBase>, nsresult>, mozilla::net::ConnectionEstablisher*, unsigned long)|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/HappyEyeballsConnectionAttempt.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b||0x39e
7|7|libxul.so|std::_Function_handler<void (mozilla::Result<RefPtr<mozilla::net::HttpConnectionBase>, nsresult>), mozilla::net::HappyEyeballsConnectionAttempt::EstablishTCPConnection(mozilla::net::NetAddr, unsigned short, nsTArray<unsigned char>&&, unsigned long, bool)::$_2>::_M_invoke(std::_Any_data const&, mozilla::Result<RefPtr<mozilla::net::HttpConnectionBase>, nsresult>&&)|/builds/worker/fetches/sysroot-x86_64-linux-gnu/usr/include/c++/10/bits/std_function.h|291|0x61
7|8|libxul.so|mozilla::net::ConnectionEstablisher::FinishInternal(nsresult)|git:github.com/mozilla-firefox/firefox:netwerk/protocol/http/ConnectionEstablisher.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|327|0x2a3
7|9|libxul.so|mozilla::detail::RunnableFunction<mozilla::net::ConnectionEstablisher::ActivateConnectionWithTransaction(RefPtr<mozilla::net::HttpConnectionBase>, std::function<void (nsresult)>)::$_0::operator()(nsresult) const::{lambda()#1}>::Run()|git:github.com/mozilla-firefox/firefox:xpcom/threads/nsThreadUtils.h:9b76a2f882af6691de21dfe290f8175c9bedce7b|536|0x37
7|10|libxul.so|nsThread::ProcessNextEvent(bool, bool*)|git:github.com/mozilla-firefox/firefox:xpcom/threads/nsThread.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|1173|0x7ab
7|11|libxul.so|NS_ProcessNextEvent(nsIThread*, bool)|git:github.com/mozilla-firefox/firefox:xpcom/threads/nsThreadUtils.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|472|0x4f
7|12|libxul.so|mozilla::net::nsSocketTransportService::Run()|git:github.com/mozilla-firefox/firefox:netwerk/base/nsSocketTransportService2.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|1254|0x564
7|13|libxul.so|{virtual override thunk({offset(-32)}, mozilla::net::nsSocketTransportService::Run())}|git:github.com/mozilla-firefox/firefox:netwerk/base/nsSocketTransportService2.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b||0xc
7|14|libxul.so|nsThread::ProcessNextEvent(bool, bool*)|git:github.com/mozilla-firefox/firefox:xpcom/threads/nsThread.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|1173|0x7ab
7|15|libxul.so|NS_ProcessNextEvent(nsIThread*, bool)|git:github.com/mozilla-firefox/firefox:xpcom/threads/nsThreadUtils.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|472|0x4f
7|16|libxul.so|mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*)|git:github.com/mozilla-firefox/firefox:ipc/glue/MessagePump.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|297|0xc6
7|17|libxul.so|MessageLoop::Run()|git:github.com/mozilla-firefox/firefox:ipc/chromium/src/base/message_loop.cc:9b76a2f882af6691de21dfe290f8175c9bedce7b|346|0x61
7|18|libxul.so|nsThread::ThreadFunc(void*)|git:github.com/mozilla-firefox/firefox:xpcom/threads/nsThread.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|374|0x1ba
7|19|libnspr4.so|_pt_root|git:github.com/mozilla-firefox/firefox:nsprpub/pr/src/pthreads/ptthread.c:9b76a2f882af6691de21dfe290f8175c9bedce7b|190|0x18c
7|20|firefox-bin|set_alt_signal_stack_and_start(PthreadCreateParams*)|git:github.com/mozilla-firefox/firefox:mozglue/interposers/pthread_create_interposer.cpp:9b76a2f882af6691de21dfe290f8175c9bedce7b|81|0x10d

Comment 1

[Kershaw Chang [:kershaw]]

Root cause

This is a Happy Eyeballs / WebSocket-upgrade race. Two HappyEyeballsConnectionAttempts are created for the same transaction (trans=0x79f093ac6800) and the same, mutated-in-place connection info (ci=0x79f09b777d00):

• attempt #1 — caps=1075872004 → STICKY_CONNECTION | LOAD_UNBLOCKED | ALLOW_SPDY_WITHOUT_KEEPALIVE | DISALLOW_HTTP3 | USE_HAPPY_EYEBALLS — the original WS upgrade, with H2 allowed.
• attempt #2 — caps=1210098052 → the same flags plus DISALLOW_SPDY | CONNECTION_RESTARTABLE | IS_RETRY — the restarted WS upgrade after H2→H1 fallback.

The Pernosco session confirms that the two pending-queue hash keys differ only in the X (NS_HTTP_DISALLOW_SPDY) byte:

.S.P......H[...]chat.talkk.ai:443[!h3]...   <- key ProcessTCPConn looks up (no X)
.S.P.X....H[...]chat.talkk.ai:443[!h3]...   <- key stored in the transaction (with X)

Flow

1. The WS upgrade transaction T is created H2-capable (ALLOW_SPDY_WITHOUT_KEEPALIVE, no X; see the upgrade-caps setup in nsHttpChannel::BeginConnect) and queued under entry K1 (no X); T’s hash key (OnPendingQueueInserted) is K1.

2. attempt #1 is created for T (mEntry = K1) and establishes an H2 connection.

3. T is dispatched onto that H2 connection via TryDispatchExtendedCONNECTTransaction. The server’s H2 does not support extended CONNECT (NO_SUPPORT), so it calls nsHttpTransaction::DisableSpdy(), which ORs in NS_HTTP_DISALLOW_SPDY and mutates ci in place via SetNoSpdy(true) — adding the X byte, truncating the h2 NPN token, and rebuilding the hash key. It returns NS_ERROR_HTTP2_FALLBACK_TO_HTTP1.

4. T is restarted (NS_ERROR_HTTP2_FALLBACK_TO_HTTP1 is restartable in nsHttpTransaction::Close); its caps gain IS_RETRY | CONNECTION_RESTARTABLE.

5. The restarted T is reinserted into the pending queue under the new X key → entry K2; its stored hash key becomes K2. attempt #2 is then created for it.

6. Meanwhile, attempt #1 still holds mTransaction = T and mEntry = K1. When it later receives its H2 success event, it goes through EnterSucceeded → ProcessTCPConn. Because this is an H2 connection for a WS upgrade, it takes the deferExtendedConnect re-queue path: FindTransaction(removeWhenFound=false, entry=K1, T) misses (because T now lives in K2), T->Connection() is null, and it calls AddTransaction(T).

7. CheckTransInPendingQueue looks up T by its stored key (K2), finds it still pending, and MOZ_ASSERT(!foundInPendingQ) fires. The trans_found_in_pending_queue telemetry just above the assert confirms that this case occurs.

Two contributing defects

1. When T falls back to H1 and is restarted (creating attempt #2), the original H2 attempt (attempt #1) is not cancelled and still holds a reference to T. Its later EnterSucceeded path then tries to re-queue a transaction it no longer owns.

2. The deferExtendedConnect re-queue guard checks mEntry (K1) rather than T’s current pending entry (K2, via T->GetHashKeyOfConnectionEntry()), so it cannot detect that T is already queued.

Comment 2

[Kershaw Chang [:kershaw]]

Attachment: Bug 2051415 - Abandon the stale Happy Eyeballs attempt when an upgrade falls back to HTTP/1, r=#necko

Comment 3

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/8ff31819fffb
https://hg.mozilla.org/integration/autoland/rev/280b35ab09b1
Abandon the stale Happy Eyeballs attempt when an upgrade falls back to HTTP/1, r=necko-reviewers,jesup

Comment 4

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/280b35ab09b1