Open Bug 764662 Opened 12 years ago Updated 2 years ago

"2048 bytes of message body(or entire message body if less than 2048 bytes) by FETCH BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data by FETCH BODY[] for mail view" is writen to IMAP offline-store file, and it is not marked as "wrong"

Categories

(MailNews Core :: Networking: IMAP, defect)

x86
All
defect
Not set
critical

Tracking

(Not tracked)

People

(Reporter: ronan.jouchet, Unassigned)

References

(Depends on 1 open bug, Blocks 1 open bug)

Details

(Keywords: dataloss, Whiteboard: [will be duped after analysis, to crisp bug 823838 for bug fixing])

Attachments

(4 files)

Attached image example of email corruption —
Thunderbird frequently corrupts my email, by mangling together several emails. To quantify 'frequently', I'd say it happens once or twice a week. I am very unsure of what causes the behavior or since when I have it.

The attached example (PNG, 400kB) shows an example of such a corruption:
1. In the 'All Mail' folder, an Eclipse mailing-list email is displayed as expected
2. This email is also in my inbox, but when I view it from the 'Inbox' view, the email is corrupted in multiple ways:
   a. the header is absent
   b. 3 lines at the top of the email have been truncated
   c. another email has been 'plain-text-appended' at the end (the email being appended is also in my inbox and in my all mail folder, as shown by the screenshot)

I'm all yours to provide debug info and help on the resolution, here and on IRC.

Platform info:
* Tb 13.0 (official Mozilla .tar.bz2, not from any repository), Ubuntu 12.04 x86_64
* Addons: Lightning 1.5, French dictionary, Evolution Mirror 0.2.3
* GMail IMAP
Note that other mail clients (I tested the official GMail web client and the iPad 'Mail' app) properly read the mail in both folders.
Does it happen on new received messages?
Have you been using any TB 12 betas?
Are you using any filters that move the affected messages into other folders?
HOw does the All Mail folder work? Is it a folder for all messages and the Inbox is a "filter/view" of it showing only received messages?
When you see the corrupted message (if you have any non-private one), export it as EML please and attach to this bug.
Ronan ??
Whiteboard: [closeme 2012-07-08]
Hello again and sorry for the delay.

- Does it happen on new received messages?
  Yes.
- Have you been using any TB 12 betas?
  No, I only use the release channel.
- Are you using any filters that move the affected messages into other folders?
  No, I only have 4 filters and they just perform tagging actions
- How does the All Mail folder work? Is it a folder for all messages and the Inbox is a "filter/view" of it showing only received messages?
  I don't know, I guess it's the standard GMail way to do folders and IMAP. Anyway, I didn't do any specific setup, I just declared my IMAP account and am using the resulting structure. Does that answer the question?
- When you see the corrupted message (if you have any non-private one), export it as EML please and attach to this bug.
  Will do once I have one. (Un)fortunately, none happened in the last two weeks. Which spoils my "once or twice a week" initial estimation, I know, but I maintain it definitely got to that frequency at some point in the past.

Feel free to close the bug on 2012-07-08, or even right now. I know where it is and will re-open it if I can reproduce it again and can provide a EML export. Thanks for the followup :)
I got a non-private example, I'm attaching .eml exports here. First part:
 - example-email1-notmangled.eml: email1 (from "kijiji", about an Apple wireless keyboard I'm selling), not mangled, found in my All Mail folder
I got a non-private example, I'm attaching .eml exports here. Second part:
 - example-email2-notmangled.eml: unfortunately I deleted that one without thinking it could be useful here, that was an ad from Apple
 - example-email1+2-mangled.eml: the mangled thing, found in my Inbox
Tell me if those attachments are complete enough to try to understand the bug. I can provide more info as needed (e.g. here I only provided 1notmangled and 1+2mangled, not 2notmangled), or additional platform details.
Whiteboard: [closeme 2012-07-08]
(In reply to Ronan Jouchet from comment #6)
> Created attachment 642244 [details]
> email1+2, mangled, found in Inbox folder

"first 2048 bytes of mail payload(data after null line)" + "full message data".
Same pattern as bug 587528. (see also bugs in dependency tree)
Setting dependency for ease of tracking.
Confirming per attached mail data.

Is Inbox offline-use=On folder? (Folder properties/Synchronization)
Did you view the mail in Inbox just after arrival of the mail?
Status: UNCONFIRMED → NEW
Component: General → Networking: IMAP
Depends on: 587528
Ever confirmed: true
Product: Thunderbird → MailNews Core
Hi, great to read that. Regarding your questions:
1. Is Inbox offline-use=On folder? (Folder properties/Synchronization)
   -> Yes.
2. Did you view the mail in Inbox just after arrival of the mail?
   -> I'm unsure what to answer, maybe. Anyway, yes I always check my mail from the Inbox folder. A typical use case might be: launch Thunderbird, see a few emails popping in Inbox, and read them immediately and sequentially. But can you precise what "just after arrival of the mail" means?
(In reply to Ronan Jouchet from comment #9)
> But can you precise what "just after arrival of the mail" means?

(i) after fetch headers of the new mail by Tb, and (ii) before/while  fetch(download) of whole message data to offline-store file by auto-syc.
i.e. You interferered (ii) of Tb on newly arrived mails by your new mail viewing, or not.
That could be the case, yes. Is there a way for me to confirm that? (i.e. how can I know when the fetching of the whole message starts and ends?)
Keywords: testcase
(In reply to Ronan Jouchet from comment #6)
> Created attachment 642244 [details]
> email1+2, mangled, found in Inbox folder

Your case is;
   (a) first 2048 bytes of mail payload(data after null line) of mail-A(UID=aaa)
       boundary line : ------=_Part_953_343929067.1342042409410
 + (b) full message data of of mail-B(UID=bbb)
       Subject: Buy the new iPad for university. Get $50 for apps.
       boundary line : ------=_Part_42097070_292757810.1342044286379

Which mail's Subject/From/To is shown at Thread pane for this mail?
What is UID of each mail? (If IMAP, "Order Received" column value is UID of mail)
How many mails arrived at same time when the mail of UID=aaa & UID=bbb arrived?

For my "just after arrival of the mail".
  after message headers of the new mails are fetched,
  before eintire mail data of new mails are fetched by auto-sync and saved in
  offline-store file(Inbox instead of Inbox.msf if folder named Inbox). 

It looks following.
(1) UID=101 and UID=102 arrives at same time
(2) uid fetch 101-102 for message headers is executed
(3) Tb fetches 2KB of UID=101(uid fetch 101 body[].2048) for internal preview
(4) Click UID=102 then Tb issues uid fetch 102 body[]
(5) Data by (3) & data by (4) is written as mail data for UID=101 or UID=102

Can you get IMAP log(with timestamp) in your environment for situation like above, by sending several mails to you at same time?
 - Compose HTML mail, Option/Format/HTML and Plain Text, Send Later, for mails
 - Send Unsent Messages at Outbox of Local Folders
See bug 402793 comment #28 for getting log.
No need of "log when problem occurs". Normal flow is sufficient for first analysis. Remove private data from log file, and remove mail data lines to reduce log file size, please.

By the way, recovery is easy if Gmail IMAP.
  (1) Add a tag to the corrupted mail at Inbox
  (2) Shift+Delete the mail at Inbox(Gmail Label of Inbox is removed),
      and execute Compact to surely remove the mail from Inbox 
  (3) At [Gmail]/All Mail, search the tagged mail, and copy it to Inbox
(In reply to WADA from comment #12)
> Which mail's Subject/From/To is shown at Thread pane for this mail?
> What is UID of each mail? (If IMAP, "Order Received" column value is UID of
> mail)
> How many mails arrived at same time when the mail of UID=aaa & UID=bbb
> arrived?
Sorry, I'm unable to answer answer those questions because, apart from the eml exports provided here, I no longer have thoe emails in my mailbox.

> Can you get IMAP log(with timestamp) in your environment for situation like
> above, by sending several mails to you at same time?
>  - Compose HTML mail, Option/Format/HTML and Plain Text, Send Later, for
> mails
>  - Send Unsent Messages at Outbox of Local Folders
> See bug 402793 comment #28 for getting log.
> No need of "log when problem occurs". Normal flow is sufficient for first
> analysis. Remove private data from log file, and remove mail data lines to
> reduce log file size, please.
I am unable to produce a log. I followed bug 402793 comment #28 and the MailNews:Logging wiki page:
 1. Quit Tb
 2. run ronj@s:~$ export NSPR_LOG_MODULES=timestamp,imap:5,smtp:5 && touch /tmp/imap.log && export NSPR_LOG_FILE=/tmp/imap.log
 3. Run Tb, perform the test scenario
 4. Shutdown Tb so that the buffered log is written to disk
--> /tmp/imap.log is still empty

Assistance welcome to help me generate the log... :-/
In step 3, did you start TB from the command line, from the same shell where you put commands 1 & 2?
Duh :D . Thanks :aceman, that works beeeeeeeetter.

Here you are, good sirs. 183kB log for sending 5 mails at the same time with (replace "n" in the subject/body with 1,2,3,4,5) :
  subject = "test for tb / n"
  body = "test <b><u>for tb</b></u> / n"
https://dl.dropbox.com/u/368761/bugreport/BZ764662-ThunderbirdCorruptsEmails_imap.log

I'm putting this on Dropbox and not as an attachment because I'm not sure I properly cleaned it up (actually apart from mountains of useless FETCHes removed at line 391 I didn't alter anything, my email and name are here, that's fine with me, anything else?), and/or if it contains the information you expect.
--> If there's a screwup, please tell me to remove it, else feel free to properly attach it to the bug.
Attached file Imap log —
Atul can you have a look at that imap log ?
(In reply to Ludovic Hirlimann [:Usul] from comment #16)
> Created attachment 666939 [details]
> Imap log

(1)  UID=31730,31731 arrived, then fetch major header data
> 2012-08-31 03:15:50.643394 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:SendData: 18 UID fetch 31730:31731 (UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type reply-to)])
> 2012-08-31 03:15:50.935187 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: * 4 FETCH (UID 31730 RFC822.SIZE 1367 FLAGS () BODY[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type reply-to)] {276}
> 2012-08-31 03:15:50.935367 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:OPEN Size: 1367: Begin Message Download Stream
> 2012-08-31 03:15:50.935656 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
> 2012-08-31 03:15:50.935687 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: * 5 FETCH (UID 31731 RFC822.SIZE 1370 FLAGS () BODY[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type reply-to)] {276}
> 2012-08-31 03:15:50.935824 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:OPEN Size: 1370: Begin Message Download Stream
> 2012-08-31 03:15:50.936121 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
> 2012-08-31 03:15:50.956618 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: 18 OK Success

(2) After (1), following requests are queued 
> 2012-08-31 03:15:50.965839 UTC - -1453185216[7fb3a8350480]: queuing url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.965853 UTC - -1453185216[7fb3a8350480]: considering playing queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.965860 UTC - -1453185216[7fb3a8350480]: creating protocol instance to play queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.965923 UTC - -1453185216[7fb3a8350480]: failed creating protocol instance to play queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.967862 UTC - -1453185216[7fb3a8350480]: queuing url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/previewBody>UID>/INBOX>31730>2048
> 2012-08-31 03:15:50.967874 UTC - -1453185216[7fb3a8350480]: considering playing queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.967881 UTC - -1453185216[7fb3a8350480]: creating protocol instance to play queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.967944 UTC - -1453185216[7fb3a8350480]: failed creating protocol instance to play queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.969517 UTC - -1453185216[7fb3a8350480]: considering playing queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.969533 UTC - -1453185216[7fb3a8350480]: creating protocol instance to play queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731
> 2012-08-31 03:15:50.969615 UTC - -1453185216[7fb3a8350480]: playing queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/fetch>UID>/INBOX>31730,31731

(3) Fetch BODY[] is requested for UID=31730,31731, and entire mail data of both mails is successfully downloaded.
> 2012-08-31 03:15:50.969724 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:ProcessCurrentURL: entering
> 2012-08-31 03:15:50.969738 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:ProcessCurrentURL:imap://ronan%2Ejouchet%40gmail%2Ecom@imap.googlemail.com:993/fetch%3EUID%3E/INBOX%3E31730,31731:  = currentUrl
> 2012-08-31 03:15:50.969968 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:SendData: 19 UID fetch 31730,31731 (UID RFC822.SIZE BODY.PEEK[])
> 2012-08-31 03:15:51.213947 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: * 4 FETCH (UID 31730 RFC822.SIZE 1367 BODY[] {1367}
> 2012-08-31 03:15:51.214277 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:OPEN Size: 1367: Begin Message Download Stream
> 2012-08-31 03:15:51.216375 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
> 2012-08-31 03:15:51.321751 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: * 5 FETCH (UID 31731 RFC822.SIZE 1370 BODY[] {1370}
> 2012-08-31 03:15:51.328017 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
> 2012-08-31 03:15:51.396281 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: 19 OK Success

(4) Even though BODY[](entire message) was already fetched normally,
    BODY.PEEK[TEXT]<0.2048> for UID=31730 is seen.
> 2012-08-31 03:15:51.404894 UTC - -1453185216[7fb3a8350480]: considering playing queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/previewBody>UID>/INBOX>31730>2048
> 2012-08-31 03:15:51.404933 UTC - -1453185216[7fb3a8350480]: creating protocol instance to play queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/previewBody>UID>/INBOX>31730>2048
> 2012-08-31 03:15:51.405187 UTC - -1453185216[7fb3a8350480]: playing queued url:imap://ronan.jouchet@gmail.com@imap.googlemail.com:993/previewBody>UID>/INBOX>31730>2048
> 2012-08-31 03:15:51.405506 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:ProcessCurrentURL: entering
> 2012-08-31 03:15:51.405543 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:ProcessCurrentURL:imap://ronan%2Ejouchet%40gmail%2Ecom@imap.googlemail.com:993/previewBody%3EUID%3E/INBOX%3E31730%3E2048:  = currentUrl
> 2012-08-31 03:15:51.406248 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:SendData: 20 UID fetch 31730 (UID BODY.PEEK[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)] BODY.PEEK[TEXT]<0.2048>)
> 2012-08-31 03:15:51.822780 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: * 4 FETCH (UID 31730 BODY[TEXT]<0> {651}
> 2012-08-31 03:15:51.823088 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:OPEN Size: 0: Begin Message Download Stream
> 2012-08-31 03:15:51.824115 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket:  BODY[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)] {90}
> 2012-08-31 03:15:51.824133 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:OPEN Size: 0: Begin Message Download Stream
> 2012-08-31 03:15:51.824253 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
> 2012-08-31 03:15:51.840795 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: * 6 EXISTS
> 2012-08-31 03:15:51.840845 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: 20 OK Success

Tb requests "BODY.PEEK[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)]" and "BODY.PEEK[TEXT]<0.2048>"
Server returns data for "BODY.PEEK[TEXT]<0.2048>" first, "BODY.PEEK[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)]" second.
This may be relevant to problem.

Note: 
BODY.PEEK[TEXT]<0.2048> is seen for UID=31730 and for UID=31732(newly arrived mail after fetch of UID=31730,31731) only in log file.

This "BODY.PEEK[TEXT]<0.2048>" was seen in my test for other similar bug.
Because "top part of corrupted mail data" is always "first 2048 bytes of message body text"(or entire message body text if message body is shorter than 2048 bytes), I believe this "BODY.PEEK[TEXT]<0.2048> for previewBody" is relevant to problem.
Summary: Thunderbird corrupts emails by mangling them together → Thunderbird corrupts emails by mangling them together("2048 bytes by BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data" is writen to IMAP offline-store file)
"previewBody" came from mail.biff.alert.show_preview.

(1) previewBody is requested at.
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#1451
>  urlSpec.Append("/previewBody>");
It's in NS_IMETHODIMP nsImapService::GetBodyStart(nsIMsgFolder *aImapMailFolder, ...
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#1427
(2) GetBodyStart is requested by;
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapMailFolder.cpp#9296
It's in NS_IMETHODIMP nsImapMailFolder::FetchMsgPreviewText(nsMsgKey ...)
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapMailFolder.cpp#9218
(3) FetchMsgPreviewText is called at;
> http://mxr.mozilla.org/comm-central/source/mail/base/content/mailWidgets.xml#2559
(4) FetchMsgPreviewText is called when showPreviewText==true.
(5) showPreviewText is set from mail.biff.alert.show_preview.
> http://mxr.mozilla.org/comm-central/source/mail/base/content/mailWidgets.xml#2520
> 2520 var showPreviewText = pref.getBoolPref("mail.biff.alert.show_preview");
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapMailFolder.cpp#5297
> 5296 bool showPreviewText;
> 5297 prefBranch->GetBoolPref("mail.biff.alert.show_preview", &showPreviewText);
Mechanism may be as follows.
(1) New mails arrive, message headers are fetched, and new mails are recognized.
(2) Biff requests "previewBody" after step (1), then BODY.PEEK[TEXT]<0.2048> is issued.
(2) IMAP code issues FETCH BODY[].
    After a change, IMAP code writes mail data to offline-store upon first fetch,
    instead of "to Disk/Memory Cache" even if offline-use=On,
    instead of "by auo-sync invoked sooner or later".
(4) If (2) ad (3) happens at same time, data by (2) and data by (3) is merged by IMAP code.
Sorry, typo & wrong explanation.

(Revised) Mechanism may be as follows.
(1) New mails arrive, message headers are fetched, and new mails are recognized.
(2) Biff requests "previewBody" after step (1), then BODY.PEEK[TEXT]<0.2048> is issued.
(3) By new mail click at thread pane, IMAP code issues FETCH BODY[].
    This is executed before "FETCH BODY[] by auo-sync invoked sooner or later",
    because user requsted Tb to show mail before auto-sync.
    After a change, IMAP code writes mail data to offline-store upon first fetch,
    instead of "to Disk/Memory Cache even if offline-use=On".
(4) If (2) and (3) happens at same time, data by (2) and data by (3) is wrongly merged by IMAP code.
Revertig Dependency, as better data for problem analysis is provided in this bug.
Blocks: 587528
No longer depends on: 587528
(In reply to WADA from comment #22)
> [...] better data for problem analysis is provided in this bug.

Is there something I can do?
FYI.
"fetch to offline-store instead of Disk cache" was done by bug 531033 on Tb 3.1.7.
"Re-fetch is not invoked upon later mail click despite incorrect mail data length" is perhaps a result by changes like next.
- Don't rely on RFC822.SIZE upon writing to offlin-store, in order to bypass
  IMAP server's bug such as "incorrect RFC822.SIZE from MS Exchange server". 

(In reply to Ronan Jouchet from comment #23)
> Is there something I can do?

No action is need for that comment, because that was merely for swapping of "Depends on:" and "Blocks:" field value.

If you can see problem frequently, can you try mail.biff.alert.show_preview=false? (restart of Tb my be needed after option change)
(In addition to comment #18)

(5) For next set of new mails of UID=31732,31733,31734.
(5-a) FETCH BODY.PEEK[] is issued for UID=31732,31733,31734
> 2012-08-31 03:15:58.495071 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:SendData: 26 UID fetch 31732,31733:31734 (UID RFC822.SIZE BODY.PEEK[])
> 2012-08-31 03:15:58.964282 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: 26 OK Success
(5-b) then FTCH BODY.PEEK[TEXT]<0.2048> is issued for for UID=31732,31733,31734
7b1bf800:imap.googlemail.com:S-INBOX:SendData: 27 UID fetch 31732 (UID BODY.PEEK[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)] BODY.PEEK[TEXT]<0.2048>)
> 2012-08-31 03:15:59.405911 UTC - 2064643840[7fb384ce36a0]: 7b1bf800:imap.googlemail.com:S-INBOX:CreateNewLineFromSocket: 27 OK Success

Problem may be as follows.
(i)   FETCH BODY.PEEK[] for uid=aa,bb,...,nn,...zz
(ii)  FETCH for previewBody(BODY.PEEK[TEXT]<0.2048>) is queued.
(iii) while executing (i), user clicks a new mail of uid=nn,
      then FETCH BODY.PEEK[] for uid=nn is queued,
      and (i) is inturrupted and some of fetched data is discared.
(iv)  BODY.PEEK[TEXT]<0.2048> for uid=aa,bb,...,nn,...zz is executed.
(v)   just after (iv), FETCH BODY.PEEK[] for uid=nn is executed.
      execution of (iv) may be inturrupted.
(vi)  both "mail data by (iv) for a new mail" and "mail data by (v)" is written
      to IMAP offline-store file.
(In reply to WADA from comment #21)
> Sorry, typo & wrong explanation.
> 
> (Revised) Mechanism may be as follows.
> (1) New mails arrive, message headers are fetched, and new mails are
> recognized.
> (2) Biff requests "previewBody" after step (1), then BODY.PEEK[TEXT]<0.2048>
> is issued.
> (3) By new mail click at thread pane, IMAP code issues FETCH BODY[].
>     This is executed before "FETCH BODY[] by auo-sync invoked sooner or
> later",
>     because user requsted Tb to show mail before auto-sync.
>     After a change, IMAP code writes mail data to offline-store upon first
> fetch,
>     instead of "to Disk/Memory Cache even if offline-use=On".
> (4) If (2) and (3) happens at same time, data by (2) and data by (3) is
> wrongly merged by IMAP code.
After going through the imap log produced by usul, this surely is making sense. WADA, how are we going to proceed to solve this problem?
(In reply to Atul Jangra [:atuljangra] from comment #26)
> After going through the imap log produced by usul, this surely is making
> sense. WADA, how are we going to proceed to solve this problem?
Flags: needinfo?(m-wada)
Keywords: dataloss
Setting platform ALL based on queries in mozilla,support.thunderbird newsgroup.
OS: Linux → All
Hardware: x86_64 → x86
I have seen TWICE in the past week, a message that has one header on the list of messages and a completely different body in the message when I checked new email.
  To fix, I closed out TB, then deleted the .msf file for the wrong message folder, then re-opened and it is OK now.
When it happened the first time, I assumed that it was a fluke, and deleted the messed up messages (there were 2 different ones that time).
  However, it just happened again to different folders for one message.
  This time, I only deleted the .msf file for the messed up message and when I reopened TB, found the one folder was as it should be and I had a duplicate message filtered into the folder where the message should have gone.
  I compact my mail folders regularly though had not done it prior to this situation happening happening today.

I have not seen corruption like that for many, many years in TB.  I'm running TB 17.0, usng POP3 mail not IMAP. 

Barbara (posted to the Thunderbird newsgroup Mozilla.support.thunderbird 12/7/2012)
(In reply to Wayne Mery (:wsmwk) from comment #27)
> (In reply to Atul Jangra [:atuljangra] from comment #26)
> > WADA, how are we going to proceed to solve this problem?

I can do nothing until someone who could fortunately exprience this bug and other similar bugs multiple times(== who can reprodce problem by his daily/ordinal operations) will provide IMAP log when the problem happens.

I think forcing three requests at same time, (a) "fetch body[]<0.2048>" by Biff, (b) "fetch body[]" by auto-sync, (c) "fetch body[]" for mail display, at same time, will be required to catch condisions which produce problem. And, I believe that Tb developer is only people who can do such test.
Flags: needinfo?(m-wada)
(In reply to Barbara from comment #29)
> using POP3 mail not IMAP. 

As very very easily known by bug summary of this bug,
> Bug 764662 Thunderbird corrupts emails by mangling them together("2048 bytes by
> BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data" is writen to IMAP
> offline-store file)
and, as stated in many comments of this bug(almost all comments in this bug),
this bug is apparently for Tb's issue(s) in IMAP access.
Barbara, how can your porblem be relevant to this bug report for IMAP?
I was referred to this bug report by someone on the Thunderbird newsgroup, with a link to this page, so I added what happened to me.
(In reply to Barbara from comment #32)
> I was referred to this bug report by someone on the Thunderbird newsgroup,
> with a link to this page, so I added what happened to me.

Barbara (New to Bugzilla), could you please show us the news article of "someone on the Thunderbird newsgroup, with a link to this page" which perhaps wrongly referred to this bug for you problem what is perhaps absolutely different from this bug.
Wayne on 12/8/2012 10:15 AM, keyboarded a reply:
> On 12/7/2012 7:27 PM, Barbara wrote:
>> Wayne wrote thusly, On 12/7/2012 2:01 PM Pacific Time:
>>> On 12/7/2012 2:37 PM, News wrote:
>>>> On 12/7/2012 2:32 PM, Barbara wrote:
>>>>> News wrote thusly, On 12/6/2012 8:55 AM Pacific Time:
>>>>>> Seeing many messages scrambled, mis-indexed (header and message body
>>>>>> misaligned/wrong body with header) after auto- or
>>>>>> manual compacting.
>>>>>>
>>>>>> Anyone else seeing this?
>>>>>
>>>>> I have seen TWICE in the past week, a message that has one header on
>>>>> the
>>>>> list of messages and a completely different body in the message when I
>>>>> checked new email.
>>>>>    To fix, I closed out TB, then deleted the .msf file for the wrong
>>>>> message folder, then re-opened and it is OK now.
>>>>> When it happened the first time, I assumed that it was a fluke, and
>>>>> deleted the messed up messages (there were 2 different ones that
>>>>> time).
>>>>>    However, it just happened again to different folders for one
>>>>> message,.
>>>>>    This time, I only deleted the .msf file for the messed up message
>>>>> and
>>>>> when I reopened TB, found the one folder was as it should be and I
>>>>> had a
>>>>> duplicate message filtered into the folder where the message should
>>>>> have
>>>>> gone.
>>>>>    I compact my mail folders regularly though had not done it prior to
>>>>> this situation happening happening today.
>>>>>
>>>>> I have not seen corruption like that for many, many years in TB.  I'm
>>>>> running TB 17.0
>>>>>
>>>>> Barbara
>>>>
>>>>
>>>> That makes two of us...  Persistent mis-indexing and multiple
>>>> appearances.
>>>
>>> there is at least one known bug in this area. It's not an indexing
>>> thing, or disk corruption per se.
>>
>> Wayne,
>> Can you tell me more about that or maybe what to watch out for?
>> Thanks
>>
>> Barbara
>
> No way to avoid it if I remember correctly.
> https://bugzilla.mozilla.org/show_bug.cgi?id=764662 is one example.

Updated this linked bug to reflect all platforms, not just Linux as originally set.
-- 
Ron K.
Who is General Failure, and why is he searching my HDD?
Kernel Restore reported Major Error used BSOD to msg the enemy!
(In reply to Barbara from comment #34)
> Wayne on 12/8/2012 10:15 AM, keyboarded a reply:

At what newsgroup? By what article of what newsgroup of what News server?

> > No way to avoid it if I remember correctly.
> > https://bugzilla.mozilla.org/show_bug.cgi?id=764662 is one example.

If I correctly read the comment by Wayne at unknown newsroup, his comment merely shows an expample of phenomenon what is similar to phenomenon of your problem.
What is reason/evidence that your problem is same as this bug, even though this bug is for IMAP related Tb's problem?
news://news.mozilla.org:119/mozilla.support.thunderbird

Subject: Re: TB17 Indexing/Compacting Errors
posted 12/06/2012

----
 The description of his issue is similar to mine.  I asked Wayne for more info and he gave this link.  If it is not the same bug, do what you do with it.  I'm just trying to add what little information I have that happened to me - twice last week. 
Barbara
(In reply to Barbara from comment #36)
> news://news.mozilla.org:119/mozilla.support.thunderbird
> 
> Subject: Re: TB17 Indexing/Compacting Errors
> posted 12/06/2012
> 
> ----
>  The description of his issue is similar to mine.  I asked Wayne for more
> info and he gave this link.  If it is not the same bug, do what you do with
> it.  I'm just trying to add what little information I have that happened to
> me - twice last week. 
> Barbara

bug I had posted a follow on 12/8/2012 6:11 PM indicating I think your issue is not this bug.
Anyway, because Barbara's case is problem with POP3, Barbara's case is absolutely different from this bug for IMAP. Barbara, please read bug well before posting comment for your problem, please.
This bug may be following phenomenon.

(1) At connection-1, select Inbox
(2) By new mail check, headers are fetched, and new mail is recognized.
(3) Fetch BODY[] request by auto-sync is queued,
    and FETCH BODY[].<2048> request by Biff is queued.
(4) Fetch BODY[] by auto-sync is scheduled at connection-1.
(5) While executing fetch by auto-sync, user clicks a new mail.
(6) Fetch BODY[] by mailview is queued.
(7) Execution of fetch by auto-sync is interrupted and cancelled,
    because mailview is requested by user, and connection-1 is set as No-Busy.
(8) Fetch by Biff is scheduled.
    (NN) fetch BODY[TEXT].<2048>
    Server returns,
      * FETCH BODY[TEXT]<0> {2048}
          body text follows
        BODY[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)] {90}
          header lines follows
      (NN) OK
    and all data is held in network level buffer.
(9) Before request by Biff processes buffered data,
    request by Biff is inturrupted and canceled by mailview request,
    and connection-1 is set as Non-Busy.
(10) Request by mailview is scheduled.
     Because previous IMAP fetch command normally ended at IMAP level,
     (NN+1) fetch BODY[] is issued.
     Following is returned from server,
       entire mail data follows
       (NN+1) OK
     and data is added to buffer.
(11) Data is read from buffer => "2048 bytes + entire mail data" is obtained.
(12) Because RFC822.SIZE is ignored after some changes even if IMAP server
     always returns absolutely correct RFC822.SIZE,
     data is written to offline-store file, and is not marked as "Wrong".
(In reply to Wayne Mery (:wsmwk) from comment #27)
> (In reply to Atul Jangra [:atuljangra] from comment #26)
> > WADA, how are we going to proceed to solve this problem?

I can do nothing also until someone who could fortunately exprience this bug and other similar bugs multiple times(== who can reprodce problem by his daily/ordinal operations) will respond to following question of comment #24.
> If you can see problem frequently, can you try mail.biff.alert.show_preview=false?
(In reply to Wayne Mery (:wsmwk) from comment #41)
> https://getsatisfaction.com/mozilla_messaging/topics/
> thunderbird_17_corrupts_emails may be an example

Example of what? This bug for problem in IMAP? Or Barbar's problem in POP3 access?
Please separate followings.
(1) Barbara's problem == POP3 only == Absolutely irrelevant to IMAP
(2) (case-a) No problem in IMAP, problem in filter move to local mail folder
    (case-b) Problem of this bug in IMAP, no problem in filter move
    (case-c) Problem of this bug in IMAP occurs,
             and problem in filter move to local mail folder also occurs
As already written in this bug and related bugs in dependency tree, corruption pattern of this bug is very specific, and this bug is for (2)/(case-b) only because filter move is absolutely irrelevant to this bug.
And, not so small number of "corruption after filter move" reports are recently seen in B.M.O.
Please do check of "a problem is this bug in IMAP or not" in problem handling of the problem instead of in this bug for IMAP only and for specific corruption pattern only, please.
Changing bug summary(remove expression like generic "mangled") to state that this bug is never for generic mangled message display penomena.
Summary: Thunderbird corrupts emails by mangling them together("2048 bytes by BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data" is writen to IMAP offline-store file) → "2048 bytes of message body(or entire message body if less than 2048 bytes) by FETCH BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data by FETCH BODY[] for mail view" is writen to IMAP offline-store file, and it is not marked as "wong"
Summary: "2048 bytes of message body(or entire message body if less than 2048 bytes) by FETCH BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data by FETCH BODY[] for mail view" is writen to IMAP offline-store file, and it is not marked as "wong" → "2048 bytes of message body(or entire message body if less than 2048 bytes) by FETCH BODY.PEEK[TEXT]<0.2048> for previewBody" + "entire mail data by FETCH BODY[] for mail view" is writen to IMAP offline-store file, and it is not marked as "wrong"
(In reply to Wayne Mery (:wsmwk) from comment #27)
> (In reply to Atul Jangra [:atuljangra] from comment #26)
> > WADA, how are we going to proceed to solve this problem?

I may be able to try to create addon for testing of trying to invoke "FETCH BODY.PEEK[TEXT]<0.2048>" and "FETCH BODY[] by mail click" at same time if I'm very fortunate, if I can read/understand followings very well and very deeply and very carfully, because I could write an addon for testing of bug 814651(check isCachedWindow status of an closed compose window of Tb by JavaScript), although it will surely take very very long.
> Note: Line number is as of today
> Requet of fetch for showPreviewText
> http://mxr.mozilla.org/comm-central/source/mail/base/content/mailWidgets.xml#2509
> onclick handler of a mail who requests fetch of the mail
> http://mxr.mozilla.org/comm-central/source/mail/base/content/mailWidgets.xml#1252
> http://mxr.mozilla.org/comm-central/source/mail/base/content/msgHdrViewOverlay.js#2034
> http://mxr.mozilla.org/comm-central/source/mail/base/content/mailContextMenus.js#137
> Emulation of mouse click event
> https://developer.mozilla.org/en-US/docs/DOM/document.createEvent
> https://developer.mozilla.org/en-US/docs/XUL/Events
(In reply to Atul Jangra [:atuljangra] from comment #26)
> After going through the imap log produced by usul, this surely is making
> sense. WADA, how are we going to proceed to solve this problem?

atuljangra, are you willing to take this for developing a patch?
Flags: needinfo?(atuljangra66)
NOT A FILTER ISSUE, but...

Confirmed behavior on manual copies since cutover to TB17.0:

IMAP Message filtered to Local INBOX - Message OK

Local INBOX Message manually copied to Local Destination folder - Message corrupted

alt-e-u (undo) recover Message from Local Destination folder to Local INBOX - recovered Message remains corrupted

delete Local INBOX .msf and OK Message is recovered

In reply to a request to test, as I'm operating in a production environment, without access to a sandbox, I am unable to test various distros of TB17.
(1) Fetch request is logged like following.
> queuing url:imap:// ... /fetch>UID>/INBOX>31730,31731

4 kinds of of request are relevant to this bug.
(A) fetch request by auto-sync for multiple UIDs 
> queuing url:imap:// ... /fetch>UID>/INBOX>N1,N2:N3,...,Nx
>   (UID=NN is usually involved, but may not be involved if many new mails)
(B) fetch request by auto-sync for single UID 
> queuing url:imap:// ... /fetch>UID>/INBOX>NN
(C) Fetch by mail click before auto-sync fetched and saved to offline-store
> queuing url:imap:// ... /fetch>UID>/INBOX>NN
(D) Fetch by previewBody before auto-sync fetched and saved to offline-store
>  queuing url:imap:// ... /previewBody>UID>/INBOX>NN>NN

(Q1) How can (B) and (C) be distingushed upon try to process request?
     How about (B)/(C) and (D)?
     Even if conidered as "same", concurrent use of same chanel(conection)
     is prevented by Busy flag of channel?

(2) Sceduling of queued request is as follows.

(2-1) Queued request is processed, and following try is repeated several times.
> considering playing queued url:imap:// ... /{RequestType}>UID>/INBOX>NN
> creating protocol instance to play queued url:imap:// ... /{RequestType}>UID>/INBOX>NN
> failed creating protocol instance to play queued url:imap:// ... /{RequestType}>UID>/INBOX>NN

(2-2) After channel(connection) is freed by previously exceuted request, queued request is schduled.
> considering playing queued url:imap:// ... /{RequestType}>UID>/INBOX>NN
> creating protocol instance to play queued url:imap:// ... /{RequestType}>UID>/INBOX>NN
> playing queued url:imap:// ... /{RequestType}>UID>/INBOX>NN

Because of same/already-selected Mbox and same UID, difference among requests is {RequestType} and Size in previewBody(last/appended ">2048") only.

(Q2) Is concurrent use of same channel(connection) prevented by Busy flag of channel?

I assume different {RequestType} and existence of Size(last/appended ">2048") forces "different URL" condition. And. even if considered as "same URL", Busy flag prevents concurrnt use of same channel(connection).

Because "2048 bytes of mail body of UID=NNa" + "entire mail data stream of UID=NNb"(where NNa != NNb) is seen in this bug's case, I guess following phenomenon.
>   ---------------------------     ------------------------     --------------------------------
>   Task-1                          IMAP task                    Task-2
>   Higher priority task            Socket level IMAP access     Lower priority task
>   ---------------------------     ------------------------     --------------------------------
>                                                                Fetch request for previewBody
>                                                                  is queued
>                                                                Wait for end-notification
>
>                                   fetch request by
>                                     previewBody is scheduled
>                                   fetch UID NNa BODY[].2048
>                                     2048 bytes data
>   Fetch request by mail click     is held in buffer
>     is queued                     OK response
>   Wait for end-notification       Notify to event listner
>                                   (listner=Task-2)
>                                   Busy flag=Off
>
>                                   Before event listner at Task-2 removes data from buffer,
>                                   fetch request by mail click is scheduled.
>                                   fetch UID NNb BODY[]
>                                     entire mail data
>                                     is added to buffer
>                                   OK response
>                                   Notify to event listner
>                                   (listner=Task-1)
>                                   Busy flag=Off
>
>   End-notification
>   Before Task-2 removes 2048 bytes data of UID=NNa from buffer,
>   Task-1 reads 2048 bytes of UID=NNa,
>   and reads entire mail data of UID=NNb
No longer blocks: 726469, 732360, 823838
Depends on: 823838
FYI.
I've opened bug 823838 and consolidated bug reports for same type of corruption.
Ronan Jouchet(bug opener), if you can see problem frequently in your daily use, and if you can accept no preview text in new mail alert in your daily use, please try mail.biff.alert.show_preview=false in your daily use.
(restart of Tb my be needed after option change)
Will frequency be reduced by mail.biff.alert.show_preview=false?
(In reply to WADA from comment #49)
> Ronan Jouchet(bug opener), if you can see problem frequently in your daily
> use, and if you can accept no preview text in new mail alert in your daily
> use, please try mail.biff.alert.show_preview=false in your daily use.
> (restart of Tb my be needed after option change)
> Will frequency be reduced by mail.biff.alert.show_preview=false?

Hi WADA, thanks for the effort! Unfortunately I haven't met the problem for months :-/ . It might be fixed since then, but from what I can understand, it might also be "fixed" by the fact that my internet connection changed since the day of my initial report. At the time (June 2012) I was using a very sloppy shared connection and now (since September 2012) I'm on a personal fast connection.

Anyway I'm leaving mail.biff.alert.show_preview=true, if I ever meet the problem again I will FALSE it + report results.
(In reply to Ronan Jouchet from comment #50)
> At the time (June 2012) I was using a very sloppy shared connection
> and now (since September 2012) I'm on a personal fast connection.

I think slow connection is relevant to problem, because "fetch UID nn BODY[TEXT]<0.2048> for previewBody" very quickly completes if fast connection and not-so-slow IMAP server.

I'll continue analysis in this bug(already sufficiently lengthy and contaminated by irrelevant POP3 related comments) before duping this bug to bug 823838, to keep new bug 823838 crisp/clean.
I'm aware of that David :Bienvenu is not in CC:...
CC-ing to David :Bienvenu.

David, is my guess in comment #47 absolutely wrong?
To explain phenomenon of "2048 bytes of message body of other mail" + "entire mail data stream of this mail", I think such flow is needed.
Flags: needinfo?(mozilla)
(In reply to Wayne Mery (:wsmwk) from comment #45)
> (In reply to Atul Jangra [:atuljangra] from comment #26)
> > After going through the imap log produced by usul, this surely is making
> > sense. WADA, how are we going to proceed to solve this problem?
> 
> atuljangra, are you willing to take this for developing a patch?

Yes, I am willing. But Since I've other priorities also, thus I am afraid I'll be working on a slower pace. If anyone else is willing to develop a patch, he surely can. :-) 
I am willing to develop the patch and I've started work on this one.
Flags: needinfo?(atuljangra66)
(In reply to Atul Jangra [:atuljangra] from comment #53)
> I am willing to develop the patch and I've started work on this one.

Thanks, but can you implement patch to fix this bug, without knowing what happens, with code inspection only, based on corrupted mail data only? 

"fetch BODY[TEXT]<0.2048>" is requested at;
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#1451
>     urlSpec.Append("/previewBody>");
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#1465
>   rv = GetImapConnectionAndLoadUrl(imapUrl, nullptr, aURL);

nsImapIncomingServer::GetImapConnectionAndLoadUrl is commonly used by "fetch for mail view", "fetch for auto-sync", and is defined by following. 
> http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapIncomingServer.cpp#412

For access to ImapIncomingServer service from JavaScript, nsIImapIncomingServer is available. 
> http://xulplanet.mozdev.org/references/xpcomref/nsIImapIncomingServer.html

And, after new mailServices.js, Account Manager Service is accessble merely by Service=MailServices.accounts.

So, if following is possible by JavaScript(add-on for test), emulation of flow like comment #47 may be possible.
(1) Offline-Use=Off folder, to prohibits auto-sync.
(2) Get the IMAP folder via Account Manager Service interface.
(3) Request "fetch body[text]<0.2048>" via GetImapConnectionAndLoadUrl of nsIImapIncomingServer interface, and do nothing on fetched data in buffer.
(4) Change the folder to "offline-use=on", and invoke onClick handler of the mail at thread pane immediately, before auto-sync fetches the mail.

Atul Jangra, do you know code example for such actions?

Or your patch means "change which can easiliy reproduce this bug"?
If so, change like "previewBody does do nothing on fetched data" may be a way to force corruption.
(In reply to WADA from comment #52)
> I'm aware of that David :Bienvenu is not in CC:...
> CC-ing to David :Bienvenu.
> 
> David, is my guess in comment #47 absolutely wrong?
> To explain phenomenon of "2048 bytes of message body of other mail" +
> "entire mail data stream of this mail", I think such flow is needed.

It has to be something like that, yes. I remembering exploring that idea a while ago but could not figure out a way that it could get by the various protections in place. Queued urls and the memory cache and potentially url retries would seem to be involved, and some sort of race condition exposed by slow connections. In theory, urls running on the same mail folder should be strictly queued. Peek fetches should not be cached because they're not the whole message. I'll try to think a little more about this.
Flags: needinfo?(mozilla)
FYI.
There are two funny behaviour in previewBody.

(A) BODY.PEEK[TEXT]<0.2048> by previewBody is requested even when entire message is already saved in offline-store file by auto-sync. (found in this bug)

(B) BODY.PEEK[TEXT]<0.2048> by previewBody was requested by Tb 10 upon each mouse hover on Inbox. (found in bug 726469)
Following is copy of my bug 726469 comment #3 on 2012-02-13.

attachment 596911 [details]
IMAP log when one new mail arrival

Tb 10.0.1 on Win-XP, Gmail IMAP, Inbox, Offline-use=Off, IDLE is enabled, no automatic new mail check, Junk filter is enabled, no message filter, small multipart/mixed mail.
Inbox is sorted by Date in ascending order, and test mail's date was 1970/01/01, new mail is placed at top of thread pane.

(1) Inbox is clicked and selected.
    Click account => Inbox is not selected at folder pane
(2) New mail notification via IDLE
(3) fetch standard headers only
> 18 UID fetch 12116 (UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type)]) 	
(3) fetch 2KB text for previewBody 
> :S-INBOX:ProcessCurrentURL:imap://yatter%2Eone%40gmail%2Ecom@imap.gmail.com:993/previewBody%3EUID%3E/INBOX%3E12116%3E2048:  = currentUrl
> 19 UID fetch 12116 (UID BODY.PEEK[HEADER.FIELDS (Content-Type Content-Transfer-Encoding)] BODY.PEEK[TEXT]<0.2048>)
(4) Upon each mouse hover on Inbox, above previewBody occurs, and fetch command is issued.
(5) Click Inbox, click the new mail
    noop => fetch by previewBody => followin fetch body[]
> :S-INBOX:ProcessCurrentURL:imap://yatter%2Eone%40gmail%2Ecom@imap.gmail.com:993/fetch%3EUID%3E/INBOX%3E12116:  = currentUrl
> 35 UID fetch 12116 (UID RFC822.SIZE BODY[])
Whiteboard: [will be duped after analysis, to crisp bug 823838 for bug fixing]
David :Bienvenu, following can occur?

Is "ImapURL" in ImapMessageSink set of 'ImapURL,Inbox,fetch,"nn>2048"' which is used in URL queuing?
If so, DisplayConsumer can distinguish data by "FETCH UID nn BODY[TEXT].2048"...

>   ---------------------------     ------------------------     --------------------------------
>   Task-1                          IMAP task                    Task-2
>   Higher priority task            Socket level IMAP access     Lower priority task
>   ---------------------------     ------------------------     --------------------------------
>                                   Inbox is selected at
>                                     a connection.
>                                   Busy for other actions on
>                                     other UID.
>                                                                Fetch request for previewBody. UID=nn
>                                                                  nsImapService::FetchMessage
>                                                                      ImapURL = Imap_server
>                                                                      ImapFolder == Inbox
>                                                                      action == fetch
>                                                                      messageIdentifierList == "nn>2048"
>                                                                      aAdditionalHeader == null
>                                                                      DisplayConsumer == StreamerForPreview
>                                                                    AddImapFetchToUrl :
>                                                                      ImapURL,Inbox,fetch,"nn>2048" is queued
>                                                                    GetMessageFromUrl :
>                                                                      ImapURL,Inbox,fetch,StreamerForPreview
>                                                                        is registered to ImapURL
>  Fetch request for MailView. UID=nn
>    nsImapService::FetchMessage
>        ImapURL = Imap_server
>        ImapFolder == Inbox
>        action == fetch
>        messageIdentifierList == "nn"
>        aAdditionalHeader == null
>        DisplayConsumer == StreamerForMailView(==may be DocShell)
>      AddImapFetchToUrl :
>        ImapURL,Inbox,fetch,"nn" is queued
>      GetMessageFromUrl :
>        ImapURL,Inbox,fetch,StreamerForMailView(==may be DocShell)
>          is registered to ImapURL
>
>                                   A connection becomes Free.
>
>                                   Fetch request by
>                                     previewBody is scheduled
>                                   FETCH UID nn BODY[TEXT].2048
>                                     2048 bytes data
>                                        is held in ImapMessageSink(key=ImapURL/UID)
>                                   OK response
>
>                                   Busy flag=Off
>
>                                   Notified to
>                                     StreamerForPreview
>                                     StreamerForMailView
>
>                                   Before StreamerForPreview at Task-2 removes data from ImapMessageSink,
>                                   fetch request by MailView is scheduled.
>                                   FETCH UID nn BODY[]
>                                     entire mail data is added to ImapMessageSink(key=ImapURL/UID)
>                                     is added to buffer
>                                   OK response
>
>                                   Notified to
>                                     StreamerForPreview
>                                     StreamerForMailView
>
>  StreamerForMailView extracts mail data from ImapMessageSink(key=ImapURL/UID).
>  Because key=ImapURL/UID, there is no way to distinguish
>    data by "FETCH UID nn BODY[TEXT].2048" and "FETCH UID nn BODY[]".
>
>  If chunked, "partial data of 2048 bytes by previewBody" is similar to a chunk of long mail.
>  This may be relevat to problem
>
>  Because RFC822.SIZE is not used any more, mail data is not marked as "BAD" in MsgFolder.
>  So, re-fetch won't be scheduled.

Following is relevant code.
http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#970
http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#988
http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#1017
http://mxr.mozilla.org/comm-central/source/mailnews/imap/public/nsIImapMessageSink.idl#14
Flags: needinfo?(mozilla)
I could write following JavaScript code(addon format).
> Currently selected mail's UID==A.
> Next mail's UID==B. UID==B is not saved in Offline-store file yet.
> When a button in ToolBar is clicked, do following.
> (A) Emulation of fetch BODY.PEEK[TEXT}<2048> by Biff' preview text
>   ImapService.getBodyStart(msgFolder,MyUrlListener,MsgKeys,2048,null) ;
>         MsgKeys[0]==B, MsgKeys.lngth=1;
> (B) Emulation of new mail click(mail which is not saved in Offline-store yet),
>     and mail is saved in Offline-store file by Tb. 
>   gDBView.selectMsgByKey(MsgKeys[0]) ;

But, both are requested serially under same main mail&news window, execution of "onDataAvailable(Streamer/DisplayCosumer) and OnStopRunningUrl(UrlListener)" for (A) and (B) are cleanly seriarized.

Emulation/Test by own streamer(DisplayConsumer) and simulteneous/concurrent request from different task may be needed.
In any fetch by mailView and previewText, following is executed.
> nsImapIncomingServer::GetImapConnectionAndLoadUrl
>   http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapService.cpp#1427
> => nsImapIncomingServer::GetImapConnection
>    http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapIncomingServer.cpp#683
>
> If a connection is usable(connection is established, folder is already selected,
> not busy, no error is happening, ...), non-null/non-undefined aProtocol is returned to
> caller(GetImapConnectionAndLoadUrl) from GetImapConnection.
>
> GetImapConnectionAndLoadUrl does following next.
>   If aProtocol is returned, call nsImapProtocol::LoadImapUrl
>      http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapProtocol.cpp#2084
>   If aProtocol is NOT returned, queue the request,
>   and call LoadNextQueuedUrl in order to give a chance of
>   quicker scheduling of already queued request.

David :Bienvenu, if above occurs at two tasks at same time when a connection is free and ready to use, is resources serialized or locked well in multi-CPU, multi-tasking environment?

>  ----------------------------------------------             ----------------------------------------------
>  CPU-1/Task-1 ( BODY[] request)                             CPU-2/Task-2 ( BODY.PEEK[TEXT]<2048> request)
>  ----------------------------------------------             ----------------------------------------------
>                                (Folder is selected at a connection, and is free)
>                                (No request is queued to the connection         )
>  GetImapConnectionAndLoadUrl                                GetImapConnectionAndLoadUrl
>    Call GetImapConnection                  A                  Call GetImapConnection
>         Connection status check            |                       Connection status check
>         => ready to use                    |                        => ready to use
>            so, returns aProtocol           |                           so,returs aProtocol
>    aProtocol is rertured,                  |                  aProtocol is rertured,
>    so call LoadImapUrl                     V                  so call LoadImapUrl
Between GetImapConnection andLoadImapUrl, I think the connection is not locked.
So, even if "connection status check by GetImapConnection" is executed under single task serially, I think aProtocol can be returned to both of above two requests.
If so, because LoadImapUrl doesn't seem to reject two concurrent LoadImapUrl requests(difference is .<2048> only), I think phenomenon of this bug may occur.

If above guess is not absolutely wrong, it may explain "2048 bytes of different mail" + "entire mail data of this mail" case.
irving, are you able to answer question in comment 59
Flags: needinfo?(irving)
I don't think this problem is a multi-thread locking issue; it's more likely that a specific sequence of operations on the mailbox doesn't clean up the preview fetch before it starts a subsequent message fetch. Without a unit test or reliable steps to reproduce, it won't be easy to find.
Flags: needinfo?(irving)
wada, Bienvenu isn't active and not replying in bugzilla. That said, I suspect your question in comment 57 has been answered or is obsolete?
Flags: needinfo?(mozilla) → needinfo?(m-wada)
(In reply to Wayne Mery (:wsmwk) from comment #62)
> I suspect your question in comment 57 has been answered or is obsolete?

My comment #57 is "my guess", and is not obsolete. I still suspect such mechanism.
Answer from any Mozilla developer is appreciated.
Flags: needinfo?(m-wada)
(In reply to WADA from comment #63)
> (In reply to Wayne Mery (:wsmwk) from comment #62)
> > I suspect your question in comment 57 has been answered or is obsolete?
> 
> My comment #57 is "my guess", and is not obsolete. I still suspect such
> mechanism.
> Answer from any Mozilla developer is appreciated.
Flags: needinfo?(irving)
I don't have anything to add; this bug just needs somebody with time to do the work.
Flags: needinfo?(irving)
Removing myslef on all the bugs I'm cced on. Please NI me if you need something on MailNews Core bugs from me.
Blocks: 783224
See Also: → 1742975
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: