Bug 1980171 Comment 7 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

Original comment by

Rob Wu [:robwu]

on 2025-07-30 10:51:38 PDT

I traced the network request in the log from comment 6, and selected the very specific part where it transitions from an okay state (MSG_DNS_LOOKUP_COMPLETE) to ultimately a bad state. To avoid incorrect interpretations, I explicitly annotated the parts I cut from the log in the log extract below.

- [`nsSocketTransportService::DoPollIteration`](https://searchfox.org/mozilla-central/rev/ab26427a8d31be475be11bbae0e04c84cc7f20ef/netwerk/base/nsSocketTransportService2.cpp#1404-1406) calls `DisengageTimeout()` and `OnSocketReady` (both appear in the log). 
- [`nsSocketTransport::OnSocketReady`](https://searchfox.org/mozilla-central/rev/ab26427a8d31be475be11bbae0e04c84cc7f20ef/netwerk/base/nsSocketTransport2.cpp#2236-2246) ends up logging `ErrorAccordingToNSPR`, with `ErrorAccordingToNSPR [in=-5999 out=80004005]` (where `-5999` is `PR_BAD_DESCRIPTOR_ERROR`).

```
2025-07-30 14:45:13.368939 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::OnSocketEvent [this=3736cfd00 type=1 status=0 param=0]
2025-07-30 14:45:13.368940 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   MSG_DNS_LOOKUP_COMPLETE
2025-07-30 14:45:13.368943 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368945 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Address [35.82.221.129] is blocklisted for host [searchfox.org].
2025-07-30 14:45:13.368947 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368950 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Address [35.155.250.20] is blocklisted for host [searchfox.org].
2025-07-30 14:45:13.368952 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368958 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   pushing io layer [0:ssl]
2025-07-30 14:45:13.368990 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] nsSSLIOLayerSetOptions: using TLS version range (0x0303,0x0304)
2025-07-30 14:45:13.368998 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] nsSSLIOLayerSetOptions: enabling TLS ECH Grease
2025-07-30 14:45:13.369007 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] Socket set up
2025-07-30 14:45:13.369010 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   [tlsSocketControl=44ffa5900 callbacks=15385bf10]
2025-07-30 14:45:13.369016 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AttachSocket [handler=3736cfd00]
2025-07-30 14:45:13.369018 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AddToIdleList 16ba72360 [handler=3736cfd00]
2025-07-30 14:45:13.369020 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=19 idle=1
2025-07-30 14:45:13.369022 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   advancing to STATE_CONNECTING
2025-07-30 14:45:13.369023 UTC - [Parent 54986: Socket Thread]: E/nsSocketTransport nsSocketTransport::SendStatus [this=3736cfd00 status=4b0007]
(... removed 3 lines from seemingly unrelated socket to unrelated domain ...)
2025-07-30 14:45:13.369159 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport STS poll iter
(... removed statuses of 19 active unrelated sockets ...)
2025-07-30 14:45:13.369265 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   idle [0] { handler=3736cfd00 condition=0 pollflags=6 }
2025-07-30 14:45:13.369267 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::MoveToPollList 126508888 [handler=3736cfd00]
2025-07-30 14:45:13.369269 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AddToPollList 126508888 [handler=3736cfd00]
2025-07-30 14:45:13.369271 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::EnsureTimeout socket=3736cfd00
2025-07-30 14:45:13.369273 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   engaging
2025-07-30 14:45:13.369274 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=20 idle=1
2025-07-30 14:45:13.369276 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::RemoveFromIdleList [handler=0]
2025-07-30 14:45:13.369278 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=20 idle=0
2025-07-30 14:45:13.369280 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   calling PR_Poll [active=20 idle=0]
(... removed 19x message like the next two lines for 19 unrelated sockets ...)
2025-07-30 14:45:13.369348 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::TimeoutIn socket=3736cfd00, timeout=65535s
2025-07-30 14:45:13.369350 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   not engaged
2025-07-30 14:45:13.369351 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport poll timeout: none
2025-07-30 14:45:13.369353 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport     timeout = -1 milliseconds
(... removed 18x "poll SSL socket using lower 5" + "poll SSL socket returned 5" ...)
2025-07-30 14:45:13.369421 UTC - [Parent 54986: Socket Thread]: V/pipnss [16468d900] poll SSL socket using lower 6
2025-07-30 14:45:13.369423 UTC - [Parent 54986: Socket Thread]: V/pipnss [16468d900] poll SSL socket returned 6
2025-07-30 14:45:13.619900 UTC - [Parent 54986: Timer]: D/nsSocketTransport STS dispatch [142f21390]
2025-07-30 14:45:13.619967 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::Signal
2025-07-30 14:45:13.619982 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::MarkFirstSignalTimestamp
2025-07-30 14:45:13.620001 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::Signal PR_Write 1
2025-07-30 14:45:13.620044 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport     ...returned after 251 milliseconds
(... removed 19x "SocketContext::TimeoutIn" + "not engaged" messages ...)
2025-07-30 14:45:13.620432 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::DisengageTimeout socket=3736cfd00
2025-07-30 14:45:13.620443 UTC - [Parent 54986: Socket Thread]: E/nsSocketTransport nsSocketTransport::OnSocketReady [this=3736cfd00 outFlags=16]
2025-07-30 14:45:13.620468 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport ErrorAccordingToNSPR [in=-5999 out=80004005]
2025-07-30 14:45:13.620480 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   connection failed! [reason=80004005]
2025-07-30 14:45:13.620490 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::DetachSocket [handler=3736cfd00]
2025-07-30 14:45:13.620500 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::OnSocketDetached [this=3736cfd00 cond=80004005]
2025-07-30 14:45:13.620511 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::RecoverFromError [this=3736cfd00 state=3 cond=80004005]
2025-07-30 14:45:13.620524 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Adding address to blocklist for host [searchfox.org], host record [415894c60].used trr=0
2025-07-30 14:45:13.620536 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Successfully adding address [44.226.105.90] to blocklist for host [searchfox.org].
2025-07-30 14:45:13.620548 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   not a recoverable error 80004005
2025-07-30 14:45:13.620558 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketInputStream::OnSocketReady [this=53b6cd040 cond=80004005]
2025-07-30 14:45:13.620568 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketOutputStream::OnSocketReady [this=53b6cee80 cond=80004005]
2025-07-30 14:45:13.620582 UTC - [Parent 54986: Socket Thread]: V/nsHttp DnsAndConnectSocket::OnOutputStreamReady [this=4f1b47ec0 ent=searchfox.org primary]
```

(if you want to see more, just look at the log from comment 6).

Revision 1 by

Rob Wu [:robwu]

on 2025-07-30 16:56:19 PDT

I traced the network request in the log from comment 6, and selected the very specific part where it transitions from an okay state (MSG_DNS_LOOKUP_COMPLETE) to ultimately a bad state. To avoid incorrect interpretations, I explicitly annotated the parts I cut from the log in the log extract below.

- [`nsSocketTransportService::DoPollIteration`](https://searchfox.org/mozilla-central/rev/ab26427a8d31be475be11bbae0e04c84cc7f20ef/netwerk/base/nsSocketTransportService2.cpp#1404-1406) calls `DisengageTimeout()` and `OnSocketReady` (both appear in the log). 
- [`nsSocketTransport::OnSocketReady`](https://searchfox.org/mozilla-central/rev/ab26427a8d31be475be11bbae0e04c84cc7f20ef/netwerk/base/nsSocketTransport2.cpp#2236-2246) ends up logging `ErrorAccordingToNSPR`, with `ErrorAccordingToNSPR [in=-5999 out=80004005]` (where `-5999` is `PR_BAD_DESCRIPTOR_ERROR`).

```
2025-07-30 14:45:13.368939 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::OnSocketEvent [this=3736cfd00 type=1 status=0 param=0]
2025-07-30 14:45:13.368940 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   MSG_DNS_LOOKUP_COMPLETE
2025-07-30 14:45:13.368943 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368945 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Address [35.82.221.129] is blocklisted for host [searchfox.org].
2025-07-30 14:45:13.368947 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368950 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Address [35.155.250.20] is blocklisted for host [searchfox.org].
2025-07-30 14:45:13.368952 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368954 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::InitiateSocket [this=3736cfd00]
2025-07-30 14:45:13.368956 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::BuildSocket [this=3736cfd00]
2
2025-07-30 14:45:13.368958 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   pushing io layer [0:ssl]
2025-07-30 14:45:13.368990 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] nsSSLIOLayerSetOptions: using TLS version range (0x0303,0x0304)
2025-07-30 14:45:13.368998 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] nsSSLIOLayerSetOptions: enabling TLS ECH Grease
2025-07-30 14:45:13.369007 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] Socket set up
2025-07-30 14:45:13.369010 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   [tlsSocketControl=44ffa5900 callbacks=15385bf10]
2025-07-30 14:45:13.369016 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AttachSocket [handler=3736cfd00]
2025-07-30 14:45:13.369018 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AddToIdleList 16ba72360 [handler=3736cfd00]
2025-07-30 14:45:13.369020 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=19 idle=1
2025-07-30 14:45:13.369022 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   advancing to STATE_CONNECTING
2025-07-30 14:45:13.369023 UTC - [Parent 54986: Socket Thread]: E/nsSocketTransport nsSocketTransport::SendStatus [this=3736cfd00 status=4b0007]
(... removed 3 lines from seemingly unrelated socket to unrelated domain ...)
2025-07-30 14:45:13.369159 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport STS poll iter
(... removed statuses of 19 active unrelated sockets ...)
2025-07-30 14:45:13.369265 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   idle [0] { handler=3736cfd00 condition=0 pollflags=6 }
2025-07-30 14:45:13.369267 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::MoveToPollList 126508888 [handler=3736cfd00]
2025-07-30 14:45:13.369269 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AddToPollList 126508888 [handler=3736cfd00]
2025-07-30 14:45:13.369271 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::EnsureTimeout socket=3736cfd00
2025-07-30 14:45:13.369273 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   engaging
2025-07-30 14:45:13.369274 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=20 idle=1
2025-07-30 14:45:13.369276 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::RemoveFromIdleList [handler=0]
2025-07-30 14:45:13.369278 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=20 idle=0
2025-07-30 14:45:13.369280 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   calling PR_Poll [active=20 idle=0]
(... removed 19x message like the next two lines for 19 unrelated sockets ...)
2025-07-30 14:45:13.369348 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::TimeoutIn socket=3736cfd00, timeout=65535s
2025-07-30 14:45:13.369350 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   not engaged
2025-07-30 14:45:13.369351 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport poll timeout: none
2025-07-30 14:45:13.369353 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport     timeout = -1 milliseconds
(... removed 18x "poll SSL socket using lower 5" + "poll SSL socket returned 5" ...)
2025-07-30 14:45:13.369421 UTC - [Parent 54986: Socket Thread]: V/pipnss [16468d900] poll SSL socket using lower 6
2025-07-30 14:45:13.369423 UTC - [Parent 54986: Socket Thread]: V/pipnss [16468d900] poll SSL socket returned 6
2025-07-30 14:45:13.619900 UTC - [Parent 54986: Timer]: D/nsSocketTransport STS dispatch [142f21390]
2025-07-30 14:45:13.619967 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::Signal
2025-07-30 14:45:13.619982 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::MarkFirstSignalTimestamp
2025-07-30 14:45:13.620001 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::Signal PR_Write 1
2025-07-30 14:45:13.620044 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport     ...returned after 251 milliseconds
(... removed 19x "SocketContext::TimeoutIn" + "not engaged" messages ...)
2025-07-30 14:45:13.620432 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::DisengageTimeout socket=3736cfd00
2025-07-30 14:45:13.620443 UTC - [Parent 54986: Socket Thread]: E/nsSocketTransport nsSocketTransport::OnSocketReady [this=3736cfd00 outFlags=16]
2025-07-30 14:45:13.620468 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport ErrorAccordingToNSPR [in=-5999 out=80004005]
2025-07-30 14:45:13.620480 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   connection failed! [reason=80004005]
2025-07-30 14:45:13.620490 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::DetachSocket [handler=3736cfd00]
2025-07-30 14:45:13.620500 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::OnSocketDetached [this=3736cfd00 cond=80004005]
2025-07-30 14:45:13.620511 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::RecoverFromError [this=3736cfd00 state=3 cond=80004005]
2025-07-30 14:45:13.620524 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Adding address to blocklist for host [searchfox.org], host record [415894c60].used trr=0
2025-07-30 14:45:13.620536 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Successfully adding address [44.226.105.90] to blocklist for host [searchfox.org].
2025-07-30 14:45:13.620548 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   not a recoverable error 80004005
2025-07-30 14:45:13.620558 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketInputStream::OnSocketReady [this=53b6cd040 cond=80004005]
2025-07-30 14:45:13.620568 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketOutputStream::OnSocketReady [this=53b6cee80 cond=80004005]
2025-07-30 14:45:13.620582 UTC - [Parent 54986: Socket Thread]: V/nsHttp DnsAndConnectSocket::OnOutputStreamReady [this=4f1b47ec0 ent=searchfox.org primary]
```

(if you want to see more, just look at the log from comment 6).

Revision 2 by

Rob Wu [:robwu]

on 2025-07-30 16:57:50 PDT

I traced the network request in the log from comment 6, and selected the very specific part where it transitions from an okay state (MSG_DNS_LOOKUP_COMPLETE) to ultimately a bad state. To avoid incorrect interpretations, I explicitly annotated the parts I cut from the log in the log extract below.

- [`nsSocketTransportService::DoPollIteration`](https://searchfox.org/mozilla-central/rev/ab26427a8d31be475be11bbae0e04c84cc7f20ef/netwerk/base/nsSocketTransportService2.cpp#1404-1406) calls `DisengageTimeout()` and `OnSocketReady` (both appear in the log). 
- [`nsSocketTransport::OnSocketReady`](https://searchfox.org/mozilla-central/rev/ab26427a8d31be475be11bbae0e04c84cc7f20ef/netwerk/base/nsSocketTransport2.cpp#2236-2246) ends up logging `ErrorAccordingToNSPR`, with `ErrorAccordingToNSPR [in=-5999 out=80004005]` (where `-5999` is `PR_BAD_DESCRIPTOR_ERROR`).

```
2025-07-30 14:45:13.368939 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::OnSocketEvent [this=3736cfd00 type=1 status=0 param=0]
2025-07-30 14:45:13.368940 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   MSG_DNS_LOOKUP_COMPLETE
2025-07-30 14:45:13.368943 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368945 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Address [35.82.221.129] is blocklisted for host [searchfox.org].
2025-07-30 14:45:13.368947 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368950 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Address [35.155.250.20] is blocklisted for host [searchfox.org].
2025-07-30 14:45:13.368952 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Checking unusable list for host [searchfox.org], host record [415894c60].
2025-07-30 14:45:13.368954 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::InitiateSocket [this=3736cfd00]
2025-07-30 14:45:13.368956 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::BuildSocket [this=3736cfd00]
2025-07-30 14:45:13.368958 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   pushing io layer [0:ssl]
2025-07-30 14:45:13.368990 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] nsSSLIOLayerSetOptions: using TLS version range (0x0303,0x0304)
2025-07-30 14:45:13.368998 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] nsSSLIOLayerSetOptions: enabling TLS ECH Grease
2025-07-30 14:45:13.369007 UTC - [Parent 54986: Socket Thread]: D/pipnss [16468d900] Socket set up
2025-07-30 14:45:13.369010 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   [tlsSocketControl=44ffa5900 callbacks=15385bf10]
2025-07-30 14:45:13.369016 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AttachSocket [handler=3736cfd00]
2025-07-30 14:45:13.369018 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AddToIdleList 16ba72360 [handler=3736cfd00]
2025-07-30 14:45:13.369020 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=19 idle=1
2025-07-30 14:45:13.369022 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   advancing to STATE_CONNECTING
2025-07-30 14:45:13.369023 UTC - [Parent 54986: Socket Thread]: E/nsSocketTransport nsSocketTransport::SendStatus [this=3736cfd00 status=4b0007]
(... removed 3 lines from seemingly unrelated socket to unrelated domain ...)
2025-07-30 14:45:13.369159 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport STS poll iter
(... removed statuses of 19 active unrelated sockets ...)
2025-07-30 14:45:13.369265 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   idle [0] { handler=3736cfd00 condition=0 pollflags=6 }
2025-07-30 14:45:13.369267 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::MoveToPollList 126508888 [handler=3736cfd00]
2025-07-30 14:45:13.369269 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::AddToPollList 126508888 [handler=3736cfd00]
2025-07-30 14:45:13.369271 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::EnsureTimeout socket=3736cfd00
2025-07-30 14:45:13.369273 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   engaging
2025-07-30 14:45:13.369274 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=20 idle=1
2025-07-30 14:45:13.369276 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::RemoveFromIdleList [handler=0]
2025-07-30 14:45:13.369278 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   active=20 idle=0
2025-07-30 14:45:13.369280 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   calling PR_Poll [active=20 idle=0]
(... removed 19x message like the next two lines for 19 unrelated sockets ...)
2025-07-30 14:45:13.369348 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::TimeoutIn socket=3736cfd00, timeout=65535s
2025-07-30 14:45:13.369350 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   not engaged
2025-07-30 14:45:13.369351 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport poll timeout: none
2025-07-30 14:45:13.369353 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport     timeout = -1 milliseconds
(... removed 18x "poll SSL socket using lower 5" + "poll SSL socket returned 5" ...)
2025-07-30 14:45:13.369421 UTC - [Parent 54986: Socket Thread]: V/pipnss [16468d900] poll SSL socket using lower 6
2025-07-30 14:45:13.369423 UTC - [Parent 54986: Socket Thread]: V/pipnss [16468d900] poll SSL socket returned 6
2025-07-30 14:45:13.619900 UTC - [Parent 54986: Timer]: D/nsSocketTransport STS dispatch [142f21390]
2025-07-30 14:45:13.619967 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::Signal
2025-07-30 14:45:13.619982 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::MarkFirstSignalTimestamp
2025-07-30 14:45:13.620001 UTC - [Parent 54986: Timer]: D/nsSocketTransport PollableEvent::Signal PR_Write 1
2025-07-30 14:45:13.620044 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport     ...returned after 251 milliseconds
(... removed 19x "SocketContext::TimeoutIn" + "not engaged" messages ...)
2025-07-30 14:45:13.620432 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport SocketContext::DisengageTimeout socket=3736cfd00
2025-07-30 14:45:13.620443 UTC - [Parent 54986: Socket Thread]: E/nsSocketTransport nsSocketTransport::OnSocketReady [this=3736cfd00 outFlags=16]
2025-07-30 14:45:13.620468 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport ErrorAccordingToNSPR [in=-5999 out=80004005]
2025-07-30 14:45:13.620480 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   connection failed! [reason=80004005]
2025-07-30 14:45:13.620490 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransportService::DetachSocket [handler=3736cfd00]
2025-07-30 14:45:13.620500 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::OnSocketDetached [this=3736cfd00 cond=80004005]
2025-07-30 14:45:13.620511 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketTransport::RecoverFromError [this=3736cfd00 state=3 cond=80004005]
2025-07-30 14:45:13.620524 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Adding address to blocklist for host [searchfox.org], host record [415894c60].used trr=0
2025-07-30 14:45:13.620536 UTC - [Parent 54986: Socket Thread]: D/nsHostResolver Successfully adding address [44.226.105.90] to blocklist for host [searchfox.org].
2025-07-30 14:45:13.620548 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport   not a recoverable error 80004005
2025-07-30 14:45:13.620558 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketInputStream::OnSocketReady [this=53b6cd040 cond=80004005]
2025-07-30 14:45:13.620568 UTC - [Parent 54986: Socket Thread]: D/nsSocketTransport nsSocketOutputStream::OnSocketReady [this=53b6cee80 cond=80004005]
2025-07-30 14:45:13.620582 UTC - [Parent 54986: Socket Thread]: V/nsHttp DnsAndConnectSocket::OnOutputStreamReady [this=4f1b47ec0 ent=searchfox.org primary]
```

(if you want to see more, just look at the log from comment 6).

Back to Bug 1980171 Comment 7