Closed Bug 1513118 Opened 5 years ago Closed 5 years ago

Add virtual console log functionality

Categories

(Core Graveyard :: Web Replay, enhancement)

enhancement
Not set
normal

Tracking

(firefox67 fixed)

RESOLVED FIXED
mozilla67
Tracking Status
firefox67 --- fixed

People

(Reporter: bhackett1024, Assigned: bhackett1024)

References

(Blocks 1 open bug)

Details

Attachments

(8 files, 2 obsolete files)

Attached patch Infrastructure WIP (obsolete) — Splinter Review
Console message handling while replaying and integration with the timeline are working very well now.  It would be nice to leverage this functionality and extend it with the ability to search within the recording for places where a breakpoint is hit, evaluate a string, and populate the console and timeline with the results.  This is essentially a virtual console.log call: one that can be added after the fact without any reloading and without affecting the recording.

The attached patch is a WIP that adds the needed functionality to ReplayDebugger and the middleman process (it also fixes a couple bugs that showed up in the workweek).  I like this patch because we don't have to mess around with IPC at all or add any new functionality to replaying child processes --- when a search is first made, we spawn a third replaying process whose sole job is to scan through the recording for places where searched locations are hit.  I don't like this patch because the ways in which that third process is managed are pretty cumbersome.  Before landing this functionality I want to move a lot more functionality from ParentIPC.cpp to debugger.js, letting JS keep track of all the child processes and their roles instead of C++.  With that in place, the additions in this patch should be much cleaner, but I'm attaching this patch for now so that it can be experimented with while I go do some other stuff for a little while.

There aren't any uses of the new functionality in the patch, but it can be accessed with:

ReplayDebuggerScript.replayVirtualConsoleLog(scriptOffset, evalText, callback);

callback will be invoked asynchronously with the execution point and evaluation result of every place that the script/offset are hit, anywhere in the recording, and including future parts of the recording as it grows.
Depends on: 1516578
Attached patch infrastructure and UI prototype (obsolete) — Splinter Review
This patch builds on the refactoring work in bug 1516578 to do a few things:

- Search functionality has been reimplemented in terms of the new control.js/debugger.js interface, which allows it to be much cleaner than in the earlier patch.

- The breakpoints UI in the debugger has been modified to allow adding a virtual console log for a given breakpoint, using the same UI components as when setting breakpoint conditions to specify the text that should be evaluated as part of the virtual log.

- After a virtual console log has been added for a breakpoint, it is forwarded to the server and a search is initiated to find all points where the breakpoint is hit and then evaluate the virtual log's text.

- The resulting logs are then passed back up to the client, where they are added to the console panel (out of order wrt any other messages there) and also populate the timeline.

This is pretty minimal/rough but it works and is I think a good starting point for building up this feature more.
Attachment #9030352 - Attachment is obsolete: true
Attached image context menu
Context menu item for adding a virtual console log for a breakpoint.
Attached image log text form
Form for specifying the text to evaluate, using the same components as when specifying a breakpoint condition.  For now object evaluation results are not supported (this seems better to fix in followup).
Attachment #9033603 - Attachment mime type: text/plain → image/png
Attached image console
Console display after adding the virtual log and warping to one of the discovered breakpoint hits.
Summary: Add 'virtual console log' functionality → Add virtual console log functionality
Attached patch patchSplinter Review
This patch removes the breakpoint UI changes made by the last patch.  Log points will be added to the debugger soon (https://github.com/devtools-html/debugger.html/pull/7592) and the logging done here matches up with the functionality added there.  After both have landed, log points can be used when not replaying to log messages about where a point is hit in the future, and when replaying the logged messages will also be created retroactively.  This patch does expose the functionality for adding virtual logs, but just hijacks breakpoint conditions to do so when replaying.  Either this can land and then be replaced with a proper fix after log points land, or if log points land first we can avoid this hack entirely.
Attachment #9033601 - Attachment is obsolete: true
In order to support having a searching replaying process that operates simultaneously with other replaying processes, we need to be able to support middleman calls being made by that searching process at the same time as middleman calls are made by the active process the user is interacting with.  The problem is that middleman calls made by multiple processes will interfere with each other --- they use the same pool of IDs and one child can reset state created by another.

The attached patch fixes this by separating the data used by different child processes in the middleman, so that calls from any number of child processes can be handled without any interaction.
Attachment #9033652 - Flags: review?(lsmyth)
Add infrastructure to ReplayControl and ReplayDebugger to support searching the execution for particular events, using a new replaying child process that is created on demand.  This is exposed to callers via ReplayDebuggerScript.replayVirtualConsoleLog(...)
Attachment #9033653 - Flags: review?(lsmyth)
Support virtual console logs in the devtools server and client.  New log points are added via SourceClient.setVirtualLog, and the resulting logs are received by the WebConsoleConnectionProxy and converted into normal console messages (this is temporary).  I also changed the toolbox to eagerly load the console when replaying.  While this could be avoided by having a way to cache virtual log messages when the console hasn't been loaded yet, making this change also fixes a bug where timeline events aren't shown until the console has been loaded once.
Attachment #9033654 - Flags: review?(lsmyth)
Set virtual logs instead of breakpoint conditions when using the UI.  No r? for now, hopefully this won't be needed when things are closer to landing.
Attachment #9033652 - Flags: review?(lsmyth) → review+
Attachment #9033653 - Flags: review?(lsmyth) → review+
Attachment #9033654 - Flags: review?(lsmyth) → review+
Pushed by bhackett@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9417ce02d4f2
Part 1 - Allow simultaneous middleman calls from multiple child processes, r=lsmyth.
https://hg.mozilla.org/integration/mozilla-inbound/rev/5ce216ffcb1d
Part 2 - Add support for virtual console logs to ReplayDebuggerScript, r=lsmyth.
https://hg.mozilla.org/integration/mozilla-inbound/rev/4abb81088a9b
Part 3 - Devtools server/client support for virtual console logs, r=lsmyth.

Backed out 12 changesets (bug 1516578, bug 1513118, bug 1516694) for failing at browser_toolbox_remoteness_change.js on a CLOSED TREE

Backout link: https://hg.mozilla.org/integration/mozilla-inbound/rev/9e3564442734c89fa1b735ff8662588576cf0115

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&resultStatus=testfailed%2Cbusted%2Cexception%2Crunnable&revision=4abb81088a9b49d700cfea840848a9dac6a0010d&selectedJob=221519592

Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=221519592&repo=mozilla-inbound&lineNumber=9675

Log snippet:

[task 2019-01-12T21:42:48.171Z] 21:42:48 INFO - GECKO(1484) | nsStringStats
[task 2019-01-12T21:42:48.171Z] 21:42:48 INFO - GECKO(1484) | => mAllocCount: 1939881
[task 2019-01-12T21:42:48.173Z] 21:42:48 INFO - GECKO(1484) | => mReallocCount: 1
[task 2019-01-12T21:42:48.173Z] 21:42:48 INFO - GECKO(1484) | => mFreeCount: 1939881
[task 2019-01-12T21:42:48.174Z] 21:42:48 INFO - GECKO(1484) | => mShareCount: 1889903
[task 2019-01-12T21:42:48.175Z] 21:42:48 INFO - GECKO(1484) | => mAdoptCount: 67026
[task 2019-01-12T21:42:48.176Z] 21:42:48 INFO - GECKO(1484) | => mAdoptFreeCount: 67986
[task 2019-01-12T21:42:48.177Z] 21:42:48 INFO - GECKO(1484) | => Process ID: 1484, Thread ID: 139783454422848
[task 2019-01-12T21:42:48.210Z] 21:42:48 INFO - TEST-INFO | Main app process: exit 0
[task 2019-01-12T21:42:48.211Z] 21:42:48 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_remoteness_change.js | leaked 4 window(s) until shutdown [url = about:blank]
[task 2019-01-12T21:42:48.212Z] 21:42:48 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_remoteness_change.js | leaked 1 window(s) until shutdown [url = chrome://devtools/content/webconsole/index.html]
[task 2019-01-12T21:42:48.222Z] 21:42:48 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_remoteness_change.js | leaked 1 window(s) until shutdown [url = about:devtools-toolbox]
[task 2019-01-12T21:42:48.223Z] 21:42:48 INFO - TEST-INFO | devtools/client/framework/test/browser_toolbox_remoteness_change.js | windows(s) leaked: [pid = 1484] [serial = 492], [pid = 1484] [serial = 490], [pid = 1484] [serial = 489], [pid = 1484] [serial = 491], [pid = 1484] [serial = 488], [pid = 1484] [serial = 487]
[task 2019-01-12T21:42:48.224Z] 21:42:48 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_remoteness_change.js | leaked 2 docShell(s) until shutdown
[task 2019-01-12T21:42:48.224Z] 21:42:48 INFO - TEST-INFO | devtools/client/framework/test/browser_toolbox_remoteness_change.js | docShell(s) leaked: [pid = 1484] [id = {2478efcb-416b-4465-ac17-c720bf9ea414}], [pid = 1484] [id = {4df99fc4-7efa-48f0-b186-723fe21e3008}]
[task 2019-01-12T21:42:48.226Z] 21:42:48 INFO - runtests.py | Application ran for: 0:15:58.112473
[task 2019-01-12T21:42:48.228Z] 21:42:48 INFO - zombiecheck | Reading PID log: /tmp/tmpCS3TLopidlog

Flags: needinfo?(bhackett1024)
Depends on: 1520972
Depends on: 1523984
Pushed by bhackett@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/6b6fd6d6d2f3
Part 1 - Allow simultaneous middleman calls from multiple child processes, r=lsmyth.
https://hg.mozilla.org/integration/mozilla-inbound/rev/ef8aa80bf429
Part 2 - Add support for virtual console logs to ReplayDebuggerScript, r=lsmyth.
https://hg.mozilla.org/integration/mozilla-inbound/rev/72597c6ab577
Part 3 - Devtools server/client support for virtual console logs, r=lsmyth.
Flags: needinfo?(bhackett1024)
Product: Core → Core Graveyard
You need to log in before you can comment on or make changes to this bug.