d8ddea13ba
Swiss dumping a disc over the adapter measures 850 KB/s (6.97 Mbit/s, 25.8% of the 27 Mbit/s EXI ceiling). The capture decomposes it completely: 18395 data frames / 9200 ACKs = 2.0 frames per ACK 18.84 MB / 9200 = 2048 B per round trip 22.78 s / 9200 = 2.48 ms per round trip 2048 B / 2.48 ms = 826 KB/s ~= the measured 850 So the flow is window x RTT bound and nothing else. Payload per frame is exactly 1024 B (wire 1078 minus 54 of headers) against a 2920 B window, so two segments fit in flight. Zero retransmissions means the 15-page ring never overflowed; 0.2% stall time means nothing waits on the disc; our W5100 bus engine sits at ~17% utilisation. The adapter is not the constraint. Levers, and the first two are not ours: a larger lwIP TCP_SND_BUF (scales almost linearly while window-bound), and full-MSS segments -- Swiss writes 1024 B at a time, so the same window and RTT at 1460 B would give ~1150 KB/s, a 1.43x gain for free. Third is a shorter round trip, which is GC-side interrupt dispatch plus lwIP, plus EXI lock contention: libogc2's bba_event_handler defers when EXI_Lock fails, so RX queues behind TX on the single channel. ⚠️ This REVERSES an earlier recommendation in the TODO. RX interrupt coalescing (NCRB.RXINTC, RXINTT) was listed as a throughput lever; for a window-bound flow it makes things worse, because delaying the ACK's interrupt lengthens the round trip and throughput is bytes-per-round-trip / RTT. The measurement showed the guess was backwards. Noted in item 3 as "implement for fidelity, not for speed". analyse-pcap.py now derives frames-per-ACK, bytes-per-round-trip and the implied RTT itself, identifies a window-bound flow, quantifies the full-MSS gain, and warns against coalescing -- so the next person gets the conclusion rather than the raw numbers. Self-test G replays this exact shape. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
234 lines
9.6 KiB
Python
Executable File
234 lines
9.6 KiB
Python
Executable File
#!/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()
|
||
|
||
# ── Is the bulk direction window x RTT bound? ────────────────────────
|
||
#
|
||
# THE decisive statistic, and the one that is easy to miss: if the sender
|
||
# can only have `window` bytes unacknowledged, throughput is
|
||
# window / RTT no matter how fast the wire or the adapter is. Derive the
|
||
# round trip from the capture itself -- one ACK is one round trip -- so
|
||
# this needs no ping and no assumptions.
|
||
data_pkts = stats["from_gc"]["pkts"]
|
||
acks = stats["to_gc"]["pkts"]
|
||
payload = stats["from_gc"]["payload"]
|
||
if acks and payload:
|
||
per_rt = payload / acks
|
||
rtt = dur / acks
|
||
print(f"\nround-trip analysis (bulk direction GC -> PC)")
|
||
print(f" {data_pkts/acks:.1f} data frames per ACK, "
|
||
f"{per_rt:.0f} B per round trip, "
|
||
f"implied RTT {rtt*1000:.2f} ms")
|
||
print(f" {per_rt/rtt/1024:.0f} KB/s = bytes-per-round-trip / RTT"
|
||
f" <- compare with the measured throughput above")
|
||
if wins:
|
||
w = max(wins)
|
||
seg = payload / data_pkts
|
||
print(f" GC advertised window {w} B; segments average "
|
||
f"{seg:.0f} B, so {w//max(int(seg),1)} fit in flight")
|
||
if per_rt <= w * 1.2:
|
||
print(f" ⚠️ WINDOW x RTT BOUND: {per_rt:.0f} B in flight "
|
||
f"against a {w} B window.")
|
||
print(f" The adapter is not the limit -- the sender "
|
||
f"cannot have more outstanding.")
|
||
print(f" Levers, in order of effect:")
|
||
print(f" 1. a larger TCP send buffer / window on the "
|
||
f"GC (lwIP TCP_SND_BUF)")
|
||
if seg < 1400:
|
||
full = w - (w % 1460) or 1460
|
||
print(f" 2. full-MSS segments: {seg:.0f} B "
|
||
f"segments waste the window;")
|
||
print(f" {full} B per round trip would give "
|
||
f"{full/rtt/1024:.0f} KB/s ({full/per_rt:.2f}x)")
|
||
print(f" 3. a shorter round trip -- throughput scales "
|
||
f"1/RTT")
|
||
print(f" ⚠️ RX interrupt COALESCING would make this "
|
||
f"WORSE, not better:")
|
||
print(f" delaying the ACK's interrupt lengthens the "
|
||
f"round trip, and")
|
||
print(f" a window-bound flow pays for that directly.")
|
||
if wins:
|
||
print(f"\nGC advertised TCP window: min {min(wins)} max {max(wins)} "
|
||
f"last {wins[-1]} B")
|
||
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()
|