Ignore:
Timestamp:
Oct 4, 2014, 12:18:38 PM (11 years ago)
Author:
Brian Burg
Message:

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.

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):

Location:
trunk/Source/JavaScriptCore/profiler
Files:
4 edited

Legend:

Unmodified
Added
Removed

  • trunk/Source/JavaScriptCore/profiler/LegacyProfiler.cpp

    r174095 r174319  
    3333#include "CodeBlock.h"
    3434#include "CommonIdentifiers.h"
    35 #include "DebuggerCallFrame.h"
    3635#include "InternalFunction.h"
    3736#include "JSFunction.h"
    … …  
    5150static CallIdentifier createCallIdentifierFromFunctionImp(ExecState*, JSObject*, const String& defaultSourceURL, unsigned defaultLineNumber, unsigned defaultColumnNumber);
    5251
    53 LegacyProfiler* LegacyProfiler::s_sharedLegacyProfiler = 0;
     52LegacyProfiler* LegacyProfiler::s_sharedLegacyProfiler = nullptr;
    5453
    5554LegacyProfiler* LegacyProfiler::profiler()
    … …  
    5857        s_sharedLegacyProfiler = new LegacyProfiler();
    5958    return s_sharedLegacyProfiler;
    60 }   
    61 
    62 void LegacyProfiler::startProfiling(ExecState* exec, const String& title)
     59}
     60
     61void LegacyProfiler::startProfiling(ExecState* exec, const String& title, PassRefPtr<Stopwatch> stopwatch)
    6362{
    6463    if (!exec)
    … …  
    7675
    7776    exec->vm().setEnabledProfiler(this);
    78     RefPtr<ProfileGenerator> profileGenerator = ProfileGenerator::create(exec, title, ++ProfilesUID);
     77    RefPtr<ProfileGenerator> profileGenerator = ProfileGenerator::create(exec, title, ++ProfilesUID, stopwatch);
    7978    m_currentProfiles.append(profileGenerator);
    8079}
    … …  
    8382{
    8483    if (!exec)
    85         return 0;
     84        return nullptr;
    8685
    8786    JSGlobalObject* origin = exec->lexicalGlobalObject();
    … …  
    9594            if (!m_currentProfiles.size())
    9695                exec->vm().setEnabledProfiler(nullptr);
    97            
     96
    9897            return returnProfile;
    9998        }
    10099    }
    101100
    102     return 0;
     101    return nullptr;
    103102}
    104103
    … …  
    183182
    184183    callFunctionForProfilesWithGroup(std::bind(&ProfileGenerator::exceptionUnwind, std::placeholders::_1, handlerCallFrame, callIdentifier), m_currentProfiles, handlerCallFrame->lexicalGlobalObject()->profileGroup());
    185 }
    186 
    187 void LegacyProfiler::didPause(PassRefPtr<DebuggerCallFrame> prpCallFrame)
    188 {
    189     if (m_currentProfiles.isEmpty())
    190         return;
    191 
    192     RefPtr<DebuggerCallFrame> callFrame = prpCallFrame;
    193     CallIdentifier callIdentifier = createCallIdentifier(callFrame->exec(), JSValue(), StringImpl::empty(), 0, 0);
    194 
    195     callFunctionForProfilesWithGroup(std::bind(&ProfileGenerator::didPause, std::placeholders::_1, callFrame, callIdentifier), m_currentProfiles, callFrame->vmEntryGlobalObject()->profileGroup());
    196 }
    197 
    198 void LegacyProfiler::didContinue(PassRefPtr<DebuggerCallFrame> prpCallFrame)
    199 {
    200     if (m_currentProfiles.isEmpty())
    201         return;
    202 
    203     RefPtr<DebuggerCallFrame> callFrame = prpCallFrame;
    204     CallIdentifier callIdentifier = createCallIdentifier(callFrame->exec(), JSValue(), StringImpl::empty(), 0, 0);
    205 
    206     callFunctionForProfilesWithGroup(std::bind(&ProfileGenerator::didContinue, std::placeholders::_1, callFrame, callIdentifier), m_currentProfiles, callFrame->vmEntryGlobalObject()->profileGroup());
    207184}
    208185

  • trunk/Source/JavaScriptCore/profiler/LegacyProfiler.h

    r174095 r174319  
    3333#include <wtf/PassRefPtr.h>
    3434#include <wtf/RefPtr.h>
     35#include <wtf/Stopwatch.h>
    3536#include <wtf/Vector.h>
    3637
    3738namespace JSC {
    3839
    39 class DebuggerCallFrame;
    4040class ExecState;
    41 class VM;
    4241class JSGlobalObject;
    4342class JSObject;
    … …  
    4948    WTF_MAKE_FAST_ALLOCATED;
    5049public:
    51     JS_EXPORT_PRIVATE static LegacyProfiler* profiler(); 
     50    JS_EXPORT_PRIVATE static LegacyProfiler* profiler();
    5251    static CallIdentifier createCallIdentifier(ExecState*, JSValue, const WTF::String& sourceURL, unsigned defaultLineNumber, unsigned defaultColumnNumber);
    5352
    54     JS_EXPORT_PRIVATE void startProfiling(ExecState*, const WTF::String& title);
     53    JS_EXPORT_PRIVATE void startProfiling(ExecState*, const WTF::String& title, PassRefPtr<Stopwatch>);
    5554    JS_EXPORT_PRIVATE PassRefPtr<Profile> stopProfiling(ExecState*, const WTF::String& title);
    5655    void stopProfiling(JSGlobalObject*);
    … …  
    6766    void exceptionUnwind(ExecState* handlerCallFrame);
    6867
    69     void didPause(PassRefPtr<DebuggerCallFrame>);
    70     void didContinue(PassRefPtr<DebuggerCallFrame>);
    71 
    7268    const Vector<RefPtr<ProfileGenerator>>& currentProfiles() { return m_currentProfiles; };
    7369

  • trunk/Source/JavaScriptCore/profiler/ProfileGenerator.cpp

    r174095 r174319  
    2929#include "CallFrame.h"
    3030#include "CodeBlock.h"
    31 #include "Debugger.h"
    3231#include "JSGlobalObject.h"
    3332#include "JSStringRef.h"
    … …  
    4140namespace JSC {
    4241
    43 PassRefPtr<ProfileGenerator> ProfileGenerator::create(ExecState* exec, const String& title, unsigned uid)
    44 {
    45     return adoptRef(new ProfileGenerator(exec, title, uid));
    46 }
    47 
    48 ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid)
     42PassRefPtr<ProfileGenerator> ProfileGenerator::create(ExecState* exec, const String& title, unsigned uid, PassRefPtr<Stopwatch> stopwatch)
     43{
     44    return adoptRef(new ProfileGenerator(exec, title, uid, stopwatch));
     45}
     46
     47ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid, PassRefPtr<Stopwatch> stopwatch)
    4948    : m_origin(exec ? exec->lexicalGlobalObject() : nullptr)
    5049    , m_profileGroup(exec ? exec->lexicalGlobalObject()->profileGroup() : 0)
    51     , m_debuggerPausedTimestamp(NAN)
     50    , m_stopwatch(stopwatch)
    5251    , m_foundConsoleStartParent(false)
    5352    , m_suspended(false)
    5453{
    55     if (Debugger* debugger = exec->lexicalGlobalObject()->debugger())
    56         m_debuggerPausedTimestamp = debugger->isPaused() ? currentTime() : NAN;
    57 
    5854    m_profile = Profile::create(title, uid);
    5955    m_currentNode = m_rootNode = m_profile->rootNode();
    … …  
    119115
    120116    if (isnan(startTime))
    121         startTime = currentTime();
    122 
    123     // If the debugger is paused when beginning, then don't set the start time. It
    124     // will be fixed up when the debugger unpauses or the call entry ends.
    125     if (!isnan(m_debuggerPausedTimestamp))
    126         startTime = NAN;
     117        startTime = m_stopwatch->elapsedTime();
    127118
    128119    node->appendCall(ProfileNode::Call(startTime));
    … …  
    134125
    135126    ProfileNode::Call& last = node->lastCall();
    136 
    137     // If the debugger is paused, ignore the interval that ends now.
    138     if (!isnan(m_debuggerPausedTimestamp) && !isnan(last.elapsedTime()))
    139         return;
    140 
    141     // If paused and no time was accrued then the debugger was never unpaused. The call will
    142     // have no time accrued and appear to have started when the debugger was paused.
    143     if (!isnan(m_debuggerPausedTimestamp)) {
    144         last.setStartTime(m_debuggerPausedTimestamp);
    145         last.setElapsedTime(0.0);
    146         return;
    147     }
    148 
    149     // Otherwise, add the interval ending now to elapsed time.
    150127    double previousElapsedTime = isnan(last.elapsedTime()) ? 0.0 : last.elapsedTime();
    151     double newlyElapsedTime = currentTime() - last.startTime();
     128    double newlyElapsedTime = m_stopwatch->elapsedTime() - last.startTime();
    152129    last.setElapsedTime(previousElapsedTime + newlyElapsedTime);
    153130}
    … …  
    224201}
    225202
    226 void ProfileGenerator::didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&)
    227 {
    228     ASSERT(isnan(m_debuggerPausedTimestamp));
    229 
    230     m_debuggerPausedTimestamp = currentTime();
    231 
    232     for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent()) {
    233         ProfileNode::Call& last = node->lastCall();
    234         ASSERT(!isnan(last.startTime()));
    235 
    236         double previousElapsedTime = isnan(last.elapsedTime()) ? 0.0 : last.elapsedTime();
    237         double additionalElapsedTime = m_debuggerPausedTimestamp - last.startTime();
    238         last.setStartTime(NAN);
    239         last.setElapsedTime(previousElapsedTime + additionalElapsedTime);
    240     }
    241 }
    242 
    243 void ProfileGenerator::didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&)
    244 {
    245     ASSERT(!isnan(m_debuggerPausedTimestamp));
    246 
    247     for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent())
    248         node->lastCall().setStartTime(m_debuggerPausedTimestamp);
    249 
    250     m_debuggerPausedTimestamp = NAN;
    251 }
    252 
    253203void ProfileGenerator::stopProfiling()
    254204{

  • trunk/Source/JavaScriptCore/profiler/ProfileGenerator.h

    r174095 r174319  
    3030#include <wtf/RefCounted.h>
    3131#include <wtf/RefPtr.h>
     32#include <wtf/Stopwatch.h>
    3233#include <wtf/text/WTFString.h>
    3334
    … …  
    4344    class ProfileGenerator : public RefCounted<ProfileGenerator>  {
    4445    public:
    45         static PassRefPtr<ProfileGenerator> create(ExecState*, const WTF::String& title, unsigned uid);
     46        static PassRefPtr<ProfileGenerator> create(ExecState*, const WTF::String& title, unsigned uid, PassRefPtr<Stopwatch>);
    4647
    4748        // Members
    … …  
    5556        void exceptionUnwind(ExecState* handlerCallFrame, const CallIdentifier&);
    5657
    57         void didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
    58         void didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
    59 
    6058        void setIsSuspended(bool suspended) { ASSERT(m_suspended != suspended); m_suspended = suspended; }
    6159
    … …  
    6361
    6462    private:
    65         ProfileGenerator(ExecState*, const WTF::String& title, unsigned uid);
     63        ProfileGenerator(ExecState*, const WTF::String& title, unsigned uid, PassRefPtr<Stopwatch>);
    6664        void addParentForConsoleStart(ExecState*);
    6765
    … …  
    7573        JSGlobalObject* m_origin;
    7674        unsigned m_profileGroup;
    77         // Timestamp is set to NAN when the debugger is not currently paused.
    78         double m_debuggerPausedTimestamp;
     75        RefPtr<Stopwatch> m_stopwatch;
    7976        RefPtr<ProfileNode> m_rootNode;
    8077        RefPtr<ProfileNode> m_currentNode;
Note: See TracChangeset for help on using the changeset viewer.