Closed Bug 834500 Opened 9 years ago Closed 9 years ago

IonMonkey: JSNES run with --no-jm is more than 10x slower than --ion-eager.

Categories

(Core :: JavaScript Engine, defect)

x86_64
Linux
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla21

People

(Reporter: nbp, Assigned: h4writer)

Details

Attachments

(1 file)

We should probably investigate this one, because as h4writer mentioned, this is likely to be a function which is not compiled with Ion and which run on the interpreter when used with --no-jm.

The following results are made on the JS NES shell benchmark:

no arguments:
warmup: 622
warmup: 579
warmup: 531
result: 553
result: 568
result: 531
result: 528
result: 494
result: 506
result: 493
result: 609
result: 565
result: 572
result: 576

with --ion-eager:
warmup: 1285
warmup: 763
warmup: 898
result: 737
result: 855
result: 802
result: 798
result: 808
result: 806
result: 1293
result: 1212
result: 1209
result: 1206
result: 1207
result: 1217
result: 1229

with --no-jm:
warmup: 9860
warmup: 9968
warmup: 10418
result: 10667
result: 9774
result: 11991
result: 11900
result: 12004
result: 12008
result: 11898
result: 12156
result: 12002
result: 11933
Tracelogging file is 7.4gb. So getting stats from it takes to much time. I've let it run for long enough to stabilize the running time:

interpreter,../source/nes.js:96: 32447950762 cycles (68%), called: 150 , 216319671 cycles/call
ion_cannon,../source/papu.js:289: 3211986848 cycles (6%), called: 1842494 , 1743 cycles/call
ion_cannon,../source/mappers.js:75: 744869512 cycles (1%), called: 3741115 , 199 cycles/call
ion_cannon,../source/cpu.js:1087: 699629511 cycles (1%), called: 2678407 , 261 cycles/call
ion_cannon,../source/papu.js:544: 419716882 cycles (0%), called: 137139 , 3060 cycles/call
ion_cannon,../source/ppu.js:975: 314957721 cycles (0%), called: 41687 , 7555 cycles/call
ion_cannon,../source/papu.js:1270: 189510800 cycles (0%), called: 1264136 , 149 cycles/call
ion_cannon,../source/ppu.js:461: 113183625 cycles (0%), called: 186 , 608514 cycles/call
ion_cannon,../source/ppu.js:947: 92741705 cycles (0%), called: 3949 , 23484 cycles/call

So it indicated that most time is spend in ../source/nes.js:96 and that it doesn't get compiled. IM logs shows the same but without reason why... Shouldn't be to hard to figure out why we disable it ...

[Abort] Disabling Ion compilation of script ../source/nes.js:96
This issue is only visible when running without threads and when disabling methodjit. Not related to real world performance at all!

../source/cpu.js:116 is disabled because it is 5818 bytes (2000bytes is max. allowed without threads, with backgroundcompiler 20000byetes)

../source/nes.js:96 is very hot and calls cpu.js:116 a lot. We have a rule that a function can only call 512 from IM -> VM -> JM/Interpreter. If we go over that, the caller gets disabled in order to compile it in JM and do JM -> JM call. Off course in this case is JM disabled so function nes.js:96 is called in the interpreter and uber slow.


My performance is in line with nbp. Therefore you can compare this with previous reported times. We are still slower, because now we have to run ../source/cpu.js:116 in the interpreter instead of JM. Enabling JM or using threaded js will have better times.
js --no-jm shell-bench.js 
warmup: 3198
warmup: 3180
warmup: 3410
result: 3622
result: 3823
result: 3181
result: 3125
result: 3109
result: 3135
result: 3128
result: 3061
result: 3059
result: 3089
Average of 10 runs: 3233.20ms.
Assignee: general → hv1989
Attachment #706179 - Flags: review?(nicolas.b.pierron)
Attachment #706179 - Flags: review?(nicolas.b.pierron) → review+
https://hg.mozilla.org/mozilla-central/rev/87cd83355b09
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla21
You need to log in before you can comment on or make changes to this bug.