WebKit Bugzilla
New
Browse
Log In
×
Sign in with GitHub
or
Remember my login
Create Account
·
Forgot Password
Forgotten password account recovery
RESOLVED FIXED
136351
Web Inspector: timelines should not count time elapsed while paused in the debugger
https://bugs.webkit.org/show_bug.cgi?id=136351
Summary
Web Inspector: timelines should not count time elapsed while paused in the de...
Brian Burg
Reported
2014-08-28 14:55:00 PDT
The timeline is basically useless if you pause in the debugger while recording, as it does not pause the elapsed timer while the debugger is paused.
Attachments
WIP
(44.90 KB, patch)
2014-09-24 16:07 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Patch
(55.39 KB, patch)
2014-09-27 14:43 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
WIP - try to fix windows build
(55.25 KB, patch)
2014-09-29 09:34 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Proposed Fix (+legacy backend code path)
(55.83 KB, patch)
2014-10-01 16:54 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Try windows fix again
(55.72 KB, patch)
2014-10-03 11:19 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Patch (Fixed test regressions)
(58.07 KB, patch)
2014-10-07 19:23 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Revised approach
(85.77 KB, patch)
2014-10-10 17:00 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Patch
(87.00 KB, patch)
2014-10-18 17:34 PDT
,
Brian Burg
timothy
: review+
Details
Formatted Diff
Diff
Patch
(3.08 KB, patch)
2014-10-25 20:47 PDT
,
Brian Burg
no flags
Details
Formatted Diff
Diff
Show Obsolete
(7)
View All
Add attachment
proposed patch, testcase, etc.
Radar WebKit Bug Importer
Comment 1
2014-08-28 14:55:18 PDT
<
rdar://problem/18167351
>
Brian Burg
Comment 2
2014-09-24 16:07:20 PDT
Created
attachment 238617
[details]
WIP
Timothy Hatcher
Comment 3
2014-09-24 21:44:31 PDT
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.
Brian Burg
Comment 4
2014-09-26 13:40:05 PDT
(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.
Brian Burg
Comment 5
2014-09-27 14:43:10 PDT
Created
attachment 238789
[details]
Patch
WebKit Commit Bot
Comment 6
2014-09-27 14:45:02 PDT
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.
Timothy Hatcher
Comment 7
2014-09-27 23:56:14 PDT
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;
Brian Burg
Comment 8
2014-09-28 14:54:04 PDT
(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.
Brian Burg
Comment 9
2014-09-29 09:34:59 PDT
Created
attachment 238862
[details]
WIP - try to fix windows build
Brian Burg
Comment 10
2014-10-01 16:54:41 PDT
Created
attachment 239068
[details]
Proposed Fix (+legacy backend code path)
WebKit Commit Bot
Comment 11
2014-10-01 16:57:41 PDT
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.
Timothy Hatcher
Comment 12
2014-10-02 19:35:44 PDT
Comment on
attachment 239068
[details]
Proposed Fix (+legacy backend code path) Not sure what is up with Windows…
Brian Burg
Comment 13
2014-10-02 20:58:07 PDT
(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.
Brian Burg
Comment 14
2014-10-03 11:19:31 PDT
Created
attachment 239217
[details]
Try windows fix again
WebKit Commit Bot
Comment 15
2014-10-03 11:22:31 PDT
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.
WebKit Commit Bot
Comment 16
2014-10-04 12:18:44 PDT
Comment on
attachment 239217
[details]
Try windows fix again Clearing flags on attachment: 239217 Committed
r174319
: <
http://trac.webkit.org/changeset/174319
>
WebKit Commit Bot
Comment 17
2014-10-04 12:18:53 PDT
All reviewed patches have been landed. Closing bug.
Brian Burg
Comment 18
2014-10-04 14:56:01 PDT
Reverted
r174319
for reason: Causes assertions in fast/profiler tests. Needs nontrivial investigation, will take offline. Committed
r174322
: <
http://trac.webkit.org/changeset/174322
>
Brian Burg
Comment 19
2014-10-07 19:23:27 PDT
Created
attachment 239446
[details]
Patch (Fixed test regressions)
WebKit Commit Bot
Comment 20
2014-10-07 19:24:38 PDT
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.
Brian Burg
Comment 21
2014-10-07 19:25:48 PDT
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.
Timothy Hatcher
Comment 22
2014-10-08 10:02:28 PDT
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?
Brian Burg
Comment 23
2014-10-09 13:48:20 PDT
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.
Brian Burg
Comment 24
2014-10-09 16:23:59 PDT
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?
Brian Burg
Comment 25
2014-10-10 17:00:11 PDT
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.
WebKit Commit Bot
Comment 26
2014-10-10 17:01:48 PDT
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.
Brian Burg
Comment 27
2014-10-18 17:34:27 PDT
Created
attachment 240077
[details]
Patch
WebKit Commit Bot
Comment 28
2014-10-18 17:35:59 PDT
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.
Brian Burg
Comment 29
2014-10-18 17:41:48 PDT
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.
Timothy Hatcher
Comment 30
2014-10-20 11:56:29 PDT
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?
Brian Burg
Comment 31
2014-10-20 15:08:36 PDT
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
Brian Burg
Comment 32
2014-10-25 15:05:55 PDT
Committed
r175203
: <
http://trac.webkit.org/changeset/175203
>
Alexey Proskuryakov
Comment 33
2014-10-25 20:00:19 PDT
This made a number of Inspector tests assert:
https://build.webkit.org/results/Apple%20Mavericks%20Debug%20WK2%20(Tests)/r175204%20(7622)/results.html
Brian Burg
Comment 34
2014-10-25 20:46:56 PDT
Reopening to attach new patch.
Brian Burg
Comment 35
2014-10-25 20:47:00 PDT
Created
attachment 240460
[details]
Patch
Brian Burg
Comment 36
2014-10-25 20:55:05 PDT
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.
Brian Burg
Comment 37
2014-10-27 09:56:36 PDT
***
Bug 136797
has been marked as a duplicate of this bug. ***
Brian Burg
Comment 38
2014-12-11 09:24:30 PST
***
Bug 135612
has been marked as a duplicate of this bug. ***
Note
You need to
log in
before you can comment on or make changes to this bug.
Top of Page
Format For Printing
XML
Clone This Bug