856519 - "Multiple mail Copy/Move from AnyStore/IMAP/Offline-Use=Off to MaildirStore/pop3_or_none" moves only "Target\tmp\nnn of last mail" to cur\nnn, so produces empty DIRECTORY in Target\cur except for last mail, and if Move, mails are deleted from IMAP folder

Status: NEW

(MailNews Core :: Networking: IMAP, defect)

Description

[WADA:World Anti-bad-Duping Agency]

[Build ID]
> Mozilla/5.0 (Windows NT 5.1; rv:22.0) Gecko/20100101 Thunderbird/22.0a1
> Application Build ID : 20130325031104

Multiple mail Copy/Move from maildirstore/IMAP/Offline-Use=Off to maildirstore/Local Folders generates empty DIRECTORY in Target\cur except for last mail, and if Move, mails are deleted from Source folder even though Move is not executed normally.

[Steps to reproduce]
(1) In maildirstore/IMAP account, copy mails to Offline-Use=Off folder
(2) Move(or Copy) multiple mails to foldr of maildirstore/Local Folders(type=none).


Followwing is dump data of some properties of msgDBHdr. 
 (1) Copy/Move Source folder : maildirstore, IMAP, Offline-Use=Off
    Gmail IMAP is used.
    To avoid data retrieve from offline-store file of Special Folders,
    Offline-Use setting of all Special folders is Off.
> Mbox=Offline-Use-Offline : prettiestName = Offline-Use-Offline, expungedBytes = 0, sizeOnDisk = 8224, All_isSpecialFolder = ( Mail,Elided,ImapBox,ImapPersonal )
> messageKey = 6, messageOffset = 6, messageSize = 2741, offlineMessageSize = 0, date = 1364793076000000, dateInSeconds = 1364793076, StringProperty = { pendingRemoval=, X-GM-MSGID=1431089271085394190 }, flags = 1, flag_Detail = { FeedMsg = false, IMAPDeleted = false, Read = true, Replied = false, Marked = false, Expunged = false, HasRe = false, Elided = false, Offline = false, Watched = false, SenderAuthed = false, Partial = false, Queued = false, Forwarded = false, Priorities = false, New = false, Ignored = false, MDNReportNeeded = false, MDNReportSent = false, Template = false, Attachment = false, Labels = false, RuntimeOnly = false }, messageId = [e-mail], mime2DecodedSubject = maildir-001
> messageKey = 7, messageOffset = 7, messageSize = 2743, offlineMessageSize = 0, date = 1364793126000000, dateInSeconds = 1364793126, StringProperty = { pendingRemoval=, X-GM-MSGID=1431089320787624018 }, flags = 1, flag_Detail = { FeedMsg = false, IMAPDeleted = false, Read = true, Replied = false, Marked = false, Expunged = false, HasRe = false, Elided = false, Offline = false, Watched = false, SenderAuthed = false, Partial = false, Queued = false, Forwarded = false, Priorities = false, New = false, Ignored = false, MDNReportNeeded = false, MDNReportSent = false, Template = false, Attachment = false, Labels = false, RuntimeOnly = false }, messageId = [e-mail], mime2DecodedSubject = maildir-002
> messageKey = 8, messageOffset = 8, messageSize = 2740, offlineMessageSize = 0, date = 1364793152000000, dateInSeconds = 1364793152, StringProperty = { pendingRemoval=, X-GM-MSGID=1431089348113939216 }, flags = 1, flag_Detail = { FeedMsg = false, IMAPDeleted = false, Read = true, Replied = false, Marked = false, Expunged = false, HasRe = false, Elided = false, Offline = false, Watched = false, SenderAuthed = false, Partial = false, Queued = false, Forwarded = false, Priorities = false, New = false, Ignored = false, MDNReportNeeded = false, MDNReportSent = false, Template = false, Attachment = false, Labels = false, RuntimeOnly = false }, messageId = [e-mail], mime2DecodedSubject = maildir-003

(2) Copy/Move Target folder : maildirstore, Local Folders(type=none)
    Because Copy/Move Source folder is Offline-Use=Off,
    mail data is fetched from IMAP server. 
> Mbox=Test : prettiestName = Test, expungedBytes = 55589, sizeOnDisk = 0, All_isSpecialFolder = ( Mail )
> messageKey = 1, messageOffset = 0, messageSize = 2927, offlineMessageSize = 0, date = 1364793076000000, dateInSeconds = 1364793076, StringProperty = { pendingRemoval=, X-GM-MSGID=1431089271085394190, storeToken=1364794315648000 }, flags = 1, flag_Detail = { FeedMsg = false, IMAPDeleted = false, Read = true, Replied = false, Marked = false, Expunged = false, HasRe = false, Elided = false, Offline = false, Watched = false, SenderAuthed = false, Partial = false, Queued = false, Forwarded = false, Priorities = false, New = false, Ignored = false, MDNReportNeeded = false, MDNReportSent = false, Template = false, Attachment = false, Labels = false, RuntimeOnly = false }, messageId = [e-mail], mime2DecodedSubject = maildir-001
> messageKey = 2, messageOffset = 0, messageSize = 2929, offlineMessageSize = 0, date = 1364793126000000, dateInSeconds = 1364793126, StringProperty = { pendingRemoval=, X-GM-MSGID=1431089320787624018, storeToken=1364794315664000 }, flags = 1, flag_Detail = { FeedMsg = false, IMAPDeleted = false, Read = true, Replied = false, Marked = false, Expunged = false, HasRe = false, Elided = false, Offline = false, Watched = false, SenderAuthed = false, Partial = false, Queued = false, Forwarded = false, Priorities = false, New = false, Ignored = false, MDNReportNeeded = false, MDNReportSent = false, Template = false, Attachment = false, Labels = false, RuntimeOnly = false }, messageId = [e-mail], mime2DecodedSubject = maildir-002
> messageKey = 3, messageOffset = 0, messageSize = 2926, offlineMessageSize = 0, date = 1364793152000000, dateInSeconds = 1364793152, StringProperty = { pendingRemoval=, X-GM-MSGID=1431089348113939216, storeToken=1364794315680000 }, flags = 1, flag_Detail = { FeedMsg = false, IMAPDeleted = false, Read = true, Replied = false, Marked = false, Expunged = false, HasRe = false, Elided = false, Offline = false, Watched = false, SenderAuthed = false, Partial = false, Queued = false, Forwarded = false, Priorities = false, New = false, Ignored = false, MDNReportNeeded = false, MDNReportSent = false, Template = false, Attachment = false, Labels = false, RuntimeOnly = false }, messageId = [e-mail], mime2DecodedSubject = maildir-003

Dirctory listing of TargetFolder\cur
> C:\Documents and Settings ... \Mail\Local Folders\Test\cur\
>  4/01/13   2:32p           0  -D---  1364794315648000    <== mail #1, messageKey = 1
>  4/01/13   2:32p           0  -D---  1364794315664000    <== mail #2, messageKey = 2
>  4/01/13   2:31p        2930  A----  1364794315680000    <== mail #3, messageKey = 3

Comment 1

[WADA:World Anti-bad-Duping Agency]

Mail data file for mail #1 and mail #2 was found in Mbox/tmp.
Pheomenon was;
- Because of Copy, msgDBHdr is copyed from Source folder.
- Because Source folder is IMAP Offline-Use=Off,
  mail is normally fetched to maildir/local folder's Target/tmp/nnnn.
- After normal end of "uid aa:bb fetch body[]" command,
  only last mail #3 is moved from Target/tmp/nnnn to Target/cur/nnnn.
- Then, bug 856387 occurs.
  Because Target/cur/nnnn-mail-#1 and nnnn-mail-#2 doesn't exists,
  empty directory of Target/cur/nnnn-mail-#1, nnn-mail-#2 is generated.

Comment 2

[WADA:World Anti-bad-Duping Agency]

Because Tb doesn't check return code, state etc. sufficiently during fetch/copy/move processes, Tb wrongly considers "move mail data from IMAP folder to local folder is successful", thus Tb issues "uid a:b +Flags \Deleted" at IMAP MoveSource folder.

Comment 3

[WADA:World Anti-bad-Duping Agency]

"Move mail data from IMAP to Local(Maildir)" ==
    "Copy mail from IMAP to Local(fetch from server to Local)" phase
  + "Delete from IMAP Mbox" phase, 
(a) In Copy phase ;
BerkleyStore or MaildirStore of "move source folder" is irrelevant when "move source folder" is IMAP/Offline-Use=Off folder, because mail data is fetched from IMAP server to Local file.
(b) In Delete phase ;
BerkleyStore or MaildirStore of "move source folder" is irrelevant when "move source folder" is IMAP/Offline-Use=Off folder, because mail data is simply deleted from server's Mbox by "uid xx fstore +Flags \Deleted".
(If Maildirstore/IMAP/Offline-Use=On, cur/nnnnnn file is relevant to problem, so different problem may occur)

So, this bug occurs in;
  Move mails
  from any msgstore / IMAP / Offline-Use=Off folder
    to MaildirStore / Mbox where cur and tmp directory is used.
  cur and tmp is used by;
    MaildirStore / type=none == folder of Local Folders
    MaildirStore / type=pop3 == folder of POP3 account
    MaildirStore / type=imap / Offline-Use=On folder of IMAP.

Comment 4

[WADA:World Anti-bad-Duping Agency]

Copy/Move mails
  from any msgstore / IMAP / Offline-Use=Off folder
    to MaildirStore / type=imap / Offline-Use=On folder of IMAP
was dfferent, although similar.
(1) Copy/Move 3 mails.
    If move, mails are deleted at thread pane of Source.
(2) One empty DIRECTORY of Target/cur/nnnn_0 is created.
    No file is created in Target/tmp/.
(3) Click Targeet folder(folder open) 
    => Three Target/cur/nnnn_1, nnnn_2, nnnn_3 file are created.
       Content is correct mail data.
It looks;
  (2) is by Online Copy/Move step, but IMAP fetch command is not issued.
  Instead, only last mail only is copied, and Source/cur/nnnn_0
  doesn't exist, empty Source/cur/nnnn_0 is created.
  By folder open, auto-sync is invoked, and 3 mails are fetched.
This "empty Target/cur/nnnn_0 directory" in step (2) was sometimes not observed. I don't know why difference occurs. 
 .

Comment 5

[Kent James (:rkent)]

With current trunk, I can reproduce what I think is still this bug, though changed due to our work last summer. When IMAP folder offlineuse = NO, when you copy multiple messages from the imap folder to a local maildir directory, only the last message succeeds. The other messages end up in the tmp directory.

What is happening is that FinishNewMessage must be called on the msg store to cause the msg to move from tmp to cur. This is triggered by OnStopRequest. But the IMAP protocol can copy more than one message with a single request, so OnStopRequest is only getting called for the last message.

FinishNewMessage should really be called in nsMsgLocalMailFolder::EndMessage not in ::EndCopy.

Comment 6

[Kent James (:rkent)]

Attachment: Do FinishNewMessage in EndMessage

The main fix is to call FinishNewMessage in EndMessage when it is active.

But the underlying copy code seems to me to be quite inconsistent. The functionality in EndMessage is largely duplicated in EndCopy, because in some cases EndMessage is not used. In the long run we should really change those to be more consistent. At the least I had to add a method of communicating to EndCopy that the file stream has been processed, which I do by nulling it (similar to the way that the existing code handles newHdr).

In passing, because I had to mess with EndCopy, I just had to fix the duplicated code that causes AFAICT bug 677853. I expect that bug will also be fixed when this patch lands.

Comment 7

[Kent James (:rkent)]

This patch was done on top of the fixes for bug 1113275 so you probably need to apply the current patches from there before testing this bug.

Comment 9

[:Irving Reid (No longer working on Firefox)]

Comment on attachment 8543244 [details] [diff] [review]
Do FinishNewMessage in EndMessage

Review of attachment 8543244 [details] [diff] [review]:
-----------------------------------------------------------------

Love the test, and the code looks good except that I'd like a bit more clarity on the XXX ToDo comment before we go forward. Is that problem always there, whether or not your patch is applied?

::: mailnews/imap/test/unit/test_multipleCopyNonlocal.js
@@ +8,5 @@
> + */
> +
> +var Cu = Components.utils;
> + 
> +// async support 

Several trailing white spaces in this file

::: mailnews/local/src/nsLocalMailFolder.cpp
@@ +2006,5 @@
>    nsCOMPtr <nsISeekableStream> seekableStream = do_QueryInterface(mCopyState->m_fileStream, &rv);
> +
> +  //  XXX ToDo: When copying multiple messages from a non-offline-enabled IMAP
> +  //  server, this fails. We should not be warning on an expected error.
> +  //  Perhaps there are unexpected consequences of returning early?

Eek, this sounds like something that needs to be looked into - I wonder if it's related to the multiple message copy bugs like bug 815012 (regression caused by bug 769346, which is being revisited in the currently active bug 1116055)

@@ +2240,5 @@
> +  // mCopyState->m_fileStream to null since it is no longer needed, and detect
> +  // here the null stream so we know that we don't have to close it here.
> +  //
> +  // Similarly, m_parseMsgState->GetNewMsgHdr() returns a null hdr if the hdr
> +  // has already been processed by EndMessage so it is not doubly added here.

Boy, do I ever hate that we don't *always* do all the "we're at the end of a message" processing in EndMessage(). Is it too much scope creep to make it consistent in this bug? If you can't fix it here, please file a new bug about cleaning it up.

Comment 10

[Kent James (:rkent)]

(In reply to :Irving Reid (No longer working on Firefox) from comment #9)
> Comment on attachment 8543244 [details] [diff] [review]
> Do FinishNewMessage in EndMessage
> 
> Review of attachment 8543244 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Love the test, and the code looks good except that I'd like a bit more
> clarity on the XXX ToDo comment before we go forward. Is that problem always
> there, whether or not your patch is applied?

If I simply add this test to current trunk, then yes it still fails at the same spot with the warning.

The issue is part of the whole issue of whether we do message processing in the ...Copy or the ...Message methods. When we are doing multiple message downloads from a single IMAP url, which is what is tested in the patch, then the BeginCopy method is being called before the message is setup, so the fileStream does not yet exist and we get the warning. It will get created in a subsequent StartMessage() call (through InitCopyMsgHdrAndFileStream). It all seems to work, but there is the spurious warning created, hence the comment. I did investigate is more, so I'll modify the comment to reflect my current understanding.

> 
> ::: mailnews/local/src/nsLocalMailFolder.cpp
> @@ +2006,5 @@
> >    nsCOMPtr <nsISeekableStream> seekableStream = do_QueryInterface(mCopyState->m_fileStream, &rv);
> > +
> > +  //  XXX ToDo: When copying multiple messages from a non-offline-enabled IMAP
> > +  //  server, this fails. We should not be warning on an expected error.
> > +  //  Perhaps there are unexpected consequences of returning early?
> 
> Eek, this sounds like something that needs to be looked into - I wonder if
> it's related to the multiple message copy bugs like bug 815012 (regression
> caused by bug 769346, which is being revisited in the currently active bug
> 1116055)

Regressions are happening because this is very confusing, with many special cases all using the code in slightly different, poorly documented ways. I would love to clean it all up, making the message processing all happen in ...Message calls. But I fear if I do that I will create a new string of regressions. I think that is beyond the scope of what I am doing at the moment, which is trying very hard to get maildir usable for TB 38.

So this is what we need to do I agree:

> Boy, do I ever hate that we don't *always* do all the "we're at the end of a
> message" processing in EndMessage(). Is it too much scope creep to make it
> consistent in this bug? If you can't fix it here, please file a new bug
> about cleaning it up.

but I don't really want to to it as part of this bug. And yes that would be a great time to add the buffering as well.

I'm not really agreeing to take on much more than is in the patch, since my focus is narrowly on maildir. So I'll cleanup what is there and submit it again.

Comment 11

[Kent James (:rkent)]

I filed bug 1118132 requesting cleanup of start/endMessage with begin/endCopy.

Comment 12

[Kent James (:rkent)]

Attachment: tweaks per review

I did not really change much from the previous patch, just comments and white space.

The big issue is how much rework to do now versus later. This copy code is very fragile, and as a result I am very reluctant to make too many changes when I don't have to. I'm already removing some duplicated code that was, per my analysis, mistakenly copied in a previous patch. But any other behavior change for the default mbox case scares me without really diving into this and doing a more extensive rework. I filed a bug as requested for that work.

So if this is not sufficient, could you please clarify what else needs to be done?

Comment 13

[:Irving Reid (No longer working on Firefox)]

Comment on attachment 8544398 [details] [diff] [review]
tweaks per review

Review of attachment 8544398 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good; I'm happy with your explanation, and with putting off further refactoring via the new bug you filed.

Comment 14

[Kent James (:rkent)]

Attachment: [CHECKED-IN] part 1 core changes (in nsMsgLocalFolder.cpp)

I divided the patch in two, one with the core changes and one with the test changes, because the test changes depend on the still-unresolved changes in bug 1113275. Carrying over r+ from irving.

Comment 15

[Kent James (:rkent)]

Attachment: Part 2, test changes

This patch only includes the test. I may revise the testing strategy to use a custom xpcshell.ini in bug 1113275 which would also affect this patch.

Comment 16

[WADA:World Anti-bad-Duping Agency]

Checked with trunk nightly.
> Mozilla/5.0 (Windows NT 5.1; rv:38.0) Gecko/20100101 Thunderbird/38.0a1

Copy 4 mails in Inbox of Gmail IMAP(MaildirStore, Offline-Use=Off) to FolderX of Local Folders(MaildirStore).
4 mails are normally copied to FolderX\cur directory of Local Folders.
Problem of this bug is aready resolved.

Comment 17

[WADA:World Anti-bad-Duping Agency]

Kent James (:rkent), can I close this bug?

Comment 18

[Kent James (:rkent)]

(In reply to WADA from comment #17)
> Kent James (:rkent), can I close this bug?

No, because I still need to land the test. I thought I would wait until after the pre-38 string freeze since this test not critical to that.