Source code
Revision control
Copy as Markdown
Other Tools
Test Info: Warnings
- This test gets skipped with pattern: os == 'android'
- Manifest: devtools/server/tracer/tests/xpcshell/xpcshell.toml
/* Any copyright is dedicated to the Public Domain.
"use strict";
const { JSTracer } = ChromeUtils.importESModule(
"resource://devtools/server/tracer/tracer.sys.mjs",
{ global: "shared" }
);
add_task(async function () {
// Because this test uses evalInSandbox, we need to tweak the following prefs
Services.prefs.setBoolPref(
"security.allow_parent_unrestricted_js_loads",
true
);
registerCleanupFunction(() => {
Services.prefs.clearUserPref("security.allow_parent_unrestricted_js_loads");
});
});
add_task(async function testTracingContentGlobal() {
const toggles = [];
const frames = [];
const listener = {
onTracingToggled(state) {
toggles.push(state);
},
onTracingFrame(frameInfo) {
frames.push(frameInfo);
},
};
info("Register a tracing listener");
JSTracer.addTracingListener(listener);
Cu.evalInSandbox("function bar() {}; function foo() {bar()};", sandbox);
info("Start tracing");
JSTracer.startTracing({ global: sandbox, prefix: "testContentPrefix" });
Assert.equal(toggles.length, 1);
Assert.equal(toggles[0], true);
info("Call some code");
sandbox.foo();
Assert.equal(frames.length, 2);
const lastFrame = frames.pop();
const beforeLastFrame = frames.pop();
Assert.equal(beforeLastFrame.depth, 0);
Assert.equal(beforeLastFrame.formatedDisplayName, "λ foo");
Assert.equal(beforeLastFrame.prefix, "testContentPrefix: ");
Assert.ok(beforeLastFrame.frame);
Assert.equal(lastFrame.depth, 1);
Assert.equal(lastFrame.formatedDisplayName, "λ bar");
Assert.equal(lastFrame.prefix, "testContentPrefix: ");
Assert.ok(lastFrame.frame);
info("Stop tracing");
JSTracer.stopTracing();
Assert.equal(toggles.length, 2);
Assert.equal(toggles[1], false);
info("Recall code after stop, no more traces are logged");
sandbox.foo();
Assert.equal(frames.length, 0);
info("Start tracing again, and recall code");
JSTracer.startTracing({ global: sandbox, prefix: "testContentPrefix" });
sandbox.foo();
info("New traces are logged");
Assert.equal(frames.length, 2);
info("Unregister the listener and recall code");
JSTracer.removeTracingListener(listener);
sandbox.foo();
info("No more traces are logged");
Assert.equal(frames.length, 2);
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingJSMGlobal() {
// We have to register the listener code in a sandbox, i.e. in a distinct global
// so that we aren't creating traces when tracer calls it. (and cause infinite loops)
const systemPrincipal = Services.scriptSecurityManager.getSystemPrincipal();
const listenerSandbox = Cu.Sandbox(systemPrincipal);
Cu.evalInSandbox(
"new " +
function () {
globalThis.toggles = [];
globalThis.frames = [];
globalThis.listener = {
onTracingToggled(state) {
globalThis.toggles.push(state);
},
onTracingFrame(frameInfo) {
globalThis.frames.push(frameInfo);
},
};
},
listenerSandbox
);
info("Register a tracing listener");
JSTracer.addTracingListener(listenerSandbox.listener);
info("Start tracing");
JSTracer.startTracing({ global: null, prefix: "testPrefix" });
Assert.equal(listenerSandbox.toggles.length, 1);
Assert.equal(listenerSandbox.toggles[0], true);
info("Call some code");
function bar() {}
function foo() {
bar();
}
foo();
// Note that the tracer will record the two Assert.equal and the info calls.
// So only assert the last two frames.
const lastFrame = listenerSandbox.frames.at(-1);
const beforeLastFrame = listenerSandbox.frames.at(-2);
Assert.equal(beforeLastFrame.depth, 7);
Assert.equal(beforeLastFrame.formatedDisplayName, "λ foo");
Assert.equal(beforeLastFrame.prefix, "testPrefix: ");
Assert.ok(beforeLastFrame.frame);
Assert.equal(lastFrame.depth, 8);
Assert.equal(lastFrame.formatedDisplayName, "λ bar");
Assert.equal(lastFrame.prefix, "testPrefix: ");
Assert.ok(lastFrame.frame);
info("Stop tracing");
JSTracer.stopTracing();
Assert.equal(listenerSandbox.toggles.length, 2);
Assert.equal(listenerSandbox.toggles[1], false);
JSTracer.removeTracingListener(listenerSandbox.listener);
});
add_task(async function testTracingValues() {
// Test the `traceValues` flag
Cu.evalInSandbox(
`function foo() { bar(-0, 1, ["array"], { attribute: 3 }, "4", BigInt(5), Symbol("6"), Infinity, undefined, null, false, NaN, function foo() {}, function () {}, class MyClass {}); }; function bar(a, b, c) {}`,
sandbox
);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
function loggingMethod(str) {
logs.push(str);
}
info("Start tracing");
JSTracer.startTracing({ global: sandbox, traceValues: true, loggingMethod });
info("Call some code");
sandbox.foo();
Assert.equal(logs.length, 3);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ foo()");
Assert.stringContains(
logs[2],
`λ bar(-0, 1, Array(1), [object Object], "4", BigInt(5), Symbol(6), Infinity, undefined, null, false, NaN, function foo(), function anonymous(), class MyClass)`
);
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingFunctionReturn() {
// Test the `traceFunctionReturn` flag
Cu.evalInSandbox(
`function foo() { bar(); return 0 } function bar() { return "string" }; foo();`,
sandbox
);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
function loggingMethod(str) {
logs.push(str);
}
info("Start tracing");
JSTracer.startTracing({
global: sandbox,
traceFunctionReturn: true,
loggingMethod,
});
info("Call some code");
sandbox.foo();
Assert.equal(logs.length, 5);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ foo");
Assert.stringContains(logs[2], "λ bar");
Assert.stringContains(logs[3], `λ bar return`);
Assert.stringContains(logs[4], "λ foo return");
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingFunctionReturnAndValues() {
// Test the `traceFunctionReturn` and `traceValues` flag
Cu.evalInSandbox(
`function foo() { bar(); second(); } function bar() { return "string" }; function second() { return null; }; foo();`,
sandbox
);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
function loggingMethod(str) {
logs.push(str);
}
info("Start tracing");
JSTracer.startTracing({
global: sandbox,
traceFunctionReturn: true,
traceValues: true,
loggingMethod,
});
info("Call some code");
sandbox.foo();
Assert.equal(logs.length, 7);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ foo()");
Assert.stringContains(logs[2], "λ bar()");
Assert.stringContains(logs[3], `λ bar return "string"`);
Assert.stringContains(logs[4], "λ second()");
Assert.stringContains(logs[5], `λ second return null`);
Assert.stringContains(logs[6], "λ foo return undefined");
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingStep() {
// Test the `traceStep` flag
const source = `
function foo() {
bar(); /* line 3 */
second(); /* line 4 */
dump("foo\\n");
}
function bar() {
let res; /* line 8 */
if (1 === 1) { /* line 9 */
res = "string"; /* line 10 */
} else {
res = "nope"
}
return res; /* line 14 */
};
function second() {
let x = 0; /* line 17 */
for (let i = 0; i < 2; i++) { /* line 18 */
x++; /* line 19 */
}
return null; /* line 21 */
};
foo();`;
Cu.evalInSandbox(source, sandbox, null, "file.js", 1);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
function loggingMethod(str) {
logs.push(str);
}
info("Start tracing");
JSTracer.startTracing({
global: sandbox,
traceSteps: true,
loggingMethod,
});
info("Call some code");
sandbox.foo();
Assert.equal(logs.length, 19);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ foo");
Assert.stringContains(logs[1], "file.js:3:3");
Assert.stringContains(logs[2], "λ bar");
Assert.stringContains(logs[2], "file.js:7:16");
// Each "step" only prints the location and nothing more
Assert.stringContains(logs[3], "file.js:9:7");
Assert.stringContains(logs[4], "file.js:10:5");
Assert.stringContains(logs[5], "file.js:14:3");
Assert.stringContains(logs[6], "file.js:4:3");
Assert.stringContains(logs[7], "λ second");
Assert.stringContains(logs[7], "file.js:16:19");
Assert.stringContains(logs[8], "file.js:17:11");
// For loop
Assert.stringContains(logs[9], "file.js:18:16");
Assert.stringContains(logs[10], "file.js:18:19");
Assert.stringContains(logs[11], "file.js:19:5");
Assert.stringContains(logs[12], "file.js:18:26");
Assert.stringContains(logs[13], "file.js:18:19");
Assert.stringContains(logs[14], "file.js:19:5");
Assert.stringContains(logs[15], "file.js:18:26");
Assert.stringContains(logs[16], "file.js:18:19");
// End of for loop
Assert.stringContains(logs[17], "file.js:21:3");
Assert.stringContains(logs[18], "file.js:5:3");
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingPauseOnStep() {
// Test the `pauseOnStep` flag
sandbox.dump = dump;
const source = `var counter = 0; function incrementCounter() { let x = 0; dump("++\\n"); counter++; };`;
Cu.evalInSandbox(source, sandbox);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
let loggingMethodResolve;
function loggingMethod(str) {
logs.push(str);
if (loggingMethodResolve) {
loggingMethodResolve();
}
}
info("Start tracing without pause");
JSTracer.startTracing({
global: sandbox,
loggingMethod,
});
info("Call some code");
sandbox.incrementCounter();
Assert.equal(logs.length, 2);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ incrementCounter");
info(
"When pauseOnStep isn't used, the traced code runs synchronously to completion"
);
Assert.equal(sandbox.counter, 1);
info("Stop tracing");
JSTracer.stopTracing();
logs.length = 0;
sandbox.counter = 0;
info("Start tracing with 0ms pause");
JSTracer.startTracing({
global: sandbox,
pauseOnStep: 0,
loggingMethod,
});
let onTraces = Promise.withResolvers();
let onResumed = Promise.withResolvers();
// This is used when receiving new traces in `loggingMethod()`
loggingMethodResolve = onTraces.resolve;
info(
"Run the to-be-traced code in a distinct event loop as it would be paused synchronously and would prevent further test script execution"
);
Services.tm.dispatchToMainThread(() => {
sandbox.incrementCounter();
onResumed.resolve();
});
info("Wait for tracer to call the listener");
await onTraces.promise;
Assert.equal(logs.length, 2);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ incrementCounter");
info(
"When pauseInStep is used, the tracer listener is called, but the traced function is paused and doesn't run synchronously to completion"
);
Assert.equal(
sandbox.counter,
0,
"The increment method was called but its execution flow was blocked and couldn't increment"
);
info("Wait for traced code to be resumed");
await onResumed.promise;
info(
"If we release the event loop, we can see the traced function completion"
);
Assert.equal(sandbox.counter, 1);
info("Stop tracing");
JSTracer.stopTracing();
logs.length = 0;
sandbox.counter = 0;
info("Start tracing with 250ms pause");
JSTracer.startTracing({
global: sandbox,
pauseOnStep: 250,
loggingMethod,
});
onTraces = Promise.withResolvers();
onResumed = Promise.withResolvers();
// This is used when receiving new traces in `loggingMethod()`
loggingMethodResolve = onTraces.resolve;
info(
"Run the to-be-traced code in a distinct event loop as it would be paused synchronously and would prevent further test script execution"
);
const startTimestamp = Cu.now();
Services.tm.dispatchToMainThread(() => {
sandbox.incrementCounter();
onResumed.resolve();
});
info("Wait for tracer to call the listener");
await onTraces.promise;
Assert.equal(logs.length, 2);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ incrementCounter");
info(
"When pauseInStep is used, the tracer lsitener is called, but the traced function is paused and doesn't run synchronously to completion"
);
Assert.equal(sandbox.counter, 0);
info("Wait for traced code to be resumed");
await onResumed.promise;
info(
"If we release the event loop, we can see the traced function completion"
);
Assert.equal(sandbox.counter, 1);
info("The thread should have paused at least the pauseOnStep's duration");
Assert.greater(Cu.now() - startTimestamp, 250);
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingFilterSourceUrl() {
// Test the `filterFrameSourceUrl` flag
// Use a unique global (sandbox), but with two distinct scripts (first.js and second.js)
const source1 = `function foo() { bar(); }`;
Cu.evalInSandbox(source1, sandbox, null, "first.js", 1);
// Only code running in that second source should be traced.
const source2 = `function bar() { }`;
Cu.evalInSandbox(source2, sandbox, null, "second.js", 1);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
function loggingMethod(str) {
logs.push(str);
}
info("Start tracing");
JSTracer.startTracing({
global: sandbox,
filterFrameSourceUrl: "second",
loggingMethod,
});
info("Call some code");
sandbox.foo();
Assert.equal(logs.length, 2);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ bar");
Assert.stringContains(logs[1], "second.js:1:18");
info("Stop tracing");
JSTracer.stopTracing();
});
add_task(async function testTracingAllGlobals() {
// Test the `traceAllGlobals` flag
// Create two distinct globals in order to verify that both are traced
const source1 = `function foo() { bar(); }`;
Cu.evalInSandbox(source1, sandbox1, null, "sandbox1.js", 1);
const source2 = `function bar() { }`;
Cu.evalInSandbox(source2, sandbox2, null, "sandbox2.js", 1);
// Expose `bar` from sandbox2 as global in sandbox1, so that `foo` from sandbox1 can call it.
sandbox1.bar = sandbox2.bar;
// Pass an override method to catch all strings tentatively logged to stdout
//
// But in this test, we have to evaluate it in a special sandbox which will be ignored by the tracer.
// Otherwise, the tracer would do an infinite loop on this loggingMethod.
const ignoredGlobal = new Cu.Sandbox(null, { invisibleToDebugger: true });
const loggingMethodString = `
var logs = [];
function loggingMethod(str) {
logs.push(str);
};
`;
Cu.evalInSandbox(
loggingMethodString,
ignoredGlobal,
null,
"loggin-method.js",
1
);
const { loggingMethod, logs } = ignoredGlobal;
info("Start tracing on all globals");
JSTracer.startTracing({
traceAllGlobals: true,
loggingMethod,
});
// Call some code while being careful to not call anything else which may be traced
sandbox1.foo();
JSTracer.stopTracing();
Assert.equal(logs.length, 4);
Assert.equal(logs[0], "Start tracing JavaScript\n");
Assert.stringContains(logs[1], "λ foo");
Assert.stringContains(logs[1], "sandbox1.js:1:18");
Assert.stringContains(logs[2], "λ bar");
Assert.stringContains(logs[2], "sandbox2.js:1:18");
Assert.equal(logs[3], "Stop tracing JavaScript\n");
});
add_task(async function testTracingInfiniteLoop() {
// Test that the tracer handles infinite loops
Cu.evalInSandbox(
`function foo() { bar(); }; function bar() { foo() };`,
sandbox
);
// Pass an override method to catch all strings tentatively logged to stdout
const logs = [];
function loggingMethod(str) {
logs.push(str);
}
info("Start tracing");
JSTracer.startTracing({
global: sandbox,
loggingMethod,
});
info("Call some code");
try {
sandbox.foo();
Assert.fail("Should have thrown error because of infinite loop");
} catch (e) {
Assert.equal(e.message, "too much recursion");
}
Assert.greater(logs.length, 1000);
Assert.equal(logs[0], "Start tracing JavaScript\n");
// This will stop logging trace once spidermonkey stopped the execution
Assert.stringContains(logs[1], "λ foo");
Assert.stringContains(logs[2], "λ bar");
Assert.stringContains(logs[3], "λ foo");
Assert.stringContains(logs[4], "λ bar");
Assert.stringContains(logs[5], "λ foo");
info("Stop tracing");
JSTracer.stopTracing();
});