Last Comment Bug 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
: Message lost(at move source IMAP folder, \Deleted is stored)/corrupted(at mov...
Status: RESOLVED FIXED
: dataloss
Product: MailNews Core
Classification: Components
Component: Networking: IMAP (show other bugs)
: 9
: All All
: -- critical with 1 vote (vote)
: Thunderbird 15.0
Assigned To: Hiroyuki Ikezoe (:hiro)
:
:
Mentors:
: 742072 (view as bug list)
Depends on:
Blocks: 693353
  Show dependency treegraph
 
Reported: 2009-10-16 03:33 PDT by Rob Knight
Modified: 2014-02-07 06:10 PST (History)
9 users (show)
ryanvm: in‑testsuite+
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---


Attachments
IMAP log for test in comment #5(Tb 9 stores \Deleted flag even when connection error occurs while copying) (42.64 KB, text/plain)
2012-01-04 23:33 PST, WADA
no flags Details
Possible fix (1016 bytes, patch)
2012-04-17 03:03 PDT, Hiroyuki Ikezoe (:hiro)
mozilla: feedback+
Details | Diff | Splinter Review
Test (4.10 KB, patch)
2012-04-19 00:53 PDT, Hiroyuki Ikezoe (:hiro)
mozilla: review+
Details | Diff | Splinter Review
Call OnProgress to interruput moving message (1.44 KB, patch)
2012-04-19 00:56 PDT, Hiroyuki Ikezoe (:hiro)
mozilla: review+
Details | Diff | Splinter Review
Test (4.09 KB, patch)
2012-05-07 15:56 PDT, Hiroyuki Ikezoe (:hiro)
hiikezoe: review+
Details | Diff | Splinter Review
Address david's comment (1.13 KB, patch)
2012-05-07 15:58 PDT, Hiroyuki Ikezoe (:hiro)
mozilla: review+
Details | Diff | Splinter Review

Description Rob Knight 2009-10-16 03:33:18 PDT
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] 2009-10-19 00:08:18 PDT
Rob, you use pop3?
Comment 2 Rob Knight 2009-10-19 03:47:35 PDT
Hi Aureliano, I'm using IMAP (port 993, SSL).
Comment 3 Wayne Mery (:wsmwk, NI for questions) 2009-12-01 05:31:31 PST
(proper severity)
Comment 4 Wayne Mery (:wsmwk, NI for questions) 2012-01-02 16:10:42 PST
bienvenu, would you expect this to not happen in a current version?
Comment 5 WADA 2012-01-04 23:30:19 PST
(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 2012-01-04 23:33:36 PST
Created attachment 585987 [details]
IMAP log for test in comment #5(Tb 9 stores \Deleted flag even when connection error occurs while copying)
Comment 7 WADA 2012-01-05 15:23:16 PST
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) 2012-04-12 23:53:34 PDT
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) 2012-04-17 03:03:12 PDT
Created attachment 615640 [details] [diff] [review]
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 10 Hiroyuki Ikezoe (:hiro) 2012-04-17 15:48:29 PDT
*** Bug 742072 has been marked as a duplicate of this bug. ***
Comment 11 Hiroyuki Ikezoe (:hiro) 2012-04-19 00:53:46 PDT
Created attachment 616485 [details] [diff] [review]
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) 2012-04-19 00:56:06 PDT
Created attachment 616486 [details] [diff] [review]
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) 2012-04-19 19:46:48 PDT
Try server results:
http://build.mozillamessaging.com/tinderboxpushlog/?tree=ThunderbirdTry&rev=6c29ddf6adc0
Comment 14 David :Bienvenu 2012-05-03 09:01:15 PDT
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 2012-05-03 09:03:38 PDT
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 2012-05-03 09:50:03 PDT
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) 2012-05-07 15:56:47 PDT
Created attachment 621768 [details] [diff] [review]
Test

Fixed argument of setupIMAPPump.

Carrying over review+.
Comment 18 Hiroyuki Ikezoe (:hiro) 2012-05-07 15:58:48 PDT
Created attachment 621770 [details] [diff] [review]
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 2012-05-07 16:00:40 PDT
Comment on attachment 621770 [details] [diff] [review]
Address david's comment

looks good, thx again for the patch!
Comment 21 beanladen 2012-09-20 00:17:31 PDT
*** Bug 792198 has been marked as a duplicate of this bug. ***

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