Bug 1835614 - [devtools] Log function call arguments. r=devtools-reviewers,fluent-reviewers,devtools-backward-compat-reviewers,nchevobbe

Introduce a new global option in the tracer to log values.

For now, it only triggers javascript function call arguments to be logged,
but this will also impact the incoming feature logging native function calls,
and also the other incoming feature to log the returned values.

Differential Revision: https://phabricator.services.mozilla.com/D196019
This commit is contained in:
Alexandre Poirot 2023-12-19 18:01:52 +00:00
Родитель b89a73183a
Коммит f69feec059
16 изменённых файлов: 282 добавлений и 22 удалений

Просмотреть файл

@ -234,6 +234,12 @@ export function setJavascriptTracingLogMethod(value) {
};
}
export function toggleJavascriptTracingValues() {
return {
type: "TOGGLE_JAVASCRIPT_TRACING_VALUES",
};
}
export function setHideOrShowIgnoredSources(shouldHide) {
return ({ dispatch, getState }) => {
dispatch({ type: "HIDE_IGNORED_SOURCES", shouldHide });

Просмотреть файл

@ -16,6 +16,7 @@ import {
getIsCurrentThreadPaused,
getIsThreadCurrentlyTracing,
getJavascriptTracingLogMethod,
getJavascriptTracingValues,
} from "../../selectors";
import { formatKeyShortcut } from "../../utils/text";
import actions from "../../actions";
@ -117,6 +118,7 @@ class CommandBar extends Component {
topFrameSelected: PropTypes.bool.isRequired,
toggleTracing: PropTypes.func.isRequired,
logMethod: PropTypes.string.isRequired,
logValues: PropTypes.bool.isRequired,
setJavascriptTracingLogMethod: PropTypes.func.isRequired,
setHideOrShowIgnoredSources: PropTypes.func.isRequired,
toggleSourceMapIgnoreList: PropTypes.func.isRequired,
@ -242,6 +244,16 @@ class CommandBar extends Component {
this.props.setJavascriptTracingLogMethod(LOG_METHODS.STDOUT);
},
},
{ type: "separator" },
{
id: "debugger-trace-menu-item-log-values",
label: L10N.getStr("traceValues"),
type: "checkbox",
checked: this.props.logValues,
click: () => {
this.props.toggleJavascriptTracingValues();
},
},
];
showMenu(event, items);
},
@ -410,11 +422,13 @@ const mapStateToProps = state => ({
isPaused: getIsCurrentThreadPaused(state),
isTracingEnabled: getIsThreadCurrentlyTracing(state, getCurrentThread(state)),
logMethod: getJavascriptTracingLogMethod(state),
logValues: getJavascriptTracingValues(state),
});
export default connect(mapStateToProps, {
toggleTracing: actions.toggleTracing,
setJavascriptTracingLogMethod: actions.setJavascriptTracingLogMethod,
toggleJavascriptTracingValues: actions.toggleJavascriptTracingValues,
resume: actions.resume,
stepIn: actions.stepIn,
stepOut: actions.stepOut,

Просмотреть файл

@ -36,6 +36,7 @@ export const initialUIState = ({ supportsDebuggerStatementIgnore } = {}) => ({
editorWrappingEnabled: prefs.editorWrapping,
javascriptEnabled: true,
javascriptTracingLogMethod: prefs.javascriptTracingLogMethod,
javascriptTracingValues: prefs.javascriptTracingValues,
mutableSearchOptions: prefs.searchOptions || {
[searchKeys.FILE_SEARCH]: {
regexMatch: false,
@ -164,6 +165,14 @@ function update(state = initialUIState(), action) {
return { ...state, javascriptTracingLogMethod: action.value };
}
case "TOGGLE_JAVASCRIPT_TRACING_VALUES": {
prefs.javascriptTracingValues = !prefs.javascriptTracingValues;
return {
...state,
javascriptTracingValues: prefs.javascriptTracingValues,
};
}
case "SET_SEARCH_OPTIONS": {
state.mutableSearchOptions[action.searchKey] = {
...state.mutableSearchOptions[action.searchKey],

Просмотреть файл

@ -72,6 +72,10 @@ export function getJavascriptTracingLogMethod(state) {
return state.ui.javascriptTracingLogMethod;
}
export function getJavascriptTracingValues(state) {
return state.ui.javascriptTracingValues;
}
export function getSearchOptions(state, searchKey) {
return state.ui.mutableSearchOptions[searchKey];
}

Просмотреть файл

@ -45,6 +45,7 @@ if (isNode()) {
pref("devtools.debugger.log-actions", true);
pref("devtools.debugger.log-event-breakpoints", false);
pref("devtools.debugger.javascript-tracing-log-method", "console");
pref("devtools.debugger.javascript-tracing-values", false);
pref("devtools.debugger.hide-ignored-sources", false);
pref("devtools.debugger.source-map-ignore-list-enabled", true);
pref("devtools.debugger.features.wasm", true);
@ -104,6 +105,7 @@ export const prefs = new PrefsHelper("devtools", {
"String",
"debugger.javascript-tracing-log-method",
],
javascriptTracingValues: ["Bool", "debugger.javascript-tracing-values"],
hideIgnoredSources: ["Bool", "debugger.hide-ignored-sources"],
sourceMapIgnoreListEnabled: [
"Bool",

Просмотреть файл

@ -15,11 +15,11 @@ add_task(async function () {
info("Enable the tracing");
await clickElement(dbg, "trace");
const topLevelThread =
const topLevelThreadActorID =
dbg.toolbox.commands.targetCommand.targetFront.threadFront.actorID;
info("Wait for tracing to be enabled");
await waitForState(dbg, state => {
return dbg.selectors.getIsThreadCurrentlyTracing(topLevelThread);
return dbg.selectors.getIsThreadCurrentlyTracing(topLevelThreadActorID);
});
ok(
@ -89,7 +89,7 @@ add_task(async function () {
await clickElement(dbg, "trace");
info("Wait for tracing to be disabled");
await waitForState(dbg, state => {
return !dbg.selectors.getIsThreadCurrentlyTracing(topLevelThread);
return !dbg.selectors.getIsThreadCurrentlyTracing(topLevelThreadActorID);
});
invokeInTab("inline_script2");
@ -179,10 +179,10 @@ add_task(async function testPageKeyShortcut() {
const dbg = await initDebuggerWithAbsoluteURL("data:text/html,key-shortcut");
const topLevelThread =
const topLevelThreadActorID =
dbg.toolbox.commands.targetCommand.targetFront.threadFront.actorID;
ok(
!dbg.selectors.getIsThreadCurrentlyTracing(topLevelThread),
!dbg.selectors.getIsThreadCurrentlyTracing(topLevelThreadActorID),
"Tracing is disabled on debugger opening"
);
@ -212,7 +212,7 @@ add_task(async function testPageKeyShortcut() {
info("Wait for tracing to be enabled");
await waitForState(dbg, state => {
return dbg.selectors.getIsThreadCurrentlyTracing(topLevelThread);
return dbg.selectors.getIsThreadCurrentlyTracing(topLevelThreadActorID);
});
is(
@ -232,7 +232,7 @@ add_task(async function testPageKeyShortcut() {
info("Wait for tracing to be disabled");
await waitForState(dbg, state => {
return !dbg.selectors.getIsThreadCurrentlyTracing(topLevelThread);
return !dbg.selectors.getIsThreadCurrentlyTracing(topLevelThreadActorID);
});
});
@ -316,3 +316,44 @@ add_task(async function testPageKeyShortcutWithoutDebugger() {
info("Wait for tracing to be disabled");
await onTracingStateDisabled;
});
add_task(async function testTracingValues() {
await pushPref("devtools.debugger.features.javascript-tracing", true);
// Cover tracing function argument values
const jsCode = `function foo() { bar(1, ["array"], { attribute: 3 }, BigInt(4), Infinity, Symbol("6"), "7"); }; function bar(a, b, c) {}`;
const dbg = await initDebuggerWithAbsoluteURL(
"data:text/html," + encodeURIComponent(`<script>${jsCode}</script>`)
);
await openContextMenuInDebugger(dbg, "trace", 4);
const toggled = waitForDispatch(
dbg.store,
"TOGGLE_JAVASCRIPT_TRACING_VALUES"
);
selectContextMenuItem(dbg, `#debugger-trace-menu-item-log-values`);
await toggled;
ok(true, "Toggled the log values setting");
await clickElement(dbg, "trace");
const topLevelThreadActorID =
dbg.toolbox.commands.targetCommand.targetFront.threadFront.actorID;
info("Wait for tracing to be enabled");
await waitForState(dbg, state => {
return dbg.selectors.getIsThreadCurrentlyTracing(topLevelThreadActorID);
});
invokeInTab("foo");
await hasConsoleMessage(dbg, "λ foo()");
await hasConsoleMessage(dbg, "λ bar");
const { value } = await findConsoleMessage(dbg, "λ bar");
is(
value,
`interpreter⟶λ bar(1, \nArray [ "array" ]\n, \nObject { attribute: 3 }\n, 4n, Infinity, Symbol("6"), "7")`,
"The argument were printed for bar()"
);
// Reset the log values setting
Services.prefs.clearUserPref("devtools.debugger.javascript-tracing-values");
});

Просмотреть файл

@ -142,6 +142,12 @@ traceInWebConsole=Trace in the web console
# This is used to force logging JavaScript traces in the stdout.
traceInStdout=Trace in the stdout
# LOCALIZATION NOTE (traceValues): The label that is displayed in the context menu
# of the trace button, which is in the top of the debugger right sidebar.
# This is used to enable logging arguments passed to function calls
# as well as returned values (only for JS function calls, but not native function calls)
traceValues=Log function arguments and returned values
# LOCALIZATION NOTE (resumeButtonTooltip): The label that is displayed on the pause
# button when the debugger is in a paused state.
resumeButtonTooltip=Resume %S

Просмотреть файл

@ -51,6 +51,7 @@ pref("devtools.debugger.map-scopes-enabled", false);
pref("devtools.debugger.log-actions", false);
pref("devtools.debugger.log-event-breakpoints", false);
pref("devtools.debugger.javascript-tracing-log-method", "console");
pref("devtools.debugger.javascript-tracing-values", false);
pref("devtools.debugger.features.wasm", true);
pref("devtools.debugger.features.code-folding", false);

Просмотреть файл

@ -43,18 +43,19 @@ add_task(async function () {
// Instead the frontend log a message as a console API message.
msg = await evaluateExpressionInConsole(
hud,
":trace --logMethod console --prefix foo",
":trace --logMethod console --prefix foo --values",
"console-api"
);
is(msg.textContent.trim(), "Started tracing to Web Console");
info("Trigger some code to log some traces");
await SpecialPowers.spawn(gBrowser.selectedBrowser, [], () => {
content.wrappedJSObject.main();
content.wrappedJSObject.main("arg", 2);
});
// Assert that we also see the custom prefix, as well as function arguments
await waitFor(
() => !!findTracerMessages(hud, `foo: interpreter⟶λ main`).length
() => !!findTracerMessages(hud, `foo: interpreter⟶λ main("arg", 2)`).length
);
info("Test toggling the tracer OFF");

Просмотреть файл

@ -19,6 +19,11 @@ const { tracerSpec } = require("resource://devtools/shared/specs/tracer.js");
const { throttle } = require("resource://devtools/shared/throttle.js");
const {
makeDebuggeeValue,
createValueGripForTarget,
} = require("devtools/server/actors/object/utils");
const {
TYPES,
getResourceWatcher,
@ -85,8 +90,18 @@ class TracerActor extends Actor {
return false;
}
startTracing(logMethod = LOG_METHODS.STDOUT) {
this.#startTracing({ logMethod });
/**
* Start tracing.
*
* @param {String} logMethod
* The output method used by the tracer.
* See `LOG_METHODS` for potential values.
* @param {Object} options
* Options used to configure JavaScriptTracer.
* See `JavaScriptTracer.startTracing`.
*/
startTracing(logMethod = LOG_METHODS.STDOUT, options = {}) {
this.#startTracing({ ...options, logMethod });
}
#startTracing(options) {
@ -109,11 +124,14 @@ class TracerActor extends Actor {
onTracingInfiniteLoop: this.onTracingInfiniteLoop.bind(this),
};
addTracingListener(this.tracingListener);
this.traceValues = !!options.traceValues;
startTracing({
global: this.targetActor.window || this.targetActor.workerGlobal,
prefix: options.prefix || "",
// Enable receiving the `currentDOMEvent` being passed to `onTracingFrame`
traceDOMEvents: true,
// Enable tracing function arguments as well as returned values
traceValues: !!options.traceValues,
});
}
@ -238,6 +256,22 @@ class TracerActor extends Actor {
});
}
let args = undefined;
// Log arguments, but only when this feature is enabled as it introduce
// some significant overhead in perf as well as memory as it may hold the objects in memory.
if (this.traceValues) {
args = [];
for (let arg of frame.arguments) {
// Debugger.Frame.arguments contains either a Debugger.Object or primitive object
if (arg?.unsafeDereference) {
arg = arg.unsafeDereference();
}
// Instantiate a object actor so that the tools can easily inspect these objects
const dbgObj = makeDebuggeeValue(this.targetActor, arg);
args.push(createValueGripForTarget(this.targetActor, dbgObj));
}
}
// Create a message object that fits Console Message Watcher expectations
this.throttledTraces.push({
resourceType: JSTRACER_TRACE,
@ -251,6 +285,7 @@ class TracerActor extends Actor {
lineNumber,
columnNumber: columnNumber - columnBase,
sourceId: script.source.id,
args,
});
this.throttleEmitTraces();
} else if (this.logMethod == LOG_METHODS.PROFILER) {

Просмотреть файл

@ -16,7 +16,7 @@ loader.lazyGetter(this, "l10n", () => {
});
const USAGE_STRING_MAPPING = {
block: "webconsole-commands-usage-block",
trace: "webconsole-commands-usage-trace",
trace: "webconsole-commands-usage-trace2",
unblock: "webconsole-commands-usage-unblock",
};
@ -871,6 +871,7 @@ WebConsoleCommandsManager.register({
const enabled = tracerActor.toggleTracing({
logMethod,
prefix: args.prefix || null,
traceValues: !!args.values,
});
owner.helperResult = {
@ -879,5 +880,5 @@ WebConsoleCommandsManager.register({
logMethod,
};
},
validArguments: ["logMethod", "prefix"],
validArguments: ["logMethod", "prefix", "values"],
});

Просмотреть файл

@ -137,3 +137,35 @@ add_task(async function testTracingJSMGlobal() {
removeTracingListener(listenerSandbox.listener);
});
add_task(async function testTracingValues() {
// Test the `traceValues` flag
const sandbox = Cu.Sandbox("https://example.com");
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");
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");
stopTracing();
});

Просмотреть файл

@ -83,9 +83,15 @@ const customLazy = {
* Optional spidermonkey's Debugger instance.
* This allows devtools to pass a custom instance and ease worker support
* where we can't load jsdebugger.sys.mjs.
* @param {Boolean} options.loggingMethod
* Optional setting to use something else than `dump()` to log traces to stdout.
* This is mostly used by tests.
* @param {Boolean} options.traceDOMEvents
* Optional setting to enable tracing all the DOM events being going through
* dom/events/EventListenerManager.cpp's `EventListenerManager`.
* @param {Boolean} options.traceValues
* Optional setting to enable tracing all function call values as well,
* as returned values (when we do log returned frames).
*/
class JavaScriptTracer {
constructor(options) {
@ -103,12 +109,24 @@ class JavaScriptTracer {
this.depth = 0;
this.prefix = options.prefix ? `${options.prefix}: ` : "";
this.loggingMethod = options.loggingMethod;
if (!this.loggingMethod) {
// On workers, `dump` can't be called with JavaScript on another object,
// so bind it.
this.loggingMethod =
globalThis.constructor.name == "WorkerDebuggerGlobalScope"
? // eslint-disable-next-line mozilla/reject-globalThis-modification
dump.bind(globalThis)
: dump;
}
this.dbg.onEnterFrame = this.onEnterFrame;
this.traceDOMEvents = !!options.traceDOMEvents;
if (this.traceDOMEvents) {
this.startTracingDOMEvents();
}
this.traceValues = !!options.traceValues;
this.notifyToggle(true);
}
@ -222,9 +240,9 @@ class JavaScriptTracer {
}
if (shouldLogToStdout) {
if (state) {
dump(this.prefix + "Start tracing JavaScript\n");
this.loggingMethod(this.prefix + "Start tracing JavaScript\n");
} else {
dump(this.prefix + "Stop tracing JavaScript\n");
this.loggingMethod(this.prefix + "Stop tracing JavaScript\n");
}
}
}
@ -241,7 +259,7 @@ class JavaScriptTracer {
}
}
if (shouldLogToStdout) {
dump(
this.loggingMethod(
this.prefix +
"Looks like an infinite recursion? We stopped the JavaScript tracer, but code may still be running!\n"
);
@ -300,7 +318,9 @@ class JavaScriptTracer {
// and are logging the topmost frame,
// then log a preliminary dedicated line to mention that event type.
if (this.currentDOMEvent && this.depth == 0) {
dump(this.prefix + padding + this.currentDOMEvent + "\n");
this.loggingMethod(
this.prefix + padding + this.currentDOMEvent + "\n"
);
}
// Use a special URL, including line and column numbers which Firefox
@ -311,11 +331,38 @@ class JavaScriptTracer {
// See https://gist.github.com/egmontkob/eb114294efbcd5adb1944c9f3cb5feda
const urlLink = `\x1B]8;;${href}\x1B\\${href}\x1B]8;;\x1B\\`;
const message = `${padding}[${
let message = `${padding}[${
frame.implementation
}]> ${urlLink} - ${formatDisplayName(frame)}`;
dump(this.prefix + message + "\n");
// Log arguments, but only when this feature is enabled as it introduces
// some significant performance and visual overhead.
// Also prevent trying to log function call arguments if we aren't logging a frame
// with arguments (e.g. Debugger evaluation frames, when executing from the console)
if (this.traceValues && frame.arguments) {
message += "(";
for (let i = 0, l = frame.arguments.length; i < l; i++) {
const arg = frame.arguments[i];
// Debugger.Frame.arguments contains either a Debugger.Object or primitive object
if (arg?.unsafeDereference) {
// Special case classes as they can't be easily differentiated in pure JavaScript
if (arg.isClassConstructor) {
message += "class " + arg.name;
} else {
message += objectToString(arg.unsafeDereference());
}
} else {
message += primitiveToString(arg);
}
if (i < l - 1) {
message += ", ";
}
}
message += ")";
}
this.loggingMethod(this.prefix + message + "\n");
}
this.depth++;
@ -328,6 +375,55 @@ class JavaScriptTracer {
}
}
/**
* Return a string description for any arbitrary JS value.
* Used when logging to stdout.
*
* @param {Object} obj
* Any JavaScript object to describe.
* @return String
* User meaningful descriptor for the object.
*/
function objectToString(obj) {
if (Element.isInstance(obj)) {
let message = `<${obj.tagName}`;
if (obj.id) {
message += ` #${obj.id}`;
}
if (obj.className) {
message += ` .${obj.className}`;
}
message += ">";
return message;
} else if (Array.isArray(obj)) {
return `Array(${obj.length})`;
} else if (Event.isInstance(obj)) {
return `Event(${obj.type}) target=${objectToString(obj.target)}`;
} else if (typeof obj === "function") {
return `function ${obj.name || "anonymous"}()`;
}
return obj;
}
function primitiveToString(value) {
const type = typeof value;
if (type === "string") {
// Use stringify to escape special characters and display in enclosing quotes.
return JSON.stringify(value);
} else if (value === 0 && 1 / value === -Infinity) {
// -0 is very special and need special threatment.
return "-0";
} else if (type === "bigint") {
return `BigInt(${value})`;
} else if (value && typeof value.toString === "function") {
// Use toString as it allows to stringify Symbols. Converting them to string throws.
return value.toString();
}
// For all other types/cases, rely on native convertion to string
return value;
}
/**
* Try to describe the current frame we are tracing
*

Просмотреть файл

@ -33,6 +33,11 @@ class TracerCommand {
);
}
const traceValues = Services.prefs.getBoolPref(
"devtools.debugger.javascript-tracing-values",
false
);
const targets = this.#targetCommand.getAllTargets(
this.#targetCommand.ALL_TYPES
);
@ -46,7 +51,7 @@ class TracerCommand {
}
if (this.#isTracing) {
return tracerFront.startTracing(logMethod);
return tracerFront.startTracing(logMethod, { traceValues });
}
return tracerFront.stopTracing();
})

Просмотреть файл

@ -24,12 +24,13 @@ webconsole-commands-usage-unblock =
It accepts only one argument, the exact same string previously passed to :block.
# Usage string for :trace command
webconsole-commands-usage-trace =
webconsole-commands-usage-trace2 =
:trace
Toggles the JavaScript tracer
It supports the following arguments:
--logMethod to be set to console for logging to the web console (the default), or stdout for logging to the standard output,
--values Optional flag to be passed to log function call arguments as well as returned values (when returned frames are enabled).
--prefix Optional string which will be logged in front of all the trace logs,
--help or --usage to show this message.

Просмотреть файл

@ -7,8 +7,13 @@
const {
generateActorSpec,
Arg,
types,
} = require("resource://devtools/shared/protocol.js");
types.addDictType("tracer.start.options", {
traceValues: "boolean",
});
const tracerSpec = generateActorSpec({
typeName: "tracer",
@ -16,6 +21,7 @@ const tracerSpec = generateActorSpec({
startTracing: {
request: {
logMethod: Arg(0, "string"),
options: Arg(1, "tracer.start.options"),
},
},
stopTracing: {