From b55778a847c37d87ad3b111b0950b4ead42a0793 Mon Sep 17 00:00:00 2001 From: Arvid Norberg Date: Tue, 7 Oct 2014 07:23:20 +0000 Subject: [PATCH] some DHT logging and parsing --- src/kademlia/traversal_algorithm.cpp | 7 ++ tools/parse_dht_log.py | 20 ++++- tools/parse_lookup_log.py | 118 +++++++++++++++++++++++++++ 3 files changed, 143 insertions(+), 2 deletions(-) create mode 100644 tools/parse_lookup_log.py diff --git a/src/kademlia/traversal_algorithm.cpp b/src/kademlia/traversal_algorithm.cpp index 1be334a37..0e14796a6 100644 --- a/src/kademlia/traversal_algorithm.cpp +++ b/src/kademlia/traversal_algorithm.cpp @@ -574,6 +574,13 @@ void traversal_algorithm::abort() if (o.flags & observer::flag_queried) o.flags |= observer::flag_done; } + +#ifdef TORRENT_DHT_VERBOSE_LOGGING + TORRENT_LOG(traversal) << "[" << this << "] ABORTED " + << " type: " << name() + ; +#endif + done(); } diff --git a/tools/parse_dht_log.py b/tools/parse_dht_log.py index fd3618ef6..715655ba9 100755 --- a/tools/parse_dht_log.py +++ b/tools/parse_dht_log.py @@ -36,12 +36,17 @@ def convert_timestamp(t): last_incoming = '' +our_node_id = '' + for line in f: counter += 1 # if counter % 1000 == 0: # print '\r%d' % counter, try: l = line.split(' ') + if 'starting DHT tracker with node id:' in line: + our_node_id = l[l.index('id:') + 1].strip() + if 'announce-distance:' in line: idx = l.index('announce-distance:') @@ -70,7 +75,9 @@ for line in f: outstanding_searches[search_id].append({ 't': ts, 'd': distance, 'o': outstanding + 1, 'a':addr, 'e': event,'i':nid, 's':source}) elif event == 'NEW': - outstanding_searches[search_id] = [{ 't': ts, 'd': 0, 'o': 0, 'e': 'NEW', 'i': ''}] + nid = l[l.index('target:')+1] + outstanding_searches[search_id] = [{ 't': ts, 'd': 0, 'o': 0, \ + 'e': event, 'abstime': ts, 'i': nid}] last_response = '' elif event == 'INVOKE' or event == 'ADD' or event == '1ST_TIMEOUT' or \ event == 'TIMEOUT' or event == 'PEERS': @@ -88,11 +95,16 @@ for line in f: outstanding_searches[search_id].append({ 't': ts, 'd': distance, 'o': outstanding + 1, 'a':addr, 'e': event,'i':nid, 's':source}) + elif event == 'ABORTED': + outstanding_searches[search_id].append({ 't': ts, 'e': event}) elif event == 'COMPLETED': distance = int(l[l.index('distance:')+1]) + lookup_type = l[l.index('type:')+1].strip() outstanding_searches[search_id].append({ 't': ts, 'd': distance, 'o': 0, 'e': event,'i':''}) + outstanding_searches[search_id][0]['type'] = lookup_type + s = outstanding_searches[search_id] try: @@ -174,9 +186,13 @@ for s in searches: print >>out, ' <-', i['t'], 160 - i['d'], i['i'], i['a'] elif i['e'] == 'PEERS': print >>out, ' <-', i['t'], 160 - i['d'], i['i'], i['a'] + elif i['e'] == 'ABORTED': + print >>out, 'abort' elif i['e'] == 'COMPLETED': print >>out, '***', i['t'], 160 - i['d'], '\n' - break + elif i['e'] == 'NEW': + print >>out, '===', i['abstime'], i['type'], '===' + print >>out, '<> ', 0, our_node_id, i['i'] out.close() out = open('dht_announce_distribution.dat', 'w+') diff --git a/tools/parse_lookup_log.py b/tools/parse_lookup_log.py new file mode 100644 index 000000000..4db5e1de5 --- /dev/null +++ b/tools/parse_lookup_log.py @@ -0,0 +1,118 @@ +# this is meant to parse the dht_lookups.log generated by parse_dht_log.py + +import os + +nodes = {} + +def get_origin(n): + if n in nodes: + return list(nodes[n]['conns']) + else: + return ['0.0.0.0'] + +def calculate_pos(nid, dist): + nid = int(nid[0:7], 16) + + x = 0 + y = 0 + for i in range(0, 28, 2): + x |= (nid & (1 << i)) >> (i / 2) + y |= (nid & (2 << i)) >> (i / 2 + 1) + +# print '%d -> %d %d' % (dist, x, y) + + return (x / 3, y / 3) + +def plot_nodes(nodes, frame): + + try: os.mkdir('dht_frames') + except: pass + + out = open('dht_frames/plot-%02d.dot' % frame, 'w+') + edges = set() + print >>out, 'graph swarm {' +# print >>out, '"tl" [shape=point pos="0,0!"];' +# print >>out, '"tr" [shape=point pos="1638,0!"];' +# print >>out, '"ll" [shape=point pos="1638,1638!"];' +# print >>out, '"tr" [shape=point pos="0,1638!"];' + for dst, n in nodes.items(): + shape = 'point' + if 's' in n: shape = n['s'] + + print >>out, '"%s" [shape=%s fillcolor="%s" label="" pos="%d,%d!"];' % (dst, shape, n['c'], n['p'][0], n['p'][1]) + for e in n['conns']: + if (e, dst) in edges: continue + + # only add an edge once to the .dot file + edges.add((e, dst)) + edges.add((dst, e)) + + style = 'solid' + col = 'gray' + if nodes[dst]['c'] != 'white' and nodes[e]['c'] != 'white': + style = 'solid' + col = 'black' + print >>out, '"%s" -- "%s" [style="%s" color="%s"];' % (e, dst, style, col) + + print >>out, '}' + out.close() + os.system('neato -n dht_frames/plot-%02d.dot -Tpng -o dht_frames/frame-%02d.png' % (frame, frame)) + + +frame = 0 +next_render_time = 100 +f = open('dht_lookups.txt') +for l in f: + if l.startswith('***'): break + + kind = l[0:3].strip() + l = l[3:].strip().split(' ') + + if kind == '===': continue + + t = int(l[0]) + if t > next_render_time: + plot_nodes(nodes, frame) + frame += 1 + next_render_time += 100 +# sys.exit(0) + + if kind == '<>': + p = calculate_pos(l[1], 0) + dst = '0.0.0.0' + if not dst in nodes: + nodes[dst] = { 'conns': set(), 'p': p, 'c': 'blue', 's': 'circle'} + + p = calculate_pos(l[2], 25) + dst = '255.255.255.255' + if not dst in nodes: + nodes[dst] = { 'conns': set(), 'p': p, 'c': 'yellow', 's': 'circle'} + elif kind == '->': + dst = l[3] + + if not dst in nodes: + src = get_origin(dst) + p = calculate_pos(l[2], int(l[1])) + nodes[dst] = { 'conns': set(src), 'p': p, 'c': 'grey'} + nodes[dst]['c'] = 'grey' + + elif kind == '+': + dst = l[3] + src = l[4] + p = calculate_pos(l[2], int(l[1])) + if not dst in nodes: + nodes[dst] = { 'conns': set(), 'p': p, 'c': 'white'} + nodes[dst]['conns'].add(src) + + elif kind == '<-': + dst = l[3] + nodes[dst]['c'] = 'green' + elif kind == 'x': + dst = l[3] + nodes[dst]['c'] = 'orange' + elif kind == 'X': + dst = l[3] + nodes[dst]['c'] = 'red' + +f.close() +