twisterp2pblockchainnetworkbittorrentipv6microbloggingsocial-networkdhtdecentralizedtwister-coretwisterarmyp2p-networktwister-servertwister-ipv6
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.
309 lines
8.1 KiB
309 lines
8.1 KiB
import os, sys, time |
|
|
|
# usage: parse_log.py log-file [socket-index to focus on] |
|
|
|
|
|
socket_filter = None |
|
if len(sys.argv) >= 3: |
|
socket_filter = sys.argv[2].strip() |
|
|
|
if socket_filter == None: |
|
print "scanning for socket with the most packets" |
|
file = open(sys.argv[1], 'rb') |
|
|
|
sockets = {} |
|
|
|
for l in file: |
|
if not 'our_delay' in l: continue |
|
|
|
try: |
|
a = l.strip().split(" ") |
|
socket_index = a[1][:-1] |
|
except: |
|
continue |
|
|
|
# msvc's runtime library doesn't prefix pointers |
|
# with '0x' |
|
# if socket_index[:2] != '0x': |
|
# continue |
|
|
|
if socket_index in sockets: |
|
sockets[socket_index] += 1 |
|
else: |
|
sockets[socket_index] = 1 |
|
|
|
items = sockets.items() |
|
items.sort(lambda x, y: y[1] - x[1]) |
|
|
|
count = 0 |
|
for i in items: |
|
print '%s: %d' % (i[0], i[1]) |
|
count += 1 |
|
if count > 5: break |
|
|
|
file.close() |
|
socket_filter = items[0][0] |
|
print '\nfocusing on socket %s' % socket_filter |
|
|
|
file = open(sys.argv[1], 'rb') |
|
out_file = 'utp.out%s' % socket_filter; |
|
out = open(out_file, 'wb') |
|
|
|
delay_samples = 'points lc rgb "blue"' |
|
delay_base = 'steps lw 2 lc rgb "purple"' |
|
target_delay = 'steps lw 2 lc rgb "red"' |
|
off_target = 'dots lc rgb "blue"' |
|
cwnd = 'steps lc rgb "green"' |
|
window_size = 'steps lc rgb "sea-green"' |
|
rtt = 'lines lc rgb "light-blue"' |
|
|
|
metrics = { |
|
'our_delay':['our delay (ms)', 'x1y2', delay_samples], |
|
'upload_rate':['send rate (B/s)', 'x1y1', 'lines'], |
|
'max_window':['cwnd (B)', 'x1y1', cwnd], |
|
'target_delay':['target delay (ms)', 'x1y2', target_delay], |
|
'cur_window':['bytes in-flight (B)', 'x1y1', window_size], |
|
'cur_window_packets':['number of packets in-flight', 'x1y2', 'steps'], |
|
'packet_size':['current packet size (B)', 'x1y2', 'steps'], |
|
'rtt':['rtt (ms)', 'x1y2', rtt], |
|
'off_target':['off-target (ms)', 'x1y2', off_target], |
|
'delay_sum':['delay sum (ms)', 'x1y2', 'steps'], |
|
'their_delay':['their delay (ms)', 'x1y2', delay_samples], |
|
'get_microseconds':['clock (us)', 'x1y1', 'steps'], |
|
'wnduser':['advertised window size (B)', 'x1y1', 'steps'], |
|
|
|
'delay_base':['delay base (us)', 'x1y1', delay_base], |
|
'their_delay_base':['their delay base (us)', 'x1y1', delay_base], |
|
'their_actual_delay':['their actual delay (us)', 'x1y1', delay_samples], |
|
'actual_delay':['actual_delay (us)', 'x1y1', delay_samples], |
|
'send_buffer':['send buffer size (B)', 'x1y1', 'lines'], |
|
'recv_buffer':['receive buffer size (B)', 'x1y1', 'lines'] |
|
} |
|
|
|
histogram_quantization = 1 |
|
socket_index = None |
|
|
|
columns = [] |
|
|
|
begin = None |
|
|
|
title = "-" |
|
packet_loss = 0 |
|
packet_timeout = 0 |
|
|
|
delay_histogram = {} |
|
packet_size_histogram = {} |
|
window_size = {'0': 0, '1': 0} |
|
|
|
# [35301484] 0x00ec1190: actual_delay:1021583 our_delay:102 their_delay:-1021345 off_target:297 max_window:2687 upload_rate:18942 delay_base:1021481154 delay_sum:-1021242 target_delay:400 acked_bytes:1441 cur_window:2882 scaled_gain:2.432 |
|
|
|
counter = 0 |
|
|
|
print "reading log file" |
|
|
|
for l in file: |
|
if "UTP_Connect" in l: |
|
title = l[:-2] |
|
if socket_filter != None: |
|
title += ' socket: %s' % socket_filter |
|
else: |
|
title += ' sum of all sockets' |
|
continue |
|
|
|
try: |
|
a = l.strip().split(" ") |
|
t = a[0][1:-1] |
|
socket_index = a[1][:-1] |
|
except: |
|
continue |
|
# if socket_index[:2] != '0x': |
|
# continue |
|
|
|
if socket_filter != None and socket_index != socket_filter: |
|
continue |
|
|
|
counter += 1 |
|
if (counter % 300 == 0): |
|
print "\r%d " % counter, |
|
|
|
if "lost." in l: |
|
packet_loss = packet_loss + 1 |
|
continue |
|
if "Packet timeout" in l: |
|
packet_timeout = packet_timeout + 1 |
|
continue |
|
|
|
if "sending packet" in l: |
|
v = l.split('size:')[1].split(' ')[0] |
|
packet_size_histogram[v] = 1 + packet_size_histogram.get(v, 0) |
|
|
|
if "our_delay:" not in l: |
|
continue |
|
|
|
# used for Logf timestamps |
|
# t, m = t.split(".") |
|
# t = time.strptime(t, "%H:%M:%S") |
|
# t = list(t) |
|
# t[0] += 107 |
|
# t = tuple(t) |
|
# m = float(m) |
|
# m /= 1000.0 |
|
# t = time.mktime(t) + m |
|
|
|
# used for tick count timestamps |
|
t = int(t) |
|
|
|
if begin is None: |
|
begin = t |
|
t = t - begin |
|
# print time. Convert from milliseconds to seconds |
|
print >>out, '%f\t' % (float(t)/1000.), |
|
|
|
#if t > 200000: |
|
# break |
|
|
|
fill_columns = not columns |
|
for i in a[2:]: |
|
try: |
|
n, v = i.split(':') |
|
except: |
|
continue |
|
v = float(v) |
|
if n == "our_delay": |
|
bucket = int(v / histogram_quantization) |
|
delay_histogram[bucket] = 1 + delay_histogram.get(bucket, 0) |
|
if not n in metrics: continue |
|
if fill_columns: |
|
columns.append(n) |
|
if n == "max_window": |
|
window_size[socket_index] = v |
|
print >>out, '%f\t' % int(reduce(lambda a,b: a+b, window_size.values())), |
|
else: |
|
print >>out, '%f\t' % v, |
|
print >>out, float(packet_loss * 8000), float(packet_timeout * 8000) |
|
packet_loss = 0 |
|
packet_timeout = 0 |
|
|
|
out.close() |
|
|
|
out = open('%s.histogram' % out_file, 'wb') |
|
for d,f in delay_histogram.iteritems(): |
|
print >>out, float(d*histogram_quantization) + histogram_quantization / 2, f |
|
out.close() |
|
|
|
out = open('%s_packet_size.histogram' % out_file, 'wb') |
|
for d,f in packet_size_histogram.iteritems(): |
|
print >>out, d, f |
|
out.close() |
|
|
|
plot = [ |
|
{ |
|
'data': ['upload_rate', 'max_window', 'cur_window', 'wnduser', 'cur_window_packets', 'packet_size', 'rtt'], |
|
'title': 'send-packet-size', |
|
'y1': 'Bytes', |
|
'y2': 'Time (ms)' |
|
}, |
|
{ |
|
'data': ['max_window', 'cur_window', 'our_delay', 'target_delay'], |
|
'title': 'cwnd', |
|
'y1': 'Bytes', |
|
'y2': 'Time (ms)' |
|
}, |
|
{ |
|
'data': ['our_delay', 'max_window', 'target_delay', 'cur_window', 'wnduser', 'cur_window_packets'], |
|
'title': 'uploading', |
|
'y1': 'Bytes', |
|
'y2': 'Time (ms)' |
|
}, |
|
{ |
|
'data': ['our_delay', 'max_window', 'target_delay', 'cur_window', 'send_buffer'], |
|
'title': 'uploading_packets', |
|
'y1': 'Bytes', |
|
'y2': 'Time (ms)' |
|
}, |
|
{ |
|
'data': ['their_delay', 'target_delay', 'rtt'], |
|
'title': 'their_delay', |
|
'y1': '', |
|
'y2': 'Time (ms)' |
|
}, |
|
{ |
|
'data': ['their_actual_delay','their_delay_base'], |
|
'title': 'their_delay_base', |
|
'y1': 'Time (us)', |
|
'y2': '' |
|
}, |
|
{ |
|
'data': ['our_delay', 'target_delay', 'rtt'], |
|
'title': 'our-delay', |
|
'y1': '', |
|
'y2': 'Time (ms)' |
|
}, |
|
{ |
|
'data': ['actual_delay', 'delay_base'], |
|
'title': 'our_delay_base', |
|
'y1': 'Time (us)', |
|
'y2': '' |
|
} |
|
] |
|
|
|
out = open('utp.gnuplot', 'w+') |
|
|
|
files = '' |
|
|
|
#print >>out, 'set xtics 0, 20' |
|
print >>out, "set term png size 1280,800" |
|
print >>out, 'set output "%s.delays.png"' % out_file |
|
print >>out, 'set xrange [0:200]' |
|
print >>out, 'set xlabel "delay (ms)"' |
|
print >>out, 'set boxwidth 1' |
|
print >>out, 'set ylabel "number of packets"' |
|
print >>out, 'plot "%s.histogram" using 1:2 with boxes fs solid 0.3' % out_file |
|
files += out_file + '.delays.png ' |
|
|
|
print >>out, 'set output "%s.packet_sizes.png"' % out_file |
|
print >>out, 'set xrange [0:*]' |
|
print >>out, 'set xlabel "packet size (B)"' |
|
print >>out, 'set boxwidth 1' |
|
print >>out, 'set ylabel "number of packets sent"' |
|
print >>out, 'set logscale y' |
|
print >>out, 'plot "%s_packet_size.histogram" using 1:2 with boxes fs solid 0.3' % out_file |
|
print >>out, 'set nologscale y' |
|
files += out_file + '.packet_sizes.png ' |
|
|
|
print >>out, "set style data steps" |
|
#print >>out, "set yrange [0:*]" |
|
print >>out, "set y2range [*:*]" |
|
#set hidden3d |
|
#set title "Peer bandwidth distribution" |
|
#set xlabel "Ratio" |
|
|
|
for p in plot: |
|
print >>out, 'set title "%s %s"' % (p['title'], title) |
|
print >>out, 'set xlabel "time (s)"' |
|
print >>out, 'set ylabel "%s"' % p['y1'] |
|
print >>out, "set tics nomirror" |
|
print >>out, 'set y2tics' |
|
print >>out, 'set y2label "%s"' % p['y2'] |
|
print >>out, 'set xrange [0:*]' |
|
print >>out, "set key box" |
|
print >>out, "set term png size 1280,800" |
|
print >>out, 'set output "%s-%s.png"' % (out_file, p['title']) |
|
files += '%s-%s.png ' % (out_file, p['title']) |
|
|
|
comma = '' |
|
print >>out, "plot", |
|
|
|
for c in p['data']: |
|
if not c in metrics: continue |
|
i = columns.index(c) |
|
print >>out, '%s"%s" using ($1/1000):%d title "%s-%s" axes %s with %s' % (comma, out_file, i + 2, metrics[c][0], metrics[c][1], metrics[c][1], metrics[c][2]), |
|
comma = ', ' |
|
print >>out, '' |
|
|
|
out.close() |
|
|
|
os.system("gnuplot utp.gnuplot") |
|
|
|
os.system("open %s" % files) |
|
|
|
|