2020627 - After 12–48+ hours of uptime all POP3 accounts stop downloading mail (manual and scheduled checks do nothing) until restart

Status: RESOLVED FIXED

(MailNews Core :: Networking: POP, defect)

Description

[wiola9099]

Attachment: console-export.txt

Steps to reproduce:

I don’t have a deterministic “click-by-click” reproduction. It typically happens after ~12–48+ hours of Thunderbird uptime on a Windows 10 machine that runs 24/7 (no sleep/hibernate).​
Steps that lead to the failure (best-effort):

1. Start Thunderbird and let it run continuously with multiple accounts configured (2× IMAP, 6× POP3).​

Actual results:

At some point after long uptime, POP3 retrieval stops working for all POP3 accounts simultaneously. Manual “Get Messages” on any POP3 account does nothing (no status/progress shown), scheduled checks also stop, while the UI remains responsive and IMAP continues to work.

Right before POP3 dies, the log shows POP3 server response: "-ERR failed to get listing". After this, POP3 retrieval stays broken until Thunderbird restart, nothing more is logged in console.

Expected results:

POP3 accounts should continue to download mail both via manual and scheduled checks.

Comment 1

[Magnus Melin [:mkmelin]]

Have you tried v148?

Comment 2

[wiola9099]

(In reply to Magnus Melin [:mkmelin] from comment #1)

Have you tried v148?

I first installed v148, and that’s when I encountered these problems for the first time (immediately after installing, before that I was using a different email client). I therefore switched to v140esr to test it and the problem is the same.

Comment 3

[Hartmut Welpmann [:welpy-cw]]

So, I fed Gemini Pro with information about this and bug 1984179 which I found to be likely linked to this. It came up with this assessment:

🐛 Root Cause Identified: Unhandled Socket Drops cause State Deadlock & False-Success

After digging into Pop3Client.sys.mjs and LineReader.sys.mjs, I've identified the root cause of this 24/7 Windows hang. Furthermore, this exact mechanism almost certainly explains Bug 1984179 (POP3 failing to check immediately on macOS wake-up).

The issue stems from how the new JavaScript POP3 client handles a TCP connection that is abruptly dropped mid-transaction (e.g., during a multi-line UIDL or RETR response).

The False-Success Bug (Pop3Client.sys.mjs)
When a socket drops unexpectedly, the _onClose event listener fires. If this._authenticating is false, it falls back to calling this._actionDone(). Because no status argument is passed, it defaults to Cr.NS_OK.
Result: Thunderbird silently treats the interrupted connection as a perfectly successful mail sync.

The State Deadlock (LineReader.sys.mjs)
Because the client didn't recognize the failure, it fails to clean up its internal state.
The LineReader remains stuck with receivingMultiLineResponse = true because it never saw the terminating \r\n.\r\n.
The this._server.serverBusy flag remains true.
Result: On the next scheduled or manual mail check, the account is effectively dead. The serverBusy lock prevents new checks, or the polluted LineReader misparses the new connection's +OK greeting.

🔗 Why this explains Bug 1984179 (macOS Wake-up)

In Bug 1984179, the user notes that the network takes ~30 seconds to become available after the Mac wakes from sleep.

Thunderbird attempts to check POP3 immediately upon wake-up.
The flaky, recovering network causes the socket to connect but abruptly drop (or drop packets).
This triggers the exact _onClose false-success flaw described above.
The account is instantly deadlocked (serverBusy = true). It ignores manual clicks and waits for the background timers to eventually clear the state, which explains why the user sees it "skip" the immediate check and only work 15 minutes later.

The following patch was also crafted mostly by Gemini. It makes sense to me, the test fails without the patch and succeeds with it.

Comment 4

[Hartmut Welpmann [:welpy-cw]]

Attachment: Bug 2020627 - Fix POP3 state deadlock and false-success on unexpected connection drops. r=#thunderbird-reviewers

If a POP3 connection dropped unexpectedly during a multi-line response (like
UIDL), _onClose defaulted to _actionDone(Cr.NS_OK). This caused Thunderbird
to silently accept the failed sync as successful. Furthermore, the LineReader
and NOOP states were not cleared, blinding the JS state machine to all future
server responses, deadlocking the account until TB was restarted.

• Added explicit check if (!this._done) in Pop3Client._onClose to propagate
  Cr.NS_ERROR_NET_INTERRUPT when a socket closes mid-transaction.

• Added LineReader.reset() and called it during Pop3Client.connect() to
  ensure a clean state buffer on retry.

• Added test_pop3StateDeadlock.js which forces a TCP drop during UIDL and
  validates both the error propagation and subsequent recovery.

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/comm-central/rev/b4859cea2c92
Fix POP3 state deadlock and false-success on unexpected connection drops. r=mkmelin

Comment 6

[wiola9099]

Bug still present (Thunderbird 150.0).

Log:

14:19:53.800 pop3.server9.17: Connecting to pop://poczta.o2.pl:995 Pop3Client.sys.mjs:140:18
14:19:53.807 pop3.server9.17: Connected Pop3Client.sys.mjs:285:18
14:19:53.867 pop3.server9.17: S: +OK POP3 ready
Pop3Client.sys.mjs:349:18
14:19:53.871 pop3.server9.17: C: CAPA Pop3Client.sys.mjs:595:20
14:19:53.876 pop3.server9.17: S: +OK Capability list follows
LAST
USER
PIPELINING
UIDL
SASL PLAIN LOGIN
.
Pop3Client.sys.mjs:349:18
14:19:53.876 pop3.server9.17: Possible auth methods: PLAIN,LOGIN,USERPASS Pop3Client.sys.mjs:710:18
14:19:53.876 pop3.server9.17: Current auth method: PLAIN Pop3Client.sys.mjs:781:18
14:19:53.876 pop3.server9.17: C: AUTH PLAIN Pop3Client.sys.mjs:595:20
14:19:53.881 pop3.server9.17: S: +
Pop3Client.sys.mjs:349:18
14:19:53.881 pop3.server9.17: C: Logging suppressed (it probably contained auth information) Pop3Client.sys.mjs:589:20
14:19:54.417 pop3.server9.17: S: -ERR failed to get listing
Pop3Client.sys.mjs:349:18
14:19:54.417 pop3.server9.17: AUTH PLAIN failed. Trying AUTH LOGIN next Pop3Client.sys.mjs:867:20
14:19:54.417 pop3.server9.17: Current auth method: LOGIN Pop3Client.sys.mjs:781:18
14:19:54.417 pop3.server9.17: C: AUTH LOGIN Pop3Client.sys.mjs:595:20
03:11:38.751 NS_ERROR_NOT_AVAILABLE
03:11:38.967 Error: Polling for changes failed: Server error https://thunderbird-settings.thunderbird.net/v1/buckets/monitor/collections/changes/changeset?_expected=0&_since=1648185887941 400 : {"code":400,"errno":107,"error":"Invalid parameters","message":"_since in querystring: The value should be integer between double quotes.","details":[{"location":"querystring","name":"_since","description":"The value should be integer between double quotes."}]}.
pollChanges resource://services-settings/remote-settings.sys.mjs:482
RemoteSettingsComponents.sys.mjs:20:15
notify resource://services-settings/RemoteSettingsComponents.sys.mjs:20

Comment 7

[Hartmut Welpmann [:welpy-cw]]

Please provide more information, what exactly did you experience in the time frame the log covers? Was the computer in sleep mode between 14:19 and 03:11?

Comment 8

[wiola9099]

The PC is running 24/7 with sleep/hibernation disabled. At 14:19 I was away from the computer; there might have been a temporary network issue, though I didn't notice anything unusual that day. Maybe there's some random issue on email provider's side - it seems the log always shows the same provider.
To summarize: starting at 14:19, all POP3 accounts in Thunderbird stopped working, while IMAP accounts continued to function correctly. At 3:11, an additional error appeared in the log, I don't know if it's related. After a restart, Thunderbird works properly until the next time this bug occurs - anywhere from a few hours to a few days.

Comment 9

[Hartmut Welpmann [:welpy-cw]]

Attachment: Bug 2020627 - Fix POP3 state deadlock when connection drops during authentication. r=#thunderbird-reviewers

The previous fix for unexpected POP3 connection drops overlooked drops that
occur during the authentication phase. If a server abruptly closed the socket
during auth, _onClose would trigger this._actionAuthResponse({ success: false }).

This caused the POP3 state machine to attempt its fallback authentication
method (e.g., moving from AUTH PLAIN to AUTH LOGIN) and send the next command
over a socket that was already dead. Because no network response could ever
arrive on a closed socket, _actionDone was never called, and the account
remained permanently deadlocked with serverBusy = true.

This patch removes the special-case _authenticating branch inside _onClose.
Now, if the socket closes unexpectedly (!this._done)—regardless of whether it
happens during authentication or a standard command—the sync is immediately
aborted via _actionDone(Cr.NS_ERROR_NET_INTERRUPT). This guarantees the
3-second cleanup timeout will fire, releasing the folder locks and freeing the
connection for the next scheduled mail check.

Comment 10

[Hartmut Welpmann [:welpy-cw]]

(In reply to wiola9099 from comment #8)

The PC is running 24/7 with sleep/hibernation disabled. At 14:19 I was away from the computer; there might have been a temporary network issue, though I didn't notice anything unusual that day. Maybe there's some random issue on email provider's side - it seems the log always shows the same provider.
To summarize: starting at 14:19, all POP3 accounts in Thunderbird stopped working, while IMAP accounts continued to function correctly. At 3:11, an additional error appeared in the log, I don't know if it's related. After a restart, Thunderbird works properly until the next time this bug occurs - anywhere from a few hours to a few days.

Thanks. Can you tell me the value of the mailnews.tcptimeout preference in your profile?

Comment 11

[wiola9099]

mailnews.tcptimeout = 100

Comment 12

[Hartmut Welpmann [:welpy-cw]]

Initially I had assumed this situation with a POP server just becoming completely unresponsive instead of closing the connection would have been caught eventually by the TCP socket timing out, but apparently it does not. Unfortunately, since POP servers are now accessed strictly serially (see also Bug 1943854), one hanging connection stalls all POP access. A relatively easy solution seems to be providing POP3Client with its own application timeout guarding each sent command. What do you think, Magnus?

Comment 13

[Magnus Melin [:mkmelin]]

I'm not sure what you're proposing

Comment 14

[Hartmut Welpmann [:welpy-cw]]

I'd suggest starting a timer at the end of POP3Client._send(), which is cleared as soon as _onData() is called. If it should time out on the other hand, it calls this._actionDone(Cr.NS_ERROR_NET_TIMEOUT); to safely free the connection.

Comment 15

[Magnus Melin [:mkmelin]]

I see, yeah that could work

Comment 16

[Hartmut Welpmann [:welpy-cw]]

Attachment: Bug 2020627 - Implement application-layer watchdog to prevent POP3 queue deadlock on silent servers. r=mkmelin

If a POP3 server drops a connection or goes completely silent without closing
the TCP socket (e.g., after receiving AUTH LOGIN), the JavaScript POP3
implementation enters a permanent deadlock. Because the client relies on an
asynchronous DOM TCPSocket, the underlying nsSocketTransport's
TIMEOUT_READ_WRITE NSPR timer does not tick while the socket is merely sitting
idle waiting for an initial response.

Since the client never times out, _actionDone() and onFree() are never
called, causing the global #_busyConnections lock in Pop3IncomingServer to
remain held forever, freezing all subsequent POP3 sync attempts across all
accounts until the application is restarted.

This patch fixes the deadlock by introducing an application-layer watchdog:

• Starts a timer inside _send() whenever a command is sent to the network.
• Clears the timer inside _onData() the moment the server proves it is alive.
• If the timer fires, it triggers _actionDone(Cr.NS_ERROR_NET_TIMEOUT) to
  safely unwind the state machine, release the global queue lock, and free the
  connection.

To prevent race conditions with the native C++ socket timeout during active,
multi-line data streams (e.g., during RETR), the watchdog reads the user's
mailnews.tcptimeout preference and adds a 10-second safety margin. This
allows the OS to handle standard network timeouts natively, while acting as a
fail-safe Time-To-First-Byte (TTFB) monitor for idle socket deadlocks.

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/comm-central/rev/a810498a80ac
Implement application-layer watchdog to prevent POP3 queue deadlock on silent servers. r=mkmelin