- Revision
- 173939
- Author
- [email protected]
- Date
- 2014-09-24 17:25:31 -0700 (Wed, 24 Sep 2014)
Log Message
Web Inspector: subtract elapsed time while debugger is paused from profile nodes
https://bugs.webkit.org/show_bug.cgi?id=136796
Reviewed by Timothy Hatcher.
Source/_javascript_Core:
Rather than accruing no time to any profile node created while the debugger is paused,
we can instead count a node's elapsed time and exclude time elapsed while paused.
Time for a node may elapse in a non-contiguous fashion depending on the interleaving of
didPause, didContinue, willExecute, and didExecute. A node's start time is set to the
start of the last such interval that accrues elapsed time.
* profiler/ProfileGenerator.cpp:
(JSC::ProfileGenerator::ProfileGenerator):
(JSC::ProfileGenerator::beginCallEntry):
(JSC::ProfileGenerator::endCallEntry):
(JSC::ProfileGenerator::didPause): Added.
(JSC::ProfileGenerator::didContinue): Added.
* profiler/ProfileGenerator.h:
(JSC::ProfileGenerator::didPause): Deleted.
(JSC::ProfileGenerator::didContinue): Deleted.
* profiler/ProfileNode.h: Rename totalTime to elapsedTime.
(JSC::ProfileNode::Call::Call):
(JSC::ProfileNode::Call::elapsedTime): Added.
(JSC::ProfileNode::Call::setElapsedTime): Added.
(JSC::CalculateProfileSubtreeDataFunctor::operator()):
(JSC::ProfileNode::Call::totalTime): Deleted.
(JSC::ProfileNode::Call::setTotalTime): Deleted.
Source/WebCore:
* inspector/TimelineRecordFactory.cpp:
(WebCore::buildInspectorObject):
Modified Paths
Diff
Modified: trunk/Source/_javascript_Core/ChangeLog (173938 => 173939)
--- trunk/Source/_javascript_Core/ChangeLog 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/_javascript_Core/ChangeLog 2014-09-25 00:25:31 UTC (rev 173939)
@@ -1,3 +1,34 @@
+2014-09-24 Brian J. Burg <[email protected]>
+
+ Web Inspector: subtract elapsed time while debugger is paused from profile nodes
+ https://bugs.webkit.org/show_bug.cgi?id=136796
+
+ Reviewed by Timothy Hatcher.
+
+ Rather than accruing no time to any profile node created while the debugger is paused,
+ we can instead count a node's elapsed time and exclude time elapsed while paused.
+
+ Time for a node may elapse in a non-contiguous fashion depending on the interleaving of
+ didPause, didContinue, willExecute, and didExecute. A node's start time is set to the
+ start of the last such interval that accrues elapsed time.
+
+ * profiler/ProfileGenerator.cpp:
+ (JSC::ProfileGenerator::ProfileGenerator):
+ (JSC::ProfileGenerator::beginCallEntry):
+ (JSC::ProfileGenerator::endCallEntry):
+ (JSC::ProfileGenerator::didPause): Added.
+ (JSC::ProfileGenerator::didContinue): Added.
+ * profiler/ProfileGenerator.h:
+ (JSC::ProfileGenerator::didPause): Deleted.
+ (JSC::ProfileGenerator::didContinue): Deleted.
+ * profiler/ProfileNode.h: Rename totalTime to elapsedTime.
+ (JSC::ProfileNode::Call::Call):
+ (JSC::ProfileNode::Call::elapsedTime): Added.
+ (JSC::ProfileNode::Call::setElapsedTime): Added.
+ (JSC::CalculateProfileSubtreeDataFunctor::operator()):
+ (JSC::ProfileNode::Call::totalTime): Deleted.
+ (JSC::ProfileNode::Call::setTotalTime): Deleted.
+
2014-09-24 Commit Queue <[email protected]>
Unreviewed, rolling out r173839.
Modified: trunk/Source/_javascript_Core/profiler/ProfileGenerator.cpp (173938 => 173939)
--- trunk/Source/_javascript_Core/profiler/ProfileGenerator.cpp 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/_javascript_Core/profiler/ProfileGenerator.cpp 2014-09-25 00:25:31 UTC (rev 173939)
@@ -48,11 +48,11 @@
ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid)
: m_origin(exec ? exec->lexicalGlobalObject() : nullptr)
, m_profileGroup(exec ? exec->lexicalGlobalObject()->profileGroup() : 0)
+ , m_debuggerPausedTimestamp(NAN)
, m_foundConsoleStartParent(false)
- , m_debuggerPaused(false)
{
if (Debugger* debugger = exec->lexicalGlobalObject()->debugger())
- m_debuggerPaused = debugger->isPaused();
+ m_debuggerPausedTimestamp = debugger->isPaused() ? currentTime() : NAN;
m_profile = Profile::create(title, uid);
m_currentNode = m_rootNode = m_profile->rootNode();
@@ -118,6 +118,12 @@
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;
+
node->appendCall(ProfileNode::Call(startTime));
}
@@ -126,9 +132,23 @@
ASSERT_ARG(node, node);
ProfileNode::Call& last = node->lastCall();
- ASSERT(isnan(last.totalTime()));
- last.setTotalTime(m_debuggerPaused ? 0.0 : currentTime() - last.startTime());
+ // 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();
+ last.setElapsedTime(previousElapsedTime + newlyElapsedTime);
}
void ProfileGenerator::willExecute(ExecState* callerCallFrame, const CallIdentifier& callIdentifier)
@@ -196,6 +216,33 @@
}
}
+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())
Modified: trunk/Source/_javascript_Core/profiler/ProfileGenerator.h (173938 => 173939)
--- trunk/Source/_javascript_Core/profiler/ProfileGenerator.h 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/_javascript_Core/profiler/ProfileGenerator.h 2014-09-25 00:25:31 UTC (rev 173939)
@@ -54,8 +54,8 @@
void didExecute(ExecState* callerCallFrame, const CallIdentifier&);
void exceptionUnwind(ExecState* handlerCallFrame, const CallIdentifier&);
- void didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&) { m_debuggerPaused = true; }
- void didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&) { m_debuggerPaused = false; }
+ void didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
+ void didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
void stopProfiling();
@@ -74,10 +74,11 @@
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<ProfileNode> m_rootNode;
RefPtr<ProfileNode> m_currentNode;
bool m_foundConsoleStartParent;
- bool m_debuggerPaused;
};
} // namespace JSC
Modified: trunk/Source/_javascript_Core/profiler/ProfileNode.h (173938 => 173939)
--- trunk/Source/_javascript_Core/profiler/ProfileNode.h 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/_javascript_Core/profiler/ProfileNode.h 2014-09-25 00:25:31 UTC (rev 173939)
@@ -56,29 +56,29 @@
struct Call {
public:
- Call(double startTime, double totalTime = NAN)
+ Call(double startTime, double elapsedTime = NAN)
: m_startTime(startTime)
- , m_totalTime(totalTime)
+ , m_elapsedTime(elapsedTime)
{
}
double startTime() const { return m_startTime; }
void setStartTime(double time)
{
- ASSERT_ARG(time, time >= 0.0);
+ ASSERT_ARG(time, time >= 0.0 || isnan(time));
m_startTime = time;
}
- double totalTime() const { return m_totalTime; }
- void setTotalTime(double time)
+ double elapsedTime() const { return m_elapsedTime; }
+ void setElapsedTime(double time)
{
- ASSERT_ARG(time, time >= 0.0);
- m_totalTime = time;
+ ASSERT_ARG(time, time >= 0.0 || isnan(time));
+ m_elapsedTime = time;
}
private:
double m_startTime;
- double m_totalTime;
+ double m_elapsedTime;
};
bool operator==(ProfileNode* node) { return m_callIdentifier == node->callIdentifier(); }
@@ -170,7 +170,7 @@
{
double selfTime = 0.0;
for (const ProfileNode::Call& call : node->calls())
- selfTime += call.totalTime();
+ selfTime += call.elapsedTime();
double totalTime = selfTime;
for (RefPtr<ProfileNode> child : node->children()) {
Modified: trunk/Source/WebCore/ChangeLog (173938 => 173939)
--- trunk/Source/WebCore/ChangeLog 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/WebCore/ChangeLog 2014-09-25 00:25:31 UTC (rev 173939)
@@ -1,3 +1,13 @@
+2014-09-24 Brian J. Burg <[email protected]>
+
+ Web Inspector: subtract elapsed time while debugger is paused from profile nodes
+ https://bugs.webkit.org/show_bug.cgi?id=136796
+
+ Reviewed by Timothy Hatcher.
+
+ * inspector/TimelineRecordFactory.cpp:
+ (WebCore::buildInspectorObject):
+
2014-09-24 Christophe Dumez <[email protected]>
Use is<HTML*Element>() instead of isHTML*Element() - Part 1
Modified: trunk/Source/WebCore/inspector/TimelineRecordFactory.cpp (173938 => 173939)
--- trunk/Source/WebCore/inspector/TimelineRecordFactory.cpp 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/WebCore/inspector/TimelineRecordFactory.cpp 2014-09-25 00:25:31 UTC (rev 173939)
@@ -274,7 +274,7 @@
{
RefPtr<Protocol::Timeline::CPUProfileNodeCall> result = Protocol::Timeline::CPUProfileNodeCall::create()
.setStartTime(call.startTime())
- .setTotalTime(call.totalTime());
+ .setTotalTime(call.elapsedTime());
return result.release();
}
