def list_timed(args):
bt_formatter = get_backtrace_formatter(args)
time_range = get_time_range(args)
with get_trace_reader(args) as reader:
timed_traces = prof.get_timed_traces(reader.get_traces(), time_range)
if args.sort:
if args.sort == 'duration':
order = -1
elif args.sort == 'time':
order = 1
timed_traces = sorted(timed_traces, key=lambda timed: order * getattr(timed, args.sort))
for timed in timed_traces:
t = timed.trace
print '0x%016x %-15s %2d %20s %7s %-20s %s%s' % (
t.thread.ptr,
t.thread.name,
t.cpu,
trace.format_time(t.time),
trace.format_duration(timed.duration),
t.name,
trace.Trace.format_data(t),
bt_formatter(t.backtrace))
def list_timed(args):
bt_formatter = get_backtrace_formatter(args)
time_range = get_time_range(args)
with get_trace_reader(args) as reader:
timed_traces = prof.get_timed_traces(reader.get_traces(), time_range)
if args.sort:
if args.sort == 'duration':
order = -1
elif args.sort == 'time':
order = 1
timed_traces = sorted(timed_traces, key=lambda timed: order * getattr(timed, args.sort))
for timed in timed_traces:
t = timed.trace
print '0x%016x %-15s %2d %20s %7s %-20s %s%s' % (
t.thread.ptr,
t.thread.name,
t.cpu,
trace.format_time(t.time),
trace.format_duration(timed.duration),
t.name,
trace.Trace.format_data(t),
bt_formatter(t.backtrace))
def list_timed(args):
bt_formatter = get_backtrace_formatter(args)
time_range = get_time_range(args)
with get_trace_reader(args) as reader:
timed_traces = get_timed_traces(reader.get_traces(), time_range)
if args.sort:
if args.sort == "duration":
order = -1
elif args.sort == "time":
order = 1
timed_traces = sorted(timed_traces, key=lambda timed: order * getattr(timed, args.sort))
for timed in timed_traces:
t = timed.trace
print "0x%016x %2d %20s %7s %-20s %s%s" % (
t.thread,
t.cpu,
trace.format_time(t.time),
trace.format_duration(timed.duration),
t.name,
t.format_data(),
bt_formatter(t.backtrace),
)
def dump_timed_trace(out_func, filter=None, sort=False):
bt_formatter = BacktraceFormatter(syminfo)
traces = ifilter(filter, all_traces())
timed_traces = get_timed_traces(traces)
if sort:
timed_traces = sorted(timed_traces, key=lambda timed: -timed.duration)
for timed in timed_traces:
trace = timed.trace
out_func('0x%016x %2d %20s %7s %-20s %s%s\n'
% (trace.thread,
trace.cpu,
format_time(trace.time),
format_duration(timed.duration),
trace.name,
trace.format_data(),
bt_formatter(trace.backtrace),
))
def dump_trace_summary(out_func):
format = "%-20s %8s %8s %8s %8s %8s %8s %8s %8s\n"
out_func("Execution times [ms]:\n")
out_func(format % ("name", "count", "min", "50%", "90%", "99%", "99.9%", "max", "total"))
for name, traces in get_timed_traces_per_function(all_traces()).iteritems():
samples = sorted(map(operator.attrgetter('duration'), traces))
out_func(format % (
name,
len(samples),
format_duration(get_percentile(samples, 0)),
format_duration(get_percentile(samples, 0.5)),
format_duration(get_percentile(samples, 0.9)),
format_duration(get_percentile(samples, 0.99)),
format_duration(get_percentile(samples, 0.999)),
format_duration(get_percentile(samples, 1)),
format_duration(sum(samples)),
))
def list_wakeup_latency(args):
bt_formatter = get_backtrace_formatter(args)
time_range = get_time_range(args)
class WaitingThread:
def __init__(self):
self.wait = None
self.wake = None
waiting = defaultdict(WaitingThread)
def format_wakeup_latency(nanos):
return "%4.6f" % (float(nanos) / 1e6)
if not args.no_header:
print '%-18s %-15s %3s %20s %13s %9s %s' % (
"THREAD", "THREAD-NAME", "CPU", "TIMESTAMP[s]", "WAKEUP[ms]", "WAIT[ms]", "BACKTRACE"
)
with get_trace_reader(args) as reader:
for t in reader.get_traces():
if t.name == "sched_wait":
waiting[t.thread.ptr].wait = t
elif t.name == "sched_wake":
thread_id = t.data[0]
if waiting[thread_id].wait:
waiting[thread_id].wake = t
elif t.name == "sched_wait_ret":
waiting_thread = waiting.pop(t.thread.ptr, None)
if waiting_thread and waiting_thread.wake:
# See https://github.com/cloudius-systems/osv/issues/295
if t.cpu == waiting_thread.wait.cpu:
wakeup_delay = t.time - waiting_thread.wake.time
wait_time = t.time - waiting_thread.wait.time
print '0x%016x %-15s %3d %20s %13s %9s %s' % (
t.thread.ptr,
t.thread.name,
t.cpu,
trace.format_time(t.time),
format_wakeup_latency(wakeup_delay),
trace.format_duration(wait_time),
bt_formatter(t.backtrace))
def list_wakeup_latency(args):
bt_formatter = get_backtrace_formatter(args)
time_range = get_time_range(args)
class WaitingThread:
def __init__(self):
self.wait = None
self.wake = None
waiting = defaultdict(WaitingThread)
def format_wakeup_latency(nanos):
return "%4.6f" % (float(nanos) / 1e6)
if not args.no_header:
print '%-18s %-15s %3s %20s %13s %9s %s' % (
"THREAD", "THREAD-NAME", "CPU", "TIMESTAMP[s]", "WAKEUP[ms]", "WAIT[ms]", "BACKTRACE"
)
with get_trace_reader(args) as reader:
for t in reader.get_traces():
if t.name == "sched_wait":
waiting[t.thread.ptr].wait = t
elif t.name == "sched_wake":
thread_id = t.data[0]
if waiting[thread_id].wait:
waiting[thread_id].wake = t
elif t.name == "sched_wait_ret":
waiting_thread = waiting.pop(t.thread.ptr, None)
if waiting_thread and waiting_thread.wake:
# See https://github.com/cloudius-systems/osv/issues/295
if t.cpu == waiting_thread.wait.cpu:
wakeup_delay = t.time - waiting_thread.wake.time
wait_time = t.time - waiting_thread.wait.time
print '0x%016x %-15s %3d %20s %13s %9s %s' % (
t.thread.ptr,
t.thread.name,
t.cpu,
trace.format_time(t.time),
format_wakeup_latency(wakeup_delay),
trace.format_duration(wait_time),
bt_formatter(t.backtrace))
