1511370 - Consider adding a simple sampling profiler to the shell

Status: NEW

(Core :: JavaScript Engine, defect, P3)

Description

[Jan de Mooij [:jandem]]

Attachment: Prototype patch

We have a number of mysterious browser bugs related to the profiler. I think the main raeson for this is that we don't have a good way to test this in the shell - we have the (ARM/MIPS) simulator's stepping mode but that doesn't account for sampling when we're iterating frames etc in C++.

One option is to move Gecko's profiler into mozglue (bug 1437246). I've no idea how much work that is.

Today I hacked up an alternative patch that adds a very primitive sampler thread to the shell (on Linux and OS X). See the attached patch. It can then be used like the example below.

It gets more interesting when we add this to jit-test/lib/prologue.js:

enableGeckoProfiling();
startSamplerThread();

This uncovers a number of assertion failures in JIT and wasm code.

--
enableGeckoProfiling();
startSamplerThread();
function g() { with(this) {} }
function f() {
    for (var i = 0; i < 10000; i++) {
	g();
    }
}
f();
stacks = stopSamplerThreadAndGetStacks();
for (var stack of stacks) {
    print("--------");
    print(stack);
}

With output:

--------
f (test.js:6:10)
--------
g (test.js:4:10),
f (test.js:6:10)
...

Comment 1

[Markus Stange [:mstange]]

Awesome!

Comment 2

[Jan de Mooij [:jandem]]

Assertion failures I see when running jit-tests with the sampler thread enabled:

(1) Somewhat frequent. This could be jesup's nullptr crash in bug 1506329.

Assertion failure: native, at js/src/jit/BaselineJIT.h:508
Exit code: -11
FAIL - basic/testBug692274-2.js

(2) Super frequent. Bug 1502744.

Assertion failure: slotInfo.isStackSynced(), at js/src/jit/JSJitFrameIter.cpp:673
Exit code: -11
FAIL - wasm/spec/binary.wast.js

(3)

Assertion failure: offset < length(), at js/src/vm/JSScript.h:1956
Exit code: -11
FAIL - wasm/spec/memory_redundancy.wast.js

(4) Wasm mutex:

Attempt to acquire mutex WasmCodeProfilingLabels with order 500 while holding GeckoProfilerStrings with order 500
Hit MOZ_CRASH(Mutex ordering violation) at js/src/threading/Mutex.cpp:56
Exit code: -11
FAIL - wasm/regress/savedframe-lookup-in-wasm.js

Attempt to acquire mutex WasmCodeProfilingLabels with order 500 while holding SharedImmutableStringsCache with order 500
Hit MOZ_CRASH(Mutex ordering violation) at js/src/threading/Mutex.cpp:56
Exit code: -11
FAIL - wasm/regress/savedframe-lookup-in-wasm.js

Comment 3

[Jan de Mooij [:jandem]]

One issue is that asm.js/wasm frame iteration can deadlock: js::Mutex maintains this "mutex stack" in debug builds (to *catch* dead locks, ironically!) and that uses malloc/free. Maybe this mechanism should just pre-allocate because debug-only and the size is bounded by the stack size.

Comment 4

[Nicolas B. Pierron [:nbp]]

I think this API of starting/stopping might cause some issues for reproducing minimizing tests cases in a fuzzing environment.
I will suggest something around the lines of:

  var Step = 1; // lµs
  var MinSamples = 10000; // 10 ms
  SampleAtUntil(Step, MinSamples, function () {
    …
  });