522675 - Message lost(at move source IMAP folder, \Deleted is stored)/corrupted(at move target local folder due to error while fetching), if network connection drops while moving mails from IMAP mail folder to local mail folder

Status: RESOLVED FIXED

(MailNews Core :: Networking: IMAP, defect)

Description

[Rob Knight]

User-Agent:       Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.04506.30; .NET CLR 3.0.04506.648; InfoPath.2)
Build Identifier: version 2.0.0.23 (20090812)

Was moving a message with three attachments from the Inbox to a local folder. Partway through the VPN connection dropped and Thunderbird went unresponsive. I waited 5 minutes or so and then closed Thunderbird. Upon restarting, the original message had gone completely from the inbox. The message is in the local folder, but only one attachment made it and is corrupt.

Reproducible: Couldn't Reproduce

Steps to Reproduce:
1. Send a large email into the inbox with a number of attachments (I use PPTs)
2. Drag and drop the message to a local folder
3. While it is "downloading", yank out the network cable
Actual Results:  
 


There are probably other factors affecting this that I can't reproduce. The bottom line is that somehow, a message was deleted from the inbox before it had successfully moved to a local folder.
Obviously, a difficult problem to resolve, however, an email client should not lose or corrupt a message even if the network connection drops.

Comment 1

[[:Aureliano Buendía]]

Rob, you use pop3?

Comment 2

[Rob Knight]

Hi Aureliano, I'm using IMAP (port 993, SSL).

Comment 3

[Wayne Mery (:wsmwk)]

(proper severity)

Comment 4

[Wayne Mery (:wsmwk)]

bienvenu, would you expect this to not happen in a current version?

Comment 5

[WADA:World Anti-bad-Duping Agency]

(In reply to Rob Knight from comment #0)
> Steps to Reproduce:
> 1. Send a large email into IMAP Inbox with a number of attachments
> 2. Drag and drop the message to a local folder
> 3. While it is "downloading", yank out the network cable

I could see next by above test
- After LAN cable is pulled off, mail in local mail folder was partial,
  because connection error occurred while fetching mail data.
- After re-connection of LAN cable, Tb issued "uid xx store flag \Deleted"
  for the mail in move source IMAP folder.
- Because I tested with Gmail IMAP and auto-expunging=On, mail data is lost
  once \Deleted flag is stored. 
- Tb looked to fetch mail data even after Tb stored \Deleted flag.
with Tb 9.0.1 on Win, with Gmail IMAP and auto-expunging=On, with IMAP offline-use=off folder, with IMAP delete model of "Just Mark it as Deleted", with Max chached connections=3, with IDLE command use is enabled.

This can't be observed by Drag&Drop of a mail in IMAP offline-use=on folder to local mail folder, if the mail data is already downloaded to offline-store file by auto-sync. Copy of mail data is executed using data in offline-store file, so mail data is fully copied to local mail folder, and original mail is deleted sooner or later after connection recovery. 
However, if Drag&Drop of multiple mails, Tb 9 possibly issues fetch for mail copy. If it's correct, similar phenomenon to offline-use=off case may be observed.

Bug opener reported this bug for Tb 3.0.x. Auto-sync of IMAP folder was not officially opened to public during Tb 2 era. Auto-sync of IMAP was enhanced by Tb 3 very much by Tb 3.0 and was enabled by default from Tb 3,0.
So, I believe auto-sync was not enabled when this bug was opened.

Tb may request "uid 2 store -Flags \Deleted" if Gmail IMAP's auto-expunging=off. However, even when Tb recovers from wrongly saved \Deleted flag, if connection error happens after "uid 2 store Flag \Deleted", \Deleted flag is kept. It's loss of original mail user(Move to Trash is widely used and is defaulted, and Remove Immediately may be used by user), and if expunge is requested after it, mail is actually lost forever.

Comment 6

[WADA:World Anti-bad-Duping Agency]

Attachment: IMAP log for test in comment #5(Tb 9 stores \Deleted flag even when connection error occurs while copying)

Comment 7

[WADA:World Anti-bad-Duping Agency]

Checked with auto-expunge of Gmail IMAP disabled. Same result as auto-expunge=enabled, except that fetch of mail data after "uid xx store Flag (\Deleted)" is successful.
i.e. Tb never resets wrongly stored \Deleted flag, because "copy step of move" is successful for Tb even though connection error occurs while copy, and because "delete step of move" is normal action for Tb.

Additional observation.
  After pull off of LAN cable,
  - At File/Offline, "Work Offline" is checked.
    i.e. Tb is in Work Offline mode.
         This is normal status, because LAN cable is pulled off by me.
  - Mail in move source IMAP folder is shown with strike-thru line,
    because "Just Mark it as Deleted" model.
  - Following is shown at message pane, because "Work Offline" mode.
      The body of this message has not been downloaded from the server
      for reading offline. (snip)
  After plug in of LAN cable,
  - Tb automatically goes back to Work Online mode, as designed.
  - Tb issues "uid xx store Flag (\Deleted)".
    This means "delete of mail while Offline mode" is normally informed to server
    when Tb returns to Online mode, as designed.

Tb looks to ignore connection error while "fetch body[]" for mail copy, if offline is detected at same time. "No more data from server" in such case is perhaps "all mail data is sent from server" for Tb.

Confirming.

Comment 8

[Hiroyuki Ikezoe (:hiro)]

I got finally reproduced this issue on my linux box. Pulling off LAN cable is not needed. To toggle offline status is just necessary.

Comment 9

[Hiroyuki Ikezoe (:hiro)]

Attachment: Possible fix

I suppose that the problem is in nsImapProtocol::ProcessCurrentURL():

1752       nsCOMPtr<nsIRequest> request = do_QueryInterface(m_mockChannel);
1753       NS_ASSERTION(request, "no request");
1754       if (request) {
1755         nsresult status;
1756         request->GetStatus(&status);
1757         rv = m_channelListener->OnStopRequest(request, m_channelContext, status);

This OnStopRequest() is invoked with NS_OK even if network connection is lost, and then the target message is deleted.

I am not really convinced this fix has no side-effect, need feedback.

Comment 11

[Hiroyuki Ikezoe (:hiro)]

Attachment: Test

I've managed to write an xpcshell test. This test can not work without the patch I will attach here soon.

Comment 12

[Hiroyuki Ikezoe (:hiro)]

Attachment: Call OnProgress to interruput moving message

Current implementation does not call OnProgress for nsIMsgCopyServiceListener, so the test can not be interrupted while moving the message.

This patch does invoke OnProgress while moving the message.

Comment 13

[Hiroyuki Ikezoe (:hiro)]

Try server results:
http://build.mozillamessaging.com/tinderboxpushlog/?tree=ThunderbirdTry&rev=6c29ddf6adc0

Comment 14

[David :Bienvenu]

Comment on attachment 616486 [details] [diff] [review]
Call OnProgress to interruput moving message

This code doesn't get hit in many situations; the only one I could find was copying a single displayed imap message that's not in the offline store. So it's relatively harmless.

Comment 15

[David :Bienvenu]

Comment on attachment 616485 [details] [diff] [review]
Test

I don't think there's any reason for "CUSTOM1" in this line:

+setupIMAPPump("CUSTOM1");

I suspect it was just from the test you started with. If so, then it should just be
setupIMAPPump();

Comment 16

[David :Bienvenu]

Comment on attachment 615640 [details] [diff] [review]
Possible fix

Thx very much for looking into this.
This looks reasonable. But I think it might be better to do something like this:

request->GetStatus(&status);
if (!GetServerStateParser().LastCommandSuccessful() && NS_SUCCEEDED(status))
  status = NS_MSG_ERROR_IMAP_COMMAND_FAILED;

so if we do get an error status back from the request, we pass that on to onstoprequest.

Comment 17

[Hiroyuki Ikezoe (:hiro)]

Attachment: Test

Fixed argument of setupIMAPPump.

Carrying over review+.

Comment 18

[Hiroyuki Ikezoe (:hiro)]

Attachment: Address david's comment

> 
> request->GetStatus(&status);
> if (!GetServerStateParser().LastCommandSuccessful() && NS_SUCCEEDED(status))
>   status = NS_MSG_ERROR_IMAP_COMMAND_FAILED;
> 
> so if we do get an error status back from the request, we pass that on to
> onstoprequest.

Right!

Comment 19

[David :Bienvenu]

Comment on attachment 621770 [details] [diff] [review]
Address david's comment

looks good, thx again for the patch!

Comment 20

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/comm-central/rev/f1233b5ea136
https://hg.mozilla.org/comm-central/rev/3292204063fa
https://hg.mozilla.org/comm-central/rev/e26534f1bce5