Bug 190641

Summary: Web Inspector: display low-power enter/exit events in Timelines and Network node waterfalls
Product: WebKit Reporter: Devin Rousso <hi>
Component: Web InspectorAssignee: Devin Rousso <hi>
Status: RESOLVED FIXED    
Severity: Normal CC: bburg, commit-queue, ews-watchlist, hi, inspector-bugzilla-changes, joepeck, keith_miller, mark.lam, msaboff, saam, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: All   
OS: All   
Bug Depends on: 189874    
Bug Blocks: 191625    
Attachments:
Description Flags
[Patch] WIP
hi: commit-queue-
[Patch] WIP
none
[Patch] WIP
none
Patch
none
[Image] After Patch is applied
none
Patch none

Devin Rousso
Reported 2018-10-16 14:40:05 PDT
It is often useful to know when a media element entered or existed low-power mode, especially if you can relate that event to nearby timeline/network activity.
Attachments
[Patch] WIP (11.40 KB, patch)
2018-10-16 14:41 PDT, Devin Rousso
hi: commit-queue-
[Patch] WIP (11.61 KB, patch)
2018-10-19 12:29 PDT, Devin Rousso
no flags
[Patch] WIP (27.98 KB, patch)
2018-10-31 00:42 PDT, Devin Rousso
no flags
Patch (29.94 KB, patch)
2018-10-31 16:24 PDT, Devin Rousso
no flags
[Image] After Patch is applied (1.05 MB, image/png)
2018-10-31 16:24 PDT, Devin Rousso
no flags
Patch (30.13 KB, patch)
2018-10-31 18:15 PDT, Devin Rousso
no flags
Devin Rousso
Comment 1 2018-10-16 14:41:18 PDT
Created attachment 352507 [details] [Patch] WIP
Radar WebKit Bug Importer
Comment 2 2018-10-16 14:41:56 PDT
Devin Rousso
Comment 3 2018-10-19 12:29:09 PDT
Created attachment 352815 [details] [Patch] WIP Minor changes to timing logic
Joseph Pecoraro
Comment 4 2018-10-29 17:19:22 PDT
Comment on attachment 352815 [details] [Patch] WIP View in context: https://bugs.webkit.org/attachment.cgi?id=352815&action=review This is a WIP, but I'm going to r- because I want to remember to see an updated version of the patch and, if possible, we should try to have some kind of test. > Source/JavaScriptCore/inspector/protocol/DOM.json:677 > + { "name": "timestamp", "$ref": "Network.Timestamp", "description": "Time when the <video> entered/exited low power mode" }, Should we include a walltime as well? If we ever wanted the UI to display a wall time (perhaps in the Detail View) I think we'd want to do this. Maybe "<video>" => "video element" in these comments. Since we seem to assume `<code>` in other description comments. I mention this because we have <code> inline comments in other protocol description strings. But I'd rather you keep your comment and we eliminate / phase out the <code> since we aren't actually displaying the description comments anywhere and if we did we'd probably do something better. > Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:336 > + m_mediaMetrics.clear(); We should also stop the timer if it is running. m_mediaMetricsTimer.stop(); > Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:2443 > + for (auto* mediaElement : HTMLMediaElement::allMediaElements()) { Because we don't remove elements from m_mediaMetrics (until reset()) it's possible that this code would make a mistake if an HTMLMediaElement gets created, gets metrics, gets destroyed, and then a HTMLMediaElement gets created at the same address. In that case the old element's m_mediaMetrics will be compared to the new element's value. That is not as unlikely as it sounds, but would be quite rare. Given this loop iterates all of the existing media elements, we should consider removing HTMLMediaElements from m_mediaMetrics if they didn't show up in HTMLMediaElement::allMediaElements(). Probably something like: m_mediaMetrics.removeIf([&] (auto& entry) { return !HTMLMediaElement::allMediaElements().contains(entry.key); }); That would reduce the possibility of this being a bug down to a single frame which I think is better, and avoids the possibility of unbounded growth in `m_mediaMetrics`. Unless there really is a good opportunity to immediately remove media elements from m_mediaMetrics, I think this is pretty good. > Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:2467 > + auto renderedFrameCount = totalVideoFrames - iterator->value.totalFrames; > + if (renderedFrameCount <= 0) Since these are both `unsigned` it seems the difference would probably also be `unsigned` and so I don't think this could ever be less than zero. I'd rather use explicit types, instead of `auto`, so that this would be more obvious. > Source/WebCore/inspector/agents/InspectorDOMAgent.h:304 > + HashMap<HTMLMediaElement*, MediaMetrics> m_mediaMetrics; There should probably be a comment that we shouldn't use the pointer in this map, it is only used for matching. It could even be a `void*` if that makes it a little more clear that we shouldn't use it. > Source/WebInspectorUI/UserInterface/Controllers/DOMManager.js:141 > + if (!node)dispatchEventToListenersreturn; Heh, this is broken. Looks like it should just be a return. > Source/WebInspectorUI/UserInterface/Views/NetworkTableContentView.css:185 > + /* 1/3 of the vertical space above any .dom-event node */ > + --low-power-vertical-padding: calc((50% - (var(--node-waterfall-dom-event-size) / 3)) / 2); Do you have a screenshot of what this looks like?
Devin Rousso
Comment 5 2018-10-31 00:13:49 PDT
Comment on attachment 352815 [details] [Patch] WIP View in context: https://bugs.webkit.org/attachment.cgi?id=352815&action=review >> Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:336 >> + m_mediaMetrics.clear(); > > We should also stop the timer if it is running. > > m_mediaMetricsTimer.stop(); I actually don't want to do that here. The reason for this is because `reset` is also called in `setDocument` and `getDocument`, meaning that the timer would be stopped there for "no reason". The timer is only started when we call `addEventListenersToNode`, which happens either when a <video> is created or when the Inspector is first opened. As such, we should keep it running until the next time we call `addEventListenersToNode`. My solution to this was to make it so that when the timer fires, if there are no media elements, stop the timer and clear the saved metrics data. This could be partially fixed by <https://webkit.org/b/189687>, such that when a node is destroyed, if it's a media element, remove it from this list. I'll add a FIXME. >> Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:2443 >> + for (auto* mediaElement : HTMLMediaElement::allMediaElements()) { > > Because we don't remove elements from m_mediaMetrics (until reset()) it's possible that this code would make a mistake if an HTMLMediaElement gets created, gets metrics, gets destroyed, and then a HTMLMediaElement gets created at the same address. In that case the old element's m_mediaMetrics will be compared to the new element's value. That is not as unlikely as it sounds, but would be quite rare. > > Given this loop iterates all of the existing media elements, we should consider removing HTMLMediaElements from m_mediaMetrics if they didn't show up in HTMLMediaElement::allMediaElements(). > > Probably something like: > > m_mediaMetrics.removeIf([&] (auto& entry) { > return !HTMLMediaElement::allMediaElements().contains(entry.key); > }); > > That would reduce the possibility of this being a bug down to a single frame which I think is better, and avoids the possibility of unbounded growth in `m_mediaMetrics`. Unless there really is a good opportunity to immediately remove media elements from m_mediaMetrics, I think this is pretty good. Good idea. See above comment (336) for another (additional) solution (in the future).
Devin Rousso
Comment 6 2018-10-31 00:42:48 PDT
Created attachment 353470 [details] [Patch] WIP
EWS Watchlist
Comment 7 2018-10-31 00:46:31 PDT
This patch modifies the inspector protocol. Please ensure that any frontend changes appropriately use feature checks for new protocol features.
Devin Rousso
Comment 8 2018-10-31 16:24:28 PDT
Created attachment 353549 [details] Patch Not sure how to test this, as there's no way to "force" low power mode :/
Devin Rousso
Comment 9 2018-10-31 16:24:46 PDT
Created attachment 353550 [details] [Image] After Patch is applied
Joseph Pecoraro
Comment 10 2018-10-31 16:42:19 PDT
Comment on attachment 353549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=353549&action=review r=me > Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.css:82 > + background-color: var(--value-changed-highlight); Should we give this another variable name? Might be weird if we rely on this being green and we suddenly change the value-changed-highlight color and this suddenly ends up not being green. How did this look in Dark mode? I suspect pretty good! > Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:84 > + if (this.layoutReason !== WI.View.LayoutReason.Dirty) > + return; It isn't obvious to me why we are bailing here. > Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:134 > + if (fullscreenRange.originator) > + fullscreenArea.title = WI.UIString("Fullscreen from â%sâ").format(fullscreenRange.originator.displayName); I think we want to avoid unicode characters in our source code. I believe having non-ASCII characters requires JavaScriptCore use a non-8-bit-string for the source code and parsing. And since this is almost all combined into a single Main.js I think that means a single file treated as UTF-16 instead of ASCII. Obviously this isn't the first place we've used non-ASCII but we may want to try eliminating it and seeing if there is a measurable performance win. I'd think in memory alone we should see some savings.
Blaze Burg
Comment 11 2018-10-31 16:53:09 PDT
Comment on attachment 353549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=353549&action=review r=me with questions > Source/JavaScriptCore/inspector/protocol/DOM.json:675 > + "description": "Called when a video element enters/exits low power mode.", Called->Emitted > Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:2480 > + bool isLowPower = (displayCompositedVideoFrames - iterator->value.displayCompositedFrames) > 0; Will this misreport if the JS debugger has paused the page? What if the video is paused? It seems a little weird to me that this will run indefinitely and doesn't throttle based on page state in some way. One simple workaround may be to ignore the metrics if the total frames count has not changed since the last polling. > Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:40 > + this._domEvents = domNodeOrEvents; These members are not initialized in the then-branch. Why not? > Source/WebInspectorUI/UserInterface/Views/NetworkTableContentView.js:1614 > + this._waterfallEndTime = timestamp + (this._waterfallTimelineRuler.secondsPerPixel * 10); Seems kind of weird.. isn't there a generic method to update the current min/max range based on timestamp?
Devin Rousso
Comment 12 2018-10-31 17:57:21 PDT
Comment on attachment 353549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=353549&action=review >> Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:2480 >> + bool isLowPower = (displayCompositedVideoFrames - iterator->value.displayCompositedFrames) > 0; > > Will this misreport if the JS debugger has paused the page? What if the video is paused? It seems a little weird to me that this will run indefinitely and doesn't throttle based on page state in some way. > > One simple workaround may be to ignore the metrics if the total frames count has not changed since the last polling. <rdar://45349499> >> Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:40 >> + this._domEvents = domNodeOrEvents; > > These members are not initialized in the then-branch. Why not? The events are pulled from `this._domNode`. I should initialize the other values to `null` though. >> Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:84 >> + return; > > It isn't obvious to me why we are bailing here. This prevents us from redrawing the entire table on `Resize` layouts, since there's no reason to do that. >> Source/WebInspectorUI/UserInterface/Views/NetworkTableContentView.js:1614 >> + this._waterfallEndTime = timestamp + (this._waterfallTimelineRuler.secondsPerPixel * 10); > > Seems kind of weird.. isn't there a generic method to update the current min/max range based on timestamp? This is what's done in a bunch of the other event handler functions.
Devin Rousso
Comment 13 2018-10-31 17:57:21 PDT
Comment on attachment 353549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=353549&action=review >> Source/WebCore/inspector/agents/InspectorDOMAgent.cpp:2480 >> + bool isLowPower = (displayCompositedVideoFrames - iterator->value.displayCompositedFrames) > 0; > > Will this misreport if the JS debugger has paused the page? What if the video is paused? It seems a little weird to me that this will run indefinitely and doesn't throttle based on page state in some way. > > One simple workaround may be to ignore the metrics if the total frames count has not changed since the last polling. <rdar://45349499> >> Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:40 >> + this._domEvents = domNodeOrEvents; > > These members are not initialized in the then-branch. Why not? The events are pulled from `this._domNode`. I should initialize the other values to `null` though. >> Source/WebInspectorUI/UserInterface/Views/DOMEventsBreakdownView.js:84 >> + return; > > It isn't obvious to me why we are bailing here. This prevents us from redrawing the entire table on `Resize` layouts, since there's no reason to do that. >> Source/WebInspectorUI/UserInterface/Views/NetworkTableContentView.js:1614 >> + this._waterfallEndTime = timestamp + (this._waterfallTimelineRuler.secondsPerPixel * 10); > > Seems kind of weird.. isn't there a generic method to update the current min/max range based on timestamp? This is what's done in a bunch of the other event handler functions.
Devin Rousso
Comment 14 2018-10-31 18:15:44 PDT
WebKit Commit Bot
Comment 15 2018-10-31 21:13:06 PDT
Comment on attachment 353566 [details] Patch Clearing flags on attachment: 353566 Committed r237669: <https://trac.webkit.org/changeset/237669>
WebKit Commit Bot
Comment 16 2018-10-31 21:13:08 PDT
All reviewed patches have been landed. Closing bug.
Note You need to log in before you can comment on or make changes to this bug.