Bug 193730

Summary: Web Inspector: CPU Usage Timeline
Product: WebKit Reporter: Joseph Pecoraro <joepeck>
Component: Web InspectorAssignee: Nobody <webkit-unassigned>
Status: RESOLVED FIXED    
Severity: Normal CC: benjamin, commit-queue, ews-watchlist, hi, inspector-bugzilla-changes, joepeck, rniwa, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: All   
OS: All   
Attachments:
Description Flags
[IMAGE] CPU Timeline Overview Zoom 1
none
[IMAGE] CPU Timeline Overview Zoom 2
none
[IMAGE] CPU Timeline Overview Zoom 3
none
[IMAGE] CPU Timeline with selection range
none
[PATCH] Proposed Fix
hi: review+, ews-watchlist: commit-queue-
Archive of layout-test-results from ews107 for mac-highsierra-wk2
none
[PATCH] For Landing none

Description Joseph Pecoraro 2019-01-23 11:57:07 PST
Web Inspector: CPU Usage Timeline

In order to better understand energy impact of a page it would be nice to expose the CPU usage of the WebContentProcess. This will often tie back to script/layout/painting but often the CPU will do work for scrolling, mouse handling, and other handling. Start by showing the CPU usage and work on categorizing.
Comment 1 Joseph Pecoraro 2019-01-23 11:57:26 PST
<rdar://problem/46797201>
Comment 2 Joseph Pecoraro 2019-01-23 12:52:44 PST
Created attachment 359925 [details]
[IMAGE] CPU Timeline Overview Zoom 1
Comment 3 Joseph Pecoraro 2019-01-23 12:52:54 PST
Created attachment 359926 [details]
[IMAGE] CPU Timeline Overview Zoom 2
Comment 4 Joseph Pecoraro 2019-01-23 12:53:03 PST
Created attachment 359927 [details]
[IMAGE] CPU Timeline Overview Zoom 3
Comment 5 Joseph Pecoraro 2019-01-23 12:53:18 PST
Created attachment 359928 [details]
[IMAGE] CPU Timeline with selection range
Comment 6 Joseph Pecoraro 2019-01-23 12:53:42 PST
Created attachment 359929 [details]
[PATCH] Proposed Fix
Comment 7 EWS Watchlist 2019-01-23 12:57:04 PST
Attachment 359929 [details] did not pass style-queue:


ERROR: Source/WebCore/page/ResourceUsageThread.h:57:  Extra space before ( in function call  [whitespace/parens] [4]
ERROR: Source/WebCore/page/ResourceUsageThread.h:79:  Extra space before ( in function call  [whitespace/parens] [4]
ERROR: Source/WebCore/page/ResourceUsageThread.cpp:49:  Extra space before ( in function call  [whitespace/parens] [4]
ERROR: Source/WebCore/page/ResourceUsageThread.cpp:88:  Extra space before ( in function call  [whitespace/parens] [4]
Total errors found: 4 in 59 files


If any of these errors are false positives, please file a bug against check-webkit-style.
Comment 8 Joseph Pecoraro 2019-01-23 13:21:18 PST
Comment on attachment 359929 [details]
[PATCH] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=359929&action=review

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:119
> +        let intervalWidth = (samplingRatePerSecond / secondsPerPixel);
> +        const minimumDisplayHeight = 2;
> +
> +        // Bars for each record.
> +        for (let record of visibleRecords) {
> +            let w = intervalWidth;
> +            let h = Math.max(minimumDisplayHeight, yScale(record.usage));
> +            let x = xScale(record.startTime - (samplingRatePerSecond / 2));
> +            let y = height - h;
> +            this._chart.addBar(x, y, w, h);
> +        }

Currently this sizes bars at 500ms wide, where the center of the bar is the time of the sample. Devin has pointed out that we may want the end of the bar to be the time of the sample, so that if developers select the range of the bar they will see all of the activity leading up to the sample and not some activity that may have happened after the sample. I think that is valid, but at the low sample rate, I'm not sure it matters as much. I think we will want to end up with finer grained categorization (something at a 1ms interval), and if we get in the detail view then the placement of the samples is not as important.
Comment 9 Devin Rousso 2019-01-23 13:57:14 PST
Comment on attachment 359929 [details]
[PATCH] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=359929&action=review

r=me, awesome work!  I love the colors.

I figured out towards the end that you'd used most of the Memory code to create this (since they're pretty similar), but I think we can take a little time to clean it up a bit, so I'm leaving my NITs.

> LayoutTests/inspector/cpu-profiler/tracking.html:8
> +    let suite = ProtocolTest.createAsyncSuite("CPUProfiler.startTracking and CPUProfiler.stopTracking");

NIT: I like to have the suite name closely match the path to the test itself:

    let suite = ProtocolTest.createAsyncSuite("CPUProfiler.Tracking");
    ...
    suite.addTestCase({
        name: "CPUProfiler.Tracking.Event",
        ...
    });

> Source/JavaScriptCore/inspector/protocol/CPUProfiler.json:8
> +            "id": "Event",

This id seems very "generic".  Is there a reason to have this be a special type rather than just inline the two values?  Considering that neither of them is optional, it seems like it would be easier/simpler to just have them as direct parameters of "trackingUpdate".

Alternatively, maybe just a better name other than "Event" would be good.  How about "TimelineRecord" or just "Record"?

> Source/JavaScriptCore/inspector/protocol/CPUProfiler.json:28
> +            "name": "trackingStart",

NIT: "trackingStarted", since this event is fired after tracking has started.

> Source/JavaScriptCore/inspector/protocol/CPUProfiler.json:42
> +            "name": "trackingComplete",

NIT: "trackingStopped" to better match the corresponding command "stopTracking".

> Source/WebCore/inspector/agents/InspectorCPUProfilerAgent.cpp:59
> +    if (m_tracking)

NIT: this would be a good place to use `errorString`, like "Already started tracking".

> Source/WebCore/inspector/agents/InspectorCPUProfilerAgent.cpp:73
> +    if (!m_tracking)

NIT: this would be a good place to use `errorString`, like "Already stopped tracking".

> Source/WebInspectorUI/UserInterface/Images/CPUInstrument.svg:2
> +<!-- Copyright © 2016 Apple Inc. All rights reserved. -->

2019?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.css:27
> +body .sidebar > .panel.navigation.timeline > .timelines-content li.item.cpu,
> +body .timeline-overview > .graphs-container > .timeline-overview-graph.cpu {

Is the `body` part of the selector necessary?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.css:46
> +    right: 0;

NIT: although this value is 0, I think our preferred style is to still use a variable.

    --cpu-timeline-overview-graph-legend-offset-end: 0;

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:34
> +        console.assert(timeline instanceof WI.Timeline);

NIT: I normally put assertions for parameters above the `super` call, so that they appear before any other assertions (e.g. from super classes).
NIT: is it worth asserting that the type of the timeline is as expected?

    console.assert(timeline.type === WI.TimelineRecord.Type.CPU);

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:37
> +        this._cpuTimeline.addEventListener(WI.Timeline.Event.RecordAdded, this._cpuTimelineRecordAdded, this);

NIT: I like to prefix event handlers with `_handle...` so it's immediately clear as to how the function is expected to be used.

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:39
> +        let size = new WI.Size(0, this.height);

0 width?  Does this mean we show nothing if "CPU" is selected and we have yet to start a recording?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:51
> +    get height()

I don't really like this name, as it implies that the height of the entire "overview graph" is 72, which isn't necessarily true.  Could you save `size` to a member variable, and just update it as needed?

    this._size = new WI.Size(0, 72);
    ...
    this._size.width = ...

Or (to re-use what you do later), just use the size from the chart itself.

    this._chart.size = new WI.Size(..., this._chart.size.height);

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:88
> +        // 500ms. This matches the ResourceUsageThread sampling frequency in the backend.

Should we add a comment inside `WebCore::ResourceUsageThread` that the `500_ms` should stay in sync with this value?  Are we ever expecting that value to change?  If so, should we care about dealing with differing values between the frontend/backend (e.g. backend changes to poll at 250_ms, and the frontend expects 500_ms)?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:101
> +        let visibleRecords = this._cpuTimeline.recordsInTimeRange(graphStartTime, visibleEndTime + (samplingRatePerSecond / 2), true);

NIT: replace `true` with `includeRecordBeforeStart`.

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:128
> +        if (this._cachedMaxUsage === this._maxUsage)

Is this purely to avoid re-drawing the legend if the value hasn't changed?  It seems like `this._cachedMaxUsage` isn't used otherwise.

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.css:36
> +    font-family: '-webkit-system-font';

NIT: are the quotes necessary?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.js:35
> +        console.assert(timeline.type === WI.TimelineRecord.Type.CPU, timeline);

Ditto (>CPUTimelineOverviewGraph.js:34).

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.js:42
> +        // FIXME: Overview with charts.

Are you referring to pie-charts, like the Memory timeline?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.js:58
> +        timeline.addEventListener(WI.Timeline.Event.RecordAdded, this._cpuTimelineRecordAdded, this);

Ditto (>CPUTimelineOverviewGraph.js:37).

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.js:73
> +    hidden()
> +    {
> +        super.hidden();
> +    }

Remove?

> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.js:142
> +            if (discontinuity) {

This can be merged with the `if` above, as well as moving `discontinuity` to be inside that `if`.

> Source/WebInspectorUI/UserInterface/Views/CPUUsageView.css:34
> +    font-family: '-webkit-system-font';

Ditto (>CPUTimelineView.css:36).

> Source/WebInspectorUI/UserInterface/Views/CPUUsageView.css:36
> +    color: hsl(0, 0%, 70%);

How does this look in dark mode?

> Source/WebInspectorUI/UserInterface/Views/CPUUsageView.css:38
> +    --cpu-usage-view-details-padding-start: 15px;

You can simplify this with `-webkit-padding-start`.

> Source/WebInspectorUI/UserInterface/Views/CPUUsageView.js:26
> +WI.CPUUsageView = class CPUUsageView extends WI.Object

Does this need `WI.Object`?

> Source/WebInspectorUI/UserInterface/Views/ColumnChart.js:62
> +    get bars() { return this._bars; }

NIT: this is never used.

> Source/WebInspectorUI/UserInterface/Views/ColumnChart.js:106
> +            let g = this._svgElement.appendChild(createSVGElement("g"));

Can you apply the `transform` (or just use `x` and `y` attributes) directly to the rect, rather than create another element?
Comment 10 Devin Rousso 2019-01-23 13:59:07 PST
Comment on attachment 359929 [details]
[PATCH] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=359929&action=review

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:119
>> +        }
> 
> Currently this sizes bars at 500ms wide, where the center of the bar is the time of the sample. Devin has pointed out that we may want the end of the bar to be the time of the sample, so that if developers select the range of the bar they will see all of the activity leading up to the sample and not some activity that may have happened after the sample. I think that is valid, but at the low sample rate, I'm not sure it matters as much. I think we will want to end up with finer grained categorization (something at a 1ms interval), and if we get in the detail view then the placement of the samples is not as important.

I would agree that if we have more often sampling, this matters less, but a lot can happen in 500ms, so at larger samples it may make all the difference.  I think the tradeoff point would be somewhere around 16ms (e.g. a single frame) as we can already do some "guess logic" per-frame using the rendering frames view, but anything above that and the record bar "correctness" or "accuracy" matters much more.
Comment 11 Benjamin Poulain 2019-01-23 14:54:08 PST
First, thanks for creating the new track. That is kick ass.

Second, some popular sites really suck :(

Some ideas:
-Would it be possible to click on one of the rect to select exactly that zone? That way one can pick the highest rect, and see everything that happened (layout, js, etc).
-The main view when clicking on the track looks a bit small on iMac where the display is very large. Maybe it should resize with the window?
-There is some space below the graph, we could eventually add more information (# timers, etc). What do you think?
-I get artifacts from time to time. See radar.
Comment 12 Benjamin Poulain 2019-01-23 14:58:50 PST
Ah, found a bug:
Record -> Select an area in the timeline -> Clear the timeline

-> The graph is cleared but the numbers for Average / Highest / Lowest remain.
Comment 13 EWS Watchlist 2019-01-23 15:15:57 PST
Comment on attachment 359929 [details]
[PATCH] Proposed Fix

Attachment 359929 [details] did not pass mac-wk2-ews (mac-wk2):
Output: https://webkit-queues.webkit.org/results/10863584

New failing tests:
imported/w3c/web-platform-tests/css/css-grid/abspos/orthogonal-positioned-grid-descendants-010.html
Comment 14 EWS Watchlist 2019-01-23 15:15:59 PST
Created attachment 359949 [details]
Archive of layout-test-results from ews107 for mac-highsierra-wk2

The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews.
Bot: ews107  Port: mac-highsierra-wk2  Platform: Mac OS X 10.13.6
Comment 15 Joseph Pecoraro 2019-01-24 15:48:30 PST
Comment on attachment 359929 [details]
[PATCH] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=359929&action=review

>> Source/JavaScriptCore/inspector/protocol/CPUProfiler.json:8
>> +            "id": "Event",
> 
> This id seems very "generic".  Is there a reason to have this be a special type rather than just inline the two values?  Considering that neither of them is optional, it seems like it would be easier/simpler to just have them as direct parameters of "trackingUpdate".
> 
> Alternatively, maybe just a better name other than "Event" would be good.  How about "TimelineRecord" or just "Record"?

It is intended to be generic. This is the same pattern as the Memory and ScriptProfiler domains (two others that follow the trackingStart, trackingUpdate, trackingComplete pattern).

>> Source/JavaScriptCore/inspector/protocol/CPUProfiler.json:42
>> +            "name": "trackingComplete",
> 
> NIT: "trackingStopped" to better match the corresponding command "stopTracking".

These names match the existing patterning other domains.

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:39
>> +        let size = new WI.Size(0, this.height);
> 
> 0 width?  Does this mean we show nothing if "CPU" is selected and we have yet to start a recording?

Yes, but the size is always updated in layout.

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:51
>> +    get height()
> 
> I don't really like this name, as it implies that the height of the entire "overview graph" is 72, which isn't necessarily true.  Could you save `size` to a member variable, and just update it as needed?
> 
>     this._size = new WI.Size(0, 72);
>     ...
>     this._size.width = ...
> 
> Or (to re-use what you do later), just use the size from the chart itself.
> 
>     this._chart.size = new WI.Size(..., this._chart.size.height);

This *is* the height of the entire TimelineOverviewGraph. This is overriding the default value in the parent which uses it for that purpose.

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:88
>> +        // 500ms. This matches the ResourceUsageThread sampling frequency in the backend.
> 
> Should we add a comment inside `WebCore::ResourceUsageThread` that the `500_ms` should stay in sync with this value?  Are we ever expecting that value to change?  If so, should we care about dealing with differing values between the frontend/backend (e.g. backend changes to poll at 250_ms, and the frontend expects 500_ms)?

Good idea.

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineOverviewGraph.js:128
>> +        if (this._cachedMaxUsage === this._maxUsage)
> 
> Is this purely to avoid re-drawing the legend if the value hasn't changed?  It seems like `this._cachedMaxUsage` isn't used otherwise.

Yes. The cost of resetting the value to the same thing was a measurable perf issue in Timelines in the past.

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.css:36
>> +    font-family: '-webkit-system-font';
> 
> NIT: are the quotes necessary?

Good point, I changed all instances to:

    font-family: -webkit-system-font, sans-serif;

>> Source/WebInspectorUI/UserInterface/Views/CPUTimelineView.js:42
>> +        // FIXME: Overview with charts.
> 
> Are you referring to pie-charts, like the Memory timeline?

Yes, some overview charts with extra detail is the goal.

>> Source/WebInspectorUI/UserInterface/Views/CPUUsageView.css:36
>> +    color: hsl(0, 0%, 70%);
> 
> How does this look in dark mode?

We look good in dark mode! NVI has some gray color suggestions I'll change in a follow-up.

>> Source/WebInspectorUI/UserInterface/Views/CPUUsageView.js:26
>> +WI.CPUUsageView = class CPUUsageView extends WI.Object
> 
> Does this need `WI.Object`?

Nope!

>> Source/WebInspectorUI/UserInterface/Views/ColumnChart.js:62
>> +    get bars() { return this._bars; }
> 
> NIT: this is never used.

Yep, but adding this to match LineChart.

>> Source/WebInspectorUI/UserInterface/Views/ColumnChart.js:106
>> +            let g = this._svgElement.appendChild(createSVGElement("g"));
> 
> Can you apply the `transform` (or just use `x` and `y` attributes) directly to the rect, rather than create another element?

Yes! Eliminated the <g>!

> Source/WebInspectorUI/UserInterface/Views/Variables.css:120
> +    --cpu-stroke-color: hsl(167, 63%, 33%);
> +    --cpu-fill-color: hsl(118, 43%, 54%);

I tweaked these styles so that the stroke doesn't change the hue (this value was more blue then the fill color, the new value stays the same green hue and adjusts the other values).
Comment 16 Joseph Pecoraro 2019-01-24 15:51:02 PST
(In reply to Benjamin Poulain from comment #12)
> Ah, found a bug:
> Record -> Select an area in the timeline -> Clear the timeline
> 
> -> The graph is cleared but the numbers for Average / Highest / Lowest
> remain.

Fixed! This was also an issue for the Memory timeline category line graphs!
Comment 17 Joseph Pecoraro 2019-01-24 16:05:04 PST
(In reply to Benjamin Poulain from comment #11)
> First, thanks for creating the new track. That is kick ass.
> 
> Second, some popular sites really suck :(
> 
> Some ideas:
> -Would it be possible to click on one of the rect to select exactly that
> zone? That way one can pick the highest rect, and see everything that
> happened (layout, js, etc).

Implementing it should be easy, so I'll look into it.

This exact situation is something we're debating given the placement of the bars right now. So when approaching this we may want to move the bars.

Currently we place the bars around when the sample happened. In this case selection would include some time before the same and some time after the sample:

    -----
    |   |
    |   |
    | + |

Devin suggested has moving the entire bar preceding the sample timestamp. In this case selection would include only time before the sample (which is arguably what caused the CPU usage to spike that high).

    -----
    |   |
    |   |
    |   +

Do you have any thoughts about which approach might be better?

> -The main view when clicking on the track looks a bit small on iMac where
> the display is very large. Maybe it should resize with the window?

This sounds like:
<https://webkit.org/b/153758> Web Inspector: Memory / CPU Timeline Views should be responsive / resizable

> -There is some space below the graph, we could eventually add more
> information (# timers, etc). What do you think?

Yep. Feel free to throw suggestions my way. I definitely want to add more content to the main view.

> -I get artifacts from time to time. See radar.

Will look.
Comment 18 Joseph Pecoraro 2019-01-24 16:09:56 PST
Created attachment 360044 [details]
[PATCH] For Landing
Comment 19 EWS Watchlist 2019-01-24 16:12:03 PST
Attachment 360044 [details] did not pass style-queue:


ERROR: Source/WebCore/page/ResourceUsageThread.h:57:  Extra space before ( in function call  [whitespace/parens] [4]
ERROR: Source/WebCore/page/ResourceUsageThread.h:79:  Extra space before ( in function call  [whitespace/parens] [4]
ERROR: Source/WebCore/page/ResourceUsageThread.cpp:49:  Extra space before ( in function call  [whitespace/parens] [4]
ERROR: Source/WebCore/page/ResourceUsageThread.cpp:88:  Extra space before ( in function call  [whitespace/parens] [4]
Total errors found: 4 in 70 files


If any of these errors are false positives, please file a bug against check-webkit-style.
Comment 20 WebKit Commit Bot 2019-01-24 17:06:24 PST
Comment on attachment 360044 [details]
[PATCH] For Landing

Clearing flags on attachment: 360044

Committed r240457: <https://trac.webkit.org/changeset/240457>