816922 - [Email] Certain HTML mail with CSP issue will bust mail parsing and make inbox stuck in message loading status

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::E-Mail, defect, P2)

Description

[Steve Chung [:steveck]]

Attachment: CSP issue log

Steps to reproduce
 - Open an email app with account that contains HTML mail with CSP issue.

Expected results
 - Messages can be loaded successfully and display the threads.

Actual results
 - Inbox stucks in message loading status

The account can receive the mail successfully in FF nightly but failed in my unagi device.

Comment 1

[Dylan Oliver [:doliver]]

Jim, let us know if you need any further help from QA to reproduce.

Comment 2

[Jim Porter (:squib)]

An email that reproduces the issue would help a lot.

Comment 3

[Ian Melven :imelven]

(In reply to Jim Porter (:squib) from comment #2)
> An email that reproduces the issue would help a lot.

from the log, it looks like one that loads external styles might trigger this ?

Comment 4

[Jim Porter (:squib)]

(In reply to Ian Melven :imelven from comment #3)
> from the log, it looks like one that loads external styles might trigger
> this ?

The obvious (<link rel="stylesheet" ...>) doesn't trigger this...

Comment 5

[Jim Porter (:squib)]

I merged in a fix to improve our logging a bit here:
  https://github.com/mozilla-b2g/gaia-email-libs-and-more/pull/90
  https://github.com/mozilla-b2g/gaia/pull/6765

Comment 6

[Jim Porter (:squib)]

Steve, do you think you could attach the source of the message that causes this issue? The HTML is really all I need, though the full message source couldn't hurt.

Comment 7

[Steve Chung [:steveck]]

Hi Jim,
Since the gecko is broken now, I only flash gaia part for testing. But the log seems that contains no additional log comparing to previous build.
I'm not sure the mail I've found is the root cause of this issue, but these emails do have the CSP issue. The weird thing is when I removed these mail to trash folder, inbox could complete the mail receiving. But trash folder also worked correctly. When I forward these emails to other account, these emails could be received successfully in other account. I will send these mail to you later, thanks.

Comment 8

[Steve Chung [:steveck]]

Attachment: Debug log from additional error information build

Comment 9

[Steve Chung [:steveck]]

Er... Because my mail account could not download any mail now, I give you the test account that I forwarded these mail previously(But these mail could be received in this account):
Email: [e-mail]
password: EmailTeam (beware of the capital)

Comment 10

[Alex Keybl [:akeybl]]

Mass Modify: All un-milestoned, unresolved blocking-basecamp+ bugs are being moved into the C3 milestone. Note that the target milestone does not mean that these bugs can't be resolved prior to 12/10, rather C2 bugs should be prioritized ahead of C3 bugs.

Comment 11

[Steve Chung [:steveck]]

I could not reproduce this bug now...
CSP warning log still exist, but sync completed log will show up before the CSP warning log.
So I'm not sure the blocking is caused by parsing the email or not.
Maybe we can close the issue first and reopen if somebody can reproduce this issue again.

Hi Ian,
I saw your comment that you were unable to receive any mail in https://bugzilla.mozilla.org/show_bug.cgi?id=814442#c3
Are you still unable to receive and mail now? Thanks.

Comment 12

[Andrew Sutherland [:asuth] (he/him)]

Steve, was the account you had the problem on ActiveSync or IMAP?  If it was IMAP, the actual problem was probably Bug 816987 (the MIME encoded-word fusion that then died on base64), but ActiveSync should not have triggered that code-path, which would mean there could still be a problem lurking in ActiveSync.  I got the impression it was ActiveSync.

Comment 13

[Steve Chung [:steveck]]

(In reply to Andrew Sutherland (:asuth) from comment #12)
> Steve, was the account you had the problem on ActiveSync or IMAP?  If it was
> IMAP, the actual problem was probably Bug 816987 (the MIME encoded-word
> fusion that then died on base64), but ActiveSync should not have triggered
> that code-path, which would mean there could still be a problem lurking in
> ActiveSync.  I got the impression it was ActiveSync.
Yes, the account I tested was ActiveSync(hotmail). Should I forward these suspected mails to IMAP account and try again?

Comment 14

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Steve Chung from comment #13)
> Yes, the account I tested was ActiveSync(hotmail). Should I forward these
> suspected mails to IMAP account and try again?

No.  I think the most likely explanation right now is that the message that was breaking synchronization was one of the older messages in your inbox near our sync threshold and that the message is no longer being synchronized.  It might be worth increasing the sync threshold to a longer time interval than whatever the automatic threshold picked in order to cause us to try and sync that message.  Of course, that may run afoul of memory limitations until I finish and land my fix for bug 799828.

I think the most important thing right now is that you make sure that when you run with e-mail that you are running with dump() enabled; the log you pasted does not have any of e-mail's dump output, so the log is not particularly useful.  While nightly builds should set it, you really want to make sure that your GAIA/build/custom-prefs.js file includes the line:

pref("browser.dom.window.dump.enabled", true);

You probably also want to symlink GAIA/custom-prefs.js to GAIA/build/custom-prefs.js too in case they ever fix the regression that changed where the file is supposed to live.

You know it's working when your logcat output starts with the following (in green):
LOG: Mail universe/bridge created, notifying.
LOG: got MailAPI!
LOG: got localized!

Comment 15

[Jim Porter (:squib)]

Update: I still haven't been able to reproduce this, since the sample emails Steve sent don't cause the issue for me, and they don't appear to generate the CSP violations that showed up in the logs anyway. I could speculatively fix this issue by wrapping try blocks around the appropriate places and logging any errors we get. Does that sound sane?

Comment 16

[Jim Porter (:squib)]

Landed more fixes to the error handling, which will hopefully help with this issue:

  https://github.com/mozilla-b2g/gaia-email-libs-and-more/pull/97
  https://github.com/mozilla-b2g/gaia/pull/6962

Steve: if you could try to sync your messages again and see what the logcat says, that'd be useful. Specifically, you'd be looking for stuff saying "Error parsing" or "Failed to parse a message". If you don't see anything like that, everything should be good, and you can feel free to resolve this as FIXED.

Comment 17

[Steve Chung [:steveck]]

Hi Jim,
I could reproduce this issue again, but there still doesn't exist any useful log while loading. When I stuck in the inbox and try to switch to another folder, one error log dumped after sync completed: 

I/GeckoDump(  466): LOG: Sync completed: added 14, changed 0, deleted 0
I/GeckoDump(  466): ERR: onerror reporting: TypeError: callback is not a function @ app://email.gaiamobile.org/js/ext/gaia-email-opt.js : 34554

Hope this information could help. BTW, I will also give you and Andrew my personal mail account for verifying this bug since it stuck in loading again.

Comment 18

[Jim Porter (:squib)]

I note that you're syncing 14 messages. Are those the same as the 14 you forwarded me? It's possible the bad message was one of the ones I didn't test, since a few of them were causing me other issues.

The second line in that log is fallout from bug 799828, and I'll have a patch up shortly.

Comment 19

[Jim Porter (:squib)]

This is what I get in the console when trying Steve's account on desktop:

ERR: onerror reporting: TypeError: oldDict[oldEndUID] is undefined @ app://email.gaiamobile.org/js/ext/gaia-email-opt.js : 24258

Comment 20

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Jim Porter (:squib) from comment #19)
> This is what I get in the console when trying Steve's account on desktop:
> 
> ERR: onerror reporting: TypeError: oldDict[oldEndUID] is undefined @
> app://email.gaiamobile.org/js/ext/gaia-email-opt.js : 24258

That's confusing.  Assuming we're all on the same line numbers, that's in _splitBodyBlock and it suggests that we've decided the body block has become big enough to split, but then when we go to split it, we find that there are way less bytes worth of messages in there than we expected.

test_folder_storage.js's test_insertion_in)block_overflow_split probably wants to check:
- the estSize values of the block infos before and after.
- that the contents of the body block match up with what the block info thinks is going on in the block.

Note that this is probably a new problem/fallout from my fixes to our size calculations of bodies rather than what Steve was originally experiencing.  Previously we thought all messages had a body size of 20 bytes, so the chances of us ever deciding to split a body block are waaaaay low.

Comment 21

[Jim Porter (:squib)]

Another weird error I see with Steve's account are a bunch of errors being thrown when we open the junk folder. Under normal circumstances, Hotmail will automatically up-convert plain text mails to HTML, but for some of these junk messages, it won't. My recent fixes mean that the only thing that happens is we don't display those messages, which it appears it what the Hotmail web interface does too, since I can't find the messages in question (but I can find messages near them).

I'm not sure this particular error is something we need to worry about, since it seems to happen only with junk mail, but it would be nice to figure out what's happening, at least.

Comment 22

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Jim Porter (:squib) from comment #21)
> I'm not sure this particular error is something we need to worry about,
> since it seems to happen only with junk mail, but it would be nice to figure
> out what's happening, at least.

That does sound mysterious and desirable to have a ballpark understanding of what's happening.

Comment 23

[Steve Chung [:steveck]]

Based on the previous discussion, is the improper size calculation makes the email loading stuck? We can modify title to describe this issue more precisely.

Comment 24

[Jim Porter (:squib)]

(In reply to Steve Chung from comment #23)
> Based on the previous discussion, is the improper size calculation makes the
> email loading stuck? We can modify title to describe this issue more
> precisely.

My guess is that this is the string of events that occurred here:

1) Some message in your folder was broken, causing us to error out and show an empty folder
2) I fixed this to only skip the broken message
3) Andrew fixed another bug with size calculation that can break in certain cases
4) You tested this again and saw the same issue, but this time because of (3) instead of (1)

Comment 25

[Alex Keybl [:akeybl]]

We need explicit STR to set blocking-basecamp+ on this bug, and it seems we're only guessing at what happened right now. Please re-nominate if either of those variables change.

Comment 26

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Alex Keybl [:akeybl] from comment #25)
> We need explicit STR to set blocking-basecamp+ on this bug, and it seems
> we're only guessing at what happened right now. Please re-nominate if either
> of those variables change.

Righto.  Since this bug has gotten muddied by the existence of multiple issues and the original thing is moot, I have filed bug 822992 on the size issue and requested blocking since it is clearly seriously bad news that has a good chance of eventually breaking for ever user of the e-mail app once they've used it long enough.

Comment 27

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Jim Porter (:squib) from comment #21)
> Another weird error I see with Steve's account are a bunch of errors being
> thrown when we open the junk folder. Under normal circumstances, Hotmail
> will automatically up-convert plain text mails to HTML, but for some of
> these junk messages, it won't. My recent fixes mean that the only thing that
> happens is we don't display those messages, which it appears it what the
> Hotmail web interface does too, since I can't find the messages in question
> (but I can find messages near them).
> 
> I'm not sure this particular error is something we need to worry about,
> since it seems to happen only with junk mail, but it would be nice to figure
> out what's happening, at least.

I just ran against Steve's account to get a log so we can know what the problem is and file a bug and be done with it.  Here's what one of the plaintext type body segments looked like:

            <AirSyncBase:Body>
              <AirSyncBase:Type>
                1
              </AirSyncBase:Type>
              <AirSyncBase:EstimatedDataSize>
                119
              </AirSyncBase:EstimatedDataSize>
              <AirSyncBase:Truncated>
                1
              </AirSyncBase:Truncated>
            </AirSyncBase:Body>

and another:

            <AirSyncBase:Body>
              <AirSyncBase:Type>
                1
              </AirSyncBase:Type>
              <AirSyncBase:EstimatedDataSize>
                121
              </AirSyncBase:EstimatedDataSize>
              <AirSyncBase:Truncated>
                1
              </AirSyncBase:Truncated>
            </AirSyncBase:Body>

And they all generally look like that; the payload claims to be in the 100-200 byte range.  All seem to be spam from hinet.net.  I don't have any recent spam of that vintage on my accounts; it seems like they are a notorious spam-haven and usually black-holed by US ISPs.

If you want to spin a bug off on handling this degenerate case a little more gracefully, that would be great.

Comment 28

[Steve Chung [:steveck]]

Close this issue Since https://bugzilla.mozilla.org/show_bug.cgi?id=822992 was fixed.