Investigate why recording many Sunspider and V8 tests results in ~2x slowdown

[joneschrisg]

This data is from rr.pdf.

These tests should be doing almost no I/O and should be relatively straight-line code without too many syscalls. A 2x slowdown is surprising. The data is old and AFAIK predates syscall wrapping, so the first step (obviously) is to reproduce the results on tip.

[joneschrisg]

Would like to see if this is still the case, and if so understand why, for 1.0. But not necessarily fix the underlying issues, if any.

[joneschrisg]

Still an issue

Without rr:
============================================
RESULTS (means and 95% confidence intervals)
--------------------------------------------
Total:                 202.6ms +/- 4.9%
--------------------------------------------
With rr:
============================================
RESULTS (means and 95% confidence intervals)
--------------------------------------------
Total:                  443.9ms +/- 2.5%
--------------------------------------------

So a 2.2x slowdown. Will see if anything obviously bad jumps out.

[joneschrisg]

Looks like too deep of an issue for 1.0, though I'd really love to have the time to stick a profiler on it.

• 75% of trace traps are futex and USR_SCHED, which also compromise 80% of the buffer flushes
• 45% of the futexes are FUTEX_WAIT, but Try to upstream a glibc fix for pthread_cond_signal()/broadcast() #749 would eliminate 45% of them
• giving tracees a huge timeslice and event budget (i.e. cutting USR_SCHED traps to a minimum) is actually a slowdown. (This is surprising.)
• overhead is substantially higher with --no-syscallbuf

I'm not sure if the old numbers were doing in-browser runs or js shell runs. Since they're a bit worse overall, and rr should have only gotten faster, I'm going to guess they were shell runs. But I only care about browser runs, so here we are :).

Guessing this is related to FF timer crap.

[rocallahan]

I think this is worth spending time on, because the overhead is quite high, intuitively the overhead should be quite low for workloads like this, and "known benchmarks" like these are quite likely targets for people to report rr overhead on.

[joneschrisg]

Okie doke.

[joneschrisg]

Just to be clear, did you want this for 1.0?

[rocallahan]

I'm flexible on that :-)

[joneschrisg]

I'm happy to settle for profiling, and then making a decision based on that.

[joneschrisg]

tl;dr ion parallel compilation is killing perf. Disabling that, and fiddling with sched knobs, gets us under 1.2x overhead. Much improved over old perf.

Guessing this is related to FF timer crap.

Nope: the same results reproduce in jsshell. Since that's easier to work with, I used it for testing. Here's the data

"baseline" == TI, ion, ion-parallel-compile=on.
                    baseline: 1.0x
        taskset 0x1 baseline: 1.16x
                          rr: 1.90x
               rr -c10000000: 2.29x
        rr -c10000000 -e1000: 2.30x
             rr -c100000 -e5: 2.07x
"no-par" == TI, ion, ion-parallel-compile=off.
                      no-par: 1.06x (1.0x)
                   rr no-par: 1.44x (1.35x)
        rr -c10000000 no-par: 1.28x (1.20x)
 rr -c10000000 -e1000 no-par: 1.25x (1.17x)

Observations

• parallel compilation is a small win on sunspider
• parallel compilation is a bigger loss when pinned to one core
• rr overhead with parallel compilation is a bit under 2x, and gets worse with larger timeslices. That's surprising.
• rr overhead also gets worse with smaller timeslices, so there are non-trivial scheduler issues
• futex accounts for over 50% of buffer flushes
• rr is considerably faster recording when parallel compilation is off, under 1.5x overhead. Increasing timeslices gets overhead under 1.2x compared to baseline no-par.
• with no-par, futex is still just under 50% of buffer flushes

Unfortunately, I think the takeaway is most likely that forced serialization of programs that actually take advantage of true parallelism, is a loss. The follow-ups I see are

• consider adding an "rr mode" to FF, where it disables parallel compilation if pinned to one core. Not sure how palatable that hack would be.
• get someone knowledgeable about ion parallel-compile to help profile what's going bad under rr
• consider adding a "cpu-bound" rr sched param, where it increases the timeslice
• implement something like HFSC/CFS in rr's recorder scheduler

It's worth thinking about whether it's fair to start comparing FF perf with ion-parallel-compilation turned off. I lean towards "no", but will ponder.

[joneschrisg]

Also, ftr, I noticed that jsshell makes a fair number of setpriority calls. Disabling priority classes actually increases the overhead slightly.

[joneschrisg]

My inclination for 1.0 is to make it widely known to disable ion parallel compilation when running under rr, if you want max perf. (Or add the "rr mode" hack to FF.) I'm afraid that trying to meliorize rr's recording of forced-serial executions of intrinsically parallel workloads is going to be tilting at windmills.

@rocallahan what do you think?

[joneschrisg]

Also ftr, before starting on #279 I measured layout/base with ion par-comp disabled, and it didn't make a difference.

[rocallahan]

js::GetCPUCount looks like this:
long n = sysconf(_SC_NPROCESSORS_ONLN);
ncpus = (n > 0) ? unsigned(n) : 1;
So, let's figure out how to make sysconf return 1 CPU under rr. That will disable Ion parallel compilation for us. I think it's completely legitimate to do this since rr is essentially providing a single-core execution environment.

In our performance comparisons, we should always compare Firefox-under-rr to unrestricted Firefox. It may be instructive to provide a number for single-core Firefox as well to show how much of the rr overhead is due to eliminating paralellism.

[joneschrisg]

js::GetCPUCount looks like this:
< long n = sysconf(SCNPROCESSORS_ONLN);
ncpus = (n > 0) ? unsigned(n) : 1;
So, let's figure out how to make sysconf return 1 CPU under rr.

On first skim of libc, it looks like that info is derived from a CPUID insn, which we can't trap. I'll take another look to be sure though.

In our performance comparisons, we should always compare Firefox-under-rr to unrestricted Firefox.

I think I agree with that. But to be clear, you mean that we should pass the same args to bare FF as for FF-under-rr?

[rocallahan]

Yes, I think so.

We can use a preload hook to override sysconf if we want to.

[joneschrisg]

Yeah, that's probably worth doing. I'm glad FF is doing the right thing here, and rr should help it.

[joneschrisg]

#814 gets us down to 1.2x overhead with default record args (!), and with an inflated timeslice, we get down to 1.04x (!!!). I think we can call this done for 1.0 :).

[joneschrisg]

Also a win on layout/base; first overhead seen under 1.4x (unscientific).

[joneschrisg]

I rebased my bare-metal x64 perf numbers for sunspider in-browser runs. (It's more convenient and those numbers are more interesting). rr overhead is ~1.44x, so not great but in the ballpark.