#!/usr/bin/env python3 # Plot the network traces output when TRACE_SOCKIO is set to 1 # ("make TRACE_SOCKIO=1" to build in this configuration) # Args: log_directory # Outputs trace.tex (and the files pdflatex builds, including the target # trace.pdf) into the log directory import glob import math import os import re import sys if len(sys.argv) != 2: print(f"Usage: {sys.argv[0]} log_directory", file=sys.stderr) sys.exit(1) # This will throw an exception if the directory does not exist os.chdir(sys.argv[1]) nodelogs = glob.glob("s*.log") nodelogs.sort(key=lambda filename : int(filename[1:-4])) # Pass 1: For each sender and receiver, make a list of each message # queued from that sender to receiver, noting its queue start time, # queue end time, size, and type. Also gather all timestamp labels for # each node queued_messages = {} labels = {} min_ts = None max_ts = None for nodelog in nodelogs: node = nodelog[:-4] labels[node] = [] with open(nodelog) as logf: queueing = {} for logline in logf: logline = logline.rstrip() if matches := re.match( r'(\d+\.\d+): RTE queueing (\d+) bytes to (\S+)', logline): [ts, size, recv] = matches.groups() assert(recv not in queueing) tsf = float(ts) queueing[recv] = \ { 'queue_start': tsf, 'size': size } if min_ts is None or min_ts > tsf: min_ts = tsf elif matches := re.match( r'(\d+\.\d+): RTE queued (\d+) bytes to (\S+)', logline): [ts, size, recv] = matches.groups() assert(recv in queueing) assert(queueing[recv]['size'] == size) if (node, recv) not in queued_messages: queued_messages[(node, recv)] = [] msg = { 'queue_start': queueing[recv]['queue_start'], 'queue_end': float(ts), 'size': size, 'type': 'RTE', } queued_messages[(node, recv)].append(msg) del queueing[recv] elif matches := re.match( r'(\d+\.\d+): Epoch \d+ (start|complete)', logline): [ts, typ] = matches.groups() tsf = float(ts) if typ == 'start': typ = 'S' elif typ == 'complete': typ = 'F' labels[node].append((tsf, typ)) if min_ts is None or min_ts > tsf: min_ts = tsf if max_ts is None or max_ts < tsf: max_ts = tsf elif matches := re.match( r'(\d+\.\d+): Round (.*) complete', logline): [ts, rnd] = matches.groups() tsf = float(ts) if rnd == '11': rnd = 'A' elif rnd == '12': rnd = 'B' elif rnd == '13': rnd = 'C' labels[node].append((tsf, rnd)) if max_ts is None or max_ts < tsf: max_ts = tsf elif matches := re.match( r'(\d+\.\d+): (Begin|End) Waksman networks precompute', logline): [ts, typ] = matches.groups() tsf = float(ts) if typ == 'Begin': typ = 'P' elif typ == 'End': typ = 'W' labels[node].append((tsf, typ)) if min_ts is None or min_ts > tsf: min_ts = tsf if max_ts is None or max_ts < tsf: max_ts = tsf elif matches := re.match( r'(\d+\.\d+): Begin ingestion', logline): [ts] = matches.groups() tsf = float(ts) labels[node].append((tsf, 'i')) if max_ts is None or max_ts < tsf: max_ts = tsf elif matches := re.match( r'(\d+\.\d+): End ingestion of \d+ messages', logline): [ts] = matches.groups() tsf = float(ts) labels[node].append((tsf, 'I')) if max_ts is None or max_ts < tsf: max_ts = tsf # Pass 2: For each sender and receiver, note the receive start time and # receive end time for each message in the queued_messages list messages = {} for nodelog in nodelogs: node = nodelog[:-4] with open(nodelog) as logf: receiving = {} for logline in logf: logline = logline.rstrip() if matches := re.match( r'(\d+\.\d+): RTE receiving (\d+) bytes from (\S+)', logline): [ts, size, snd] = matches.groups() assert(snd not in receiving) receiving[snd] = \ { 'recv_start': float(ts), 'size': size } elif matches := re.match( r'(\d+\.\d+): RTE received (\d+) bytes from (\S+)', logline): [ts, size, snd] = matches.groups() assert(snd in receiving) assert(receiving[snd]['size'] == size) assert(queued_messages[(snd, node)][0]['size'] == size) tsf = float(ts) if (snd, node) not in messages: messages[(snd, node)] = [] msg = queued_messages[(snd, node)].pop(0) msg['recv_start'] = receiving[snd]['recv_start'] msg['recv_end'] = tsf if max_ts is None or max_ts < tsf: max_ts = tsf messages[(snd, node)].append(msg) del receiving[snd] # Write a latex file that draws the messages # ((max_ts-min_ts)*timescale) must be at most 570 # Timescale (cm per second) timescale = min(570/(max_ts-min_ts), 2) # Nodescale (cm between nodes) nodescale = 1 # Seconds between time label ticks time_tick = math.ceil(1/timescale) with open("trace.tex", "w") as tf: print(r'''\documentclass{article} \usepackage[paperwidth=%fcm,paperheight=%fcm,margin=1cm]{geometry} \usepackage{tikz} \usepackage{times} \setlength\parindent{0pt} \pagestyle{empty} \begin{document} \begin{tikzpicture}''' % (((max_ts-min_ts)*timescale)+2.5, (len(nodelogs)+1)*nodescale+2.5), file=tf) nodenum = 0 nodepos = {} print(r'''\draw[thick] (0,0) -- ++(%lf,0);''' % ((max_ts-min_ts)*timescale), file=tf) ts=0 while ts<(max_ts-min_ts): print(r'''\draw [thick] (%lf,.1) node [anchor=south] { %s } -- ++(0,-.1);''' % (ts*timescale, str(ts)), file=tf) ts+=time_tick for nodelog in nodelogs: node = nodelog[:-4] nodenum += 1 nodepos[node] = -nodenum * nodescale print(r'''\node [anchor=east] at (0,%lf) { %s }; \draw[thick] (0,%lf) -- ++(%lf,0);''' % (nodepos[node], node, nodepos[node], (max_ts-min_ts)*timescale), file=tf) for (snd,recv) in messages: for msg in messages[(snd,recv)]: print(r'''%% %s %s %s %lf %lf %lf %lf''' % (snd, recv, msg['size'], msg['queue_start'], msg['queue_end'], msg['recv_start'], msg['recv_end']), file=tf) print(r'''\fill [fill=%s,fill opacity=.2] (%lf,%lf) -- (%lf,%lf) -- (%lf,%lf) -- (%lf,%lf) -- cycle;''' % ('black', (msg['queue_start']-min_ts)*timescale, nodepos[snd], (msg['queue_end']-min_ts)*timescale, nodepos[snd], (msg['recv_end']-min_ts)*timescale, nodepos[recv], (msg['recv_start']-min_ts)*timescale, nodepos[recv]), file=tf) for node in labels: for (ts,label) in labels[node]: print(r'''%% %lf''' % ts, file=tf) print(r'''\draw [thick] (%lf,%lf) node [anchor=south] { %s } -- ++(0,-.1);''' % ((ts-min_ts)*timescale, nodepos[node]+.1, label), file=tf) print(r'''\end{tikzpicture} \end{document}''', file=tf) os.system("pdflatex trace")