Closed Bug 1395620 Opened 2 years ago Closed 2 years ago

image attachment of message in non-synchronised IMAP folder is truncated if followed by non-inline attachment (700KB image + 1.5MB PDF)

Categories

(MailNews Core :: Networking: IMAP, defect)

defect
Not set

Tracking

(thunderbird_esr5256+ fixed, thunderbird56 fixed, thunderbird57 fixed)

RESOLVED FIXED
Thunderbird 57.0
Tracking Status
thunderbird_esr52 56+ fixed
thunderbird56 --- fixed
thunderbird57 --- fixed

People

(Reporter: mozilla, Assigned: jorgk)

References

Details

(Whiteboard: TB 56 beta 4, TB 52.4.0 ESR)

Attachments

(6 files, 2 obsolete files)

Attached file Classe 1ES1.jpg
User Agent: Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:55.0) Gecko/20100101 Firefox/55.0
Build ID: 20170824070828

Steps to reproduce:

On a Gmail account, receive an email with several attachments.
Try to view (inline) or with external program with double click, or to save the images.



Actual results:

Attachments that are images (png, jpg etc.) are not correctly processed : they are not viewed inline, they cannot be opened or saved (all files are truncated to 27 bytes). See attached documents.
Other documents types (pdf, word etc.) are processed as usual and can be saved/viewed.
When the message is forwarded, all attachments (including the images) are correctly processed and are received by the recipient.
When the same message is sent to a 'regular' (i.e IMAP, no Gmail) then all attachments are processed as expected.



Expected results:

Images should be viewed/saved correctly.
This attachment is larger than 27 bytes when saved/viewed (257052) but is much smaller than the original attachment (4MB). The image is corrupted and cannot be viewed.
Attachment #8903201 - Attachment mime type: image/jpeg → text/plain
Which version are you using exactly? TB 52.3?

Wayne, have we seen reports like this one on SUMO?
Flags: needinfo?(vseerror)
I'm using 52.3.0 64bits on Linux (version shipped with Fedora 26).
I've just seen the problem happening on a regular IMAP account so it's not only related to gmail accounts ... I reproduce 100% on gmail and it appears to be random on other account types.
Does this this only happen with large images or are even small imaged (50KB) truncated?

What are the synchronisation settings of the folders? Right-Click, Properties, Synchronisation.
(In reply to Jorg K (GMT+2) from comment #3)
> Which version are you using exactly? TB 52.3?
> 
> Wayne, have we seen reports like this one on SUMO?

perhaps tonnes and zenos
Flags: needinfo?(vseerror)
Flags: needinfo?(tonnes.mb)
Flags: needinfo?(chris.ramsden)
I've tested again with 2 images : 
18kB : works
650kB : image is truncated
1.3MB PDF works

The inbox folder is not synchronized on the 2 accounts on which I experienced the issue (gmail & regular IMAP).
I'm going to change the setting and let you know what happens...
With synchronisation turned on it works... 
To summarize : 
If synchronization is disabled : 
a 18kB image displays & opens fine
a 657kB image does not display/open
a 1.4MB PDF does open correctly (no in-line display)

When synchronization is enabled : 
Everything works.

So it's related to file type & image when synchronization is disabled...
It was working fine on previous versions of Thunderbird.
When synchronisation is disabled, Thunderbird uses a local cache. Between TB 45 and TB 52 we have switched caching technology and fixed part caching, so caching of individual message parts like embedded/attached images and other non-inline attachments.

Here is a list of the relevant bugs:
Bug 1021843 - migrate to cache2 (included in TB 52)
Bug 629738  - Part caching with follow-up bug 1310446 (included in TB 52).
Bug 1355350 - caching problems with very large images >15MB (included in TB 52.1.1)
Bug 1382008 - Increased max. cache size to 25MB (included in TB 52.3).

So you can see that there are quite a few bugs and I've tested that area over and over, especially for bug 1355350 where large parts were cached incomplete like you're describing here.

When you say it was working fine, which version are you referring to? TB 45? Yes, that used the old technology and parts weren't cached at all. Or did it work in TB 52.1.1 and stopped working now that TB 52.3 was released?

I'll try a scenario like the one you're describing, but in the meantime I have some questions:
1) The machine you're using is rather a high end machine with lots of memory or low end? How much memory?
2) In Tools > Options, Advanced, General, Config Editor, can you check the values of
   browser.cache.memory.max_entry_size and
   browser.cache.memory.capacity for me.
   The first one should be 25000 and the second one 200000.
When doing testing for bug 1355350, I made sure that the system works even when the image is larger than the threshold, so it's a bit hard to understand why a medium size image 657KB doesn't work when a 1.4MB PDF does. But I'll see.
OK, with the combination of 700KB image first and 1.6MB PDF I can reproduce this. The image is truncated, the PDF is fine. I had all sorts of test cases, but not this combination. Sigh, yet another caching bug. Anyway, thanks for reporting it.
Assignee: nobody → jorgk
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
Flags: needinfo?(tonnes.mb)
Flags: needinfo?(chris.ramsden)
Summary: image attachment (png, jpg etc.) of messages on gmail account cannot be viewed or saved → image attachment of message in non-synchronised IMAP folder is truncated if followed by non-inline attachment (700KB image + 1.5MB PDF)
When I say it was working fine it was with the TB version shipped with Fedora 24 (up to the latest update from a mirror on which I just looked-it up I found thunderbird-45.1.0-2.fc24), since F24 reached EOL I upgraded to F26 and discovered this bug.
The machine I used is an i5-4460 with 16GB of RAM which is not, according to my standards, a low-end machine.
My config values are :
browser.cache.memory.max_entry_size;25000
browser.cache.memory.capacity;200000
So I'm in-line with your values.

I saw your latest message where you mention that you've reproduced the issue, that's great. Sorry for giving you more headaches but this is really annoying.
Good luck with your debugging.
Just a remark regarding your summary. I discovered the issue on a message that contained only images (4 jpgs, the largest one being 404kB). I reproduced this with the combination of image + pdf because I used these different attachment types to further identify the issue. So I just want to outline again that it also happens when there are only in-line attachments to the message...
If done a bit of testing, here is what happens:

We request the image from the cache and write 67440 bytes to it, which is short, so someone aborted the write.
=== |imap://jorgk%40jorgk%2Ecom@mail.your-server.de:993/fetch%3EUID%3E.INBOX.No%20local%20storage%3E14?part=1.2&filename=IMG_12513-mod.JPG|
=== nsImapMockChannel::OnCacheEntryAvailable: WRITE END
=== nsImapUrl::SetContentModified Modified View Inline
=== nsImapProtocol::PostLineDownLoadEvent: Written 15983 bytes
=== nsImapProtocol::PostLineDownLoadEvent: Written 15984 bytes
=== nsImapProtocol::PostLineDownLoadEvent: Written 15984 bytes
=== nsImapProtocol::PostLineDownLoadEvent: Written 15984 bytes
=== nsImapProtocol::PostLineDownLoadEvent: Written 3525 bytes

Later we come asking for the same thing again and accept the short one:
=== |imap://jorgk%40jorgk%2Ecom@mail.your-server.de:993/fetch%3EUID%3E.INBOX.No%20local%20storage%3E14?part=1.2&filename=IMG_12513-mod.JPG|
=== nsImapMockChannel::OnCacheEntryAvailable: READ, size=67460
=== reading part, should use cache entry
=== End separate processing: should use cache entry: 1
=== After header check: should use cache entry: 1
=== Cache entry accepted
=== nsImapCacheStreamListener::OnDataAvailable: Count = 67460
=== nsImapMockChannel::OnCacheEntryAvailable, new=0

So whoever cancels the first transfer doesn't doom the incomplete cache entry. One line fix, just have to find where to put it. I already added a doom call in bug 1355350:
https://hg.mozilla.org/releases/comm-esr52/rev/0fe57a87f5b17ac3cc9f52e98fc65b12d7ef5c7e#l1.31
I've just made a pretty ugly discovery. When you have a message with an inline attachment (image) and a non-image attachment (PDF) and view the message in TB 45, then the image is truncated. That's what we're seeing here, the transfer is stopped after about 64KB. To add insult to injury, TB 52+ caches this incomplete download, whereas TB 45 never did any part caching, so on second access you get the whole thing.

I can fix caching something that's incomplete, but to repair the logic that does an incomplete download is much harder.
Attached patch 1395620-cache-problem.patch (obsolete) — Splinter Review
Kent, what do you think of this band-aid approach? As outlined in comment #13 and comment #14 some crazy logic decides to only partly download an image part. As we can already see in TB 31, 38 or 45, the image part of a 700KB image + 1.5MB PDF message is truncated.

Since we now cache parts properly, we cache the incomplete part and it's downhill from there. The patch fixes caching of an incomplete part but it doesn't address the root problem that there is a hole, most likely in the body shell code (nsIMAPBodyShell.cpp), that only downloads part of an image although the image is displayed inline and needed in full.

With this patch, the incomplete part is doomed, so it's fetched again form the server when the user comes to save/open it. Other things I noticed: The attachment size is shown as "at least 46.7KB" and when opening it, it shows 3.1MB when about 700KB would be correct. So part caching hit a can of worms here.
Attachment #8903784 - Flags: feedback?(rkent)
Comment on attachment 8903784 [details] [diff] [review]
1395620-cache-problem.patch

Kent, any idea which part of that IMAP code decides to download part of the message part? See the beginning of comment #13.

It appears that m_fetchingWholeMessage is set to false, so it wasn't a kEveryThingRFC822/kEveryThingRFC822Peek where that's set to true. I did a bit of debugging and saw various calls with kMIMEPart, and the only place we do these is in 
mailnews/imap/src/nsIMAPBodyShell.cpp
455 aShell->GetConnection()->FetchTryChunking(aShell->GetUID(), kMIMEPart, true, m_partNumberString, m_partLength, !fetchingSpecificPart);

So I guess the patch testing 'm_fetchingWholeMessage' isn't right and the focus should be on fixing that ancient bug that decides to abort fetching a part which leads to an incomplete display and caching of something truncated.
Attachment #8903784 - Flags: feedback?(rkent)
OK, so I've looked at this again.

The problem only happens in the configuration of large inline image plus non-inline part, say a PDF.

We fetch the image part using chunking since the image is larger than 64KB. Sadly GetServerStateParser().GetLastFetchChunkReceived() is returned as true after the first chunk has been fetched, and we stop and end up with the truncated image (which is also cached and havoc results later).

This patch hacks away the "last chunk logic" and instead keeps fetching until the part is complete.

Gene or Kent: Do you know anything about chunking? Why would the response parser say it's the last chunk when it wasn't. I haven't debugged it more but I will.

The debug I get with this patch is:
=== Fetching part 1.1 8
=== fLastChunk (2) 1
=== Fetching part 1.2 227
=== fLastChunk (2) 1
=== Fetching part 2 940938
=== 0 65536 940938
=== fLastChunk (2) 1
So after fetching the first 64KB chunk of a 900KB part, we stop since that's supposedly the last chunk.
Attachment #8903784 - Attachment is obsolete: true
Flags: needinfo?(rkent)
Flags: needinfo?(gds)
Gene, could you please review this for me. This is a one line change:
+    m_curFetchSize = m_chunkSize;
All the rest is debug only which I won't land.

As far as I can see, chunking was always broken, since the fetch size was always the full download size despite the comment:
  m_curFetchSize = downloadSize; // we'll change this if chunking.
That promised something that never happened.

Do you agree that this is the correct change? Debugging showed that in nsImapServerResponseParser::msg_fetch_literal()
we compared the numberOfCharsInThisChunk with the full download size an it never matched.
Attachment #8904019 - Attachment is obsolete: true
Flags: needinfo?(rkent)
Flags: needinfo?(gds)
Attachment #8904021 - Flags: review?(gds)
Comment on attachment 8904021 [details] [diff] [review]
1395620-IMAP-chunking.patch (v1)

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

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +3707,5 @@
>          GetServerStateParser().ServerHasIMAP4Rev1Capability() &&
>      (downloadSize > (uint32_t) m_chunkThreshold))
>    {
>      uint32_t startByte = 0;
> +    m_curFetchSize = m_chunkSize;

This is the only change to review here.
Comment on attachment 8904021 [details] [diff] [review]
1395620-IMAP-chunking.patch (v1)

I'd like to have this for my beta 4 tomorrow, so a quick review would be appreciated. One line shouldn't be hard to review.
Attachment #8904021 - Flags: review?(acelists)
Comment on attachment 8904021 [details] [diff] [review]
1395620-IMAP-chunking.patch (v1)

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

Thanks, this works nicely. I created my own test message where the bug was visible.
Thanks for being brave to dive into this caching stuff. But in this dark place no oneliner is quick to review ;)
Hopefully this does not break another case.
Attachment #8904021 - Flags: review?(acelists) → review+
Indeed, I am leery of rushing this into beta.
(In reply to :aceman from comment #22)
> Thanks for being brave to dive into this caching stuff.
Thanks for the quick review. You meant "chunking" stuff. This seems to have been wrong since day one, or that line got lost at some stage. Caching only exposed the problem.

(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #23)
> Indeed, I am leery of rushing this into beta.
With no automatic updates on Daily, that's the only way we can give it exposure. Best to take it to beta now and ship it in TB 52.4 after four weeks. I'm really surprised there are no earlier reports of this.
Attachment #8904021 - Flags: review?(gds)
I duplicated the problem too with a large png and pdf attachment saved to drafts. I haven't tried building with the fix but it looks like it will work (and apparently Jorg and aceman have tried it, so I'm sure it's OK). Anyhow, I see that my "review?" flag got reset while I was working on the review.
(In reply to gene smith from comment #26)
> I see that my "review?" flag got reset while I was working on the review.
No offence intended, sorry. Sometimes I ask for multiple reviews to speed things up, this time I forgot to write "only one review required". Thanks for checking it out, yes, the patch fixes the problem we observed.

It's interesting to see that a message with two images doesn't run that code, so needs to be a certain MIME structure that causes the problem.
Oh, no offence taken!
You are right. When I attach two ~1M png I see the both with no problem. Also, the problem only occurs with the non-default setting of "don't store messages locally" (i.e., not sync'd) and a mixture of large file types.
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/b143aa60d983
fix chunking in IMAP download. r=aceman
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 57.0
Comment on attachment 8904050 [details] [diff] [review]
1395620-IMAP-chunking.patch (v1) with no debug.

Ancient bug made worse by part caching.
Attachment #8904050 - Flags: approval-comm-esr52+
Attachment #8904050 - Flags: approval-comm-beta+
Duplicate of this bug: 1396779
Whiteboard: TB 56 beta 4, TB 52.4.0 ESR
Component: Untriaged → Networking: IMAP
Product: Thunderbird → MailNews Core
Version: 52 Branch → 52
You need to log in before you can comment on or make changes to this bug.