aboutsummaryrefslogtreecommitdiffhomepage
path: root/tools
diff options
context:
space:
mode:
authorGravatar Craig Tiller <craig.tiller@gmail.com>2015-05-06 10:20:53 -0700
committerGravatar Craig Tiller <craig.tiller@gmail.com>2015-05-06 10:20:53 -0700
commit78193bf0350069ae67993ce7fa3ee516e9f9fe66 (patch)
tree92ea4d5128627935e05a83efc469a1de0ec11845 /tools
parent999971dbf78d182731c5fb0459260a3296069ded (diff)
parent5b2ea2979b9fe27cf50d60325ad8a3ae26d46cf6 (diff)
Merge pull request #1491 from dgquintas/important_mark_analysis
Added support for important mark (!) analysis.
Diffstat (limited to 'tools')
-rwxr-xr-xtools/profile_analyzer/profile_analyzer.py56
1 files changed, 54 insertions, 2 deletions
diff --git a/tools/profile_analyzer/profile_analyzer.py b/tools/profile_analyzer/profile_analyzer.py
index f15277491f..00b1079466 100755
--- a/tools/profile_analyzer/profile_analyzer.py
+++ b/tools/profile_analyzer/profile_analyzer.py
@@ -38,19 +38,43 @@ Usage:
import collections
+import itertools
import re
import sys
# Create a regex to parse output of the C core basic profiler,
# as defined in src/core/profiling/basic_timers.c.
_RE_LINE = re.compile(r'GRPC_LAT_PROF ' +
- r'([0-9]+\.[0-9]+) 0x([0-9a-f]+) ([{}.]) ([0-9]+) ' +
+ r'([0-9]+\.[0-9]+) 0x([0-9a-f]+) ([{}.!]) ([0-9]+) ' +
r'([^ ]+) ([^ ]+) ([0-9]+)')
Entry = collections.namedtuple(
'Entry',
['time', 'thread', 'type', 'tag', 'id', 'file', 'line'])
+
+class ImportantMark(object):
+ def __init__(self, entry, stack):
+ self._entry = entry
+ self._pre_stack = stack
+ self._post_stack = list()
+ self._n = len(stack) # we'll also compute times to that many closing }s
+
+ @property
+ def entry(self):
+ return self._entry
+
+ def append_post_entry(self, entry):
+ if self._n > 0:
+ self._post_stack.append(entry)
+ self._n -= 1
+
+ def get_deltas(self):
+ pre_and_post_stacks = itertools.chain(self._pre_stack, self._post_stack)
+ return collections.OrderedDict((stack_entry,
+ (self._entry.time - stack_entry.time))
+ for stack_entry in pre_and_post_stacks)
+
def entries():
for line in sys.stdin:
m = _RE_LINE.match(line)
@@ -66,13 +90,27 @@ def entries():
threads = collections.defaultdict(lambda: collections.defaultdict(list))
times = collections.defaultdict(list)
+# Indexed by the mark's tag. Items in the value list correspond to the mark in
+# different stack situations.
+important_marks = collections.defaultdict(list)
+
for entry in entries():
thread = threads[entry.thread]
if entry.type == '{':
thread[entry.tag].append(entry)
+ if entry.type == '!':
+ # Save a snapshot of the current stack inside a new ImportantMark instance.
+ # Get all entries with type '{' from "thread".
+ stack = [e for entries_for_tag in thread.values()
+ for e in entries_for_tag if e.type == '{']
+ important_marks[entry.tag].append(ImportantMark(entry, stack))
elif entry.type == '}':
last = thread[entry.tag].pop()
times[entry.tag].append(entry.time - last.time)
+ # Update accounting for important marks.
+ for imarks_for_tag in important_marks.itervalues():
+ for imark in imarks_for_tag:
+ imark.append_post_entry(entry)
def percentile(vals, pct):
return sorted(vals)[int(len(vals) * pct / 100.0)]
@@ -80,8 +118,22 @@ def percentile(vals, pct):
print 'tag 50%/90%/95%/99% us'
for tag in sorted(times.keys()):
vals = times[tag]
- print '%d %.2f/%.2f/%.2f/%.2f' % (tag,
+ print '%d %.2f/%.2f/%.2f/%.2f' % (tag,
percentile(vals, 50),
percentile(vals, 90),
percentile(vals, 95),
percentile(vals, 99))
+
+print
+print 'Important marks:'
+print '================'
+for tag, imark_for_tag in important_marks.iteritems():
+ for imark in imarks_for_tag:
+ deltas = imark.get_deltas()
+ print '{tag} @ {file}:{line}'.format(**imark.entry._asdict())
+ for entry, time_delta_us in deltas.iteritems():
+ format_dict = entry._asdict()
+ format_dict['time_delta_us'] = time_delta_us
+ print '{tag} {type} ({file}:{line}): {time_delta_us:12.3f} us'.format(
+ **format_dict)
+ print