JSMime header parsing makes quick filter slow

NEW
Unassigned

Status

4 years ago
2 years ago

People

(Reporter: wsmwk, Unassigned)

Tracking

(Depends on: 3 bugs, Blocks: 4 bugs, {perf, regression})

Trunk
perf, regression
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [regression:TB32][has profile])

Attachments

(1 attachment)

(Reporter)

Description

4 years ago
+++ This bug was initially created as a clone of Bug #858337 +++

This has bothered me for a few weeks and I tracked the regression range to probably bug 858337 (build 20140604 is good, 20140605 is slow). 

My Inbox is ~4,000 messages. type "test" brings 244 hits.
On my fairly beefy work desktop:
20140604 instantaneous response and CPU usage <1sec
20140605 3-5 sec response and 3-5 sec CPU usage, and an annoying choppiness to the display of results
(Reporter)

Updated

4 years ago
Keywords: regression
(Reporter)

Comment 1

4 years ago
Profiled with 2014-08-22 nightly build.  This has been an excruciating exercise because I can't get upload the full profile run of 10 seconds to mozilla for the 4k message Inbox folder because the profile is >9mb.  Too much data, for 10 seconds!

So I profiled the last few seconds of quick search - with profiler off I pasted the "phpmyadmin" in quicksearch, waited a few seconds, and then enabled profiler for the last few seconds - http://people.mozilla.org/~bgirard/cleopatra/?1408741199883#report=04abac43e1c513ebc324d7a7e3b8c1e8ee3bdc84

20% of time is in getHeaderTokens() jsmime.js:317

Smaller folders do not seem to have quite the same profile:
* 2k messages - http://people.mozilla.org/~bgirard/cleopatra/?1408740691944#report=9096cbfffca464dd353b1c6913e5b1705147e5cc
* 1k messages - http://people.mozilla.org/~bgirard/cleopatra/?1408738063795#report=40c47833d3f9b0b727780047f652d0fbca12279b

Now, 20% of 10 seconds in getHeaderTokens by itself doesn't explain why quick search time increased 5-fold (10 seconds in profiler, about 5 seconds when not profiling)
Flags: needinfo?(Pidgeot18)
Whiteboard: [regression:TB32] → [regression:TB32][has profile]
Great work, Wayne!

The fear I have had with the move to javascript everywhere is that we would see serious performance regressions.
(Reporter)

Comment 3

4 years ago
I have more info to come along those lines.
(In reply to Wayne Mery (:wsmwk) from comment #1)
> 20% of time is in getHeaderTokens() jsmime.js:317

I was somewhat expecting this--I've been told that generators are not great performance-wise, and it looks like this is a performance bottleneck. I'll talk with JS people to see what their plans are for optimizing generators.
Flags: needinfo?(Pidgeot18)
(Reporter)

Comment 5

4 years ago
Created attachment 8477818 [details]
bug 1055077 bailouts.png

This shows one of my profiles, which I could not save, with a very high percentage is "bailout".
Converting headerparser.getTokenHeaders to return an array instead of a generator improves speed from ~6K headers/sec to ~14K headers/sec on my machine, according to a prototype microbenchmark I wrote. That alone is something like a 10-20% overall speedup on your profiles.

[I used 12-13K headers extracted from some email list archives I have. The headers were anonymized by by randomly rotating letters and numbers. RFC 2047 is very rare in this set (only a few hundred), and I have no non-ASCII 8-bit headers.]
This is really annoying btw. For years I have been able to hold thousands of emails in my folders and searching was instant. Now even for 1000 emails it takes a noticable time. I've worked around by setting up archiving for at least my inbox and going down to only showing mails of the last 2-3 months, but this isn't ideal.
I have a patch for this on bug 1005413.
Depends on: 1005413
Comment hidden (abusive)
(In reply to alta88 from comment #9)
> (In reply to Joshua Cranmer [:jcranmer] from comment #8)
> > I have a patch for this on bug 1005413.
> 
> HAHAHA, that's wholly inadequate, nor anything but alleged.  Clearly, no
> perf testing was done here at all.

Please stop spreading lies. I in fact took the time out of my schedule to extract a corpus of headers to use for testing, build a millibenchmark to estimate parsing time, attempt to build a reliable performance testing suite (with the help of people in #jsapi), and even try to get Ion dumps of assembly code for proper microoptimization. I'm not going to claim that the patch does not fix everything, but it is a substantial improvement by itself.

> Plus, Bug 858337 seems to have landed despite standard8's
> issue and non r+, what's going on here?

There were discussions over IRC that are not reflected in the bug.

If you want to be productive, then by all means, I would welcome your help in building a performance test suite to catch performance regressions. It would be a load off of my back to have one less thing I have to juggle. But if all you're going to do is snipe, then please leave. It would let me do more productive work in actually fixing the problems.

Comment 11

4 years ago
Quite likely related, we also see this issue in current SeaMonkey releases (given that JSMime is MailNews Core code, that wouldn't be surprising and matches the regression window reported here, although the QFB design itself differs between TB and SM).

Bug 1067972 - slow "Search Subject or Adress" process after upgrade to SM 2.29 (Gecko 32).
Comment hidden (abusive)
I landed the change from generators last night, so it should be in the nightly. It missed the Aurora uplift, though. If you try the latest nightly, how bad is it still?
(ni'ing wsmwk to remind him to upload a profile that has the recent changes).
Flags: needinfo?(vseerror)
(Reporter)

Comment 15

4 years ago
2014-10-23 daily build, Inbox, 4k message, warm folder (not first time entering folder), laptop, ~25% CPu in use by music player, not in safe mode, filter on "test", times NOT via stopwatch:

- recipient+sender+subject  (<5sec, 225 hits) http://people.mozilla.org/~bgirard/cleopatra/?1414243934911#report=e1dca35ebe3369ff209382fa959f1f96336be903
- subject only (<2sec, 216 hits) http://people.mozilla.org/~bgirard/cleopatra/?1414244158168#report=3539a2fd8d9cf12113b86faf1e984c3311e53a3c
- recipient+sender (<4sec, 17 hits) http://people.mozilla.org/~bgirard/cleopatra/?1414244402251#report=3cee87481dbfb9364ea0cf202c20f85d3194a326
Blocks: 1067972
Flags: needinfo?(vseerror) → needinfo?(Pidgeot18)
(In reply to Wayne Mery (:wsmwk) from comment #15)
> - subject only (<2sec, 216 hits)
> http://people.mozilla.org/~bgirard/cleopatra/
> ?1414244158168#report=3539a2fd8d9cf12113b86faf1e984c3311e53a3c

So the jsmime portion of this profile is rather slim, at most 10-20%. The profile is rather flat (PR_Now is at the top of the inverted callstack!). There are some easy wins, it looks like, from avoiding UTF-8-to-UTF-16 conversions: we convert the UTF-16 result to UTF-8 and then right back into UTF-16. If I make the search terms convert to UTF-16 and match on that, that should be a worthwhile gain.

Another possible improvement would be finding ways to avoid doing the conversion altogether, or somehow caching the result. The fact that we're doing a .sort() does suggest we could be doing some caching, but we're not accessing the methods in an easy way to implement caching (and I don't want to encourage using Mime2Decoded* methods--they're all sorts of levels of subtly wrong). Structured headers for the message database could effectively cache this sort of stuff, but... there's a lot of details to work out about eager/lazy parsing of stuff.

We could avoid going through nsIMimeConverter (and xpconnect) if we detect that said method would do nothing. For an en-US build, this is the common case, but it would hurt performance in the situation for non-ASCII headers. However, for the subject header, we could probably get around that by rejiggling the code to do RFC 2047 decoding on header creation instead on every damn time we're using the header. This wouldn't improve existing headers, but as people reindex their folders or get new headers, it would improve the situation.

> - recipient+sender+subject  (<5sec, 225 hits)
> http://people.mozilla.org/~bgirard/cleopatra/
> ?1414243934911#report=e1dca35ebe3369ff209382fa959f1f96336be903

Over here, I see fixArray is fairly expensive. Considering that I expect toString is rather little called (which is the main point of fixArray), I suspect I can probably make this much cheaper by using proxies for toString instead of resetting prototypes. It's a bit nasty to code, but it should improve performance.

The jsmime header parsing logic is still hot code though, and it's less amenable to avoid-doing-it-at-all tricks like the subject header. Although we might be able to cheat and make the search code work by just doing a mime decoding and search for the string in the header instead of parsing the header. This doesn't apply for IsInAB searches, though.

I'll ask Benoit for help in disecting the actual JS code here when I get the time. But first, I'll file bugs on the other, easier wins.
Flags: needinfo?(Pidgeot18)
Depends on: 1089298
Depends on: 1089299
Depends on: 1089300
Depends on: 1089301
Duplicate of this bug: 1103840
(Reporter)

Comment 18

4 years ago
Would you say bug 1089298 is the easiest significant win?
And what might be the next best one to attack?
Flags: needinfo?(Pidgeot18)
(In reply to Wayne Mery (:wsmwk) from comment #18)
> Would you say bug 1089298 is the easiest significant win?
> And what might be the next best one to attack?

Bug 1089298 turned out to not be a terribly significant win. Bug 1089301 was a phenomenal one.
Flags: needinfo?(Pidgeot18)
(Reporter)

Comment 20

3 years ago
recently described for 100k message folder in https://support.mozilla.org/en-US/questions/1119695 quick filter used to be quick few years ago, but now it is really slow
(Reporter)

Updated

3 years ago
Blocks: 944942
(Reporter)

Updated

2 years ago
Blocks: 1284753
Comment hidden (off-topic)
Comment hidden (off-topic)
You need to log in before you can comment on or make changes to this bug.