Open Bug 1665146 Opened 4 years ago Updated 3 years ago

IMAP FETCH Mail in endless loop if internet connection breaks while synchronising IMAP folders, and incorrect progress information

Categories

(MailNews Core :: Networking: IMAP, defect)

defect

Tracking

(Not tracked)

People

(Reporter: Robert_Hartmann, Unassigned)

References

Details

(Whiteboard: [dupme?])

Attachments

(2 files)

Attached image Screenshot 2020-09-14 220149.jpg (deleted) —

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

Steps to reproduce:

  1. Start Thunderbird (master password active) with classic window layout showing "Folder pane" and "Message Pane".

  2. Just start synchronising IMAP-Folders and while mails are in downloading process disconnect WLAN and LAN so that the IMAP server is not reachable.

Actual results:

Status information about downloaded mails is counting like an infinity-loop.
See attached screenshot. Without connection to the server you can "downlooad" more mails as with connection to server.

Expected results:

While syncing an IMAP-Folder there should be a number check or a connection check. The faster check is a number check.

If there is no server connection or in faster way, if number bounds are reached than "downloading" should stopp.
May be warning message but not neccessary.

Reproducible on Windows 10 64bit Version 2004 (Build 19041.508) testing with
TB 32bit + TB 64bit :

  • 78.2.2 german Build 20200908210243,
  • 81.0b3 german Build 20200908000014,
  • 82.0a1 english 20200914104010

May be connected to bug 1315533

FWIW, you cannot judge by the progress meter moving, or being stuck. However if download numbers are changing this is indeed a problem.

[I see it happen with gmail accounts - but I think unrelated to network connectivity, just happens out of the blue but I'm sure there is some reason behind it. Is this only happening with your gmx account? How often?]

Wayne, I'm not following this. Where is the indication he is downloading stuff with the network disabled? (Maybe I'm just not familiar with what windows shows like in the attachment.)

What happens if you disconnect the networks and then start tb. Surely nothing can be fetched.
Why would you want to disconnect the network while tb is fetching new messages. (I think that's what he mean by "synchronizing" but not sure.)

I misunderstood the problem - so I have revised comment 2.

I haven't tested, but a shorter list of steps should be:

  1. Start TB with active network
  2. Start syncing
  3. Disable network while sync is in progress

At this point you SHOULD see TB's online icon change to offline! At least on Windows and Mac - because TB can detect whether there is an active network connection.

Flags: needinfo?(Robert_Hartmann)

(In reply to gene smith from comment #3)

Wayne, I'm not following this. Where is the indication he is downloading stuff with the network disabled? (Maybe I'm just not familiar with what windows shows like in the attachment.)

What happens if you disconnect the networks and then start tb. Surely nothing can be fetched.

a) TB-online-Icon with status "You are currently online" is shown.
b) TB starts to find connections to first IMAP-Server (without timeout - well I haven't wait multiple hours)
And in footer right to the TB-online-Icon there is the message "<E-Mail-Adress>: <IMAP-Server> nachschlagen..."
(nachschlagen is German for searching)

Why would you want to disconnect the network while tb is fetching new messages. (I think that's what he mean by "synchronizing" but not sure.)

@gene smith: The answer to that question is simple. I wanted to simulate the situation that the server is not reachable anymore while doing things for a test scenario in bug 1517464 comment 57 ( https://bugzilla.mozilla.org/show_bug.cgi?id=1517464#c57 )
And while doing that steps ( with the result of beeing not connected to the inernet anymore) I recognized that the numbers of fetched mail shown just in the neighbourhood of the TB-online-Icon increased higher than the showed upperbound of available mails without stopping the counter...

That the TB-online-Icon has showed, that TB is online, I haven'd noticed - but Wayne did it maybe on my screenshot.

Attached image Screenshot_2020-09-16_MailCounter.jpg (deleted) —

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

FWIW, you cannot judge by the progress meter moving, or being stuck. However if download numbers are changing this is indeed a problem.

[I see it happen with gmail accounts - but I think unrelated to network connectivity, just happens out of the blue but I'm sure there is some reason behind it. Is this only happening with your gmx account? How often?]

The situation is reproducible on other not GMX related servers, see second screenshot.
It is not related to the windows version, too.

The easyest way to reproduce was, create a new TB profile, and just after TB has shown some (or all)
IMAP-Folders just disconnect network.

TB-status Icon show "you are online" , numbercounter for fetching mails is doing buggy things.

Flags: needinfo?(Robert_Hartmann)

Yes, I see it. With profile1 I put many messages in Inbox. Then I closed tb and opened the same account in profile2 and click on Inbox. I see the status at the bottom start to count up and when I remove the network cable I see this:

((offline)) gds@domain.com Downloading 72 of 17081 in Inbox...

It looks stable for a while but then after a few minutes I see the first number start to go up quickly and it finally reached:

((offline)) gds@domain.com Downloading 28709 of 17081 in Inbox...

I'm not sure if the count start and stop happened spontaneously. It seemed like the start of the improper count happened after I moved or resized the tb screen. And I noticed the stop occurred after I switched to another window to check the imap log. Of course, there was no imap activity recorded after the network cabled was pulled. I'll try again later to check this theory.

Edit: Looks like my theory is wrong and count-up is spontaneous. Tried again with hands-off and it went to this:
((offline)) gds@domain.com Downloading 40049 of 10533 in Inbox...

So this is a mystery!

Note: I think I can also duplicate this by "repairing" the Inbox folder which forces a re-download of all messages.

Of course, there was no imap activity recorded after the network cabled was pulled.

I'm wrong about this too. There is activity in the imap log. It appears that every message ID is still attempted to be fetched -- a FETCH url is generated and sent to nsImapProtocol.cpp but each fails due to the lack of a connection. However, this activity is still reflected erroneously in the fetch count somehow.
Edit: I think the count exceeds the number of messages because retries are also being counted -- just a guess.

could explain things like these?

bug 538034 deadlock if error doing status checks - chaining imap status calls, if previous url had a network error, we can be locked on a monitor on the server when the next url tries to run
bug 554055 network connection timeout ETIMEDOUT misreported as ECONNREFUSED
bug 881086 Thunderbird hogs CPU when no network via WiFi (or otherwise)
bug 937371 process lingers after shutdown (hang) when network access is limited (down)

(In reply to gene smith from comment #8)

Of course, there was no imap activity recorded after the network cabled was pulled.

I'm wrong about this too. There is activity in the imap log. It appears that every message ID is still attempted to be fetched -- a FETCH url is generated and sent to nsImapProtocol.cpp but each fails due to the lack of a connection. However, this activity is still reflected erroneously in the fetch count somehow.
Edit: I think the count exceeds the number of messages because retries are also being counted -- just a guess.

Where I can have a look into that *.cpp ? I think a break condition in a while-loop or a if-then-else is missing?

This may be related to or a dupe of Bug 1373940 which reported the 1st number larger than the 2nd in the progress message. The reason and the exact behavior was never definitely determined. But no one saw the sudden counting-up like Robert reports.

Wayne, thanks for the links. I'll look through them.

Robert, the file I'm referring to is here: https://searchfox.org/comm-central/source/mailnews/imap/src/nsImapProtocol.cpp. Not sure the problem is there but might be.

I don't clearly see anything in the Wayne's links that address this. But I do think I see what's happening. The stuff at the nsImapProtocol level seems to only affect what appears in the Activity Manager and the percent complete as indicated by the bar graph in the status bar. This seems to stop updating when the network is disconnected.

The status bar indication of progress is set in the autosync code in autosync.jsm. It is actually called from here: https://searchfox.org/comm-central/rev/e617b978ea4161d7120f4f8f2565ff81dc52b2c8/mailnews/imap/src/nsAutoSyncManager.cpp#872. This call occurs when the "download is successfully started". Each download attempt tries to fetch 1 to 3 messages and is always "successfully started" so the count of messages increases. When this call to OnDownloadStarted() occurs it is unknown at that point in the code that the network is down so the count increases even though each fetch fails in the end. Also, since each failed fetch is retried 3 times, the count of downloaded messages can reach a high value of 4 times the expected number so you could see something like "24000 of 8000 in Inbox" worst case on the status line.

I'm not sure at all how to fix this (or if it is worth fixing). Seems like it should only increment the message count when the fetch is "successfully completed" rather than when "successfully started".
FYI, here is where this behavior is documented: https://searchfox.org/comm-central/rev/e617b978ea4161d7120f4f8f2565ff81dc52b2c8/mailnews/imap/public/nsIAutoSyncManager.idl#43

Also, to check this I added a printf() like this in nsAutoSyncManager.cpp:

 870     aAutoSyncStateObj->GetOwnerFolder(getter_AddRefs(folder));
 871     if (NS_SUCCEEDED(rv) && folder)
 872     {
 873       printf("gds: length=%d, totalCount=%d\n", length, totalCount);
 874       NOTIFY_LISTENERS(OnDownloadStarted, (folder, length, totalCount));
 875     }
 876   }

and with the network disconnected I see lots output like this:

:
gds: length=2, totalCount=8722
gds: length=2, totalCount=8722
gds: length=2, totalCount=8722
gds: length=2, totalCount=8722
:

This correlates with what I see on the status line. Note: The length is the number of messages in a single fetch so these add-up to the total number of fetches (actually fetch attempts) and at the end exceeds 8722 (by almost a factor of 4 !!).

Component: Mail Window Front End → Networking: IMAP
Product: Thunderbird → MailNews Core

(In reply to gene smith from comment #12)
[...]

I'm not sure at all how to fix this (or if it is worth fixing). Seems like it should only increment the message count when the fetch is "successfully completed" rather than when "successfully started".
FYI, here is where this behavior is documented: https://searchfox.org/comm-central/rev/e617b978ea4161d7120f4f8f2565ff81dc52b2c8/mailnews/imap/public/nsIAutoSyncManager.idl#43

so the progressbar could be an observer or listener for "onDownloadStarted" and the numbers should be an observer or listener for "onDownloadCompleted" but the draw back is, than the numbers "jump" after completed a folder ... If I understand above linked *.idl than there is no notifyer or signal which can tell, that exactly one mail has been downloaded.

Additional, a problem with the mail-counter is, if you move 3803 mails from an imap-folder to a local folder, than the numbers of moved mails don't count up, several minutes it stay at infomation "1 von 3803 Nachichten nach Zielordner verschieben" , may be with the last moved mail, the number has its finale value (TB Version 78.6.0 - 32bit). I think at first information there sould be "analysing mails to become moved ..." and than after the first mail has moved the information should be "moved 1 of 3803 mails to foldername" ... :-)

Severity: -- → S4
Status: UNCONFIRMED → NEW
Ever confirmed: true
Summary: IMAP FETCH Mail in endless loop if internet connection breaks while synchronising IMAP folders → IMAP FETCH Mail in endless loop if internet connection breaks while synchronising IMAP folders, and incorrect progress information
Whiteboard: [dupme?]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: