parsetrace/analyze-tcp.py

   1 #!/usr/bin/python
   2 #
   3 # Read a pcap dump containing a single TCP connection and analyze it to
   4 # determine as much as possible about the performance of that connection.
   5 # (Specifically designed for measuring performance of fetches to Amazon S3.)
   6
   7 import impacket, json, pcapy, re, sys
   8 import impacket.ImpactDecoder, impacket.ImpactPacket
   9
  10 # Estimate of the network RTT
  11 RTT_EST = 0.03
  12
  13 def dump_data(obj):
  14     return json.dumps(result_list, sort_keys=True, indent=2)
  15
  16 class Packet:
  17     def __init__(self, connection, ts, pkt):
  18         self.connection = connection
  19         self.ts = ts
  20         self.pkt = pkt
  21         self.ip = self.pkt.child()
  22         self.tcp = self.ip.child()
  23
  24         self.datalen = self.ip.get_ip_len() - self.ip.get_header_size() \
  25                         - self.tcp.get_header_size()
  26         self.data = self.tcp.get_data_as_string()[0:self.datalen]
  27
  28         self.seq = (self.tcp.get_th_seq(), self.tcp.get_th_seq() + self.datalen)
  29         self.ack = self.tcp.get_th_ack()
  30         self.id = self.ip.get_ip_id()
  31
  32         if self.tcp.get_th_sport() == 80:
  33             # Incoming packet
  34             self.direction = -1
  35         elif self.tcp.get_th_dport() == 80:
  36             # Outgoing packet
  37             self.direction = 1
  38         else:
  39             self.direction = 0
  40
  41     def __repr__(self):
  42         return "<Packet[%s]: id=%d seq=%d..%d ack=%d %s>" % \
  43             ({-1: '<', 1: '>', 0: '?'}[self.direction], self.id,
  44              self.seq[0], self.seq[1], self.ack, self.ts)
  45
  46 class TcpAnalysis:
  47     def __init__(self):
  48         self.start_time = None
  49         self.decoder = impacket.ImpactDecoder.EthDecoder()
  50         self.packets = []
  51
  52     def process_file(self, filename):
  53         """Load a pcap file and process the packets contained in it."""
  54
  55         p = pcapy.open_offline(filename)
  56         p.setfilter(r"ip proto \tcp")
  57         assert p.datalink() == pcapy.DLT_EN10MB
  58         p.loop(0, self.packet_handler)
  59
  60     def packet_handler(self, header, data):
  61         """Callback function run by the pcap parser for each packet."""
  62
  63         (sec, us) = header.getts()
  64         ts = sec * 1000000 + us
  65         if self.start_time is None:
  66             self.start_time = ts
  67         ts -= self.start_time
  68         pkt = Packet(self, ts * 1e-6, self.decoder.decode(data))
  69         self.packets.append(pkt)
  70
  71 def split_trace(packets, predicate, before=True):
  72     """Split a sequence of packets apart where packets satisfy the predicate.
  73
  74     If before is True (default), the split happens just before the matching
  75     packet; otherwise it happens just after.
  76     """
  77
  78     segment = []
  79     for p in packets:
  80         if predicate(p):
  81             if before:
  82                 if len(segment) > 0:
  83                     yield segment
  84                 segment = [p]
  85             else:
  86                 segment.append(p)
  87                 yield segment
  88                 segment = []
  89         else:
  90             segment.append(p)
  91     if len(segment) > 0:
  92         yield segment
  93
  94 def analyze_get(packets):
  95     packets = iter(packets)
  96     p = packets.next()
  97
  98     start_ts = p.ts
  99     id_out = p.id
 100
 101     # Check for connection establishment (SYN/SYN-ACK) and use that to estimate
 102     # th network RTT.
 103     if p.tcp.get_SYN():
 104         p = packets.next()
 105         #print "Connection establishment: RTT is", p.ts - start_ts
 106         return {'syn_rtt': p.ts - start_ts}
 107
 108     # Otherwise, we expect the first packet to be the GET request itself
 109     if not(p.direction > 0 and p.data.startswith('GET')):
 110         #print "Doesn't seem to be a GET request..."
 111         return
 112
 113     # Find the first response packet containing data
 114     while not(p.direction < 0 and p.datalen > 0):
 115         p = packets.next()
 116
 117     resp_ts = p.ts
 118     id_in = p.id
 119     start_seq = p.seq[0]
 120     tot_bytes = (p.seq[1] - start_seq) & 0xffffffff
 121     spacings = []
 122
 123     #print "Response time:", resp_ts - start_ts
 124
 125     # Scan through the incoming packets, looking for gaps in either the IP ID
 126     # field or in the timing
 127     last_ts = resp_ts
 128     for p in packets:
 129         gap = False
 130         bytenr = (p.seq[1] - start_seq) & 0xffffffff
 131         if not p.direction < 0: continue
 132         if p.tcp.get_FIN(): continue
 133         spacings.append((p.ts - last_ts, bytenr))
 134         if p.id != (id_in + 1) & 0xffff:
 135             gap = True
 136             #print "Sequence number gap at", id_in
 137         if p.ts - last_ts > 2 * RTT_EST:
 138             gap = True
 139             #print "Long gap of", p.ts - last_ts
 140         elif p.ts - last_ts > RTT_EST / 2:
 141             gap = True
 142             #print "Short gap of", p.ts - last_ts
 143         if gap:
 144             #print "    [occurred after", p.seq[0] - start_seq, "bytes, time", p.ts, "sec]"
 145             pass
 146         if p.datalen not in (1448, 1460):
 147             #print "Short packet of", p.datalen, "bytes, brings total to", p.seq[1] - start_seq
 148             pass
 149         if (p.seq[0] - start_seq) & 0xffffffff != tot_bytes:
 150             #print "Packet out of order; got sequence number %d, expected %d" \
 151             #        % ((p.seq[0] - start_seq) & 0xffffffff, tot_bytes)
 152             pass
 153         last_ts = p.ts
 154         id_in = p.id
 155         tot_bytes = max(tot_bytes, bytenr)
 156
 157     #print "Transferred %d bytes in %s seconds, initial response after %s" % (tot_bytes, last_ts - start_ts, resp_ts - start_ts)
 158     return {'bytes': tot_bytes,
 159             'start_latency': resp_ts - start_ts,
 160             'finish_latency': last_ts - start_ts,
 161             'interpacket_times': spacings}
 162
 163 if __name__ == '__main__':
 164     for f in sys.argv[1:]:
 165         conn = TcpAnalysis()
 166         conn.process_file(f)
 167         ts = 0.0
 168         def request_start(p):
 169             return p.direction > 0 and p.datalen > 0
 170         result_list = []
 171         for s in split_trace(conn.packets, request_start):
 172             s = list(s)
 173             if False:
 174                 for p in s:
 175                     #if p.ts - ts > 0.01:
 176                         #print "----"
 177                     #if p.ts - ts > 2 * RTT_EST:
 178                         #print "LONG DELAY\n----"
 179                     ts = p.ts
 180                     #print p
 181                     #if p.direction > 0 and p.datalen > 0:
 182                         #print "Request:", repr(p.data)
 183             results = analyze_get(s)
 184             if results is not None:
 185                 result_list.append(results)
 186             #print "===="
 187
 188         print dump_data(result_list)