Created attachment 247359 [details] frame rate timeline mockup It would be helpful to developers debugging rendering performance issues for the layout and rendering timeline to show a frame graph rather than a bar graph. Each frame should be divided horizontally into colored regions, indicating the time spent on different tasks: scripting (purple), layout/painting (red), other (gray).
<rdar://problem/19961762>
Created attachment 247457 [details] Quick demo to visualize run-loop executions in Timelines, alongside layout and rendering records.
Created attachment 247463 [details] Demo to visualize run-loop executions in the Layout and Rendering Timeline.
Created attachment 247485 [details] Semi-working WIP patch This fixes a bug in Matt's patch. We were not using CFRunLoopObserver correctly.
Created attachment 247486 [details] Picture with the patch This slows down really bad on graphic intense sites.
Created attachment 247728 [details] WIP with updated run loop observers Frame start based on kCFRunLoopBeforeTimers. Styles, Layout, and Paint events consistently fall with frame bounds.
Can you post a picture? I see a lot of interesting new code! You might have want to use my RunLoopObserver changes so there isn't Mac code in InspectorTimelineAgent.
Comment on attachment 247728 [details] WIP with updated run loop observers View in context: https://bugs.webkit.org/attachment.cgi?id=247728&action=review > Source/WebCore/inspector/InspectorTimelineAgent.cpp:146 > + m_frameStartObserver = CFRunLoopObserverCreateWithHandler(NULL, kCFRunLoopBeforeTimers, YES, 0, ^(CFRunLoopObserverRef observer, CFRunLoopActivity activity) > + { > + UNUSED_PARAM(observer); > + UNUSED_PARAM(activity); > + if (!m_enabled) > + return; > + > + ASSERT(!m_didStartRecordingRunLoop); > + pushCurrentRecord(InspectorObject::create(), TimelineRecordType::RunLoop, false, nullptr); > + m_didStartRecordingRunLoop = true; > + }); > + CFRunLoopAddObserver(CFRunLoopGetMain(), m_frameStartObserver, kCFRunLoopCommonModes); > + > + m_frameStopObserver = CFRunLoopObserverCreateWithHandler(NULL, kCFRunLoopBeforeWaiting | kCFRunLoopExit, YES, frameStopRunLoopOrder, ^(CFRunLoopObserverRef observer, CFRunLoopActivity activity) > + { > + UNUSED_PARAM(observer); > + UNUSED_PARAM(activity); > + if (!m_enabled || !m_didStartRecordingRunLoop) > + return; > + > + didCompleteCurrentRecord(TimelineRecordType::RunLoop); > + m_didStartRecordingRunLoop = false; > + }); > + CFRunLoopAddObserver(CFRunLoopGetMain(), m_frameStopObserver, kCFRunLoopCommonModes); This should go back to using platform/RunLoopObserver.cpp. We shouldn't add Mac code to this cross platform file. See my WIP for a way to extend WebCore::RunLoopObserver.
The bracketing looks good to me with the latest patch. Maybe split the backend and fronted changes?
Created attachment 248296 [details] Patch
Created attachment 248297 [details] Backend
Created attachment 248299 [details] Frontend
Created attachment 248300 [details] Backend
Comment on attachment 248300 [details] Backend View in context: https://bugs.webkit.org/attachment.cgi?id=248300&action=review Looks good. Lets get the changes we need into Platform/RunLoopObserver.cpp. > Source/WebCore/inspector/InspectorTimelineAgent.cpp:126 > + m_frameStartObserver = CFRunLoopObserverCreateWithHandler(NULL, kCFRunLoopBeforeTimers, YES, 0, ^(CFRunLoopObserverRef observer, CFRunLoopActivity activity) This needs to use platform abstractions. We can't put Mac code here.
Created attachment 248526 [details] Backend Updated to use RunLoopObserver.
Created attachment 248527 [details] Frontend All runloop records with children are now included, not just those with Layout events. Frames that exceed 16 ms are displayed with a 16 ms frame width, and shorter frames are as wide as their duration. Dropped frames appear following any frame that exceeded 16 ms. Frames are combined and averaged when their displayed size drops below a minimum threshold. A new CSS style class is added to combined frames containing one or more dropped frames, so that we can style this in the future.
Comment on attachment 248526 [details] Backend Nice an clean! Check out the build errors on EWS though.
Comment on attachment 248526 [details] Backend View in context: https://bugs.webkit.org/attachment.cgi?id=248526&action=review This would need a ChangeLog as well. > Source/WebCore/inspector/InspectorTimelineAgent.cpp:80 > +static const CFIndex frameStopRunLoopOrder = (CFIndex)RunLoopObserver::WellKnownRunLoopOrders::CoreAnimationCommit + 1; > + > +static CFRunLoopRef currentRunLoop() > +{ > +#if PLATFORM(IOS) > + // A race condition during WebView deallocation can lead to a crash if the layer sync run loop > + // observer is added to the main run loop <rdar://problem/9798550>. However, for responsiveness, > + // we still allow this, see <rdar://problem/7403328>. Since the race condition and subsequent > + // crash are especially troublesome for iBooks, we never allow the observer to be added to the > + // main run loop in iBooks. > + if (applicationIsIBooksOnIOS()) > + return WebThreadRunLoop(); > +#endif > + return CFRunLoopGetCurrent(); > +} These uses of CF must be behind PLATFORM(COCOA) or other ports will break. That said, it is unusual to have platform specific code and types inside WebCore/inspector. It would be nice if this was abstracted away. Otherwise, if platform specific code could show up all over the place and be difficult to maintain. Typically this is done by adding a WebCore/platform file with a null implementation for ports that haven't yet implemented it, and port specific implementations for those that do support it. For example, "Locale": ./text/LocaleNone.cpp ./text/LocaleICU.h ./text/mac/LocaleMac.h ./text/win/LocaleWin.h That said, maybe the abstraction doesn't need to be a RunLoopObserver, but just a > Source/WebCore/inspector/InspectorTimelineAgent.cpp:162 > + m_frameStartObserver = RunLoopObserver::create(0, [this]() { > + if (!m_enabled) > + return; > + > + ASSERT(!m_didStartRecordingRunLoop); > + pushCurrentRecord(InspectorObject::create(), TimelineRecordType::RunLoop, false, nullptr); > + m_didStartRecordingRunLoop = true; > + }); > + > + m_frameStopObserver = RunLoopObserver::create(frameStopRunLoopOrder, [this]() { > + if (!m_enabled || !m_didStartRecordingRunLoop) > + return; > + > + didCompleteCurrentRecord(TimelineRecordType::RunLoop); > + m_didStartRecordingRunLoop = false; > + }); Does this gracefully handle nested runloops (e.g. pausing in the Web Inspector)? I feel like currently this would assert as soon as you nest. - Entry - BeforeTimers => run your observer - BeforeSources => run JavaScript and trigger Pause, run Nested Run Loop - Entry - BeforeTimers => run your observer, I expect the first time it will ASSERT that !didStart, in a Release build it would open a RunLoop record - BeforeSources => run JavaScript... eventually unpause - BeforeWaiting => complete the last record - AfterWaiting - Exit - BeforeWaiting => bail, because !didStartRecording - AfterWaiting - Exit > Source/WebCore/inspector/InspectorTimelineAgent.cpp:165 > + m_frameStartObserver->schedule(currentRunLoop(), kCFRunLoopBeforeTimers); > + m_frameStopObserver->schedule(currentRunLoop()); Not having "kCFRunLoopBeforeWaiting | kCFRunLoopExit" at the call sight makes this really hard to follow. > Source/WebCore/inspector/InspectorTimelineAgent.cpp:191 > + m_frameStartObserver->invalidate(); > + m_frameStartObserver.reset(); > + m_frameStopObserver->invalidate(); > + m_frameStopObserver.reset(); I think we have been preferring "= nullptr" instead of ".reset()" with unique_ptr.
Comment on attachment 248527 [details] Frontend View in context: https://bugs.webkit.org/attachment.cgi?id=248527&action=review Not a full review. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:226 > + return; This should probably return null instead of just undefined. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:230 > + var childRecord = processRecord.call(this, childRecordPayload, recordPayload); Maybe processRecord should be promoted to a member function instead of this inline function. I don't think it has closure information. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:231 > + if (!childRecord) I have a feeling null is not expected. Lets console.assert(), and knowing the childRecordPayload would prove useful in debugging this. Otherwise we silently drop records. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:238 > + if (children.length) > + return new WebInspector.RunLoopTimelineRecord(startTime, endTime, children); > This unexpectedly falls through if !children.length. Maybe return a new RunLoopTimelineRecord regardless of whether or not the children list is empty or not. Not to mention, RunLoopTimelineRecord's constructor defaults to an empty list of children so it must be fine. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:321 > + console.log("RequestAnimationFrame", startTime, endTime) Debugging. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:336 > + function processEvent(recordPayload, parentRecordPayload) Likewise this could be a member function. > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:343 > + var startTime = this.activeRecording.computeElapsedTime(recordPayload.startTime); > + var endTime = this.activeRecording.computeElapsedTime(recordPayload.endTime); > + var callFrames = this._callFramesFromPayload(recordPayload.stackTrace); > + > + var significantCallFrame = null; > + if (callFrames) { And we should try to avoid this duplicated code if possible. > Source/WebInspectorUI/UserInterface/Models/RunLoopTimelineRecord.js:61 > + durationForRecords: function(recordType) Lets adopt the new method syntax for 2015 files: durationForRecords(recordType) > Source/WebInspectorUI/UserInterface/Views/RunLoopTimelineOverviewGraph.js:72 > + this._framesPerSecondDividers = new Map; I have been going with "Map.prototype.clear()". > Source/WebInspectorUI/UserInterface/Views/TimelineOverview.js:84 > +WebInspector.TimelineOverview.MinimumSecondsPerPixel = 0.0001; Whoa. > Source/WebInspectorUI/UserInterface/Views/TimelineOverviewGraph.js:44 > + if (timelineType === WebInspector.TimelineRecord.Type.RunLoop) > + return new WebInspector.RunLoopTimelineOverviewGraph(timeline); Is it useful to have this if the port does not support RunLoops? > Source/WebInspectorUI/UserInterface/Views/TimelineRecordFrame.js:33 > + this.records = records; This irks me... I think we can assume we will never call this with a single record. > Source/WebInspectorUI/UserInterface/Views/TimelineRecordFrame.js:40 > +WebInspector.TimelineRecordFrame.StyleClassName = "timeline-record-frame"; > +WebInspector.TimelineRecordFrame.FrameStyleClassName = "frame"; > +WebInspector.TimelineRecordFrame.IncludesDroppedStyleClassName = "includes-dropped"; Honestly, I've just been using style names inline now. Unless they repeat quite a bit. I find they are often, 1-off, so why have a long property name for them. Donna what Tim's thoughts are on this. > Source/WebInspectorUI/UserInterface/Views/TimelineRecordFrame.js:47 > +WebInspector.TimelineRecordFrame.createCombinedFrames = function(records, secondsPerPixel, graphDataSource, createFrameCallback) Nit: " =" => " =" > Source/WebInspectorUI/UserInterface/Views/TimelineRecordTreeElement.js:103 > + title = WebInspector.RunLoopTimelineRecord.DisplayName; I think you should just inline the DisplayName here. And it should be a UIString: title = WebInspector.UIString("Runloop Executed");
Created attachment 248781 [details] Backend
Created attachment 248782 [details] Frontend
Created attachment 248807 [details] Example frame data 1 Data captured during page load
Created attachment 248810 [details] Example frame data 2 Data captured while hovering page elements
Created attachment 248811 [details] Example frame data 3 Data captured while scrolling, hovering page elements
Created attachment 248816 [details] Backend
Created attachment 248821 [details] Backend
Created attachment 248822 [details] Frontend
Comment on attachment 248821 [details] Backend View in context: https://bugs.webkit.org/attachment.cgi?id=248821&action=review > Source/WebCore/inspector/InspectorTimelineAgent.cpp:86 > +#if PLATFORM(COCOA) > +static const CFIndex frameStopRunLoopOrder = (CFIndex)RunLoopObserver::WellKnownRunLoopOrders::CoreAnimationCommit + 1; > + > +static CFRunLoopRef currentRunLoop() > +{ > +#if PLATFORM(IOS) > + // A race condition during WebView deallocation can lead to a crash if the layer sync run loop > + // observer is added to the main run loop <rdar://problem/9798550>. However, for responsiveness, > + // we still allow this, see <rdar://problem/7403328>. Since the race condition and subsequent > + // crash are especially troublesome for iBooks, we never allow the observer to be added to the > + // main run loop in iBooks. > + if (applicationIsIBooksOnIOS()) > + return WebThreadRunLoop(); > +#endif > + return CFRunLoopGetCurrent(); > +} > +#endif This could really move to RunLoopObserver.cpp and just pass nullptr for the runloop to get the default via this code. > Source/WebCore/platform/cf/RunLoopObserver.cpp:55 > if (!runLoop) > runLoop = CFRunLoopGetCurrent(); …replacing this code.
Comment on attachment 248822 [details] Frontend View in context: https://bugs.webkit.org/attachment.cgi?id=248822&action=review > Source/WebInspectorUI/UserInterface/Models/RunLoopTimelineRecord.js:68 > + if (currentValue.usesActiveStartTime) In practice you won't see these. But it is good to be safe. > Source/WebInspectorUI/UserInterface/Models/TimelineRecord.js:50 > + RunLoop: "timeline-record-type-runloop" This should really just replace the Layout timeline graph. You can do that in a follow up. I don't want to hold up landing this.
Comment on attachment 248821 [details] Backend View in context: https://bugs.webkit.org/attachment.cgi?id=248821&action=review >> Source/WebCore/inspector/InspectorTimelineAgent.cpp:86 >> +#endif > > This could really move to RunLoopObserver.cpp and just pass nullptr for the runloop to get the default via this code. This code was originally copied from LayerFlushSchedulerMac and could probably be removed altogether. The comment indicates that it is specified to layer code, and isn't relevant to TimelineAgent.
Comment on attachment 248821 [details] Backend Clearing flags on attachment: 248821 Committed r181625: <http://trac.webkit.org/changeset/181625>
Comment on attachment 248822 [details] Frontend Clearing flags on attachment: 248822 Committed r181626: <http://trac.webkit.org/changeset/181626>
All reviewed patches have been landed. Closing bug.
(In reply to comment #18) > > Source/WebCore/inspector/InspectorTimelineAgent.cpp:162 > > + m_frameStartObserver = RunLoopObserver::create(0, [this]() { > > + if (!m_enabled) > > + return; > > + > > + ASSERT(!m_didStartRecordingRunLoop); > > + pushCurrentRecord(InspectorObject::create(), TimelineRecordType::RunLoop, false, nullptr); > > + m_didStartRecordingRunLoop = true; > > + }); > > + > > + m_frameStopObserver = RunLoopObserver::create(frameStopRunLoopOrder, [this]() { > > + if (!m_enabled || !m_didStartRecordingRunLoop) > > + return; > > + > > + didCompleteCurrentRecord(TimelineRecordType::RunLoop); > > + m_didStartRecordingRunLoop = false; > > + }); > > Does this gracefully handle nested runloops (e.g. pausing in the Web > Inspector)? > > I feel like currently this would assert as soon as you nest. > > - Entry > - BeforeTimers > => run your observer > - BeforeSources > => run JavaScript and trigger Pause, run Nested Run Loop > > - Entry > - BeforeTimers > => run your observer, I expect the first time it will ASSERT that > !didStart, in a Release build it would open a RunLoop record > - BeforeSources > => run JavaScript... eventually unpause > - BeforeWaiting > => complete the last record > - AfterWaiting > - Exit > > - BeforeWaiting > => bail, because !didStartRecording > - AfterWaiting > - Exit I think tests are seeing exactly this ASSERT scenario if we run inspector tests that have nested run loops in debug builds.
For example, running: LayoutTests/inspector/timeline/debugger-paused-while-recording.html In debug will hit an ASSERT. I'll follow up with you directly.