1761589 - Cannot get new messages due to pop3ServerBusy error

Status: RESOLVED FIXED

(MailNews Core :: Networking: POP, defect)

Description

[doug2]

Attachment: mailnewspop3.txt

+++ This bug was initially created as a clone of Bug #1759372 +++

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:98.0) Gecko/20100101 Firefox/98.0

Steps to reproduce:

Clicked on the Menu bar's "Get Mail" option to request new email from the server.

User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:99.0) Gecko/20100101
Thunderbird/99.0

Actual results:

Though there was no indication in the status bar that the function was initiated, the mail retrieval function did seem to be working.

Expected results:

Expected a status bar message indicating that mail was being requested from the server.

Comment 1

[doug2]

Attachment: mailnewspop3-b.txt

Mail stops being downloaded via Pop3 for the primary account. When this happens, no request to get mail for that account works (including the Get New Messages menu and F5). Only restarting Thunderbird will restart mail downloads. By observation, the stoppage seems to be related to the message(s) "Moved xxx messages from a to b."

Comment 2

[Ping Chen [:rnons] (away)]

Since this is a totally different bug, it's better to remove the original text of bug 1759372 in comment 0.

By observation, the stoppage seems to be related to the message(s) "Moved xxx messages from a to b."

I didn't see "Moved xxx messages from a to b." in your logs.

Comment 3

[doug2]

Attachment: mailnewspop3-c.txt

Complete log file attached.

Comment 4

[doug2]

Once the "Moved xxx messages ..." appears in the status bar, it seems to block all other messages or the message function stops working.

Comment 5

[Ping Chen [:rnons] (away)]

Do you have some filters that move messages?

Comment 6

[doug2]

Yes. Several. All based on subject line contents for some senders and the spam flag. Do you want me to disable them?

Comment 7

[doug2]

As an experiment, I have disabled all message filters. The Status Line alerts about moving messages have recently come from TB automatic processes such as "Moved xx messages from Inbox to Trash" (the ones I have deleted) or "Deleted xx messages from Trash" (per my retention date instructions). I don't have a way to control the moving deleted messages to trash process except not delete them. I can change my retention date temporarily to stop deleting messages in trash for a while.

Comment 8

[doug2]

The experiment in comment 7 above has made no difference. The custom filters are disabled, but "most of the time" an automatic status of "moved xx messages to yy" is followed by no messages downloaded, F5 doesn't work, etc. Only shutting down and restarting TB reenables downloads.

Comment 9

[doug2]

Attachment: mailnewspop3-d.txt

New error file added. Download stopped at message 7 of 17 per status message. Checked F5 did not restart. Had to shut down and reopen to continue download.

Comment 10

[Magnus Melin [:mkmelin]]

Maybe https://searchfox.org/comm-central/rev/925606caac04e4b8b401807fd631ac83c9e7b52d/mailnews/local/src/Pop3Client.jsm#847 should just more or less ignore the "error"...

Comment 11

[doug2]

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

Maybe https://searchfox.org/comm-central/rev/925606caac04e4b8b401807fd631ac83c9e7b52d/mailnews/local/src/Pop3Client.jsm#847 should just more or less ignore the "error"...

Seems reasonable to me. Ref. comment #9 - after restarting TB, got a second copy of several messages. "Ignoring" the error would have resolved that also. Essentially a timed retry should work?

Comment 12

[Ping Chen [:rnons] (away)]

Attachment: Bug 1761589 - Ignore serverBusy when connecting to server in Pop3Client.jsm. r=mkmelin

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/comm-central/rev/612eda019d69
Ignore serverBusy when connecting to server in Pop3Client.jsm. r=mkmelin

Comment 14

[Ping Chen [:rnons] (away)]

Please help me test by downloading a nightly build. Go to https://www.thunderbird.net, search for "daily channel". Thanks.

Comment 15

[doug2]

Running 100.0a1 Will report any stops, etc.

Comment 16

[doug2]

So far, so good. No stops over night. I have turned my filters back on (didn't make a difference while they were off).
Running well on daily 100.0a1 after more than 3 hours of fairly constant use this AM.

Comment 17

[doug2]

Attachment: mailnewspop3-e.txt

Tried F5 to get new mail. Says email in progress. New log file.

Comment 18

[doug2]

Sorry for not reporting sooner. Our internet has been down for 8 hours. The fix seems solid so far as I can tell. I have not seen a stoppage since installing 100.0a1. F5 and other requests for new mail work and a status appears every time.
I turned all my filters back on earlier (having them off had not made any difference). I am still seeing some odd status messages (e.g., "Moved 4 messages from Drafts to Trash" when no messages were actually moved), but that's different problem.
************* spoke too soon ****** tried to get mail with F5 and got an error that email was being processed. see new (partial) trace

Comment 19

[doug2]

Turns out there was a message "sending" but never completed. (Previous problem). I have been just canceling the send when that happens and retrying and the message usually goes the 2nd time. This time, daily was locked up - get mail was still stuck after the message went. I stopped and started Daily and got a second copy of several messages.

Comment 20

[doug2]

Attachment: mailnewspop3-f.txt

Comment 21

[doug2]

Attachment: mailnewspop3-g.txt

F5 attempt to get new mail. Consistently mailserver busy. Shut down daily and restarted, mail came in.

Comment 22

[doug2]

Attachment: mailnewspop3-h.txt

F5 get mail, mail begins download - stops downloading. does not restart = 2nd F5 required to continue downloading.

Comment 23

[Ping Chen [:rnons] (away)]

Thanks, no need to post new logs if they are not adding new info. Please refer to https://wiki.mozilla.org/MailNews:Logging#Generating_a_Protocol_Log, replace imap with pop3 to get some backend logs.

After every Get Message, you should see something like

[Parent 44943: Main Thread]: D/POP3 sink: [this=7efbb6fda7a0] Calling ReleaseFolderLock from EndMailDelivery
[Parent 44943: Main Thread]: D/POP3 sink: [this=7efbb6fda7a0] ReleaseFolderLock haveSemaphore = TRUE

or

[Parent 44943: Main Thread]: D/POP3 sink: [this=7efbb6fda7a0] Calling ReleaseFolderLock from ~nsPop3Sink
[Parent 44943: Main Thread]: D/POP3 sink: [this=7efbb6fda7a0] ReleaseFolderLock haveSemaphore = FALSE

If you don't see any of the above, or see folder lock not released successfully instead, then it's a problem.

Comment 24

[doug2]

requested mail. status "Gmail: Host contacted, sending login information ...
error console:
1649635074551 addons.xpi WARN Checking C:\Program Files\Mozilla Thunderbird\distribution\extensions for addons
Exception { name: "NS_ERROR_FAILURE", message: "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsISecretDecoderRing.decryptString]", result: 2147500037, filename: "chrome://openpgp/content/modules/masterpass.jsm", lineNumber: 230, columnNumber: 0, data: null, stack: "_readPasswordFromFile@chrome://openpgp/content/modules/masterpass.jsm:230:16\n", location: XPCWrappedNative_NoHelper }
​
columnNumber: 0
​
data: null
​
filename: "chrome://openpgp/content/modules/masterpass.jsm"
​
lineNumber: 230
​
location: XPCWrappedNative_NoHelper { QueryInterface: QueryInterface(), filename: Getter, name: Getter, … }
​
message: "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsISecretDecoderRing.decryptString]"
​
name: "NS_ERROR_FAILURE"
​
result: 2147500037
​
stack: "_readPasswordFromFile@chrome://openpgp/content/modules/masterpass.jsm:230:16\n"
​
<prototype>: ExceptionPrototype { toString: toString(), name: Getter, message: Getter, … }
RNP.jsm:47:15
uncaught exception: 2147500036
uncaught exception: 2147500036

​