Modified: trunk/Source/_javascript_Core/heap/Heap.cpp (181820 => 181821)
--- trunk/Source/_javascript_Core/heap/Heap.cpp 2015-03-21 00:07:17 UTC (rev 181820)
+++ trunk/Source/_javascript_Core/heap/Heap.cpp 2015-03-21 02:02:44 UTC (rev 181821)
@@ -80,115 +80,125 @@
struct GCTimer {
GCTimer(const char* name)
- : m_name(name)
+ : name(name)
{
}
~GCTimer()
{
- logData(m_allCollectionData, "(All)");
- logData(m_edenCollectionData, "(Eden)");
- logData(m_fullCollectionData, "(Full)");
+ logData(allCollectionData, "(All)");
+ logData(edenCollectionData, "(Eden)");
+ logData(fullCollectionData, "(Full)");
}
struct TimeRecord {
TimeRecord()
- : m_time(0)
- , m_min(std::numeric_limits<double>::infinity())
- , m_max(0)
- , m_count(0)
+ : time(0)
+ , min(std::numeric_limits<double>::infinity())
+ , max(0)
+ , count(0)
{
}
- double m_time;
- double m_min;
- double m_max;
- size_t m_count;
+ double time;
+ double min;
+ double max;
+ size_t count;
};
void logData(const TimeRecord& data, const char* extra)
{
- dataLogF("[%d] %s %s: %.2lfms (avg. %.2lf, min. %.2lf, max. %.2lf, count %lu)\n",
+ dataLogF("[%d] %s (Parent: %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);
+ name,
+ parent ? parent->name : "nullptr",
+ extra,
+ data.time * 1000,
+ data.time * 1000 / data.count,
+ data.min * 1000,
+ data.max * 1000,
+ data.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;
+ if (duration < data.min)
+ data.min = duration;
+ if (duration > data.max)
+ data.max = duration;
+ data.count++;
+ data.time += duration;
}
void didFinishPhase(HeapOperation collectionType, double duration)
{
- TimeRecord& data = "" == EdenCollection ? m_edenCollectionData : m_fullCollectionData;
+ TimeRecord& data = "" == EdenCollection ? edenCollectionData : fullCollectionData;
updateData(data, duration);
- updateData(m_allCollectionData, duration);
+ updateData(allCollectionData, duration);
}
- TimeRecord m_allCollectionData;
- TimeRecord m_fullCollectionData;
- TimeRecord m_edenCollectionData;
- const char* m_name;
+ static GCTimer* s_currentGlobalTimer;
+
+ TimeRecord allCollectionData;
+ TimeRecord fullCollectionData;
+ TimeRecord edenCollectionData;
+ const char* name;
+ GCTimer* parent { nullptr };
};
+GCTimer* GCTimer::s_currentGlobalTimer = nullptr;
+
struct GCTimerScope {
- GCTimerScope(GCTimer* timer, HeapOperation collectionType)
- : m_timer(timer)
- , m_start(WTF::monotonicallyIncreasingTime())
- , m_collectionType(collectionType)
+ GCTimerScope(GCTimer& timer, HeapOperation collectionType)
+ : timer(timer)
+ , start(WTF::monotonicallyIncreasingTime())
+ , collectionType(collectionType)
{
+ timer.parent = GCTimer::s_currentGlobalTimer;
+ GCTimer::s_currentGlobalTimer = &timer;
}
~GCTimerScope()
{
- double delta = WTF::monotonicallyIncreasingTime() - m_start;
- m_timer->didFinishPhase(m_collectionType, delta);
+ double delta = WTF::monotonicallyIncreasingTime() - start;
+ timer.didFinishPhase(collectionType, delta);
+ GCTimer::s_currentGlobalTimer = timer.parent;
}
- GCTimer* m_timer;
- double m_start;
- HeapOperation m_collectionType;
+ GCTimer& timer;
+ double start;
+ HeapOperation collectionType;
};
struct GCCounter {
GCCounter(const char* name)
- : m_name(name)
- , m_count(0)
- , m_total(0)
- , m_min(10000000)
- , m_max(0)
+ : name(name)
+ , count(0)
+ , total(0)
+ , min(10000000)
+ , max(0)
{
}
- void count(size_t amount)
+ void add(size_t amount)
{
- m_count++;
- m_total += amount;
- if (amount < m_min)
- m_min = amount;
- if (amount > m_max)
- m_max = amount;
+ count++;
+ total += amount;
+ if (amount < min)
+ min = amount;
+ if (amount > max)
+ max = amount;
}
~GCCounter()
{
- 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);
+ dataLogF("[%d] %s: %zu values (avg. %zu, min. %zu, max. %zu)\n", getCurrentProcessID(), name, total, total / count, min, max);
}
- const char* m_name;
- size_t m_count;
- size_t m_total;
- size_t m_min;
- size_t m_max;
+ const char* name;
+ size_t count;
+ size_t total;
+ size_t min;
+ size_t max;
};
-#define GCPHASE(name) DEFINE_GC_LOGGING_GLOBAL(GCTimer, name##Timer, (#name)); GCTimerScope name##TimerScope(&name##Timer, m_operationInProgress)
-#define GCCOUNTER(name, value) do { DEFINE_GC_LOGGING_GLOBAL(GCCounter, name##Counter, (#name)); name##Counter.count(value); } while (false)
+#define GCPHASE(name) DEFINE_GC_LOGGING_GLOBAL(GCTimer, name##Timer, (#name)); GCTimerScope name##TimerScope(name##Timer, m_operationInProgress)
+#define GCCOUNTER(name, value) do { DEFINE_GC_LOGGING_GLOBAL(GCCounter, name##Counter, (#name)); name##Counter.add(value); } while (false)
#else
Added: trunk/Tools/Scripts/parse-gc-phase-timings (0 => 181821)
--- trunk/Tools/Scripts/parse-gc-phase-timings (rev 0)
+++ trunk/Tools/Scripts/parse-gc-phase-timings 2015-03-21 02:02:44 UTC (rev 181821)
@@ -0,0 +1,131 @@
+#!/usr/bin/env python
+
+# Copyright (C) 2015 Mark Hahnenberg. 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 INC. 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 INC. 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.
+
+import fileinput
+import re
+
+TIMING_REGEX = re.compile(
+ r'^\[(?P<pid>[0-9]+)\] '
+ '(?P<name>[^ ]+) '
+ '\(Parent: (?P<parent>[^\)]+)\) '
+ '\((?P<collect_type>[^\)]+)\): '
+ '(?P<total_time>[0-9]+\.[0-9]+)ms '
+ '\(avg. (?P<avg_time>[^,]+), '
+ 'min. (?P<min_time>[^,]+), '
+ 'max. (?P<max_time>[^,]+), '
+ 'count (?P<count>[^\)]+)\)')
+
+class Timing(object):
+ def __init__(self, pid, name, parent, collect_type, total_time, avg_time, min_time, max_time, count):
+ self.pid = int(pid)
+ self.name = str(name)
+ self.parent = str(parent)
+ self.collect_type = str(collect_type)
+ self.total_time = float(total_time)
+ self.avg_time = float(avg_time)
+ self.min_time = float(min_time)
+ self.max_time = float(max_time)
+ self.count = int(count)
+ self.children = []
+
+ def __unicode__(self):
+ return u"%s - %s total: %.2f, avg: %.2f" % (self.name, self.collect_type, self.total_time, self.avg_time)
+
+ def __str__(self):
+ return "%s - %s total: %.2f, avg: %.2f" % (self.name, self.collect_type, self.total_time, self.avg_time)
+
+ def __repr__(self):
+ return "%s - %s total: %.2f, avg: %.2f" % (self.name, self.collect_type, self.total_time, self.avg_time)
+
+
+def parse_input():
+ timings = []
+ for line in fileinput.input():
+ result = TIMING_REGEX.match(line)
+ if result is None:
+ continue
+ timings.append(Timing(
+ result.group('pid'),
+ result.group('name'),
+ result.group('parent'),
+ result.group('collect_type'),
+ result.group('total_time'),
+ result.group('avg_time'),
+ result.group('min_time'),
+ result.group('max_time'),
+ result.group('count'),
+ ))
+ return timings
+
+
+def print_timing_node(root, timings, tabs):
+ for _ in range(tabs):
+ print " ",
+ percent_time = 1.0
+ if root.parent is not None:
+ percent_time = float(root.total_time) / float(root.parent.total_time)
+ print "%s - %.2f%%" % (str(root), percent_time * 100.0)
+ for child in reversed(sorted(root.children, key=lambda t: t.total_time)):
+ if child.parent != root:
+ continue
+ if child.collect_type != root.collect_type:
+ continue
+ print_timing_node(child, timings, tabs + 1)
+
+
+def print_timing_tree(timings):
+ timings.sort(key=lambda t: t.total_time)
+ timings.reverse()
+ collection_types = ["All", "Eden", "Full"]
+ for collect_type in collection_types:
+ for timing in timings:
+ if timing.collect_type != collect_type:
+ continue
+ if timing.parent is not None:
+ continue
+ print_timing_node(timing, timings, 0)
+ print ""
+
+
+def link_parents(timings):
+ for timing in timings:
+ if timing.parent == "nullptr":
+ timing.parent = None
+ continue
+ for parent in timings:
+ if timing.parent != parent.name:
+ continue
+ if timing.collect_type != parent.collect_type:
+ continue
+ timing.parent = parent
+ parent.children.append(timing)
+
+def main():
+ timings = parse_input()
+ link_parents(timings)
+ print_timing_tree(timings)
+
+if __name__ == "__main__":
+ main()
Property changes on: trunk/Tools/Scripts/parse-gc-phase-timings
___________________________________________________________________
