Bug 25503 – Add instrumentation framework to WebCore

• Status: RESOLVED
• Resolution: FIXED
• Component: WebCore Misc.

[James Robinson]

I think it would be good to have a lightweight instrumentation framework in WebCore to keep tabs on things like the number of layouts and their duration.

[James Robinson]

Created attachment 29934 [details]
Implementation of instrumentation and simple aggregate in DRT

This is an example of instrumentation in layout, style recalculation, html parsing and painting.  There is also a fairly simplistic implementation of an aggregator in DumpRenderTree that will optionally spit out stats when running layout tests.

[Sam Weinig]

Some basic comments.  The names of the client methods don't really mesh well with our current idiom for client methods.  For instance, instead of "layoutStarting", we would use "didStartLayout".

How does this effect the performance of the various perf tests we run? 

[Simon Fraser (smfr)]

Some general feedback (I didn't read Sam's yet)

* I'm not sure I like the pairing of a specific start signal ("recalcStyleStarting") with a generic end signal ("finished"). Seems like it would be good to force pairing, even if just to assert that they are correctly paired.
* Rather than hard-coding all the categories in method names, why not make it extensible:

analysisClient()->start("parsing");
analysisClient()->end("parsing");

Then you just need a hash to store data in on the collection side.

* Why have WebAnalysisClient in WebKit? Seems like the mechanics of data collection and analysis will be the same for every platform, so should be in WebCore. Then what you export via WebKit is:
i) a way to turn it on and off
ii) a way to get at the raw data (e.g. for a UI visualizer) or summary data?
I think WebCore should also have code to dump the output. You could use a log channel for output, maybe.

[James Robinson]

Created attachment 30205 [details]
Addresses some comments and rebases against r43514

This patch addresses the naming issues with AnalysisClient and creates a separate didFoo() callback instead of the generic finished() callback.  This way an implementation only interested in a subset of the instrumentation points could support only the willFoo()/didFoo() pairs they cared about.

This patch also merges up to r43514 and fixes some whitespace/path issues from the original patch.  I'll address the other comments raised in the bug directly.

[James Robinson]

(In reply to comment #2)
> Some basic comments.  The names of the client methods don't really mesh well
> with our current idiom for client methods.  For instance, instead of
> "layoutStarting", we would use "didStartLayout".
> 
> How does this effect the performance of the various perf tests we run? 
> 

The performance of the instrumentation depends pretty much entirely on how much work is done by the AnalysisClient implementation.  In this case, since very little work is done by the DRT implementation there is no measurable performance impact as determined by running SunSpider, the layout tests in LayoutTests/fast, or a mozilla page cycler with some popular websites.  I don't have access to IBench.

[James Robinson]

(In reply to comment #3)
> Some general feedback (I didn't read Sam's yet)
> 
> * I'm not sure I like the pairing of a specific start signal
> ("recalcStyleStarting") with a generic end signal ("finished"). Seems like it
> would be good to force pairing, even if just to assert that they are correctly
> paired.
> * Rather than hard-coding all the categories in method names, why not make it
> extensible:
> 
> analysisClient()->start("parsing");
> analysisClient()->end("parsing");
> 
> Then you just need a hash to store data in on the collection side.

The advantage of having separate callbacks is that the instrumentation points can be easily parameterized to keep data around beyond simple start/end timestamps. For example, the paint instrumentation point could also have the size of the bounding box being painted.

> 
> * Why have WebAnalysisClient in WebKit? Seems like the mechanics of data
> collection and analysis will be the same for every platform, so should be in
> WebCore. Then what you export via WebKit is:
> i) a way to turn it on and off
> ii) a way to get at the raw data (e.g. for a UI visualizer) or summary data?
> I think WebCore should also have code to dump the output. You could use a log
> channel for output, maybe.
> 

The DRT aggregation is fairly simple and could potentially apply to all platforms, but it's more intended as an example of a use of this data and not the only one.   We've experimented with tools that keep entire trace trees around and found that the data is quite interesting but also very large and probably doesn't make sense to keep around in WebCore proper.  In the other extreme, the Android folks have experimented with instrumentation points that do nothing except log to one of their system logs to keep the observer effects down while understand perf regressions.  I think it makes sense to keep the instrumentation itself very generic for now and figure out exactly what sort of processing should be in WebCore vs the platform layer as times goes on.  Does that approach seem good to you?

[Oliver Hunt]

Comment on attachment 30205 [details]
Addresses some comments and rebases against r43514

I am not sure why these need to use client objects -- as this is primarily of value to developers it should be entirely inside webcore with appropriate bindings to the inspector.  Currently it sits in the inspector directory but the inspector does not use it at all.

I feel it's value in DRT is vastly less than in the inspector so there should be at least rudimentary information displayed in the inspector as part of this patch.

Also you're adding branches to some very hot code paths so i'd like to be sure that you've ensured that there isn't a performance regression in layout or rendering.

Given these issues i'm r-'ing this for now

[Kelly Norton]

Created attachment 38382 [details]
Similar instrumentation points, but this time it goes to an agent in InspectorController.

This path is a much delayed follow up to James' patches that addresses the first part of Oliver's objection. Are there runnable perf tests for determining the impact of some of the branches this adds?

Also note that this does not add any UI to inspector. This is something I discussed with Timonthy and Sam a little while back and I think they were ok with that. (I requested Timothy on the review).

I'm also kellegous on IRC if there are questions better handled in real-time.

[Timothy Hatcher]

Comment on attachment 38382 [details]
Similar instrumentation points, but this time it goes to an agent in InspectorController.


> +InspectorTimelineAgent* Document::inspectorTimelineAgent() const
> +{
> +    return page() ? page()->inspectorTimelineAgent() : 0;
> +}

Make these getters inline functions and it will be better. It would make the callers simplier to keep them.

> +    if (inspectorTimelineAgent())
> +        inspectorTimelineAgent()->willRecalculateStyle();

This should store the timeline agent into a local so the work isn't done twice when it is enabled. Same for the other callers.

> +void InspectorTimelineAgent::willDispatchDOMEvent(const Event& event)
> +{
> +    TimelineItem* newItem = newTimelineItem(DOMDispatchTimelineItemType);
> +    newItem->addDOMEventProperties(m_frontend, event);
> +}
> +
> +void InspectorTimelineAgent::didDispatchDOMEvent()
> +{
> +    didCompleteCurrentRecord();
> +}

I worry about didCompleteCurrentRecord() ending the wrong record. As long as all the recorded things are synchronous it is fine. We should ASSERT here that the current TimelineItem is the right type (DOMDispatchTimelineItemType in this case). And in all the other places didCompleteCurrentRecord() is called.

> +void InspectorTimelineAgent::TimelineItem::addItemProperties(double endTime)
> +{
> +    m_scriptObject.set("time", m_startTime);
> +    m_scriptObject.set("type", static_cast<int>(m_itemType));
> +    m_scriptObject.set("duration", endTime - m_startTime);
> +    if (m_childObjects.length())
> +        m_scriptObject.set("children", m_childObjects);
> +}
> +
> +void InspectorTimelineAgent::TimelineItem::addDOMEventProperties(InspectorFrontend* frontend, const Event& event)
> +{
> +    ScriptObject data = frontend->newScriptObject();
> +    data.set("type", event.type().string());
> +    m_scriptObject.set("data", data);
> +}

These should be normal data members, and more like ConsoleMessage when the ScriptObjects are created. Like what Pavel was saying on IRC.

> +        // Must be kept in sync with Timeline.js

This should say TimelineAgent.js.

[Kelly Norton]

Created attachment 38838 [details]
Addresses review suggestions and updates to r47896

[Timothy Hatcher]

Comment on attachment 38838 [details]
Addresses review suggestions and updates to r47896

Looks good! Some small nits. Will r+ when you fix these.

> +    InspectorTimelineAgent* timelineAgent = inspectorTimelineAgent();
> +    if (timelineAgent)
> +        timelineAgent->willRecalculateStyle();

You can combine these into 2 lines. Same comment for the rest of the palces like this.

    if (InspectorTimelineAgent* timelineAgent = inspectorTimelineAgent())
        timelineAgent->willRecalculateStyle();

> +    int i = 0;
> +    for (TimelineItems::const_iterator it(m_children.begin()); it != m_children.end(); ++it) {
> +        ScriptObject childObject = (*it)->convertToScriptObject(frontend);
> +        children.set(i++, childObject);
> +    }

Just use a normal for loop and a count and not iterators.

> +InspectorTimelineAgent* Page::inspectorTimelineAgent() const
> +{
> +    return m_inspectorController->timelineAgent();
> +}

You should inline this in the header.

[Kelly Norton]

Created attachment 39009 [details]
Fixes the remaining iterator nit.

[Pavel Feldman]

I think it will break the Windows WebKit build. Could you update vcproj file as well?

[Kelly Norton]

Created attachment 39093 [details]
Adds Windows build changes.

[Eric Seidel (no email)]

Comment on attachment 39093 [details]
Adds Windows build changes.

Rejecting patch 39093 from commit-queue.  This patch will require manual commit.

Patch https://bugs.webkit.org/attachment.cgi?id=39093 from bug 25503 failed to download and apply.

[Eric Seidel (no email)]

Several patch application failures, including the XCode project file.  the commit-queue can't land this unless someone updates it for tip of tree.

[Kelly Norton]

Created attachment 39191 [details]
Same patch updated to r48154.

[Eric Seidel (no email)]

Comment on attachment 39191 [details]
Same patch updated to r48154.

Based on Tim's previous r+, this still looks fine.  The bots are red atm so it will be a bit before the commit-queue wakes up and commits this.

[Eric Seidel (no email)]

Comment on attachment 39191 [details]
Same patch updated to r48154.

Clearing flags on attachment: 39191

Committed r48167: <http://trac.webkit.org/changeset/48167>

[Eric Seidel (no email)]

All reviewed patches have been landed.  Closing bug.

[Dimitri Glazkov (Google)]

Build fix landed as http://trac.webkit.org/changeset/48171.