629738 - Attachment is immediately re-cached after successful cache operation (no offline sync, download on demand)

Status: RESOLVED FIXED

(MailNews Core :: Networking: IMAP, defect)

Description

[rsx11m]

I have observed this while testing bug 629247. The problem may be a fall-out
from bug 565852, but it simply may not have been visible before, given that caching was performed incorrectly. I can reproduce this on both current TB 3.3a3 nightly build and TB 3.1.8 release candidate, Windows 7 and XP.

After the cache operation for the attachment has been finished and the "Open with" dialog initiated, it appears that another network operation of same size and duration occurs, likely re-caching the same attachment. This operation is unnecessary and a significant performance hit for network operations, given that IMAP access for that folder (e.g., to get another message) is stalled while the cache is refreshed.

Conditions of testing (observed with Gmail and an independent IMAP server):

Send yourself a message with a 20MB+ attachment.
Open Windows 7 Resource Monitor, Network tab, or a similar tool.
Start Thunderbird and wait for activity to quiet down.
Offline synchronization disabled.
Other relevant settings:
  browser.cache.disk.enable = false
  browser.cache.memory.enable = true
  browser.cache.memory.capacity = 32768
  mail.server.default.mime_parts_on_demand = true

Initial opening of the message and attachment (cache miss):

1. Open the message, no substantial network activity.
2. Open attachment, download is indicated as expected.
3. The "Open with" dialog appears, network activity stops.
4. However, then a spike of similar TB activity occurs.
5. Select application to open, then close attachment.

Subsequent opening of the message and attachment (cache hit):

1. Go to a different (small) message, then return to large message.
2. Open attachment, which is cached now.
3. The "Open with" dialog appears immediately, apparently taken from cache.
4. However, then a spike of similar TB activity occurs (re-caching?).
5. Select application to open, then close attachment.

Steps #4 should not happen for either cache miss or hit. I'm adding the Core Networking: Cache people as CC in case they have any additional insight.

Comment 1

[rsx11m]

Also observed with Mozilla/5.0 (X11; Linux x86_64; rv:2.0b8pre) Gecko/20101116 Thunderbird/3.3a1, thus cross-platform and after bug 565852 landing on trunk.

Comment 2

[WADA:World Anti-bad-Duping Agency]

As I wrote in bug 565852 comment #25 (Problem-A), "re-fetch of already cached part" is not attachment only phenomenon. After fix of bug 565852, fetch of mail body(fetch body[1] for first text/xxx part in multipart/mixed) was always issued upon each mail viewing with offline-use=off. Unless whole mail data is downloaded(eg. by mail.imap.mime_parts_on_demand=false, fortunately "fetch body[]" is used upon download for atachment, ...), re-fetch of part in multipart/mixed was observed.
I thought "it's current design/implementation or restriction of Disk/Memory Cache".
  As Bug 175600 exists, max entries of Disk Cache is merely 8192.
  It's not sufficient for effective caching of mail data of many many mails.
  As bug 290032 exists, cache data is not kept if contention of hash value
  happens.
  So, "Limiting of Disk Cache use to keeping of whole mail data only"
  is reasonable in some situations.

Comment 3

[rsx11m]

(In reply to comment #2)
>   As Bug 175600 exists, max entries of Disk Cache is merely 8192.

WADA, a fixed limit does no longer apply. Bug 569709 made this dynamic.

>   As bug 290032 exists, cache data is not kept if contention of hash value
>   happens.

This bug has been closed as fixed, and regardless of which hash function one eventually employs, it's always possible to have collisions (so the question there was how to update the hash function to minimize those). I sure may have misread or missed any implication that fix may have which you wanted to point
me to by this reference?

>   So, "Limiting of Disk Cache use to keeping of whole mail data only"
>   is reasonable in some situations.

I don't think this actually happens due to the behavior seen in the cache-hit case (reloading of the same message). It is possible to open the attachment already while the re-caching occurs in the background (steps #2 and #3 of the second opening). I can even disconnect the machine while the attachment is re-cached and yet am able to open the attachment (and it's temporarily saved
as a distinct instance of that file in %TEMP%).

Thus, the problem isn't that the MIME part wouldn't be cached (indeed it is), but that it apparently expires immediately after it is used and then refetched for some reason. Note that about:cache doesn't show any expiration time for either the message body itself nor any of the "imap://...?section=x" parts.  

So, to summarize:
 (a) attachments are cached if downloaded on demand as "?section=x" entry;
 (b) there doesn't seem to be any expiration handling (at least not by time);
 (c) re-fetching of the attachment into the cache occurs *after* using it.

Comment 4

[WADA:World Anti-bad-Duping Agency]

Following is Disk Cache Entries after;
  mail#1 : UID=2, text/plain, 0.9KB
  mail#2 : UID=3, text/plain, 9KB
  mail#3 : UID=4, multipart/mixed (one text/plain + one application/pdf),
                  1.5MB, text/plain part is single line text, PDF size=1.5MB.
  (0) Clear Disk Cache, Restart Tb(trunk, 2011/1/15 build, on Win-XP)
  (1) View mail#1, mail#2, mail#3 multiple times.
  (2) "Open" of PDF attachment of mail#3(UID=4),
      => application selection dialog is opened
      => Cancel at the dialog
  (3) Check Disk Cache entries

> Disk cache device
> Key                                                             Data size       Fetch count   Last modified         Expires
>
> https://www.mozillamessaging.com/img/thunderbird/start/main-feature.jpg
>                                                                   29128 bytes             1   2011-01-31 16:57:21   2011-02-04 12:01:57
>
> (mail#1 : UID=2, text/plain, 0.9KB)
> 23e69343imap://[e-mail]:993
>         /fetch%3EUID%3E/AA/AAAA%3E2                                 938 bytes             5   2011-01-31 16:58:19   No expiration time
>
> (mail#2 : UID=3, text/plain, 9KB)
>
> 23e69343imap://[e-mail]:993
>         /fetch%3EUID%3E/AA/AAAA%3E3                                9212 bytes             4   2011-01-31 16:59:01   No expiration time
>
> (mail#3 : UID=4, multipart/mixed(text/plain+application/PDF), 1.5MB, text/plain part is single line text)
>
> 23e69343imap://[e-mail]:993
>         /fetch%3EUID%3E/AA/AAAA%3E4/;section=2                  1484603 bytes             1   2011-01-31 17:03:03   No expiration time
>
> 23e69343imap://[e-mail]:993
>         /fetch%3EUID%3E/AA/AAAA%3E4?section=2                   1484645 bytes             1   2011-01-31 17:03:06   No expiration time

Following two Disk Cache files correspond to above two entries for attachment.
> C:\Documents and Settings\wada\Local Settings\Application Data\Thunderbird\Profiles\wxkq5msh.Gmail-IMAP\Cache
> ...\6\39\078ECd01 2011/01/31 17:03 1,484,603 bytes
> ...\E\2B\7CA02d01 2011/01/31 17:03 1,484,645 bytes 

(1) If small text/plain mail(UID=2,UID=3), whole data is cached and is re-used.
(2) Nothing is seen in Disk Cache entry for "fetch BODY[1]" of UID=4.
    It seems reason why Bug 565852 comment #25 (Problem-A) occurs.
    Memory cache is used?
    Kept in _CACHE_xxx_ file because of small text, and entry is invalidated
    after use for mail display?
(3) If attachment part(UID=4,BODY[2]), fetch/storing in Disk Cache is executed twice.
      (i)  /;section=2  (section name is a file-path part of URL)  
      (ii) ?section=2   (section name is search string of URL) 
    It looks one of causes of this bug.
    Why file size is different?
(4) Expires is not set if entry for mail data.
    Expires is set as expected if entry for jpeg data etc.
    IIRC, bug report for "no expiration control" exists.

Comment 5

[rsx11m]

David, any idea where this may be coming from?

Comment 6

[David :Bienvenu]

(In reply to comment #5)
> David, any idea where this may be coming from?

As far as the cache is concerned in your initial STR, I wouldn't think turning off the disk cache would be relevant, since we don't treat the disk cache differently from the mem cache. And presumably this is not an attachment we can display inline. There are several possibilities; one is that the cache lookup is failing, perhaps because the key is different, or we're looking at the cache entry and deciding it's invalid, or we're throwing it away for some other reason. I'll try to debug it quickly...

Comment 7

[rsx11m]

(In reply to comment #6)
> turning off the disk cache would be relevant, since we don't treat the disk cache
> differently from the mem cache. [...] not an attachment we can display inline.

Correct, the main reason I switched off the disk cache was to ensure that everything is "clean" on startup, and WADA could reproduce with disk cache.
That attachment was a ZIP file, thus not suitable for inline display.

Comment 8

[WADA:World Anti-bad-Duping Agency]

_CACHE_002_ content in test of comment #4.  

(1) data of mail#1(UID=2, whole mail data) was seen in _CACHE_001_.   
(2) data of mail#2(UID=3, whole mail data) was seen in _CACHE_003_.   
(3) data like next for mail#3(UID=4) was seen in _CACHE_002_.
text/plain part(downloaded by fetch body[1]) is merged with mail headers, and not-downloaded application/pdf part is written with "X-Mozilla-IMAP-Part: 2" and "This part will be...".
> Received: from [127.0.0.1] (KHP222009106185.ppp-bb.dion.ne.jp [222.9.106.185])
>(snip)
> Content-Type: multipart/mixed; boundary="------------010904010901020702040308"
>
> --------------010904010901020702040308
> Content-Type: text/plain; charset=ISO-8859-1; format=flowed
> Content-Transfer-Encoding: 7bit
>
> with-pdf-attachment
> --------------010904010901020702040308
> X-Mozilla-IMAP-Part: 2
> Content-Type: application/pdf; name="ECMA-357.pdf"
> Content-Transfer-Encoding: base64
> Content-Disposition: attachment; filename="ECMA-357.pdf"
>
> This body part will be downloaded on demand.
> --------------010904010901020702040308--
(4) Following lines are also seen in in _CACHE_002_. (fields are perhaps separated by 0x00)  
> lIMAP-anywhere:23e69343imap://[e-mail]:993/fetch%3EUID%3E/AA/AAAA%3E2 ContentModified Not Modified security-info FnhllAKWRHGAlo+ESXykKAAAA...(snip)
> lIMAP-anywhere:23e69343imap://[e-mail]:993/fetch%3EUID%3E/AA/AAAA%3E3 ContentModified Not Modified security-info FnhllAKWRHGAlo+ESXykKAAAA...(snip)
> uIMAP-anywhere:23e69343imap://[e-mail]:993/fetch%3EUID%3E/AA/AAAA%3E4 ContentModified Modified View As Link security-info FnhllAKWRHGAlo+ESXykKAAAA...(snip)

"l" at left most position for UID=2 and UID=3 seems "valid cache entry".
"u" at left most position for UID=4 seems "invalidated data or partial data".
No part number is added to internal URL for UID=4(multipar/mixed, text/plain part is fetched by fetch body[1].)

Comment 9

[rsx11m]

(reposting from bug 345832 comment #144)
> I've seen 0-size attachments showing up on the 5.0 branch resembling
> on-demand attachments, with a "busy" indication in the status bar when
> viewing such a message suggesting an incomplete download of the MIME
> part. It's not clear to me if that's part of bug 629738 or a new problem
> now, somewhat hard to reproduce.

Anybody else seeing this as well?

Comment 10

[Thomas D. (:thomas8)]

rsx11m, would you think that Bug 329660 is a duplicate of your bug?

Per Bug 329660 comment 10, such problem of bug 329660 and this bug 629738 might have been solved by bug 740453. Could you re-test your steps if this bug still occurs?

Comment 11

[costinel]

this behaviour still ocurs on tb 24.3.0
i connect over a slow vpn and it's easily reproductible with any attachment: slow down the network link between client and server, then watch tb download the attachment when clicking the email, then downloading again when clicking the attachment name.

Comment 13

[rsx11m]

Sorry for the late response to the needinfo request. Yes, confirming costinel's comment #11, this is still reproducible both with the current 31.0a1 nightly and the 24.4.0 release builds on Windows 7.

With (1) synchronization disabled, (2) download on demand left at its default values, (3) Global Indexing disabled, and (4) the disk cache disabled (don't know if the latter is relevant),

 1. Thunderbird upon first-time opening of the message does not download the attachment as intended
 2. when opening the attachment:
    a. the progress bar indicates action from 0% to 100%, network activity present
    b. "Open" dialog is shown, confirming opens the document as desired, but then
    c. the progress bar indicates action from 0% again, network activity persists
 3. going to a different message, returning to the first, opening the same attachment:
    b. "Open" dialog is shown immediately, confirming opens the document without delay
    c. the progress bar indicates action from 0% again, network activity resumes

Interestingly, the behavior on SeaMonkey 2.28a1 trunk builds is different:

 1. SeaMonkey upon first-time opening of the message does not download the attachment as intended
 2. when opening the attachment:
    a. "Open" dialog is shown, confirming starts the download process
    b. progress bar in Download Manager indicates action from 0% to 100%, network activity present
    c. the document is opened, no further network or UI activity
 3. going to a different message, returning to the first, opening the same attachment:
    a. "Open" dialog is shown immediately, confirming opens the document without delay
    b. progress bar in the Download Manager goes from 0% to 100% immediately, no network action

Thus, something is different in the way SeaMonkey handles attachments given that it seems to do it the right way whereas only Thunderbird has the "shadow" download after opening the document. Bug 740453 may have fixed one aspect of the issue, but another one seems to be still around asking to be fixed.

Comment 14

[Jorg K (CEST = GMT+2)]

I'm looking into this in bug 1021843. Apparently it needs to a plaintext or HTML message with a non-image attachment, for example a PDF. What happens is that the message is (partly) cached, and when it comes to reuse the cache entry, it is rejected. See bug 1021843 comment #55. Basically, the cache entry is marked "Modified View Inline", which prevents reuse. Even if ignoring that, next there is a mismatch in cache entry and message size, since a part size is compared to the full message size.

Comment 15

[Jorg K (CEST = GMT+2)]

I decided to fix bug 1021843 first in order to keep issues separate. Once that's landed, I'll continue here. It's been broken for 5.5 years now, so it can wait a little longer. Most likely it's something fairly trivial (see comment #14 or Wada's observations in comment #4 (/;section=2 vs. ?section=2 and size issues).

Comment 16

[Jorg K (CEST = GMT+2)]

With some debug prints, I can see exactly what Wada reported. These URIs are cached:
(snip)/;section=2?part=1.2&filename=A01.JPG
(snip)?section=2?part=1.2&filename=A01.JPG&type=image/jpeg&filename=A01.JPG
I was using a message with attached images without inline preview.
With inline preview, caching works as expected. While the cache generally works, there seems to be quite a mess in requesting parts (wrongly) causing the message to be fetched again and stored in the cache again.

Comment 17

[Jorg K (CEST = GMT+2)]

You get a little history of "/;section=" vs. "?section=" by clicking:
https://dxr.mozilla.org/comm-central/search?q=%3Bsection&redirect=false
"/;section=" is created in mimei.cpp. There are two spots where "/;section=" is changed to "?section" for no apparent reason (nsImapService.cpp and nsMessenger.cpp) and then there are a few spots that deal with the two variants ... and say:
  unforunately (sic.) an imap part can have the form: /;section= OR ?section=.

Anyway, the caching code should rip both variants out and reduce the URL to the part and perhaps the filename, so 
(snip)/;section=2?part=1.2&filename=A01.JPG
(snip)?section=2?part=1.2&filename=A01.JPG&type=image/jpeg&filename=A01.JPG
become
(snip)?part=1.2&filename=A01.JPG

See here
https://dxr.mozilla.org/comm-central/rev/cd5ba215a523a82a8e4ef980b0654fe2a9af09fd/mailnews/imap/src/nsImapService.cpp#296
for how type and filename get added.

And see bug 1021843 comment #55 for some "nice" URLs that we should aim for.

That can be done easily and is a first step. Then there are other problems as mentioned in comment #14.

Comment 18

[Jorg K (CEST = GMT+2)]

Attachment: WIP: remving section= and type=

This "normalises" the URL before the cache access to:
(snip)?part=x.y&filename=file.ext

However, this doesn't help at all due to the completely broken cache access logic as far as "parts vs. whole message" is concerned. As far as I've seen, the current logic fails to cache any parts correctly. This needs thorough looking at after bug 1021843 has landed.

Comment 19

[Jorg K (CEST = GMT+2)]

Attachment: WIP: removing section= and type=

(more elegant)

Just for the record:
nsImapMockChannel::ReadFromMemCache() has some checks whether a cache entry should be used. One is to compare the cache entry data length to the message length. That will work real well for parts (NOT!):
https://dxr.mozilla.org/comm-central/rev/8c7ddccf95c4168995fa6e57182133f22d21be03/mailnews/imap/src/nsImapProtocol.cpp#9170

It also checks for a header at the start of the entry:
https://dxr.mozilla.org/comm-central/rev/8c7ddccf95c4168995fa6e57182133f22d21be03/mailnews/imap/src/nsImapProtocol.cpp#
That also won't work for parts.

In short: This logic is well and truly broken. Looking at blame, this comes from bug 609683, bug 531033 and bug 740453. Difficult territory.

Comment 20

[Jorg K (CEST = GMT+2)]

Attachment: Useful debug patch, originally from bug 1021843.

Comment 21

[Jorg K (CEST = GMT+2)]

Just for the record:
Bug 609683: https://hg.mozilla.org/comm-central/rev/9d7a6096be80#l2.112
Bug 531033: https://hg.mozilla.org/comm-central/rev/f0c903a93fc6#l2.14
Bug 740453: https://hg.mozilla.org/comm-central/rev/cc21e9b859a5#l1.13
At least the first change will be 100% in the way of caching parts, because part size is not equal total message size. Maybe the other two changes are OK, since parts will also have headers, for example:
Content-Type: application/pdf; name=ESDHSSPANISH1.pdf
Content-Transfer-Encoding: base64

Comment 22

[alta88]

It's my understanding that various things are added to the url in order to transmit information further on, ie the url is abused (rightly or wrongly). But all a mime part's cache entry should need is uniqueness - and the combination of folder url + message key + part number should be sufficient for global uniqueness. A name parm isn't required in Content-Type, so can't be counted on.

This could be wrong, and there may be some valid reason these additional pieces (name, size) were added, because it's just so odd otherwise. Maybe libmime couldn't reliably get a part number? That would be sad.

Comment 23

[Jorg K (CEST = GMT+2)]

(In reply to alta88 from comment #22)
> But all a mime part's cache entry should need is uniqueness - and the
> combination of folder url + message key + part number should be sufficient
> for global uniqueness.
Agreed, that's why I want to remove the /;section-nn or ?section=nn and the &type= as is already done in the attached patch (see comment #18).

> A name parm isn't required in Content-Type, so can't be counted on.
The code only checks for a header with a colon (":"), so Content-Type: would already satisfy this.

> This could be wrong, and there may be some valid reason these additional
> pieces (name, size) were added, because it's just so odd otherwise. Maybe
> libmime couldn't reliably get a part number? That would be sad.
I'll look into it during the next few weeks. As I said in comment #21: So far I believe that the logic accessing the cache doesn't lend itself to storing parts, see also bug 1021843 comment #67 to see that parts really aren't stored at all. Only complete messages. And where a complete message isn't retrieved due to "parts on demand", the whole logic falls apart as can be seen in this bug here.

Images are somewhat different since attached images that need to be viewed inline cause the entire message to be retrieved and stored. The trouble starts when switching off inline display of attachments or using attachments, like PDF, which aren't displayed inline in any case.

Comment 24

[alta88]

Right, it seems mail.imap.mime_parts_on_demand (default true) is fairly useless, since mail.inline_attachments (default true) will always need to download/parse the whole thing to even know if there's an inlineable attachment (image).  So if the latter is true, it's pointless to download partials.

Thanks for all the recent really great work, btw.

Comment 25

[Jorg K (CEST = GMT+2)]

Attachment: Useful debug patch, originally from bug 1021843 (v2)

Here is the debug patch again, with more debug to look into the various cases.

First a little survey of what works and what doesn't.

I have four test messages in a folder with no local storage.
1) plain text with four attached images.
2) HTML with two embedded/attached imaged.
3) plain text with PDF attachment.
4) HTML with PDF attachment.

So, click on the message, click on a dummy message, then revisit the test message.

A) mail.imap.mime_parts_on_demand=true and mail.inline_attachments=true
1) Works, whole message is cached, images retrieved from entire message.
2) Works, whole message is cached.
3) + 4) Does not work, rejection: annotation: |Modified View Inline|

B) mail.imap.mime_parts_on_demand=true and mail.inline_attachments=false
1) Does not work, rejection: annotation: |Modified View As Link|
   Opening attached images repeatedly caches them.
2)3)4 Does not work, rejection: annotation: |Modified View As Link|

C) mail.imap.mime_parts_on_demand=false and mail.inline_attachments=true
All cases behave as in A)

D) mail.imap.mime_parts_on_demand=false and mail.inline_attachments=false
All cases behave as in B)

So I think the first job is to check out the "annotation" which comes for the "ContentModified" meta data element of the cache entry since it blocks the reuse of cache entries.

BTW, I was wrong in comment #19 and comment #21. For parts, which I haven't seen stored yet, is does *not* compare the cache entry size to the message size. I overlooked an if-clause ;-(

Comment 26

[Jorg K (CEST = GMT+2)]

Just for the record: The meta data is set here in nsImapUrl::SetContentModified().
https://dxr.mozilla.org/comm-central/rev/f3f22e07b8e8beb02592cd68c83267fe570e59e9/mailnews/imap/src/nsImapUrl.cpp#1066

This is called in several places:
https://dxr.mozilla.org/comm-central/search?q=SetContentModified
On call site says: "This will be looked at by the cache".

Notable the calls in nsIMAPBodyShell.cpp where one says:
m_protocolConnection->SetContentModified(IMAP_CONTENT_NOT_MODIFIED);	// So that when we cache it, we know we have the whole message

So it appears to be the original design that messages fetched incompletely are tagged either
IMAP_CONTENT_MODIFIED_VIEW_INLINE or IMAP_CONTENT_MODIFIED_VIEW_AS_LINKS (as observed)
https://dxr.mozilla.org/comm-central/rev/f3f22e07b8e8beb02592cd68c83267fe570e59e9/mailnews/imap/src/nsIMAPBodyShell.cpp#73
and that their cache entries don't get reused ever again.

I talked to Kent on IRC and there is no one left around who understands this design. So I'm not in a position to change this "content modified" business.

What I did notice though is that when opening an attached PDF, that part gets fetched and cached, however, when revisiting it, it gets requested with at different section. This is due to the /;section= vs. ?section=, so I will continue the investigation there.

Comment 27

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v1a).

This does the trick.
Parts (attachments) are cached and when they are opened, the cache is used.
URLs are normalised, the funny section stuff is removed.

Comment 28

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work.

I have a question for Honza. What happens when a cache entry is requested twice almost concurrently, most likely by two different threads.

In my debugging I can see that the entry is opened and it's new. So I write to it. Shortly after, it's opened for read, and the size is retrieved as 0, maybe the write hasn't finished. Looks like it's read OK though and everything works.

So what should I do about this?

Magnus, you can delay the review until after this is answered.

Comment 29

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v2).

Will now compile on all platforms.

Comment 30

[Jorg K (CEST = GMT+2)]

(In reply to Jorg K (GMT+2, PTO during summer) from comment #28)
> I have a question for Honza. What happens when a cache entry is requested
> twice almost concurrently, most likely by two different threads.
(snip)
> So what should I do about this?
https://developer.mozilla.org/en-US/docs/Mozilla/HTTP_cache suggests that readers can read while the writer is still writing. I hope you make sure that the reader won't outperform/overtake the writer and therefore not get all the data.

Comment 31

[Jorg K (CEST = GMT+2)]

Note that the concurrent write/read access looks like this in the debug:

=== |imap://[e-mail]:993/fetch%3EUID%3E.INBOX.AAA%20Test%20no%20local%20storage%3E10?part=1.2&filename=RG1.pdf|
=== nsImapMockChannel::OnCacheEntryAvailable: WRITE
=== nsImapMockChannel::OnCacheEntryAvailable: WRITE END

=== cacheStorage->AsyncOpenURI IMAP, part (1)
=== |imap://[e-mail]:993/fetch%3EUID%3E.INBOX.AAA%20Test%20no%20local%20storage%3E10?part=1.2&filename=RG1.pdf|
=== nsImapMockChannel::OnCacheEntryAvailable - reading part, FOUND, length 0
=== nsImapMockChannel::OnCacheEntryAvailable: READ, size=0 <<<=== Size is returned zero.
=== 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

However, I have no indication that the read fails or is incomplete.

Try run:
https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=fecf2da555635528555acd56251effca1517bed2
If you subtract the failures from bug 1300059 and bug 1300395 there are test failures in
mailnews/imap/test/unit/test_dod.js

Comment 32

[Jorg K (CEST = GMT+2)]

The test uses test cases/data in mailnews/test/data and the failing cases are bodystructuretest1 and bodystructuretest2. The remaining ones pass.

Looks like the tests use URL's like
imap://user@localhost:50218/fetch%3EUID%3E%5EINBOX%3E1?header=quotebody.

The ? is mistaken for a part, and it goes wrong after this.

Comment 33

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v1b).

OK, tests pass now.

Comment 34

[Honza Bambas (:mayhemer)]

Comment on attachment 8787970 [details] [diff] [review]
Proposed solution (v1b).

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

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +9195,5 @@
>      if (shouldUseCacheEntry)
>      {
>        int64_t entrySize;
>  
> +      (void) entry->GetDataSize(&entrySize);

this change is absolutely wrong.  you MUST check the result.

please read the idl files in /cache2 on how this is correctly used.

Comment 35

[Honza Bambas (:mayhemer)]

Comment on attachment 8787970 [details] [diff] [review]
Proposed solution (v1b).

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

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +8990,5 @@
> +    if (mTryingToReadPart)
> +    {
> +      if (aNew)
> +      {
> +        entry->AsyncDoom(nullptr);

and this sounds bad too.  if you read the IDL documentation carefully you find out there is a flag to open cache entry only if it exists in the cache - OPEN_READONLY.  You would then never get OnCacheEntryAvailable with NS_OK and aNew == true.  You would just get NS_ERROR_CACHE_ENTRY_NOT_FOUND (not sure of exact name) - OR - NS_OK and the existing entry (aNew == false).

Again, please read the IDL docs in cache2 and if anything is not clear, just ask before you waste time writing something that is wrong.

Comment 36

[Honza Bambas (:mayhemer)]

(In reply to Jorg K (GMT+2, PTO during summer) from comment #28)
> Created attachment 8787907 [details] [diff] [review]
> Debug patch if you want to see this at work.
> 
> I have a question for Honza. What happens when a cache entry is requested
> twice almost concurrently, most likely by two different threads.

Let's assume there is no entry for that context/url during open.  Regardless if it happens on one thread or two threads, the "winning" consumer will get OnCacheEntryAvailable() call with NS_OK and aNew == true.  It becomes the "writer" responsible for two things: fill the metadata on the entry (if applicable and needed), write the data.

The "loosing" or "pending" consumer(es) will be blocked until one of happens with the entry:
- MetaDataReady() method is called on it (intended to be called after all vital metadata are set on the entry)
- OpenOutputStream() is called on it
- the entry is either doomed or simply released (reference is threw away)

Let's say the writer (or anyone!) calls OpenOutputStream() or MetaDataReady() on the entry.  After that the pending consumers will ALL get OnCacheEntryCheck call with the entry to examine.  If the output stream on the entry is not yet closed, GetDataSize will throw NS_ERROR_IN_PROGRESS.  It means that data write is still in progress.  You can either start reading concurrently (just by returning ENTRY_WANTED from OnCacheEntryCheck) without knowing the size, or wait until the entry is completely written (output stream closed, hence the size is known, GetDataSize returns NS_OK and the data size) by returning RECHECK_AFTER_WRITE_FINISHED from OnCacheEntryCheck.  OnCacheEntryCheck will then be called again for those consumers doing that AFTER output stream was closed.

That's all.

And it's all I think well documented in cache2/*.idl.  Please read those comments, it will help.

Comment 37

[Jorg K (CEST = GMT+2)]

Comment on attachment 8787970 [details] [diff] [review]
Proposed solution (v1b).

Thank you for all the comments!

(In reply to Honza Bambas (:mayhemer) from comment #34)
> > +      (void) entry->GetDataSize(&entrySize);
> this change is absolutely wrong.  you MUST check the result.
In my defence I must say that before (cache(1) version) the return value was ignored:
https://hg.mozilla.org/comm-central/annotate/fca207401880/mailnews/imap/src/nsImapProtocol.cpp#l9154
(Thanks for teaching me to use permalinks.) 
That call should only happen where no concurrent reading is expected. Anyway, I'll fix it.

(In reply to Honza Bambas (:mayhemer) from comment #35)
> > +      if (aNew) {
> > +        entry->AsyncDoom(nullptr);
> and this sounds bad too.
Dooming a new entry is not elegant, I agree, but the (pre-)existing logic requested all the entries the same (nsICache::ACCESS_READ_WRITE;), even if they had to be thrown away:
https://hg.mozilla.org/comm-central/annotate/fca207401880/mailnews/imap/src/nsImapProtocol.cpp#l8999
https://hg.mozilla.org/comm-central/annotate/fca207401880/mailnews/imap/src/nsImapProtocol.cpp#l9100
https://hg.mozilla.org/comm-central/annotate/fca207401880/mailnews/imap/src/nsImapProtocol.cpp#l9122
I'll look into restructuring this.

(In reply to Honza Bambas (:mayhemer) from comment #36)
Thanks for the explanation re. concurrent reading. Only in my debug patch did I get data size 0 due to ignoring the status on a concurrent read. I'll fix that.

> And it's all I think well documented in cache2/*.idl.  Please read those
> comments, it will help.
Oh, the documentation is in the code, well, the interface files in this case ;-)
I'll give them a good read.

Comment 38

[Jorg K (CEST = GMT+2)]

Attachment: WIP: (v2).

This addresses Honza's issues. While testing I found more variations on the URL, so the normalisation needs to change.

Comment 39

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v2a).

Fixed normalisation. Will test some more and then request review.

Comment 40

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v2a).

Comment 41

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v2b).

Sadly it turned out that OPEN_READONLY couldn't be used since it's used in another context to skip caching altogether. So it's back to the less elegant dooming.

Comment 42

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v2b).

Comment 43

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v2c).

Removed spaghetti code and created utility function instead to strip query parts. I won't attach the debug patch again to reduce noise. It will come for the review.

Comment 44

[Jorg K (CEST = GMT+2)]

Attachment: WIP: test (v1a).

Comment 45

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution: test (v2a).

I go the test going, I had to fix a few things in nsImapService.cpp.

Comment 46

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v2c).

Debug patch.

Grammar correction: I *got* the test going.

Comment 47

[Jorg K (CEST = GMT+2)]

Comment on attachment 8788087 [details] [diff] [review]
Proposed solution (v2c).

This should be good to go now.

Comment 48

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v3a).

Sorry about the noise ;-)

Here a little background. The cache distinguishes between two types of messages: Those which are cached completely (meta data "not modified") because all their parts are inline, and needed for display and those which are not cached completely.

The previous patch had the downside that "complete" messages were read via the IMAP connection multiple times, once to retrieve the entire message and once to retrieve the parts.

In this patch I'm optimising this, and sadly it has become very complicated:
If you're displaying parts inline and there are only inline parts (like pictures, *no* PDF attachments), then the message is read completely and the parts are extracted from it.

If the message contains a non-inline attachment and (or attachments are not displayed inline) the parts will be cached separately.

(I'll have to redo the test, too.)

Comment 49

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v3a).

Comment 50

[Jorg K (CEST = GMT+2)]

Attachment: WIP: Test (v3a).

Honza, in my test I want to modify the metadata of a cache entry, so I do:

  MailServices.imap
              .cacheStorage
              .asyncOpenURI(gMsgURL2, extension, Ci.nsICacheStorage.OPEN_NORMALLY, {
      onCacheEntryAvailable: function(cacheEntry, isNew, appCache, status) {
        dump(isNew+"===============\n");
        dump(status+"===============\n");
        // cacheEntry.setMetaDataElement("ContentModified", "Modified View As Link");
      }
  });

onCacheEntryAvailable is called with a null cacheEntry and status 2152398909 = 0x804b 003d.

I can't find the definition of this status and I don't understand why this is going wrong. The cache entry was written before.

In general, I have trouble mapping the network errors to something meaningful. For example, in bug 1299562 comment #3 I went chasing for 0x804B000D. There I found it.

I can see a few occurrences of NS_ERROR_MODULE_NETWORK but nothing with +61 or 0x3d. BTW, errors are not documented for onCacheEntryAvailable in nsICacheEntryOpenCallback.idl.

Comment 51

[Jorg K (CEST = GMT+2)]

Found it: var NS_ERROR_CACHE_KEY_NOT_FOUND = kNetBase + 61;

Comment 52

[Jorg K (CEST = GMT+2)]

Hmm, I'm not sure that why this happens, my debug shows:

"=== nsImapMockChannel::OpenCacheEntry |imap://user@localhost:60814/fetch%3EUID%3E/INBOX%3E2|"
"=== cacheStorage->AsyncOpenURI IMAP, part (0)"
"=== |imap://user@localhost:60814/fetch%3EUID%3E/INBOX%3E2|"
"=== nsImapMockChannel::OnCacheEntryAvailable: WRITE END"

"imap://user@localhost:60814/fetch%3EUID%3E/INBOX%3E2"
"false==============="
"2152398909==============="

So for the very same cache entry that got written before, I now get NS_ERROR_CACHE_KEY_NOT_FOUND. Even more surprising to get NS_ERROR_CACHE_KEY_NOT_FOUND on an "OPEN_NORMALLY" which should just return a new entry.

Comment 53

[Jorg K (CEST = GMT+2)]

Looks like the onCacheEntryCheck callback is missing. I'll look at some other examples, for example here:
https://dxr.mozilla.org/comm-central/rev/dbe4b47941c7b3d6298a0ead5e40dd828096c808/mozilla/netwerk/test/mochitests/test_web_packaged_app.html#37

Comment 54

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution: test (v3a).

Here comes the test. For messages that are cached completely, it tests that parts are NOT cached separately. This is the previous behaviour. For messages with non-inline parts/attachments, it tests that these parts are cached separately from the overall message. So for example any PDF attachment will only be downloaded once.

Comment 55

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution: test (v3a+).

(Grr, some debug had sneaked in.)

Comment 56

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v3b).

Same code as v3a but with improved comments. I wanted to comment on the patch and noticed that it was better to put the documentation into the code rather than BMO.

Comment 57

[Jorg K (CEST = GMT+2)]

Comment on attachment 8788453 [details] [diff] [review]
Proposed solution (v3b).

It becomes clearer when you run it with debug. You need the four test messages described in comment #25.

I have a green try run here:
https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=7d26cc5c94b823d70dae55b55d4f0819ceb7ca94
(You need to ignore the Xpcshell failures from bug 1300059.)

Comment 58

[Honza Bambas (:mayhemer)]

Jorg, slow down ;)  read the docs carefully.  It will save you and me a lot of time.  I thought I mentioned OnCacheEntryCheck at least once.  Anyway, if there is a problem I'm happy to help.  Logs with cache2:5 may do (when you also give me URIs to hunt in the log for) in case you are out of ideas.

Comment 59

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v3b).

Comment 60

[Jorg K (CEST = GMT+2)]

(In reply to Honza Bambas (:mayhemer) from comment #58)
> Jorg, slow down ;)  read the docs carefully.  It will save you and me a lot
> of time.  I thought I mentioned OnCacheEntryCheck at least once.
OnCacheEntryCheck was missing from my test in JS, that's all. I added it and all works as desired.

The difficult part here is the application logic with messages which can have parts and can either be cached entirely or part-wise. And if they are cached entirely, there is still a class that is cached incomplete and can't be used for parts extraction.

I think it's sorted out now. In the last revision I added tons of comments. Since I also provide a debug patch for testing, every revision generates double the noise. Sorry. I'll stop now.

Only one question remains:
When I see error 2152398909 = 0x804b 003d, what is the quickest way to identify this as
NS_ERROR_CACHE_KEY_NOT_FOUND = kNetBase + 61?

And returning this because OnCacheEntryCheck couldn't be called is a little misleading, no?

Comment 61

[Honza Bambas (:mayhemer)]

(In reply to Jorg K (GMT+2, PTO during summer) from comment #60)
> (In reply to Honza Bambas (:mayhemer) from comment #58)
> > Jorg, slow down ;)  read the docs carefully.  It will save you and me a lot
> > of time.  I thought I mentioned OnCacheEntryCheck at least once.
> OnCacheEntryCheck was missing from my test in JS, that's all. I added it and
> all works as desired.

Good!

> 
> The difficult part here is the application logic with messages which can
> have parts and can either be cached entirely or part-wise. And if they are
> cached entirely, there is still a class that is cached incomplete and can't
> be used for parts extraction.

Understand.  You can always doom the entry immediately you conclude it be partial only and thus actually non-reusable for your purpose.

> 
> I think it's sorted out now. In the last revision I added tons of comments.
> Since I also provide a debug patch for testing, every revision generates
> double the noise. Sorry. I'll stop now.

That's alright!

> 
> Only one question remains:
> When I see error 2152398909 = 0x804b 003d, what is the quickest way to
> identify this as
> NS_ERROR_CACHE_KEY_NOT_FOUND = kNetBase + 61?

http://james-ross.co.uk//mozilla/misc/nserror?804b003d

> 
> And returning this because OnCacheEntryCheck couldn't be called is a little
> misleading, no?

Yes.. that may be confusing, that's right.  We might want to return the error that we got from call to OnCacheEntryCheck (which may be some JS_NOT_IMPLEMENTED or some like) leading to cause more quickly.  Bug 1300796 filed.

Comment 62

[Jorg K (CEST = GMT+2)]

Thanks for your continued support.

(In reply to Honza Bambas (:mayhemer) from comment #61)
> (In reply to Jorg K (GMT+2, PTO during summer) from comment #60)
> > The difficult part here is the application logic with messages which can
> > have parts and can either be cached entirely or part-wise. And if they are
> > cached entirely, there is still a class that is cached incomplete and can't
> > be used for parts extraction.
> Understand.  You can always doom the entry immediately you conclude it be
> partial only and thus actually non-reusable for your purpose.
Perhaps you can help me here. The logic is this, abridged version:
Call AsyncOpenURI() for a URL representing a message part, like an image.
If not found, doom new entry (*).
The callback then (indirectly) calls AsyncOpenURI() for a URL representing the whole message.
If whole message is "partial" and can't be used, the second callback calls AsyncOpenURI() for a third time, this time with the original part URL, this time causing the cache entry to be written for the part in the third invocation of the callback.
(*): You suggested using "read-only". We can't do that, since read-only is already used to "skip" cache processing. Under certain circumstances we always call "read-only", and when NS_ERROR_CACHE_KEY_NOT_FOUND is returned, we just read the data directly from the mail server.

Sounds like spaghetti code where the "slave calls the master"?
Now this could be improved like this:
We check if the part is in the cache using Exists(), if so, we call AsyncOpenURI() on its URL. Done.
If the part doesn't exist, call AsyncOpenURI() with the URL of the entire message.
Use the onCacheEntryCheck() function to weed out unwanted "partial" entries.
OK, the documentation says to return ENTRY_NOT_WANTED. Should the entry be doomed in onCacheEntryCheck() right away?
The documentation doesn't say what happens in onCacheEntryAvailable() in this case. So:
AsyncOpenURI() is called, onCacheEntryCheck() returns ENTRY_NOT_WANTED and perhaps dooms the entry. What happens in onCacheEntryAvailable()? It gets a new entry or an error code that the entry doesn't exist or something else?
I still need to go back calling AsyncOpenURI() for the part URL, if I have no luck with getting the part from the entire message.

> > I think it's sorted out now. In the last revision I added tons of comments.
> > Since I also provide a debug patch for testing, every revision generates
> > double the noise. Sorry. I'll stop now.
> That's alright!
Well, as indicated, what I have works but I'm trying to make it simpler. Of course that will create more noise.

> http://james-ross.co.uk//mozilla/misc/nserror?804b003d
Hmm, Mozilla needs to external websites to explain its error codes? No so impressive especially given that the site answers in absolute snail pace.

Putting NI again since I don't know what's the best way to get attention ;-)

Comment 63

[Jorg K (CEST = GMT+2)]

(In reply to Jorg K (GMT+2, PTO during summer) from comment #62)
> AsyncOpenURI() is called, onCacheEntryCheck() returns ENTRY_NOT_WANTED and
> perhaps dooms the entry. What happens in onCacheEntryAvailable()? It gets a
> new entry or an error code that the entry doesn't exist or something else?
It gets NS_ERROR_CACHE_KEY_NOT_FOUND, I tried it ;-)
I'll think about how to simplify the application logic.

Comment 64

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v4a).

I ripped out the spaghetti logic and redid the whole handling. A lot of complication was removed this way.

I'll do some more testing and then ask for review again.

Sorry about the noise.

Comment 65

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v4b).

Minor tweak. Should be right now.
Green try run here:
https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=0789cf301aa23201998d097422760849a4460be4
(subtract the failures from bug 1300059).

Comment 66

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (v4a).

Comment 67

[Jorg K (CEST = GMT+2)]

I forgot to repeat: If becomes clearer when you run it with debug. You need the four test messages described in comment #25.

Comment 68

[Jorg K (CEST = GMT+2)]

Comment on attachment 8788413 [details] [diff] [review]
Proposed solution: test (v3a+).

Test written by a newcomer. Sadly I had to fix the code first :-(

Comment 69

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution: test (v3a+) (refreshed)

Also fixing some quotes, leftover from bug 870864.

Comment 70

[Kent James (:rkent)]

Attachment: Promisify the test

I have not yet really looked at your code, but here are the (rote) changes needed to convert your test to promises. do_check_??? is also considered obsolete, there is a direct Assert.??? equivalent.

Comment 71

[Jorg K (CEST = GMT+2)]

Comment on attachment 8792051 [details] [diff] [review]
Promisify the test

Fantastic!! Grand master Kent at work. Thanks so so so much!!
I will now supersede the test and your patch with the merged version.

Comment 72

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution: test (v4a), promise part by R Kent James

I have merged my and Kent's part and noted his authorship in the commit message.
Thanks again!
BTW, I ran it too and it still works ;-)

Comment 73

[Kent James (:rkent)]

Comment on attachment 8788775 [details] [diff] [review]
Proposed solution (v4b).

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

Probably more comments that you wanted :(

Part of the problem that you are trying to solve is previous poor parsing assumptions about the url query. But you have added your own fragile code with the same set of problems. Let's really fix it this time by using a proper query parser.

Reuse of newUri is confusing and make the code hard to follow.

Finally, when in a callback you can't just return on error, you need to understand what the parent protocol needs to not get hung. A simple error return hangs the protocol.

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +8979,5 @@
>      entry->AsyncDoom(nullptr);
>      return NS_OK;
>    }
>  
>    NS_ENSURE_ARG(m_url); // kick out if m_url is null for some reason.

We are in the middle of a callback generated by core code. In this situation, it is rarely the correct thing to do to simply return an error rv. Usually you need to understand what is the expected error callback from the routine, and do that.

@@ +9016,5 @@
> +      if (!aNew) {
> +        // Check the meta data.
> +        nsCString annotation;
> +        rv = entry->GetMetaDataElement("ContentModified", getter_Copies(annotation));
> +        NS_ENSURE_SUCCESS(rv, rv);

This is not a valid error response. The protocol is expecting some kind of callback, cache2 does not know how to propagate an error back to the protocol.

@@ +9074,5 @@
>    *aResult = nsICacheEntryOpenCallback::ENTRY_WANTED;
>    return NS_OK;
>  }
>  
> +// Little helper function to strip a query qualifier. Returns true if a change was made.

As I said earlier, I think that the better approach here would be to write a similar methods that extracts the value of particular query values, and reassemble the URI path to be what you want.

@@ +9143,5 @@
> +  nsAutoCString extension;
> +  extension.AppendInt(uidValidity, 16);
> +
> +  // Open a cache entry where the key is the potentially modified URL.
> +  nsCOMPtr<nsIURI> newUri;

I think that this variable newUri is a source of confusion in this code, later you have to add comments about what it is currently pointing at.

Could you instead create a little later either a partUri or a messageUri so that it is clear what you are using?

@@ +9148,3 @@
>    m_url->Clone(getter_AddRefs(newUri));
>    nsAutoCString path;
>    newUri->GetPath(path);

This could just was easily be

m_url=>GetPath(path)

with a delayed cloning until you know what it is you really want.

@@ +9148,5 @@
>    m_url->Clone(getter_AddRefs(newUri));
>    nsAutoCString path;
>    newUri->GetPath(path);
>  
> +  // These are seen in the wild:

This whole section seems fragile to me. You are assuming that you know what junk might get added to the URL when the whole idea of a query is that it is specification of variables with values. Wierd that a semicolon is an allowed separator, but solving that problem is beyond the scope of this bug.

Can't you parse the query field (allowing weirdly this semicolon) into an array of variables, look for the existence of certain variables (header=filter for example), then reassemble a URL that you want to cache based on what you really need (just part, right?) for the cachable URL? Or use a query value extractor to look for what you care about?

I faced the same general issue in ExQuilla protocol code. I wrote a simple utility getQueryVariable(name, spec) that would return the value of a query variable from a string spec.

@@ +9165,2 @@
>    int32_t anchorIndex = path.RFindChar('?');
> +  if (anchorIndex == kNotFound)

You are assuming that an empty query indicated that no part is needed. Isn't the more correct test whether there is a query entry for "part"?

@@ +9165,4 @@
>    int32_t anchorIndex = path.RFindChar('?');
> +  if (anchorIndex == kNotFound)
> +  {
> +    // Not looking for a part. That's the easy part.

Now that you know what you want, clone into messageUri and set the path to be what you really want, which I think means you want to clear the query, right?

@@ +9171,5 @@
> +
> +  // Check if this is a filter plugin requesting the message. In that case,
> +  // we're not fetching a part, and we want the cache key to be just the URI.
> +  nsAutoCString anchor(Substring(path, anchorIndex));
> +  if (anchor.EqualsLiteral("?header=filter") ||

This section is assuming that the header= is the first and only remaining variable, but that seems at odds to me with the normal assumption of a URL query field. This should behave correctly if other query fields are added, and if those additional fields are first. Note that similar sections in mime search for either "?header=" or "&header=" so this is very inconsistent.

Also, this AsyncOpenURI is really identical to the previous one, right? Can't you check for the existence of these header= values prior to deciding if you want to get a fell message URI from the cache, and then only have one place where you ask for that?

@@ +9181,5 @@
> +    newUri->SetPath(path);
> +    return cacheStorage->AsyncOpenURI(newUri, extension, cacheAccess, this);
> +  }
> +
> +  // Part processing.

This comment applies to the entire section below, so it needs to be formatted differently to make it clear that it is a major section comment, and not a comment on if (mTryingToReadPart)

@@ +9192,5 @@
> +    mTryingToReadPart = false;
> +
> +    // Do not truncate and leave the part name intact, so the cache can
> +    // store it appropriately.
> +    // Note that part extraction was already set the first time.

Another confusing comment caused by multiple uses of newUri.

@@ +9215,5 @@
> +  NS_ENSURE_SUCCESS(rv, rv);
> +
> +  if (!exists) {
> +    // The entire message is not in the cache.
> +    // Undo the damage we did to the URI and request the part.

This is the kind of confusing comment I would like to avoid. It is too hard to keep track of the state of newUri

Comment 74

[Jorg K (CEST = GMT+2)]

(In reply to Kent James (:rkent) from comment #73)
> Probably more comments that you wanted :(
Yes, and no, I thought of some of them myself already. Let's see.

> ::: mailnews/imap/src/nsImapProtocol.cpp
> @@ +8979,5 @@
> >      entry->AsyncDoom(nullptr);
> >      return NS_OK;
> >    }
> >  
> >    NS_ENSURE_ARG(m_url); // kick out if m_url is null for some reason.
> We are in the middle of a callback generated by core code. In this
> situation, it is rarely the correct thing to do to simply return an error
> rv. Usually you need to understand what is the expected error callback from
> the routine, and do that.
Hey, you're complaining about existing code. Complain to D/B instead ;-)
So what do I need to do here?

> This is not a valid error response. The protocol is expecting some kind of
> callback, cache2 does not know how to propagate an error back to the
> protocol.
And here?

> As I said earlier, I think that the better approach here would be to write a
> similar methods that extracts the value of particular query values, and
> reassemble the URI path to be what you want.
Indeed. I should extract the query values I want instead of madly trying to kill the bad bits.
100% agreement.

Let me do a new proposal based on that ;-)

But can you help me with the error response, please.

Comment 75

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v5a).

OK, I've fixed the query part. I'll continue once I have your answer re. the error handling.

Note: This is untested, but it cleans up the URL parsing as you suggested.

Comment 76

[Jorg K (CEST = GMT+2)]

Comment on attachment 8792148 [details] [diff] [review]
Proposed solution (v5a).

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

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +9153,5 @@
> +  ind = path.Find("/;");
> +  if (ind != kNotFound)
> +    path.SetLength(ind);
> +
> +  bool exists = false;

OK, I'll move that down.

Comment 77

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v5b).

(same as v5a, only comment changes and moved variable declaration down).

Comment 78

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v5c).

Tested and works. Still missing: Error handling in the cache callback.
Kent, please help/advise.

Comment 79

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (matching v5c).

Comment 80

[Kent James (:rkent)]

Comment on attachment 8792176 [details] [diff] [review]
Proposed solution (v5c).

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

I believe that you are just asking for suggestions for the error handling, so that is what I did (and all that I did). feedback- since it needs these implemented.

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +8980,5 @@
>      entry->AsyncDoom(nullptr);
>      return NS_OK;
>    }
>  
>    NS_ENSURE_ARG(m_url); // kick out if m_url is null for some reason.

Yes you did not write this, but we need a proper response. I believe that the correct response should be something like:

return Cancel(NS_ERROR_UNEXPECTED);

@@ +9017,5 @@
> +      if (!aNew) {
> +        // Check the meta data.
> +        nsCString annotation;
> +        rv = entry->GetMetaDataElement("ContentModified", getter_Copies(annotation));
> +        NS_ENSURE_SUCCESS(rv, rv);

Here we are failing while trying to do a cache entry. An error response could be, like the end of this method,

  return ReadFromImapConnection();

Bonus points for not having this statement twice. This is where I tend to use do () while(false); error loops.

Comment 81

[Jorg K (CEST = GMT+2)]

Comment on attachment 8792176 [details] [diff] [review]
Proposed solution (v5c).

Well, not being able to get the metadata for a cache entry that exists is equally unexpected, right?
So why not treat it similarly with
  return Cancel(NS_ERROR_UNEXPECTED);

The feedback was actually requested for the modified part extraction code that I did the way you wanted it.

Comment 82

[Kent James (:rkent)]

(In reply to Jorg K (GMT+2, can't work due to bug 1304183) from comment #81)
> Comment on attachment 8792176 [details] [diff] [review]
> Proposed solution (v5c).
> 
> Well, not being able to get the metadata for a cache entry that exists is
> equally unexpected, right?
> So why not treat it similarly with
>   return Cancel(NS_ERROR_UNEXPECTED);
> 
> The feedback was actually requested for the modified part extraction code
> that I did the way you wanted it.

With a null m_url I see no way for the method to proceed, hence cancel. In the other case, something went wrong with the cache, and we might still be able to proceed without it. That is why I did not propose Cancel there.

Comment 83

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v5d).

This features:
Better query part extraction as per first review (comment #73).
Modified error handling in the callback. In my book, not being able to get meta data for a cache entry that is known to exist shows a logic error somewhere and I believe it doesn't make much sense to carry on in this case.

Comment 84

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (matching v5d).

Comment 85

[Kent James (:rkent)]

(In reply to Jorg K (GMT+2) from comment #83)
> Created attachment 8793215 [details] [diff] [review]
> Proposed solution (v5d).
> 
> This features:
> Better query part extraction as per first review (comment #73).
> Modified error handling in the callback. In my book, not being able to get
> meta data for a cache entry that is known to exist shows a logic error
> somewhere and I believe it doesn't make much sense to carry on in this case.

I'm looking at this today, sorry for the delay but I had a lot of backlogged rabble rousing that I needed to do.

Your comment makes sense from a developer's point of view, but in release code the user just wants to display her email, and does not care that the cache has failed. You seem to assume that a cache failure indicates some sort of catastrophic failure that will also prevent a non-cache access from succeeding, but I don't know why you assume that. I don't really know why the cache might fail, but it is clearly optional so if it fails, why not try to proceed without it? That is, the onus is on you to make the case that this particular failure makes proceeding with non-cache email reading impossible, and I do not believe you have made a persuasive case. "shows a logic error somewhere" is not strong enough. A typical debug build of Thunderbird spews warnings where the developer shows a logic error. Thankfully they did not decide to abort at that point, but allowed the code to proceed as possible. That's all that I am asking as the normal response to a non-fatal error.

At the same time, we do want to see these errors. We probably need to have a warning call if the error is not reasonably expected during typical operation but indicates a logic error.

Comment 86

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v5e).

OK, keep going if meta data can't be retrieved.

Comment 87

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch if you want to see this at work (matching v5e).

Comment 88

[Kent James (:rkent)]

Comment on attachment 8796208 [details] [diff] [review]
Proposed solution (v5e).

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

OK with a few small points.

::: mailnews/imap/src/nsImapProtocol.cpp
@@ +8981,5 @@
>      return NS_OK;
>    }
>  
> +  if (!m_url)
> +    return Cancel(NS_ERROR_UNEXPECTED);  // Something has gone terribly wrong.

Please add a warning here before "return Cancel" so that we see the issue in debug builds.

@@ +8997,5 @@
> +    // For URLs not related to parts, the processing is easy:
> +    // aNew==true means that we need to write to the entry,
> +    // aNew==false means that we can read it.
> +    //
> +    // Parts processing is a little complicated, we distringuish two cases:

Nit: "distinguish"

@@ +9023,5 @@
> +        {
> +          // The cache entry is not marked "Not Modified", that means it doesn't
> +          // contain the entire message, so we can't use it. Call OpenCacheEntry()
> +          // a second time.
> +          return OpenCacheEntry();

We have the same error return issue here. OpenCacheEntry() can return an error, if it does then protocol hangs. We need to only return on success, else do the error fallback of reading from the imap connection.

Comment 89

[Jorg K (CEST = GMT+2)]

Attachment: Proposed solution (v5f).

Addressed the review comments. Also corrected some comments and used a |do ... while (false);| to control the main action in OnCacheEntryAvailable() to earn the bonus points ;-)

Comment 90

[Jorg K (CEST = GMT+2)]

https://hg.mozilla.org/comm-central/rev/f75bbafc8100
https://hg.mozilla.org/comm-central/rev/907ba80124fe

The astute reader will have spotted
if (NS_SUCCEEDED(rv));
  return rv;
in the attached patch (v5f). Luckily I spotted this before landing ;-)
Otherwise I'm sure the Linux or Mac C++ compilers would have noticed it. Windows didn't.