mirror of https://github.com/grpc/grpc.git
The C based gRPC (C++, Python, Ruby, Objective-C, PHP, C#)
https://grpc.io/
You can not select more than 25 topics
Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.
276 lines
8.7 KiB
276 lines
8.7 KiB
#!/usr/bin/env python2.7 |
|
# Copyright 2015 gRPC authors. |
|
# |
|
# Licensed under the Apache License, Version 2.0 (the "License"); |
|
# you may not use this file except in compliance with the License. |
|
# You may obtain a copy of the License at |
|
# |
|
# http://www.apache.org/licenses/LICENSE-2.0 |
|
# |
|
# Unless required by applicable law or agreed to in writing, software |
|
# distributed under the License is distributed on an "AS IS" BASIS, |
|
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
|
# See the License for the specific language governing permissions and |
|
# limitations under the License. |
|
|
|
import argparse |
|
import collections |
|
import hashlib |
|
import json |
|
import math |
|
import sys |
|
import time |
|
|
|
from six.moves import zip |
|
import tabulate |
|
|
|
SELF_TIME = object() |
|
TIME_FROM_SCOPE_START = object() |
|
TIME_TO_SCOPE_END = object() |
|
TIME_FROM_STACK_START = object() |
|
TIME_TO_STACK_END = object() |
|
TIME_FROM_LAST_IMPORTANT = 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') |
|
argp.add_argument('--out', default='-', type=str) |
|
args = argp.parse_args() |
|
|
|
|
|
class LineItem(object): |
|
|
|
def __init__(self, line, indent): |
|
self.tag = line['tag'] |
|
self.indent = indent |
|
self.start_time = line['t'] |
|
self.end_time = None |
|
self.important = line['imp'] |
|
self.filename = line['file'] |
|
self.fileline = line['line'] |
|
self.times = {} |
|
|
|
|
|
class ScopeBuilder(object): |
|
|
|
def __init__(self, call_stack_builder, line): |
|
self.call_stack_builder = call_stack_builder |
|
self.indent = len(call_stack_builder.stk) |
|
self.top_line = LineItem(line, self.indent) |
|
call_stack_builder.lines.append(self.top_line) |
|
self.first_child_pos = len(call_stack_builder.lines) |
|
|
|
def mark(self, line): |
|
line_item = LineItem(line, self.indent + 1) |
|
line_item.end_time = line_item.start_time |
|
self.call_stack_builder.lines.append(line_item) |
|
|
|
def finish(self, line): |
|
assert line['tag'] == self.top_line.tag, ( |
|
'expected %s, got %s; thread=%s; t0=%f t1=%f' % |
|
(self.top_line.tag, line['tag'], line['thd'], |
|
self.top_line.start_time, line['t'])) |
|
final_time_stamp = line['t'] |
|
assert self.top_line.end_time is None |
|
self.top_line.end_time = final_time_stamp |
|
self.top_line.important = self.top_line.important or line['imp'] |
|
assert SELF_TIME not in self.top_line.times |
|
self.top_line.times[ |
|
SELF_TIME] = final_time_stamp - self.top_line.start_time |
|
for line in self.call_stack_builder.lines[self.first_child_pos:]: |
|
if TIME_FROM_SCOPE_START not in line.times: |
|
line.times[ |
|
TIME_FROM_SCOPE_START] = line.start_time - self.top_line.start_time |
|
line.times[TIME_TO_SCOPE_END] = final_time_stamp - line.end_time |
|
|
|
|
|
class CallStackBuilder(object): |
|
|
|
def __init__(self): |
|
self.stk = [] |
|
self.signature = hashlib.md5() |
|
self.lines = [] |
|
|
|
def finish(self): |
|
start_time = self.lines[0].start_time |
|
end_time = self.lines[0].end_time |
|
self.signature = self.signature.hexdigest() |
|
last_important = start_time |
|
for line in self.lines: |
|
line.times[TIME_FROM_STACK_START] = line.start_time - start_time |
|
line.times[TIME_TO_STACK_END] = end_time - line.end_time |
|
line.times[ |
|
TIME_FROM_LAST_IMPORTANT] = line.start_time - last_important |
|
if line.important: |
|
last_important = line.end_time |
|
last_important = end_time |
|
|
|
def add(self, line): |
|
line_type = line['type'] |
|
self.signature.update(line_type.encode('UTF-8')) |
|
self.signature.update(line['tag'].encode('UTF-8')) |
|
if line_type == '{': |
|
self.stk.append(ScopeBuilder(self, line)) |
|
return False |
|
elif line_type == '}': |
|
assert self.stk, ( |
|
'expected non-empty stack for closing %s; thread=%s; t=%f' % |
|
(line['tag'], line['thd'], line['t'])) |
|
self.stk.pop().finish(line) |
|
if not self.stk: |
|
self.finish() |
|
return True |
|
return False |
|
elif line_type == '.' or line_type == '!': |
|
if self.stk: |
|
self.stk[-1].mark(line) |
|
return False |
|
else: |
|
raise Exception('Unknown line type: \'%s\'' % line_type) |
|
|
|
|
|
class CallStack(object): |
|
|
|
def __init__(self, initial_call_stack_builder): |
|
self.count = 1 |
|
self.signature = initial_call_stack_builder.signature |
|
self.lines = initial_call_stack_builder.lines |
|
for line in self.lines: |
|
for key, val in list(line.times.items()): |
|
line.times[key] = [val] |
|
|
|
def add(self, call_stack_builder): |
|
assert self.signature == call_stack_builder.signature |
|
self.count += 1 |
|
assert len(self.lines) == len(call_stack_builder.lines) |
|
for lsum, line in zip(self.lines, call_stack_builder.lines): |
|
assert lsum.tag == line.tag |
|
assert list(lsum.times.keys()) == list(line.times.keys()) |
|
for k, lst in list(lsum.times.items()): |
|
lst.append(line.times[k]) |
|
|
|
def finish(self): |
|
for line in self.lines: |
|
for lst in list(line.times.values()): |
|
lst.sort() |
|
|
|
|
|
builder = collections.defaultdict(CallStackBuilder) |
|
call_stacks = collections.defaultdict(CallStack) |
|
|
|
lines = 0 |
|
start = time.time() |
|
with open(args.source) as f: |
|
for line in f: |
|
lines += 1 |
|
inf = json.loads(line) |
|
thd = inf['thd'] |
|
cs = builder[thd] |
|
if cs.add(inf): |
|
if cs.signature in call_stacks: |
|
call_stacks[cs.signature].add(cs) |
|
else: |
|
call_stacks[cs.signature] = CallStack(cs) |
|
del builder[thd] |
|
time_taken = time.time() - start |
|
|
|
call_stacks = sorted(list(call_stacks.values()), |
|
key=lambda cs: cs.count, |
|
reverse=True) |
|
total_stacks = 0 |
|
for cs in call_stacks: |
|
total_stacks += cs.count |
|
cs.finish() |
|
|
|
|
|
def percentile(N, percent, key=lambda x: x): |
|
""" |
|
Find the percentile of an already sorted list of values. |
|
|
|
@parameter N - is a list of values. MUST be already sorted. |
|
@parameter percent - a float value from [0.0,1.0]. |
|
@parameter key - optional key function to compute value from each element of N. |
|
|
|
@return - the percentile of the values |
|
""" |
|
if not N: |
|
return None |
|
float_idx = (len(N) - 1) * percent |
|
idx = int(float_idx) |
|
result = key(N[idx]) |
|
if idx < len(N) - 1: |
|
# interpolate with the next element's value |
|
result += (float_idx - idx) * (key(N[idx + 1]) - key(N[idx])) |
|
return result |
|
|
|
|
|
def tidy_tag(tag): |
|
if tag[0:10] == 'GRPC_PTAG_': |
|
return tag[10:] |
|
return tag |
|
|
|
|
|
def time_string(values): |
|
num_values = len(values) |
|
return '%.1f/%.1f/%.1f' % (1e6 * percentile(values, 0.5), 1e6 * percentile( |
|
values, 0.9), 1e6 * percentile(values, 0.99)) |
|
|
|
|
|
def time_format(idx): |
|
|
|
def ent(line, idx=idx): |
|
if idx in line.times: |
|
return time_string(line.times[idx]) |
|
return '' |
|
|
|
return ent |
|
|
|
|
|
BANNER = {'simple': 'Count: %(count)d', 'html': '<h1>Count: %(count)d</h1>'} |
|
|
|
FORMAT = [ |
|
('TAG', lambda line: '..' * line.indent + tidy_tag(line.tag)), |
|
('LOC', lambda line: '%s:%d' % |
|
(line.filename[line.filename.rfind('/') + 1:], line.fileline)), |
|
('IMP', lambda line: '*' if line.important else ''), |
|
('FROM_IMP', time_format(TIME_FROM_LAST_IMPORTANT)), |
|
('FROM_STACK_START', time_format(TIME_FROM_STACK_START)), |
|
('SELF', time_format(SELF_TIME)), |
|
('TO_STACK_END', time_format(TIME_TO_STACK_END)), |
|
('FROM_SCOPE_START', time_format(TIME_FROM_SCOPE_START)), |
|
('SELF', time_format(SELF_TIME)), |
|
('TO_SCOPE_END', time_format(TIME_TO_SCOPE_END)), |
|
] |
|
|
|
out = sys.stdout |
|
if args.out != '-': |
|
out = open(args.out, 'w') |
|
|
|
if args.fmt == 'html': |
|
out.write('<html>') |
|
out.write('<head>') |
|
out.write('<title>Profile Report</title>') |
|
out.write('</head>') |
|
|
|
accounted_for = 0 |
|
for cs in call_stacks: |
|
out.write('\n') |
|
if args.fmt in BANNER: |
|
out.write(BANNER[args.fmt] % { |
|
'count': cs.count, |
|
}) |
|
header, _ = list(zip(*FORMAT)) |
|
table = [] |
|
for line in cs.lines: |
|
fields = [] |
|
for _, fn in FORMAT: |
|
fields.append(fn(line)) |
|
table.append(fields) |
|
out.write(tabulate.tabulate(table, header, tablefmt=args.fmt)) |
|
accounted_for += cs.count |
|
if accounted_for > .99 * total_stacks: |
|
break |
|
|
|
if args.fmt == 'html': |
|
print('</html>')
|
|
|