<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN"
"http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head><meta http-equiv="content-type" content="text/html; charset=utf-8" />
<title>[173939] trunk/Source</title>
</head>
<body>
<style type="text/css"><!--
#msg dl.meta { border: 1px #006 solid; background: #369; padding: 6px; color: #fff; }
#msg dl.meta dt { float: left; width: 6em; font-weight: bold; }
#msg dt:after { content:':';}
#msg dl, #msg dt, #msg ul, #msg li, #header, #footer, #logmsg { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; }
#msg dl a { font-weight: bold}
#msg dl a:link { color:#fc3; }
#msg dl a:active { color:#ff0; }
#msg dl a:visited { color:#cc6; }
h3 { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; font-weight: bold; }
#msg pre { overflow: auto; background: #ffc; border: 1px #fa0 solid; padding: 6px; }
#logmsg { background: #ffc; border: 1px #fa0 solid; padding: 1em 1em 0 1em; }
#logmsg p, #logmsg pre, #logmsg blockquote { margin: 0 0 1em 0; }
#logmsg p, #logmsg li, #logmsg dt, #logmsg dd { line-height: 14pt; }
#logmsg h1, #logmsg h2, #logmsg h3, #logmsg h4, #logmsg h5, #logmsg h6 { margin: .5em 0; }
#logmsg h1:first-child, #logmsg h2:first-child, #logmsg h3:first-child, #logmsg h4:first-child, #logmsg h5:first-child, #logmsg h6:first-child { margin-top: 0; }
#logmsg ul, #logmsg ol { padding: 0; list-style-position: inside; margin: 0 0 0 1em; }
#logmsg ul { text-indent: -1em; padding-left: 1em; }#logmsg ol { text-indent: -1.5em; padding-left: 1.5em; }
#logmsg > ul, #logmsg > ol { margin: 0 0 1em 0; }
#logmsg pre { background: #eee; padding: 1em; }
#logmsg blockquote { border: 1px solid #fa0; border-left-width: 10px; padding: 1em 1em 0 1em; background: white;}
#logmsg dl { margin: 0; }
#logmsg dt { font-weight: bold; }
#logmsg dd { margin: 0; padding: 0 0 0.5em 0; }
#logmsg dd:before { content:'\00bb';}
#logmsg table { border-spacing: 0px; border-collapse: collapse; border-top: 4px solid #fa0; border-bottom: 1px solid #fa0; background: #fff; }
#logmsg table th { text-align: left; font-weight: normal; padding: 0.2em 0.5em; border-top: 1px dotted #fa0; }
#logmsg table td { text-align: right; border-top: 1px dotted #fa0; padding: 0.2em 0.5em; }
#logmsg table thead th { text-align: center; border-bottom: 1px solid #fa0; }
#logmsg table th.Corner { text-align: left; }
#logmsg hr { border: none 0; border-top: 2px dashed #fa0; height: 1px; }
#header, #footer { color: #fff; background: #636; border: 1px #300 solid; padding: 6px; }
#patch { width: 100%; }
#patch h4 {font-family: verdana,arial,helvetica,sans-serif;font-size:10pt;padding:8px;background:#369;color:#fff;margin:0;}
#patch .propset h4, #patch .binary h4 {margin:0;}
#patch pre {padding:0;line-height:1.2em;margin:0;}
#patch .diff {width:100%;background:#eee;padding: 0 0 10px 0;overflow:auto;}
#patch .propset .diff, #patch .binary .diff {padding:10px 0;}
#patch span {display:block;padding:0 10px;}
#patch .modfile, #patch .addfile, #patch .delfile, #patch .propset, #patch .binary, #patch .copfile {border:1px solid #ccc;margin:10px 0;}
#patch ins {background:#dfd;text-decoration:none;display:block;padding:0 10px;}
#patch del {background:#fdd;text-decoration:none;display:block;padding:0 10px;}
#patch .lines, .info {color:#888;background:#fff;}
--></style>
<div id="msg">
<dl class="meta">
<dt>Revision</dt> <dd><a href="http://trac.webkit.org/projects/webkit/changeset/173939">173939</a></dd>
<dt>Author</dt> <dd>burg@cs.washington.edu</dd>
<dt>Date</dt> <dd>2014-09-24 17:25:31 -0700 (Wed, 24 Sep 2014)</dd>
</dl>
<h3>Log Message</h3>
<pre>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/JavaScriptCore:
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):</pre>
<h3>Modified Paths</h3>
<ul>
<li><a href="#trunkSourceJavaScriptCoreChangeLog">trunk/Source/JavaScriptCore/ChangeLog</a></li>
<li><a href="#trunkSourceJavaScriptCoreprofilerProfileGeneratorcpp">trunk/Source/JavaScriptCore/profiler/ProfileGenerator.cpp</a></li>
<li><a href="#trunkSourceJavaScriptCoreprofilerProfileGeneratorh">trunk/Source/JavaScriptCore/profiler/ProfileGenerator.h</a></li>
<li><a href="#trunkSourceJavaScriptCoreprofilerProfileNodeh">trunk/Source/JavaScriptCore/profiler/ProfileNode.h</a></li>
<li><a href="#trunkSourceWebCoreChangeLog">trunk/Source/WebCore/ChangeLog</a></li>
<li><a href="#trunkSourceWebCoreinspectorTimelineRecordFactorycpp">trunk/Source/WebCore/inspector/TimelineRecordFactory.cpp</a></li>
</ul>
</div>
<div id="patch">
<h3>Diff</h3>
<a id="trunkSourceJavaScriptCoreChangeLog"></a>
<div class="modfile"><h4>Modified: trunk/Source/JavaScriptCore/ChangeLog (173938 => 173939)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/JavaScriptCore/ChangeLog 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/JavaScriptCore/ChangeLog 2014-09-25 00:25:31 UTC (rev 173939)
</span><span class="lines">@@ -1,3 +1,34 @@
</span><ins>+2014-09-24 Brian J. Burg <burg@cs.washington.edu>
+
+ 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.
+
</ins><span class="cx"> 2014-09-24 Commit Queue <commit-queue@webkit.org>
</span><span class="cx">
</span><span class="cx"> Unreviewed, rolling out r173839.
</span></span></pre></div>
<a id="trunkSourceJavaScriptCoreprofilerProfileGeneratorcpp"></a>
<div class="modfile"><h4>Modified: trunk/Source/JavaScriptCore/profiler/ProfileGenerator.cpp (173938 => 173939)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/JavaScriptCore/profiler/ProfileGenerator.cpp 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/JavaScriptCore/profiler/ProfileGenerator.cpp 2014-09-25 00:25:31 UTC (rev 173939)
</span><span class="lines">@@ -48,11 +48,11 @@
</span><span class="cx"> ProfileGenerator::ProfileGenerator(ExecState* exec, const String& title, unsigned uid)
</span><span class="cx"> : m_origin(exec ? exec->lexicalGlobalObject() : nullptr)
</span><span class="cx"> , m_profileGroup(exec ? exec->lexicalGlobalObject()->profileGroup() : 0)
</span><ins>+ , m_debuggerPausedTimestamp(NAN)
</ins><span class="cx"> , m_foundConsoleStartParent(false)
</span><del>- , m_debuggerPaused(false)
</del><span class="cx"> {
</span><span class="cx"> if (Debugger* debugger = exec->lexicalGlobalObject()->debugger())
</span><del>- m_debuggerPaused = debugger->isPaused();
</del><ins>+ m_debuggerPausedTimestamp = debugger->isPaused() ? currentTime() : NAN;
</ins><span class="cx">
</span><span class="cx"> m_profile = Profile::create(title, uid);
</span><span class="cx"> m_currentNode = m_rootNode = m_profile->rootNode();
</span><span class="lines">@@ -118,6 +118,12 @@
</span><span class="cx">
</span><span class="cx"> if (isnan(startTime))
</span><span class="cx"> startTime = currentTime();
</span><ins>+
+ // 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;
+
</ins><span class="cx"> node->appendCall(ProfileNode::Call(startTime));
</span><span class="cx"> }
</span><span class="cx">
</span><span class="lines">@@ -126,9 +132,23 @@
</span><span class="cx"> ASSERT_ARG(node, node);
</span><span class="cx">
</span><span class="cx"> ProfileNode::Call& last = node->lastCall();
</span><del>- ASSERT(isnan(last.totalTime()));
</del><span class="cx">
</span><del>- last.setTotalTime(m_debuggerPaused ? 0.0 : currentTime() - last.startTime());
</del><ins>+ // 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);
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> void ProfileGenerator::willExecute(ExecState* callerCallFrame, const CallIdentifier& callIdentifier)
</span><span class="lines">@@ -196,6 +216,33 @@
</span><span class="cx"> }
</span><span class="cx"> }
</span><span class="cx">
</span><ins>+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;
+}
+
</ins><span class="cx"> void ProfileGenerator::stopProfiling()
</span><span class="cx"> {
</span><span class="cx"> for (ProfileNode* node = m_currentNode.get(); node != m_profile->rootNode(); node = node->parent())
</span></span></pre></div>
<a id="trunkSourceJavaScriptCoreprofilerProfileGeneratorh"></a>
<div class="modfile"><h4>Modified: trunk/Source/JavaScriptCore/profiler/ProfileGenerator.h (173938 => 173939)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/JavaScriptCore/profiler/ProfileGenerator.h 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/JavaScriptCore/profiler/ProfileGenerator.h 2014-09-25 00:25:31 UTC (rev 173939)
</span><span class="lines">@@ -54,8 +54,8 @@
</span><span class="cx"> void didExecute(ExecState* callerCallFrame, const CallIdentifier&);
</span><span class="cx"> void exceptionUnwind(ExecState* handlerCallFrame, const CallIdentifier&);
</span><span class="cx">
</span><del>- void didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&) { m_debuggerPaused = true; }
- void didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&) { m_debuggerPaused = false; }
</del><ins>+ void didPause(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
+ void didContinue(PassRefPtr<DebuggerCallFrame>, const CallIdentifier&);
</ins><span class="cx">
</span><span class="cx"> void stopProfiling();
</span><span class="cx">
</span><span class="lines">@@ -74,10 +74,11 @@
</span><span class="cx"> RefPtr<Profile> m_profile;
</span><span class="cx"> JSGlobalObject* m_origin;
</span><span class="cx"> unsigned m_profileGroup;
</span><ins>+ // Timestamp is set to NAN when the debugger is not currently paused.
+ double m_debuggerPausedTimestamp;
</ins><span class="cx"> RefPtr<ProfileNode> m_rootNode;
</span><span class="cx"> RefPtr<ProfileNode> m_currentNode;
</span><span class="cx"> bool m_foundConsoleStartParent;
</span><del>- bool m_debuggerPaused;
</del><span class="cx"> };
</span><span class="cx">
</span><span class="cx"> } // namespace JSC
</span></span></pre></div>
<a id="trunkSourceJavaScriptCoreprofilerProfileNodeh"></a>
<div class="modfile"><h4>Modified: trunk/Source/JavaScriptCore/profiler/ProfileNode.h (173938 => 173939)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/JavaScriptCore/profiler/ProfileNode.h 2014-09-24 23:29:35 UTC (rev 173938)
+++ trunk/Source/JavaScriptCore/profiler/ProfileNode.h 2014-09-25 00:25:31 UTC (rev 173939)
</span><span class="lines">@@ -56,29 +56,29 @@
</span><span class="cx">
</span><span class="cx"> struct Call {
</span><span class="cx"> public:
</span><del>- Call(double startTime, double totalTime = NAN)
</del><ins>+ Call(double startTime, double elapsedTime = NAN)
</ins><span class="cx"> : m_startTime(startTime)
</span><del>- , m_totalTime(totalTime)
</del><ins>+ , m_elapsedTime(elapsedTime)
</ins><span class="cx"> {
</span><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> double startTime() const { return m_startTime; }
</span><span class="cx"> void setStartTime(double time)
</span><span class="cx"> {
</span><del>- ASSERT_ARG(time, time >= 0.0);
</del><ins>+ ASSERT_ARG(time, time >= 0.0 || isnan(time));
</ins><span class="cx"> m_startTime = time;
</span><span class="cx"> }
</span><span class="cx">
</span><del>- double totalTime() const { return m_totalTime; }
- void setTotalTime(double time)
</del><ins>+ double elapsedTime() const { return m_elapsedTime; }
+ void setElapsedTime(double time)
</ins><span class="cx"> {
</span><del>- ASSERT_ARG(time, time >= 0.0);
- m_totalTime = time;
</del><ins>+ ASSERT_ARG(time, time >= 0.0 || isnan(time));
+ m_elapsedTime = time;
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> private:
</span><span class="cx"> double m_startTime;
</span><del>- double m_totalTime;
</del><ins>+ double m_elapsedTime;
</ins><span class="cx"> };
</span><span class="cx">
</span><span class="cx"> bool operator==(ProfileNode* node) { return m_callIdentifier == node->callIdentifier(); }
</span><span class="lines">@@ -170,7 +170,7 @@
</span><span class="cx"> {
</span><span class="cx"> double selfTime = 0.0;
</span><span class="cx"> for (const ProfileNode::Call& call : node->calls())
</span><del>- selfTime += call.totalTime();
</del><ins>+ selfTime += call.elapsedTime();
</ins><span class="cx">
</span><span class="cx"> double totalTime = selfTime;
</span><span class="cx"> for (RefPtr<ProfileNode> child : node->children()) {
</span></span></pre></div>
<a id="trunkSourceWebCoreChangeLog"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebCore/ChangeLog (173938 => 173939)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -1,3 +1,13 @@
</span><ins>+2014-09-24 Brian J. Burg <burg@cs.washington.edu>
+
+ 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):
+
</ins><span class="cx"> 2014-09-24 Christophe Dumez <cdumez@apple.com>
</span><span class="cx">
</span><span class="cx"> Use is<HTML*Element>() instead of isHTML*Element() - Part 1
</span></span></pre></div>
<a id="trunkSourceWebCoreinspectorTimelineRecordFactorycpp"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebCore/inspector/TimelineRecordFactory.cpp (173938 => 173939)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -274,7 +274,7 @@
</span><span class="cx"> {
</span><span class="cx"> RefPtr<Protocol::Timeline::CPUProfileNodeCall> result = Protocol::Timeline::CPUProfileNodeCall::create()
</span><span class="cx"> .setStartTime(call.startTime())
</span><del>- .setTotalTime(call.totalTime());
</del><ins>+ .setTotalTime(call.elapsedTime());
</ins><span class="cx"> return result.release();
</span><span class="cx"> }
</span><span class="cx">
</span></span></pre>
</div>
</div>
</body>
</html>