1875633 - Hotmail POP3 intermittently displays UIDL or XTND XLST error messages

Status: RESOLVED FIXED

(MailNews Core :: Networking: POP, defect)

Description

[Isaac Ribeiro]

Attachment: Error Message

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36

Steps to reproduce:

When this error affected a first account, I just changed the POP3 authentication method from "Normal Password" to "OAuth2" after upgrading to Thunderbird 115.1.0 in August 2023. Other accounts using the same server continued to work perfectly.

When this error affected two more accounts today, I just updated Thunderbird to version 115.6.1 after a few weeks of not opening it, precisely because my main account had stopped downloading messages for a long time.

New messages from these two accounts had been downloaded before restarting Thunderbird to apply the said update and other accounts using the same server continued to work perfectly.

Actual results:

I am currently unable to download messages from 3 Hotmail accounts, although other accounts with the same server configuration are working normally.

The error message displayed is "The POP3 mail server (outlook.office365.com) does not support UIDL or XTND XLST, which are required to implement the 'Leave on Server', 'Maximum Message Size' or 'Fetch Headers Only' options . To download your mail, turn off these options in the Server Settings for your mail server in the Account Settings window."

Expected results:

I hope that some Thunderbird update will restore the download of new messages on all my Hotmail accounts.

Comment 1

[Isaac Ribeiro]

Attachment: Error Console

Comment 2

[gene smith]

Sounds very similar to bug 1577548. But this was fixed several years ago when TB's POP3 was using c++ code. I wonder if that fix got ported to the Javascript POP3 implementation?
Reporter Isaac: Are you only seeing a problem after you change your accounts over to OAuth2?

Comment 3

[gene smith]

I set up a new pop3 account with outlook.com with default settings and don't see a problem receiving new mail with normal password or then after changing to oauth2. Not seeing any error messages regarding UIDL or XTND XLST.

Can you you tell me exactly your various POP3 server setting you have in TB?
Is the problem intermittent?
If you restart TB, does it allow new messages to come in?

Comment 4

[Isaac Ribeiro]

(In reply to gene smith from comment #2)

Sounds very similar to bug 1577548. But this was fixed several years ago when TB's POP3 was using c++ code. I wonder if that fix got ported to the Javascript POP3 implementation?
Reporter Isaac: Are you only seeing a problem after you change your accounts over to OAuth2?

Exactly. I only had the problem after automatically switching my accounts to OAuth2, but the problem continued when I returned the faulty account to "normal password".

I didn't want to set up a new Outlook.com account so TB wouldn't re-download 100000+ messages from my main account.

I can now say that the problem is intermittent, because TB is currently downloading almost 5,000 messages from my main account and the two accounts that started having problems yesterday are working again today.

I closed TB yesterday a few hours after upgrading to version 115.6.1 and restarted it a little while ago.

Today is the second time TB has downloaded messages from my main account since August last year. The problem was not resolved when restarting the TB.

Comment 5

[Isaac Ribeiro]

Attachment: Server Settings

Comment 6

[Isaac Ribeiro]

Attachment: Disk Space

Comment 7

[gene smith]

I'm now doubting it's the same problem as bug 1577548, but not 100% sure.
My newly set up outlook account definitely reports that it has UIDL capability. But capabilities reported have been known to vary depending on which actual server is accessed, especially for the big providers like microsoft, yahoo and maybe gmail.
Anyhow, looking at the code, it appears that if TB sees an error from the server when trying to do the UIDL command it puts up the error message you reported in comment 0:
"The POP3 mail server (outlook.office365.com) does not support UIDL or XTND XLST, which are required to implement the 'Leave on Server', 'Maximum Message Size' or 'Fetch Headers Only' options . To download your mail, turn off these options in the Server Settings for your mail server in the Account Settings window.
When this error occurs there is no attempt to fetch the messages by other means. So if the server actually doesn't support UIDL, to get your mail you really do have to switch off those items. So in your case, you only have "Leave on Server" selected so you would need to turn that off to reliably fetch new messages, it seems.

However, I assume you still want to keep your messages on the server so we need to find out if outlook is really not supporting UIDL. To see what it reports you can set the preference mailnews.pop3.loglevel to Debug and look at the log using TB's built-in console. The console can be accessed with ctrl-shift-j. Each time you click the "Get Mail" button or when your 62 minute timer expires a request for new mail will occur and be logged. Then in the console, on each request for new mail, you should see something like this:

S: +OK The Microsoft Exchange POP3 service is ready. [TQBOADIAUABSADEAMQBDAEEAMAAwADMAMAAuAG4AYQBtAHAAcgBkADEAMQAuAHAAcgBvAGQALgBvAHUAdABsAG8AbwBrAC4AYwBvAG0A]
C: CAPA
S: +OK
TOP
UIDL
SASL PLAIN XOAUTH2
USER

If UIDL is not in the list, it will cause the problem you are seeing.
Again, this appears to be intermittent so you need to look at this several times over a fairly long time period and maybe every now and then you will see that UIDL is missing from the list or there is an error getting the response to the "CAPA" command.

So let me know what your see.
Thanks!

Comment 8

[gene smith]

Attachment: fix-uidl-problem.diff

Looking some more, maybe it is the same problem as was fixed in the c++ version. Exchange doesn't support RESP-CODE capability so can't really tell when an error is "temporary" with response code [SYS/TEMP] but the possibly intermittent failure on UIDL commands seems like a "temporary" error, so the attached diff may may work around the issue and does essentially the same thing as the patch to the defunct c++ code.
Anyhow, still need info that I asked about in my last comment.

Comment 9

[Isaac Ribeiro]

I got the following code when requesting to receive new messages:

Connecting to pop://outlook.office365.com:995
Connected
S: +OK The Microsoft Exchange POP3 service is ready. [QwBQADYAUAAyADgANABDAEEAMAAxADAAMgAuAEIAUgBBAFAAMgA4ADQALgBQAFIATwBEAC4ATwBVAFQATABPAE8ASwAuAEMATwBNAA==]
C: CAPA
S: +OK

TOP
UIDL
SASL PLAIN XOAUTH2
USER
.

Possible auth methods: XOAUTH2
Current auth method: XOAUTH2
C: AUTH XOAUTH2
S: + 

XHRPOST https://login.microsoftonline.com/common/oauth2/v2.0/token [HTTP/2 200 OK 596ms]

C: Logging suppressed (it probably contained auth information)
S: +OK User successfully authenticated.

C: STAT

TB found no new messages, even though there are new messages on the server.

Comment 10

[gene smith]

Not sure if you just cut it off, but is there stuff past the STAT command? When I sent a new message to the outlook POP3 account and then click "Get Message", I also see this after at STAT command. Otherwise, what you show looks OK and Outlook is reporting support for UIDL just like I also see at my location.

C: STAT
S: +OK 72 3862358
Folder lock acquired uri=mailbox://[e-mail]/Inbox.
C: LIST
S: +OK 72 3862358
1 11862
2 11974
3 28599
4 13005
5 13134
:
.
C: UIDL
S: +OK
1 94
2 397
3 790
4 909
5 988
:
C: RETR 72
S: +OK
S: Return-Path: <[e-mail]>
Received: from charter.net ([47.43.20.35])
          by mtain012.msg.chrl.nc.charter.net
          (InterMail vM.9.01.00.036 201-2473-137-122-162) with ESMTP
          id <[e-mail]>
          for <[e-mail]>; Wed, 6 Sep 2023 03:45:18 +0000
:
:
<Rest of new message comes in>

Comment 11

[Isaac Ribeiro]

Attachment: Main Account Debug (Part 1)

Comment 12

[Isaac Ribeiro]

Attachment: Main Account Debug (Part 2)

Comment 13

[Isaac Ribeiro]

(In reply to gene smith from comment #10)

Not sure if you just cut it off, but is there stuff past the STAT command? When I sent a new message to the outlook POP3 account and then click "Get Message", I also see this after at STAT command. Otherwise, what you show looks OK and Outlook is reporting support for UIDL just like I also see at my location.

C: STAT
S: +OK 72 3862358
Folder lock acquired uri=mailbox://[e-mail]/Inbox.
C: LIST
S: +OK 72 3862358
1 11862
2 11974
3 28599
4 13005
5 13134
:
.
C: UIDL
S: +OK
1 94
2 397
3 790
4 909
5 988
:
C: RETR 72
S: +OK
S: Return-Path: <[e-mail]>
Received: from charter.net ([47.43.20.35])
          by mtain012.msg.chrl.nc.charter.net
          (InterMail vM.9.01.00.036 201-2473-137-122-162) with ESMTP
          id <[e-mail]>
          for <[e-mail]>; Wed, 6 Sep 2023 03:45:18 +0000
:
:
<Rest of new message comes in>

I view this additional information regarding new messages found in other accounts. My main account does not display this.

I have attached 2 images with my full main account information displayed after requesting to receive new messages.

On the other hand, how do I apply the correction you proposed in the diff? Can I do this to test?

Comment 14

[gene smith]

It looks to me like outlook.com is just dropping the connection. It does appear to be some kind of "security" error that exchange server doesn't like. However, it seems to accept your OAuth2 token (the password) OK so don't know why it then rejects the STAT command.

You might run the check for new mail again and see if this is consistent and if it happens every time you request new mail.
You might also, before attaching the log, set it so only DEBUG items are shown. That will then only show the POP3 related log items and not the other items that that don't seem to be relevant. (It will then probably fit on one screen.) On the next log you attach, please also include timestamps since I would be curious to know how much time occurs between TB sending the STAT command and the error response from the server. (Timestamps can be enabled under "Console Settings" icon.)

When you see the failure to respond to STAT, does TB pop up any other error messages?

If you erase the log, then do "Get Messages" only for your main account and look at the log, and do this, say, 10 times, how many time does it work completely without producing an error? I need this info to know how intermittent this really is.

On the other hand, how do I apply the correction you proposed in the diff? Can I do this to test?

Based on the info you have supplied, it doesn't appear that the patch, as is, would do any good. You are showing me failure to respond to STAT and my patch/diff only involves response to UIDL which occurs only after STAT and LIST.

I view this additional information regarding new messages found in other accounts. My main account does not display this.

You may have said but are these "other account" also hotmail/exchange/outlook" or something else. Are they now using OAuth2 or normal passwords?

I didn't want to set up a new Outlook.com account so TB wouldn't re-download 100000+ messages from my main account.

Do you suppose you may be running into a limit on the number of messages allowed in a POP3 mailbox? I doubt it, but maybe a possibility.

Comment 15

[Isaac Ribeiro]

(In reply to gene smith from comment #14)

I'm now adding the log for one of the accounts that started experiencing this problem intermittently this month. Soon, I will follow your guidance to receive messages on the main account repeatedly.

When you see the failure to respond to STAT, does TB pop up any other error messages?
In the example in comment #13, TB did not display an error message.
You may have said but are these "other account" also hotmail/exchange/outlook" or something else. Are they now using OAuth2 or normal passwords?
These other accounts are also hotmail/exchange/outlook and they are using OAuth2.
Do you suppose you may be running into a limit on the number of messages allowed in a POP3 mailbox? I doubt it, but maybe a possibility.
I believe I may be running into a limit on the number of messages, because messages have always accumulated in the main account due to errors in POP3 since I switched to OAuth2. If that's the case, I believe this limit didn't exist when accounts used a normal password.

This last time, the server accumulated 4900 messages over a period of 4 months. By the way, TB only managed to download around 4700 messages before displaying an error at the time of comment #4.

Comment 16

[Isaac Ribeiro]

In comment #15, I answered your questions, but I formatted it wrong.

Comment 17

[Isaac Ribeiro]

Attachment: Secondary Account Log (Part 1)

Comment 18

[Isaac Ribeiro]

Attachment: Secondary Account Log (Part 2)

Comment 19

[Isaac Ribeiro]

Attachment: Main Account Log

The log was always the same in 6 repetitions.

Comment 20

[gene smith]

Isaac, I see that you can just right-click on the log and save all the log to a file. So probably better just to do that rather than attaching screen shots. Just want to mention this before you attach more.
:
:
That's OK, your new message came in while writing the above :).

(In reply to Isaac Ribeiro from comment #19)

Created attachment 9376080 [details]
Main Account Log

The log was always the same in 6 repetitions.

That's interesting. On 6 tries it always fails on the STAT and it's a "security error". Do you get the same results if you switch back to "PLAIN" for password?

On your other accounts (comment 18 and comment 19) it fails (server drops connection?) during the middle of IUDL and don't know why. Also, looks like LIST response gets cut off. Are there really about 34000 message in your secondary account? Does your main account really have 100000+ messages? If so the LIST and UIDL responses are going to be pretty long.

Comment 21

[gene smith]

At the outlook mail site there is a page that show your storage usage. You may have already checked this but since I'm not sure how many messages and how big they are in you Inbox, it might be good to check your usage against the quota.
For me, I'm seeing it here: https://outlook.live.com/mail/0/options/general/storage
For my outlook account (used only for TB testing) it only shows 1% used and < 0.1 GB / 5 GB. Not sure if the max is 5 GB since down below it says I have up 15 GB for email ??

Comment 22

[Isaac Ribeiro]

(In reply to gene smith from comment #21)

At the outlook mail site there is a page that show your storage usage. You may have already checked this but since I'm not sure how many messages and how big they are in you Inbox, it might be good to check your usage against the quota.
For me, I'm seeing it here: https://outlook.live.com/mail/0/options/general/storage
For my outlook account (used only for TB testing) it only shows 1% used and < 0.1 GB / 5 GB. Not sure if the max is 5 GB since down below it says I have up 15 GB for email ??

My account has a capacity of 50 GB and the space used is 37.2 GB.

Comment 23

[Isaac Ribeiro]

(In reply to gene smith from comment #20)

I have the same results on my main account with the normal password, according to the attached log. The secondary account is working again.

Yes, these accounts actually have these thousands of messages.

Furthermore, I can normally download messages in other email managers on my desktop and smartphone, but I would like to continue using TB.

Comment 24

[Isaac Ribeiro]

Attachment: Main Account Log

Comment 25

[Isaac Ribeiro]

Attachment: Main Account Log (success and problem)

The main account just downloaded new messages after about five automatic searches with no response from the server using the normal password. As the first log had clear text messages, I attached a log that I obtained shortly afterwards recording successful connections and connections with the problem again.

Comment 26

[gene smith]

Ok, I may see what the problem is. As we have seen, in the log for your main account it fails waiting for the STAT response. The wait is about 100 seconds in each case. There is parameter called mailnews.tcptimeout that is, by default, 100 seconds. You could set it to something much larger, maybe 1000, and see if that fixes the problem.
With so many messages on the server, my guess is that it takes the server longer to sort through all the data and produce a response than the default 100 seconds. The same problem (timeout) may also occur for the other commands, LIST and UIDL. So setting mailnews.tcptimeout bigger (maybe even 2000) may fix all the problems on all account (I hope!).

If this fixes the problem, I would be curious to see the log again and see how long the STAT command is actually taking. Then we could maybe changed the default of 100 to something larger for POP3.

Comment 27

[Isaac Ribeiro]

Attachment: Main Account Log

Increasing the timeout to 1000 solved part of the problem. TB continues to display the UIDL or XTND XLST support error message intermittently.

Comment 28

[gene smith]

Well, it looks like the STAT response is taking about 112 seconds. So I would say a tcptimeout of 200 would take care of that.
However, the error on UIDL is another issue. In that case, it appears that the server sends the complete UIDL response (for the 200K+ messages). But TB is taking too long to process it (over a minute) and then the server times out the connection and disconnects before TB finishes its processing and sends QUIT. So in this case, it looks like the server needs a longer timeout waiting for QUIT to be received but there is no way for a user to change that at the Exchange server.

But in your attachment at comment 25, the "success" example TB only took 18 seconds to process the UIDL response from your main account. So not sure what is going on.

I've tried to add messages to my outlook POP3 account to simulate your setup but it's a slow process and so far I only have about 5k message there, and, of course, it works fine with 5k messages. It would take a long time to reach your 200k number (and I don't have that many unique messages to copy there).

TB continues to display the UIDL or XTND XLST support error message intermittently.

Well, I can go ahead and make a "try" build that you can test with my patch. It should cause the "intermittent" error to be ignored.
The "try" build can be applied to the current "daily" version and it only has English localization. I'll let you know when it is ready and provide a link for downloading a win64 installer.

Comment 29

[Isaac Ribeiro]

Well, I can go ahead and make a "try" build that you can test with my patch. It should cause the "intermittent" error to be ignored.
The "try" build can be applied to the current "daily" version and it only has English localization. I'll let you know when it is ready and provide a link for downloading a win64 installer.

I can test your patch.

Comment 30

[gene smith]

Here's the installer link:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ATAGphs5TLaow2OynOfmDA/runs/0/artifacts/public/build/install/sea/target.installer.exe

FYI, here's the link to where I did the try build:
https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=888f776420ca6967caef7ad4dd7fa1a7a2f3573f

Comment 31

[gene smith]

Here's how I think the "try" build should work.
When you click "Get Messages" and there is a UIDL error, you will see the error

Temporary error from outlook.office365.com while retrieving new messages.
The operation will be retried at the next check for new messages.

When new messages are checked using the timer (I think you have set it to 62 minutes) you probably won't see any indication of a failure. You should not see the error you were seeing before. It will only occur if UIDL is actually not supported by the server capabilities and outlook definitely supports UIDL.

Comment 32

[gene smith]

Hi Isaac,
Any results with the "try" build? I still haven't been able to duplicate the problem but I still don't have anywhere near the almost 300K messages you have in your Inbox.
Looking at the log for POP3, I do have enough messages (about 14K) that I see about a 5 second delay on the response to STAT. So setting the tcptimeout to at least 200 (seconds) is definitely needed with your 300K messages.

There is also a "keep alive" setting for tcp/ip connection in the Config Editor. If TB takes a long time to process the UIDL data before responding back to Outlook (as you show in comment 27), this will cause TB to send "keep-alive" packets to outlook to let it know the computer has at least not crashed and to keep waiting. I don't know that this will help but you might try setting these parameters:

network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

This will cause the keepalive to be sent after 50 seconds (default 100 seconds). Since outlook seems to be willing to wait about a minute before reporting a timeout error, this might tell it that TB is still there and to keep waiting. (But, I'm not sure this will help. I'm running with these parameters now and it doesn't seem to cause any problems.)
If this doesn't help or doesn't have an effect, just go ahead and set these back to default values.

Comment 33

[Isaac Ribeiro]

Hi gene,

I tried to install "target.installer.exe", but the computer processed without anything happening. I waited some time and ended up giving up.

I installed Thunderbird 123.0b1 (64-bit) and I reverted the authentication method to OAuth2, but the problem remains partially resolved. Fortunately, TB downloads new messages when I least expect them. This hadn't happened in months.

I have now changed the network.tcp.keepalive.idle_time from 600 (default) to 50 and I have changed the network.tcp.keepalive.retry_interval from 1 (default) to 5, as per your suggestions. This also makes sense, but attempts to download new messages failed.

Comment 34

[Isaac Ribeiro]

Attachment: Main Account Log 1

Current auth method: XOAUTH2
mailnews.tcptimeout = 1000 (I forgot to lower this value.)
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

Comment 35

[Isaac Ribeiro]

Attachment: Main Account Log 2

Current auth method: XOAUTH2
mailnews.tcptimeout = 1000 (I forgot to lower this value.)
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

Comment 36

[Isaac Ribeiro]

Attachment: Main Account Log 3

Current auth method: XOAUTH2
mailnews.tcptimeout = 1000 (I forgot to lower this value.)
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

Comment 37

[Isaac Ribeiro]

Attachment: Main Account Log 4 (success)

This search for new messages occurred automatically.

Current auth method: XOAUTH2
mailnews.tcptimeout = 1000 (I forgot to lower this value.)
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

Comment 38

[gene smith]

Isaac,
Is it correct to say that you typically see "success" 1 time out of 4. If that is the case, then ignoring the error like I proposed in the patch is probably the wrong thing to do.

Don't know why the installer didn't do anything. I'll have to boot into windows and see what is wrong with it. Currently I'm running linux.

mailnews.tcptimeout = 1000 (I forgot to lower this value.)

That's OK. Being very large won't affect the results for what you are doing. But still recommend setting back to 200 or maybe even 150 since the time to respond to STAT is just a little more than 100.

Anyhow, if it's really only working about 1 out of 4 times, then there must be something wrong in TB that's making it not respond within 60 seconds. When it works OK (your last attachment) it only took about 11 seconds to respond after the UIDL was sent.

Would you look at some files in your profile and tell me how big they are, specifically:
(I'm guessing the path name in windows, so maybe you know it better),
c:\users\<your name>\App Data\Roaming\thunderbird\profiles\<profile name>\Mail\outlook.office365.com
files: popstate.dat
Inbox
Inbox.msf
I suspect that with almost 300k messages these are pretty big.
Thanks again and sorry for all the problems.

Comment 39

[Isaac Ribeiro]

Hi gene,

Considering that I separate messages into folders and subfolders, the Inbox is 1.3 GB and Inbox.msf is 8.1 MB. The main account's popstate.dat is 9.7 MB.

I thank you for your help.

Comment 40

[Isaac Ribeiro]

Attachment: Main Account Log 5 (success over time)

This search for new messages occurred automatically. The TB is working well over time (in this case, 62 minutes) since the comment #37.

Current Version: 123.0b1 (64 bits)
Current auth method: XOAUTH2
mailnews.tcptimeout = 200
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

Comment 41

[Isaac Ribeiro]

Attachment: Main Account Log 6 (success with "Get Mail")

This search for new messages occurred manually. TB had no problem the two times I clicked Get Mail today.

Current Version: 123.0b1 (64 bits)
Current auth method: XOAUTH2
mailnews.tcptimeout = 200
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

Comment 42

[gene smith]

(In reply to Isaac Ribeiro from comment #41)

Created attachment 9376666 [details]
Main Account Log 6 (success with "Get Mail")

This search for new messages occurred manually. TB had no problem the two times I clicked Get Mail today.

Current Version: 123.0b1 (64 bits)
Current auth method: XOAUTH2
mailnews.tcptimeout = 200
network.tcp.keepalive.idle_time = 50
network.tcp.keepalive.retry_interval = 5

This only shows retrieving (RETR) two messages but only the first line of the received email is show. Am I correct that you edited the log file to remove the full email? (Comment 40 shows about 7 RETR commands with the full emails shown so I assume you didn't edit that log file.)

Both comment 40 and comment 42 show the UIDL response taking less than 12 seconds so I doubt that the keepalive parameter setting is really helping, but you can leave it as you have it if you want to. Of course, the tcptimeout at >=125, as you have it, is definitely needed.

Thanks for info on file sizes. They sound reasonable considering how many messages you have on the server.

From comment 33:

I tried to install "target.installer.exe", but the computer processed without anything happening. I waited some time and ended up giving up.

Not sure what the problem is. I downloaded the installer file to a win10 system and it brought up the prompts to install "Daily" as I would expect. (I did first received prompts from anti-virus software to allow the install, but I didn't actually do the install.) Anyhow, lets just stay with the beta you are using for now.

Comment 43

[Isaac Ribeiro]

Am I correct that you edited the log file to remove the full email?

I only edited one of these two files.

Not sure what the problem is. I downloaded the installer file to a win10 system and it brought up the prompts to install "Daily" as I would expect.

Windows wanted to prevent the installation. I executed it anyway. The antivirus judged that the file did not contain malware.

Comment 44

[gene smith]

From comment 40:

This search for new messages occurred automatically. The TB is working well over time (in this case, 62 minutes) since the comment #37.

From comment 41:

This search for new messages occurred manually. TB had no problem the two times I clicked Get Mail today.

I'm not certain I understand your current status on this bug.
Is the current beta you have now working OK for you with tcptimeout set to 200?
Are you still sometimes seeing the UIDL error pop up with the beta and tcptimeout at 200?

From comment 43:

Windows wanted to prevent the installation. I executed it anyway. The antivirus judged that the file did not contain malware.

Or does this mean you have now successfully installed the "try" build? If so, is it working any better than the beta? Are you also running it with tcptimeout at 200?

I now have about 33k messages in my outlook pop3 account and don't see the problem. But if I add some extra code that just outputs text to stdout and wastes some time while processing the UIDL responses, I do see the same error that you originally reported. I'm trying to understand why this happens.

Comment 45

[Isaac Ribeiro]

I was unable to install the "try" build, but the current beta version worked fine with tcptimeout set to 200 until I restarted TB this morning. After reboot, TB did not download new messages from the main account. Additionally, it displayed UIDL or XTND XLST error messages both times I clicked "Get Mail".

Comment 46

[gene smith]

I downloaded this link (same as above):
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ATAGphs5TLaow2OynOfmDA/runs/0/artifacts/public/build/install/sea/target.installer.exe
on win11 (on dual-boot laptop) and it installed OK and runs OK. So it seem OK on win10 and 11, at least for me.

Anyhow, from what I can tell, if you have new messages in your inbox and and start TB, with try build you will probably still get the UIDL/XTND XLST message if there are problems. If there are initially no new message in Inbox at startup, it might be OK after that. But if there are new messages and your click "get mail" you might still see the prompt. So the try build is not really a good fix.

The tcptimeout only fixes the response to STAT, which occurs first. The main problem is in TB's processing of the response to UIDL which appears to be taking way too much time and causing the server to stop waiting and then drop the connection (always after about a minute). If TB is really just taking a long time to send something else, I'm thinking that it needs to send the server a NOOP. This might act as an application layer keepalive which should be more effective than the tcp level keepalive that you have set. Also, not sure the tcp level keepalive is actually working. I'm not seeing it with wireshark.

Comment 47

[gene smith]

Hi Isaac,
Not sure from your previous comment if it's consistently working acceptably or not. I've worked on it some more and have come up with another possible fix.
Here's a link to my new patch applied to 123.0b2 (beta) version:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Gho5I-kAS0676FKShAgudA/runs/0/artifacts/public/build/install/sea/target.installer.exe
Hopefully you can successfully install this and see how it does.
It keeps the changes from my original patch (for now) but adds sending a POP3 "NOOP" as a application level keepalive. So in the TB console you need to enable the "LOG" tab as well as the "DEBUG" tab and it will also show, if they are sent, the NOOPs.
You need to keep your setting for tcptimeout at 200 (for the STAT response) and you should probably also set
network.tcp.keepalive.idle_time
network.tcp.keepalive.retry_interval
back to their default values using Config Editor. These tcp level keepalives seem to have no effect on the POP3 connections.
Thanks!

P/S: Here's the link to where I did the new try build: https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=2c70bef984383f8f46be66bcc5c6de1e972558d8
As I mentioned above, this is based on the latest 123 beta (not daily) but it is still English localized.
Also, not sure what the problem was before trying to install the try build. When I installed it, there is a prompt that has a "More Info" link. I had to click that before it gave a prompt to allow me to do the install. I see this on both win 10 and 11.

Comment 48

[Isaac Ribeiro]

Attachment: Main Account Log 7 (success)

This is the first log from the main account after TB initialization. I believe the problem is resolved with your solution. Thanks!

Current Version: 123.0b2 (64 bits)
Current auth method: XOAUTH2
mailnews.tcptimeout = 200
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 49

[Isaac Ribeiro]

Attachment: Main Account Log 8 (success)

Faster connection over time and with more messages.

Comment 50

[gene smith]

Re: comment 48:
Thanks for testing and at least it finishes getting the new messages. However, the time it takes seems extremely long.
The STAT response is taking 2m 27s (147 seconds). That's a bit more than we saw before but I guess it's OK, and with your tcptimeout at 200 it's not causing a problem.
The outlook server returns the complete UID list in about 15s so that's not adding a lot to the time. However the time for TB to process the UIDL before the first RETR is sent is about 15m 30s. Now that the NOOPs are keeping the server happy while TB cranks through the UIDs, at least there is no -ERR and all the new messages are retrieved. Maybe the sending of the NOOPs every 10s is too quick and time between them should be increased to maybe 20s or 30s (the outlook server is willing to wait 60 seconds before giving up on TB and reporting the -ERR response so a longer NOOP send interval should be OK).

Re: comment 49:
I'm trying to determine why there is so much variation. Comment 49 is fairly quick (one NOOP), comment 48 very slow (lots of NOOPs).
It's not the server but something in TB that is causing the slow/fast new message processing. I'm thinking the problem is related to this:
https://searchfox.org/comm-central/rev/73c90e7da573c044a560ab3905979493d9caf26a/mailnews/base/src/LineReader.jsm#58-60

Comment 51

[Magnus Melin [:mkmelin]]

That could be it. Possibly that should back off less agressively (like 1000 instead of 100) and maybe just use await new Promise(resolve => setTimeout(resolve));

Comment 52

[Isaac Ribeiro]

Apparently, the TB takes a long time to process the UIDL before the first RETR is sent only until it gets the first successful connection.

Comment 53

[gene smith]

Attachment: fix-uidl-problem--test-code-simulate-more-lines.diff

Since I don't have anywhere near as many messages in Outlook Inbox as reporter (38k vs. 300k), I simulated the extra "line" processing by doing the call to "lineCallback(line)" in LineReader.jsm 10 times in a loop (see attachment). With just this change I don't see a server timeout when receiving new POP3 messages (I typicially test with 10 new messages delivered to Inbox). However, if I scroll the message list continuously, I do see the problem. So apparently when reporter Isaac sees the timeout (or there is a 15m delay on getting new messages using the "try" build), there is other background activity happening in TB preventing the UIDL "lines" from being processed.

Since currently the call to spinEventLoopUntilEmpty() allows other activities to occur on every 100 lines, it is giving too much priority to those activities (e.g., allow message list to scroll). When I change it as Magnus suggests in comment 51, I still see 2 or 3 NOOPs occur (on 10s intervals) while scrolling the message list, but this allows the POP3 activities to finish without a timeout.

So I'll go ahead and make the change recommended by Magnus: On every 1000th line, do await new Promise(resolve => setTimeout(resolve));. This also requires that read() in LineReader.jsm (used only by POP3 and NNTP) be defined async.
And I'll keep the NOOP keepalive that I've added so if it still takes too long to process the UIDL lines, the outlook server won't time us out at 60 seconds.
I may also include the NOOP in the LIST processing since its response is as long as UIDL lines but the processing is not as involved. In my testing I've seen -ERR reported by server after LIST processing a few random times so should probably allow NOOP to occur there too.

Reporter Isaac also had to increase the tcptimeout parameter (default 100s) in Config Editor to 200s, due to the STAT response consistently coming back delayed from outlook. Not sure if that is something that should be changed in the POP3 code. Maybe use twice the default value?

Comment 54

[gene smith]

Isaac, Here a new version to try. Again, the patch is applied on top of the latest beta.
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KVZ9c3bZQaSXYfBvhRL-dA/runs/0/artifacts/public/build/install/sea/target.installer.exe

This implements Magnus' suggestion from comment 51 except, for me, 5000 seemed to work better (instead of the recommended 1000).
I also included the possibility of sending NOOP at any point during the POP3 processing when TB doesn't send something for 10 seconds, not just during UIDL processing.

For me, I only see NOOP sent if I am continuously scrolling the message list with the mouse wheel. If I "grab" the scroll bar and move the list up and down continuously, it completely blocks the POP3 process and nothing is sent (including NOOPs) or received. So if do this for a minute, I always see the -ERR response.

Re: comment 52:

Apparently, the TB takes a long time to process the UIDL before the first RETR is sent only until it gets the first successful connection.

I'm not sure I know what you mean. Maybe you are saying that once the UIDL list is processed that any new messages come right in with no delay. However, if I do the message list scrolling (with mouse wheel or scroll bar) I can also cause the incoming messages to not come in and also timeout with -ERR response after 1 minute (since outlook drops the connection if idle for 1 minute).

Here's the complete link to the try build: https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=d3bd66c9a13225021087d6793533fad7996fb491

Comment 55

[Isaac Ribeiro]

Attachment: Main Account Log 9 (success after about 13 minutes)

Log recorded after the first TB boot with the new build.

Even considering the complete log, TB does not display background activity records in the log while waiting for the first RETR.

I meant that apparently this long wait for the first RETR only happens once every TB reboot.

Comment 56

[gene smith]

Ok, I see what you mean, almost. By "TB boot" do you mean TB starting up or do you mean the computer is rebooted and then TB is started? (I suspect you mean just TB is started but not sure.)

So are you saying that after initial TB start up/boot and the slow automatic check for new messages, that if you check for new messages again (click the "get messages" button) it is always faster after that?

Even considering the complete log, TB does not display background activity records in the log while waiting for the first RETR.

That's interesting too. So something is also blocking the log in the console from appearing. Do you only see this at first TB startup?

In comment 0 you mentioned that you have 3 POP3 accounts all going to outlook/hotmail. Do you have any other imap mail, news or RSS accounts on your system? If so, maybe they are slowing down the processing of you main POP3 account.

You might try disabling "check for mail at startup" (under server settings) on all accounts except for your main POP3 account with ~300k messages. That way, at TB startup, all attention will be directed to your main POP3 account. Then restart and see if the main account is still slow on the initial message fetch.

Comment 57

[Isaac Ribeiro]

Ok, I see what you mean, almost. By "TB boot" do you mean TB starting up or do you mean the computer is rebooted and then TB is started?

I end the TB process manually and start it again.

So are you saying that after initial TB start up/boot and the slow automatic check for new messages, that if you check for new messages again (click the "get messages" button) it is always faster after that?

Whether TB automatically checks messages or I click on "Get New Messages", the application will take a long time to receive messages just once. If I no longer restart the TB manually after receiving messages once, it will work perfectly, receiving messages quickly. TB only needs to send many NOOPs once per session.

That's interesting too. So something is also blocking the log in the console from appearing. Do you only see this at first TB startup?

If I haven't misunderstood, you said that background activities increase the time until the first RETR. However, I don't see constant activity in the log while waiting for the first RETR.

I believe the log is normal. I see message checks from other accounts that start and complete quickly, including Hotmail/Outlook.

In comment 0 you mentioned that you have 3 POP3 accounts all going to outlook/hotmail. Do you have any other imap mail, news or RSS accounts on your system? If so, maybe they are slowing down the processing of you main POP3 account.

I have 18 Hotmail/Outlook POP3 accounts and I have accounts from other providers as well. However, if I suspend checking messages from all these accounts, the RETR for the main account will take a long time to appear once per TB session. The issue currently only affects the primary account. I don't have news or RSS accounts.

You might try disabling "check for mail at startup" (under server settings) on all accounts except for your main POP3 account with ~300k messages. That way, at TB startup, all attention will be directed to your main POP3 account. Then restart and see if the main account is still slow on the initial message fetch.

I've done this in previous versions of TB without success. I will do it with your build.

Comment 58

[gene smith]

18 POP3 accounts! Didn't expect that. And all to outlook!
Do all 18 check for new mail at startup?
Also, when doing the test you might also disable the "check for new mail every X minutes" setting so nothing is ever happening except for your main POP3 account which still has "check for new mail at startup" and "check for new mail every 62 minutes" enabled.
Then restart and see what happens with only your main POP3 account active.
Thanks for the info! I should have ask this stuff earlier!

Comment 59

[gene smith]

... and I have accounts from other providers as well

Ok, actually more than 18. All POP3, I assume?

I've done this in previous versions of TB without success. I will do it with your build.

I doubt that my build will make a difference. But it's worth a try if you disable "check msgs at startup" and "check msgs every X minutes" on the accounts and see what happens again. Be sure to restart TB after making the changes.

You should also check it again with the official release or official beta, which ever you want to use (or on both).

Comment 60

[gene smith]

I have one more idea for a test. Turn off "check for msgs at startup" and "check new messages every X minutes" on ALL accounts, including your main account. Then restart TB.
Then right-click the "Get Messages" button (cloud icon) and click your main account from the list. Does that go fast or slow?

Then right-click cloud icon again and select "Get all new messages" (at the top of the list). This will check for new mail on all accounts. Does this go fast or slow?

Comment 61

[gene smith]

Hi Isaac,
If you do the tests that I have suggested, it might be better to reset the logging parameter mailnews.pop3.loglevel back to Warn (the default setting) since we are mostly just checking for just fast or slow. If you have 18 pop3 account and others, the logging may slow down the tests, so maybe better to disable the logging. Probably better to also restart TB after changing this, just to be sure.

From comment 0:

When this error affected a first account, I just changed the POP3 authentication method from "Normal Password" to "OAuth2" after upgrading to Thunderbird 115.1.0 in August 2023. Other accounts using the same server continued to work perfectly.

Am I correct to assume that before you went to 115.1.0, you were using a previous 102.x.x version? Was the 102.x.x version working OK with your 18 POP3 accounts with about the same number of messages?
Also, you may not know but do you know how the parameter mailnews.pop3.jsmodule was set in 102.x.x? That parameter does not exist in 115 and later since pop3 only uses javascript (js) starting with 115.

Also, I think you have verified that OAuth2 really had no effect. I don't see how it could since it is just a longer password to send and the delays we see in your main account occur after the password is sent (mostly during UIDL processing).

Comment 62

[Isaac Ribeiro]

Attachment: Main Account Log 10

I turned off "Check for new messages at startup" and "Check for new messages every X minutes" on all accounts. Then, I clicked on "Get Messages" only on the main account. The total time to receive new messages has reduced absurdly.

Current Version: 123.0b2 (64-bit) gds build 2
Current authentication method: XOAUTH2
mailnews.tcptimeout = 200
mailnews.pop3.loglevel = default
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 63

[Isaac Ribeiro]

Do all 18 check for new mail at startup?

Only 4 accounts checked for new email on startup. Additionally, the 18 accounts checked for new emails every 62, 248, 186, 124, 0905, 843, 967, 302, 781, 1021, 1081, 541, 489, 427, 365, 727, 603 and 665 minutes.

Was the 102.x.x version working OK with your 18 POP3 accounts with about the same number of messages?

Until TB 102.x.x, all accounts (POP3 and normal password) checked email on startup and checked for new messages every 10 minutes without any problems.

Also, you may not know but do you know how the parameter mailnews.pop3.jsmodule was set in 102.x.x?

I Only have a backup of the prefs of version 91.9.1 and I didn't find mailnews.pop3.jsmodule in it.

Ok, actually more than 18. All POP3, I assume?

Yes, all POP3.

Comment 64

[Isaac Ribeiro]

Attachment: Error Console with All Accounts

I turned off "Check for new messages at startup" and "Check for new messages every X minutes" on all accounts. Then, I clicked on "Get All New Messages". The total time to receive new messages increased again.

Current Version: 123.0b2 (64-bit) gds build 2
Current authentication method: XOAUTH2
mailnews.tcptimeout = 200
mailnews.pop3.loglevel = default
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 65

[gene smith]

Reply to comment 62:
I do see one "NOOP keepalive" in the log in comment 62. So at some point it had to go 10s without TB sending anything. However, it kind of looks like you didn't have "DEBUG" enabled on the "console", only "LOG" was clicked. Either that or you had set mailnews.pop3.loglevel back to warn, which is what I requested.

Anyhow, it would be good to know if it is consistently "reduced absurdly" when you just check email for main account.

FYI, I have done a few experiments to try to determine what is going on.
I installed the last version of 102 (the release previous to 115), specifically 102.15.1. I can't make this slow down POP3 handling even if I scroll messages as fast as possible or grab the message list scroll mark and move it up and down fast. With 102.x.x you can select the old c++ POP3 implementation or javascript (with mailnews.pop3.jsmodule). Both work perfectly when I scroll or drag the message list pane and all new message come in with no timeouts or slowdowns.

I download and installed the latest beta, 123.0b4. When I drag the message list pane with scroll bar quickly up and down, it completely blocked the UIDL processing and the outlook server, after 1m, reported the -ERR. Of course, this official version from TB archive site does not have my "NOOP" feature in the "try" build.

So since POP3 responds perfectly with 102 (with c++ or JS implementation) and it has problems (as described in this bug report) with 115, daily and 123b, it looks to me like this is an issue with the "supernova" implementation having highest priority and not allowing POP3 code to run. I think POP3 always runs on the UI/main thread, but that has always been the case, including 102. But now the main thread is busy handling UI supernova stuff and doesn't allow POP3 enough cycles to run as quickly as it should.

In your (reporter Isaac's) case, there are 18 POP tasks all trying to run at startup to check for new messages. This also worked fine with 102 but is broken with 115 and later. So, since the current POP JS code is mostly the same as 102, the only thing that could cause this is the overall "supernova" implementation. Even giving maximum priority to POP3 by removing https://searchfox.org/comm-central/rev/66a417335c695d7b145980ea23219bf57f451267/mailnews/base/src/LineReader.jsm#58-61 or adjusting it doesn't help.

Comment 66

[gene smith]

Reply to comment 63 and comment 64:
Ok, if you tell TB to check ALL the POP3 accounts together, you see the time to complete go up to 15 minutes. That's what I would expect.

I only see "problems" with POP3 when I very quickly scroll or move with scroll bar the message list. Of course, most user don't do this a lot, I assume. So it occurred to me, do you have any addons installed that may be affecting your system? I did see something about addons/extensions in the attached logs. If you do have addons, try the tests again with them disabled. You can go to "Help | Troubleshooting mode" to temporarily disable addons after a restart.

Thanks for the information.

Comment 67

[Isaac Ribeiro]

Attachment: Error Console with All Accounts 2

I made the Troubleshooting mode modifications permanent and clicked "Get All New Messages" a few times. Message reception time appears normal. The only installed extension was already disabled in the beta version. I don't know what could have influenced it.

Current Version: 123.0b2 (64-bit) gds build 2
Current authentication method: XOAUTH2
mailnews.tcptimeout = 200
mailnews.pop3.loglevel = default
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 68

[gene smith]

Ok, that may take the "blame" off of the POP3 code and supernova changes if it fixes it with the unmodified beta (without "gds build 2") or the latest 115 release.
I should have suggested disabling addons to begin with. But I'm not an addon user at all so it didn't occur to me until I saw some of your recent logs.

If it keeps working OK without addons, I'd be curious to see the log again with mailnews.pop3.loglevel set back to "Debug" again and see if the 200 second mailnews.tcptimeout is still needed. Maybe it could also be returned to default (100 seconds).

Comment 69

[Isaac Ribeiro]

Attachment: Error Console with All Accounts (debug)

Current Version: 123.0b2 (64-bit) gds build 2
Current authentication method: XOAUTH2
mailnews.tcptimeout = 200
mailnews.pop3.loglevel = default
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 70

[Isaac Ribeiro]

Ok, that may take the "blame" off of the POP3 code and supernova changes if it fixes it with the unmodified beta (without "gds build 2") or the latest 115 release.

TB 123.0b4 keeps showing UIDL error message. I can no longer open my profile in version 115.

Comment 71

[gene smith]

Note: I wrote this before I saw your comment 70. I'll respond to comment 70 next.

Looks like STAT for you main account is still taking about 2m to come back from outlook; from line 8929 of your comment 69 attachment:

Pop3Client.jsm:348:18
17:00:37.929 mailnews.pop3.25: C: STAT Pop3Client.jsm:508:20
17:02:36.845 mailnews.pop3.25: S: +OK 295317 37587024710

The others only take a second or so, but I didn't check them all. So you need to keep the mailnews.tcptimeout at 200.

I see that you are connecting to 23 pop3 servers so your are giving the pop code a good workout!
The total time to complete the "check for new mail" process is 3m 20s. Since 2m of that is waiting for outlook to return the STAT response, I would say it looks pretty good!

17:03:22.131 mailnews.pop3.32: Connection closed. Pop3Client.jsm:395:18  (last line: 13581)
17:00:01.787 mailnews.pop3.0: Connecting to pop://pop.mail.yahoo.com:995 Pop3Client.jsm:141:18 (first pop3 line: 6)

I don't see any NOOPs sent so probably my changes are not making a big difference. If you get the same results with the official release or beta, I would say that no changes are really needed. If the release or beta do OK and take about the same time, you probably don't need to attach the log. Of course, you will need to keep your setting for tcptimeout at 200.

Comment 72

[gene smith]

First, you can run an older version after you have run a newer version only if you start TB with the --allow-downgrade option. I always run TB from command line on linux like this:

thunderbird --allow-downgrade

So you need to right-click on the icon to start 115 and select properties. Then somewhere in there it shows the command to start TB, maybe: "c:\Program Files\<path-to-tb>\thunderbird.exe". You just need to add --allow-downgrade after the quoted command and save it. I'm not on windows now so I don't know the exact names for the shortcut menus I'm referring to.

Anyhow, if it's really working consistently with the modified beta and not the official beta, then I guess some of the changes really are needed, which is somewhat surprising.

Comment 73

[gene smith]

I'll make a new modified beta for you try but I'll leave out just the NOOP send, which, based on your last successful log (comment 69) is not needed.
But I would also like to know one more thing before you test the new modified beta:
During the 3m 20s that the 123.0b2 (64-bit) gds build 2 is checking for new mail, can you do other things like open existing messages or scroll the message and folder list or open other folders during this time? This is to check that the UI still responds acceptably during your "checking for new messages" interval.

Comment 74

[gene smith]

Here the fix without NOOP sending.
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/CsbYQ2c7Rwa_zlY7PslJpg/runs/0/artifacts/public/build/install/sea/target.installer.exe
Again the patch is applied on top of 123.0b2. There is now a b3 but to avoid throwing in more variables, I just patched b2 again.

FYI, here is the link to the full "try" build:
https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=edf5d6adf372258dabd18274b7b39aaa890a3366&selectedTaskRun=CsbYQ2c7Rwa_zlY7PslJpg.0

Comment 75

[Isaac Ribeiro]

Attachment: Error Console with All Accounts (123.0b2 64-bit gds build 3)

Thanks for the tip about downgrading! I will remain with the modified beta until they make changes to the oficial version.

Comment 76

[gene smith]

From the log at comment 75, it shows an error at the bottom for the 28th account (pop3.28). It looks like TB offered to send the oauth2 password and server said go ahead (sent a +) but TB never sent anything and then after about 9 minutes the server reported -ERR connection closed:

22:04:22.242 mailnews.pop3.28: C: AUTH XOAUTH2 Pop3Client.jsm:508:20
22:04:22.292 mailnews.pop3.28: S: + 

Pop3Client.jsm:348:18
22:05:31.066 mailnews.pop3.28: Connection closed. Pop3Client.jsm:395:18
22:05:31.067 mailnews.pop3.28: S: -ERR Connection is closed. 12

Was there a error popup in TB about something that reported this? This is completely different than anything you've shown me before since it occurred during authentication.

Comment 77

[Isaac Ribeiro]

I believe this happened because TB asked me to enter an account password and I took a while to enter it.

Comment 78

[Isaac Ribeiro]

TB did not display any error popups.

Comment 79

[gene smith]

(In reply to Isaac Ribeiro from comment #77)

I believe this happened because TB asked me to enter an account password and I took a while to enter it.

Good! That explains it. Looks like outook is wlling to wait almost 10m for a password, but times out other POP3 protocol stuff after 1 minute.

Before I submit a patch for approval, we need to make sure the UI responsiveness is OK for you as I mentioned in comment 73.
This is to ensure that the proposed changes do not cause something like is reported in bug 1792675.
Note: The reporter of that bug didn't actually "received" 13000 emails. Later he clarifies that what he meant was he had 13k existing messages in the server's Inbox.

Comment 80

[gene smith]

(In reply to Isaac Ribeiro from comment #75)

Created attachment 9379134 [details]
Error Console with All Accounts (123.0b2 64-bit gds build 3)

Thanks for the tip about downgrading! I will remain with the modified beta until they make changes to the oficial version.

Hi Isaac,
How's it going? Is the modified beta working OK? I haven't submitted a patch yet to change the official version since I'm waiting on a status report you regarding the UI behavior (as I mentioned in comment 79).
-gene

Comment 81

[Isaac Ribeiro]

Attachment: Error Console

Hi, gene! I was using TB without restarting it and I was getting messages normally. Today TB showed an error on the console after I manually restarted it. He had already presented the "ReferenceError: clearTimeout is not defined" other times. The error only appears in the console.

Comment 82

[gene smith]

(In reply to Isaac Ribeiro from comment #81)

Created attachment 9380315 [details]
Error Console

Hi, gene! I was using TB without restarting it and I was getting messages normally. Today TB showed an error on the console after I manually restarted it. He had already presented the "ReferenceError: clearTimeout is not defined" other times. The error only appears in the console.

I'm not sure if that's a bad error (I forgot to explicitly declare it). However, it shows that you are NOT running my last build but probably the one from comment 54 since that was the last one I that I used "clearTimeout".

So you should run the try build from comment 74. Here's the link to installer again (copied from comment 74):
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/CsbYQ2c7Rwa_zlY7PslJpg/runs/0/artifacts/public/build/install/sea/target.installer.exe

If the build with "clearTimeout" error is running OK and you are not seeing long response times and not seeing NOOP being sent in the log, then it's probably OK (as long as you keep your extensions/addons disabled). But it would be good to run the build from comment 74 since it never sends NOOPs and does not use the "clearTimeout" function.

Thanks and let me know how it goes!

Comment 83

[Isaac Ribeiro]

I will install the build from comment 74. I believed I had installed this build, as it is downloaded on my computer. Thanks!

Comment 84

[Isaac Ribeiro]

Attachment: Main Account Log 11 (problem)

Log of the main account's POP3 connection with the comment 74 build. I inform you that I uninstalled other versions of TB before installing the comment 74 build.

TB froze a few times during this automatic message fetching at startup and displayed the UIDL error dialog. It also froze when I first started this build a few days ago.

Only the TB freezes. All other applications continue to run normally. The amount of memory and CPU available is OK.

TB quickly received messages from the main account when I clicked "Get Messages" from that account individually, apparently without freezing.

Comment 85

[gene smith]

Isaac,
Here is one more to try. It is the same as the the version in comment 54 (includes sending NOOPs) but it has a fix for the clearTimeout error you saw. I think that error is actually important and caused problems. This is now a patched version of the latest beta 123.0b5:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/D7hHbqQaQYKX6VZXXSgIUQ/runs/0/artifacts/public/build/install/sea/target.installer.exe

FYI: Here is the link to the complete try build:
https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=b665d910a916c1dc2e91233afd760163dcb782c2

If this fixes the issues, I'll go ahead and submit this as a formal patch. Let me know if this makes any difference with fetching new POP3 emails.
Thanks and sorry for all the problems.

Comment 86

[Isaac Ribeiro]

Attachment: Main Account Log 12 (problem)

I had considered the performance of the beta 5 build to be good, although the TB froze on the first launch. However, now a connection error has appeared without displaying a dialog box.

Comment 87

[gene smith]

Attachment: about-daily.png

First let's make sure you are running the "try" build from last night. In TB, go to Help | About Daily and you should see the attached picture. It will say it is "Daily" and that the version is 123.0b5.
If you only see Help | About Beta or maybe Help | About Thunderbird or a different version number then it's not last night's try build.

The reason I want to make sure is because I don't see any NOOPs in the log you attached. I just downloaded the try build and I do see NOOPs in the log when I scroll the message list quickly.

It also seem like you have reduced the number of messages some in your main account. But that's OK, there is still close to 300k messages and I'm not sure the number is that important.

Another question: Was only your main (largest) account enabled when you recorded the log and did it occur when you started TB?

Comment 88

[gene smith]

Sorry, I found another error in the previous try build. I'm not sure this will fix the problems but it least it corrects the error:
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ffmrcu4eT_6aVOFwYMR40g/runs/0/artifacts/public/build/install/sea/target.installer.exe

With this you will again see the version as "Daily 123.0b5" but when you record the log you will see mail2_17.pop3. as the log items prefixes. (Before it was mailnews.pop3.)

Again, here is the link to the complete try build:
https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=4212666987747effe04da24558cad962b16fc32a

Comment 89

[Isaac Ribeiro]

Attachment: Main Account Log 13 (success)

Log from my main account with the Comment #88 build. I keep seeing mailnews.pop3. I removed the previous build before installing the new build. TB keeps freezing when fetching messages from main account on startup. The error displayed in the previous log did not occur at startup. I am using the following message receiving scheme:

@customdomain1.com.br				102
@hotmail.com					62 + startup
@hotmail.com.br					165
@gmail.com					115
@live.com					171
@msn.com					161
@customdomain2.com.br				195
@gmail.com					74
@ufrn.edu.br					175
@yahoo.com.br					129
@yahoo.com.br					186
@hotmail.com					90
@hotmail.com					185
@hotmail.com					85 + startup
@hotmail.com.br					125
@yahoo.com.br					155
@gmail.com					135
@unp.edu.br					133
@hotmail.com					197
@uminho.pt					113
@uminho.pt					105
@gmail.com					97
@hotmail.com					95
@hotmail.com.br					141
@hotmail.com 					145	
@hotmail.com.br					151
@gmail.com					82
@msn.com					80 + startup
@customdomain4.com.br 				78 + startup
@customdomain5.com.br				76 + startup
@hotmail.com					181
@customdomain6.com.br				27 + startup
@gmail.com					182
@hotmail.com					21 + startup

Comment 90

[Isaac Ribeiro]

Attachment: about-daily

About Daily | 123.0b5 (64-bit)

Comment 91

[Isaac Ribeiro]

Attachment: -ERR Connection is Closed. 12

I notice that "markMessages" always appears after "-ERR Connection is Closed. 12". Maybe deleting messages is blocking NOOPs from being sent.

Comment 92

[Isaac Ribeiro]

Attachment: Main Account Log with mail2_17.pop3 (problem)

I simply restarted TB after adding the PT-BR language. This made mail2_17.pop3 appear in the log. This is a record of automatic message fetching at startup.

Comment 93

[gene smith]

I simply restarted TB after adding the PT-BR language. This made mail2_17.pop3 appear in the log.

I thought the logging prefix string (hard coded) was independent of localization, but I have never worked with language settings. I just changed it in the try build to identify the "try" version with date 2-17.
Anyhow, it really didn't make a difference and failed even worse and timed out during the LIST processing and never even got to UIDL processing.

So at this point, the only thing I could suggest is that at startup you only have one POP3 account check for new mail. In comment 89 you show 7 accounts all checking for new mail at startup. Maybe if you only have one account (probably your main and largest account) check for mail at startup it would help. Also, having each account check for new mail on different times, as you now have it, is a good idea to avoid more than one account checking for new mail at the same time. Maybe keep all account's "check for new mail" times at least 5 minutes apart.

(In reply to Isaac Ribeiro from comment #91)

I notice that "markMessages" always appears after "-ERR Connection is Closed. 12". Maybe deleting messages is blocking NOOPs from being sent.

I haven't really studies how POP3 deleting works in detail. But I've seen that when you delete a pop3 message from Inbox, it marks it as deleted in the popstate.dat file. Then only on the next restart check for new messages are the messages actually deleted from the POP3 server (using POP3 "DELE" command). But I don't think the "markMessage" is blocking the NOOPs since it occurred well after the -ERR Connection is Closed.

What I've seen while testing here is that NOOPs or other POP3 commands are never sent if there is a lot of other activity going on, like quickly scrolling the messages list. In your case, the other background activities might be the other POP3 accounts checking for mail.

Note: With 102.15.1 (the last 102 version) scrolling the message list has no effect on POP3 commands getting sent yet with 115 and later it can completely stop POP3 activities.

Comment 94

[Isaac Ribeiro]

Attachment: -ERR Connection is closed. 12 with only the main account on startup

"-ERR Connection is closed. 12" with only the main account on startup and no foreground activity on the TB.

TB always freezes when fetching new messages from the main account on startup, even though it is the only activity in the foreground.

The language change just coincided with the prefix change. It continues with the language in English.

The number of messages reduced because I decided to put an end to the "email marketing museum". I have already deleted more than 40 thousand messages.

Comment 95

[Isaac Ribeiro]

Attachment: Main Account Log with TB 123.0b2 build 20240130 (success)

TB does not freeze with this build from comment #47. I consider it the best version.

Comment 96

[gene smith]

(In reply to Isaac Ribeiro from comment #95)

TB does not freeze with this build from comment #47. I consider it the best version.

Ok, here's the version from comment 47, again patched onto 123.0b5. All I changed was I removed some debug strings I put in for my own use (strings starting with "gds:"). I also made the logging prefix mail2_18.pop3 to identify the version.
https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/E9gdcaAARkq65KbHhYUv-A/runs/0/artifacts/public/build/install/sea/target.installer.exe
Edit: Fixed typo in above link. See comment 97.

And here's the link to the full try build:
https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=adbd09cc6a4f2c29ab61e8ef00eb3f82e19419fb

The problem you saw with this before was it would sometimes take a long time to complete the whole check for new mail, almost 20 minutes according to the log at comment 48. But there were no -ERR present which is good and it shows NOOPs sent.

So let me know how this version does now.

Comment 97

[Isaac Ribeiro]

Attachment: Main Account Log with TB 123.0b5 build 20240218 (success)

Performance continues to be good with this new build. TB is only with the main account at startup. Congratulations on the work!

The waiting time is not very high and, even if it was high, the delay only occurred once per session.

Ideally, POP3 activities would not stop due to other actions as it was until version 102.15.1, but your patch solves the problem that gave rise to this topic.

TB does not display the UIDL error dialog, does not display "-ERR Connection is Closed" in the log, and does not freeze while fetching messages.

I was able to download this new build just through the following URL: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/E9gdcaAARkq65KbHhYUv-A/runs/0/artifacts/public/build/install/sea/target.installer.exe

I replaced ...in/stall/sea/target.installer.exe with ...install/sea/target.installer.exe.

Congratulations on the work!

Comment 98

[Isaac Ribeiro]

Attachment: Main Account Log with TB 123.0b5 build 20240218 on second TB startup (success)

62 seconds to get a response to STAT and 5 minutes sending NOOPs.

Current Version: 123.0b5 (64-bit) build 20240218
Current authentication method: XOAUTH2
mailnews.tcptimeout = 200
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 99

[Isaac Ribeiro]

Attachment: Main Account Log with TB 123.0b5 build 20240218 when clicking Get Messages (success)

TB is sending NOOPs for about 5 minutes in other searches for new messages in the same session, but this has no impact on application usage.

Current Version: 123.0b5 (64-bit) build 20240218
Current authentication method: XOAUTH2
mailnews.tcptimeout = 200
network.tcp.keepalive.idle_time = default
network.tcp.keepalive.retry_interval = default

Comment 100

[gene smith]

Hi Isaac,
I have a new version to try. I think it is similar to the last version I made in comment 96. The problem with the comment 96 version is that I sometimes see problems because the NOOP response is not handled and sometimes it get seen as a response to a normal POP3 command. So I've seen "RETR +OK" occur where +OK is the NOOP response. The correct parameter for RETR is a message number.

Here's the installer: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/J6CAkbRWSfCpwRLv8xy7dA/runs/0/artifacts/public/build/install/sea/target.installer.exe
It is now based on 124.0b3 and I set the logging prefix for the build identification to "mail2_29.pop3". Happy Leap Year!.

FYI, here's the full try build:
https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=bf7bc4b340200d6196ac9a66c5adc291fe0d467d

One other thing I've noticed is that when my laptop battery is very low, I see more NOOPs sent fairly consistently. It also took much longer to process the LIST and UIDL response and to receive new messages. When I plugged in the charger the NOOPs didn't occur and the LIST, UIDL and RETR responses were much faster. I don't know if your computer is battery powered or not. If it is, maybe you have noticed this?

Comment 101

[Isaac Ribeiro]

(In reply to gene smith from comment #100)

Hi Gene!

The build from comment #100 maintains the good overall performance of the build from comment #96.

Regarding the main account, TB needed to send NOOPs for 3min54s with 232121 messages on the server.

In turn, I inform you that I always keep my laptop connected to the charger.

Happy Leap Year! :)

Comment 102

[gene smith]

Thanks for the update. Since to 124.0b3 (marked 2_29) is working OK for you with your huge number of pop3 UIDs, I'll go ahead and submit a formal patch with the change.

Comment 103

[gene smith]

Removing mention of oauth2 from summary since that is really not relevant to this bug.
Actually, neither is "Hotmail" but it makes an easy way to find the tab. :)

Comment 104

[Isaac Ribeiro]

(In reply to gene smith from comment #102 and comment #103)

Thanks!

Comment 105

[gene smith]

Attachment: Bug 1875633 - Avoid timeouts when huge number of pop3 messages left on server. r=mkmelin

This now sends a pop3 NOOP when processing LIST, UIDL, TOP and RETR responses if
the time since the last pop3 command sent exceeds 10 seconds. This acts as a
"keep-alive" so the server doesn't close the connection due to inactivity.

A change is also made to LineReader.jsm (also used by NNTP) so that the whole
response is received before processing the individual lines. This ensures that
NOOP is not sent while server responses may still be coming in.

Finally, this includes a fix to c++ pop3 code made at Bug 1577548 for "temporary"
errors reported by the server. The fix was never considered or included in the JS
pop3 version. Specifically, if a UIDL response error occurs and the server has UIDL
capability, UIDL command will now be tried again on the next check for new mail
and reported as a temporary error rather than stopping further checks with a
modal dialog. (This doesn't handle possible temporary errors from other
commands, but UIDL is historically the main cause.)

Comment 106

[gene smith]

Here the full try build: https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=5452aa247a719e8d2dd182ffa1a704e30ed92ba4
See quite a few "Your are leaking the world" warnings. Not sure I am causing them.
Also, it reported a ES lint error that I missed, "no-useless-concat" which I've fixed and have updated in the diff.

Comment 107

[[e-mail]]

Please consider adding a delay (say, 100 ms) to the timeout here:
https://hg.mozilla.org/try-comm-central/rev/5452aa247a719e8d2dd182ffa1a704e30ed92ba4#l2.128

Comment 108

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/comm-central/rev/2e171d15d953
Avoid timeouts when huge number of pop3 messages left on server. r=mkmelin

Comment 109

[Wayne Mery (:wsmwk)]

Missing target milestone

Comment 110

[Wayne Mery (:wsmwk)]

Is this behavior a regression?

Comment 111

[gene smith]

(In reply to Wayne Mery (:wsmwk) from comment #110)

Is this behavior a regression?

See comment 65.
It is definitely a regression but I can't pin it on a specific change. I tested with the last 102 and earlier version and didn't see the problem and the reporter didn't see problems until moving from 102 to 115. (102 and 115 have essentially the same POP3 code.)
All I can guess is that the increased processing required by supernova changes in UI thread affected the POP3 code, also running in UI thread.

Comment 112

[Wayne Mery (:wsmwk)]

Affects version 115, so tracking. But might wait til 128.