#394 UDP client's relayed "Server Report" summary shows garbage Lost count under --udp-l4s -e (client reads wrong/stale packet as server's final-stats ack)

[Robert McMahon]

Description
Running a short --udp-l4s -e UDP test, the client's final relayed "Server Report:" summary line displays a nonsensical Lost/Total value close to UINT32_MAX, while the server's own directly-printed per-interval output for the exact same run is completely clean (zero loss throughout).

Repro

server

iperf -s -u -p 5000 -P 1 -i 1 -t 3

client

iperf -c <server-ip> -u -p 5000 -P 1 --udp-l4s -e -i 1 -t 2
Observed (client output, tail)
[ 1] Server Report:
[ ID] Interval Transfer Bandwidth Jitter Lost/Total Datagrams
[ 1] 0.00-0.00 sec 0.000 Bytes 0.000 bits/sec 0.000 ms 4294967096/0 (0%)
Compare to the server's own direct output for the same run (correct):</server-ip>

[ 1] 0.00-1.00 sec 1.21 MBytes 10.1 Mbits/sec 0.000 ms 0/863 (0%) ...
[ 1] 1.00-2.00 sec 6.72 MBytes 56.4 Mbits/sec 0.000 ms 0/4793 (0%) ...
[ 1] 0.00-2.00 sec 7.93 MBytes 33.2 Mbits/sec 0.000 ms 0/5656 (0%) ...
Also frequently accompanies (server side): [ N] WARNING: ack of last datagram failed. — this on its own may be a separate, more benign symptom of the same best-effort retry budget in write_UDP_AckFIN() (src/Reports.c), not necessarily the root cause.

Investigation so far
The relayed summary is built by InitServerRelayUDPReport() (src/Reports.c), which reads a struct server_hdr out of the client's mSettings->mBuf after read(mySocket, mSettings->mBuf, MAXUDPBUF) in the client's final-ack-wait loop (src/Client.cpp, around line 2324). Instrumented both sides with temporary debug prints:

Server sent: flags=0x88000000, error_cnt=0x0 (i.e., HEADER_VERSION1 | HEADER_SEQNO64B, zero loss — consistent with its own clean printed output).
Client received/parsed: flags=0x0, error_cnt=0xffffff38 (-200 as a signed 32-bit value, i.e. 4294967096 once naively assigned to an unsigned/widened field).
The two sides' offset conventions for locating server_hdr inside the packet match exactly (both use (struct UDP_datagram *)buf + 1), so this isn't a struct-layout/offset bug. The client is parsing different bytes than the server actually sent — this points to a race where the client's ack-wait read() picks up a different UDP datagram than the server's explicit final-stats ack (e.g. a late/stray data packet from the tail of the L4S burst, given L4S's traffic pattern is bursty and high-rate), rather than a pure formatting/sign-extension bug. mSettings->mBuf is shared between the regular traffic-receive path and this teardown code, which is the leading suspect for how a stale or wrong packet's bytes could end up parsed as a server_hdr.

Root cause is not yet confirmed — next step would be a packet capture (tcpdump on loopback) correlated with the debug prints above to see exactly which packet the client's read() call is consuming at the point of the bad parse, and/or an audit of mSettings->mBuf ownership/lifetime across the client traffic thread vs. the final-ack-wait code.

Notes
Only reproduced so far with --udp-l4s -e; not yet confirmed whether plain (non-L4S) UDP tests with a similarly bursty/high-rate pattern and a short -t can trigger the same relayed-summary corruption, since the underlying InitServerRelayUDPReport()/write_UDP_AckFIN() code isn't L4S-specific.
Found via a new make check test, t/t26_udp_l4s.sh, added to give the L4S output path basic regression coverage. That test currently does not assert on the relayed Lost/Total value (it would be flaky until this is root-caused), and works around a separate test-harness false positive where t/base.sh's blanket failure grep treats "ack of last datagram failed" as a hard failure.

[Robert McMahon]

1. New evidence for the open UDP-L4S SourceForge ticket — RunUDPL4S() (lines 1290–1365 vs. 1410–1415)

This is the piece that ties directly back to the ticket I filed earlier (client's relayed "Server Report" showing a garbage ~UINT32_MAX Lost count). RunUDPL4S()'s main loop sends a small per-packet L4S ack (struct udp_l4s_ack, via sendmsg() at line 1356) on the same connected UDP socket throughout the transfer. Only after that loop ends does write_UDP_AckFIN() (line 1415) send the much larger, structurally different final stats packet (struct server_hdr) that the client's AwaitServerFinPacket() parses into the "Server Report" line.

On the client side, ack_poll() (Client.cpp) reads udp_l4s_ack-sized packets off that same socket throughout the run. If the server's last per-packet ack is still in flight (or queued in the socket's receive buffer) right as the loop ends and write_UDP_AckFIN() fires, the client's dedicated single read() in AwaitServerFinPacket() could consume that leftover small udp_l4s_ack instead of the real server_hdr — and blindly reinterpreting a udp_l4s_ack's bytes as a server_hdr would produce exactly the kind of nonsense field values (wrong flags, garbage error_cnt) I saw in the original investigation. This significantly narrows down the root cause from "some stray packet" to "the L4S per-packet ack channel racing the final-stats handoff on the same socket." Worth adding to the ticket, but I'd want to actually reproduce with this specific hypothesis (e.g. instrument for udp_l4s_ack vs server_hdr sized reads) before calling it confirmed.