Web Inspector: timelines should not count time elapsed while paused in the debugger
authorburg@cs.washington.edu <burg@cs.washington.edu@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Sat, 4 Oct 2014 19:18:38 +0000 (19:18 +0000)
committerburg@cs.washington.edu <burg@cs.washington.edu@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Sat, 4 Oct 2014 19:18:38 +0000 (19:18 +0000)
https://bugs.webkit.org/show_bug.cgi?id=136351

Reviewed by Timothy Hatcher.

Source/JavaScriptCore:

Now that we have a stopwatch to provide pause-aware timing data, we can remove the
profiler's handling of debugger pause/continue callbacks. The timeline agent accounts
for debugger pauses by pausing and resuming the stopwatch.

* API/JSProfilerPrivate.cpp:
(JSStartProfiling): Use a fresh stopwatch when profiling from the JSC API.
* inspector/ScriptDebugServer.cpp:
(Inspector::ScriptDebugServer::handlePause):
* profiler/LegacyProfiler.cpp:
(JSC::LegacyProfiler::profiler): Use nullptr.
(JSC::LegacyProfiler::startProfiling): Hand off a stopwatch to the profile generator.
(JSC::LegacyProfiler::stopProfiling): Use nullptr.
(JSC::LegacyProfiler::didPause): Deleted.
(JSC::LegacyProfiler::didContinue): Deleted.
* profiler/LegacyProfiler.h:
* profiler/ProfileGenerator.cpp: Remove debugger pause/continue callbacks and the
timestamp member that was used to track time elapsed by the debugger. Just use the
stopwatch's elapsed times to generate start/elapsed times for function calls.
(JSC::ProfileGenerator::create):
(JSC::ProfileGenerator::ProfileGenerator):
(JSC::ProfileGenerator::beginCallEntry):
(JSC::ProfileGenerator::endCallEntry):
(JSC::ProfileGenerator::didPause): Deleted.
(JSC::ProfileGenerator::didContinue): Deleted.
* profiler/ProfileGenerator.h:

Source/WebCore:

To avoid counting time elapsed while the debugger is paused, timeline records should
keep track of time elapsed since the start of timeline capturing, rather than wall clock
timestamps. We can easily compute elapsed time by sharing Stopwatch instance among
all timeline record-generating code. The stopwatch is paused while the debugger is paused,
so subsequent time measurements will not include time elapsed while the debugger is paused.

Agents use the shared stopwatch to generate timestamps if the timeline agent is active
(i.e., a timeline recording is being captured). If not, use a zero timestamp since the timing data is only revealed through the Timeline interface.

This refactoring is safe because start and end times are only used to graph records; the
timestamp's actual value is irrelevant and is not displayed in the user interface. Date
timestamps are still included with network-related records as part of their header data.

No new tests, because we cannot reliably test timing changes induced by debugger pauses.
It is possible for records to accrue time before the debugger pauses or after it resumes.

* inspector/InspectorCSSAgent.cpp: Remove unused include.
* inspector/InspectorPageAgent.cpp: Use timestamps from the shared stopwatch.
(WebCore::InspectorPageAgent::timestamp):
(WebCore::InspectorPageAgent::domContentEventFired):
(WebCore::InspectorPageAgent::loadEventFired):
* inspector/InspectorPageAgent.h:
* inspector/InspectorResourceAgent.cpp: Use timestamps from the shared stopwatch.
(WebCore::InspectorResourceAgent::timestamp):
(WebCore::InspectorResourceAgent::willSendRequest):
(WebCore::InspectorResourceAgent::didReceiveResponse):
(WebCore::InspectorResourceAgent::didReceiveData):
(WebCore::InspectorResourceAgent::didFinishLoading):
(WebCore::InspectorResourceAgent::didFailLoading):
(WebCore::InspectorResourceAgent::didLoadResourceFromMemoryCache):
(WebCore::InspectorResourceAgent::willSendWebSocketHandshakeRequest):
(WebCore::InspectorResourceAgent::didReceiveWebSocketHandshakeResponse):
(WebCore::InspectorResourceAgent::didCloseWebSocket):
(WebCore::InspectorResourceAgent::didReceiveWebSocketFrame):
(WebCore::InspectorResourceAgent::didSendWebSocketFrame):
(WebCore::InspectorResourceAgent::didReceiveWebSocketFrameError):
* inspector/InspectorResourceAgent.h:
* inspector/InspectorTimelineAgent.cpp: Add calls to reset, start, and stop the stopwatch.
(WebCore::InspectorTimelineAgent::didCreateFrontendAndBackend):
(WebCore::InspectorTimelineAgent::internalStart):
(WebCore::InspectorTimelineAgent::internalStop):
(WebCore::startProfiling):
(WebCore::InspectorTimelineAgent::startFromConsole):
(WebCore::InspectorTimelineAgent::willCallFunction):
(WebCore::InspectorTimelineAgent::willEvaluateScript):
(WebCore::InspectorTimelineAgent::didPause):
(WebCore::InspectorTimelineAgent::didContinue):
(WebCore::InspectorTimelineAgent::InspectorTimelineAgent):
(WebCore::InspectorTimelineAgent::timestamp):
(WebCore::TimelineTimeConverter::reset): Deleted.
* inspector/InspectorTimelineAgent.h: Make timestamp() public, and remove old timepieces.
(WebCore::TimelineTimeConverter::TimelineTimeConverter): Deleted.
(WebCore::TimelineTimeConverter::fromMonotonicallyIncreasingTime): Deleted.
(WebCore::InspectorTimelineAgent::timeConverter): Deleted.
* inspector/TimelineRecordFactory.cpp:

Source/WebInspectorUI:

Don't update the timeline's current time when the debugger is paused.

Start and end times for timeline records are now in seconds elapsed since timeline
recording started, rather than milliseconds since the epoch. Add a workaround to
preserve compatibility with old backends.

* UserInterface/Controllers/TimelineManager.js:
(WebInspector.TimelineManager.prototype.capturingStarted):
(WebInspector.TimelineManager.prototype.eventRecorded.processRecord):
(WebInspector.TimelineManager.prototype.eventRecorded):
* UserInterface/Views/TimelineContentView.js:
(WebInspector.TimelineContentView.prototype._debuggerPaused):
(WebInspector.TimelineContentView.prototype._debuggerResumed):

Source/WTF:

* WTF.vcxproj/WTF.vcxproj:
* WTF.vcxproj/WTF.vcxproj.filters:
* WTF.xcodeproj/project.pbxproj:
* wtf/CMakeLists.txt:
* wtf/Stopwatch.h: Added. This implements a refcounted monotonic stopwatch.
(WTF::Stopwatch::reset):
(WTF::Stopwatch::start):
(WTF::Stopwatch::stop):

git-svn-id: https://svn.webkit.org/repository/webkit/trunk@174319 268f45cc-cd09-0410-ab3c-d52691b4dbfc

25 files changed:
Source/JavaScriptCore/API/JSProfilerPrivate.cpp
Source/JavaScriptCore/ChangeLog
Source/JavaScriptCore/inspector/ScriptDebugServer.cpp
Source/JavaScriptCore/profiler/LegacyProfiler.cpp
Source/JavaScriptCore/profiler/LegacyProfiler.h
Source/JavaScriptCore/profiler/ProfileGenerator.cpp
Source/JavaScriptCore/profiler/ProfileGenerator.h
Source/WTF/ChangeLog
Source/WTF/WTF.vcxproj/WTF.vcxproj
Source/WTF/WTF.vcxproj/WTF.vcxproj.filters
Source/WTF/WTF.xcodeproj/project.pbxproj
Source/WTF/wtf/CMakeLists.txt
Source/WTF/wtf/Stopwatch.h [new file with mode: 0644]
Source/WebCore/ChangeLog
Source/WebCore/inspector/InspectorCSSAgent.cpp
Source/WebCore/inspector/InspectorPageAgent.cpp
Source/WebCore/inspector/InspectorPageAgent.h
Source/WebCore/inspector/InspectorResourceAgent.cpp
Source/WebCore/inspector/InspectorResourceAgent.h
Source/WebCore/inspector/InspectorTimelineAgent.cpp
Source/WebCore/inspector/InspectorTimelineAgent.h
Source/WebCore/inspector/TimelineRecordFactory.cpp
Source/WebInspectorUI/ChangeLog
Source/WebInspectorUI/UserInterface/Controllers/TimelineManager.js
Source/WebInspectorUI/UserInterface/Views/TimelineContentView.js

index 2a5ec2c823901ed9e1bbd824cfa9c63f8a823686..35ba83bb60881baf64ee7f50ec48b1b5d5d1612b 100644 (file)
@@ -34,7 +34,7 @@ using namespace JSC;
 
 void JSStartProfiling(JSContextRef ctx, JSStringRef title)
 {
-    LegacyProfiler::profiler()->startProfiling(toJS(ctx), title->string());
+    LegacyProfiler::profiler()->startProfiling(toJS(ctx), title->string(), Stopwatch::create());
 }
 
 void JSEndProfiling(JSContextRef ctx, JSStringRef title)
index 5355c9f52837aff13722791568efd4da29b58636..8f97466b1aff1b4f75ca2a28345cb8548e3141a4 100644 (file)
@@ -1,3 +1,36 @@
+2014-10-04  Brian J. Burg  <burg@cs.washington.edu>
+
+        Web Inspector: timelines should not count time elapsed while paused in the debugger
+        https://bugs.webkit.org/show_bug.cgi?id=136351
+
+        Reviewed by Timothy Hatcher.
+
+        Now that we have a stopwatch to provide pause-aware timing data, we can remove the
+        profiler's handling of debugger pause/continue callbacks. The timeline agent accounts
+        for debugger pauses by pausing and resuming the stopwatch.
+
+        * API/JSProfilerPrivate.cpp:
+        (JSStartProfiling): Use a fresh stopwatch when profiling from the JSC API.
+        * inspector/ScriptDebugServer.cpp:
+        (Inspector::ScriptDebugServer::handlePause):
+        * profiler/LegacyProfiler.cpp:
+        (JSC::LegacyProfiler::profiler): Use nullptr.
+        (JSC::LegacyProfiler::startProfiling): Hand off a stopwatch to the profile generator.
+        (JSC::LegacyProfiler::stopProfiling): Use nullptr.
+        (JSC::LegacyProfiler::didPause): Deleted.
+        (JSC::LegacyProfiler::didContinue): Deleted.
+        * profiler/LegacyProfiler.h:
+        * profiler/ProfileGenerator.cpp: Remove debugger pause/continue callbacks and the
+        timestamp member that was used to track time elapsed by the debugger. Just use the
+        stopwatch's elapsed times to generate start/elapsed times for function calls.
+        (JSC::ProfileGenerator::create):
+        (JSC::ProfileGenerator::ProfileGenerator):
+        (JSC::ProfileGenerator::beginCallEntry):
+        (JSC::ProfileGenerator::endCallEntry):
+        (JSC::ProfileGenerator::didPause): Deleted.
+        (JSC::ProfileGenerator::didContinue): Deleted.
+        * profiler/ProfileGenerator.h:
+
 2014-10-04  Filip Pizlo  <fpizlo@apple.com>
 
         FTL should sink PutLocals
index 2c783af4776d6154f0ff32346075f7184b2e0b49..3a61663e36c477c1173b2cc388793d152cbf38cd 100644 (file)
@@ -38,7 +38,6 @@
 #include "JSJavaScriptCallFrame.h"
 #include "JSLock.h"
 #include "JavaScriptCallFrame.h"
-#include "LegacyProfiler.h"
 #include "ScriptValue.h"
 #include "SourceProvider.h"
 #include <wtf/NeverDestroyed.h>
@@ -307,14 +306,12 @@ void ScriptDebugServer::handleExceptionInBreakpointCondition(JSC::ExecState* exe
 void ScriptDebugServer::handlePause(Debugger::ReasonForPause, JSGlobalObject* vmEntryGlobalObject)
 {
     dispatchFunctionToListeners(&ScriptDebugServer::dispatchDidPause);
-    LegacyProfiler::profiler()->didPause(currentDebuggerCallFrame());
     didPause(vmEntryGlobalObject);
 
     m_doneProcessingDebuggerEvents = false;
     runEventLoopWhilePaused();
 
     didContinue(vmEntryGlobalObject);
-    LegacyProfiler::profiler()->didContinue(currentDebuggerCallFrame());
     dispatchFunctionToListeners(&ScriptDebugServer::dispatchDidContinue);
 }
 
index 4fe2ba6b1ce42b692a6c485703686fa9e4f7f7ff..e0ca2680bdb95475148fe4c41936dc6e96fc3a47 100644 (file)
@@ -32,7 +32,6 @@
 #include "CallFrame.h"
 #include "CodeBlock.h"
 #include "CommonIdentifiers.h"
-#include "DebuggerCallFrame.h"
 #include "InternalFunction.h"
 #include "JSFunction.h"
 #include "JSGlobalObject.h"
@@ -50,16 +49,16 @@ static unsigned ProfilesUID = 0;
 
 static CallIdentifier createCallIdentifierFromFunctionImp(ExecState*, JSObject*, const String& defaultSourceURL, unsigned defaultLineNumber, unsigned defaultColumnNumber);
 
-LegacyProfiler* LegacyProfiler::s_sharedLegacyProfiler = 0;
+LegacyProfiler* LegacyProfiler::s_sharedLegacyProfiler = nullptr;
 
 LegacyProfiler* LegacyProfiler::profiler()
 {
     if (!s_sharedLegacyProfiler)
         s_sharedLegacyProfiler = new LegacyProfiler();
     return s_sharedLegacyProfiler;
-}   
+}
 
-void LegacyProfiler::startProfiling(ExecState* exec, const String& title)
+void LegacyProfiler::startProfiling(ExecState* exec, const String& title, PassRefPtr<Stopwatch> stopwatch)
 {
     if (!exec)
         return;
@@ -75,14 +74,14 @@ void LegacyProfiler::startProfiling(ExecState* exec, const String& title)
     }
 
     exec->vm().setEnabledProfiler(this);
-    RefPtr<ProfileGenerator> profileGenerator = ProfileGenerator::create(exec, title, ++ProfilesUID);
+    RefPtr<ProfileGenerator> profileGenerator = ProfileGenerator::create(exec, title, ++ProfilesUID, stopwatch);
     m_currentProfiles.append(profileGenerator);
 }
 
 PassRefPtr<Profile> LegacyProfiler::stopProfiling(ExecState* exec, const String& title)
 {
     if (!exec)
-        return 0;
+        return nullptr;
 
     JSGlobalObject* origin = exec->lexicalGlobalObject();
     for (ptrdiff_t i = m_currentProfiles.size() - 1; i >= 0; --i) {
@@ -94,12 +93,12 @@ PassRefPtr<Profile> LegacyProfiler::stopProfiling(ExecState* exec, const String&
             m_currentProfiles.remove(i);
             if (!m_currentProfiles.size())
                 exec->vm().setEnabledProfiler(nullptr);
-            
+
             return returnProfile;
         }
     }
 
-    return 0;
+    return nullptr;
 }
 
 void LegacyProfiler::stopProfiling(JSGlobalObject* origin)
@@ -184,28 +183,6 @@ void LegacyProfiler::exceptionUnwind(ExecState* handlerCallFrame)
     callFunctionForProfilesWithGroup(std::bind(&ProfileGenerator::exceptionUnwind, std::placeholders::_1, handlerCallFrame, callIdentifier), m_currentProfiles, handlerCallFrame->lexicalGlobalObject()->profileGroup());
 }
 
-void LegacyProfiler::didPause(PassRefPtr<DebuggerCallFrame> prpCallFrame)
-{
-    if (m_currentProfiles.isEmpty())
-        return;
-
-    RefPtr<DebuggerCallFrame> callFrame = prpCallFrame;
-    CallIdentifier callIdentifier = createCallIdentifier(callFrame->exec(), JSValue(), StringImpl::empty(), 0, 0);
-
-    callFunctionForProfilesWithGroup(std::bind(&ProfileGenerator::didPause, std::placeholders::_1, callFrame, callIdentifier), m_currentProfiles, callFrame->vmEntryGlobalObject()->profileGroup());
-}
-
-void LegacyProfiler::didContinue(PassRefPtr<DebuggerCallFrame> prpCallFrame)
-{
-    if (m_currentProfiles.isEmpty())
-        return;
-
-    RefPtr<DebuggerCallFrame> callFrame = prpCallFrame;
-    CallIdentifier callIdentifier = createCallIdentifier(callFrame->exec(), JSValue(), StringImpl::empty(), 0, 0);
-
-    callFunctionForProfilesWithGroup(std::bind(&ProfileGenerator::didContinue, std::placeholders::_1, callFrame, callIdentifier), m_currentProfiles, callFrame->vmEntryGlobalObject()->profileGroup());
-}
-
 CallIdentifier LegacyProfiler::createCallIdentifier(ExecState* exec, JSValue functionValue, const String& defaultSourceURL, unsigned defaultLineNumber, unsigned defaultColumnNumber)
 {
     if (!functionValue)
index 1d6cb26f83ff02f8cad3270d14e0143660ab76af..8f6af40ee99ea4a90501e7eeea7b90275cee3ea3 100644 (file)
 #include "Profile.h"
 #include <wtf/PassRefPtr.h>
 #include <wtf/RefPtr.h>
+#include <wtf/Stopwatch.h>
 #include <wtf/Vector.h>
 
 namespace JSC {
 
-class DebuggerCallFrame;
 class ExecState;
-class VM;
 class JSGlobalObject;
 class JSObject;
 class JSValue;
@@ -48,10 +47,10 @@ struct CallIdentifier;
 class LegacyProfiler {
     WTF_MAKE_FAST_ALLOCATED;
 public:
-    JS_EXPORT_PRIVATE static LegacyProfiler* profiler(); 
+    JS_EXPORT_PRIVATE static LegacyProfiler* profiler();
     static CallIdentifier createCallIdentifier(ExecState*, JSValue, const WTF::String& sourceURL, unsigned defaultLineNumber, unsigned defaultColumnNumber);
 
-    JS_EXPORT_PRIVATE void startProfiling(ExecState*, const WTF::String& title);
+    JS_EXPORT_PRIVATE void startProfiling(ExecState*, const WTF::String& title, PassRefPtr<Stopwatch>);
     JS_EXPORT_PRIVATE PassRefPtr<Profile> stopProfiling(ExecState*, const WTF::String& title);
     void stopProfiling(JSGlobalObject*);
 
@@ -66,9 +65,6 @@ public:
 
     void exceptionUnwind(ExecState* handlerCallFrame);
 
-    void didPause(PassRefPtr<DebuggerCallFrame>);
-    void didContinue(PassRefPtr<DebuggerCallFrame>);
-
     const Vector<RefPtr<ProfileGenerator>>& currentProfiles() { return m_currentProfiles; };
 
 private:
index 32e89260eefc78f2a8eb996ae9a77f896ed94378..9f9ca658485383de86d791415db386ee1e61e225 100644 (file)
@@ -28,7 +28,6 @@
 
 #include "CallFrame.h"
 #include "CodeBlock.h"
-#include "Debugger.h"
 #include "JSGlobalObject.h"
 #include "JSStringRef.h"
 #include "JSFunction.h"
 
 namespace JSC {
 
-PassRefPtr<ProfileGenerator> ProfileGenerator::create(ExecState* exec, const String& title, unsigned uid)
+PassRefPtr<ProfileGenerator> ProfileGenerator::create(ExecState* exec, const String& title, unsigned uid, PassRefPtr<Stopwatch> stopwatch)
 {
-    return adoptRef(new ProfileGenerator(exec, title, uid));
+    return adoptRef(new ProfileGenerator(exec, title, uid, stopwatch));
 }
 
-ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid)
+ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid, PassRefPtr<Stopwatch> stopwatch)
     : m_origin(exec ? exec->lexicalGlobalObject() : nullptr)
     , m_profileGroup(exec ? exec->lexicalGlobalObject()->profileGroup() : 0)
-    , m_debuggerPausedTimestamp(NAN)
+    , m_stopwatch(stopwatch)
     , m_foundConsoleStartParent(false)
     , m_suspended(false)
 {
-    if (Debugger* debugger = exec->lexicalGlobalObject()->debugger())
-        m_debuggerPausedTimestamp = debugger->isPaused() ? currentTime() : NAN;
-
     m_profile = Profile::create(title, uid);
     m_currentNode = m_rootNode = m_profile->rootNode();
     if (exec)
@@ -118,12 +114,7 @@ void ProfileGenerator::beginCallEntry(ProfileNode* node, double startTime)
     ASSERT_ARG(node, node);
 
     if (isnan(startTime))
-        startTime = currentTime();
-
-    // If the debugger is paused when beginning, then don't set the start time. It
-    // will be fixed up when the debugger unpauses or the call entry ends.
-    if (!isnan(m_debuggerPausedTimestamp))
-        startTime = NAN;
+        startTime = m_stopwatch->elapsedTime();
 
     node->appendCall(ProfileNode::Call(startTime));
 }
@@ -133,22 +124,8 @@ void ProfileGenerator::endCallEntry(ProfileNode* node)
     ASSERT_ARG(node, node);
 
     ProfileNode::Call& last = node->lastCall();
-
-    // If the debugger is paused, ignore the interval that ends now.
-    if (!isnan(m_debuggerPausedTimestamp) && !isnan(last.elapsedTime()))
-        return;
-
-    // If paused and no time was accrued then the debugger was never unpaused. The call will
-    // have no time accrued and appear to have started when the debugger was paused.
-    if (!isnan(m_debuggerPausedTimestamp)) {
-        last.setStartTime(m_debuggerPausedTimestamp);
-        last.setElapsedTime(0.0);
-        return;
-    }
-
-    // Otherwise, add the interval ending now to elapsed time.
     double previousElapsedTime = isnan(last.elapsedTime()) ? 0.0 : last.elapsedTime();
-    double newlyElapsedTime = currentTime() - last.startTime();
+    double newlyElapsedTime = m_stopwatch->elapsedTime() - last.startTime();
     last.setElapsedTime(previousElapsedTime + newlyElapsedTime);
 }
 
@@ -223,33 +200,6 @@ void ProfileGenerator::exceptionUnwind(ExecState* handlerCallFrame, const CallId
     }
 }
 
-void ProfileGenerator::didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&)
-{
-    ASSERT(isnan(m_debuggerPausedTimestamp));
-
-    m_debuggerPausedTimestamp = currentTime();
-
-    for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent()) {
-        ProfileNode::Call& last = node->lastCall();
-        ASSERT(!isnan(last.startTime()));
-
-        double previousElapsedTime = isnan(last.elapsedTime()) ? 0.0 : last.elapsedTime();
-        double additionalElapsedTime = m_debuggerPausedTimestamp - last.startTime();
-        last.setStartTime(NAN);
-        last.setElapsedTime(previousElapsedTime + additionalElapsedTime);
-    }
-}
-
-void ProfileGenerator::didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&)
-{
-    ASSERT(!isnan(m_debuggerPausedTimestamp));
-
-    for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent())
-        node->lastCall().setStartTime(m_debuggerPausedTimestamp);
-
-    m_debuggerPausedTimestamp = NAN;
-}
-
 void ProfileGenerator::stopProfiling()
 {
     for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent())
index 9f51a3dc86cd33f41a4e4beafe9f50c3ccc941f2..785f799f2ceebd3b57488eec6fc934b037e58f9c 100644 (file)
@@ -29,6 +29,7 @@
 #include <wtf/PassRefPtr.h>
 #include <wtf/RefCounted.h>
 #include <wtf/RefPtr.h>
+#include <wtf/Stopwatch.h>
 #include <wtf/text/WTFString.h>
 
 namespace JSC {
@@ -42,7 +43,7 @@ namespace JSC {
 
     class ProfileGenerator : public RefCounted<ProfileGenerator>  {
     public:
-        static PassRefPtr<ProfileGenerator> create(ExecState*, const WTF::String& title, unsigned uid);
+        static PassRefPtr<ProfileGenerator> create(ExecState*, const WTF::String& title, unsigned uid, PassRefPtr<Stopwatch>);
 
         // Members
         const WTF::String& title() const;
@@ -54,15 +55,12 @@ namespace JSC {
         void didExecute(ExecState* callerCallFrame, const CallIdentifier&);
         void exceptionUnwind(ExecState* handlerCallFrame, const CallIdentifier&);
 
-        void didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
-        void didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
-
         void setIsSuspended(bool suspended) { ASSERT(m_suspended != suspended); m_suspended = suspended; }
 
         void stopProfiling();
 
     private:
-        ProfileGenerator(ExecState*, const WTF::String& title, unsigned uid);
+        ProfileGenerator(ExecState*, const WTF::String& title, unsigned uid, PassRefPtr<Stopwatch>);
         void addParentForConsoleStart(ExecState*);
 
         void removeProfileStart();
@@ -74,8 +72,7 @@ namespace JSC {
         RefPtr<Profile> m_profile;
         JSGlobalObject* m_origin;
         unsigned m_profileGroup;
-        // Timestamp is set to NAN when the debugger is not currently paused.
-        double m_debuggerPausedTimestamp;
+        RefPtr<Stopwatch> m_stopwatch;
         RefPtr<ProfileNode> m_rootNode;
         RefPtr<ProfileNode> m_currentNode;
         bool m_foundConsoleStartParent;
index 202cc5d1c01c1d86ec2ccefcc0c88fad3d6bbec5..f8ebe3c3fa4945e8d28b919715625e709ac4781b 100644 (file)
@@ -1,3 +1,19 @@
+2014-10-04  Brian J. Burg  <burg@cs.washington.edu>
+
+        Web Inspector: timelines should not count time elapsed while paused in the debugger
+        https://bugs.webkit.org/show_bug.cgi?id=136351
+
+        Reviewed by Timothy Hatcher.
+
+        * WTF.vcxproj/WTF.vcxproj:
+        * WTF.vcxproj/WTF.vcxproj.filters:
+        * WTF.xcodeproj/project.pbxproj:
+        * wtf/CMakeLists.txt:
+        * wtf/Stopwatch.h: Added. This implements a refcounted monotonic stopwatch.
+        (WTF::Stopwatch::reset):
+        (WTF::Stopwatch::start):
+        (WTF::Stopwatch::stop):
+
 2014-10-04  Filip Pizlo  <fpizlo@apple.com>
 
         FTL should sink PutLocals
index 5a425abf586c8df3f0ed286bb6093fa26d28f134..14246296fd4e493cebfe1c2e253db6c99daa8907 100644 (file)
     <ClInclude Include="..\wtf\StackBounds.h" />
     <ClInclude Include="..\wtf\StaticConstructors.h" />
     <ClInclude Include="..\wtf\StdLibExtras.h" />
+    <ClInclude Include="..\wtf\Stopwatch.h" />
     <ClInclude Include="..\wtf\StringExtras.h" />
     <ClInclude Include="..\wtf\StringHasher.h" />
     <ClInclude Include="..\wtf\StringPrintStream.h" />
index 1ce050ddbc83ed287e353e38c47f521537bcadd0..69f3206c05064f9b157c6f9b607ae009c3ebb7c2 100644 (file)
     <ClInclude Include="..\wtf\StdLibExtras.h">
       <Filter>wtf</Filter>
     </ClInclude>
+    <ClInclude Include="..\wtf\Stopwatch.h">
+      <Filter>wtf</Filter>
+    </ClInclude>
     <ClInclude Include="..\wtf\StringExtras.h">
       <Filter>wtf</Filter>
     </ClInclude>
index b54dfa8687c4caa2912c5968d7c84286bb347d95..5d3e933114d60f5a659e5353188595da36f9dd89 100644 (file)
                A8A47487151A825B004123FF /* WTFThreadData.h in Headers */ = {isa = PBXBuildFile; fileRef = A8A4737B151A825B004123FF /* WTFThreadData.h */; };
                A8A4748C151A8264004123FF /* config.h in Headers */ = {isa = PBXBuildFile; fileRef = A8A4748B151A8264004123FF /* config.h */; };
                B38FD7BD168953E80065C969 /* FeatureDefines.h in Headers */ = {isa = PBXBuildFile; fileRef = B38FD7BC168953E80065C969 /* FeatureDefines.h */; };
+               C4F8A93719C65EB400B2B15D /* Stopwatch.h in Headers */ = {isa = PBXBuildFile; fileRef = C4F8A93619C65EB400B2B15D /* Stopwatch.h */; };
                CD5497AC15857D0300B5BC30 /* MediaTime.cpp in Sources */ = {isa = PBXBuildFile; fileRef = CD5497AA15857D0300B5BC30 /* MediaTime.cpp */; };
                CD5497AD15857D0300B5BC30 /* MediaTime.h in Headers */ = {isa = PBXBuildFile; fileRef = CD5497AB15857D0300B5BC30 /* MediaTime.h */; };
                CE46516E19DB1FB4003ECA05 /* NSMapTableSPI.h in Headers */ = {isa = PBXBuildFile; fileRef = CE46516D19DB1FB4003ECA05 /* NSMapTableSPI.h */; };
                A8A4737B151A825B004123FF /* WTFThreadData.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = WTFThreadData.h; sourceTree = "<group>"; };
                A8A4748B151A8264004123FF /* config.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = config.h; sourceTree = "<group>"; };
                B38FD7BC168953E80065C969 /* FeatureDefines.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = FeatureDefines.h; sourceTree = "<group>"; };
+               C4F8A93619C65EB400B2B15D /* Stopwatch.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = Stopwatch.h; sourceTree = "<group>"; };
                CD5497AA15857D0300B5BC30 /* MediaTime.cpp */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; path = MediaTime.cpp; sourceTree = "<group>"; };
                CD5497AB15857D0300B5BC30 /* MediaTime.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MediaTime.h; sourceTree = "<group>"; };
                CE46516D19DB1FB4003ECA05 /* NSMapTableSPI.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = NSMapTableSPI.h; sourceTree = "<group>"; };
                                FEDACD3C1630F83F00C69634 /* StackStats.h */,
                                A8A47310151A825B004123FF /* StaticConstructors.h */,
                                A8A47311151A825B004123FF /* StdLibExtras.h */,
+                               C4F8A93619C65EB400B2B15D /* Stopwatch.h */,
                                1A6BB768162F300500DD16DB /* StreamBuffer.h */,
                                A8A47313151A825B004123FF /* StringExtras.h */,
                                A748745117A0BDAE00FA04CB /* StringHashDumpContext.h */,
                                A8A473A3151A825B004123FF /* DecimalNumber.h in Headers */,
                                0F2B66A617B6B4FB00A7AE3F /* DeferrableRefCounted.h in Headers */,
                                A8A473A5151A825B004123FF /* Deque.h in Headers */,
+                               C4F8A93719C65EB400B2B15D /* Stopwatch.h in Headers */,
                                A8A473A6151A825B004123FF /* DisallowCType.h in Headers */,
                                A8A473AF151A825B004123FF /* diy-fp.h in Headers */,
                                A8A473B1151A825B004123FF /* double-conversion.h in Headers */,
index e5ad9f27658f0bebd4e814b5ceeb1b94684c5e8d..97ce8d411d00540ce94db52d2f970895fd0a5051 100644 (file)
@@ -92,6 +92,7 @@ set(WTF_HEADERS
     StackStats.h
     StaticConstructors.h
     StdLibExtras.h
+    Stopwatch.h
     StringExtras.h
     StringHasher.h
     StringPrintStream.h
diff --git a/Source/WTF/wtf/Stopwatch.h b/Source/WTF/wtf/Stopwatch.h
new file mode 100644 (file)
index 0000000..38f3d0d
--- /dev/null
@@ -0,0 +1,97 @@
+/*
+ * Copyright (C) 2014 University of Washington. All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ * 1. Redistributions of source code must retain the above copyright
+ *    notice, this list of conditions and the following disclaimer.
+ * 2. Redistributions in binary form must reproduce the above copyright
+ *    notice, this list of conditions and the following disclaimer in the
+ *    documentation and/or other materials provided with the distribution.
+ *
+ * THIS SOFTWARE IS PROVIDED BY APPLE AND ITS CONTRIBUTORS "AS IS" AND ANY
+ * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
+ * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
+ * DISCLAIMED. IN NO EVENT SHALL APPLE OR ITS CONTRIBUTORS BE LIABLE FOR ANY
+ * DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
+ * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
+ * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+ * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+ * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
+ * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ */
+
+#ifndef Stopwatch_h
+#define Stopwatch_h
+
+#include <cmath>
+#include <wtf/CurrentTime.h>
+#include <wtf/RefCounted.h>
+
+namespace WTF {
+
+class Stopwatch : public RefCounted<Stopwatch> {
+public:
+    static PassRefPtr<Stopwatch> create()
+    {
+        return adoptRef(new Stopwatch());
+    }
+
+    void reset();
+    void start();
+    void stop();
+
+    double elapsedTime();
+
+private:
+    Stopwatch()
+        : m_elapsedTime(NAN)
+        , m_lastStartTime(NAN)
+    {
+    }
+
+    double m_elapsedTime;
+    double m_lastStartTime;
+};
+
+inline void Stopwatch::reset()
+{
+    m_elapsedTime = 0.0;
+    m_lastStartTime = NAN;
+}
+
+inline void Stopwatch::start()
+{
+    ASSERT(!isnan(m_elapsedTime) && isnan(m_lastStartTime));
+
+    m_lastStartTime = monotonicallyIncreasingTime();
+}
+
+inline void Stopwatch::stop()
+{
+    ASSERT(!isnan(m_elapsedTime) && !isnan(m_lastStartTime));
+
+    m_elapsedTime += monotonicallyIncreasingTime() - m_lastStartTime;
+    m_lastStartTime = NAN;
+}
+
+inline double Stopwatch::elapsedTime()
+{
+    bool shouldSuspend = !isnan(m_lastStartTime);
+    if (shouldSuspend)
+        stop();
+
+    ASSERT(!isnan(m_elapsedTime) && isnan(m_lastStartTime));
+    double elapsedTime = m_elapsedTime;
+
+    if (shouldSuspend)
+        start();
+    return elapsedTime;
+}
+
+} // namespace WTF
+
+using WTF::Stopwatch;
+
+#endif // Stopwatch_h
index 28afe1a7cebd16ef1350fbfd2d647e0956413f7d..01af5543b41203dead06cbb1859110ba3ec90e01 100644 (file)
@@ -1,3 +1,66 @@
+2014-10-04  Brian J. Burg  <burg@cs.washington.edu>
+
+        Web Inspector: timelines should not count time elapsed while paused in the debugger
+        https://bugs.webkit.org/show_bug.cgi?id=136351
+
+        Reviewed by Timothy Hatcher.
+
+        To avoid counting time elapsed while the debugger is paused, timeline records should
+        keep track of time elapsed since the start of timeline capturing, rather than wall clock
+        timestamps. We can easily compute elapsed time by sharing Stopwatch instance among
+        all timeline record-generating code. The stopwatch is paused while the debugger is paused,
+        so subsequent time measurements will not include time elapsed while the debugger is paused.
+
+        Agents use the shared stopwatch to generate timestamps if the timeline agent is active
+        (i.e., a timeline recording is being captured). If not, use a zero timestamp since the timing data is only revealed through the Timeline interface.
+
+        This refactoring is safe because start and end times are only used to graph records; the
+        timestamp's actual value is irrelevant and is not displayed in the user interface. Date
+        timestamps are still included with network-related records as part of their header data.
+
+        No new tests, because we cannot reliably test timing changes induced by debugger pauses.
+        It is possible for records to accrue time before the debugger pauses or after it resumes.
+
+        * inspector/InspectorCSSAgent.cpp: Remove unused include.
+        * inspector/InspectorPageAgent.cpp: Use timestamps from the shared stopwatch.
+        (WebCore::InspectorPageAgent::timestamp):
+        (WebCore::InspectorPageAgent::domContentEventFired):
+        (WebCore::InspectorPageAgent::loadEventFired):
+        * inspector/InspectorPageAgent.h:
+        * inspector/InspectorResourceAgent.cpp: Use timestamps from the shared stopwatch.
+        (WebCore::InspectorResourceAgent::timestamp):
+        (WebCore::InspectorResourceAgent::willSendRequest):
+        (WebCore::InspectorResourceAgent::didReceiveResponse):
+        (WebCore::InspectorResourceAgent::didReceiveData):
+        (WebCore::InspectorResourceAgent::didFinishLoading):
+        (WebCore::InspectorResourceAgent::didFailLoading):
+        (WebCore::InspectorResourceAgent::didLoadResourceFromMemoryCache):
+        (WebCore::InspectorResourceAgent::willSendWebSocketHandshakeRequest):
+        (WebCore::InspectorResourceAgent::didReceiveWebSocketHandshakeResponse):
+        (WebCore::InspectorResourceAgent::didCloseWebSocket):
+        (WebCore::InspectorResourceAgent::didReceiveWebSocketFrame):
+        (WebCore::InspectorResourceAgent::didSendWebSocketFrame):
+        (WebCore::InspectorResourceAgent::didReceiveWebSocketFrameError):
+        * inspector/InspectorResourceAgent.h:
+        * inspector/InspectorTimelineAgent.cpp: Add calls to reset, start, and stop the stopwatch.
+        (WebCore::InspectorTimelineAgent::didCreateFrontendAndBackend):
+        (WebCore::InspectorTimelineAgent::internalStart):
+        (WebCore::InspectorTimelineAgent::internalStop):
+        (WebCore::startProfiling):
+        (WebCore::InspectorTimelineAgent::startFromConsole):
+        (WebCore::InspectorTimelineAgent::willCallFunction):
+        (WebCore::InspectorTimelineAgent::willEvaluateScript):
+        (WebCore::InspectorTimelineAgent::didPause):
+        (WebCore::InspectorTimelineAgent::didContinue):
+        (WebCore::InspectorTimelineAgent::InspectorTimelineAgent):
+        (WebCore::InspectorTimelineAgent::timestamp):
+        (WebCore::TimelineTimeConverter::reset): Deleted.
+        * inspector/InspectorTimelineAgent.h: Make timestamp() public, and remove old timepieces.
+        (WebCore::TimelineTimeConverter::TimelineTimeConverter): Deleted.
+        (WebCore::TimelineTimeConverter::fromMonotonicallyIncreasingTime): Deleted.
+        (WebCore::InspectorTimelineAgent::timeConverter): Deleted.
+        * inspector/TimelineRecordFactory.cpp:
+
 2014-10-04  Tim Horton  <timothy_horton@apple.com>
 
         Make it possible to test page overlays
index 9e5687da47b17a5e9c8ae795086da972fc56112d..b571dfee08093d4da64b3e44d1f51a0f2efcd035 100644 (file)
@@ -57,7 +57,6 @@
 #include "StyleSheetList.h"
 #include "WebKitNamedFlow.h"
 #include <inspector/InspectorValues.h>
-#include <wtf/CurrentTime.h>
 #include <wtf/HashSet.h>
 #include <wtf/Ref.h>
 #include <wtf/Vector.h>
index 4099b29f43719681b1c4f48cf7d1ae3201584d20..3c2ff7a814667fcdbe9f7f2275a9142149c723f1 100644 (file)
@@ -57,6 +57,7 @@
 #include "InspectorDOMAgent.h"
 #include "InspectorInstrumentation.h"
 #include "InspectorOverlay.h"
+#include "InspectorTimelineAgent.h"
 #include "InspectorWebFrontendDispatchers.h"
 #include "InstrumentingAgents.h"
 #include "MainFrame.h"
@@ -73,7 +74,6 @@
 #include <inspector/ContentSearchUtilities.h>
 #include <inspector/IdentifiersFactory.h>
 #include <inspector/InspectorValues.h>
-#include <wtf/CurrentTime.h>
 #include <wtf/ListHashSet.h>
 #include <wtf/Vector.h>
 #include <wtf/text/Base64.h>
@@ -361,6 +361,16 @@ void InspectorPageAgent::willDestroyFrontendAndBackend(InspectorDisconnectReason
 #endif
 }
 
+double InspectorPageAgent::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;
+}
+
 void InspectorPageAgent::enable(ErrorString&)
 {
     m_enabled = true;
@@ -752,12 +762,12 @@ void InspectorPageAgent::didClearWindowObjectInWorld(Frame* frame, DOMWrapperWor
 void InspectorPageAgent::domContentEventFired()
 {
     m_isFirstLayoutAfterOnLoad = true;
-    m_frontendDispatcher->domContentEventFired(currentTime());
+    m_frontendDispatcher->domContentEventFired(timestamp());
 }
 
 void InspectorPageAgent::loadEventFired()
 {
-    m_frontendDispatcher->loadEventFired(currentTime());
+    m_frontendDispatcher->loadEventFired(timestamp());
 }
 
 void InspectorPageAgent::frameNavigated(DocumentLoader* loader)
index 18dcc3fa190a75a2d8c5555d34035df18c1b928d..06637e2d55050ab2de357f7c4ada271ed65a69e8 100644 (file)
@@ -167,6 +167,8 @@ private:
     void updateTouchEventEmulationInPage(bool);
 #endif
 
+    double timestamp();
+
     static bool mainResourceContent(Frame*, bool withBase64Encode, String* result);
     static bool dataContent(const char* data, unsigned size, const String& textEncodingName, bool withBase64Encode, String* result);
 
index 0512249c83a2399acad03eba36fed9092a6010c2..302bc34f4e4f2937267f59fd54171cf70c957493 100644 (file)
@@ -47,6 +47,7 @@
 #include "IconController.h"
 #include "InspectorClient.h"
 #include "InspectorPageAgent.h"
+#include "InspectorTimelineAgent.h"
 #include "InspectorWebFrontendDispatchers.h"
 #include "InstrumentingAgents.h"
 #include "JSMainThreadExecState.h"
@@ -69,7 +70,6 @@
 #include <inspector/InspectorValues.h>
 #include <inspector/ScriptCallStack.h>
 #include <inspector/ScriptCallStackFactory.h>
-#include <wtf/CurrentTime.h>
 #include <wtf/RefPtr.h>
 #include <wtf/text/StringBuilder.h>
 
@@ -276,6 +276,16 @@ InspectorResourceAgent::~InspectorResourceAgent()
     ASSERT(!m_instrumentingAgents->inspectorResourceAgent());
 }
 
+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;
+}
+
 void InspectorResourceAgent::willSendRequest(unsigned long identifier, DocumentLoader* loader, ResourceRequest& request, const ResourceResponse& redirectResponse)
 {
     if (request.hiddenFromInspector()) {
@@ -320,7 +330,7 @@ void InspectorResourceAgent::willSendRequest(unsigned long identifier, DocumentL
     Inspector::Protocol::Page::ResourceType resourceType = InspectorPageAgent::resourceTypeJson(type);
 
     RefPtr<Inspector::Protocol::Network::Initiator> initiatorObject = buildInitiatorObject(loader->frame() ? loader->frame()->document() : nullptr);
-    m_frontendDispatcher->requestWillBeSent(requestId, m_pageAgent->frameId(loader->frame()), m_pageAgent->loaderId(loader), loader->url().string(), buildObjectForResourceRequest(request), currentTime(), initiatorObject, buildObjectForResourceResponse(redirectResponse, loader), type != InspectorPageAgent::OtherResource ? &resourceType : nullptr);
+    m_frontendDispatcher->requestWillBeSent(requestId, m_pageAgent->frameId(loader->frame()), m_pageAgent->loaderId(loader), loader->url().string(), buildObjectForResourceRequest(request), timestamp(), initiatorObject, buildObjectForResourceResponse(redirectResponse, loader), type != InspectorPageAgent::OtherResource ? &resourceType : nullptr);
 }
 
 void InspectorResourceAgent::markResourceAsCached(unsigned long identifier)
@@ -365,7 +375,7 @@ void InspectorResourceAgent::didReceiveResponse(unsigned long identifier, Docume
     m_resourcesData->responseReceived(requestId, m_pageAgent->frameId(loader->frame()), response);
     m_resourcesData->setResourceType(requestId, type);
 
-    m_frontendDispatcher->responseReceived(requestId, m_pageAgent->frameId(loader->frame()), m_pageAgent->loaderId(loader), currentTime(), InspectorPageAgent::resourceTypeJson(type), resourceResponse);
+    m_frontendDispatcher->responseReceived(requestId, m_pageAgent->frameId(loader->frame()), m_pageAgent->loaderId(loader), timestamp(), InspectorPageAgent::resourceTypeJson(type), resourceResponse);
 
     // If we revalidated the resource and got Not modified, send content length following didReceiveResponse
     // as there will be no calls to didReceiveData from the network stack.
@@ -391,7 +401,7 @@ void InspectorResourceAgent::didReceiveData(unsigned long identifier, const char
             m_resourcesData->maybeAddResourceData(requestId, data, dataLength);
     }
 
-    m_frontendDispatcher->dataReceived(requestId, currentTime(), dataLength, encodedDataLength);
+    m_frontendDispatcher->dataReceived(requestId, timestamp(), dataLength, encodedDataLength);
 }
 
 void InspectorResourceAgent::didFinishLoading(unsigned long identifier, DocumentLoader* loader, double finishTime)
@@ -411,7 +421,7 @@ void InspectorResourceAgent::didFinishLoading(unsigned long identifier, Document
     // However, all other times passed to the Inspector are generated from the web process. Mixing
     // times from different processes can cause the finish time to be earlier than the response
     // received time due to inter-process communication lag.
-    finishTime = currentTime();
+    finishTime = timestamp();
 
     String sourceMappingURL;
     NetworkResourcesData::ResourceData const* resourceData = m_resourcesData->data(requestId);
@@ -437,7 +447,7 @@ void InspectorResourceAgent::didFailLoading(unsigned long identifier, DocumentLo
     }
 
     bool canceled = error.isCancellation();
-    m_frontendDispatcher->loadingFailed(requestId, currentTime(), error.localizedDescription(), canceled ? &canceled : nullptr);
+    m_frontendDispatcher->loadingFailed(requestId, timestamp(), error.localizedDescription(), canceled ? &canceled : nullptr);
 }
 
 void InspectorResourceAgent::didLoadResourceFromMemoryCache(DocumentLoader* loader, CachedResource* resource)
@@ -456,7 +466,7 @@ void InspectorResourceAgent::didLoadResourceFromMemoryCache(DocumentLoader* load
 
     RefPtr<Inspector::Protocol::Network::Initiator> initiatorObject = buildInitiatorObject(loader->frame() ? loader->frame()->document() : nullptr);
 
-    m_frontendDispatcher->requestServedFromMemoryCache(requestId, frameId, loaderId, loader->url().string(), currentTime(), initiatorObject, buildObjectForCachedResource(resource, loader));
+    m_frontendDispatcher->requestServedFromMemoryCache(requestId, frameId, loaderId, loader->url().string(), timestamp(), initiatorObject, buildObjectForCachedResource(resource, loader));
 }
 
 void InspectorResourceAgent::setInitialScriptContent(unsigned long identifier, const String& sourceString)
@@ -588,7 +598,7 @@ void InspectorResourceAgent::willSendWebSocketHandshakeRequest(unsigned long ide
 {
     RefPtr<Inspector::Protocol::Network::WebSocketRequest> requestObject = Inspector::Protocol::Network::WebSocketRequest::create()
         .setHeaders(buildObjectForHeaders(request.httpHeaderFields()));
-    m_frontendDispatcher->webSocketWillSendHandshakeRequest(IdentifiersFactory::requestId(identifier), currentTime(), requestObject);
+    m_frontendDispatcher->webSocketWillSendHandshakeRequest(IdentifiersFactory::requestId(identifier), timestamp(), requestObject);
 }
 
 void InspectorResourceAgent::didReceiveWebSocketHandshakeResponse(unsigned long identifier, const ResourceResponse& response)
@@ -597,12 +607,12 @@ void InspectorResourceAgent::didReceiveWebSocketHandshakeResponse(unsigned long
         .setStatus(response.httpStatusCode())
         .setStatusText(response.httpStatusText())
         .setHeaders(buildObjectForHeaders(response.httpHeaderFields()));
-    m_frontendDispatcher->webSocketHandshakeResponseReceived(IdentifiersFactory::requestId(identifier), currentTime(), responseObject);
+    m_frontendDispatcher->webSocketHandshakeResponseReceived(IdentifiersFactory::requestId(identifier), timestamp(), responseObject);
 }
 
 void InspectorResourceAgent::didCloseWebSocket(unsigned long identifier)
 {
-    m_frontendDispatcher->webSocketClosed(IdentifiersFactory::requestId(identifier), currentTime());
+    m_frontendDispatcher->webSocketClosed(IdentifiersFactory::requestId(identifier), timestamp());
 }
 
 void InspectorResourceAgent::didReceiveWebSocketFrame(unsigned long identifier, const WebSocketFrame& frame)
@@ -611,7 +621,7 @@ void InspectorResourceAgent::didReceiveWebSocketFrame(unsigned long identifier,
         .setOpcode(frame.opCode)
         .setMask(frame.masked)
         .setPayloadData(String(frame.payload, frame.payloadLength));
-    m_frontendDispatcher->webSocketFrameReceived(IdentifiersFactory::requestId(identifier), currentTime(), frameObject);
+    m_frontendDispatcher->webSocketFrameReceived(IdentifiersFactory::requestId(identifier), timestamp(), frameObject);
 }
 
 void InspectorResourceAgent::didSendWebSocketFrame(unsigned long identifier, const WebSocketFrame& frame)
@@ -620,12 +630,12 @@ void InspectorResourceAgent::didSendWebSocketFrame(unsigned long identifier, con
         .setOpcode(frame.opCode)
         .setMask(frame.masked)
         .setPayloadData(String(frame.payload, frame.payloadLength));
-    m_frontendDispatcher->webSocketFrameSent(IdentifiersFactory::requestId(identifier), currentTime(), frameObject);
+    m_frontendDispatcher->webSocketFrameSent(IdentifiersFactory::requestId(identifier), timestamp(), frameObject);
 }
 
 void InspectorResourceAgent::didReceiveWebSocketFrameError(unsigned long identifier, const String& errorMessage)
 {
-    m_frontendDispatcher->webSocketFrameError(IdentifiersFactory::requestId(identifier), currentTime(), errorMessage);
+    m_frontendDispatcher->webSocketFrameError(IdentifiersFactory::requestId(identifier), timestamp(), errorMessage);
 }
 
 #endif // ENABLE(WEB_SOCKETS)
index 283920dfe56307921d46749e61340304ccf5c6c2..b9644afc80dcea7fa8308122c0faa103a99b747d 100644 (file)
@@ -138,6 +138,8 @@ public:
 private:
     void enable();
 
+    double timestamp();
+
     InspectorPageAgent* m_pageAgent;
     InspectorClient* m_client;
     std::unique_ptr<Inspector::InspectorNetworkFrontendDispatcher> m_frontendDispatcher;
index a86ca8990479d3e65df7fb05254d0cd26c62cb8d..8b3eb4edc1c9a05050b97fb641dd499ab13c789a 100644 (file)
@@ -61,11 +61,6 @@ using namespace Inspector;
 
 namespace WebCore {
 
-void TimelineTimeConverter::reset()
-{
-    m_startOffset = monotonicallyIncreasingTime() - currentTime();
-}
-
 InspectorTimelineAgent::~InspectorTimelineAgent()
 {
 }
@@ -76,6 +71,7 @@ void InspectorTimelineAgent::didCreateFrontendAndBackend(Inspector::InspectorFro
     m_backendDispatcher = InspectorTimelineBackendDispatcher::create(backendDispatcher, this);
 
     m_instrumentingAgents->setPersistentInspectorTimelineAgent(this);
+    m_stopwatch->reset();
 
     if (m_scriptDebugServer)
         m_scriptDebugServer->recompileAllJSFunctions();
@@ -118,7 +114,7 @@ void InspectorTimelineAgent::internalStart(const int* maxCallStackDepth)
     else
         m_maxCallStackDepth = 5;
 
-    m_timeConverter.reset();
+    m_stopwatch->start();
 
     m_instrumentingAgents->setInspectorTimelineAgent(this);
 
@@ -136,6 +132,8 @@ void InspectorTimelineAgent::internalStop()
     if (!m_enabled)
         return;
 
+    m_stopwatch->stop();
+
     m_instrumentingAgents->setInspectorTimelineAgent(nullptr);
 
     if (m_scriptDebugServer)
@@ -157,9 +155,9 @@ void InspectorTimelineAgent::setPageScriptDebugServer(PageScriptDebugServer* scr
     m_scriptDebugServer = scriptDebugServer;
 }
 
-static inline void startProfiling(JSC::ExecState* exec, const String& title)
+static inline void startProfiling(JSC::ExecState* exec, const String& title, PassRefPtr<Stopwatch> stopwatch)
 {
-    JSC::LegacyProfiler::profiler()->startProfiling(exec, title);
+    JSC::LegacyProfiler::profiler()->startProfiling(exec, title, stopwatch);
 }
 
 static inline PassRefPtr<JSC::Profile> stopProfiling(JSC::ExecState* exec, const String& title)
@@ -167,9 +165,9 @@ static inline PassRefPtr<JSC::Profile> stopProfiling(JSC::ExecState* exec, const
     return JSC::LegacyProfiler::profiler()->stopProfiling(exec, title);
 }
 
-static inline void startProfiling(Frame* frame, const String& title)
+static inline void startProfiling(Frame* frame, const String& title, PassRefPtr<Stopwatch> stopwatch)
 {
-    startProfiling(toJSDOMWindow(frame, debuggerWorld())->globalExec(), title);
+    startProfiling(toJSDOMWindow(frame, debuggerWorld())->globalExec(), title, stopwatch);
 }
 
 static inline PassRefPtr<JSC::Profile> stopProfiling(Frame* frame, const String& title)
@@ -193,7 +191,7 @@ void InspectorTimelineAgent::startFromConsole(JSC::ExecState* exec, const String
     if (!m_enabled && m_pendingConsoleProfileRecords.isEmpty())
         internalStart();
 
-    startProfiling(exec, title);
+    startProfiling(exec, title, m_stopwatch);
 
     m_pendingConsoleProfileRecords.append(createRecordEntry(TimelineRecordFactory::createConsoleProfileData(title), TimelineRecordType::ConsoleProfile, true, frameFromExecState(exec)));
 }
@@ -232,7 +230,7 @@ void InspectorTimelineAgent::willCallFunction(const String& scriptName, int scri
     pushCurrentRecord(TimelineRecordFactory::createFunctionCallData(scriptName, scriptLine), TimelineRecordType::FunctionCall, true, frame);
 
     if (frame && !m_callStackDepth)
-        startProfiling(frame, ASCIILiteral("Timeline FunctionCall"));
+        startProfiling(frame, ASCIILiteral("Timeline FunctionCall"), m_stopwatch);
 
     ++m_callStackDepth;
 }
@@ -407,7 +405,7 @@ void InspectorTimelineAgent::willEvaluateScript(const String& url, int lineNumbe
 
     if (frame && !m_callStackDepth) {
         ++m_callStackDepth;
-        startProfiling(frame, ASCIILiteral("Timeline EvaluateScript"));
+        startProfiling(frame, ASCIILiteral("Timeline EvaluateScript"), m_stopwatch);
     }
 }
 
@@ -554,6 +552,16 @@ void InspectorTimelineAgent::breakpointActionProbe(JSC::ExecState* exec, const I
     appendRecord(TimelineRecordFactory::createProbeSampleData(action, hitCount), TimelineRecordType::ProbeSample, false, frameFromExecState(exec));
 }
 
+void InspectorTimelineAgent::didPause(JSC::ExecState*, const Deprecated::ScriptValue&, const Deprecated::ScriptValue&)
+{
+    m_stopwatch->stop();
+}
+
+void InspectorTimelineAgent::didContinue()
+{
+    m_stopwatch->start();
+}
+
 static Inspector::Protocol::Timeline::EventType toProtocol(TimelineRecordType type)
 {
     switch (type) {
@@ -690,6 +698,7 @@ InspectorTimelineAgent::InspectorTimelineAgent(InstrumentingAgents* instrumentin
     : InspectorAgentBase(ASCIILiteral("Timeline"), instrumentingAgents)
     , m_pageAgent(pageAgent)
     , m_scriptDebugServer(nullptr)
+    , m_stopwatch(Stopwatch::create())
     , m_id(1)
     , m_callStackDepth(0)
     , m_maxCallStackDepth(5)
@@ -748,7 +757,7 @@ void InspectorTimelineAgent::localToPageQuad(const RenderObject& renderer, const
 
 double InspectorTimelineAgent::timestamp()
 {
-    return m_timeConverter.fromMonotonicallyIncreasingTime(monotonicallyIncreasingTime());
+    return m_stopwatch->elapsedTime();
 }
 
 Page* InspectorTimelineAgent::page()
index a4cb4c4e2ef23ecd37d0ef04dc153a986c65f4be..74b7eb547c72b7af2d0ee72445101b173b28627a 100644 (file)
@@ -40,6 +40,7 @@
 #include "LayoutRect.h"
 #include <inspector/InspectorValues.h>
 #include <inspector/ScriptDebugListener.h>
+#include <wtf/Stopwatch.h>
 #include <wtf/Vector.h>
 #include <wtf/WeakPtr.h>
 
@@ -113,19 +114,6 @@ enum class TimelineRecordType {
     WebSocketDestroy
 };
 
-class TimelineTimeConverter {
-public:
-    TimelineTimeConverter()
-        : m_startOffset(0)
-    {
-    }
-    double fromMonotonicallyIncreasingTime(double time) const  { return (time - m_startOffset) * 1000.0; }
-    void reset();
-
-private:
-    double m_startOffset;
-};
-
 class InspectorTimelineAgent
     : public InspectorAgentBase
     , public Inspector::InspectorTimelineBackendDispatcherHandler
@@ -210,6 +198,10 @@ public:
     void willFireAnimationFrame(int callbackId, Frame*);
     void didFireAnimationFrame();
 
+    // 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();
+
 #if ENABLE(WEB_SOCKETS)
     void didCreateWebSocket(unsigned long identifier, const URL&, const String& protocol, Frame*);
     void willSendWebSocketHandshakeRequest(unsigned long identifier, Frame*);
@@ -218,11 +210,11 @@ public:
 #endif
 
 protected:
-    // ScriptDebugListener. This is only used to create records for probe samples.
+    // ScriptDebugListener
     virtual void didParseSource(JSC::SourceID, const Script&) override { }
     virtual void failedToParseSource(const String&, const String&, int, int, const String&) override { }
-    virtual void didPause(JSC::ExecState*, const Deprecated::ScriptValue&, const Deprecated::ScriptValue&) override { }
-    virtual void didContinue() override { }
+    virtual void didPause(JSC::ExecState*, const Deprecated::ScriptValue&, const Deprecated::ScriptValue&) override;
+    virtual void didContinue() override;
 
     virtual void breakpointActionLog(JSC::ExecState*, const String&) override { }
     virtual void breakpointActionSound(int) override { }
@@ -264,17 +256,15 @@ private:
     void clearRecordStack();
 
     void localToPageQuad(const RenderObject&, const LayoutRect&, FloatQuad*);
-    const TimelineTimeConverter& timeConverter() const { return m_timeConverter; }
-    double timestamp();
     Page* page();
 
     InspectorPageAgent* m_pageAgent;
     PageScriptDebugServer* m_scriptDebugServer;
-    TimelineTimeConverter m_timeConverter;
+
+    RefPtr<Stopwatch> m_stopwatch;
 
     std::unique_ptr<Inspector::InspectorTimelineFrontendDispatcher> m_frontendDispatcher;
     RefPtr<Inspector::InspectorTimelineBackendDispatcher> m_backendDispatcher;
-    double m_timestampOffset;
 
     Vector<TimelineRecordEntry> m_recordStack;
 
index 3fec400ab1224258d788d29d3e65b95c16bc230c..16cb388df287af44aa00cf3dd6873798e60930e3 100644 (file)
@@ -47,7 +47,6 @@
 #include <inspector/ScriptCallStack.h>
 #include <inspector/ScriptCallStackFactory.h>
 #include <profiler/Profile.h>
-#include <wtf/CurrentTime.h>
 
 using namespace Inspector;
 
index bb96a8828557e96cbe72d265fe666ed08ebb807d..704772bdb5c0c4bee2979e51c27c388c2e90d0ce 100644 (file)
@@ -1,3 +1,24 @@
+2014-10-04  Brian J. Burg  <burg@cs.washington.edu>
+
+        Web Inspector: timelines should not count time elapsed while paused in the debugger
+        https://bugs.webkit.org/show_bug.cgi?id=136351
+
+        Reviewed by Timothy Hatcher.
+
+        Don't update the timeline's current time when the debugger is paused.
+
+        Start and end times for timeline records are now in seconds elapsed since timeline
+        recording started, rather than milliseconds since the epoch. Add a workaround to
+        preserve compatibility with old backends.
+
+        * UserInterface/Controllers/TimelineManager.js:
+        (WebInspector.TimelineManager.prototype.capturingStarted):
+        (WebInspector.TimelineManager.prototype.eventRecorded.processRecord):
+        (WebInspector.TimelineManager.prototype.eventRecorded):
+        * UserInterface/Views/TimelineContentView.js:
+        (WebInspector.TimelineContentView.prototype._debuggerPaused):
+        (WebInspector.TimelineContentView.prototype._debuggerResumed):
+
 2014-10-03  Saam Barati  <saambarati1@gmail.com>
 
         Web Inspector: Move the computation that results in UI strings from JSC to the Web Inspector
index 90212e142568cb6b3baa419b1bf703ac85dee886..dbd9a588bbb19dd7955922e5280193dc5370a221 100644 (file)
@@ -35,6 +35,8 @@ WebInspector.TimelineManager = function()
     this._activeRecording = null;
     this._isCapturing = false;
 
+    // For legacy backends, we compute the elapsed time of records relative to this timestamp.
+    this._legacyFirstRecordTimestamp = NaN;
     this._nextRecordingIdentifier = 1;
 
     this._boundStopCapturing = this.stopCapturing.bind(this);
@@ -55,6 +57,7 @@ WebInspector.TimelineManager.Event = {
     CapturingStopped: "timeline-manager-capturing-stopped"
 };
 
+WebInspector.TimelineManager.StartTimeThresholdForLegacyRecordConversion = 28800000; // Date.parse("Jan 1, 1970")
 WebInspector.TimelineManager.MaximumAutoRecordDuration = 90000; // 90 seconds
 WebInspector.TimelineManager.MaximumAutoRecordDurationAfterLoadEvent = 10000; // 10 seconds
 WebInspector.TimelineManager.DeadTimeRequiredToStopAutoRecordingEarly = 2000; // 2 seconds
@@ -163,9 +166,20 @@ WebInspector.TimelineManager.prototype = {
 
         function processRecord(recordPayload, parentRecordPayload)
         {
-            // Convert the timestamps to seconds to match the resource timestamps.
-            var startTime = recordPayload.startTime / 1000;
-            var endTime = recordPayload.endTime / 1000;
+            var startTime = recordPayload.startTime;
+            var endTime = recordPayload.endTime;
+
+            // 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;
+
+            // If the record's start time sems unreasonably large, treat it as a legacy timestamp.
+            if (startTime > WebInspector.StartTimeThresholdForLegacyRecordConversion) {
+                startTime = (startTime - this._legacyFirstRecordTimestamp) / 1000;
+                endTime = isNaN(endTime) ? NaN : (startTime - this._legacyFirstRecordTimestamp) / 1000;
+            }
 
             var callFrames = this._callFramesFromPayload(recordPayload.stackTrace);
 
index be4a4e7a88412bc407338e519b05bfc925b4e20d..a203f2e31fb399ceb7ed094a09f3b35ec0c9f022 100644 (file)
@@ -98,6 +98,9 @@ WebInspector.TimelineContentView = function(recording)
     WebInspector.timelineManager.addEventListener(WebInspector.TimelineManager.Event.CapturingStarted, this._capturingStarted, this);
     WebInspector.timelineManager.addEventListener(WebInspector.TimelineManager.Event.CapturingStopped, this._capturingStopped, this);
 
+    WebInspector.debuggerManager.addEventListener(WebInspector.DebuggerManager.Event.Paused, this._debuggerPaused, this);
+    WebInspector.debuggerManager.addEventListener(WebInspector.DebuggerManager.Event.Resumed, this._debuggerResumed, this);
+
     this.showOverviewTimelineView();
 };
 
@@ -407,6 +410,22 @@ WebInspector.TimelineContentView.prototype = {
         this._stopUpdatingCurrentTime();
     },
 
+    _debuggerPaused: function(event)
+    {
+        if (WebInspector.replayManager.sessionState === WebInspector.ReplayManager.SessionState.Replaying)
+            return;
+
+        this._stopUpdatingCurrentTime();
+    },
+
+    _debuggerResumed: function(event)
+    {
+        if (WebInspector.replayManager.sessionState === WebInspector.ReplayManager.SessionState.Replaying)
+            return;
+
+        this._startUpdatingCurrentTime();
+    },
+
     _recordingTimesUpdated: function(event)
     {
         if (!this._waitingToResetCurrentTime)