Closed Bug 1776823 Opened 2 years ago Closed 2 years ago

Thunderbird offline autosynchronization not happening

Categories

(MailNews Core :: Backend, defect, P2)

Thunderbird 102

Tracking

(thunderbird_esr102+ affected, thunderbird107 affected)

RESOLVED FIXED
108 Branch
Tracking Status
thunderbird_esr102 + affected
thunderbird107 --- affected

People

(Reporter: KaiE, Assigned: gds)

References

(Blocks 1 open bug)

Details

Attachments

(3 files, 5 obsolete files)

Offline IMAP folder synchronization isn't working for me on 102.

I had a folder with missing messages in offline mode. We suspected some folder corruption. I quit Thunderbird, identified the file in my profile folder below ImapMail by its folder name, and delete both primary and .msf files.

I started Thunderbird, and it re-synched the headers of the folder.

However, after having kept it running for 8 hours, overnight with no other activity, the folder still was NOT downloaded. (To confirm, I quit Thundebird again, and I only had a .msf file, no mail contents.)

The folder is included in my message sync advanced list of folders. Right click folder, properties, sync, also shows "select for offline use" is checked.

Sounds like the feature is broken, or randomly nonworking for some folders.

This is an old Thunderbird profile, but I think it should work anyway. We should find out what's causing this failure to sync.

Who understands how this is supposed to work?

Do we have a background timer, which routinely checks if all configured folders have been fully downloaded already?

Why do we even have a button "download now" in folder properties? Isn't that supposed to be done automatically?

My impression is, the syncing happens for new arriving emails, and also when copying to a folder.

However, there's apparently no automatism to re-sync old folders with incomplete offline cache.

Maybe this state can be reached, if settings in the past didn't ask for offline sync (I might have had this disabled in the past).

Also, the default workflow for going offline involves the question "want to download messages before going offline?". It seems this was done, because otherwise offline availability of messages isn't guaranteed.

I'm concluding: Simply enabling the prefs for offline sync is insufficient to have full local offline data. You'll have to use the UI to go offline and allow to download messages to ensure it.

If this is the intended behavior, we can close this bug.

I think this is handled by something called "autosync". When you visit a folder and you have offline store enabled for the folder, any new messages are downloaded and stored in a/the file (mbox or maildir). There is no downloads and store of new messages for a folder until you visit (open) it except when new messages are checked for Inbox or any other folder that is set to be checked for new mail or if the folder has recently been opened and imap IDLE is in effect for the folder to also detect new mail. If autosync is disable (via a pref) messages are not downloaded and stored until they are explicitly opened.

However, I also see a somewhat intermittent problem like what you describe. If I delete the mbox and .msf file for a folder with offline store and then visit that folder, I see the messages appear in the list. But I also sometime see no .msf or mbox file appear and nothing is downloaded except when a message is opened, and this doesn't create even the .msf file for the folder. Only by repairing the folder do I see the .msf and mbox files appear and download of messages occur. But sometimes this works fine and a repair is not need and both files appear and download occurs upon opening (visiting) the folder.

I just now saw this on 91.9 and on 102rc-build-2 so it doesn't seem to be a new bug.

I'll look closer at this tomorrow.

Blocks: tb102found

(In reply to gene smith from comment #3)

I'll look closer at this tomorrow.

Don't suppose you found something?

Summary: Thunderbird offline synchronization not happening → Thunderbird offline autosynchronization not happening

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

(In reply to gene smith from comment #3)

I'll look closer at this tomorrow.

Don't suppose you found something?

No not yet, other things came up but I see it when testing stuff. For example, I copy new messages to a folder and they sometimes don't appear in the mbox file until I repair the folder. But usually they do appear, so it's definitely not consistent.

Flags: needinfo?(gds)
OS: Unspecified → All
Priority: -- → P2
Hardware: Unspecified → All

(In reply to Kai Engert (:KaiE:) from comment #0)

Offline IMAP folder synchronization isn't working for me on 102.

I had a folder with missing messages in offline mode. We suspected some folder corruption. I quit Thunderbird, identified the file in my profile folder below ImapMail by its folder name, and delete both primary and .msf files.

First of all, just to be clear, deleting .msf and mbox files to fix a busted folder is not typically suggested as the 1st step for end users. Instead, right-click->Properties->Repair Folder is the documented method. However, removing the .msf and mbox files is something I do a lot while debugging problems.

I started Thunderbird, and it re-synched the headers of the folder.

However, after having kept it running for 8 hours, overnight with no other activity, the folder still was NOT downloaded. (To confirm, I quit Thundebird again, and I only had a .msf file, no mail contents.)

Probably the first thing to check is make sure autosync is enabled. Possibly at some point mail.server.default.autosync_offline_stores got set false. Without this true, individual messages are only downloaded and stored in the mbox file when they are opened.
Also, make sure there were no attempts to create account specific autosync settings with mail.server.serverX.autosync_offline_stores where X is the server/account index/key number, 1, 2, 3 ....
Another thing is check to make sure mail.imap.use_status_for_biff is true (the default). I think I saw somewhere that this is needed for autosync.

I did this several times on two accounts with successful results by following these steps:

  • Shutdown TB
  • Delete the <folder-name>.msf file for folder having offline store, e.g., INBOX.msf
  • Delete the <folder-name> mbox file, e.g., INBOX
  • Repeat the above 2 step for any other folder in the account you want to re-download that has offline store configured
  • Start TB and select any folder in the same account
  • Autosync requires TB be "idle" for 10 seconds before it starts, so don't do anything in TB for at least 10 seconds.
  • First, all the headers for the removed files are downloaded and stored in re-created <folder-name>.msf files
  • After header downloads finish each full message in <folder-name> having offline store is downloaded and stored in <folder-name> mbox files

If there are enough messages in the folders so that the download is not almost instantaneous, you should see the in the status bar at the bottom the activity for downloading the headers for all folders followed by slower progressing activity for downloading the full messages for all folders which are added to the <folder-name> mbox files.

However, I tried this again with a folder that is a subfolder of Inbox that has offline store. But on restart that folder didn't automatically download and create a new mbox file containing all the messages. I had to click the subfolder of Inbox before it downloaded and created the mbox file. I don't have to do this, it seems, with Inbox or other folders at the same level as Inbox.
Possibly the folder that didn't download for you was a subfolder? Also, did clicking on/opening the folder finally trigger the download and mbox creation?

Other that this, it appears that autosync is downloading and re-creating and populating the user-deleted .msf and mbox files properly.

I will look closer at the code for autosync and try to determine why lower level folders are not automatically autosync-ing and require that the folder be clicked (opened).

Flags: needinfo?(gds)

However, I tried this again with a folder that is a subfolder of Inbox that has offline store. But on restart that folder didn't automatically download and create a new mbox file containing all the messages. I had to click the subfolder of Inbox before it downloaded and created the mbox file. I don't have to do this, it seems, with Inbox or other folders at the same level as Inbox.

After more testing and code examination, my observation of a lack of automatic autosync for subfolders is a red-herring. It had nothing to do with the level of the folder in the hierarchy.

After a lot more testing and debugging I now see that there is a real problem with autosync that will cause a folder with offline store to never update even when new messages are added to it either by new mail arriving naturally into Inbox, messages being filtered into the folder or messages copied to to the folder by another client. So what is described in comment 0 is confirmed.

Unless the folder is opened by the user, new messages will stop being detected if the imap folder status, triggered on biff interval after TB enters the idle state (10s after the last keyboard or mouse activity in a TB window), detects a change in any of several counts (e.g., number of messages in folder), a folder update (an imap select url) is triggered by autosync. But if the folder update response doesn't detect the need to download any missing message bodies, the autosync state gets stuck in "stUpdateIssued" and never returns to the initial state, "stCompletedIdle", locking out any further autosync downloads for the folder. Also, the autosync manager state never returns to "completed" which also stop any further autosync new message detection and download.

The last change to autosync functionality was bug 428266. Before that, TB always did just a folder update (imap select url) to detect new messages needing to be downloaded. As part of the fix for that bug, instead of always doing an update, first a status (imap folderstatus url) is done to see if anything has really changed. This is a lot less network activity since typically nothing really changes and a imap STATUS command produces a lot less network traffic than the imap SELECT and flag re-fetches used for update. So only if something appears to be changed, indicated by the status response, is the full folder update (imap select and full flag fetch) done.

The problem occurs because imap STATUS returns 4 values such as MESSAGES 21 RECENT 0 UNSEEN 2 UIDNEXT 1173.
If autosync sees a change in any of these, it triggers an update. In my testing, there is often a change seen in the UNSEEN value even though there was no change in the number of unseen (a.k.a, unread) messages in the folder. This causes the update to be triggered and update detects no real changes, causing the autosync state for the folder to get hung in "stUpdateIssued".

So far I've haven't found out exactly why the unread (unseen) count appears changed. (I think also the recent count may trigger a false update but I haven't verified it.)

I've made some experimental changes (see next attachment) to the autosync and related code to tolerate the false change indications from status. However, I still need to find out why the the false indications occur. If it can't be fixed with reasonable effort then I might propose just removing the change check for UNSEEN and maybe RECENT from the autosync code since the number of MESSAGES changing is the primary reason to download the new messages and that is detected accurately.

See Also: → 428266
Attached patch autosync-debug-changes.diff (obsolete) — Splinter Review

Here's my changes to autosync that I've been working on. Most of the changes are just printfs or MOZ_LOGs for better debugging so I can try to see what is going on better. It also temporarily changes the update and discovery timers so that I don't have to wait 1 hour before something is added to the queues.

The actual fix to handle updates that find no new messages to download is marked with "fixes it".

Assignee: nobody → gds
See Also: → 1373940

The reason false changes are detected, which triggers a folder update that finds no need to download anything, is caused by a couple of factors.

The first one is a parsing error that appears to have been present since day one. It occurs when trying to determine the number of unread (UNSEEN in imap parlance) messages. The UNSEEN response from imap STATUS returns the correct value. However, the UNSEEN response from imap SELECT is not really the number of unseen (unread) messages but is instead the message sequence number of the 1st unseen message in the mailbox. So the UNSEEN response from SELECT should be ignored when determining the number of unread messages.

But just ignoring the UNSEEN response code from SELECT doesn't completely fix the problem.

The other problem is that the folderCache.json item serverUnseen gets set or set back to 0 from the correct value that is returned in the imap STATUS response. The reason is because the value written to serverUnseen is initialized to zero and imap STATUS does not always occur during a session. Also, during a folder update (select URL) the value to be written to serverUnseen is first zero'd but, as mentioned above, the UNSEEN value from SELECT is not really the number of unseen messages so it can't be used so the value remains, often incorrectly, zero.

Autosync reads the value from folderCache serverUnseen and compares it to the value from the STATUS response. Since zero is usually stored in cache, this can appear to be a false change and triggers the update (SELECT) and finds nothing needing downloading.

The vars for handling the UNSEEN value from STATUS are all signed int32_t but negative UNSEEN count is never valid. So my solution is change the var initialization to -1 instead of as they currently are now, initialized to 0 and avoid saving 0 back into folderCache serverUnseen when imap STATUS has yet to occur.

This WIP diff keeps the fix from the previous diff (mark obsolete) and just adds the initialization to -1 fix described above.

Attachment #9287313 - Attachment is obsolete: true

On beta for some weeks I've been seeing slow message sync, particularly for messages being filtered to non-Inbox folders. The headers appear in the target folder, but for dozens of seconds some times the message body doesn't display and status bar has "loading message".

I disabled global indexing but it didn't help

Gene, is the patch ready for review? Or dependent on some other work?
Do we know why this got worse in version 102?

Flags: needinfo?(gds)

I got side tracked to other things and haven't got back to this in a couple weeks. I'm not sure what the status is.

Do we know why this got worse in version 102?

Are you referring to this comment above?:

On beta for some weeks I've been seeing slow message sync, particularly for messages being filtered to non-Inbox folders. The headers appear in the target folder, but for dozens of seconds some times the message body doesn't display and status bar has "loading message".

I disabled global indexing but it didn't help

Is this on an IMAP inbox? How many messages are coming in at a time? Are they typical sizes like bugmails or are they messages with huge attachments? Are you saving messages to mbox or maildir offline store? Is this slowness only observed at startup or at any time new msgs come in?

I don't think the changes I proposed so far to autosync affect the speed. It just fixes failure to autosync at all.

Flags: needinfo?(gds)
Attachment #9287871 - Attachment is obsolete: true
  • Fix parsing for imap UNSEEN in SELECT command -- it's not number of unseen.
  • Make sure only UNSEEN from imap STATUS is used -- it is number of unseen
  • Make sure imap STATUS has occurred before using the stored UNSEEN value.
  • Store imap untagged EXISTS and MESSAGES from imap STATUS to same variable.
  • Store imap untagged RECENT and RECENT from imap STATUS to same variable.
  • Avoid autosync lockup if folder update finds no new headers to fetch.
  • Force folder update if .msf is empty or missing on initial access.
  • Add more MOZ_LOG for better debugging.

stellar changes, Gene!

Thanks. I'll go ahead and request checkin.

Target Milestone: --- → 106 Branch

Pushed by geoff@darktrojan.net:
https://hg.mozilla.org/comm-central/rev/9d358a4c4bb5
Fix for autosync sometimes stops or doesn't occur at all. r=BenC

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Attached file autosync.odt (obsolete) —

I wrote this up to remember how autosync actually works, from what I can tell.

Attached file autosync.pdf (obsolete) —

Thanks Gene, I created a PDF version of your document, that format is more likely to survive the times.

Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: 106 Branch → ---

I found the problem causing bug 1791169 and it seems OK now. But I want to do a some more testing to be sure it's OK.

(In reply to Kai Engert (:KaiE:) from comment #19)

Created attachment 9295236 [details]
autosync.pdf

Thanks Gene, I created a PDF version of your document, that format is more likely to survive the times.

Thanks. I probably need to update the document based on what I'm still learning. If I make a modification I'll attach it as PDF.

(In reply to gene smith from comment #21)

Thanks. I probably need to update the document based on what I'm still learning. If I make a modification I'll attach it as PDF.

We should have an in-tree documentation setup soon which would be a good place for stuff like this. I've made a note to double check that some version of this gets in there after it's working.

Regressions: 1791169
See Also: → 1786252

I have a very similar, if not the same, problem with V 102.2.2 (64-bit) on Ubuntu 20.04. What's strange is this:

I have an Inbox folder with "Select this folder for offline use" checked. The setting "Download messages for offline use when going offline?" is set to "Yes". Also, all the config settings mentioned in comment #6 are as they should.

  1. I click on the offline button, I see the status message "Downloading mail for offline use..." with the names of the folders supposedly being downloaded. Then I get the "offline" symbol.

  2. Now I select a somewhat older message in the Inbox. It appears blank, and in the status bar I see the message "[account name]: Looking up [account name]...".

  3. I go online again. The message gets downloaded and it isn't blank anymore.

I see it as a bug not only that the message was blank while offline, but also that Thunderbird seems to trying to contact the mail server while offline.

I have a very similar, if not the same, problem with V 102.2.2 (64-bit) on Ubuntu 20.04. What's strange is this:

I've also have come across a situation where messages are not really stored offline when they appear to have been. I have a fix for that in my patch for this bug but I haven't submitted it again since this requires a lot of testing to get it right (as I learned from my first attempt).

Thunderbird seems to trying to contact the mail server while offline.

This bug doesn't address what happen while the tb system is offline. That may be a separate/new bug.

Attachment #9293044 - Attachment is obsolete: true

(In reply to gene smith from comment #14)

Created attachment 9293044 [details]
Bug 1776823 - Fix for autosync sometimes stops or doesn't occur at all. r=benc

These are reverted:

  • Fix parsing for imap UNSEEN in SELECT command -- it's not number of unseen.
  • Make sure only UNSEEN from imap STATUS is used -- it is number of unseen
  • Make sure imap STATUS has occurred before using the stored UNSEEN value.
  • Store imap untagged EXISTS and MESSAGES from imap STATUS to same variable.
  • Store imap untagged RECENT and RECENT from imap STATUS to same variable.

These are still present:

  • Avoid autosync lockup if folder update finds no new headers to fetch.
  • Force folder update if .msf is empty or missing on initial access.
  • Add more MOZ_LOGs for better debugging.

Note: When referring to a folder as "offline" it means the messages in the corresponding imap mailbox are stored locally (in mbox or maildir format) for potential offline use and for faster access when online. It does not mean the system is in offline mode.

This fixes the problems found that caused the previous patch to be backed out. My changes for handling UNSEEN (aka, UNREAD), EXISTS and MESSAGES counts in nsImapServerParser.cpp and nsImapMailFolder.cpp had to be reverted. It was causing the count of messages in offline folders to report 0 messages and then the correct number, causing re-downloads.

This update also fixes another bug in the released code. A copy or move to a destination offline folder from a source folder not offline on the same server didn't autosync the destination folder. This is because the source message is flagged as offline even though it is not, so a fetch of the message body from the server by the destination folder never occurred. (Note: If the source folder is also offline, the message is copied between the offline files and no fetch from the server is even needed and that worked OK.) The solution for same server move/copies from not-offline to offline is to make sure the copied/moved messages are marked with the offline status of the source folders and not assume they are always offline so the full body fetch is triggered by the destination folder.

This also makes a change to logging in nsImapProtocol.cpp. Debugging and testing autosync features required fetching/downloading many often large messages resulted in a huge and hard to read log file. To make the IMAP log more compact and easier to read, I changed a couple logging items from DEBUG to VERBOSE. So now with logging level set to IMAP:4, the number of lines in the log is reduced by up to 66% without losing useful data.

As mentioned above about reverting the UNSEEN/UNREAD and EXISTS/MESSAGES changes that caused the problem with the original patch, the UNSEEN/UNREAD values as originally used in the nsAutoSyncState::OnStopRunningURL() to determines if something has changed to cause a complete folder update are still incorrect. So I removed the check there for a changes in the unseen count to determine if an update is needed since frequently the unseen value is wrong since it can come from the UNSEEN count returned by imap SELECT which is not actually the UNSEEN count. So now the folder update is still triggered by a change in number of messages (EXISTS) or the number of RECENT messages or by a change in the UIDNEXT value, but not by a change in the often incorrect UNSEEN value.

Another issue fixed is that autosync for accounts using oauth2 would intermittently not autosync. This would appear in the IMAPAutoSync log file AutoUpdateFolders: server |server name| don't autosync; not yet logged in. The reason for this is because nsMsgIncomingServer::Observe() often clears the flag that autosync uses to determine if the server has been logged in when the auth method is oauth2. The Observe() function sees any change in the password manager state and clears the password from cache even though it might only be an update of the oauth2 token and not a password change or deletion. So my fix for imap is to ignore change when oauth2 is in effect so autosync doesn't see it as not logged in and does autosync for the server. This is similar to the fix for previous unrelated issues, Bug 1745205 and Bug 1759883. Also, this touches on a similar issue: Bug 1695703.

The next comment will contain the proposed patch.
Here's a "try" build: https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=63a0a450105ac007dba77f6fbf591bff216d97f4

See Also: → 1745205, 1759883, 1695703

I'd be interested in a try build for Mac.

I'd be interested in a try build for Mac.

Should be here real soon now for all archs except linux: https://treeherder.mozilla.org/jobs?repo=try-comm-central&revision=8c9950907e212014999cec072d7ec675548c3ecb

Try server is (and was on some earlier attempts) giving me some weird intermittent errors on linux but the others, including macosx64, seem to be building OK at this time, I think.

I am having mixed results with the try build on Mac. Background - for weeks/months on the Mac where I use beta I have been having issues with slow autosync (and filtering), but mainly with only one gmail account. (plus Bug 1749276 - Crash getting mail [@ nsMsgLocalMailFolder::EndMessage ] with message filter copy/move)

Try build initially seemed better, message bodies and filtering was slightly faster. But now it is much worse than beta was - some message bodies are not syncing after minutes, even after going offline, or restarting Thunderbird. Status bar for example shows "Loading message". And filtering is slower. But to be fair, since I don't normally run nightly I don't know that this got worse just because of the patches from this bug.

some message bodies are not syncing after minutes, even after going offline, or restarting

Wayne, can you explain exactly what you mean by "not syncing". Can I assume you are looking at gmail Inbox and you have new messages come in. If so, how many new messages are coming in at a time? You then click on a message and it doesn't open? Is that what you mean by "not syncing"? Or maybe you are looking at the profile under ImapFolders and you you don't see the mbox files update with the new messages?

Also, I'm not sure what you are doing with filtering. Are you just moving incoming gmail messages, using TB's filters, from Inbox to another gmail folder? If so, are all messages that arrive at Inbox moved to another gmail folder on the same account? About how many are moved? Are you using any of gmail's own filtering?

Is the problem mac-specific. I.e., have you run the same problem accounts on win or linux and don't see a problem or are you only using mac exclusively? I have an old mac air but not sure it can run the latest TB since it's so old (circa 2008 I think).

I've never seen the crash you referred to but I don't use filters much other than to move BMO mail to its own folder from my Inbox.

Are all the folders that don't or are slow to sync using offline store? Just to be clear, autosync only acts on folders having offline store.

Not sure it would help but you can record a combined IMAP and Autosync log like this from cmd line:

MOZ_LOG=IMAP:4,timestamp,sync,IMAPAutoSync:5  MOZ_LOG_FILE=~/tblog    <path to thunderbird executable> -p --allow-downgrade

Then again, what this records could get messy if you have multiple accounts going at once so you might want to disable "check for new mail at startup" and "check for new messages every X min" for all but the "problem" account before recording the log. Also, you may not need the -p and --allow-downgrade; I just always use them by default.

(In reply to gene smith from comment #30)

some message bodies are not syncing after minutes, even after going offline, or restarting

Wayne, can you explain exactly what you mean by "not syncing".

Meaning the message bodies don't appear in a reasonable period of time.

Can I assume you are looking at gmail Inbox and you have new messages come in. If so, how many new messages are coming in at a time? You then click on a message and it doesn't open? Is that what you mean by "not syncing"? Or maybe you are looking at the profile under ImapFolders and you you don't see the mbox files update with the new messages?

Usually less than 20 messages at a time.
Sometimes the messages are seen in the Inbox before they get filtered (they shouldn't) , but never with messages bodies.
More typical, is I see an increased message count in the target folder, and folder decoration indicating it has new messages, but the message header takes time to appear, and even longer for the message body

Also, I'm not sure what you are doing with filtering. Are you just moving incoming gmail messages, using TB's filters, from Inbox to another gmail folder? If so, are all messages that arrive at Inbox moved to another gmail folder on the same account? About how many are moved? Are you using any of gmail's own filtering?

Moving within same account.
Almost all messages are moved out of the Inbox by filters.
I have 138 filters for this gmail account.

Is the problem mac-specific. I.e., have you run the same problem accounts on win or linux and don't see a problem or are you only using mac exclusively? I have an old mac air but not sure it can run the latest TB since it's so old (circa 2008 I think).

I don't have a comparable filter list or account with mail volume on another computer.

Are all the folders that don't or are slow to sync using offline store? Just to be clear, autosync only acts on folders having offline store.

I have multiple accounts in this profile.
No other accounts have this problem - but then none have this message volume nor number of filters.

I have emailed you the logs.

I appears that Wayne's issues starting at comment 29 are probably not related to this bug (based on our email exchange).
So I'm going ahead and setting the check-in needed flag since the patch has been reviewed and a couple of minor comment related changes were made.

(In reply to gene smith from comment #32)

I appears that Wayne's issues starting at comment 29 are probably not related to this bug (based on our email exchange).

Agreed. FWIW, I set mail.server.default.use_condstore = true, which significantly helped the gmail account.

So I'm going ahead and setting the check-in needed flag since the patch has been reviewed and a couple of minor comment related changes were made.

That will give us two weeks on nightly before it sees beta, which is good.

Target Milestone: --- → 108 Branch

Please mark D156392 as abandoned.

Pushed by mkmelin@iki.fi:
https://hg.mozilla.org/comm-central/rev/d8be423a19fe
Fix for autosync sometimes stops or doesn't occur at all (2nd try). r=BenC

Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → FIXED
See Also: → 1802295
Blocks: 1804374
Attachment #9295153 - Attachment is obsolete: true
Attachment #9295236 - Attachment is obsolete: true
Attached file autosync-v2.odt
Attached file autosync-v2.pdf

Update the "autosync overview" document some.

Regressions: 1802295
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: