diff --git a/.gitignore b/.gitignore index 18b42811b28..bfbc3934649 100644 --- a/.gitignore +++ b/.gitignore @@ -37,10 +37,11 @@ cache.mk # Temporary test reports report.xml +latency_trace.txt # port server log portlog.txt # gyp generated make files *-gyp.mk -out \ No newline at end of file +out diff --git a/tools/profile_analyzer/profile_analyzer.py b/tools/profiling/latency_profile/profile_analyzer.py similarity index 86% rename from tools/profile_analyzer/profile_analyzer.py rename to tools/profiling/latency_profile/profile_analyzer.py index 259bbb08a31..175b1859354 100755 --- a/tools/profile_analyzer/profile_analyzer.py +++ b/tools/profiling/latency_profile/profile_analyzer.py @@ -1,4 +1,5 @@ #!/usr/bin/env python2.7 +import argparse import collections import hashlib import itertools @@ -15,6 +16,11 @@ TIME_FROM_STACK_START = object() TIME_TO_STACK_END = object() +argp = argparse.ArgumentParser(description='Process output of basic_prof builds') +argp.add_argument('--source', default='latency_trace.txt', type=str) +argp.add_argument('--fmt', choices=tabulate.tabulate_formats, default='simple') +args = argp.parse_args() + class LineItem(object): def __init__(self, line, indent): @@ -117,10 +123,9 @@ class CallStack(object): builder = collections.defaultdict(CallStackBuilder) call_stacks = collections.defaultdict(CallStack) -print 'Loading...' lines = 0 start = time.time() -with open('latency_trace.txt') as f: +with open(args.source) as f: for line in f: lines += 1 inf = json.loads(line) @@ -133,14 +138,13 @@ with open('latency_trace.txt') as f: call_stacks[cs.signature] = CallStack(cs) del builder[thd] time_taken = time.time() - start -print 'Read %d lines in %f seconds (%f lines/sec)' % (lines, time_taken, lines / time_taken) -print 'Analyzing...' call_stacks = sorted(call_stacks.values(), key=lambda cs: cs.count, reverse=True) +total_stacks = 0 for cs in call_stacks: + total_stacks += cs.count cs.finish() -print 'Writing report...' def percentile(N, percent, key=lambda x:x): """ Find the percentile of a list of values. @@ -191,8 +195,23 @@ FORMAT = [ ('TO_SCOPE_END', time_format(TIME_TO_SCOPE_END)), ] +BANNER = { + 'simple': 'Count: %(count)d', + 'html': '

Count: %(count)d

' +} + +if args.fmt == 'html': + print '' + print '' + print 'Profile Report' + print '' + +accounted_for = 0 for cs in call_stacks: - print cs.count + if args.fmt in BANNER: + print BANNER[args.fmt] % { + 'count': cs.count, + } header, _ = zip(*FORMAT) table = [] for line in cs.lines: @@ -200,4 +219,11 @@ for cs in call_stacks: for _, fn in FORMAT: fields.append(fn(line)) table.append(fields) - print tabulate.tabulate(table, header, tablefmt="simple") + print tabulate.tabulate(table, header, tablefmt=args.fmt) + accounted_for += cs.count + if accounted_for > .99 * total_stacks: + break + +if args.fmt == 'html': + print '' + diff --git a/tools/profiling/latency_profile/run_latency_profile.sh b/tools/profiling/latency_profile/run_latency_profile.sh new file mode 100755 index 00000000000..41686be5606 --- /dev/null +++ b/tools/profiling/latency_profile/run_latency_profile.sh @@ -0,0 +1,29 @@ +#!/bin/bash + +set -ex + +cd $(dirname $0)/../../.. + +BINS="sync_unary_ping_pong_test sync_streaming_ping_pong_test" +CPUS=`python -c 'import multiprocessing; print multiprocessing.cpu_count()'` + +make CONFIG=basicprof -j$CPUS $BINS + +mkdir -p reports + +echo '' > reports/index.html +for bin in $BINS +do + bins/basicprof/$bin + mv latency_trace.txt $bin.trace + echo "$bin
" >> reports/index.html +done +for bin in $BINS +do + tools/profiling/latency_profile/profile_analyzer.py \ + --source=$bin.trace --fmt=simple > reports/$bin.txt & +done +echo '' >> reports/index.html + +wait +