Closed
Bug 1202462
Opened 9 years ago
Closed 6 years ago
Octane score gains considerably with incremental GC disabled
Categories
(Core :: JavaScript: GC, defect)
Tracking
()
RESOLVED
WONTFIX
People
(Reporter: tenisthenewnine, Unassigned)
References
Details
So on the latest nightly I get the below Octane scores:
With iGC enabled:
http://i.imgur.com/u4sxv11.png
With it disabled and a restart:
http://i.imgur.com/CL77GFv.png
I can reproduce this again and again. Is this normal?
Updated•9 years ago
|
Blocks: IncrementalGC
Component: Untriaged → JavaScript: GC
Flags: needinfo?(wmccloskey)
Product: Firefox → Core
Comment 1•9 years ago
|
||
The main difference I can see on a quick compare of images is Raytrace doubles its score with iGC disabled. That seems strange.
Comment 2•9 years ago
|
||
Also, Splay Latency score is halved with iGC disabled.
Comment 3•9 years ago
|
||
The latency tests getting worse without iGC is expected.
After all they test how long the GC pauses are during the run.
Comment 4•9 years ago
|
||
Generally speaking, incremental GC trades away throughput to improve latency.
That said, the huge drop in score on Raytrace might be worth looking at. Terrence is more focused on GC perf these days than Bill.
Flags: needinfo?(wmccloskey) → needinfo?(terrence)
Comment 5•9 years ago
|
||
This should not be hitting any IGC in the shell and indeed, does not reproduce in the shell. I'll check the browser after morning meetings.
Comment 6•9 years ago
|
||
I cannot reproduce in the browser either:
with: 38251
without: 35061
So, faster with IGC enabled. Looking at the MOZ_GCTIMER=stdout output, we see some GC events near Raytrace. First for the browser:
GC(T+33.751s) =================================================================
Invocation Kind: Normal
Reason: ALLOC_TRIGGER
Incremental: yes
Zones Collected: 1 of 4
Compartments Collected: 1 of 124
MinorGCs since last GC: 636
Store Buffer Overflows: 0
MMU 20ms:49.5%; 50ms:79.8%
SCC Sweep Total (MaxPause): 3.236ms (3.236ms)
HeapSize: 89.645 MiB
Chunk Delta (magnitude): +42 (44)
Arenas Relocated: 0.000 MiB
---- Totals ----
Total Time: 10.105ms
Max Pause: 10.105ms
Begin Callback: 0.001ms
Mark Discard Code: 0.015ms
Relazify Functions: 0.058ms
Purge: 0.002ms
Mark: 4.528ms
Other: 2.789ms
Mark Roots: 0.266ms
Buffer Gray Roots: 0.068ms
Mark Cross Compartment Wrappers: 0.131ms
Mark Rooters: 0.007ms
Mark Embedding: 0.004ms
Mark Compartments: 0.046ms
Unmark: 1.473ms
Sweep: 5.355ms
Mark During Sweeping: 0.016ms
Mark Weak: 0.011ms
Mark Gray: 0.002ms
Mark Gray and Weak: 0.002ms
Finalize Start Callback: 0.020ms
Sweep Compartments: 1.979ms
Sweep Discard Code: 0.013ms
Sweep Base Shapes: 0.005ms
Sweep Initial Shapes: 0.008ms
Sweep Type Objects: 0.275ms
Sweep Regexps: 0.001ms
Sweep Miscellaneous: 0.035ms
Sweep type information: 1.659ms
Other: 1.650ms
Sweep type tables and compilations: 0.008ms
Free type arena: 0.001ms
Sweep Object: 2.908ms
Sweep String: 0.001ms
Sweep Script: 0.040ms
Sweep Shape: 0.043ms
Sweep JIT code: 0.003ms
Finalize End Callback: 0.301ms
Deallocate: 0.010ms
End Callback: 0.002ms
All Minor GCs: 71.697ms
Other: 67.407ms
Mark Roots: 4.290ms
Other: 2.630ms
Mark Rooters: 1.660ms
Minor GCs to Evict Nursery: 0.111ms
Other: 0.104ms
Mark Roots: 0.007ms
Mark Rooters: 0.002ms
And in the shell:
GC(T+5.197s) =================================================================
Invocation Kind: Normal
Reason: ALLOC_TRIGGER
Incremental: yes
Zones Collected: 1 of 3
Compartments Collected: 1 of 3
MinorGCs since last GC: 466
Store Buffer Overflows: 0
MMU 20ms:59.2%; 50ms:83.7%
SCC Sweep Total (MaxPause): 1.445ms (1.445ms)
HeapSize: 82.961 MiB
Chunk Delta (magnitude): +0 (78)
Arenas Relocated: 0.000 MiB
---- Totals ----
Total Time: 8.153ms
Max Pause: 8.153ms
Relazify Functions: 0.040ms
Purge: 0.007ms
Mark: 4.225ms
Other: 2.895ms
Mark Roots: 0.010ms
Mark Cross Compartment Wrappers: 0.001ms
Mark Rooters: 0.003ms
Unmark: 1.320ms
Sweep: 3.818ms
Mark During Sweeping: 0.018ms
Mark Incoming Black Pointers: 0.001ms
Mark Weak: 0.013ms
Mark Gray and Weak: 0.004ms
Sweep Compartments: 2.636ms
Sweep Discard Code: 0.032ms
Sweep Cross Compartment Wrappers: 0.001ms
Sweep Base Shapes: 0.001ms
Sweep Initial Shapes: 0.006ms
Sweep Type Objects: 0.263ms
Sweep Miscellaneous: 0.078ms
Sweep type information: 2.258ms
Other: 2.254ms
Sweep type tables and compilations: 0.003ms
Free type arena: 0.001ms
Sweep Object: 1.063ms
Sweep String: 0.001ms
Sweep Script: 0.030ms
Sweep Shape: 0.035ms
Sweep JIT code: 0.027ms
Deallocate: 0.001ms
All Minor GCs: 44.981ms
Other: 39.273ms
Mark Roots: 5.708ms
Other: 5.235ms
Mark Rooters: 0.473ms
Minor GCs to Evict Nursery: 0.049ms
Mark Roots: 0.009ms
Mark Rooters: 0.003ms
These appear to be materially the same, at least on my hardware.
It would be interesting to see what the MOZ_GCTIMER output is like when it's falling over. My guess is that on a 30% slower machine, the GC is running over budget and having to do a second slice. Since the mutator is much slower with barriers enabled, this could substantially slow down whatever test is unlucky enough to have this happen to it. So this seems like is is probably a case where we are trading off throughput for latency and our awful hacks to keep this from showing up too badly on octane are not engaging correctly. :-/
Flags: needinfo?(terrence)
Updated•6 years ago
|
Status: UNCONFIRMED → RESOLVED
Closed: 6 years ago
Resolution: --- → WONTFIX
You need to log in
before you can comment on or make changes to this bug.
Description
•