Bug 136351

<rdar://problem/18167351>

Created attachment 238617 [details] WIP

Comment on attachment 238617 [details] WIP View in context: https://bugs.webkit.org/attachment.cgi?id=238617&action=review > Source/WebCore/inspector/InspectorResourceAgent.cpp:287 > +double InspectorResourceAgent::timestamp() > +{ > + // If the timeline agent is recording now, use its stopwatch. Otherwise, just report 0.0 > + // since the timestamps are only used to accurately graph records on the timeline. > + if (InspectorTimelineAgent* timelineAgent = m_instrumentingAgents->inspectorTimelineAgent()) > + return timelineAgent->timestamp(); > + > + return 0.0; > +} Some how I feel we use those timestamps other times for Resources. But I don't know… > Source/WebCore/inspector/InspectorTimelineAgent.h:203 > + // Returns the elapsed time from a monotonic stopwatch that starts with timeline recording and > + // pauses when the debugger pauses or execution is otherwise suspended. > + double timestamp(); Such win in this patch! > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:170 > + // FIXME: compatibility: old versions pass milliseconds since epoch, > + // while trunk uses seconds elapsed since start of recording. > + var startTime = recordPayload.startTime; > + var endTime = recordPayload.endTime; Should be easy to convert the old. We just need to subtract the records from the startTime of the first record if greater than epoch? We will need to address this.

(In reply to comment #3) > (From update of attachment 238617 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=238617&action=review > > > Source/WebCore/inspector/InspectorResourceAgent.cpp:287 > > +double InspectorResourceAgent::timestamp() > > +{ > > + // If the timeline agent is recording now, use its stopwatch. Otherwise, just report 0.0 > > + // since the timestamps are only used to accurately graph records on the timeline. > > + if (InspectorTimelineAgent* timelineAgent = m_instrumentingAgents->inspectorTimelineAgent()) > > + return timelineAgent->timestamp(); > > + > > + return 0.0; > > +} > > Some how I feel we use those timestamps other times for Resources. But I don't know… I did not believe it at first, but I have not found any regressions. The actual wall-clock times are included and displayed as HTTP headers/resource load timing.

Created attachment 238789 [details] Patch

Attachment 238789 [details] did not pass style-queue: ERROR: Source/JavaScriptCore/profiler/ProfileGenerator.cpp:50: Wrong number of spaces before statement. (expected: 8) [whitespace/indent] [4] Total errors found: 1 in 22 files If any of these errors are false positives, please file a bug against check-webkit-style.

Comment on attachment 238789 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=238789&action=review > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:134 > + this._capturingStartedTimestamp = Date.now(); The device time might be drastically different from the local machine's time. So this has a high likelihood of never meeting the "recordPayload.startTime > this._capturingStartedTimestamp" check in processRecord. Even if the device time and local machine time are in sync, the protocol delay can cause the backend times to be a few ms earlier, so the first few records would have bad time values. The Timeline rulers and graphs simply us TimelineRecording.startTime, which is the earliest record startTime seen. It should always be the first record. So maybe in processRecord, just do something like: if (isNaN(this._capturingStartedTimestamp)) this._capturingStartedTimestamp = recordPayload.startTime;

(In reply to comment #7) > (From update of attachment 238789 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=238789&action=review > > > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:134 > > + this._capturingStartedTimestamp = Date.now(); > > The device time might be drastically different from the local machine's time. So this has a high likelihood of never meeting the "recordPayload.startTime > this._capturingStartedTimestamp" check in processRecord. Even if the device time and local machine time are in sync, the protocol delay can cause the backend times to be a few ms earlier, so the first few records would have bad time values. > > The Timeline rulers and graphs simply us TimelineRecording.startTime, which is the earliest record startTime seen. It should always be the first record. So maybe in processRecord, just do something like: > > if (isNaN(this._capturingStartedTimestamp)) > this._capturingStartedTimestamp = recordPayload.startTime; It's always safe to subtract the first timestamp from subsequent ones to (possibly no-op) compute the elapsed time. But, how do we know whether to divide by 1000? Hardcoding something like |if (this._capturingStartedTimestamp > 100.0) startTime /= 1000;| seems kinda hacky.

Created attachment 238862 [details] WIP - try to fix windows build

Created attachment 239068 [details] Proposed Fix (+legacy backend code path)

Attachment 239068 [details] did not pass style-queue: ERROR: Source/JavaScriptCore/profiler/ProfileGenerator.cpp:50: Wrong number of spaces before statement. (expected: 8) [whitespace/indent] [4] Total errors found: 1 in 22 files If any of these errors are false positives, please file a bug against check-webkit-style.

Comment on attachment 239068 [details] Proposed Fix (+legacy backend code path) Not sure what is up with Windows…

(In reply to comment #12) > (From update of attachment 239068 [details]) > Not sure what is up with Windows… Unnecessary WTF_EXPORT_PRIVATE since everything is in the header now. Will remove before landing.

Created attachment 239217 [details] Try windows fix again

Attachment 239217 [details] did not pass style-queue: ERROR: Source/JavaScriptCore/profiler/ProfileGenerator.cpp:50: Wrong number of spaces before statement. (expected: 8) [whitespace/indent] [4] Total errors found: 1 in 22 files If any of these errors are false positives, please file a bug against check-webkit-style.

Comment on attachment 239217 [details] Try windows fix again Clearing flags on attachment: 239217 Committed r174319: <http://trac.webkit.org/changeset/174319>

All reviewed patches have been landed. Closing bug.

Reverted r174319 for reason: Causes assertions in fast/profiler tests. Needs nontrivial investigation, will take offline. Committed r174322: <http://trac.webkit.org/changeset/174322>

Created attachment 239446 [details] Patch (Fixed test regressions)

Attachment 239446 [details] did not pass style-queue: ERROR: Source/JavaScriptCore/profiler/ProfileGenerator.cpp:50: Wrong number of spaces before statement. (expected: 8) [whitespace/indent] [4] Total errors found: 1 in 23 files If any of these errors are false positives, please file a bug against check-webkit-style.

Comment on attachment 239446 [details] Patch (Fixed test regressions) Relative to the patch that was rolled out, this patch simplifies Stopwatch so reset() doesn't need to be called before start()---the stopwatch constructor returns an object in a valid state. Also, fix some uses of one-off stopwatches for profiling through console.profile (used in tests) and JSStartProfiling.

Comment on attachment 239446 [details] Patch (Fixed test regressions) View in context: https://bugs.webkit.org/attachment.cgi?id=239446&action=review > Source/WebCore/inspector/InspectorTimelineAgent.cpp:194 > + // Use an independent stopwatch for console-initiated profiling, since the user will expect it > + // to be relative to when their command was issued. How does this affect the UI? > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:176 > + // COMPATIBILITY (iOS8): old versions use milliseconds since the epoch, rather > + // than seconds elapsed since timeline capturing started. We approximate the latter by > + // subtracting the start timestamp, as old versions did not use monotonic times. > + if (isNaN(this._legacyFirstRecordTimestamp)) > + this._legacyFirstRecordTimestamp = recordPayload.startTime; What about iOS 8 and earlier with WebInspector.ProfileNodeCall times?

Comment on attachment 239446 [details] Patch (Fixed test regressions) View in context: https://bugs.webkit.org/attachment.cgi?id=239446&action=review >> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:176 >> + this._legacyFirstRecordTimestamp = recordPayload.startTime; > > What about iOS 8 and earlier with WebInspector.ProfileNodeCall times? Double checking, but looks like there are a few regressions with this patch when inspecting iOS 8. Now that I can directly test this use case, I'll post a revised patch.

Another regression: probe samples come with timestamps, but currently they aren't synced to the timeline's sense of elapsed time. It is not as easy to plumb the Stopwatch to InspectorDebuggerAgent. I think it may make sense to move the shared Stopwatch instance (or a getElapsedTime() method) to the InspectorEnvironment since it is used by 4 agents (CSS, Debugger, Page, Timeline). Depending on environment type, the stopwatch could come from Timeline agent (WebCore) or from a JSGlobalObjectInspectorController (JSC). We don't need to worry about computing elapsed time for resources when the timelines agent is unavailable, because this is only surfaced in the UI through the timelines UI and the default dashboard's time-to-load-event ticker (which uses data gathered by an auto-capturing timeline started on page load). What do you think?

Created attachment 239660 [details] Revised approach This patch is up for review but still has some legacy regressions. Investigating those is somewhat blocked by remote inspector crashing often. Please look at design changes in the attached patch. Namely, moving the shared stopwatch to InspectorEnvironment.

Attachment 239660 [details] did not pass style-queue: ERROR: Source/JavaScriptCore/inspector/JSGlobalObjectInspectorController.cpp:47: Alphabetical sorting problem. [build/include_order] [4] ERROR: Source/JavaScriptCore/profiler/ProfileGenerator.cpp:50: Wrong number of spaces before statement. (expected: 8) [whitespace/indent] [4] Total errors found: 2 in 36 files If any of these errors are false positives, please file a bug against check-webkit-style.

Created attachment 240077 [details] Patch

Attachment 240077 [details] did not pass style-queue: ERROR: Source/JavaScriptCore/inspector/JSGlobalObjectInspectorController.cpp:47: Alphabetical sorting problem. [build/include_order] [4] ERROR: Source/JavaScriptCore/profiler/ProfileGenerator.cpp:50: Wrong number of spaces before statement. (expected: 8) [whitespace/indent] [4] Total errors found: 2 in 37 files If any of these errors are false positives, please file a bug against check-webkit-style.

Latest patch is confirmed to work for iOS 8. It moves the legacy first timestamp to be per-TimelineRecording, since these could be arbitrarily delayed from one another. Elapsed time should be relative to the start of a recording. Note that for legacy backends, elapsed time will revert to its previous behavior: there will be gaps in the timeline when the debugger pauses. We can't do much about that, and it's fine. On my device there are weird issues with remote inspection hanging after an auto-captured timeline recording, but this happens with a nightly build without these changes. I could not trigger any wrong-timestamp bugs.

Comment on attachment 240077 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=240077&action=review > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:124 > + computeElapsedTime: function(timestamp) This function sounds more like a duration calculation taking a start and stop time. Maybe computeRelativeTime? > Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:127 > + if (!this._activeRecording) > + return; Be explicit here: return 0; ? return undefined; ? > Source/WebInspectorUI/UserInterface/Models/TimelineRecording.js:183 > + computeElapsedTime: function(timestamp) Ditto re: computeRelativeTime?

Comment on attachment 240077 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=240077&action=review >> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:124 >> + computeElapsedTime: function(timestamp) > > This function sounds more like a duration calculation taking a start and stop time. Maybe computeRelativeTime? It is! The start time is implicit. It's either 0.0 or the legacy first timestamp for the timeline recording. >> Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js:127 >> + return; > > Be explicit here: > return 0; ? > return undefined; ? oops

Committed r175203: <http://trac.webkit.org/changeset/175203>

This made a number of Inspector tests assert: https://build.webkit.org/results/Apple%20Mavericks%20Debug%20WK2%20(Tests)/r175204%20(7622)/results.html

Reopening to attach new patch.

Created attachment 240460 [details] Patch

Committed r175206: <http://trac.webkit.org/changeset/175206> Somehow I missed the (unusual for the UI) situation uncovered by inspector-protocol/debugger, where we never start the environment stopwatch then hit a breakpoint. The debugger should check first before calling stop() to respect its precondition.

*** Bug 136797 has been marked as a duplicate of this bug. ***

*** Bug 135612 has been marked as a duplicate of this bug. ***