Closed Bug 1246132 Opened 8 years ago Closed 8 years ago

asm.js compilation takes a very long time on AdVenture Capitalist Facebook asm.js game

Categories

(Core :: JavaScript Engine, defect)

41 Branch
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla47
Tracking Status
firefox47 --- fixed

People

(Reporter: jujjyl, Assigned: bhackett1024)

Details

Attachments

(1 file, 1 obsolete file)

STR: Visit https://apps.facebook.com/1470759159861550/

Observed: Firefox hangs for several minutes. Chrome loads up in less than a minute.

Jeff Muizelaar was able to get Firefox to crash as well on this: https://crash-stats.mozilla.com/report/index/07e62c5f-d0d4-4971-b2f4-65a7f2160202 and reported that profiling indicates that a lot of time would be spent in register allocation for minified function 'Suj'.
Version: 47 Branch → 43 Branch
Flags: needinfo?(luke)
Version: 43 Branch → 41 Branch
Bisected this down to a 9 month old commit https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=df6f82e4a2dbc8fe04121ab4f90f48a68ded91fb&tochange=261cadb8301573f6ed2314b3d05f47c1da8b2b4c, which was reported 5 months ago to impact another test case in bug 1200274.

Not marking as duplicate, since these are two separate test cases, and in this bug, it is affecting asm.js compile time, and in bug 1200274 it is affecting runtime performance, so the testcases exhibit different behavior.
Flags: needinfo?(sunfish)
Flags: needinfo?(bhackett1024)
Before the impacting commit, I am seeing asm.js compile time of

Successfully compiled asm.js code (total compilation time 13395ms; stored in cache; 3 functions compiled slowly: Tuj:54:9 (1563ms), Uuj:52:9 (2319ms), Suj:53:9 (5754ms))

and afterwards, Jeff Muizelaar reported

Successfully compiled asm.js code (total compilation time 180377ms;
storage initialization failed (consider filing a bug); 10 functions
compiled slowly: RRp:35 (271ms), vgp:51 (304ms), sgp:51 (338ms),
tgp:51 (842ms), wgp:51 (829ms), ugp:51 (1187ms), xgp:51 (1154ms),
Tuj:54 (13584ms), Uuj:52 (22968ms), Suj:53 (171446ms)

Cross-referencing these two, it looks like the function Suj is the big time hog, although other functions show 10x explosion in compile times as well (though apples to oranges, since different hardware).
Flags: needinfo?(luke)
Would it be possible to extract a .js or other shell based testcase for this webpage?  That would make it much easier to study why the regalloc is performing so poorly here.
(In reply to Brian Hackett (:bhackett) from comment #3)
> Would it be possible to extract a .js or other shell based testcase for this
> webpage?  That would make it much easier to study why the regalloc is
> performing so poorly here.

I think it usually works to grab the JS file from the browser's devtools and run it in the shell. It will error immediately but asm.js compilation should be done at that point, as far as I know...
Attached patch round 1 (obsolete) — Splinter Review
I got the .js for this page (56MB, yeesh) and used cachegrind to find a couple spots where we were spending too much time, which this patch fixes.

- entryOf() calls LBlock::firstInstructionWithId, which is an out of line function that loops over the block's instructions.  This patch caches entryOf (and exitOf, for symmetry) and improves the time on the slowest compilations by 5-15%.

- splitAcrossCalls() does a linear walk of all the calls in the graph to find the call positions within a given bundle.  This patch uses a splay tree instead, giving a large improvement on the slowest compilations.

Combined, these fixes improve my time on the three slowest compilations from 14/21/175 seconds to 5/7/40 seconds.

I think more improvement can be wrung out of this test case.  Of the 40 seconds still spent on the slowest compilation, 35 seconds are spent in a brute force loop (cribbed from LSRA, way back when) near the end of compilation that adds moves to resolve different allocations across graph edges.  Fixing this will be more involved and would be better to do in a separate patch.
Assignee: nobody → bhackett1024
Flags: needinfo?(bhackett1024)
Attachment #8725447 - Flags: review?(sunfish)
Attached patch patchSplinter Review
Actually, improving the brute force loop was straightforward, and the first patch had a few bugs, so this is just a rolled up patch with all three fixes.  On the three slowest compilations I now get allocation times of 1.8/2.5/11.3 seconds.  Before bug 1067610 the comparable numbers are .7/.9/2.2, and since the things fixed by this patch are performance faults that predate bug 1067610 this is very peculiar and I'll try to investigate more.
Attachment #8725447 - Attachment is obsolete: true
Attachment #8725447 - Flags: review?(sunfish)
Flags: needinfo?(sunfish)
Attachment #8725473 - Flags: review?(sunfish)
Awesome performance improvements! Will be interesting to see if this affects other benchmarks/workloads.
Attachment #8725473 - Flags: review?(sunfish) → review+
https://hg.mozilla.org/mozilla-central/rev/6ab9c45cffbc
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla47
You need to log in before you can comment on or make changes to this bug.