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 * 1e6
  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, 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, prev_time = None):
  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         addr = p.ip.get_ip_dst()
 105         p = packets.next()
 106         #print "Connection establishment: RTT is", p.ts - start_ts
 107         return {'syn_rtt': (p.ts - start_ts) / 1e6, 'addr': addr}
 108
 109     # Otherwise, we expect the first packet to be the GET request itself
 110     if not(p.direction > 0 and p.data.startswith('GET')):
 111         #print "Doesn't seem to be a GET request..."
 112         return
 113
 114     # Find the first response packet containing data
 115     while not(p.direction < 0 and p.datalen > 0):
 116         p = packets.next()
 117
 118     resp_ts = p.ts
 119     id_in = p.id
 120     start_seq = p.seq[0]
 121     tot_bytes = (p.seq[1] - start_seq) & 0xffffffff
 122     spacings = []
 123
 124     #print "Response time:", resp_ts - start_ts
 125
 126     # Scan through the incoming packets, looking for gaps in either the IP ID
 127     # field or in the timing
 128     last_ts = resp_ts
 129     last_was_short = False
 130     for p in packets:
 131         gap = False
 132         flags = []
 133         bytenr = (p.seq[1] - start_seq) & 0xffffffff
 134         if not p.direction < 0: continue
 135         if p.tcp.get_FIN(): continue
 136
 137         if last_was_short:
 138             flags.append('LAST_PACKET_SHORT')
 139         last_was_short = False
 140         if p.id != (id_in + 1) & 0xffff:
 141             gap = True
 142             flags.append('IPID_GAP')
 143         if p.datalen not in (1448, 1460):
 144             last_was_short = True
 145         if (p.seq[0] - start_seq) & 0xffffffff != tot_bytes:
 146             flags.append('OUT_OF_ORDER')
 147         if ((p.seq[0] - start_seq) & 0xffffffff) % 9000 == 0:
 148             flags.append('9000')
 149         spacings.append(((p.ts - last_ts) / 1e6, bytenr) + tuple(flags))
 150         last_ts = p.ts
 151         id_in = p.id
 152         tot_bytes = max(tot_bytes, bytenr)
 153
 154     #print "Transferred %d bytes in %s seconds, initial response after %s" % (tot_bytes, last_ts - start_ts, resp_ts - start_ts)
 155     if prev_time is not None:
 156         prev_delay = start_ts - prev_time
 157     else:
 158         prev_delay = 0
 159     return {'bytes': tot_bytes,
 160             'start_latency': resp_ts - start_ts,
 161             'finish_latency': last_ts - start_ts,
 162             'interpacket_times': spacings,
 163             'delay_from_previous': prev_delay}
 164
 165 if __name__ == '__main__':
 166     for f in sys.argv[1:]:
 167         conn = TcpAnalysis()
 168         conn.process_file(f)
 169         ts = 0
 170         def request_start(p):
 171             return p.direction > 0 and p.datalen > 0
 172         result_list = []
 173         prev_time = None
 174         for s in split_trace(conn.packets, request_start):
 175             s = list(s)
 176             if False:
 177                 for p in s:
 178                     #if p.ts - ts > 0.01:
 179                         #print "----"
 180                     #if p.ts - ts > 2 * RTT_EST:
 181                         #print "LONG DELAY\n----"
 182                     ts = p.ts
 183                     #print p
 184                     #if p.direction > 0 and p.datalen > 0:
 185                         #print "Request:", repr(p.data)
 186             results = analyze_get(s, prev_time)
 187             if results is not None:
 188                 result_list.append(results)
 189             prev_time = s[-1].ts
 190             #print "===="
 191
 192         print dump_data(result_list)