From b08a3cc809edaf912816bdb7ec7d0bac2381b9a0 Mon Sep 17 00:00:00 2001 From: Brian Hackett Date: Mon, 16 Sep 2019 00:12:34 +0000 Subject: [PATCH] Bug 1581013 - Support event logpoints when replaying, r=jlast. Differential Revision: https://phabricator.services.mozilla.com/D45778 --HG-- extra : moz-landing-system : lando --- devtools/server/actors/replay/control.js | 195 ++++++++++++++-------- devtools/server/actors/replay/debugger.js | 27 +++ devtools/server/actors/replay/replay.js | 76 ++++++++- devtools/server/actors/thread.js | 19 +++ 4 files changed, 244 insertions(+), 73 deletions(-) diff --git a/devtools/server/actors/replay/control.js b/devtools/server/actors/replay/control.js index 86594ce7d7c1..f70203e1c1c5 100644 --- a/devtools/server/actors/replay/control.js +++ b/devtools/server/actors/replay/control.js @@ -519,6 +519,9 @@ function CheckpointInfo() { // If the checkpoint is saved, any debugger statement hits in its region. this.debuggerStatements = []; + + // If the checkpoint is saved, any events in its region. + this.events = []; } function getCheckpointInfo(id) { @@ -661,6 +664,10 @@ function forSavedCheckpointsInRange(start, end, callback) { } } +function forAllSavedCheckpoints(callback) { + forSavedCheckpointsInRange(FirstCheckpointId, gLastFlushCheckpoint, callback); +} + function getSavedCheckpoint(checkpoint) { while (!gCheckpoints[checkpoint].saved) { checkpoint--; @@ -795,15 +802,11 @@ function unscannedRegions() { } } - forSavedCheckpointsInRange( - FirstCheckpointId, - gLastFlushCheckpoint, - checkpoint => { - if (!findScanChild(checkpoint)) { - addRegion(checkpoint, nextSavedCheckpoint(checkpoint)); - } + forAllSavedCheckpoints(checkpoint => { + if (!findScanChild(checkpoint)) { + addRegion(checkpoint, nextSavedCheckpoint(checkpoint)); } - ); + }); const lastFlush = gLastFlushCheckpoint || FirstCheckpointId; if (lastFlush != gRecordingEndpoint) { @@ -1213,13 +1216,13 @@ async function finishResume() { continue; } - let hits = []; + const hits = []; // Find any breakpoint hits in this region of the recording. for (const bp of gBreakpoints) { if (canFindHits(bp)) { const bphits = await findHits(checkpoint, bp); - hits = hits.concat(bphits); + hits.push(...bphits); } } @@ -1227,15 +1230,15 @@ async function finishResume() { // steps for the current frame. if (checkpoint == startCheckpoint && hasSteppingBreakpoint()) { const steps = await findFrameSteps(gPausePoint); - hits = hits.concat( - steps.filter(point => { + hits.push( + ...steps.filter(point => { return gBreakpoints.some(bp => positionSubsumes(bp, point.position)); }) ); } // Always pause at debugger statements, as if they are breakpoint hits. - hits = hits.concat(getCheckpointInfo(checkpoint).debuggerStatements); + hits.push(...getCheckpointInfo(checkpoint).debuggerStatements); const hit = findClosestPoint( hits, @@ -1467,6 +1470,39 @@ function updateNearbyPoints() { // associated with the logpoint. const gLogpoints = []; +async function evaluateLogpoint({ point, text, condition, callback }) { + assert(point); + if (!condition) { + callback(point, ["Loading..."]); + } + let skipPauseData = false; + const manifest = { + shouldSkip: () => false, + contents() { + return { kind: "hitLogpoint", text, condition, skipPauseData }; + }, + onFinished(child, { pauseData, result, resultData, restoredSnapshot }) { + if (restoredSnapshot && !skipPauseData) { + // Gathering pause data sometimes triggers a snapshot restore. + skipPauseData = true; + sendAsyncManifest(manifest); + } else { + if (result) { + if (!skipPauseData) { + addPauseData(point, pauseData, /* trackCached */ true); + } + callback(point, result, resultData); + } + child.divergedFromRecording = true; + } + }, + point, + expectedDuration: 250, + lowPriority: true, + }; + sendAsyncManifest(manifest); +} + // Asynchronously invoke a logpoint's callback with all results from hitting // the logpoint in the range of the recording covered by checkpoint. async function findLogpointHits( @@ -1475,35 +1511,59 @@ async function findLogpointHits( ) { const hits = await findHits(checkpoint, position); for (const point of hits) { - if (!condition) { - callback(point, ["Loading..."]); + evaluateLogpoint({ point, text, condition, callback }); + } +} + +//////////////////////////////////////////////////////////////////////////////// +// Event Breakpoints +//////////////////////////////////////////////////////////////////////////////// + +// Event kinds which will be logged. For now this set can only grow, as we don't +// have a way to remove old event logpoints from the client. +const gLoggedEvents = []; + +const gEventFrameEntryPoints = new Map(); + +async function findEventFrameEntry(checkpoint, progress) { + if (gEventFrameEntryPoints.has(progress)) { + return gEventFrameEntryPoints.get(progress); + } + + const savedCheckpoint = getSavedCheckpoint(checkpoint); + await scanRecording(savedCheckpoint); + await sendAsyncManifest({ + shouldSkip: () => gEventFrameEntryPoints.has(progress), + contents: () => ({ kind: "findEventFrameEntry", checkpoint, progress }), + onFinished: (_, { rv }) => gEventFrameEntryPoints.set(progress, rv), + scanCheckpoint: savedCheckpoint, + }); + + return gEventFrameEntryPoints.get(progress); +} + +async function findEventLogpointHits(checkpoint, event, callback) { + for (const info of getCheckpointInfo(checkpoint).events) { + if (info.event == event) { + const point = await findEventFrameEntry(info.checkpoint, info.progress); + if (point) { + evaluateLogpoint({ point, text: "arguments[0]", callback }); + } } - let skipPauseData = false; - const manifest = { - shouldSkip: () => false, - contents() { - return { kind: "hitLogpoint", text, condition, skipPauseData }; - }, - onFinished(child, { pauseData, result, resultData, restoredSnapshot }) { - if (restoredSnapshot && !skipPauseData) { - // Gathering pause data sometimes triggers a snapshot restore. - skipPauseData = true; - sendAsyncManifest(manifest); - } else { - if (result) { - if (!skipPauseData) { - addPauseData(point, pauseData, /* trackCached */ true); - } - callback(point, result, resultData); - } - child.divergedFromRecording = true; - } - }, - point, - expectedDuration: 250, - lowPriority: true, - }; - sendAsyncManifest(manifest); + } +} + +function setActiveEventBreakpoints(events, callback) { + dumpv(`SetActiveEventBreakpoints ${JSON.stringify(events)}`); + + for (const event of events) { + if (gLoggedEvents.some(info => info.event == event)) { + continue; + } + gLoggedEvents.push({ event, callback }); + forAllSavedCheckpoints(checkpoint => + findEventLogpointHits(checkpoint, event, callback) + ); } } @@ -1519,6 +1579,7 @@ function handleResumeManifestResponse({ consoleMessages, scripts, debuggerStatements, + events, }) { if (!point.position) { addCheckpoint(point.checkpoint - 1, duration); @@ -1539,9 +1600,16 @@ function handleResumeManifestResponse({ } }); + const savedCheckpoint = getSavedCheckpoint( + point.position ? point.checkpoint : point.checkpoint - 1 + ); + for (const point of debuggerStatements) { - const checkpoint = getSavedCheckpoint(point.checkpoint); - getCheckpointInfo(checkpoint).debuggerStatements.push(point); + getCheckpointInfo(savedCheckpoint).debuggerStatements.push(point); + } + + for (const event of events) { + getCheckpointInfo(savedCheckpoint).events.push(event); } // In repaint stress mode, the child process creates a checkpoint before every @@ -1653,6 +1721,9 @@ function ensureFlushed() { findBreakpointHits(checkpoint, position) ); gLogpoints.forEach(logpoint => findLogpointHits(checkpoint, logpoint)); + for (const { event, callback } of gLoggedEvents) { + findEventLogpointHits(checkpoint, event, callback); + } } ); @@ -1801,10 +1872,8 @@ const gControl = { // Start searching for breakpoint hits in the recording immediately. if (canFindHits(position)) { - forSavedCheckpointsInRange( - FirstCheckpointId, - gLastFlushCheckpoint, - checkpoint => findBreakpointHits(checkpoint, position) + forAllSavedCheckpoints(checkpoint => + findBreakpointHits(checkpoint, position) ); } @@ -1916,13 +1985,13 @@ const gControl = { // Add a new logpoint. addLogpoint(logpoint) { gLogpoints.push(logpoint); - forSavedCheckpointsInRange( - FirstCheckpointId, - gLastFlushCheckpoint, - checkpoint => findLogpointHits(checkpoint, logpoint) + forAllSavedCheckpoints(checkpoint => + findLogpointHits(checkpoint, logpoint) ); }, + setActiveEventBreakpoints, + unscannedRegions, cachedPoints, @@ -2011,22 +2080,18 @@ function maybeDumpStatistics() { let timeTotal = 0; let scanDurationTotal = 0; - forSavedCheckpointsInRange( - FirstCheckpointId, - gLastFlushCheckpoint, - checkpoint => { - const checkpointTime = timeForSavedCheckpoint(checkpoint); - const info = getCheckpointInfo(checkpoint); + forAllSavedCheckpoints(checkpoint => { + const checkpointTime = timeForSavedCheckpoint(checkpoint); + const info = getCheckpointInfo(checkpoint); - timeTotal += checkpointTime; - if (info.scanTime) { - delayTotal += checkpointTime * (info.scanTime - info.assignTime); - scanDurationTotal += info.scanDuration; - } else { - unscannedTotal += checkpointTime; - } + timeTotal += checkpointTime; + if (info.scanTime) { + delayTotal += checkpointTime * (info.scanTime - info.assignTime); + scanDurationTotal += info.scanDuration; + } else { + unscannedTotal += checkpointTime; } - ); + }); const memoryUsage = []; let totalSaved = 0; diff --git a/devtools/server/actors/replay/debugger.js b/devtools/server/actors/replay/debugger.js index c6f1562dcdbc..de5bf74cd34a 100644 --- a/devtools/server/actors/replay/debugger.js +++ b/devtools/server/actors/replay/debugger.js @@ -299,6 +299,14 @@ ReplayDebugger.prototype = { return []; }, + replayGetExecutionPointPosition({ position }) { + const script = this._getScript(position.script); + if (position.kind == "EnterFrame") { + return { script, offset: script.mainOffset }; + } + return { script, offset: position.offset }; + }, + ///////////////////////////////////////////////////////// // Paused/running state ///////////////////////////////////////////////////////// @@ -752,6 +760,21 @@ ReplayDebugger.prototype = { return messages.map(this._convertConsoleMessage.bind(this)); }, + ///////////////////////////////////////////////////////// + // Event Breakpoint methods + ///////////////////////////////////////////////////////// + + replaySetActiveEventBreakpoints(events, callback) { + this._control.setActiveEventBreakpoints( + events, + (point, result, resultData) => { + const pool = new ReplayPool(this, resultData); + const converted = result.map(v => pool.convertValue(v)); + callback(point, converted); + } + ); + }, + ///////////////////////////////////////////////////////// // Handlers ///////////////////////////////////////////////////////// @@ -804,6 +827,9 @@ ReplayDebuggerScript.prototype = { get format() { return this._data.format; }, + get mainOffset() { + return this._data.mainOffset; + }, _forward(type, value) { return this._dbg._sendRequestMainChild({ type, id: this._data.id, value }); @@ -813,6 +839,7 @@ ReplayDebuggerScript.prototype = { return this._forward("getLineOffsets", line); }, getOffsetLocation(pc) { + assert(pc !== undefined); return this._forward("getOffsetLocation", pc); }, getSuccessorOffsets(pc) { diff --git a/devtools/server/actors/replay/replay.js b/devtools/server/actors/replay/replay.js index b66763360422..e89a6abd7087 100644 --- a/devtools/server/actors/replay/replay.js +++ b/devtools/server/actors/replay/replay.js @@ -23,7 +23,7 @@ const CC = Components.Constructor; -// Create a sandbox with the resources we need. require() doesn't work here. +// Create a sandbox with the resources we need. const sandbox = Cu.Sandbox( CC("@mozilla.org/systemprincipal;1", "nsIPrincipal")(), { @@ -49,14 +49,13 @@ const { findClosestPoint, } = sandbox; -function formatDisplayName(frame) { - if (frame.type === "call") { - const callee = frame.callee; - return callee.name || callee.userDisplayName || callee.displayName; - } +const { require } = ChromeUtils.import("resource://devtools/shared/Loader.jsm"); +const jsmScope = require("resource://devtools/shared/Loader.jsm"); +const { DebuggerNotificationObserver } = Cu.getGlobalForObject(jsmScope); - return `(${frame.type})`; -} +const { + eventBreakpointForNotification, +} = require("devtools/server/actors/utils/event-breakpoints"); const dbg = new Debugger(); const gFirstGlobal = dbg.makeGlobalObjectReference(sandbox); @@ -69,6 +68,7 @@ dbg.onNewGlobalObject = function(global) { gAllGlobals.push(global); scanningOnNewGlobal(global); + eventListenerOnNewGlobal(global); } catch (e) { // Ignore errors related to adding a same-compartment debuggee. // See bug 1523755. @@ -384,6 +384,40 @@ function NewTimeWarpTarget() { return gWarpTargetPoints.length - 1; } +/////////////////////////////////////////////////////////////////////////////// +// Event State +/////////////////////////////////////////////////////////////////////////////// + +const gNewEvents = []; + +const gDebuggerNotificationObserver = new DebuggerNotificationObserver(); +gDebuggerNotificationObserver.addListener(eventBreakpointListener); + +function eventListenerOnNewGlobal(global) { + try { + gDebuggerNotificationObserver.connect(global.unsafeDereference()); + } catch (e) {} +} + +function eventBreakpointListener(notification) { + const event = eventBreakpointForNotification(dbg, notification); + if (!event) { + return; + } + + // Advance the progress counter before and after each event, so that we can + // determine later if any JS ran between the two points. + RecordReplayControl.advanceProgressCounter(); + + if (notification.phase == "pre") { + const progress = RecordReplayControl.progressCounter(); + + if (gManifest.kind == "resume") { + gNewEvents.push({ event, checkpoint: gLastCheckpoint, progress }); + } + } +} + /////////////////////////////////////////////////////////////////////////////// // Recording Scanning /////////////////////////////////////////////////////////////////////////////// @@ -601,6 +635,16 @@ function findFrameSteps({ targetPoint, breakpointOffsets }) { return steps; } +function findEventFrameEntry({ checkpoint, progress }) { + const entryHits = findChangeFrames(checkpoint, 0, "EnterFrame", 0); + for (const hit of entryHits) { + if (hit.progress == progress + 1) { + return hit; + } + } + return null; +} + /////////////////////////////////////////////////////////////////////////////// // Position Handler State /////////////////////////////////////////////////////////////////////////////// @@ -945,6 +989,10 @@ const gManifestStartHandlers = { RecordReplayControl.manifestFinished(findFrameSteps(info)); }, + findEventFrameEntry(progress) { + RecordReplayControl.manifestFinished({ rv: findEventFrameEntry(progress) }); + }, + flushRecording() { RecordReplayControl.flushRecording(); RecordReplayControl.manifestFinished(); @@ -1066,10 +1114,12 @@ function finishResume(point) { consoleMessages: gNewConsoleMessages, scripts: gNewScripts, debuggerStatements: gNewDebuggerStatements, + events: gNewEvents, }); gNewConsoleMessages.length = 0; gNewScripts.length = 0; gNewDebuggerStatements.length = 0; + gNewEvents.length = 0; } // Handlers that run after a checkpoint is reached to see if the manifest has @@ -1225,6 +1275,7 @@ function getScriptData(id) { displayName: script.displayName, url: script.url, format: script.format, + mainOffset: script.mainOffset, }; } @@ -1674,6 +1725,15 @@ function getPauseData() { return rv; } +function formatDisplayName(frame) { + if (frame.type === "call") { + const callee = frame.callee; + return callee.name || callee.userDisplayName || callee.displayName; + } + + return `(${frame.type})`; +} + /////////////////////////////////////////////////////////////////////////////// // Handlers /////////////////////////////////////////////////////////////////////////////// diff --git a/devtools/server/actors/thread.js b/devtools/server/actors/thread.js index 316c2069c1de..1a3f16972b7d 100644 --- a/devtools/server/actors/thread.js +++ b/devtools/server/actors/thread.js @@ -544,6 +544,25 @@ const ThreadActor = ActorClassWithSpec(threadSpec, { this._eventBreakpointListener ); } + + if (isReplaying && this._options.logEventBreakpoints) { + const logpointId = `logGroup-${Math.random()}`; + this.dbg.replaySetActiveEventBreakpoints(ids, (executionPoint, rv) => { + const { script, offset } = this.dbg.replayGetExecutionPointPosition( + executionPoint + ); + const { lineNumber, columnNumber } = script.getOffsetLocation(offset); + const message = { + filename: script.url, + lineNumber, + columnNumber, + executionPoint, + arguments: rv, + logpointId, + }; + this._parent._consoleActor.onConsoleAPICall(message); + }); + } }, _onNewDebuggee(global) {