<!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>[166544] trunk/Source/JavaScriptCore</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/166544">166544</a></dd>
<dt>Author</dt> <dd>mhahnenberg@apple.com</dd>
<dt>Date</dt> <dd>2014-03-31 16:27:29 -0700 (Mon, 31 Mar 2014)</dd>
</dl>
<h3>Log Message</h3>
<pre>Improve GC_LOGGING
https://bugs.webkit.org/show_bug.cgi?id=130988
Reviewed by Geoffrey Garen.
GC_LOGGING can be useful for diagnosing where we're spending our time during collection,
but it doesn't distinguish between Eden and Full collections in the data it gathers. This
patch updates it so that it can. It also adds the process ID to the beginning of each line
of input to be able to distinguish between the output of multiple processes exiting at the
same time.
* heap/Heap.cpp:
(JSC::Heap::collect):</pre>
<h3>Modified Paths</h3>
<ul>
<li><a href="#trunkSourceJavaScriptCoreChangeLog">trunk/Source/JavaScriptCore/ChangeLog</a></li>
<li><a href="#trunkSourceJavaScriptCoreheapHeapcpp">trunk/Source/JavaScriptCore/heap/Heap.cpp</a></li>
</ul>
</div>
<div id="patch">
<h3>Diff</h3>
<a id="trunkSourceJavaScriptCoreChangeLog"></a>
<div class="modfile"><h4>Modified: trunk/Source/JavaScriptCore/ChangeLog (166543 => 166544)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/JavaScriptCore/ChangeLog 2014-03-31 23:23:43 UTC (rev 166543)
+++ trunk/Source/JavaScriptCore/ChangeLog 2014-03-31 23:27:29 UTC (rev 166544)
</span><span class="lines">@@ -1,3 +1,19 @@
</span><ins>+2014-03-31 Mark Hahnenberg <mhahnenberg@apple.com>
+
+ Improve GC_LOGGING
+ https://bugs.webkit.org/show_bug.cgi?id=130988
+
+ Reviewed by Geoffrey Garen.
+
+ GC_LOGGING can be useful for diagnosing where we're spending our time during collection,
+ but it doesn't distinguish between Eden and Full collections in the data it gathers. This
+ patch updates it so that it can. It also adds the process ID to the beginning of each line
+ of input to be able to distinguish between the output of multiple processes exiting at the
+ same time.
+
+ * heap/Heap.cpp:
+ (JSC::Heap::collect):
+
</ins><span class="cx"> 2014-03-31 Dean Jackson <dino@apple.com>
</span><span class="cx">
</span><span class="cx"> Remove WEB_ANIMATIONS
</span></span></pre></div>
<a id="trunkSourceJavaScriptCoreheapHeapcpp"></a>
<div class="modfile"><h4>Modified: trunk/Source/JavaScriptCore/heap/Heap.cpp (166543 => 166544)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/JavaScriptCore/heap/Heap.cpp 2014-03-31 23:23:43 UTC (rev 166543)
+++ trunk/Source/JavaScriptCore/heap/Heap.cpp 2014-03-31 23:27:29 UTC (rev 166544)
</span><span class="lines">@@ -49,6 +49,7 @@
</span><span class="cx"> #include <algorithm>
</span><span class="cx"> #include <wtf/RAMSize.h>
</span><span class="cx"> #include <wtf/CurrentTime.h>
</span><ins>+#include <wtf/ProcessID.h>
</ins><span class="cx">
</span><span class="cx"> using namespace std;
</span><span class="cx"> using namespace JSC;
</span><span class="lines">@@ -77,42 +78,81 @@
</span><span class="cx">
</span><span class="cx"> struct GCTimer {
</span><span class="cx"> GCTimer(const char* name)
</span><del>- : m_time(0)
- , m_min(100000000)
- , m_max(0)
- , m_count(0)
- , m_name(name)
</del><ins>+ : m_name(name)
</ins><span class="cx"> {
</span><span class="cx"> }
</span><span class="cx"> ~GCTimer()
</span><span class="cx"> {
</span><del>- dataLogF("%s: %.2lfms (avg. %.2lf, min. %.2lf, max. %.2lf)\n", m_name, m_time * 1000, m_time * 1000 / m_count, m_min*1000, m_max*1000);
</del><ins>+ logData(m_allCollectionData, "(All)");
+ logData(m_edenCollectionData, "(Eden)");
+ logData(m_fullCollectionData, "(Full)");
</ins><span class="cx"> }
</span><del>- double m_time;
- double m_min;
- double m_max;
- size_t m_count;
</del><ins>+
+ struct TimeRecord {
+ TimeRecord()
+ : m_time(0)
+ , m_min(std::numeric_limits<double>::infinity())
+ , m_max(0)
+ , m_count(0)
+ {
+ }
+
+ double m_time;
+ double m_min;
+ double m_max;
+ size_t m_count;
+ };
+
+ void logData(const TimeRecord& data, const char* extra)
+ {
+ dataLogF("[%d] %s %s: %.2lfms (avg. %.2lf, min. %.2lf, max. %.2lf, count %lu)\n",
+ getCurrentProcessID(),
+ m_name, extra,
+ data.m_time * 1000,
+ data.m_time * 1000 / data.m_count,
+ data.m_min * 1000,
+ data.m_max * 1000,
+ data.m_count);
+ }
+
+ void updateData(TimeRecord& data, double duration)
+ {
+ if (duration < data.m_min)
+ data.m_min = duration;
+ if (duration > data.m_max)
+ data.m_max = duration;
+ data.m_count++;
+ data.m_time += duration;
+ }
+
+ void didFinishPhase(HeapOperation collectionType, double duration)
+ {
+ TimeRecord& data = collectionType == EdenCollection ? m_edenCollectionData : m_fullCollectionData;
+ updateData(data, duration);
+ updateData(m_allCollectionData, duration);
+ }
+
+ TimeRecord m_allCollectionData;
+ TimeRecord m_fullCollectionData;
+ TimeRecord m_edenCollectionData;
</ins><span class="cx"> const char* m_name;
</span><span class="cx"> };
</span><span class="cx">
</span><span class="cx"> struct GCTimerScope {
</span><del>- GCTimerScope(GCTimer* timer)
</del><ins>+ GCTimerScope(GCTimer* timer, HeapOperation collectionType)
</ins><span class="cx"> : m_timer(timer)
</span><span class="cx"> , m_start(WTF::monotonicallyIncreasingTime())
</span><ins>+ , m_collectionType(collectionType)
</ins><span class="cx"> {
</span><span class="cx"> }
</span><span class="cx"> ~GCTimerScope()
</span><span class="cx"> {
</span><span class="cx"> double delta = WTF::monotonicallyIncreasingTime() - m_start;
</span><del>- if (delta < m_timer->m_min)
- m_timer->m_min = delta;
- if (delta > m_timer->m_max)
- m_timer->m_max = delta;
- m_timer->m_count++;
- m_timer->m_time += delta;
</del><ins>+ m_timer->didFinishPhase(m_collectionType, delta);
</ins><span class="cx"> }
</span><span class="cx"> GCTimer* m_timer;
</span><span class="cx"> double m_start;
</span><ins>+ HeapOperation m_collectionType;
</ins><span class="cx"> };
</span><span class="cx">
</span><span class="cx"> struct GCCounter {
</span><span class="lines">@@ -136,7 +176,7 @@
</span><span class="cx"> }
</span><span class="cx"> ~GCCounter()
</span><span class="cx"> {
</span><del>- dataLogF("%s: %zu values (avg. %zu, min. %zu, max. %zu)\n", m_name, m_total, m_total / m_count, m_min, m_max);
</del><ins>+ dataLogF("[%d] %s: %zu values (avg. %zu, min. %zu, max. %zu)\n", getCurrentProcessID(), m_name, m_total, m_total / m_count, m_min, m_max);
</ins><span class="cx"> }
</span><span class="cx"> const char* m_name;
</span><span class="cx"> size_t m_count;
</span><span class="lines">@@ -145,14 +185,12 @@
</span><span class="cx"> size_t m_max;
</span><span class="cx"> };
</span><span class="cx">
</span><del>-#define GCPHASE(name) DEFINE_GC_LOGGING_GLOBAL(GCTimer, name##Timer, (#name)); GCTimerScope name##TimerScope(&name##Timer)
-#define COND_GCPHASE(cond, name1, name2) DEFINE_GC_LOGGING_GLOBAL(GCTimer, name1##Timer, (#name1)); DEFINE_GC_LOGGING_GLOBAL(GCTimer, name2##Timer, (#name2)); GCTimerScope name1##CondTimerScope(cond ? &name1##Timer : &name2##Timer)
</del><ins>+#define GCPHASE(name) DEFINE_GC_LOGGING_GLOBAL(GCTimer, name##Timer, (#name)); GCTimerScope name##TimerScope(&name##Timer, m_operationInProgress)
</ins><span class="cx"> #define GCCOUNTER(name, value) do { DEFINE_GC_LOGGING_GLOBAL(GCCounter, name##Counter, (#name)); name##Counter.count(value); } while (false)
</span><span class="cx">
</span><span class="cx"> #else
</span><span class="cx">
</span><span class="cx"> #define GCPHASE(name) do { } while (false)
</span><del>-#define COND_GCPHASE(cond, name1, name2) do { } while (false)
</del><span class="cx"> #define GCCOUNTER(name, value) do { } while (false)
</span><span class="cx"> #endif
</span><span class="cx">
</span><span class="lines">@@ -887,7 +925,6 @@
</span><span class="cx"> SamplingRegion samplingRegion("Garbage Collection");
</span><span class="cx">
</span><span class="cx"> RELEASE_ASSERT(!m_deferralDepth);
</span><del>- GCPHASE(Collect);
</del><span class="cx"> ASSERT(vm()->currentThreadIsHoldingAPILock());
</span><span class="cx"> RELEASE_ASSERT(vm()->atomicStringTable() == wtfThreadData().atomicStringTable());
</span><span class="cx"> ASSERT(m_isSafeToCollect);
</span><span class="lines">@@ -896,6 +933,7 @@
</span><span class="cx">
</span><span class="cx"> suspendCompilerThreads();
</span><span class="cx"> willStartCollection(collectionType);
</span><ins>+ GCPHASE(Collect);
</ins><span class="cx">
</span><span class="cx"> double gcStartTime = WTF::monotonicallyIncreasingTime();
</span><span class="cx">
</span></span></pre>
</div>
</div>
</body>
</html>