diff --git a/tools/trace/ice-transport/stats b/tools/trace/ice-transport/stats new file mode 100755 index 0000000000000000000000000000000000000000..c22065a65d7354962e2e5ea332772c1450ff119d --- /dev/null +++ b/tools/trace/ice-transport/stats @@ -0,0 +1,131 @@ +#!/usr/bin/env python3 + +import argparse + +import bt2 + +def main(args): + + path = args.path[0] + + if args.tid < 0: + vtids = { + msg.event["vtid"] + for msg in bt2.TraceCollectionMessageIterator(path) + if type(msg) is bt2._EventMessageConst + } + else: + vtids = [args.tid] + + for tid in vtids: + analyze_trace(path, tid) + +def analyze_trace(path, tid): + + send_avg = 0 + recv_avg = 0 + send_N = 0 + recv_N = 0 + send_hist = [] + recv_hist = [] + + prefix = "jami:ice_transport_" + + def pkt_hist(hist, size): + + diff = size - len(hist) + + if diff >= 0: + hist += [0] * (diff + 1) + + hist[size] += 1 + + for msg in bt2.TraceCollectionMessageIterator(path): + + if type(msg) is bt2._EventMessageConst: + + name = msg.event.name + + if msg.event["vtid"] != tid: + continue + + if not name.startswith(prefix): + continue + + name = name[len(prefix):] + + if name == "send": + + pkt_len = msg.event["packet_length"] + + pkt_hist(send_hist, pkt_len) + + send_avg += pkt_len + send_N += 1 + + elif name == "recv": + + pkt_len = msg.event["packet_length"] + + pkt_hist(recv_hist, pkt_len) + + recv_avg += pkt_len + recv_N += 1 + + if send_N != 0: + send_avg /= send_N + + if recv_N != 0: + recv_avg /= recv_N + + if send_hist or recv_hist: + print(f"Thread: {tid}") + print("{:^20s}\t{:^20s}\t{:^20s}".format("Direction", "Count", "Average size (bytes)")) + print("{:^20s}\t{:^20d}\t{:^20d}".format("Send", send_N, int(send_avg))) + print("{:^20s}\t{:^20d}\t{:^20d}".format("Recv", recv_N, int(recv_avg))) + print("") + + if send_hist: + print_hist("Send", send_hist, args.log_scale) + + if recv_hist: + print_hist("Recv", recv_hist, args.log_scale) + + print("") + + +def print_hist(name, bins, log_scale=False): + + total_count = sum(bins) + + if log_scale: + next_hi = lambda x: 2 * x + else: + next_hi = lambda x: x + 1 + + lo = 0 + hi = 1 + + print('=' * 80) + print("{:^22s}|{:^10s}|{:^45s}|".format(name, "count", "distribution")) + print('-' * 80) + + while lo < len(bins): + count = sum(bins[lo:hi]) + print("{:>9d} -> {:<9d}|{:^10d}|{:45s}|".format(lo, hi, count, "*" * int(45 * count / total_count))) + lo = hi + hi = next_hi(hi) + print('=' * 80) + +if __name__ == "__main__": + + parser = argparse.ArgumentParser(description="Show ICE transport statistics.") + + parser.add_argument("path", metavar="TRACE", type=str, nargs=1) + parser.add_argument("tid", metavar="TID", type=int, nargs='?', default=-1) + parser.add_argument("--log-scale", action="store_true") + parser.add_argument("--scale", type=int, default=1) + + args = parser.parse_args() + + main(args) diff --git a/tools/trace/timeline/executor b/tools/trace/timeline/executor new file mode 100755 index 0000000000000000000000000000000000000000..cedbf3fd533a58088c1ab73e9486c529ef58b9cb --- /dev/null +++ b/tools/trace/timeline/executor @@ -0,0 +1,90 @@ +#!/usr/bin/env python3 + +import argparse +from datetime import datetime + +import bt2 + +class Thread: + + def __init__(self): + self.tasks = {} + self.executors = {} + +class Task: + + def __init__(self, beg, end): + self.source = "{}:{}".format(beg.event["source_filename"], beg.event["source_line"]) + self.sched = datetime.utcfromtimestamp(beg.default_clock_snapshot.ns_from_origin // 1E9).strftime("%X") + self.elapse = (end.default_clock_snapshot.ns_from_origin - + beg.default_clock_snapshot.ns_from_origin) / 1E3 + +def print_timeline(name, tasks): + print(f"\tExecutor: {name}") + print("\t\t{:<12s}{:<15}source".format("scheduled", "duration (µs)")) + for task in tasks: + print("\t\t{:<12s}{:<15.2f}{}".format(task.sched, task.elapse, task.source)) + print("") + +def main(args): + + filter_tid = args.tid + threads = {} + prefix = "jami:scheduled_executor_" + + for msg in bt2.TraceCollectionMessageIterator(args.path[0]): + + if type(msg) is bt2._EventMessageConst: + + name = msg.event.name + + if filter_tid > 0 and msg.event["vtid"] != filter_tid: + continue + + tid = msg.event["vtid"] + + if tid not in threads: + threads[tid] = Thread() + + thread = threads[tid] + + tasks = thread.tasks + + if not name.startswith(prefix): + continue + + name = name[len(prefix):] + + if name == "task_begin": + tasks[msg.event["cookie"]] = msg + + elif name == "task_end": + + executors = thread.executors + + begin = tasks[msg.event["cookie"]] + end = msg + task = Task(begin, end) + executor = begin.event["executor"] + + if executor not in executors: + executors[executor] = [task] + else: + executors[executor].append(task) + + for tid, thread in threads.items(): + if thread.executors: + print(f"Thread: {tid}") + for executor, tasks in thread.executors.items(): + print_timeline(executor, tasks) + +if __name__ == "__main__": + + parser = argparse.ArgumentParser(description="Show scheduled executors timeline.") + + parser.add_argument("path", metavar="TRACE", type=str, nargs=1) + parser.add_argument("tid", metavar="TID", type=int, nargs='?', default=-1) + + args = parser.parse_args() + + main(args) diff --git a/tools/trace/timeline/signals b/tools/trace/timeline/signals new file mode 100755 index 0000000000000000000000000000000000000000..9cc64a3dd4af3c8420cb34461707c60ca7665c83 --- /dev/null +++ b/tools/trace/timeline/signals @@ -0,0 +1,113 @@ +#!/usr/bin/env python3 + +import argparse +from datetime import datetime + +import bt2 + +class Thread: + + def __init__(self): + self.signals = [] + self.pendings = [] + +class Signal: + + def __init__(self, msg, indent): + self.indent = indent + self.beg = msg + self.signals = [] + self.callbacks = [] + self.pendings = [] + self.elapse = -1 + + def end(self, end): + self.elapse = (end.default_clock_snapshot.ns_from_origin - + self.beg.default_clock_snapshot.ns_from_origin) / 1E3 + return self + + def __str__(self): + return "{:.2f}us: {}".format(self.elapse, self.beg.event["signal_type"]) + +class Callback(): + + def __init__(self, begin): + self.source = "{}:{}".format(begin.event["source_filename"], + begin.event["source_line"]) + self.beg = begin + self.elapse = -1 + self.name = "" + + def end(self, end): + self.elapse = (end.default_clock_snapshot.ns_from_origin - + self.beg.default_clock_snapshot.ns_from_origin) / 1E3 + return self + +def print_timeline(thread): + for s in thread.signals: + prefix = "\t" * s.indent + print(f"{prefix}{s}") + print("{}\t{:<30s}{:<15}".format(prefix, "callback", "duration (%)")) + for cb in s.callbacks: + print("{}\t{:<30s}{:<.2f}".format(prefix, + cb.source, + 100 *cb.elapse / s.elapse)) + print("") + +def main(args): + + filter_tid = args.tid + threads = {} + prefix = "jami:emit_signal" + + for msg in bt2.TraceCollectionMessageIterator(args.path[0]): + + if type(msg) is bt2._EventMessageConst: + + name = msg.event.name + + if not name.startswith(prefix): + continue + + if filter_tid > 0 and msg.event["vtid"] != filter_tid: + continue + + tid = msg.event["vtid"] + + if tid not in threads: + threads[tid] = Thread() + + thread = threads[tid] + + pendings = thread.pendings + + name = name[len(prefix):] + + if name == "": + pendings.append(Signal(msg, len(pendings) + 1)) + + elif name == "_end": + thread.signals.append(pendings.pop().end(msg)) + + elif name == "_begin_callback": + signal = pendings[-1] + signal.pendings.append(Callback(msg)) + + elif name == "_end_callback": + signal = pendings[-1] + signal.callbacks.append(signal.pendings.pop().end(msg)) + + for tid, thread in threads.items(): + print(f"Thread: {tid}") + print_timeline(thread) + +if __name__ == "__main__": + + parser = argparse.ArgumentParser(description="Show signals timeline.") + + parser.add_argument("path", metavar="TRACE", type=str, nargs=1) + parser.add_argument("tid", metavar="TID", type=int, nargs='?', default=-1) + + args = parser.parse_args() + + main(args) diff --git a/tools/trace/trace-jami b/tools/trace/trace-jami new file mode 100755 index 0000000000000000000000000000000000000000..472d48e02fd90907b9ad244896ba766cfe19f5af --- /dev/null +++ b/tools/trace/trace-jami @@ -0,0 +1,28 @@ +#!/bin/sh + +epilogue() { + lttng stop + lttng destroy + exit 0 +} + +trap epilogue SIGINT + +lttng create jami +lttng enable-event --userspace 'jami:*' +lttng add-context --userspace --type=vtid + +for arg in "$@"; do + case "$arg" in + "--") break ;; + *) lttng add-context --userspace --type="$1" ;; + esac + shift +done +shift + +lttng start + +$@ + +epilogue