diff --git a/scripts/analyse-pcap.py b/scripts/analyse-pcap.py new file mode 100755 index 0000000..dbaea88 --- /dev/null +++ b/scripts/analyse-pcap.py @@ -0,0 +1,192 @@ +#!/usr/bin/env python3 +"""Work out what is limiting BBA throughput, from a capture. + + sudo tcpdump -i enp0s31f6 -s0 -w /tmp/bba.pcap host 10.0.0.64 + # ... run the Swiss dump for ~20 s, then Ctrl-C ... + ./scripts/analyse-pcap.py /tmp/bba.pcap --gc-ip 10.0.0.64 + +Answers, per direction: + * throughput, and what fraction of the 27 Mbit/s EXI ceiling it is + * MEAN FRAME SIZE -- if this is far below 1514 the cost is per-frame + overhead (interrupts, EXI transactions, socket bookkeeping), not bandwidth + * retransmissions -- frames we dropped would show up here, e.g. from the + 15-page RX ring overflowing (RBFI) + * the GC's advertised TCP window, and how long it sat at zero + * the largest gaps in the stream, which is where the stall actually is + +Classic pcap only (what `tcpdump -w` writes). Stdlib only, no root needed. +""" + +import argparse +import collections +import socket +import struct +import sys + +PCAP_MAGICS = {0xA1B2C3D4: (">", 1_000_000), 0xD4C3B2A1: ("<", 1_000_000), + 0xA1B23C4D: (">", 1_000_000_000), 0x4D3CB2A1: ("<", 1_000_000_000)} +EXI_BYTES_PER_S = 27_000_000 / 8 # the hard ceiling: 27 MHz, 1 bit/clock + + +def packets(path): + with open(path, "rb") as f: + hdr = f.read(24) + if len(hdr) < 24: + sys.exit("not a pcap file (too short)") + magic = struct.unpack(">I", hdr[:4])[0] + if magic == 0x0A0D0D0A: + sys.exit("this is pcapng; re-capture with `tcpdump -w ... ` " + "(libpcap writes classic pcap) or convert with " + "`editcap -F pcap in.pcapng out.pcap`") + if magic not in PCAP_MAGICS: + sys.exit(f"unknown pcap magic {magic:#010x}") + endian, divisor = PCAP_MAGICS[magic] + linktype = struct.unpack(endian + "I", hdr[20:24])[0] + if linktype != 1: + sys.exit(f"linktype {linktype}, expected 1 (Ethernet)") + while True: + ph = f.read(16) + if len(ph) < 16: + return + ts_s, ts_f, incl, orig = struct.unpack(endian + "IIII", ph) + data = f.read(incl) + if len(data) < incl: + return + yield ts_s + ts_f / divisor, data, orig + + +def main(): + ap = argparse.ArgumentParser(description=__doc__, + formatter_class=argparse.RawDescriptionHelpFormatter) + ap.add_argument("pcap") + ap.add_argument("--gc-ip", default="10.0.0.64") + ap.add_argument("--top-gaps", type=int, default=5) + a = ap.parse_args() + gc = socket.inet_aton(a.gc_ip) + + stats = {d: dict(pkts=0, wire=0, payload=0, retx=0, sizes=[], zerowin=0) + for d in ("from_gc", "to_gc")} + seen = {d: set() for d in ("from_gc", "to_gc")} + t0 = t1 = None + wins, gaps, last_ts = [], [], None + zero_win_spans, zw_start = [], None + other = collections.Counter() + + for ts, frame, orig in packets(a.pcap): + if len(frame) < 34: + continue + etype = struct.unpack("!H", frame[12:14])[0] + if etype != 0x0800: + other[etype] += 1 + continue + ip = frame[14:] + ihl = (ip[0] & 0x0F) * 4 + src, dst = ip[12:16], ip[16:20] + if src == gc: + d = "from_gc" + elif dst == gc: + d = "to_gc" + else: + continue + if t0 is None: + t0 = ts + t1 = ts + s = stats[d] + s["pkts"] += 1 + s["wire"] += orig + s["sizes"].append(orig) + if ip[9] != socket.IPPROTO_TCP: + continue + tcp = ip[ihl:] + if len(tcp) < 20: + continue + sport, dport, seq = struct.unpack("!HHI", tcp[:8]) + doff = (tcp[12] >> 4) * 4 + win = struct.unpack("!H", tcp[14:16])[0] + plen = struct.unpack("!H", ip[2:4])[0] - ihl - doff + if plen > 0: + s["payload"] += plen + key = (sport, dport, seq, plen) + if key in seen[d]: + s["retx"] += 1 + else: + seen[d].add(key) + # Gaps measured on the DATA direction only: a gap between data + # frames is a stall, a gap before an ACK is just latency. + if d == "from_gc": + if last_ts is not None: + gaps.append((ts - last_ts, ts)) + last_ts = ts + if d == "from_gc": + wins.append(win) + if d == "to_gc": + if win == 0 and zw_start is None: + zw_start = ts + elif win != 0 and zw_start is not None: + zero_win_spans.append(ts - zw_start) + zw_start = None + + if t0 is None: + sys.exit(f"no IPv4 traffic involving {a.gc_ip} in the capture") + dur = max(t1 - t0, 1e-9) + print(f"capture: {dur:.2f} s involving {a.gc_ip}\n") + + for d, label in (("from_gc", "GC -> PC (disc dump)"), ("to_gc", "PC -> GC")): + s = stats[d] + if not s["pkts"]: + print(f"{label}: nothing\n") + continue + mean = s["wire"] / s["pkts"] + bps = s["wire"] / dur + pps = s["pkts"] / dur + print(f"{label}") + print(f" {s['pkts']} frames, {s['wire']/1e6:.2f} MB on the wire, " + f"{s['payload']/1e6:.2f} MB TCP payload") + print(f" throughput {bps/1024:.0f} KB/s ({bps*8/1e6:.2f} Mbit/s, " + f"{100*bps/EXI_BYTES_PER_S:.1f}% of the 27 Mbit/s EXI ceiling)") + print(f" {pps:.0f} frames/s, mean frame {mean:.0f} B " + f"(max {max(s['sizes'])} B)") + if s["payload"]: + print(f" retransmissions {s['retx']} " + f"({100*s['retx']/max(s['pkts'],1):.2f}% of frames)") + if mean < 1000 and s["payload"]: + print(f" ⚠️ mean frame {mean:.0f} B is well under 1514: the cost " + f"is PER-FRAME overhead,") + print(f" not bandwidth. {pps:.0f} frames/s each needing an " + f"interrupt + EXI") + print(f" transactions + W5100 socket bookkeeping.") + print() + + if wins: + print(f"GC advertised TCP window: min {min(wins)} max {max(wins)} " + f"last {wins[-1]} B") + if max(wins) < 8192: + print(f" ⚠️ a {max(wins)} B window caps a single TCP stream at " + f"window/RTT; at 1 ms RTT that is " + f"{max(wins)/1e-3/1024:.0f} KB/s") + if zero_win_spans: + print(f"PC saw zero-window from the GC {len(zero_win_spans)} times, " + f"total {sum(zero_win_spans)*1000:.0f} ms " + f"({100*sum(zero_win_spans)/dur:.1f}% of the capture)") + print(" -> the GC could not drain fast enough: CPU/stack bound") + if other: + print("non-IPv4 frames: " + + ", ".join(f"{e:#06x}×{n}" for e, n in other.most_common(4))) + + if gaps: + gaps.sort(reverse=True) + total_stall = sum(g for g, _ in gaps if g > 0.005) + print(f"\nlargest gaps between GC data frames " + f"(top {a.top_gaps}):") + for g, ts in gaps[:a.top_gaps]: + print(f" {g*1000:7.2f} ms at t+{ts-t0:.3f}s") + print(f" gaps >5 ms total {total_stall*1000:.0f} ms " + f"({100*total_stall/dur:.1f}% of the capture)") + if total_stall / dur > 0.2: + print(" -> most of the time is spent NOT sending: the limit is " + "upstream of the wire") + print(" (disc read, CPU, or stack), not the adapter") + + +if __name__ == "__main__": + main() diff --git a/scripts/test-analyse-pcap.py b/scripts/test-analyse-pcap.py new file mode 100755 index 0000000..a2d257d --- /dev/null +++ b/scripts/test-analyse-pcap.py @@ -0,0 +1,134 @@ +#!/usr/bin/env python3 +"""Self-test for analyse-pcap.py: synthesise a capture with known properties +and check the tool reports them.""" +import os, socket, struct, subprocess, sys, tempfile + +GC = socket.inet_aton("10.0.0.64") +PC = socket.inet_aton("10.0.0.1") +MAC_GC = bytes.fromhex("0009bf000001") +MAC_PC = bytes.fromhex("002b67d4156c") + + +def tcp_frame(src, dst, smac, dmac, seq, payload, win=4096): + tcp = struct.pack("!HHIIBBHHH", 4000, 21, seq, 0, 5 << 4, 0x10, win, 0, 0) + ip = struct.pack("!BBHHHBBH4s4s", 0x45, 0, 20 + len(tcp) + len(payload), + 0, 0, 64, socket.IPPROTO_TCP, 0, src, dst) + return dmac + smac + b"\x08\x00" + ip + tcp + payload + + +def write_pcap(path, pkts): + with open(path, "wb") as f: + f.write(struct.pack(" reported {pct}% of the EXI ceiling") + +# Scenario B: small frames -- must trigger the per-frame-overhead warning. +pkts, seq, t = [], 1, 2000.0 +for i in range(1000): + pkts.append((t, tcp_frame(GC, PC, MAC_GC, MAC_PC, seq, b"\0" * 200))) + seq += 200 + t += 0.002 +pB = os.path.join(tmp, "b.pcap") +write_pcap(pB, pkts) +out = run(pB) +if "PER-FRAME overhead" not in out: + fails.append(f"B: small frames did not trigger the overhead warning\n{out}") +else: + print("B 200B payloads -> per-frame-overhead warning raised") + +# Scenario C: retransmissions (same seq+len twice) must be counted. +pkts, t = [], 3000.0 +for i in range(10): + pkts.append((t, tcp_frame(GC, PC, MAC_GC, MAC_PC, 1, b"\0" * 1460))) + t += 0.002 +pC = os.path.join(tmp, "c.pcap") +write_pcap(pC, pkts) +out = run(pC) +if "retransmissions 9" not in out: + fails.append(f"C: expected 9 retransmissions\n{out}") +else: + print("C same seq x10 -> 9 retransmissions counted") + +# Scenario D: a long stall must be found and attributed. +pkts, seq, t = [], 1, 4000.0 +for i in range(100): + pkts.append((t, tcp_frame(GC, PC, MAC_GC, MAC_PC, seq, b"\0" * 1460))) + seq += 1460 + t += 0.3 if i == 50 else 0.001 # one 300 ms hole +pD = os.path.join(tmp, "d.pcap") +write_pcap(pD, pkts) +out = run(pD) +if "300.00 ms" not in out: + fails.append(f"D: the 300 ms gap was not reported\n{out}") +elif "NOT sending" not in out: + fails.append(f"D: dominant stall not attributed\n{out}") +else: + print("D one 300ms hole in 100 frames -> found and attributed") + +# Scenario E: zero-window from the GC means the GC cannot drain. +pkts, t = [], 5000.0 +pkts.append((t, tcp_frame(PC, GC, MAC_PC, MAC_GC, 1, b"\0" * 100, win=0))) +pkts.append((t + 0.05, tcp_frame(PC, GC, MAC_PC, MAC_GC, 2, b"\0" * 100, win=4096))) +pE = os.path.join(tmp, "e.pcap") +write_pcap(pE, pkts) +out = run(pE) +if "zero-window" not in out or "CPU/stack bound" not in out: + fails.append(f"E: zero-window not reported\n{out}") +else: + print("E zero-window span -> reported as CPU/stack bound") + +# Scenario F: pcapng must be refused with a useful message, not misparsed. +pF = os.path.join(tmp, "f.pcapng") +with open(pF, "wb") as f: + f.write(struct.pack(">I", 0x0A0D0D0A) + b"\0" * 64) +r = subprocess.run([sys.executable, "-I", "scripts/analyse-pcap.py", pF], + capture_output=True, text=True) +if "pcapng" not in (r.stdout + r.stderr): + fails.append("F: pcapng not detected") +else: + print("F pcapng refused with a conversion hint") + +print("\nFAILURES:\n " + "\n ".join(fails) if fails else + "\nAll analyse-pcap self-tests passed.") +sys.exit(1 if fails else 0)