DevTools/OperationInstrument

'Operation Instrument' is a project that aims to add tracing instrumentation to Gecko and provide a holistic view of where time is being spent and why.

Examples of traced operations include:

• Style Recalculation
• Layout
• Painting
• JavaScript run-to-completion
• HTML parsing
• Etc...

The traced operations are displayed in the DevTools Performance tool's timeline.

This is a meta bug for tracking instrumentation: (operation-instrument) [meta Instrument Gecko w/ moar timeline markers]

Tutorial: Instrumenting Gecko: Adding New Markers

The Firefox performance tool breaks Gecko operations into labeled chunks of time, displayed as a waterfall (reflows, painting, restyle, JS run-to-completion, parse HTML, ...). Each of these chunks is registered with a pair of markers. A marker for when the operation starts, and a marker for when the operations end. To add a new type of marker, instrumentation is required at the Gecko platform level, and some minimal configuration on the devtools frontend side.

This is a good example bug, to see what adding new instrumentation is like: Bug 1151703 - Add profiler timeline markers for HTML/XML parsing

1. Adding the Instrumentation to Gecko

The easiest way to trace Gecko events/tasks with start and end timeline markers is to use the mozilla::AutoTimelineMarker RAII class. It automatically adds the start marker on construction, and adds the end marker on destruction. Don't worry too much about potential performance impact! It only actually adds the markers when the given docshell is being recorded.

--- a/dom/base/nsContentUtils.cpp
+++ b/dom/base/nsContentUtils.cpp
@@ -4241,16 +4242,18 @@
 nsresult
 nsContentUtils::ParseFragmentHTML(const nsAString& aSourceBuffer,
                                   nsIContent* aTargetNode,
                                   nsIAtom* aContextLocalName,
                                   int32_t aContextNamespace,
                                   bool aQuirks,
                                   bool aPreventScriptExecution)
 {
+  AutoTimelineMarker marker(aTargetNode->OwnerDoc()->GetDocShell(), "Parse HTML");
+
   if (nsContentUtils::sFragmentParsingActive) {
     NS_NOTREACHED("Re-entrant fragment parsing attempted.");
     return NS_ERROR_DOM_INVALID_STATE_ERR;
   }
   mozilla::AutoRestore<bool> guard(nsContentUtils::sFragmentParsingActive);
   nsContentUtils::sFragmentParsingActive = true;
   if (!sHTMLFragmentParser) {
     NS_ADDREF(sHTMLFragmentParser = new nsHtml5StringParser());

Under the hood, AutoTimelineMarker is using the TimelineMarker class is defined in docshell/base/TimelineMarker.h. A timestamp and the current JS stack (if any) is recorded when the marker is instantiated. It's also possible to attach arbitrary metadata to a marker by subclassing TimelineMarker, which can then be displayed in the performance tool frontend. Markers are stored in the docshell being profiled. To store a marker, call nsDocShell->AddProfileTimelineMarker(). See docshell/base/nsDocShell.h. Markers are popped out from the docshell at regular interval via nsIDocShell.popProfileTimelineMarkers() by devtools code (timeline actor). See docshell/base/nsIDocShell.idl and toolkit/devtools/server/actors/timeline.js.

For now, only the main thread is instrumented.

2. Telling the DevTools Frontend About the New Markers

To get your new markers displayed in the performance tool's UI, edit the config data in browser/devtools/shared/timeline/global.js. To add new support for new markers in the UI, updating this file is enough.

https://developer.mozilla.org/en-US/docs/Tools/DevToolsColors#Highlight_Colors

See Part 2 in the example bug above.

--- a/browser/devtools/shared/timeline/global.js
+++ b/browser/devtools/shared/timeline/global.js
@@ -48,16 +48,26 @@ const TIMELINE_BLUEPRINT = {
     colorName: "highlight-lightorange",
     label: L10N.getStr("timeline.label.domevent")
   },
   "Javascript": {
     group: 1,
     colorName: "highlight-lightorange",
     label: L10N.getStr("timeline.label.javascript2")
   },
+  "Parse HTML": {
+    group: 1,
+    colorName: "highlight-purple",
+    label: L10N.getStr("timeline.label.parseHTML")
+  },
   "ConsoleTime": {
     group: 2,
     colorName: "highlight-bluegrey",
     label: L10N.getStr("timeline.label.consoleTime")
   },
 };
--- a/browser/locales/en-US/chrome/browser/devtools/timeline.properties
+++ b/browser/locales/en-US/chrome/browser/devtools/timeline.properties
@@ -35,16 +35,18 @@ timeline.records=RECORDS
 
 # LOCALIZATION NOTE (timeline.label.*):
 # These strings are displayed in the timeline waterfall, identifying markers.
 # We want to use the same wording as Google Chrome
 timeline.label.styles2=Recalculate Style
 timeline.label.reflow2=Layout
 timeline.label.paint=Paint
 timeline.label.javascript2=Function Call
+timeline.label.parseHTML=Parse HTML
 timeline.label.domevent=DOM Event
 timeline.label.consoleTime=Console
 
 # LOCALIZATION NOTE (graphs.memory):
 # This string is displayed in the memory graph of the Performance tool,
 # as the unit used to memory consumption. This label should be kept
 # AS SHORT AS POSSIBLE so it doesn't obstruct important parts of the graph.
 graphs.memory=MB

For displaying new markers, that is enough. To display a marker's custom metadata - if any (displayed when the marker is selected in the waterfall) add a rendering function in browser/devtools/timeline/widgets/marker-details.js.

Recording markers in a different thread

For now, it's not supported. Only operations in main thread are instrumented.

Notes from Tom:

First, right now when a marker object is created, it acquires the time from the docshell. In docshell/base/TimelineMarker.cpp:

   TimelineMarker::TimelineMarker(nsDocShell* aDocShell, const char* aName,
                                  TracingMetadata aMetaData)
   [...]
     aDocShell->Now(&mTime);

Now, I think nsDocShell::Now is actually thread-safe. However, I would probably move the logic into TimelineMarker itself and avoid the need to have a docshell at TimelineMarker creation. The code was written this way mostly for historical reasons, but also perhaps to make sure that the timeline epoch is dealt with in a single place.

At this point you could make a new TimelineMarker object on any thread.

So then the next step is to ship it to the main thread. Basically I'd make a new nsIRunnable that holds the TimelineMarker object, and use NS_DispatchToMainThread. This runnable would call nsDocShell::AddProfileTimelineMarker when it ran.

This last step is the trickiest -- you have to pick which docshell to notify. I don't know of a generic way to do this; it's been the trickiest part of the patches I worked on. (Note from Paul: depending on the type of thread, we might register these markers at the global level. For example, it doesn't make sense to attach markers from the compositor thread to a docshell. It's not the case to network threads though).

Because we add the start and stop-markers to the docshell separately, it's simple to add a start marker from one thread and an end marker from another thread; or whatever you like.