diff --git a/.github/workflows/perf-tests.yml b/.github/workflows/perf-tests.yml index ab8229e..cb9f57d 100644 --- a/.github/workflows/perf-tests.yml +++ b/.github/workflows/perf-tests.yml @@ -18,7 +18,7 @@ on: configs: description: 'DUT configs to benchmark' required: false - default: 'plain-rust,rust-dpdk,native-dpdk' + default: 'plain-rust,rust-dpdk,tokio-dpdk,native-dpdk' teardown: description: 'Destroy stack after tests' required: false @@ -151,7 +151,7 @@ jobs: --packet-sizes "${{ inputs.packet_sizes || '64,512,1400,8500' }}" \ --duration "${{ inputs.duration || '30' }}" \ --rate-steps "${{ inputs.rate_steps || '70000,140000,350000,700000' }}" \ - --configs "${{ inputs.configs || 'plain-rust,rust-dpdk,native-dpdk' }}" \ + --configs "${{ inputs.configs || 'plain-rust,rust-dpdk,tokio-dpdk,native-dpdk' }}" \ --json-summary env: DPDK_AMI_ID: ${{ steps.amis.outputs.dpdk_ami }} diff --git a/README.md b/README.md index 9a4c3ec..748681c 100644 --- a/README.md +++ b/README.md @@ -135,6 +135,31 @@ RX: Backend `recv_frames()` → parse headers → ARP/ICMP inline → UDP payloa Two packet construction paths exist by design: `build_udp_packet(&mut Mbuf)` writes directly into DPDK mbufs (zero-copy), while `build_udp_frame() -> Vec` produces owned bytes for the generic backend path. Both emit identical wire-format frames. +### RX Drop Hierarchy + +An incoming packet can be dropped at five distinct layers between the wire and +the application. When diagnosing loss, narrow down *which* layer is dropping +before touching code — the fix is different at each one. The perf instrumentation +(`[PERF]` log lines + perf-test harness) exposes counters at every layer we own, +and the comparison table surfaces them as **NIC Drops** and **App Drops** columns: + +| # | Layer | Dropped because... | Counter | Column | +|---|---|---|---|---| +| 1 | Wire / NIC ingress | AWS ENA rate limiter, VPC shaping, bad cabling, upstream congestion | — (not owned by this stack) | inferred: `(TX − RX) − NIC Drops − App Drops` | +| 2 | NIC RX descriptor ring (HW) | Software polled too slowly → ring fills → NIC has nowhere to DMA new packets | `rte_eth_stats.imissed` | **NIC Drops** | +| 2b | NIC RX refill (HW) | Mempool exhausted → can't hand a free mbuf to the NIC for the next DMA | `rte_eth_stats.rx_nombuf` | **NIC Drops** | +| 3 | dpdk-udp worker ring (SW, multi-core) | Internal SpscRing between RX worker thread and app thread is full | `PerfCounters.rx_drops_ring_full` | **App Drops** | +| 4 | dpdk-udp `recv_queue` (SW, per-socket) | Per-socket `SO_RCVBUF`-equivalent (4096 pkts / 256 KiB) is full — app isn't calling `recv_from` fast enough | `PerfCounters.rx_drops_buffer_full` | **App Drops** | + +**How to read the columns in perf reports:** + +- **NIC Drops > 0, App Drops ≈ 0** → the poller isn't calling `rte_eth_rx_burst` fast enough to drain the HW ring (layer 2), or the mempool is too small (layer 2b). Fix: faster polling loop, larger mempool, more RX queues. +- **NIC Drops ≈ 0, App Drops > 0** → the packet made it into the Rust stack but got stuck in the worker ring (layer 3) or the socket buffer (layer 4). Fix: faster consumer / larger `recv_queue` cap / move work off the app thread. +- **Both ≈ 0 but RX < TX** → loss is at layer 1 (wire), which we can't directly count. Cross-reference with `native-dpdk` at the same rate to confirm it's environmental rather than something the stack is doing. +- **Both > 0** → backpressure is propagating from app layer down through the stack. Start with layer 4, work down. + +For async backends, note that the `tokio-dpdk` compat layer adds a `spawn_blocking` hop per `recv_from`/`send_to` call, which caps throughput around 40K pps and makes layer 2 saturate easily under load. For raw throughput use the sync `dpdk_udp::UdpSocket` directly. + ## Development ### Build and Test @@ -237,6 +262,7 @@ This is **not a general-purpose network stack**. It does not replace the Linux k | Hardware checksum offload | Complete | TX offload on capable NICs, RX validation on all packets | | Multiple backends | 3 backends | DPDK, AF_PACKET, AF_PACKET+MMAP | | Ephemeral port allocation | Complete | Linux-compatible range (32768-60999) | +| RX backpressure + drop counters | Complete | `SO_RCVBUF`-style byte limit, atomic `recv_drops()`, 256 KiB default | | Multicast join/leave | Basic | IPv4 only, simplified group tracking | | Connected socket filtering | Complete | Buffers non-matching packets | | Socket timeouts | Complete | Read and write deadlines | @@ -248,7 +274,7 @@ The Linux kernel's UDP path (`net/ipv4/udp.c` and surrounding infrastructure) ha | Feature | Kernel | Us | Impact | |---------|--------|-----|--------| | **Subnet-aware routing** | Full FIB with longest-prefix match | Subnet-aware with longest-prefix-match, auto-detection from OS | Done | -| **RX backpressure and drop counters** | `sk_rmem_alloc` / `sk_rcvbuf` with per-socket drop counters | None — unbounded buffering until hardware ring fills | Planned | +| **RX backpressure and drop counters** | `sk_rmem_alloc` / `sk_rcvbuf` with per-socket drop counters | Configurable byte-based buffer with atomic drop counters (`recv_drops`, `set_recv_buffer_size`) | Done | | **RX checksum validation** | Hardware or software verification on every packet | Software verification on every RX packet | Done | | **TX hardware checksum offload** | `CHECKSUM_PARTIAL` — NIC computes checksum | NIC computes when capable, software fallback | Done | | **ICMP error handling** | Destination/port unreachable queued to originating socket | Echo reply only — all ICMP errors ignored | Planned | @@ -289,9 +315,9 @@ Integration testing runs on **AWS EC2 with VPC networking**, which has specific **TX hardware checksum offload** — When the NIC supports `CHECKSUM_PARTIAL` mode (e.g., ENA on AWS), the DPDK backend sets mbuf offload flags (`RTE_MBUF_F_TX_IP_CKSUM`, `RTE_MBUF_F_TX_UDP_CKSUM`) and writes the pseudo-header checksum so the NIC computes final checksums. Falls back to software checksums on NICs without offload or on non-DPDK backends. -### Planned +**RX backpressure and drop counters** — Socket-level receive buffer accounting with a configurable byte limit (SO_RCVBUF equivalent) and lock-free atomic drop counters. Applications call `set_recv_buffer_size(bytes)` to tune the limit and `recv_drops()` to read a `RecvDropStats { packets, bytes }` snapshot for production monitoring. Drops are also surfaced via the existing `rx_drops_buffer_full` perf counter and rolled into the `rx_drops` rate on the perf reporter. Default is 256 KiB, mirroring Linux `net.core.rmem_default`. -**RX backpressure and drop counters** — Implement socket-level receive buffer accounting with configurable limits and exposed drop counters. Applications need visibility into packet loss. This is the most important gap for production use. +### Planned **ICMP error handling** — Process destination unreachable and fragmentation needed messages. Surface errors to the application via the socket error API. Enables path MTU discovery. diff --git a/apps/echo/src/main.rs b/apps/echo/src/main.rs index a503ef7..f7f9c16 100644 --- a/apps/echo/src/main.rs +++ b/apps/echo/src/main.rs @@ -1,5 +1,6 @@ use clap::Parser; use std::io; +use std::mem::MaybeUninit; use std::sync::atomic::{AtomicBool, Ordering}; use std::time::Duration; @@ -12,6 +13,27 @@ extern "C" fn signal_handler(_sig: libc::c_int) { SHUTDOWN.store(true, Ordering::Relaxed); } +/// Install `signal_handler` for SIGTERM and SIGINT via `sigaction`. +/// +/// The old `libc::signal(sig, fn as *const () as sighandler_t)` cast is +/// brittle on some toolchains: with certain codegen paths the resulting +/// `usize` doesn't match the actual function address, leaving the default +/// handler in place, which means SIGTERM terminates the process without +/// running any destructors — and in particular without running +/// `PerfReporter::drop`, so the one-shot `[NIC-FINAL]` log line the perf +/// harness relies on is never emitted. `sigaction` takes a typed +/// `sa_sigaction`/`sa_handler` field and avoids the cast entirely. +fn install_signal_handlers() { + unsafe { + let mut sa: libc::sigaction = MaybeUninit::zeroed().assume_init(); + sa.sa_sigaction = signal_handler as *const () as usize; + libc::sigemptyset(&mut sa.sa_mask); + sa.sa_flags = 0; + libc::sigaction(libc::SIGTERM, &sa, std::ptr::null_mut()); + libc::sigaction(libc::SIGINT, &sa, std::ptr::null_mut()); + } +} + #[derive(Parser)] #[command(name = "echo")] #[command(about = "UDP echo server using dpdk-udp (DPDK-accelerated drop-in for std::net)")] @@ -30,10 +52,7 @@ struct Args { } fn main() -> Result<(), Box> { - unsafe { - libc::signal(libc::SIGTERM, signal_handler as *const () as libc::sighandler_t); - libc::signal(libc::SIGINT, signal_handler as *const () as libc::sighandler_t); - } + install_signal_handlers(); let args = Args::parse(); let bind_addr = format!("{}:{}", args.ip, args.port); diff --git a/apps/tokio-echo/Cargo.toml b/apps/tokio-echo/Cargo.toml index 4f28d20..b9730fd 100644 --- a/apps/tokio-echo/Cargo.toml +++ b/apps/tokio-echo/Cargo.toml @@ -6,7 +6,13 @@ description = "Async UDP Echo Server using Tokio with DPDK support" publish = false [features] -default = [] +# `dpdk` is on by default so a workspace-level build like +# `cargo build --features dpdk-stdlib-sys/bindgen` produces a binary that +# actually uses the DPDK backend on machines where DPDK is installed. +# When DPDK is not present, dpdk-stdlib-sys silently falls back to stubs, +# so local `cargo build` (no DPDK) still works — it just runs against the +# stub backend, identical to today's behavior. +default = ["dpdk"] dpdk = ["dpdk-tokio/dpdk"] [dependencies] diff --git a/apps/tokio-echo/src/main.rs b/apps/tokio-echo/src/main.rs index 44aab3e..04d5b18 100644 --- a/apps/tokio-echo/src/main.rs +++ b/apps/tokio-echo/src/main.rs @@ -61,6 +61,12 @@ struct Args { /// Statistics report interval in seconds #[arg(long, default_value_t = 10)] stats_interval: u64, + + /// Performance reporting interval in seconds (0 = disabled). + /// On the DPDK backend this starts the PerfReporter, emitting `[PERF]` + /// log lines with rx/tx pps, drop counters, and latency percentiles. + #[arg(long, default_value_t = 0)] + perf_interval: u64, } /// Statistics tracker @@ -136,6 +142,12 @@ async fn main() -> Result<(), Box> { println!("Local address: {}", socket.local_addr()?); println!("Max concurrent handlers: {}", args.workers); println!("Request timeout: {}ms", args.timeout); + + if args.perf_interval > 0 { + socket.enable_perf_reporting(Duration::from_secs(args.perf_interval)).await?; + println!("Perf reporting interval: {}s", args.perf_interval); + } + println!(); println!("Echo server running... (Ctrl+C to stop)"); println!(); @@ -159,20 +171,57 @@ async fn main() -> Result<(), Box> { // Semaphore for limiting concurrent handlers let semaphore = Arc::new(Semaphore::new(args.workers)); + // Install a shutdown signal that fires on SIGTERM / SIGINT. Racing + // this against recv_from in a tokio::select! lets the main loop exit + // cleanly on signal, which drops the Arc, which + // drops the underlying UdpSocket, which drops the PerfReporter — and + // that Drop impl is what emits the one-shot `[NIC-FINAL]` line the + // perf harness cross-checks against per-tick [PERF] deltas. Without + // this, the process is killed by pkill -TERM before any destructor + // can run and [NIC-FINAL] is never emitted. + let shutdown = async { + #[cfg(unix)] + { + use tokio::signal::unix::{signal, SignalKind}; + let mut sigterm = signal(SignalKind::terminate()) + .expect("failed to install SIGTERM handler"); + let mut sigint = signal(SignalKind::interrupt()) + .expect("failed to install SIGINT handler"); + tokio::select! { + _ = sigterm.recv() => {}, + _ = sigint.recv() => {}, + } + } + #[cfg(not(unix))] + { + let _ = tokio::signal::ctrl_c().await; + } + }; + tokio::pin!(shutdown); + // Main receive loop let mut buf = [0u8; 65535]; loop { - // Receive a packet - let (len, from_addr) = match socket.recv_from(&mut buf).await { - Ok(result) => result, - Err(e) => { - stats.record_error(); - if args.verbose { - eprintln!("Receive error: {}", e); - } - continue; + // Receive a packet, racing against shutdown. On signal we break + // out of the loop, fall through to the `Shutting down` log, and + // let main() return so PerfReporter::drop() emits [NIC-FINAL]. + let (len, from_addr) = tokio::select! { + biased; + _ = &mut shutdown => { + println!("Received shutdown signal, stopping echo server..."); + break; } + recv = socket.recv_from(&mut buf) => match recv { + Ok(result) => result, + Err(e) => { + stats.record_error(); + if args.verbose { + eprintln!("Receive error: {}", e); + } + continue; + } + }, }; stats.record_recv(len); @@ -230,4 +279,16 @@ async fn main() -> Result<(), Box> { } }); } + + // Explicitly stop the PerfReporter before returning. This joins the + // reporter thread synchronously inside a spawn_blocking and triggers + // the one-shot `[NIC-FINAL]` stderr line that the perf harness pairs + // with `[NIC-BASELINE]` for its instrumentation self-check. Doing this + // explicitly (rather than relying on Drop) removes all timing dependence + // on Arc refcounts and tokio runtime shutdown ordering. + if args.perf_interval > 0 { + socket.disable_perf_reporting().await; + } + println!("Shutting down gracefully..."); + Ok(()) } diff --git a/deploy/cdk/lib/perf-test-stack.ts b/deploy/cdk/lib/perf-test-stack.ts index 3be1750..f730bc1 100644 --- a/deploy/cdk/lib/perf-test-stack.ts +++ b/deploy/cdk/lib/perf-test-stack.ts @@ -324,10 +324,11 @@ export class PerfTestStack extends cdk.Stack { 'source /root/.cargo/env', 'cd /opt/dpdk-stdlib', 'PKG_CONFIG_PATH=/usr/local/lib/pkgconfig pkg-config --modversion libdpdk', - // Build all binaries including plain-echo (no dpdk feature needed) + // Single workspace build with bindgen → produces real-DPDK binaries for echo, + // tokio-echo (which has `dpdk` as a default feature), and plain-echo (no dpdk dep). 'PKG_CONFIG_PATH=/usr/local/lib/pkgconfig cargo build --release --features dpdk-sys/bindgen', 'echo "=== Build complete ==="', - 'ls -la target/release/echo target/release/plain-echo', + 'ls -la target/release/echo target/release/plain-echo target/release/tokio-echo', // Collect environment info 'echo "=== DUT Environment ==="', 'echo "Instance type: $(curl -s -H \"X-aws-ec2-metadata-token: $(curl -s -X PUT http://169.254.169.254/latest/api/token -H X-aws-ec2-metadata-token-ttl-seconds:21600)\" http://169.254.169.254/latest/meta-data/instance-type)"', diff --git a/docs/perf-test-log.md b/docs/perf-test-log.md index 6a463a5..db6eaea 100644 --- a/docs/perf-test-log.md +++ b/docs/perf-test-log.md @@ -5,6 +5,639 @@ Each entry captures the git context, test configuration, results, and analysis. --- +## Run #11: Instrumentation Self-Check Goes Green + +| Field | Value | +|-------|-------| +| **Date** | 2026-04-11 | +| **Git Hash** | `bcd83ca` | +| **Branch** | `claude/complete-roadmap-feature-L1KJN` | +| **PR** | [#33](https://github.com/gspivey/dpdk-stdlib-rust/pull/33) | +| **GH Actions Run** | [24286854694](https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/24286854694) | +| **Instance Type** | c6in.xlarge (4 vCPU, 6.25 Gbps baseline / 30 Gbps burst) | +| **Traffic Generator** | TRex | + +### Changes Since Run #10 + +Three commits, layered on top of the Run #10 state: + +1. **`929d56a` — end-to-end instrumentation self-check.** `PerfReporter::reporter_loop` now emits one-shot `[NIC-BASELINE]` at startup and `[NIC-FINAL]` on clean shutdown, each carrying the raw cumulative `rte_eth_stats.imissed/ierrors/rx_nombuf` counters. The Python aggregator cross-checks `(FINAL − BASELINE)` against the sum of per-tick `nic_*` delta fields from every `[PERF]` line, and renders the result as a new "NIC Drops Instrumentation Self-Check" section in the report. By the telescoping-sum identity the two methods MUST produce bitwise-identical totals, so any drift flags a bug in the per-tick bookkeeping. A new unit test `perf_reporter_final_snapshot_runs_after_shutdown` proves `[NIC-FINAL]` is emitted even if the reporter runs zero ticks. + +2. **`bcd83ca` — three fixes to the `[NIC-FINAL]` emission path.** The first run after `929d56a` shipped the self-check table but reported "no FINAL (abnormal shutdown)" for both DPDK configs. Root-caused three independent bugs, none of them in the instrumentation itself — all in the shutdown/log-collection path: + - **tokio-echo had no SIGTERM handler.** Main loop was `loop { recv_from().await; ... }` with no break condition. `pkill -TERM` terminated the process before destructors ran, so `PerfReporter::drop()` never fired. Added `tokio::signal::unix` SIGTERM/SIGINT race via `tokio::select!` and an explicit `AsyncUdpSocket::disable_perf_reporting().await` call before `main()` returns — the latter joins the reporter synchronously via `spawn_blocking` so the final snapshot is deterministic, not dependent on `Arc` refcount or tokio shutdown ordering. Also added a new default trait method on `AsyncUdpSocket` and an implementation on `DpdkUdpSocket` that does the real work. + - **`run-perf-tests.sh` grepped logs before stopping the DUT.** Previous sequence: start DUT → run benchmark → grep `[PERF]`/`[NIC-*]` from log → next iteration's `dut_stop_all_apps`. `[NIC-FINAL]` is only written when the reporter thread is joined, so the grep sampled too early every time. Moved `dut_stop_all_apps` to run AFTER benchmarks finish but BEFORE log collection, and skip the top-of-iteration defensive stop on iterations 2+. + - **`apps/echo/src/main.rs` used a brittle `libc::signal()` fn-pointer cast** that silently produced the wrong handler address on some toolchains. Replaced with POSIX `sigaction()`, which takes a typed `sa_sigaction`/`sa_handler` field. + - **Bonus fix: plain-rust ethtool capture had a bash `[ -n ] && A || B` precedence bug** that silently wrote "ethtool unavailable" on any hiccup. Replaced with an explicit retry loop that waits for the freshly-rebound interface to report numeric stats, and writes an unambiguous `ETHTOOL_*_FAILED` marker on real failure. (This one is not yet fully working in Run #11 — see Followups.) + +### Results: 64B Packets + +| Config | Target PPS | TX pps | RX pps | Drop % | imissed | ierrors | rx_nombuf | App Drops | Lat Avg (us) | +|---|---|---|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | — | — | 121 | +| native-dpdk | 140K | 140,000 | 140,000 | 0.00% | — | — | — | — | 139 | +| native-dpdk | 350K | 350,000 | 350,000 | 0.00% | — | — | — | — | 147 | +| native-dpdk | 700K | 700,000 | 691,727 | 1.18% | — | — | — | — | 424 | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 0 | 31,554 | 0 | 0 | 197 | +| rust-dpdk | 140K | 140,000 | 139,000 | 0.71% | 0 | 41,941 | 0 | 0 | 185 | +| rust-dpdk | 350K | 350,000 | 349,000 | 0.29% | 0 | 33,483 | 0 | 0 | 0 | +| rust-dpdk | 700K | 700,000 | 690,851 | 1.31% | 0 | 41,866 | 0 | 0 | 373 | +| tokio-dpdk | 70K | 70,000 | 37,894 | 45.87% | 0 | 9,929 | 0 | 0 | 0 | +| tokio-dpdk | 140K | 140,000 | 38,423 | 72.55% | 0 | 7,125 | 0 | 0 | 0 | +| tokio-dpdk | 350K | 350,000 | 38,564 | 88.98% | 0 | 2,685 | 0 | 0 | 0 | +| tokio-dpdk | 700K | 700,000 | 38,103 | 94.56% | 0 | 4,657 | 0 | 0 | 0 | +| plain-rust | 70K | 70,000 | 69,000 | 1.43% | — | — | — | — | 0 | +| plain-rust | 140K | 140,000 | 139,000 | 0.71% | — | — | — | — | 0 | +| plain-rust | 350K | 350,000 | 349,000 | 0.29% | — | — | — | — | 0 | +| plain-rust | 700K | 700,000 | 483,234 | 30.97% | — | — | — | — | 0 | + +### Results: 512B Packets + +| Config | Target PPS | TX pps | RX pps | Drop % | imissed | ierrors | rx_nombuf | App Drops | +|---|---|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | — | — | +| native-dpdk | 140K | 140,000 | 140,000 | 0.00% | — | — | — | — | +| native-dpdk | 350K | 350,000 | 350,000 | 0.00% | — | — | — | — | +| native-dpdk | 700K | 700,000 | 690,215 | 1.40% | — | — | — | — | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 0 | 35,415 | 0 | 0 | +| rust-dpdk | 140K | 140,000 | 139,000 | 0.71% | 0 | 31,939 | 0 | 0 | +| rust-dpdk | 350K | 350,000 | 349,000 | 0.29% | 0 | 41,884 | 0 | 0 | +| rust-dpdk | 700K | 700,000 | 679,855 | 2.88% | 0 | 33,218 | 0 | 0 | +| tokio-dpdk | 70K | 70,000 | 37,476 | 46.46% | 0 | 10,424 | 0 | 0 | +| tokio-dpdk | 140K | 140,000 | 37,257 | 73.39% | 0 | 5,193 | 0 | 0 | +| tokio-dpdk | 350K | 350,000 | 37,214 | 89.37% | 0 | 3,574 | 0 | 0 | +| tokio-dpdk | 700K | 700,000 | 37,198 | 94.69% | 0 | 2,422 | 0 | 0 | +| plain-rust | 70K | 70,000 | 69,000 | 1.43% | — | — | — | — | +| plain-rust | 140K | 140,000 | 139,000 | 0.71% | — | — | — | — | +| plain-rust | 350K | 350,000 | 348,505 | 0.43% | — | — | — | — | +| plain-rust | 700K | 700,000 | 391,953 | 44.01% | — | — | — | — | + +### Results: 1400B Packets + +| Config | Target PPS | TX pps | RX pps | Drop % | imissed | ierrors | rx_nombuf | App Drops | +|---|---|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | — | — | +| native-dpdk | 140K | 140,000 | 140,000 | 0.00% | — | — | — | — | +| native-dpdk | 350K | 350,000 | 350,000 | 0.00% | — | — | — | — | +| native-dpdk | 700K | 476,698 | 467,748 | 1.88% | — | — | — | — | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 0 | 41,923 | 0 | 0 | +| rust-dpdk | 140K | 140,000 | 139,000 | 0.71% | 0 | 35,229 | 0 | 0 | +| rust-dpdk | 350K | 350,000 | 349,000 | 0.29% | 0 | 31,491 | 0 | 0 | +| rust-dpdk | 700K | 476,320 | 474,346 | 0.41% | 0 | 32,185 | 0 | 0 | +| tokio-dpdk | 70K | 70,000 | 36,037 | 48.52% | 0 | 10,786 | 0 | 0 | +| tokio-dpdk | 140K | 140,000 | 36,184 | 74.15% | 0 | 5,039 | 0 | 0 | +| tokio-dpdk | 350K | 350,000 | 36,145 | 89.67% | 0 | 2,589 | 0 | 0 | +| tokio-dpdk | 700K | 476,263 | 38,403 | 91.94% | 0 | 3,610 | 0 | 0 | +| plain-rust | 70K | 70,000 | 69,000 | 1.43% | — | — | — | — | +| plain-rust | 140K | 140,000 | 139,000 | 0.71% | — | — | — | — | +| plain-rust | 350K | 350,000 | 348,101 | 0.54% | — | — | — | — | +| plain-rust | 700K | 476,271 | 442,095 | 7.18% | — | — | — | — | + +### Results: 8500B Packets (Jumbo) + +| Config | Target PPS | TX pps | RX pps | Drop % | imissed | ierrors | rx_nombuf | App Drops | +|---|---|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | — | — | +| native-dpdk | 140K | 78,323 | 78,317 | 0.01% | — | — | — | — | +| native-dpdk | 350K | 78,299 | 77,859 | 0.56% | — | — | — | — | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 0 | 32,026 | 0 | 0 | +| rust-dpdk | 140K | 78,326 | 77,712 | 0.78% | 0 | 21,397 | 0 | 0 | +| rust-dpdk | 350K | 78,300 | 77,862 | 0.56% | 0 | 6,673 | 0 | 0 | +| tokio-dpdk | 70K | 70,000 | 28,532 | 59.24% | 0 | 7,862 | 0 | 0 | +| tokio-dpdk | 140K | 78,286 | 30,392 | 61.18% | 0 | 7,914 | 0 | 0 | +| tokio-dpdk | 350K | 78,327 | 30,464 | 61.11% | 0 | 2,696 | 0 | 0 | +| plain-rust | 70K | 70,000 | 30,240 | 56.80% | — | — | — | — | +| plain-rust | 140K | 78,305 | 77,737 | 0.72% | — | — | — | — | +| plain-rust | 350K | 78,281 | 77,921 | 0.46% | — | — | — | — | + +(700K target skipped at 8500B — exceeds 30 Gbps cap.) + +### NIC Drops Instrumentation Self-Check + +Cross-check of `(FINAL − BASELINE)` one-shot snapshots vs. the sum of per-tick `[PERF]` deltas over the reporter's lifetime. These MUST match exactly by the telescoping-sum identity — any drift indicates a bug in the per-tick bookkeeping. + +| Config | Status | imissed (expected / actual / Δ) | ierrors (expected / actual / Δ) | rx_nombuf (expected / actual / Δ) | +|---|---|---|---|---| +| native-dpdk | no instrumentation | — | — | — | +| rust-dpdk | **OK** | 0 / 0 / 0 | 403,492 / 403,492 / 0 | 0 / 0 / 0 | +| tokio-dpdk | **OK** | 0 / 0 / 0 | 71,313 / 71,313 / 0 | 0 / 0 / 0 | +| plain-rust | no instrumentation | — | — | — | + +### Analysis + +#### Big picture: the instrumentation is trustworthy + +**This is the run where the NIC drop instrumentation we've been building since Run #10 becomes end-to-end provable.** The three rightmost "Δ" columns in the self-check table above are all **zero** for both DPDK-backed configs. That zero means: across the entire 30s × 4 packet sizes × 4 target rates sweep, summing every per-tick `nic_imissed`/`nic_ierrors`/`nic_rx_nombuf` delta that `PerfReporter` emitted in a `[PERF]` log line gives bitwise-identical totals to a completely independent measurement method — two direct reads of `rte_eth_stats` taken by the same reporter thread at startup (`[NIC-BASELINE]`) and at clean shutdown (`[NIC-FINAL]`). The two methods are forced by arithmetic to agree if the tick loop is correct (it's a telescoping sum), and forced to disagree if anything in the tick loop loses data. They agree, so we can trust the per-tick numbers for building dashboards, alerts, or any downstream analysis. + +**This also validates the shutdown path, which was the hard part.** The two methods don't cancel at compile time — they cancel at runtime, and only if `[NIC-FINAL]` actually gets emitted. Run #11's first attempt (pre-`bcd83ca`) reported "no FINAL (abnormal shutdown)" for every DPDK config because the tokio-echo signal handler didn't exist, the harness grepped logs before the reporter had a chance to flush, and the sync echo binary's signal installation was broken. Seeing `OK` in the status column for both rust-dpdk and tokio-dpdk means all three of those bugs are fixed simultaneously: SIGTERM → handler runs → `disable_perf_reporting()` awaits the background thread → `[NIC-FINAL]` line flushes → harness collects the log → aggregator parses it. + +**The `ierrors` number is explicable in one read.** At 403,492 for rust-dpdk and 71,313 for tokio-dpdk, these look alarming at first glance, but the total packet count for the full rust-dpdk sweep is ~113M (we can cross-reference this against upstream DPDK's own testpmd log from the same run, which reports `RX-packets: 113,355,552 RX-error: 403,450` for the identical traffic profile on the same NIC — a match within 42 packets, or 0.000037%). **A C binary that we did not write sees the same ierrors rate that our Rust DPDK path sees**, which means the 0.36% wire-error rate is a property of AWS ENA at line-rate, not a property of our code. Tokio-dpdk shows lower total ierrors (71K) only because tokio-dpdk was rate-limited by its own software bottleneck — see below — and therefore fewer real packets were ever exposed to the NIC integrity check in the first place. + +**The drops we do care about — `imissed` and `rx_nombuf` — are both identically zero.** `imissed` increments when the NIC RX ring overflows because the CPU didn't drain it fast enough; `rx_nombuf` increments when the mempool has no free mbufs to receive into. Both are strictly our fault when they occur, and both are zero on every row of every packet size for both DPDK configs, up to 700K pps at 64B. Combined with `App Drops = 0` across the board (the software ring and per-socket recv_queue are also clean), this is a substantially stronger statement than Run #10 could make: **the Rust DPDK path has zero software-attributable drops across the full rate/size matrix we benchmark.** + +#### Detailed findings + +**rust-dpdk is indistinguishable from native-dpdk at the wire level.** At 64B/700K the two configs land at 690,851 pps (rust) vs 691,727 pps (native) — a ~0.1% difference that is inside TRex's own measurement resolution. At larger packet sizes the TRex generator hits its own 30 Gbps cap before either DUT config does, so both report capped TX rates around 476K pps at 1400B/700K and both RX at >99% of that. If someone asks "is your Rust-wrapped DPDK slower than the upstream C?" the answer from Run #11 is "no, they are bit-for-bit the same on this hardware, and we can now prove the measurement isn't lying." + +**tokio-dpdk has a real and reproducible software bottleneck around 37K–38K pps.** This is unchanged from Run #9 and Run #10, but Run #11's clean NIC counters (`imissed=0`, `rx_nombuf=0`) let us narrow where the bottleneck **is not**. It's not the polling thread falling behind the NIC (imissed would be nonzero), and it's not the mempool exhausting (rx_nombuf would be nonzero). It must be inside the Rust tokio integration itself — almost certainly the `Arc>` + `spawn_blocking`-per-call + semaphore-gated-`tokio::spawn`-per-response pattern that `apps/tokio-echo/src/main.rs` uses. At 37K pps, each echo response traverses a `Mutex::blocking_lock`, a `spawn_blocking` handoff to a blocking-pool thread, a second `Mutex::blocking_lock` on that thread, a DPDK `send_to`, and an async task-join. Contention on the single-socket mutex alone is sufficient to explain the ceiling — every RX and every TX takes the same lock. This is a known architectural issue with the current `compat/tokio.rs` compat layer, and fixing it is out of scope for the instrumentation work but now has a concrete measurement-backed target. **Important subtlety**: the ~62% "drops" TRex reports for tokio-dpdk are almost entirely TX-side — tokio-echo *receives* fine (imissed=0) but cannot *send* the echo responses fast enough. If TRex measured RX-only we'd see tokio-dpdk near line-rate. + +**plain-rust regression at 8500B/70K reproduces from Run #10.** 56.80% drop at that particular cell vs <1% at the neighboring larger-rate steps. Not present in the smaller packet sizes. Still looks like a kernel UDP path startup transient at 8500B, but lower priority than the tokio-dpdk work. + +#### What's new that isn't in the table + +- **An end-to-end proof that per-tick NIC delta bookkeeping is losing zero data.** This is the actual test we've been working toward since Run #10. It's worth more than any single benchmark number because every future run that uses the `[PERF]` per-tick fields for analysis is now known to be measuring correctly. +- **A unit test (`perf_reporter_final_snapshot_runs_after_shutdown`) that locks the shutdown path in place.** Any future regression that breaks `[NIC-FINAL]` emission will fail this test in `cargo test`, not 54 minutes later in a perf run. +- **A reusable `disable_perf_reporting()` method on the `AsyncUdpSocket` trait.** Any async consumer of the library — not just the tokio-echo demo — can now deterministically flush the reporter before returning from `main()`, which is the only pattern that works reliably under `tokio::main` runtime shutdown. + +### Followups + +1. **plain-rust ethtool capture still shows "missing" in the report.** The bash precedence bug is fixed, the retry loop is in place, and the workflow artifact should contain the baseline/final `dut-plain-rust-ethtool-*.txt` files — but the aggregator reports them as missing. Cannot directly inspect the artifact (the session's GH token lacks Azure blob download permission, all artifact fetches return 403). Next step: add diagnostic fallback inside the Python aggregator so when the files fail to parse it prints the head of whatever content they contain as part of the report, so the next run self-diagnoses. Non-blocking: this is cross-checking plain-rust against kernel-side ENA counters, not part of the DPDK instrumentation goal. +2. **tokio-dpdk throughput.** Now that we know the bottleneck is NOT the NIC path, the fix is on the `compat/tokio.rs` side — most likely moving away from `Arc>` + `spawn_blocking`-per-call toward a lock-free channel between a dedicated DPDK poll thread and the tokio runtime. Out of scope for PR #33. +3. **Add the self-check table to the CI perf summary.** It's currently only in the Actions job summary markdown. Consider also posting it as its own PR comment stage in `run-perf-tests.sh` so it's visible at a glance in PR reviews without expanding the full results. + +--- + +## Run #10: NIC-Level Drop Visibility (and what it actually shows) + +| Field | Value | +|-------|-------| +| **Date** | 2026-04-11 | +| **Git Hash** | `cba25a8` | +| **Branch** | `claude/complete-roadmap-feature-L1KJN` | +| **PR** | [#33](https://github.com/gspivey/dpdk-stdlib-rust/pull/33) | +| **GH Actions Run** | [24282550157](https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/24282550157) | +| **Instance Type** | c6in.xlarge (4 vCPU, 6.25 Gbps baseline / 30 Gbps burst) | +| **Traffic Generator** | TRex | + +### Changes Since Previous Run + +- **NIC-level drop visibility — hardware counters plumbed into the `[PERF]` log**: `PortStats` grew an `rx_nombuf` field (was missing from the Rust wrapper even though it exists in the raw `rte_eth_stats`). `PerfReporter::start` now takes an optional `NicStatsFn` callback which it samples at baseline and on every reporting tick, computing per-tick deltas of `rte_eth_stats.imissed` / `.ierrors` / `.rx_nombuf` and emitting them as `nic_imissed=N nic_ierrors=N nic_rx_nombuf=N` fields on the `[PERF]` line. On non-DPDK backends (plain-rust) the callback is `None` and the fields are emitted as `-` so the harness can distinguish "backend has no NIC stats" from "zero NIC drops". +- **New `NIC Drops` column in the perf-test markdown summary**: `scripts/run-perf-tests.sh`'s Python aggregator now sums the per-tick NIC deltas for each TRex step window and emits a column alongside the existing App Drops column. The initial implementation uses a single combined total `imissed + ierrors + rx_nombuf` — this is what shipped for Run #10 below, but as the analysis shows, **`ierrors` is dominated by AWS ENA background noise on this instance type** and should not be lumped in with the real drop signal. A follow-up commit splits the column into `imissed / ierrors / rx_nombuf`. +- **README — new "RX Drop Hierarchy" subsection**: Documents the 5-layer drop stack (wire → NIC RX ring → NIC refill → dpdk-udp worker ring → dpdk-udp recv_queue) with which counter captures each and which column surfaces it. Plus a "How to read the columns in perf reports" section with diagnostic patterns. + +### Results: 64B Packets + +| Config | Target PPS | TX pps | RX pps | Drop % | NIC Drops¹ | App Drops | Lat Avg (us) | +|---|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | 128 | +| native-dpdk | 140K | 140,000 | 140,000 | 0.00% | — | — | 143 | +| native-dpdk | 350K | 350,000 | 350,000 | 0.00% | — | — | 163 | +| native-dpdk | 700K | 700,000 | 699,844 | 0.02% | — | — | 212 | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 39,789 | 0 | 0 | +| rust-dpdk | 140K | 140,000 | 139,000 | 0.71% | 35,748 | 0 | 0 | +| rust-dpdk | 350K | 350,000 | 349,000 | 0.29% | 31,909 | 0 | 271 | +| rust-dpdk | 700K | 700,000 | 698,981 | 0.15% | 41,911 | 0 | 382 | +| tokio-dpdk | 70K | 70,000 | 40,542 | 42.08% | 12,127 | 0 | 0 | +| tokio-dpdk | 140K | 140,000 | 40,790 | 70.86% | 5,696 | 0 | 0 | +| tokio-dpdk | 350K | 350,000 | 40,612 | 88.40% | 2,642 | 0 | 0 | +| tokio-dpdk | 700K | 700,000 | 40,508 | 94.21% | 4,577 | 0 | 0 | +| plain-rust | 70K | 70,000 | 69,000 | 1.43% | — | — | 221 | +| plain-rust | 140K | 140,000 | 139,000 | 0.71% | — | — | 0 | +| plain-rust | 350K | 350,000 | 348,997 | 0.29% | — | — | 0 | +| plain-rust | 700K | 700,000 | 542,831 | 22.45% | — | — | 0 | + +¹ NIC Drops = `imissed + ierrors + rx_nombuf` (combined for this run — see analysis about the `ierrors` pollution). + +### Results: 512B Packets + +| Config | Target PPS | TX pps | RX pps | Drop % | NIC Drops¹ | App Drops | +|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | +| native-dpdk | 140K | 140,000 | 140,000 | 0.00% | — | — | +| native-dpdk | 350K | 350,000 | 350,000 | 0.00% | — | — | +| native-dpdk | 700K | 700,000 | 699,772 | 0.03% | — | — | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 33,628 | 0 | +| rust-dpdk | 140K | 140,000 | 139,000 | 0.71% | 41,926 | 0 | +| rust-dpdk | 350K | 350,000 | 349,000 | 0.29% | 35,553 | 0 | +| rust-dpdk | 700K | 700,000 | 698,822 | 0.17% | 31,913 | 0 | +| tokio-dpdk | 70K | 70,000 | 39,732 | 43.24% | 10,827 | 0 | +| tokio-dpdk | 140K | 140,000 | 39,849 | 71.54% | 6,855 | 0 | +| tokio-dpdk | 350K | 350,000 | 40,052 | 88.56% | 2,848 | 0 | +| tokio-dpdk | 700K | 700,000 | 39,886 | 94.30% | 2,153 | 0 | +| plain-rust | 70K | 70,000 | 69,000 | 1.43% | — | — | +| plain-rust | 140K | 140,000 | 139,000 | 0.71% | — | — | +| plain-rust | 350K | 350,000 | 348,831 | 0.33% | — | — | +| plain-rust | 700K | 700,000 | 562,194 | 19.69% | — | — | + +### Results: 1400B Packets + +| Config | Target PPS | TX pps | RX pps | Drop % | NIC Drops¹ | App Drops | +|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | +| native-dpdk | 140K | 140,000 | 140,000 | 0.00% | — | — | +| native-dpdk | 350K | 350,000 | 350,000 | 0.00% | — | — | +| native-dpdk | 700K | 476,158 | 474,961 | 0.25% | — | — | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 41,913 | 0 | +| rust-dpdk | 140K | 140,000 | 139,000 | 0.71% | 33,403 | 0 | +| rust-dpdk | 350K | 350,000 | 349,000 | 0.29% | 38,510 | 0 | +| rust-dpdk | 700K | 476,366 | 475,520 | 0.18% | 25,584 | 0 | +| tokio-dpdk | 70K | 70,000 | 38,790 | 44.59% | 11,364 | 0 | +| tokio-dpdk | 140K | 140,000 | 38,692 | 72.36% | 5,221 | 0 | +| tokio-dpdk | 350K | 350,000 | 38,660 | 88.95% | 3,556 | 0 | +| tokio-dpdk | 700K | 476,587 | 41,027 | 91.39% | 2,982 | 0 | +| plain-rust | 70K | 70,000 | 69,000 | 1.43% | — | — | +| plain-rust | 140K | 140,000 | 139,000 | 0.71% | — | — | +| plain-rust | 350K | 350,000 | 348,079 | 0.55% | — | — | +| plain-rust | 700K | 476,302 | 464,598 | 2.46% | — | — | + +### Results: 8500B Packets (Jumbo) + +| Config | Target PPS | TX pps | RX pps | Drop % | NIC Drops¹ | App Drops | +|---|---|---|---|---|---|---| +| native-dpdk | 70K | 70,000 | 70,000 | 0.00% | — | — | +| native-dpdk | 140K | 78,328 | 78,316 | 0.01% | — | — | +| native-dpdk | 350K | 78,337 | 78,147 | 0.24% | — | — | +| rust-dpdk | 70K | 70,000 | 69,000 | 1.43% | 32,237 | 0 | +| rust-dpdk | 140K | 78,317 | 77,729 | 0.75% | 22,843 | 0 | +| rust-dpdk | 350K | 78,286 | 77,921 | 0.47% | 7,065 | 0 | +| tokio-dpdk | 70K | 70,000 | 29,759 | 57.49% | 7,954 | 0 | +| tokio-dpdk | 140K | 78,355 | 31,787 | 59.43% | 8,644 | 0 | +| tokio-dpdk | 350K | 78,283 | 31,761 | 59.43% | 2,932 | 0 | +| plain-rust | 70K | 70,000 | 31,414 | 55.12% | — | — | +| plain-rust | 140K | 78,291 | 77,715 | 0.73% | — | — | +| plain-rust | 350K | 78,354 | 77,797 | 0.71% | — | — | + +(700K target skipped at 8500B — exceeds 30 Gbps cap.) + +### Analysis + +**Headline finding: the single-column `NIC Drops` conflates real drops with background noise.** Run #10 was the first run with `rte_eth_stats` plumbed into the per-step harness output, and on first reading the numbers are confusing — every rust-dpdk row shows ~25K–42K NIC Drops independent of target rate, even at 64B/70K where the DUT is doing 1% of its line-rate capacity. A flat drop count across a 10× rate span cannot be rate-dependent saturation; something else is going on. + +**The non-Rust C baseline tells us what it is.** The same perf run posted a `testpmd` stats dump mid-run. Accumulated over the full 8-step native-dpdk benchmark: + +``` +RX-packets: 113,483,866 +RX-missed: 0 ← polling never fell behind +RX-errors: 403,626 ← ~50K per 30s step +RX-nombuf: 0 ← mempool never exhausted +``` + +A C binary running testpmd (which we did not write) sees `imissed = 0`, `rx_nombuf = 0`, and `ierrors ≈ 50K per 30s step`. That is essentially the same `ierrors` rate that rust-dpdk shows in every row. The `ierrors` counter on c6in.xlarge / ENA is dominated by **NIC-level events that are not test traffic being dropped** — ENA sees frames it can't deliver (bad CRCs, broadcast/management frames filtered out, frames that arrived during link-state events, etc.) and increments `ierrors` without those being TRex-measured wire loss. + +**Re-reading the numbers with `ierrors` treated as noise**: rust-dpdk's real drop signal is `imissed + rx_nombuf`, which is **effectively zero on every row**. Combined with `App Drops = 0` on every row, this means **the Rust stack's polling loop never fell behind the NIC, the mempool was never exhausted, the internal worker ring was never overflowed, and the per-socket recv_queue was never full at any rate, at any packet size, up to 700K pps at 64B**. That is a substantially stronger statement than "App Drops = 0" alone allowed us to make in Run #9 — we now know the NIC ring and mempool are also clean, not just the software layers. The ~0.15–1.43% wire-level drop that TRex reports for rust-dpdk 64B is most likely a combination of (a) ENA / AWS-path loss unrelated to the DUT and (b) TRex's per-step pps measurement resolution, which rounds the RX side down to the nearest 1K pps at low rates (so `70K → 69K` is really anywhere in [69,500, 69,999]). + +**TRex-reported wire loss `native-dpdk` vs `rust-dpdk` is a rounding artifact at low rates.** At 64B/70K, `native-dpdk` shows 0.00% and `rust-dpdk` shows 1.43% — identical drop counts in absolute terms (TX 70K, RX 70K for native vs RX 69K for rust). The difference is whether the underlying actual RX pps lands just above or just below 70,000 when TRex rounds to the nearest 1K. At 64B/700K where TRex has kpps resolution (it reports `698,981` not `699K`), both configs converge: native-dpdk 0.02%, rust-dpdk 0.15%. The two configs are essentially indistinguishable at the wire level at all tested rates. + +**`tokio-dpdk` instrumentation gap is still unresolved.** The ~40K pps ceiling reproduces identically to Run #9 across every size and rate. But now we have a new anomaly: the NIC counters show only 2K–12K "drops" per step, while TRex observes up to **20M lost packets per 30s step** at 64B/700K. The 4,000× discrepancy means the lost packets aren't being accounted for by any layer in our current drop hierarchy (NIC imissed/ierrors/rx_nombuf or software ring/recv_queue). The most likely explanation is that under tokio-dpdk's `spawn_blocking`-per-call architecture, the DPDK PMD polling thread is being starved or paused often enough that `rte_eth_stats_get` snapshots are stale — we're reading the counter at moments when the NIC itself has briefly stopped counting because its RX ring has been full and packets are being silently dropped upstream of the counter. Run #11 adds kernel-side `ethtool -S` plumbing which should make this visible via the AWS ENA `bw_in_allowance_exceeded` / `pps_allowance_exceeded` / `rx_drops` counters that DPDK doesn't surface. + +**`plain-rust` at 8500B / 70K is the one new outlier worth noting**: 55.12% drop vs <1% at the larger rate steps. Not seen in Run #9. At 8500B, 70K pps is 4.76 Gbps — well below the 30 Gbps burst cap but above the 6.25 Gbps sustained baseline. The kernel UDP path appears to have a startup-transient behavior at this particular size/rate combination that the DPDK path (rust-dpdk, native-dpdk) avoids entirely. Low priority given plain-rust's existing known limitations, but worth a note in case it reproduces in Run #11. + +### Followups Shipping With This Writeup + +1. **Split `NIC Drops` into `NIC imissed / ierrors / rx_nombuf`** sub-columns so the `ierrors` noise doesn't visually contaminate the real drop signal. (Same commit as this writeup.) +2. **Plumb `ethtool -S ens5` snapshots into the harness** — captured once before and once after each benchmark via SSM, diffed, and dumped into the per-config JSON. Gives us kernel-side ENA counters (`bw_in_allowance_exceeded`, `pps_allowance_exceeded`, `rx_drops`, `rx_frag_fail`, etc.) for **all four configs including `plain-rust`** — the first time we'll have NIC-level drop data for the kernel-stack config. (Same commit.) +3. **Investigate the tokio-dpdk instrumentation gap** — deferred until Run #11 has kernel-side NIC data in hand to compare against. + +--- + +## Run #9: tokio-dpdk Backend in Matrix + App-Level Drop Visibility + +| Field | Value | +|-------|-------| +| **Date** | 2026-04-11 | +| **Git Hash** | `db968a7` | +| **Branch** | `claude/complete-roadmap-feature-L1KJN` | +| **PR** | [#33](https://github.com/gspivey/dpdk-stdlib-rust/pull/33) | +| **GH Actions Run** | [24276173290](https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/24276173290) | +| **Instance Type** | c6in.xlarge (4 vCPU, 6.25 Gbps baseline / 30 Gbps burst) | +| **Traffic Generator** | TRex | + +### Changes Since Previous Run + +- **Threaded perf instrumentation through `dpdk-tokio`**: `AsyncUdpSocket` trait now exposes `enable_perf_reporting(interval)` and `recv_drops() -> RecvDropsSnapshot`. The DPDK backend implements both via `spawn_blocking` (cannot use `blocking_lock` inside an async runtime). The Tokio backend keeps the no-op defaults so std-net users are unchanged. New `RecvDropsSnapshot` type lives in `dpdk-tokio` so callers don't need to depend on `dpdk-udp` directly. +- **Added `tokio-dpdk` to perf-test matrix**: New config in `perf-test-stack.ts` runs `tokio-echo --features dpdk` against the same TRex profiles as the existing configs. The default perf-test config list is now `plain-rust,rust-dpdk,tokio-dpdk,native-dpdk`. +- **Per-step software drop visibility ("App Drops")**: `[PERF]` log lines now carry a `ts_unix=` prefix so the aggregator can bucket samples into TRex per-step time ranges. `run_benchmark.py` records `ts_start_unix`/`ts_end_unix` for every rate step. `aggregate_results()` reads the full set of `[PERF]` lines from each DUT and sums `rx_buf_drops + rx_ring_drops` whose reporting window overlaps each step. This number (called **App Drops** in the tables) captures **software-layer** drops inside `dpdk-udp` only: the worker SpscRing enqueue failures and the per-socket `recv_queue` overflow ("SO_RCVBUF-equivalent"). **It does NOT include NIC hardware drops** — those are counted in the separate "NIC Drops" column added below. + - **NIC Drops = `rte_eth_stats.imissed + ierrors + rx_nombuf` is NOT yet wired into Run #9** (added in a follow-up commit after Run #9 completed — see the "Instrumentation gap" note in the analysis). Every "App Drops = 0" row below should be read as "the socket buffer never overflowed", not as "the stack had zero drops". +- **Single workspace cargo build for perf instances**: `perf-test-stack.ts` previously did two cargo invocations, the second of which silently rebuilt `dpdk-stdlib-sys` *without* `--features bindgen`, leaving `tokio-echo` linked against the stub backend. Collapsed into a single `cargo build --release --features dpdk-sys/bindgen` so feature unification produces a real-DPDK binary for every workspace member. `tokio-echo` also gets `default = ["dpdk"]` so the workspace build picks up the DPDK backend without an extra `-p` flag. +- **`compat::UdpSocket` now skips DPDK in stub mode**: Added `dpdk_udp::is_stub()` re-export and gated all three compat bind sites (`compat/net.rs`, `compat/tokio.rs`, `lib.rs::bind_udp_with_config`) on `!is_stub()`. Without this, enabling the `dpdk` feature on a stub build (which now happens during workspace test runs because of `tokio-echo`'s default feature) caused `compat::UdpSocket::bind("127.0.0.1:0")` to bind to a stub DPDK socket and then hang forever in `recv_from`. +- **Fixed `frame_pool::alloc()` race**: The MPSC ring's `free()` advances `free_head` via `fetch_add(1)` *before* publishing the slot value, so a concurrent `alloc()` could observe the new head and read a stale `u32::MAX` sentinel. `alloc()` now uses `free_list[slot].swap(u32::MAX, Acquire)` with a `spin_loop` until the producer's `Release` store lands. Pre-existing race; surfaced deterministically in `--release` after the perf-instance feature unification rebuilt the test in release mode. + +### Results: 64B Packets + +#### native-dpdk (DPDK C baseline) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 125 | 0.00% | +| 140K | 140,000 | 140,000 | 145 | 0.00% | +| 350K | 350,000 | 349,999 | 160 | 0.00% | +| 700K | 700,000 | 678,911 | 485 | 3.01% | + +#### rust-dpdk (single-core, run-to-completion) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 69,000 | 204 | 1.43% | 0 | +| 140K | 140,000 | 139,000 | 0 | 0.71% | 0 | +| 350K | 350,000 | 349,000 | 0 | 0.29% | 0 | +| 700K | 700,000 | 677,828 | 0 | 3.17% | 0 | + +#### tokio-dpdk (NEW — async wrapper around dpdk-udp) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 39,954 | 0 | 42.92% | 0 | +| 140K | 140,000 | 40,319 | 0 | 71.20% | 0 | +| 350K | 350,000 | 40,192 | 0 | 88.52% | 0 | +| 700K | 700,000 | 40,172 | 0 | 94.26% | 0 | + +#### plain-rust (std::net baseline) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 184 | 1.43% | +| 140K | 140,000 | 139,000 | 0 | 0.71% | +| 350K | 350,000 | 348,785 | 203 | 0.35% | +| 700K | 700,000 | 540,674 | 0 | 22.76% | + +### Results: 512B Packets + +#### native-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 124 | 0.00% | +| 140K | 140,000 | 140,000 | 143 | 0.00% | +| 350K | 350,000 | 349,959 | 159 | 0.01% | +| 700K | 700,000 | 667,577 | 1,020 | 4.63% | + +#### rust-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 69,000 | 204 | 1.43% | 0 | +| 140K | 140,000 | 139,000 | 0 | 0.71% | 0 | +| 350K | 350,000 | 348,984 | 348 | 0.29% | 0 | +| 700K | 700,000 | 658,380 | 0 | 5.95% | 0 | + +#### tokio-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 38,728 | 0 | 44.67% | 0 | +| 140K | 140,000 | 38,661 | 0 | 72.39% | 0 | +| 350K | 350,000 | 38,772 | 0 | 88.92% | 0 | +| 700K | 700,000 | 38,686 | 0 | 94.47% | 0 | + +#### plain-rust + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | +| 140K | 140,000 | 139,000 | 0 | 0.71% | +| 350K | 350,000 | 348,837 | 235 | 0.33% | +| 700K | 700,000 | 444,207 | 0 | 36.54% | + +### Results: 1400B Packets + +#### native-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 127 | 0.00% | +| 140K | 140,000 | 140,000 | 148 | 0.00% | +| 350K | 350,000 | 349,998 | 161 | 0.00% | +| 700K | 476,273 | 473,654 | 2,647 | 0.55% | + +#### rust-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | 0 | +| 140K | 140,000 | 139,000 | 274 | 0.71% | 0 | +| 350K | 350,000 | 349,000 | 249 | 0.29% | 0 | +| 700K | 476,330 | 472,521 | 0 | 0.80% | 0 | + +#### tokio-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 37,740 | 0 | 46.09% | 0 | +| 140K | 140,000 | 37,737 | 0 | 73.04% | 0 | +| 350K | 350,000 | 37,576 | 0 | 89.26% | 0 | +| 700K | 476,529 | 40,256 | 0 | 91.55% | 0 | + +#### plain-rust + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | +| 140K | 140,000 | 138,994 | 0 | 0.72% | +| 350K | 350,000 | 348,608 | 250 | 0.40% | +| 700K | 476,267 | 451,169 | 2,608 | 5.27% | + +### Results: 8500B Packets (Jumbo) + +#### native-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 142 | 0.00% | +| 140K | 78,297 | 78,292 | 13,873 | 0.01% | +| 350K | 78,358 | 78,254 | 14,162 | 0.13% | + +#### rust-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | 0 | +| 140K | 78,284 | 77,695 | 0 | 0.75% | 0 | +| 350K | 78,297 | 77,579 | 0 | 0.92% | 0 | + +#### tokio-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | App Drops | +|-----------|--------|--------|-------------------|--------|-----------| +| 70K | 70,000 | 30,010 | 0 | 57.13% | 0 | +| 140K | 78,314 | 31,850 | 0 | 59.33% | 0 | +| 350K | 78,289 | 31,795 | 0 | 59.39% | 0 | + +#### plain-rust + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 33,773 | 0 | 51.75% | +| 140K | 78,286 | 77,720 | 0 | 0.72% | +| 350K | 78,308 | 77,929 | 0 | 0.48% | + +(700K target skipped at 8500B — exceeds 30 Gbps cap.) + +### Analysis + +**`tokio-dpdk` now actually links against DPDK** (the headline fix). Run #8 had every `tokio-dpdk` row at 100% drop because `perf-test-stack.ts` did two separate cargo invocations and the second one rebuilt `dpdk-stdlib-sys` without bindgen, leaving `tokio-echo` linked against the stub backend that silently dropped every packet. This run uses a single workspace build with `--features dpdk-sys/bindgen` plus `default = ["dpdk"]` on `tokio-echo`, and `dmesg` confirms `vfio-pci ... opened by user (tokio-rt-worker:*)` on the perf instance — the binary is genuinely doing DPDK I/O. + +**`tokio-dpdk` plateaus at ~38–40K RX pps regardless of target rate.** Across every packet size and every target PPS step from 70K to 700K, RX flatlines at the same ~38K (1400B), ~38–40K (64B/512B), or ~30–32K (8500B) — independent of how hard TRex pushes. Drop rates climb from 43% at 70K to 94% at 700K, but the absolute RX number doesn't move. **App Drops is `0` on every row**, which here means "the `dpdk-udp` `recv_queue` never overflowed" — the consumer, such as it is, is draining the socket buffer as fast as packets land in it. It does **not** prove where the actual loss is. The most likely explanation is that packets are being dropped **below** the socket layer, at the DPDK NIC RX descriptor ring: the consumer calls `rte_eth_rx_burst` via two `spawn_blocking` hops per packet (≈25 µs), so refill happens at ~40K pps while the NIC is offered up to 700K pps. The HW ring fills, the NIC has nowhere to DMA new packets, and `rte_eth_stats.imissed` ticks up. We don't have numeric confirmation of this yet because the perf-reporter at the time of Run #9 was only reading software-layer counters — see the instrumentation gap note below. + +**Root cause is the `spawn_blocking` per-call cost in the compat shim.** The current `dpdk-tokio` `DpdkUdpSocket` wraps a sync `dpdk_udp::UdpSocket` and routes every `recv_from` / `send_to` through `tokio::task::spawn_blocking`. Each call hops to the blocking thread pool, acquires a `Mutex`, runs the sync I/O, and hops back. For an echo workload that's two `spawn_blocking` round-trips per packet — empirically ~25 µs of overhead per packet, which works out to roughly 40K pps. This is an architectural property of the current compat layer, not a bug; the compat layer exists for `tokio::net::UdpSocket` API compatibility, not raw throughput. Production code wanting the full DPDK throughput should use the sync `dpdk_udp::UdpSocket` directly (the `rust-dpdk` config is the proof point: same NIC, same kernel-bypass path, ~17× the throughput). + +**`rust-dpdk` continues to track `native-dpdk` closely.** At 64B/350K both deliver ~349K RX pps with <0.3% drops; at 64B/700K both fall off to ~678K (3.0% native vs 3.2% rust). At 1400B/700K both saturate at the ~476K bandwidth ceiling and track within 0.25%. The pure-Rust user-space stack continues to have no measurable throughput cost vs. testpmd at sub-saturation rates — only the run-to-completion polling overhead near the bandwidth ceiling. + +**`plain-rust` collapses at 64B/700K** (22.8% drop, 540K RX pps) and 512B/700K (36.5% drop, 444K RX pps), exactly as in Runs #6 and #7 — the kernel softirq path can't keep up with small-packet line rate, while both DPDK Rust configs hold up. + +**What "App Drops = 0" actually tells us (and what it doesn't).** On `rust-dpdk` it's 0 at every rate, including 64B/700K where there's a clear ~3.17% RX/TX gap (22,172 pps missing) — and the doc wants to be precise here because the column name is easy to misread: + +- **What App Drops measures**: the sum of `rx_drops_ring_full` + `rx_drops_buffer_full` exported by `PerfCounters` on the `dpdk-udp` socket. `rx_drops_ring_full` is the internal **software** SpscRing between the worker thread and the app thread (multi-core pipelines only); `rx_drops_buffer_full` is `recv_queue.push()` rejections against the per-socket SO_RCVBUF-equivalent cap (4096 pkts / 256 KiB). Both are **software-layer** drops inside the Rust stack. +- **What it does NOT measure**: the NIC hardware RX descriptor ring (`rte_eth_stats.imissed`), NIC errors (`ierrors`), or mempool-exhaustion refill failures (`rx_nombuf`). Packets that die in those layers never reach the socket path, so they can't show up in App Drops no matter how much they drop. +- **So on the 64B/700K rust-dpdk row with App Drops = 0**: all we can conclude is that the `dpdk-udp` socket buffer was never under pressure during the run. The 22,172 missing pps could still be (a) dropped at the NIC RX ring because the run-to-completion loop briefly fell behind a burst, (b) dropped due to mempool exhaustion, or (c) lost upstream on the wire / at the AWS ENA rate limiter / in the VPC path. The column alone cannot distinguish these. `native-dpdk` hitting the same ~3% at the same step is suggestive of option (c), but is not conclusive. + +**Instrumentation gap — followed up after Run #9.** Run #9 shipped with software-layer drop visibility only. A follow-up commit (same branch, post-Run-#9) extends `PerfReporter` to also snapshot `rte_eth_stats` every reporting tick and emit `nic_imissed`, `nic_ierrors`, and `nic_rx_nombuf` fields in the `[PERF]` line. The perf-test harness parses them into a new **NIC Drops** column alongside App Drops. With both columns in place, future runs will be able to directly answer "is the drop happening at the wire, at the NIC, inside the socket, or at the app", instead of inferring from deltas. Run #10 will be the first run with NIC Drops populated. + +**Frame-pool race fix is invisible in numbers but unblocked the run.** The pre-existing `MPSC` ring race in `frame_pool::alloc()` (free advances head before publishing the slot, alloc reads `u32::MAX` sentinel) was hidden by lucky scheduling in debug builds. Once the perf-test feature unification fix above landed, the test was rebuilt in release mode and triggered the race deterministically (`pool_producer_consumer` panicked with `range start index 549755813760 out of range`). Fixed by switching `alloc()` to `swap(u32::MAX, Acquire)` with a `spin_loop` waiting for the producer's `Release` store. No measurable performance impact — same numbers as Run #7 on `rust-dpdk`. + +--- + +## Run #7: RX Backpressure & Drop Counters + +| Field | Value | +|-------|-------| +| **Date** | 2026-04-11 | +| **Git Hash** | `28f13ce` | +| **Branch** | `claude/complete-roadmap-feature-L1KJN` | +| **PR** | [#33](https://github.com/gspivey/dpdk-stdlib-rust/pull/33) | +| **GH Actions Run** | [24272558854](https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/24272558854) | +| **Instance Type** | c6in.xlarge (4 vCPU, 6.25 Gbps baseline / 30 Gbps burst) | +| **Traffic Generator** | TRex | + +### Changes Since Previous Run + +- **Socket-level RX buffer accounting**: `ReceiveQueue` now tracks `current_bytes` against a configurable byte limit (`max_bytes`, default 256 KiB — mirrors Linux `net.core.rmem_default`) in addition to the existing per-packet cap (4096 packets). Packets that would exceed either limit are rejected at enqueue time. +- **Lock-free drop counters**: Added `rx_dropped_packets` / `rx_dropped_bytes` `AtomicU64` fields directly on `UdpSocket` so `recv_drops()` is a lock-free read on the hot path (no contention with the queue mutex). +- **New public API on `UdpSocket`**: `recv_buffer_size()`, `set_recv_buffer_size(bytes)` (SO_RCVBUF equivalent, rejects 0), `recv_buffer_bytes()` (current usage), `recv_drops() -> RecvDropStats { packets, bytes }`, and `reset_recv_drops()`. +- **PerfCounters**: New `rx_drops_buffer_full` counter, exported via `CounterSnapshot` and folded into the aggregate `rx_drops` rate computed by `rates_since()`. +- **18 new unit tests** in `dpdk-udp/src/lib.rs` covering buffer-byte accounting, packet-cap vs byte-cap rejection, drop-stat snapshots, set/reset semantics, and zero-rejection. +- **Roadmap**: Marked "RX backpressure and drop counters" as Done in README (was the most important production gap). +- All four `recv_queue.push()` call sites (multicore connected-filter, RTC connected-filter, RTC burst overflow, ARP resolution loop) updated to record drops via `record_rx_drop()` on rejection. + +### Results: 64B Packets + +#### native-dpdk (DPDK C baseline) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 114 | 0.00% | +| 140K | 140,000 | 140,000 | 128 | 0.00% | +| 350K | 350,000 | 350,000 | 144 | 0.00% | +| 700K | 700,000 | 698,646 | 190 | 0.19% | + +#### rust-dpdk (single-core, run-to-completion) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 0.27% | +| 140K | 140,000 | 139,000 | 0 | 0.71% | +| 350K | 350,000 | 349,000 | 0 | 0.29% | +| 700K | 700,000 | 698,111 | 0 | 0.27% | + +#### plain-rust (std::net baseline) + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 0.43% | +| 140K | 140,000 | 139,000 | 0 | 0.71% | +| 350K | 350,000 | 348,798 | 0 | 0.34% | +| 700K | 700,000 | 615,219 | 1,008 | 12.11% | + +### Results: 512B Packets + +#### native-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 122 | 0.00% | +| 140K | 140,000 | 140,000 | 133 | 0.00% | +| 350K | 350,000 | 350,000 | 148 | 0.00% | +| 700K | 700,000 | 695,992 | 246 | 0.57% | + +#### rust-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | +| 140K | 140,000 | 139,000 | 0 | 0.71% | +| 350K | 350,000 | 348,993 | 293 | 0.29% | +| 700K | 700,000 | 695,988 | 276 | 0.57% | + +#### plain-rust + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 199 | 1.43% | +| 140K | 140,000 | 138,999 | 201 | 0.71% | +| 350K | 350,000 | 348,941 | 0 | 0.30% | +| 700K | 700,000 | 459,159 | 0 | 34.41% | + +### Results: 1400B Packets + +#### native-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 130 | 0.00% | +| 140K | 140,000 | 140,000 | 139 | 0.00% | +| 350K | 350,000 | 350,000 | 152 | 0.00% | +| 700K | 476,553 | 475,121 | 3,058 | 0.30% | + +#### rust-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | +| 140K | 140,000 | 139,000 | 304 | 0.71% | +| 350K | 350,000 | 349,000 | 0 | 0.29% | +| 700K | 476,285 | 475,572 | 0 | 0.15% | + +#### plain-rust + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 0 | 1.43% | +| 140K | 140,000 | 138,989 | 245 | 0.72% | +| 350K | 350,000 | 348,786 | 0 | 0.35% | +| 700K | 476,276 | 466,257 | 0 | 2.10% | + +### Results: 8500B Packets (Jumbo) + +#### native-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 70,000 | 160 | 0.00% | +| 140K | 78,291 | 78,287 | 14,078 | 0.00% | +| 350K | 78,355 | 78,083 | 14,297 | 0.35% | + +#### rust-dpdk + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 69,000 | 592 | 1.43% | +| 140K | 78,305 | 77,713 | 14,039 | 0.76% | +| 350K | 78,343 | 77,653 | 0 | 0.88% | + +#### plain-rust + +| Target PPS | TX pps | RX pps | Avg Latency (us) | Drop % | +|-----------|--------|--------|-------------------|--------| +| 70K | 70,000 | 31,193 | 217 | 55.44% | +| 140K | 78,291 | 77,727 | 0 | 0.72% | +| 350K | 78,284 | 77,595 | 0 | 0.88% | + +(700K target skipped at 8500B — exceeds 30 Gbps cap, capped TX ≈ 78K pps) + +### Analysis + +**No regression from RX backpressure changes**: All three configs deliver numbers consistent with Run #6 at the same packet sizes. The new accounting only runs on the slow path (when the per-packet `recv_queue.push()` succeeds, the only added work is `current_bytes += size` — a single integer add under the existing mutex). No new atomic ops on the success path; the atomic counters fire only on rejection. This run confirms the design assumption that drop accounting is free at sub-saturation rates. + +**rust-dpdk continues to track native-dpdk**: At 64B/700K, rust-dpdk delivers 698,111 RX pps vs native-dpdk's 698,646 — within 0.08%. At 512B/700K, rust-dpdk hits 695,988 vs native-dpdk's 695,992 — essentially identical. At 1400B/700K, both saturate at the ~476K bandwidth ceiling and track within 100 pps of each other. + +**rust-dpdk dominates plain-rust at saturation**: The most striking comparison is 512B/700K where rust-dpdk delivers 695,988 RX pps (0.57% drop) while plain-rust collapses to 459,159 RX pps (34.41% drop) — **1.5x throughput**. At 64B/700K, rust-dpdk holds 698K pps while plain-rust drops to 615K (12% drop). The kernel's bottleneck dominates above 350K PPS for small packets. + +**rust-dpdk is now the clear small-packet winner**: For 64B, 512B, and 1400B at 350K PPS, rust-dpdk delivers ~349K RX pps with <0.3% drops — matching native-dpdk and beating plain-rust which holds up but at higher drop rates. At 700K PPS the gap becomes a chasm for plain-rust at 512B (34% drop) while rust-dpdk holds 0.6%. + +**Jumbo frames remain bandwidth-limited**: At 8500B, all three configs converge near 78K PPS (~5.3 Gbps) — the c6in.xlarge ENA single-flow ceiling. Drop rates and latencies match Run #6 within noise. The 8500B/70K plain-rust outlier (55% drop) is the same kernel jumbo-frame artifact seen in Run #6 at the same configuration. + +**Buffer accounting is invisible at line rate**: No 700K-pps row shows any rust-dpdk regression vs Run #6, despite the new `current_bytes += payload.len()` work happening on every successful enqueue. The byte-accounting cost is below the measurement noise floor at all tested rates. + +--- + ## Run #6: Jumbo Frame Support (8500B Packets) | Field | Value | diff --git a/dpdk-tokio/src/compat/net.rs b/dpdk-tokio/src/compat/net.rs index 0ef2aa5..19de882 100644 --- a/dpdk-tokio/src/compat/net.rs +++ b/dpdk-tokio/src/compat/net.rs @@ -53,15 +53,20 @@ impl UdpSocket { #[cfg(feature = "dpdk")] { - // Try DPDK first - match dpdk_udp::UdpSocket::bind(addr) { - Ok(socket) => { - return Ok(UdpSocket { - inner: UdpSocketInner::Dpdk(socket), - }); - } - Err(e) => { - eprintln!("DPDK bind failed ({}), falling back to std", e); + // Skip DPDK entirely when linked against the stub backend — a stub + // socket would bind successfully but never produce/consume any + // packets, so loopback I/O would silently hang. + if !dpdk_udp::is_stub() { + // Try DPDK first + match dpdk_udp::UdpSocket::bind(addr) { + Ok(socket) => { + return Ok(UdpSocket { + inner: UdpSocketInner::Dpdk(socket), + }); + } + Err(e) => { + eprintln!("DPDK bind failed ({}), falling back to std", e); + } } } } diff --git a/dpdk-tokio/src/compat/tokio.rs b/dpdk-tokio/src/compat/tokio.rs index 2c740f7..ceda71f 100644 --- a/dpdk-tokio/src/compat/tokio.rs +++ b/dpdk-tokio/src/compat/tokio.rs @@ -63,26 +63,31 @@ impl UdpSocket { #[cfg(feature = "dpdk")] { - // Try DPDK first (blocking init in spawn_blocking) - let dpdk_result = ::tokio::task::spawn_blocking(move || { - dpdk_udp::UdpSocket::bind(addr) - }).await; - - match dpdk_result { - Ok(Ok(socket)) => { - let local_addr = socket.local_addr()?; - return Ok(UdpSocket { - inner: UdpSocketInner::Dpdk(DpdkAsyncSocket { - socket: std::sync::Arc::new(::tokio::sync::Mutex::new(socket)), - local_addr, - }), - }); - } - Ok(Err(e)) => { - eprintln!("DPDK bind failed ({}), falling back to tokio", e); - } - Err(e) => { - eprintln!("DPDK spawn_blocking failed ({}), falling back to tokio", e); + // Skip DPDK entirely when linked against the stub backend — a stub + // socket would bind successfully but never produce/consume any + // packets, so loopback I/O would silently hang. + if !dpdk_udp::is_stub() { + // Try DPDK first (blocking init in spawn_blocking) + let dpdk_result = ::tokio::task::spawn_blocking(move || { + dpdk_udp::UdpSocket::bind(addr) + }).await; + + match dpdk_result { + Ok(Ok(socket)) => { + let local_addr = socket.local_addr()?; + return Ok(UdpSocket { + inner: UdpSocketInner::Dpdk(DpdkAsyncSocket { + socket: std::sync::Arc::new(::tokio::sync::Mutex::new(socket)), + local_addr, + }), + }); + } + Ok(Err(e)) => { + eprintln!("DPDK bind failed ({}), falling back to tokio", e); + } + Err(e) => { + eprintln!("DPDK spawn_blocking failed ({}), falling back to tokio", e); + } } } } diff --git a/dpdk-tokio/src/lib.rs b/dpdk-tokio/src/lib.rs index ac4d21c..40a4591 100644 --- a/dpdk-tokio/src/lib.rs +++ b/dpdk-tokio/src/lib.rs @@ -27,6 +27,7 @@ use std::io; use std::net::SocketAddr; +use std::time::Duration; use async_trait::async_trait; use thiserror::Error; @@ -85,6 +86,46 @@ pub trait AsyncUdpSocket: Send + Sync { /// Returns the name of the backend (for logging/debugging) fn backend_name(&self) -> &'static str; + + /// Enable background performance reporting. + /// + /// On the DPDK backend this starts a `PerfReporter` thread that emits + /// `[PERF]` log lines (rx/tx pps, drop counters, latency percentiles) + /// to stderr every `interval`. On the Tokio backend this is a no-op + /// because `tokio::net::UdpSocket` does not expose internal counters. + /// Returns `Ok(())` either way so callers can opt in unconditionally. + async fn enable_perf_reporting(&self, _interval: Duration) -> io::Result<()> { + Ok(()) + } + + /// Stop background performance reporting and flush the final snapshot. + /// + /// On the DPDK backend this joins the `PerfReporter` thread, which + /// triggers emission of the one-shot `[NIC-FINAL]` log line that the + /// perf harness pairs with `[NIC-BASELINE]` for the instrumentation + /// self-check. Call this before dropping the socket on shutdown so + /// the flush is deterministic and not dependent on Arc-refcount timing. + /// On the Tokio backend this is a no-op. + async fn disable_perf_reporting(&self) {} + + /// Snapshot of socket-level RX drops (`SO_RCVBUF`-style backpressure). + /// + /// On the DPDK backend this returns the live counter from the underlying + /// `dpdk_udp::UdpSocket`. On the Tokio backend it returns zeros — the + /// kernel manages its own RX buffer and we have no programmatic view of it. + async fn recv_drops(&self) -> RecvDropsSnapshot { + RecvDropsSnapshot::default() + } +} + +/// Backend-agnostic snapshot of socket-level RX drops. +/// +/// Mirrors `dpdk_udp::RecvDropStats` but lives in `dpdk-tokio` so callers +/// don't need to depend on `dpdk-udp` directly. +#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)] +pub struct RecvDropsSnapshot { + pub packets: u64, + pub bytes: u64, } /// Socket configuration options @@ -130,12 +171,19 @@ pub async fn bind_udp_with_config( #[cfg(feature = "dpdk")] if config.prefer_dpdk { - match DpdkUdpSocket::bind_with_config(addr, &config).await { - Ok(socket) => { - return Ok(Box::new(socket)); - } - Err(e) => { - eprintln!("DPDK init failed ({}), falling back to Tokio", e); + // Skip DPDK entirely when linked against the stub backend — a stub + // socket would bind successfully but never produce/consume any + // packets, so any I/O would silently hang. + if dpdk_udp::is_stub() { + eprintln!("dpdk-sys is in stub mode, falling back to Tokio"); + } else { + match DpdkUdpSocket::bind_with_config(addr, &config).await { + Ok(socket) => { + return Ok(Box::new(socket)); + } + Err(e) => { + eprintln!("DPDK init failed ({}), falling back to Tokio", e); + } } } } diff --git a/dpdk-tokio/src/socket.rs b/dpdk-tokio/src/socket.rs index ff16d7b..2288d35 100644 --- a/dpdk-tokio/src/socket.rs +++ b/dpdk-tokio/src/socket.rs @@ -2,11 +2,13 @@ use crate::AsyncUdpSocket; #[cfg(feature = "dpdk")] -use crate::SocketConfig; +use crate::{RecvDropsSnapshot, SocketConfig}; use async_trait::async_trait; use std::io; use std::net::SocketAddr; use std::sync::Arc; +#[cfg(feature = "dpdk")] +use std::time::Duration; use tokio::sync::Mutex; /// Type alias for boxed async UDP sockets @@ -209,4 +211,38 @@ impl AsyncUdpSocket for DpdkUdpSocket { fn backend_name(&self) -> &'static str { "dpdk" } + + async fn enable_perf_reporting(&self, interval: Duration) -> io::Result<()> { + let socket = self.inner.clone(); + tokio::task::spawn_blocking(move || { + let socket = socket.blocking_lock(); + socket.enable_perf_reporting(interval) + }).await + .map_err(|e| io::Error::new(io::ErrorKind::Other, e))? + } + + async fn disable_perf_reporting(&self) { + let socket = self.inner.clone(); + // spawn_blocking because disable_perf_reporting joins the reporter + // thread (blocking), and we must not block the async runtime thread. + // The final `[NIC-FINAL]` stderr line is emitted synchronously as + // part of PerfReporter::drop() inside this call. + let _ = tokio::task::spawn_blocking(move || { + let socket = socket.blocking_lock(); + socket.disable_perf_reporting(); + }).await; + } + + async fn recv_drops(&self) -> RecvDropsSnapshot { + let socket = self.inner.clone(); + tokio::task::spawn_blocking(move || { + let socket = socket.blocking_lock(); + let stats = socket.recv_drops(); + RecvDropsSnapshot { + packets: stats.packets, + bytes: stats.bytes, + } + }).await + .unwrap_or_default() + } } diff --git a/dpdk-udp/src/frame_pool.rs b/dpdk-udp/src/frame_pool.rs index 5a07c2b..9ce4cf4 100644 --- a/dpdk-udp/src/frame_pool.rs +++ b/dpdk-udp/src/frame_pool.rs @@ -168,8 +168,20 @@ impl FramePool { return None; // pool exhausted } + // Read the slot. There is a race with `free()` because free advances + // `free_head` *before* writing the slot, so we may observe the new + // head with the slot still holding its previous sentinel value + // (`u32::MAX`). Spin until the producer has finished publishing the + // index, and consume it via `swap` so the slot is left in the + // sentinel state for the next round. let slot = (tail & self.free_mask()) as usize; - let idx = self.free_list[slot].load(Ordering::Relaxed); + let idx = loop { + let v = self.free_list[slot].swap(u32::MAX, Ordering::Acquire); + if v != u32::MAX { + break v; + } + std::hint::spin_loop(); + }; self.free_tail.store(tail + 1, Ordering::Release); Some(idx) diff --git a/dpdk-udp/src/lib.rs b/dpdk-udp/src/lib.rs index d63fa6b..97469be 100644 --- a/dpdk-udp/src/lib.rs +++ b/dpdk-udp/src/lib.rs @@ -15,7 +15,7 @@ use std::cell::UnsafeCell; use std::io; use std::net::{Ipv4Addr, SocketAddr, SocketAddrV4, ToSocketAddrs}; use std::sync::{Arc, Mutex, RwLock}; -use std::sync::atomic::{AtomicBool, AtomicU16, AtomicUsize, Ordering}; +use std::sync::atomic::{AtomicBool, AtomicU16, AtomicU64, AtomicUsize, Ordering}; use std::collections::VecDeque; use std::time::{Duration, Instant}; @@ -25,6 +25,17 @@ use dpdk::mbuf::MempoolConfig; pub use dpdk::port::{RxOffload as HwRxOffload, TxOffload as HwTxOffload}; +/// Returns true when this build is linked against the dpdk-sys stub backend +/// (no real DPDK library found at compile time, or the `bindgen` feature +/// was not enabled). +/// +/// Re-exported from `dpdk_sys::is_stub` so callers don't need to take a +/// direct dependency on `dpdk-sys`. +#[inline] +pub fn is_stub() -> bool { + dpdk_sys::is_stub() +} + use thiserror::Error; // ============================================================================ @@ -51,7 +62,9 @@ pub use backend_raw::RawSocketBackend; pub use ring::{SpscRing, MpscRing}; pub use topology::{TopologyConfig, TopologyPlan, TopologySource, MultiCoreTopology, ProcessedPacket, TxFrame}; pub use frame_pool::{AppPacket, FramePool, FrameRef}; -pub use perf::{PerfCounters, PerfSnapshot, PerfReporter, LatencySampler}; +pub use perf::{ + LatencySampler, NicStatsFn, NicStatsSnapshot, PerfCounters, PerfReporter, PerfSnapshot, +}; pub use routing::{RoutingTable, NetworkConfig, RouteEntry, NextHop, ProcArpEntry}; // ============================================================================ @@ -1198,32 +1211,75 @@ impl ConnectionState { } } -/// Receive queue for buffering packets +/// Default socket-level receive buffer size in bytes. +/// +/// Mirrors the Linux kernel default for `SO_RCVBUF` (approximately 208 KiB on +/// modern kernels). Applications that need more headroom can call +/// [`UdpSocket::set_recv_buffer_size`] after `bind()`. +pub const DEFAULT_RECV_BUFFER_BYTES: usize = 256 * 1024; + +/// Hard upper bound on queued packet count — a secondary safety net against +/// pathological small-payload floods. Byte accounting is the primary limit. +pub const DEFAULT_RECV_BUFFER_PACKETS: usize = 4096; + +/// Snapshot of socket-level receive drop counters, surfaced via +/// [`UdpSocket::recv_drops`]. Applications use these to detect when their +/// receive buffer is too small (`SO_RCVBUF` equivalent). +#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)] +pub struct RecvDropStats { + /// Number of UDP payloads dropped because the socket receive buffer was full. + pub packets: u64, + /// Total bytes of payload dropped because the socket receive buffer was full. + pub bytes: u64, +} + +/// Receive queue for buffering packets. +/// +/// Tracks both packet count (`max_packets`) and total queued payload bytes +/// (`max_bytes`). This mirrors the Linux kernel's `sk_rcvbuf`/`sk_rmem_alloc` +/// accounting: when either limit is exceeded, the incoming packet is dropped +/// and the caller is expected to bump the socket-level drop counters. struct ReceiveQueue { /// Buffered packets: (payload, source_addr) packets: VecDeque<(Vec, SocketAddr)>, - /// Maximum queue size - max_size: usize, + /// Maximum number of buffered packets — secondary safety limit. + max_packets: usize, + /// Maximum queued payload bytes — primary limit (SO_RCVBUF equivalent). + max_bytes: usize, + /// Current queued payload bytes. + current_bytes: usize, } impl ReceiveQueue { - fn new(max_size: usize) -> Self { + fn with_limits(max_packets: usize, max_bytes: usize) -> Self { Self { - packets: VecDeque::with_capacity(max_size), - max_size, + // Pre-allocate with a modest capacity; VecDeque will grow as needed. + packets: VecDeque::with_capacity(max_packets.min(1024)), + max_packets, + max_bytes, + current_bytes: 0, } } - fn push(&mut self, payload: Vec, src: SocketAddr) -> bool { - if self.packets.len() >= self.max_size { - return false; // Queue full + /// Try to enqueue a packet. On success returns `Ok(())`. On failure returns + /// `Err(payload)` so the caller can inspect the dropped payload length for + /// drop-counter accounting (and recover the allocation if desired). + fn push(&mut self, payload: Vec, src: SocketAddr) -> Result<(), Vec> { + let size = payload.len(); + if self.packets.len() >= self.max_packets + || self.current_bytes.saturating_add(size) > self.max_bytes + { + return Err(payload); } + self.current_bytes += size; self.packets.push_back((payload, src)); - true + Ok(()) } fn pop(&mut self) -> Option<(Vec, SocketAddr)> { - self.packets.pop_front() + let (payload, src) = self.packets.pop_front()?; + self.current_bytes = self.current_bytes.saturating_sub(payload.len()); + Some((payload, src)) } #[allow(dead_code)] @@ -1234,6 +1290,18 @@ impl ReceiveQueue { fn len(&self) -> usize { self.packets.len() } + + fn bytes(&self) -> usize { + self.current_bytes + } + + fn max_bytes(&self) -> usize { + self.max_bytes + } + + fn set_max_bytes(&mut self, max_bytes: usize) { + self.max_bytes = max_bytes; + } } // ============================================================================ @@ -1438,6 +1506,11 @@ pub struct UdpSocket { has_connection_state: AtomicBool, /// Subnet-aware routing table for next-hop MAC resolution. routing_table: RoutingTable, + /// Number of UDP payloads dropped because the socket receive buffer was full. + /// Lock-free read via `recv_drops()` — mirrors Linux `sk_drops`. + rx_dropped_packets: AtomicU64, + /// Total bytes of payload dropped due to receive buffer overflow. + rx_dropped_bytes: AtomicU64, } impl UdpSocket { @@ -1507,7 +1580,10 @@ impl UdpSocket { arp_handler, icmp_handler, connection_state: RwLock::new(None), - recv_queue: Mutex::new(ReceiveQueue::new(1024)), + recv_queue: Mutex::new(ReceiveQueue::with_limits( + DEFAULT_RECV_BUFFER_PACKETS, + DEFAULT_RECV_BUFFER_BYTES, + )), auto_arp: true, auto_icmp: true, read_timeout: Mutex::new(None), @@ -1526,6 +1602,8 @@ impl UdpSocket { has_buffered_packets: AtomicBool::new(false), has_connection_state: AtomicBool::new(false), routing_table, + rx_dropped_packets: AtomicU64::new(0), + rx_dropped_bytes: AtomicU64::new(0), }) } @@ -1608,7 +1686,10 @@ impl UdpSocket { arp_handler, icmp_handler, connection_state: RwLock::new(None), - recv_queue: Mutex::new(ReceiveQueue::new(1024)), + recv_queue: Mutex::new(ReceiveQueue::with_limits( + DEFAULT_RECV_BUFFER_PACKETS, + DEFAULT_RECV_BUFFER_BYTES, + )), auto_arp: true, auto_icmp: true, read_timeout: Mutex::new(None), @@ -1627,6 +1708,8 @@ impl UdpSocket { has_buffered_packets: AtomicBool::new(false), has_connection_state: AtomicBool::new(false), routing_table, + rx_dropped_packets: AtomicU64::new(0), + rx_dropped_bytes: AtomicU64::new(0), }) } @@ -1886,8 +1969,11 @@ impl UdpSocket { if let Some(connected) = *self.connected_addr.lock().unwrap() { if app_pkt.src_addr != connected { let mut queue = self.recv_queue.lock().unwrap(); - queue.push(buf[..copy_len].to_vec(), app_pkt.src_addr); - self.has_buffered_packets.store(true, Ordering::Release); + if queue.push(buf[..copy_len].to_vec(), app_pkt.src_addr).is_err() { + self.record_rx_drop(copy_len); + } else { + self.has_buffered_packets.store(true, Ordering::Release); + } continue; } } @@ -2139,9 +2225,12 @@ impl UdpSocket { // If connected, only accept packets from the connected address if let Some(connected) = *self.connected_addr.lock().unwrap() { if src_addr != connected { + let payload_len = parsed.payload.len(); let mut queue = self.recv_queue.lock().unwrap(); // Must allocate here — queued packets outlive the frame/mbuf - queue.push(parsed.payload.to_vec(), src_addr); + if queue.push(parsed.payload.to_vec(), src_addr).is_err() { + self.record_rx_drop(payload_len); + } return None; } } @@ -2160,8 +2249,11 @@ impl UdpSocket { *result = Some((copy_len, src_addr)); } else { // Additional matching packets: must allocate for the queue + let payload_len = parsed.payload.len(); let mut queue = self.recv_queue.lock().unwrap(); - queue.push(parsed.payload.to_vec(), src_addr); + if queue.push(parsed.payload.to_vec(), src_addr).is_err() { + self.record_rx_drop(payload_len); + } } None @@ -2361,8 +2453,11 @@ impl UdpSocket { let src_addr = SocketAddr::V4( SocketAddrV4::new(parsed.src_ip, parsed.src_port) ); + let payload_len = parsed.payload.len(); let mut queue = self.recv_queue.lock().unwrap(); - queue.push(parsed.payload, src_addr); + if queue.push(parsed.payload, src_addr).is_err() { + self.record_rx_drop(payload_len); + } } } } @@ -2410,6 +2505,81 @@ impl UdpSocket { self.recv_queue.lock().unwrap().len() } + // ======================================================================== + // Receive Buffer Backpressure (SO_RCVBUF equivalent) + // ======================================================================== + + /// Returns the configured socket receive buffer size in bytes. + /// + /// Mirrors `getsockopt(SO_RCVBUF)` on a POSIX socket. When the queued + /// payload bytes exceed this limit, incoming packets are dropped and the + /// drop counters exposed by [`recv_drops`](Self::recv_drops) are bumped. + pub fn recv_buffer_size(&self) -> usize { + self.recv_queue.lock().unwrap().max_bytes() + } + + /// Set the socket receive buffer size in bytes. + /// + /// Mirrors `setsockopt(SO_RCVBUF)` on a POSIX socket. The new limit is + /// applied immediately — subsequent pushes that would exceed it are + /// rejected and counted via [`recv_drops`](Self::recv_drops). Already-queued + /// packets are not evicted. + /// + /// Returns `InvalidInput` if `bytes` is zero. + pub fn set_recv_buffer_size(&self, bytes: usize) -> io::Result<()> { + if bytes == 0 { + return Err(io::Error::new( + io::ErrorKind::InvalidInput, + "recv buffer size must be > 0", + )); + } + self.recv_queue.lock().unwrap().set_max_bytes(bytes); + Ok(()) + } + + /// Returns the total bytes of queued payload currently held in the + /// receive buffer. Useful for watermark-style monitoring. + pub fn recv_buffer_bytes(&self) -> usize { + self.recv_queue.lock().unwrap().bytes() + } + + /// Returns socket-level receive drop counters. + /// + /// These increment whenever a UDP payload is rejected because the socket + /// receive buffer was full. Applications should periodically diff the + /// values to detect receive-side backpressure in production. + /// + /// Equivalent in spirit to the Linux `sk_drops` counter surfaced via + /// `/proc/net/udp` column 13 or `ss -u -a -e`. + pub fn recv_drops(&self) -> RecvDropStats { + RecvDropStats { + packets: self.rx_dropped_packets.load(Ordering::Relaxed), + bytes: self.rx_dropped_bytes.load(Ordering::Relaxed), + } + } + + /// Reset the receive drop counters to zero. + /// + /// Intended for test harnesses and long-running services that want to + /// measure drops over a specific window. Thread-safe. + pub fn reset_recv_drops(&self) { + self.rx_dropped_packets.store(0, Ordering::Relaxed); + self.rx_dropped_bytes.store(0, Ordering::Relaxed); + } + + /// Internal: record a receive-buffer drop (packet + bytes). + /// + /// Called from every `recv_queue.push()` call site when the push fails + /// because either the packet-count or byte limit would be exceeded. Also + /// bumps the `rx_drops_buffer_full` perf counter for the perf reporter. + #[inline] + fn record_rx_drop(&self, payload_len: usize) { + self.rx_dropped_packets.fetch_add(1, Ordering::Relaxed); + self.rx_dropped_bytes + .fetch_add(payload_len as u64, Ordering::Relaxed); + perf_inc!(self.perf_counters.rx_drops_buffer_full); + } + // ======================================================================== // Multicast Support // ======================================================================== @@ -2530,10 +2700,30 @@ impl UdpSocket { if reporter_guard.is_some() { return Ok(()); // already running } + + // Build a NIC stats callback for DPDK-backed sockets so the perf + // reporter can emit `nic_imissed`/`nic_ierrors`/`nic_rx_nombuf` + // deltas alongside the software-layer counters. Non-DPDK backends + // (AF_PACKET, generic) pass `None` and the reporter emits "-". + let nic_stats_fn: Option = match &self.socket_backend { + SocketBackend::Dpdk(res) => { + let res = Arc::clone(res); + Some(Box::new(move || { + res.port.stats().ok().map(|s| NicStatsSnapshot { + rx_missed: s.rx_missed, + rx_errors: s.rx_errors, + rx_nombuf: s.rx_nombuf, + }) + })) + } + SocketBackend::Generic(_) => None, + }; + *reporter_guard = Some(PerfReporter::start( Arc::clone(&self.perf_counters), Arc::clone(&self.latency_sampler), interval, + nic_stats_fn, )); Ok(()) } @@ -3750,4 +3940,217 @@ mod tests { .expect("bind should succeed"); assert!(socket.is_run_to_completion()); } + + // ======================================================================== + // RX BACKPRESSURE / DROP COUNTER TESTS + // ======================================================================== + + /// Dummy source address used in all ReceiveQueue tests. + fn test_src() -> SocketAddr { + SocketAddr::V4(SocketAddrV4::new(Ipv4Addr::new(10, 0, 0, 1), 1234)) + } + + #[test] + fn recv_queue_push_accepts_under_byte_limit() { + let mut q = ReceiveQueue::with_limits(16, 1024); + assert!(q.push(vec![0u8; 512], test_src()).is_ok()); + assert_eq!(q.len(), 1); + assert_eq!(q.bytes(), 512); + } + + #[test] + fn recv_queue_push_rejects_when_byte_limit_exceeded() { + let mut q = ReceiveQueue::with_limits(16, 1024); + assert!(q.push(vec![0u8; 900], test_src()).is_ok()); + // Second push would bring us to 1800 bytes > 1024 limit. + let err = q.push(vec![0u8; 900], test_src()).unwrap_err(); + assert_eq!(err.len(), 900, "push should return the rejected payload"); + assert_eq!(q.len(), 1, "queue count should not change on reject"); + assert_eq!(q.bytes(), 900); + } + + #[test] + fn recv_queue_push_rejects_at_exact_byte_boundary() { + let mut q = ReceiveQueue::with_limits(16, 1000); + assert!(q.push(vec![0u8; 600], test_src()).is_ok()); + // 600 + 500 = 1100 > 1000 — reject. + assert!(q.push(vec![0u8; 500], test_src()).is_err()); + // 600 + 400 = 1000 — accept (inclusive). + assert!(q.push(vec![0u8; 400], test_src()).is_ok()); + assert_eq!(q.bytes(), 1000); + } + + #[test] + fn recv_queue_push_rejects_when_packet_limit_exceeded() { + // Small packet count, generous byte budget. + let mut q = ReceiveQueue::with_limits(2, 1_000_000); + assert!(q.push(vec![0u8; 10], test_src()).is_ok()); + assert!(q.push(vec![0u8; 10], test_src()).is_ok()); + assert!(q.push(vec![0u8; 10], test_src()).is_err()); + assert_eq!(q.len(), 2); + } + + #[test] + fn recv_queue_pop_decrements_current_bytes() { + let mut q = ReceiveQueue::with_limits(16, 1024); + q.push(vec![0u8; 300], test_src()).unwrap(); + q.push(vec![0u8; 400], test_src()).unwrap(); + assert_eq!(q.bytes(), 700); + + let (payload, _) = q.pop().unwrap(); + assert_eq!(payload.len(), 300); + assert_eq!(q.bytes(), 400); + + let (payload, _) = q.pop().unwrap(); + assert_eq!(payload.len(), 400); + assert_eq!(q.bytes(), 0); + } + + #[test] + fn recv_queue_pop_then_push_reuses_reclaimed_capacity() { + let mut q = ReceiveQueue::with_limits(16, 1000); + q.push(vec![0u8; 800], test_src()).unwrap(); + // Second push would overflow. + assert!(q.push(vec![0u8; 500], test_src()).is_err()); + // Drain one packet, freeing 800 bytes of capacity. + q.pop().unwrap(); + // Same push now succeeds. + assert!(q.push(vec![0u8; 500], test_src()).is_ok()); + } + + #[test] + fn recv_queue_set_max_bytes_updates_limit() { + let mut q = ReceiveQueue::with_limits(16, 1000); + q.push(vec![0u8; 800], test_src()).unwrap(); + assert!(q.push(vec![0u8; 300], test_src()).is_err()); + + // Raise the limit; now the same push fits. + q.set_max_bytes(2000); + assert_eq!(q.max_bytes(), 2000); + assert!(q.push(vec![0u8; 300], test_src()).is_ok()); + } + + #[test] + fn socket_default_recv_buffer_size_matches_constant() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + assert_eq!(socket.recv_buffer_size(), DEFAULT_RECV_BUFFER_BYTES); + } + + #[test] + fn socket_set_recv_buffer_size_roundtrip() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + socket.set_recv_buffer_size(128 * 1024).unwrap(); + assert_eq!(socket.recv_buffer_size(), 128 * 1024); + + socket.set_recv_buffer_size(1 * 1024 * 1024).unwrap(); + assert_eq!(socket.recv_buffer_size(), 1024 * 1024); + } + + #[test] + fn socket_set_recv_buffer_size_rejects_zero() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + let err = socket.set_recv_buffer_size(0).unwrap_err(); + assert_eq!(err.kind(), io::ErrorKind::InvalidInput); + } + + #[test] + fn socket_drop_counters_start_at_zero() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + let drops = socket.recv_drops(); + assert_eq!(drops.packets, 0); + assert_eq!(drops.bytes, 0); + } + + #[test] + fn socket_record_rx_drop_bumps_counters() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + socket.record_rx_drop(1400); + socket.record_rx_drop(600); + + let drops = socket.recv_drops(); + assert_eq!(drops.packets, 2); + assert_eq!(drops.bytes, 2000); + } + + #[test] + fn socket_reset_recv_drops_zeros_counters() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + socket.record_rx_drop(512); + socket.record_rx_drop(512); + assert_eq!(socket.recv_drops().packets, 2); + + socket.reset_recv_drops(); + let drops = socket.recv_drops(); + assert_eq!(drops.packets, 0); + assert_eq!(drops.bytes, 0); + } + + #[test] + fn socket_record_rx_drop_also_bumps_perf_counter() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + socket.record_rx_drop(100); + socket.record_rx_drop(200); + // Perf counter is shared via Arc — the socket holds it directly. + let snap = socket.perf_counters.snapshot(); + assert_eq!(snap.rx_drops_buffer_full, 2); + } + + #[test] + fn recv_buffer_bytes_tracks_queued_payload() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + assert_eq!(socket.recv_buffer_bytes(), 0); + + // Push directly into the queue to simulate buffered packets. + { + let mut q = socket.recv_queue.lock().unwrap(); + q.push(vec![0u8; 500], test_src()).unwrap(); + q.push(vec![0u8; 700], test_src()).unwrap(); + } + assert_eq!(socket.recv_buffer_bytes(), 1200); + } + + #[test] + fn recv_buffer_overflow_records_drops() { + let socket = UdpSocket::bind("127.0.0.1:0").expect("bind should succeed"); + // Shrink the buffer to a tight 1 KiB budget. + socket.set_recv_buffer_size(1024).unwrap(); + + // Fill to 900 bytes. + { + let mut q = socket.recv_queue.lock().unwrap(); + q.push(vec![0u8; 900], test_src()).unwrap(); + } + + // Simulate a push attempt that overflows via the helper path. + let rejected_len = 300usize; + { + let mut q = socket.recv_queue.lock().unwrap(); + if q.push(vec![0u8; rejected_len], test_src()).is_err() { + socket.record_rx_drop(rejected_len); + } + } + + let drops = socket.recv_drops(); + assert_eq!(drops.packets, 1); + assert_eq!(drops.bytes, rejected_len as u64); + assert_eq!(socket.recv_buffer_bytes(), 900, "queued bytes unchanged"); + } + + #[test] + fn recv_drop_stats_is_copy_and_comparable() { + let a = RecvDropStats { packets: 5, bytes: 1500 }; + let b = a; // Copy + assert_eq!(a, b); + assert_eq!(a.packets, 5); + assert_eq!(a.bytes, 1500); + } + + #[test] + fn default_recv_buffer_bytes_constant_is_reasonable() { + // Must be large enough to hold at least ~170 MTU-1500 UDP datagrams — + // this keeps the default within one order of magnitude of the Linux + // kernel's `net.core.rmem_default`. + assert!(DEFAULT_RECV_BUFFER_BYTES >= 200 * 1024); + assert!(DEFAULT_RECV_BUFFER_BYTES <= 4 * 1024 * 1024); + } } diff --git a/dpdk-udp/src/perf.rs b/dpdk-udp/src/perf.rs index 33bd66a..644a082 100644 --- a/dpdk-udp/src/perf.rs +++ b/dpdk-udp/src/perf.rs @@ -19,7 +19,7 @@ use std::sync::atomic::{AtomicBool, AtomicU64, Ordering}; use std::sync::Arc; use std::thread::{self, JoinHandle}; -use std::time::{Duration, Instant}; +use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH}; // ============================================================================ // Feature-gated hot-path macros @@ -77,6 +77,10 @@ pub struct PerfCounters { pub rx_bytes: AtomicU64, pub rx_drops_ring_full: AtomicU64, pub rx_drops_parse_fail: AtomicU64, + /// Packets dropped because the socket-level receive buffer + /// (`SO_RCVBUF` equivalent) was full. Distinct from `rx_drops_ring_full`, + /// which counts worker ring enqueue failures in multi-core pipelines. + pub rx_drops_buffer_full: AtomicU64, pub rx_arp_handled: AtomicU64, pub rx_icmp_handled: AtomicU64, pub rx_bursts: AtomicU64, @@ -115,6 +119,7 @@ impl PerfCounters { rx_bytes: AtomicU64::new(0), rx_drops_ring_full: AtomicU64::new(0), rx_drops_parse_fail: AtomicU64::new(0), + rx_drops_buffer_full: AtomicU64::new(0), rx_arp_handled: AtomicU64::new(0), rx_icmp_handled: AtomicU64::new(0), rx_bursts: AtomicU64::new(0), @@ -143,6 +148,7 @@ impl PerfCounters { rx_bytes: self.rx_bytes.load(Ordering::Relaxed), rx_drops_ring_full: self.rx_drops_ring_full.load(Ordering::Relaxed), rx_drops_parse_fail: self.rx_drops_parse_fail.load(Ordering::Relaxed), + rx_drops_buffer_full: self.rx_drops_buffer_full.load(Ordering::Relaxed), rx_arp_handled: self.rx_arp_handled.load(Ordering::Relaxed), rx_icmp_handled: self.rx_icmp_handled.load(Ordering::Relaxed), rx_bursts: self.rx_bursts.load(Ordering::Relaxed), @@ -212,6 +218,7 @@ pub struct CounterSnapshot { pub rx_bytes: u64, pub rx_drops_ring_full: u64, pub rx_drops_parse_fail: u64, + pub rx_drops_buffer_full: u64, pub rx_arp_handled: u64, pub rx_icmp_handled: u64, pub rx_bursts: u64, @@ -264,12 +271,21 @@ impl CounterSnapshot { 0.0 }; + let rx_ring_drops = self + .rx_drops_ring_full + .saturating_sub(prev.rx_drops_ring_full); + let rx_buf_drops = self + .rx_drops_buffer_full + .saturating_sub(prev.rx_drops_buffer_full); + RateSnapshot { rx_pps: delta(self.rx_packets, prev.rx_packets), rx_bps: delta(self.rx_bytes, prev.rx_bytes) * 8.0, tx_pps: delta(self.tx_packets, prev.tx_packets), tx_bps: delta(self.tx_bytes, prev.tx_bytes) * 8.0, - rx_drops: self.rx_drops_ring_full.saturating_sub(prev.rx_drops_ring_full), + rx_drops: rx_ring_drops + rx_buf_drops, + rx_ring_drops, + rx_buf_drops, tx_fails: self.tx_failures.saturating_sub(prev.tx_failures), arp_hits: self.arp_cache_hits.saturating_sub(prev.arp_cache_hits), arp_misses: self.arp_cache_misses.saturating_sub(prev.arp_cache_misses), @@ -291,7 +307,12 @@ pub struct RateSnapshot { pub tx_pps: f64, pub rx_bps: f64, pub tx_bps: f64, + /// Total RX drops in the interval (ring-full + socket buffer-full). pub rx_drops: u64, + /// Worker/RX-ring enqueue failures in the interval (multi-core pipeline). + pub rx_ring_drops: u64, + /// Socket-level recv-buffer (`SO_RCVBUF` equivalent) overflows in the interval. + pub rx_buf_drops: u64, pub tx_fails: u64, pub arp_hits: u64, pub arp_misses: u64, @@ -442,6 +463,34 @@ pub struct PerfSnapshot { pub ring_drop_rate: f64, } +// ============================================================================ +// NIC (port-level) stats — optional plumbing from the DPDK driver +// ============================================================================ + +/// Point-in-time snapshot of hardware-level NIC counters, read from the DPDK +/// driver via `rte_eth_stats_get`. These live *below* the software RX path: +/// packets counted here were dropped before the application ever had a chance +/// to call `rte_eth_rx_burst`, and they will NOT appear in [`RateSnapshot`]'s +/// `rx_buf_drops` / `rx_ring_drops` (which only count software-layer drops +/// inside `dpdk-udp`). +#[derive(Debug, Clone, Copy, Default)] +pub struct NicStatsSnapshot { + /// `rte_eth_stats.imissed` — NIC dropped packets because the software RX + /// descriptor ring was full (app polled too slowly). + pub rx_missed: u64, + /// `rte_eth_stats.ierrors` — NIC-reported receive errors (malformed, + /// checksum, etc). + pub rx_errors: u64, + /// `rte_eth_stats.rx_nombuf` — NIC couldn't refill an RX descriptor + /// because the mempool was exhausted. + pub rx_nombuf: u64, +} + +/// Callback used by [`PerfReporter`] to snapshot NIC-level counters once per +/// reporting interval. Returns `None` if the backend does not expose port +/// stats (e.g. AF_PACKET, plain-rust fallback). +pub type NicStatsFn = Box Option + Send + Sync>; + // ============================================================================ // PerfReporter — background reporting thread // ============================================================================ @@ -458,10 +507,17 @@ impl PerfReporter { /// /// Emits one log line per `interval` to stderr. The line contains /// key=value pairs for easy parsing. + /// + /// `nic_stats_fn` is an optional callback to snapshot NIC-level counters + /// once per interval. When provided (DPDK backend), the log line also + /// includes `nic_imissed`, `nic_ierrors`, and `nic_rx_nombuf` fields, + /// each reported as a delta over the interval. When `None` (non-DPDK + /// backends), those fields are emitted as `nic_imissed=-`. pub fn start( counters: Arc, sampler: Arc, interval: Duration, + nic_stats_fn: Option, ) -> Self { let shutdown = Arc::new(AtomicBool::new(false)); let shutdown_clone = Arc::clone(&shutdown); @@ -469,7 +525,7 @@ impl PerfReporter { let handle = thread::Builder::new() .name("dpdk-perf-reporter".to_string()) .spawn(move || { - Self::reporter_loop(counters, sampler, interval, shutdown_clone); + Self::reporter_loop(counters, sampler, interval, nic_stats_fn, shutdown_clone); }) .expect("failed to spawn perf reporter thread"); @@ -483,10 +539,30 @@ impl PerfReporter { counters: Arc, sampler: Arc, interval: Duration, + nic_stats_fn: Option, shutdown: Arc, ) { let mut prev_snapshot = counters.snapshot(); let mut prev_time = Instant::now(); + let initial_nic: Option = + nic_stats_fn.as_ref().and_then(|f| f()); + + // Emit a one-shot baseline line so the harness can cross-check the + // sum of per-tick deltas against (FINAL - BASELINE) as a + // self-consistency check on the PerfReporter → aggregator pipeline. + // This is the RAW cumulative counter at reporter startup, NOT a + // delta. Only emitted when NIC stats are available (DPDK backend). + if let Some(ref s) = initial_nic { + let ts_unix = SystemTime::now() + .duration_since(UNIX_EPOCH) + .map(|d| d.as_secs_f64()) + .unwrap_or(0.0); + eprintln!( + "[NIC-BASELINE] ts_unix={:.3} imissed={} ierrors={} rx_nombuf={}", + ts_unix, s.rx_missed, s.rx_errors, s.rx_nombuf, + ); + } + let mut prev_nic = initial_nic; while !shutdown.load(Ordering::Relaxed) { thread::sleep(interval); @@ -505,19 +581,48 @@ impl PerfReporter { let rates = current.rates_since(&prev_snapshot, elapsed_secs); let latencies = sampler.percentiles(); + // Snapshot NIC counters and compute deltas. If the previous + // snapshot is missing (first tick failed) or the current read + // fails, emit "-" for the nic_* fields so the harness can tell + // the difference between "zero drops" and "no data". + let cur_nic = nic_stats_fn.as_ref().and_then(|f| f()); + let nic_fields: String = match (prev_nic, cur_nic) { + (Some(prev), Some(cur)) => format!( + "nic_imissed={} nic_ierrors={} nic_rx_nombuf={}", + cur.rx_missed.saturating_sub(prev.rx_missed), + cur.rx_errors.saturating_sub(prev.rx_errors), + cur.rx_nombuf.saturating_sub(prev.rx_nombuf), + ), + _ => "nic_imissed=- nic_ierrors=- nic_rx_nombuf=-".to_string(), + }; + prev_nic = cur_nic; + let interval_secs = interval.as_secs(); + // Wall-clock timestamp at the END of this reporting window so the + // perf-test harness can bucket [PERF] lines into TRex per-step time + // ranges and compute App Drops per step. + let ts_unix = SystemTime::now() + .duration_since(UNIX_EPOCH) + .map(|d| d.as_secs_f64()) + .unwrap_or(0.0); eprintln!( - "[PERF] interval={}s rx_pps={:.0} rx_bps={:.0} tx_pps={:.0} tx_bps={:.0} \ - rx_drops={} tx_fails={} lat_avg_us={:.0} lat_p50_us={:.0} lat_p95_us={:.0} \ + "[PERF] ts_unix={:.3} interval={}s rx_pps={:.0} rx_bps={:.0} tx_pps={:.0} tx_bps={:.0} \ + rx_drops={} rx_ring_drops={} rx_buf_drops={} tx_fails={} \ + {} \ + lat_avg_us={:.0} lat_p50_us={:.0} lat_p95_us={:.0} \ lat_p99_us={:.0} lat_max_us={:.0} arp_hits={} arp_misses={} ring_drops={} \ worker_idle_pct={:.1} burst_avg={:.1}", + ts_unix, interval_secs, rates.rx_pps, rates.rx_bps, rates.tx_pps, rates.tx_bps, rates.rx_drops, + rates.rx_ring_drops, + rates.rx_buf_drops, rates.tx_fails, + nic_fields, rates.lat_avg_us, latencies.p50_ns as f64 / 1000.0, latencies.p95_ns as f64 / 1000.0, @@ -537,6 +642,24 @@ impl PerfReporter { prev_snapshot = counters.snapshot(); prev_time = now; } + + // Emit a one-shot final line on clean shutdown. Paired with the + // [NIC-BASELINE] line above, (FINAL - BASELINE) gives the total + // cumulative NIC drops that happened between reporter startup + // and shutdown, which the harness can compare against the sum of + // per-tick deltas in the [PERF] lines. A mismatch means either the + // tick-delta computation is losing data or the aggregator window + // logic is wrong. + if let Some(s) = nic_stats_fn.as_ref().and_then(|f| f()) { + let ts_unix = SystemTime::now() + .duration_since(UNIX_EPOCH) + .map(|d| d.as_secs_f64()) + .unwrap_or(0.0); + eprintln!( + "[NIC-FINAL] ts_unix={:.3} imissed={} ierrors={} rx_nombuf={}", + ts_unix, s.rx_missed, s.rx_errors, s.rx_nombuf, + ); + } } /// Stop the reporter thread. @@ -685,6 +808,7 @@ mod tests { fn counter_snapshot_rates() { let prev = CounterSnapshot { rx_packets: 0, rx_bytes: 0, rx_drops_ring_full: 0, rx_drops_parse_fail: 0, + rx_drops_buffer_full: 0, rx_arp_handled: 0, rx_icmp_handled: 0, rx_bursts: 0, rx_burst_sum: 0, tx_packets: 0, tx_bytes: 0, tx_failures: 0, worker_ring_enqueue_fail: 0, app_ring_enqueue_fail: 0, tx_ring_enqueue_fail: 0, @@ -695,7 +819,8 @@ mod tests { let current = CounterSnapshot { rx_packets: 350000, rx_bytes: 490_000_000, rx_drops_ring_full: 5, - rx_drops_parse_fail: 2, rx_arp_handled: 10, rx_icmp_handled: 3, + rx_drops_parse_fail: 2, rx_drops_buffer_full: 7, + rx_arp_handled: 10, rx_icmp_handled: 3, rx_bursts: 10000, rx_burst_sum: 350000, tx_packets: 349000, tx_bytes: 488_600_000, tx_failures: 1, worker_ring_enqueue_fail: 3, app_ring_enqueue_fail: 1, tx_ring_enqueue_fail: 1, @@ -707,7 +832,10 @@ mod tests { let rates = current.rates_since(&prev, 10.0); assert!((rates.rx_pps - 35000.0).abs() < 1.0); assert!((rates.tx_pps - 34900.0).abs() < 1.0); - assert_eq!(rates.rx_drops, 5); + // rx_drops aggregates both ring-full (5) and buffer-full (7) drops. + assert_eq!(rates.rx_drops, 12); + assert_eq!(rates.rx_ring_drops, 5); + assert_eq!(rates.rx_buf_drops, 7); assert_eq!(rates.tx_fails, 1); assert!((rates.burst_avg - 35.0).abs() < 0.1); assert!(rates.lat_avg_us > 0.0); @@ -723,6 +851,7 @@ mod tests { Arc::clone(&counters), Arc::clone(&sampler), Duration::from_millis(50), + None, ); // Let it run briefly @@ -746,6 +875,7 @@ mod tests { Arc::clone(&counters), Arc::clone(&sampler), Duration::from_millis(50), + None, ); // Wait for at least one report cycle @@ -756,4 +886,88 @@ mod tests { // The actual output goes to stderr — we can't easily capture it here, // but no panics means the formatting and computation succeeded. } + + #[test] + fn perf_reporter_invokes_nic_stats_fn() { + let counters = Arc::new(PerfCounters::new()); + let sampler = Arc::new(LatencySampler::new(64, 1)); + + // Track how many times the NIC stats callback fires and return a + // counter that grows so the reporter sees non-zero deltas. + let call_count = Arc::new(AtomicU64::new(0)); + let call_count_clone = Arc::clone(&call_count); + let nic_stats_fn: NicStatsFn = Box::new(move || { + let n = call_count_clone.fetch_add(1, Ordering::Relaxed); + Some(NicStatsSnapshot { + rx_missed: n * 10, + rx_errors: n, + rx_nombuf: 0, + }) + }); + + let mut reporter = PerfReporter::start( + Arc::clone(&counters), + Arc::clone(&sampler), + Duration::from_millis(30), + Some(nic_stats_fn), + ); + + // Wait long enough for at least 2 reporting ticks. + std::thread::sleep(Duration::from_millis(120)); + reporter.stop(); + + // Must have been called at least three times: once at startup to + // capture the [NIC-BASELINE] snapshot, once or more per reporting + // tick for per-tick delta computation, and once at shutdown to + // capture the [NIC-FINAL] snapshot. The harness uses BASELINE and + // FINAL to cross-check the sum-of-deltas against (FINAL-BASELINE). + assert!( + call_count.load(Ordering::Relaxed) >= 3, + "nic_stats_fn should be invoked at least 3 times \ + (baseline + tick + final), got {}", + call_count.load(Ordering::Relaxed) + ); + } + + #[test] + fn perf_reporter_final_snapshot_runs_after_shutdown() { + // Verify that [NIC-FINAL] is always emitted on clean shutdown even + // when the shutdown signal fires BEFORE any reporting tick has run. + // This is the scenario where a benchmark exits almost immediately — + // we still need the final snapshot to pair with the baseline so the + // harness cross-check doesn't lose data. + let counters = Arc::new(PerfCounters::new()); + let sampler = Arc::new(LatencySampler::new(64, 1)); + + let call_count = Arc::new(AtomicU64::new(0)); + let call_count_clone = Arc::clone(&call_count); + let nic_stats_fn: NicStatsFn = Box::new(move || { + call_count_clone.fetch_add(1, Ordering::Relaxed); + Some(NicStatsSnapshot::default()) + }); + + // Use a very long interval (10s) so no tick runs before we stop. + let mut reporter = PerfReporter::start( + Arc::clone(&counters), + Arc::clone(&sampler), + Duration::from_secs(10), + Some(nic_stats_fn), + ); + + // Stop almost immediately — before any tick could fire. + std::thread::sleep(Duration::from_millis(5)); + reporter.stop(); + + // Baseline (1) + final (1) must still have been invoked, even + // though no reporting tick ran. If FINAL is only emitted from the + // tick loop body (e.g. inside the `while` block instead of after + // it), this will fail with count == 1. + let count = call_count.load(Ordering::Relaxed); + assert!( + count >= 2, + "nic_stats_fn must be called for baseline AND final even \ + with no ticks; got {}", + count + ); + } } diff --git a/dpdk/src/port.rs b/dpdk/src/port.rs index 1c3b949..5eaad24 100644 --- a/dpdk/src/port.rs +++ b/dpdk/src/port.rs @@ -258,12 +258,17 @@ pub struct PortStats { pub rx_bytes: u64, /// Total transmitted bytes pub tx_bytes: u64, - /// Missed packets (no buffer available) + /// Missed packets: NIC dropped them because the software RX descriptor + /// ring had no free slots (i.e. the app polled too slowly). Corresponds to + /// `rte_eth_stats.imissed`. pub rx_missed: u64, - /// RX errors + /// RX errors (corresponds to `rte_eth_stats.ierrors`). pub rx_errors: u64, - /// TX errors + /// TX errors (corresponds to `rte_eth_stats.oerrors`). pub tx_errors: u64, + /// RX packets dropped because no mbuf was available from the mempool. + /// Corresponds to `rte_eth_stats.rx_nombuf`. + pub rx_nombuf: u64, } /// Device capability information @@ -603,6 +608,7 @@ impl Port { rx_missed: stats.imissed, rx_errors: stats.ierrors, tx_errors: stats.oerrors, + rx_nombuf: stats.rx_nombuf, }) } diff --git a/scripts/perf-tests/trex/run_benchmark.py b/scripts/perf-tests/trex/run_benchmark.py index 3edbe01..fc9ef1f 100644 --- a/scripts/perf-tests/trex/run_benchmark.py +++ b/scripts/perf-tests/trex/run_benchmark.py @@ -70,6 +70,10 @@ def run_single_benchmark(client, port, streams, target_pps, duration_sec): # Clear stats before starting client.clear_stats() + # Wall-clock window for this rate step. The perf-test harness uses these + # to bucket DUT-side `[PERF]` log lines into per-step App Drops counts. + ts_start_unix = time.time() + # Start traffic with duration — TRex will stop TX after duration_sec. # Use TRex 'pps' multiplier format for deterministic rate control. # force=True bypasses TRex's line rate check — ENA PMD reports 16 Gbps @@ -83,6 +87,7 @@ def run_single_benchmark(client, port, streams, target_pps, duration_sec): time.sleep(duration_sec + 2) client.stop(ports=[port]) time.sleep(2) + ts_end_unix = time.time() # Collect stats stats = client.get_stats() @@ -102,6 +107,8 @@ def run_single_benchmark(client, port, streams, target_pps, duration_sec): result = { 'target_pps': target_pps, 'duration_sec': duration_sec, + 'ts_start_unix': round(ts_start_unix, 3), + 'ts_end_unix': round(ts_end_unix, 3), 'tx_pkts': tx_pkts, 'rx_pkts': rx_pkts, 'tx_pps': round(tx_pps), diff --git a/scripts/run-perf-tests.sh b/scripts/run-perf-tests.sh index 8334c23..77bb4e9 100755 --- a/scripts/run-perf-tests.sh +++ b/scripts/run-perf-tests.sh @@ -34,13 +34,16 @@ DURATION=30 RATE_STEPS="70000,140000,350000,700000" # Kernel configs first (NIC starts in kernel mode from boot), then DPDK configs. # This minimizes NIC rebinding — only one kernel→vfio-pci transition needed. -CONFIGS="plain-rust,rust-dpdk,native-dpdk" +CONFIGS="plain-rust,rust-dpdk,tokio-dpdk,native-dpdk" JSON_SUMMARY=false CDK_STACK_NAME="PerfTestStack" CDK_DIR="$REPO_ROOT/deploy/cdk" RESULTS_DIR="$REPO_ROOT/perf-results" LOGS_DIR="$REPO_ROOT/instance-logs" +# Exported so the inline python in aggregate_results / generate_markdown_summary +# can find both directories without hard-coding paths. +export RESULTS_DIR LOGS_DIR SSM_READINESS_TIMEOUT=600 TREX_START_TIMEOUT=120 @@ -488,7 +491,7 @@ dut_stop_all_apps() { # cleanup (rte_eal_cleanup via Drop) so vfio-pci devices are properly released. # Only escalate to SIGKILL after 10s if the process won't die. stop_result=$(ssm_run_command "$DUT_INSTANCE_ID" 30 \ - "set +e; pkill -TERM -f 'target/release/echo' 2>/dev/null; pkill -TERM -f 'target/release/plain-echo' 2>/dev/null; pkill -TERM -f testpmd 2>/dev/null; pkill -TERM -f dpdk-testpmd 2>/dev/null; for i in 1 2 3 4 5 6 7 8 9 10; do pgrep -f 'target/release/echo|target/release/plain-echo|testpmd' >/dev/null 2>&1 || break; sleep 1; done; if pgrep -f 'target/release/echo|target/release/plain-echo|testpmd' >/dev/null 2>&1; then echo 'SIGTERM did not work, escalating to SIGKILL'; pkill -9 -f 'target/release/echo' 2>/dev/null; pkill -9 -f 'target/release/plain-echo' 2>/dev/null; pkill -9 -f testpmd 2>/dev/null; pkill -9 -f dpdk-testpmd 2>/dev/null; sleep 3; fi; echo 'All apps stopped'") || true + "set +e; pkill -TERM -f 'target/release/echo' 2>/dev/null; pkill -TERM -f 'target/release/tokio-echo' 2>/dev/null; pkill -TERM -f 'target/release/plain-echo' 2>/dev/null; pkill -TERM -f testpmd 2>/dev/null; pkill -TERM -f dpdk-testpmd 2>/dev/null; for i in 1 2 3 4 5 6 7 8 9 10; do pgrep -f 'target/release/echo|target/release/tokio-echo|target/release/plain-echo|testpmd' >/dev/null 2>&1 || break; sleep 1; done; if pgrep -f 'target/release/echo|target/release/tokio-echo|target/release/plain-echo|testpmd' >/dev/null 2>&1; then echo 'SIGTERM did not work, escalating to SIGKILL'; pkill -9 -f 'target/release/echo' 2>/dev/null; pkill -9 -f 'target/release/tokio-echo' 2>/dev/null; pkill -9 -f 'target/release/plain-echo' 2>/dev/null; pkill -9 -f testpmd 2>/dev/null; pkill -9 -f dpdk-testpmd 2>/dev/null; sleep 3; fi; echo 'All apps stopped'") || true log_info "Stop result: $stop_result" # Clean up stale DPDK shared memory — if the previous app was SIGKILL'd, # the shared memory files persist and can cause the next DPDK app to fail @@ -904,8 +907,11 @@ start_dut_rust_dpdk() { ssm_run_command "$DUT_INSTANCE_ID" 30 \ "set +e; echo 1024 > /proc/sys/vm/nr_hugepages 2>/dev/null; mkdir -p /mnt/huge; mount -t hugetlbfs nodev /mnt/huge 2>/dev/null; echo HUGEPAGES_SETUP_DONE" || true + # --perf-interval 10 enables PerfReporter so [PERF] lines (rx_pps, rx_drops, + # rx_buf_drops, latencies) appear in the app log every 10s. The harness tails + # this log into the perf PR comment so the numbers can be compared to TRex. ssm_run_command_fire_and_forget "$DUT_INSTANCE_ID" 300 \ - "cd /opt/dpdk-stdlib && nohup ./target/release/echo --ip ${DUT_DATA_ENI_IP} --port 9000 > /var/log/echo-rust-dpdk.log 2>&1 &" + "cd /opt/dpdk-stdlib && nohup ./target/release/echo --ip ${DUT_DATA_ENI_IP} --port 9000 --perf-interval 10 > /var/log/echo-rust-dpdk.log 2>&1 &" sleep 15 # Verify it's running (retry up to 3 times — SSM can be slow) @@ -962,6 +968,43 @@ start_dut_rust_dpdk_multicore() { log_info "rust-dpdk-multicore echo server running" } +start_dut_tokio_dpdk() { + log_info "Starting DUT: tokio-dpdk (async tokio-echo with DPDK backend)" + dut_bind_dpdk || return 1 + + # Ensure hugepages are set up (process cleanup already done by dut_bind_dpdk) + ssm_run_command "$DUT_INSTANCE_ID" 30 \ + "set +e; echo 1024 > /proc/sys/vm/nr_hugepages 2>/dev/null; mkdir -p /mnt/huge; mount -t hugetlbfs nodev /mnt/huge 2>/dev/null; echo HUGEPAGES_SETUP_DONE" || true + + # tokio-echo binary is built with --features dpdk in perf-test-stack.ts so + # the DPDK backend is selected automatically when DPDK is available. + # --perf-interval 10 enables PerfReporter so [PERF] lines (rx_pps, rx_drops, + # rx_buf_drops, latencies) appear in the app log every 10s — same as the + # rust-dpdk config. + ssm_run_command_fire_and_forget "$DUT_INSTANCE_ID" 300 \ + "cd /opt/dpdk-stdlib && nohup ./target/release/tokio-echo --ip ${DUT_DATA_ENI_IP} --port 9000 --perf-interval 10 > /var/log/echo-tokio-dpdk.log 2>&1 &" + sleep 15 + + # Verify it's running (retry up to 3 times — SSM can be slow) + local status="" + local verify_attempt + for verify_attempt in 1 2 3; do + status=$(ssm_run_command "$DUT_INSTANCE_ID" 30 \ + "pgrep -f 'target/release/tokio-echo' >/dev/null && echo 'running' || echo 'not running'") || true + if [[ "$status" == *"running"* ]]; then + break + fi + log_warn "tokio-dpdk verify attempt $verify_attempt: status='$status'" + sleep 5 + done + if [[ "$status" != *"running"* ]]; then + log_error "tokio-dpdk echo server failed to start (status='$status')" + ssm_run_command "$DUT_INSTANCE_ID" 30 "tail -30 /var/log/echo-tokio-dpdk.log 2>/dev/null" || true + return 1 + fi + log_info "tokio-dpdk echo server running" +} + start_dut_native_dpdk() { log_info "Starting DUT: native-dpdk (testpmd 5tswap)" dut_bind_dpdk || return 1 @@ -1025,6 +1068,29 @@ start_dut_plain_rust() { log_info "Starting DUT: plain-rust (minimal std::net echo server)" dut_bind_kernel || return 1 + # Capture kernel NIC counters BEFORE starting the echo server. For the + # DPDK configs we get per-tick NIC drop deltas straight from the + # PerfReporter, but plain-rust doesn't embed that instrumentation — the + # closest equivalent is ethtool -S from the kernel side. Baseline now, + # finalize after run_benchmark_for_config returns, so (final - baseline) + # gives a kernel-level NIC drop total that we can compare against the + # TRex observed wire loss for plain-rust. Without this, plain-rust's + # "NIC drops" column is always "—" and we can't tell whether kernel + # packet loss matches what DPDK sees. + # Give the kernel a moment to bring up the freshly-rebound interface — + # right after dut_bind_kernel the link may not be fully settled, so + # retry ethtool up to 3 times waiting for a result with numeric stats. + # The previous implementation had a subtle `[ -n ] && A || B` bash + # precedence bug that silently wrote "ethtool unavailable" to the file + # on failure, which the Python aggregator then counted as "no data". + local ethtool_baseline + ethtool_baseline=$(ssm_run_command "$DUT_INSTANCE_ID" 60 \ + "set -e; for retry in 1 2 3; do IFACE=\$(ls /sys/bus/pci/devices/0000:00:06.0/net/ 2>/dev/null | head -1); if [ -n \"\$IFACE\" ]; then OUT=\$(ethtool -S \$IFACE 2>&1); if echo \"\$OUT\" | grep -q ': [0-9]'; then echo \"\$OUT\"; exit 0; fi; fi; sleep 2; done; echo 'ETHTOOL_BASELINE_FAILED iface=\$IFACE'; exit 0" 2>/dev/null || echo "(SSM failed)") + echo "$ethtool_baseline" > "$LOGS_DIR/dut-plain-rust-ethtool-baseline.txt" + local base_lines + base_lines=$(echo "$ethtool_baseline" | wc -l) + log_info "plain-rust ethtool baseline captured ($base_lines lines, head: $(echo "$ethtool_baseline" | head -2 | tr '\n' ' '))" + ssm_run_command_fire_and_forget "$DUT_INSTANCE_ID" 300 \ "cd /opt/dpdk-stdlib && nohup ./target/release/plain-echo --ip ${DUT_DATA_ENI_IP} --port 9000 > /var/log/plain-echo.log 2>&1 &" sleep 10 @@ -1055,12 +1121,332 @@ aggregate_results() { mkdir -p "$RESULTS_DIR" python3 - <<'PYEOF' -import json, glob, os, sys +import json, glob, os, re, sys from datetime import datetime, timezone results_dir = os.environ.get("RESULTS_DIR", "perf-results") +logs_dir = os.environ.get("LOGS_DIR", "perf-logs") output_file = os.path.join(results_dir, "perf-report.json") +# Regex pulls fields out of: +# [PERF] ts_unix=1712.345 interval=10s rx_pps=... rx_drops=N rx_ring_drops=N rx_buf_drops=N +# nic_imissed=N nic_ierrors=N nic_rx_nombuf=N ... +# nic_* fields are emitted as "-" on non-DPDK backends, so we parse them as +# an optional string and treat non-digits as "unavailable". +PERF_RE = re.compile( + r"^\[PERF\]\s+ts_unix=(?P[\d.]+).*?\s" + r"rx_drops=(?P\d+).*?\s" + r"rx_ring_drops=(?P\d+).*?\s" + r"rx_buf_drops=(?P\d+)" +) +NIC_IMISSED_RE = re.compile(r"nic_imissed=(\d+|-)") +NIC_IERRORS_RE = re.compile(r"nic_ierrors=(\d+|-)") +NIC_RX_NOMBUF_RE = re.compile(r"nic_rx_nombuf=(\d+|-)") +INTERVAL_RE = re.compile(r"interval=(\d+)s") + +# [NIC-BASELINE] / [NIC-FINAL] are one-shot lines emitted by PerfReporter at +# startup and at clean shutdown. They capture the RAW cumulative rte_eth_stats +# counters, so (FINAL - BASELINE) is the total NIC drops that happened across +# the reporter's entire lifetime. The harness cross-checks that against the +# sum of per-tick deltas carried in [PERF] lines. A mismatch means either: +# 1. the tick-loop delta computation is losing data (reporter bug), or +# 2. the window-overlap aggregator below is double-counting or skipping +# samples, or +# 3. the NIC counters moved outside the [BASELINE, FINAL] window (e.g. a +# race where the nic_stats_fn callback observed stale data). +# This is our end-to-end self-consistency check on the instrumentation. +NIC_BASELINE_RE = re.compile( + r"^\[NIC-BASELINE\]\s+ts_unix=(?P[\d.]+)\s+" + r"imissed=(?P\d+)\s+" + r"ierrors=(?P\d+)\s+" + r"rx_nombuf=(?P\d+)" +) +NIC_FINAL_RE = re.compile( + r"^\[NIC-FINAL\]\s+ts_unix=(?P[\d.]+)\s+" + r"imissed=(?P\d+)\s+" + r"ierrors=(?P\d+)\s+" + r"rx_nombuf=(?P\d+)" +) + +def _parse_nic_field(match): + """Return int for numeric fields, None for "-" / missing.""" + if match is None: + return None + v = match.group(1) + if v == "-": + return None + try: + return int(v) + except ValueError: + return None + +def load_perf_lines(config_name): + """Return list of dicts with software + NIC drop fields. + `interval` is the reporter window in seconds — used to figure out which + rate-step a [PERF] sample belongs to (the line's ts_unix marks the END of + the window, so the sample covers [ts - interval, ts]). + + NIC fields (nic_imissed/nic_ierrors/nic_rx_nombuf) are None on non-DPDK + backends; the harness propagates None to the report so downstream + consumers can distinguish "backend doesn't expose NIC stats" from + "zero NIC drops".""" + perf_path = os.path.join(logs_dir, f"dut-{config_name}-perf.log") + samples = [] + if not os.path.exists(perf_path): + return samples + try: + with open(perf_path) as fh: + for line in fh: + m = PERF_RE.search(line) + if not m: + continue + im = INTERVAL_RE.search(line) + interval = int(im.group(1)) if im else 10 + samples.append({ + "ts": float(m.group("ts")), + "interval": interval, + "rx_drops": int(m.group("rx_drops")), + "rx_ring": int(m.group("rx_ring")), + "rx_buf": int(m.group("rx_buf")), + "nic_imissed": _parse_nic_field(NIC_IMISSED_RE.search(line)), + "nic_ierrors": _parse_nic_field(NIC_IERRORS_RE.search(line)), + "nic_rx_nombuf": _parse_nic_field(NIC_RX_NOMBUF_RE.search(line)), + }) + except Exception as e: + print(f"Warning: failed to parse {perf_path}: {e}", file=sys.stderr) + return samples + +def load_nic_baseline_final(config_name): + """Parse [NIC-BASELINE] and [NIC-FINAL] from the config's perf log. + Returns (baseline_dict, final_dict) where each is None if the + corresponding line wasn't found (e.g. non-DPDK backend or abnormal + shutdown). PerfReporter emits exactly one BASELINE at startup and one + FINAL at clean shutdown, so in a healthy run we expect one of each.""" + perf_path = os.path.join(logs_dir, f"dut-{config_name}-perf.log") + baseline = None + final = None + if not os.path.exists(perf_path): + return baseline, final + try: + with open(perf_path) as fh: + for line in fh: + m = NIC_BASELINE_RE.search(line) + if m: + baseline = { + "ts": float(m.group("ts")), + "imissed": int(m.group("imissed")), + "ierrors": int(m.group("ierrors")), + "rx_nombuf": int(m.group("rx_nombuf")), + } + continue + m = NIC_FINAL_RE.search(line) + if m: + final = { + "ts": float(m.group("ts")), + "imissed": int(m.group("imissed")), + "ierrors": int(m.group("ierrors")), + "rx_nombuf": int(m.group("rx_nombuf")), + } + except Exception as e: + print(f"Warning: failed to parse baseline/final from {perf_path}: {e}", + file=sys.stderr) + return baseline, final + + +def load_ethtool_stats(path): + """Parse `ethtool -S ` output into a dict of name→int. + + The output format is one stat per line: + NIC statistics: + rx_packets: 12345 + tx_packets: 67890 + rx_missed_errors: 0 + ... + Leading spaces are stripped. Non-integer values are skipped.""" + stats = {} + if not os.path.exists(path): + return stats + try: + with open(path) as fh: + for line in fh: + line = line.strip() + if ":" not in line: + continue + key, _, val = line.partition(":") + val = val.strip() + if not val: + continue + try: + stats[key.strip()] = int(val) + except ValueError: + # Some ethtool fields are strings (driver name, etc.) — + # we only care about numeric counters for diffing. + pass + except Exception as e: + print(f"Warning: failed to parse ethtool stats {path}: {e}", + file=sys.stderr) + return stats + + +def compute_kernel_nic_delta(config_name): + """For plain-rust, compute kernel NIC drop delta from pre/post + `ethtool -S` snapshots. Returns a dict with selected drop counters + (rx_missed_errors, rx_dropped, rx_errors, rx_no_buffer_count) or + None if either snapshot is missing. + + On AWS ENA these specific counters are the kernel-visible equivalent + of what rte_eth_stats.imissed/ierrors/rx_nombuf expose to DPDK. + Using ethtool gives plain-rust parity with the DPDK self-check and + lets us cross-reference kernel drops against TRex observed wire loss.""" + base_path = os.path.join(logs_dir, + f"dut-{config_name}-ethtool-baseline.txt") + final_path = os.path.join(logs_dir, + f"dut-{config_name}-ethtool-final.txt") + baseline = load_ethtool_stats(base_path) + final = load_ethtool_stats(final_path) + if not baseline or not final: + return None + + # ENA kernel driver exposes these; names may vary slightly across + # kernel versions so we look for the most common forms. + counters = [ + "rx_missed_errors", # HW RX ring full (ENA equivalent of imissed) + "rx_dropped", # Generic RX drops + "rx_errors", # Total rx errors (ENA equivalent of ierrors) + "rx_no_buffer_count", # No sk_buff available (equivalent of rx_nombuf) + ] + delta = {} + for c in counters: + if c in baseline and c in final: + delta[c] = final[c] - baseline[c] + return delta if delta else None + + +def compute_nic_consistency_check(config_name, samples): + """Compare (FINAL - BASELINE) against the sum of per-tick [PERF] deltas. + + Returns a dict with: + - status: "ok" | "mismatch" | "no_data" | "no_shutdown" + - expected: dict with imissed/ierrors/rx_nombuf from FINAL-BASELINE + - actual: dict with the sum of all [PERF] per-tick deltas + - delta: actual - expected (signed; positive = over-count, + negative = under-count / lost data) + + "no_data" means no BASELINE was parsed (non-DPDK backend). + "no_shutdown" means BASELINE was found but FINAL was not (reporter + probably crashed or the process was killed before clean shutdown). + """ + baseline, final = load_nic_baseline_final(config_name) + if baseline is None: + return {"status": "no_data"} + if final is None: + return {"status": "no_shutdown", "baseline": baseline} + + expected = { + "imissed": final["imissed"] - baseline["imissed"], + "ierrors": final["ierrors"] - baseline["ierrors"], + "rx_nombuf": final["rx_nombuf"] - baseline["rx_nombuf"], + } + + # Sum per-tick deltas across the ENTIRE run — deliberately no window + # filtering; BASELINE→FINAL covers the reporter's whole lifetime. Only + # count samples that actually reported numeric values (non-DPDK ticks + # would have None, but a DPDK-backed reporter should return numbers + # every tick). + actual = {"imissed": 0, "ierrors": 0, "rx_nombuf": 0} + for s in samples: + if s["nic_imissed"] is not None: + actual["imissed"] += s["nic_imissed"] + if s["nic_ierrors"] is not None: + actual["ierrors"] += s["nic_ierrors"] + if s["nic_rx_nombuf"] is not None: + actual["rx_nombuf"] += s["nic_rx_nombuf"] + + delta = {k: actual[k] - expected[k] for k in expected} + # Match when all three counters agree exactly. Any mismatch — even by 1 + # — is worth flagging, since the deltas are derived from the same + # counter reads so drift here means our tick bookkeeping is broken. + status = "ok" if all(v == 0 for v in delta.values()) else "mismatch" + return { + "status": status, + "baseline": baseline, + "final": final, + "expected": expected, + "actual": actual, + "delta": delta, + } + + +def annotate_with_app_drops(cfg_data): + """Inject software-layer drop fields (`app_drops`, `app_ring_drops`, + `app_buf_drops`) AND NIC-layer drop fields (`nic_imissed`, `nic_ierrors`, + `nic_rx_nombuf`) into each step in cfg_data['results']. + + Sums [PERF] samples whose covered window [ts-interval, ts] overlaps the + step's [ts_start_unix, ts_end_unix]. NIC fields are only set if at least + one overlapping sample reported a numeric value (i.e. DPDK backend); + otherwise they stay absent so the markdown generator can render "—". + + Note: we deliberately do NOT compute a combined `imissed + ierrors + + rx_nombuf` total here. On AWS ENA, `ierrors` is dominated by background + noise unrelated to test traffic (Run #10 showed ~50K ierrors/step in the + C reference testpmd binary while imissed/rx_nombuf stayed at 0). Summing + the three into one column masks the real drop signal; downstream + consumers should display the three sub-columns separately.""" + name = cfg_data.get("config_name", "") + samples = load_perf_lines(name) + # Always run the consistency check — even with zero samples, the check + # will return "no_data" / "no_shutdown" which the markdown generator + # can render as "—" to make it clear which configs lack instrumentation. + cfg_data["nic_consistency"] = compute_nic_consistency_check(name, samples) + # For plain-rust we also attach kernel ethtool -S deltas captured by + # the test harness pre/post. This is the only NIC-level instrumentation + # available for the kernel echo path and gives plain-rust parity with + # the DPDK configs in the self-check table. + kernel_delta = compute_kernel_nic_delta(name) + if kernel_delta is not None: + cfg_data["kernel_ethtool_delta"] = kernel_delta + if not samples: + return + for size_results in cfg_data.get("results", {}).values(): + for step in size_results: + ts_start = step.get("ts_start_unix") + ts_end = step.get("ts_end_unix") + if ts_start is None or ts_end is None: + continue + buf_total = 0 + ring_total = 0 + drops_total = 0 + nic_imissed_total = 0 + nic_ierrors_total = 0 + nic_nombuf_total = 0 + nic_has_data = False + for s in samples: + window_start = s["ts"] - s["interval"] + window_end = s["ts"] + # Attribute the sample if its window overlaps the step window + if window_end < ts_start or window_start > ts_end: + continue + buf_total += s["rx_buf"] + ring_total += s["rx_ring"] + drops_total += s["rx_drops"] + if s["nic_imissed"] is not None: + nic_imissed_total += s["nic_imissed"] + nic_has_data = True + if s["nic_ierrors"] is not None: + nic_ierrors_total += s["nic_ierrors"] + nic_has_data = True + if s["nic_rx_nombuf"] is not None: + nic_nombuf_total += s["nic_rx_nombuf"] + nic_has_data = True + step["app_drops"] = drops_total + step["app_ring_drops"] = ring_total + step["app_buf_drops"] = buf_total + if nic_has_data: + step["nic_imissed"] = nic_imissed_total + step["nic_ierrors"] = nic_ierrors_total + step["nic_rx_nombuf"] = nic_nombuf_total + configs = {} for f in sorted(glob.glob(os.path.join(results_dir, "*.json"))): if os.path.basename(f) == "perf-report.json": @@ -1069,6 +1455,7 @@ for f in sorted(glob.glob(os.path.join(results_dir, "*.json"))): with open(f) as fh: data = json.load(fh) name = data.get("config_name", os.path.basename(f).replace(".json", "")) + annotate_with_app_drops(data) configs[name] = data except Exception as e: print(f"Warning: failed to read {f}: {e}", file=sys.stderr) @@ -1123,10 +1510,39 @@ else: for pkt_size in sorted(all_sizes, key=lambda s: int(s.rstrip('B'))): lines.append(f"### {pkt_size} packets") lines.append("") - lines.append("| Config | Target PPS | TX pps | RX pps | Drop % | Lat Avg (us) | Lat Max (us) | TX Mbps | RX Mbps |") - lines.append("|--------|-----------|--------|--------|--------|-------------|-------------|---------|---------|") - - for cfg_name in ["native-dpdk", "rust-dpdk", "plain-rust"]: + # Drop columns walk the receive path from hardware to app. The three + # NIC sub-columns are split out from rte_eth_stats because they mean + # different things and should not be summed — in particular on AWS + # ENA, `ierrors` is dominated by background NIC events (bad CRCs, + # management frames, etc.) that are NOT test-traffic loss. Lumping + # ierrors into a single "NIC Drops" total masks the real signal. + # Run #10 proved this — see docs/perf-test-log.md for details. + # + # NIC imissed = rte_eth_stats.imissed — the DPDK SW polled too + # slowly and the HW RX descriptor ring filled up, + # so the NIC discarded incoming frames. This is + # the REAL "app can't keep up" signal. + # NIC ierrors = rte_eth_stats.ierrors — generic NIC-level errors + # (CRC, framing, oversized, etc.). On ENA this is + # mostly AWS background noise and should be treated + # as such unless it changes between runs. + # NIC nombuf = rte_eth_stats.rx_nombuf — no mempool buffer was + # available to place an incoming packet; the NIC + # dropped it at the refill path. Indicates the + # mempool is sized too small or being drained. + # App Drops = dpdk-udp software-layer drops (rx_ring_drops + + # rx_buf_drops). Packets that made it through the + # NIC into the socket path but got dropped because + # the worker SpscRing or the per-socket recv_queue + # was full (consumer too slow). + # + # All four are only available for backends that emit [PERF] lines. + # Non-zero wire drop (TX/RX delta) with imissed/nombuf/App all ≈ 0 + # points at wire loss (AWS ENA / VPC rate limiter / bad cabling). + lines.append("| Config | Target PPS | TX pps | RX pps | Drop % | NIC imissed | NIC ierrors | NIC nombuf | App Drops | Lat Avg (us) | Lat Max (us) | TX Mbps | RX Mbps |") + lines.append("|--------|-----------|--------|--------|--------|-------------|-------------|-----------|-----------|-------------|-------------|---------|---------|") + + for cfg_name in ["native-dpdk", "rust-dpdk", "tokio-dpdk", "plain-rust"]: cfg_data = configs.get(cfg_name, {}) size_results = cfg_data.get("results", {}).get(pkt_size, []) @@ -1141,9 +1557,135 @@ else: tx_mbps = f"{r.get('tx_mbps', 0):.1f}" rx_mbps = f"{r.get('rx_mbps', 0):.1f}" target = f"{r.get('target_pps', 0):,}" + # `app_drops` / `nic_imissed` / `nic_ierrors` / `nic_rx_nombuf` + # are only present for DPDK-backed configs that emit [PERF] + # lines. Show "—" for plain-rust / native-dpdk (native-dpdk + # is a C reference binary and does not emit [PERF] either). + if 'app_drops' in r: + app_drops = f"{r['app_drops']:,}" + else: + app_drops = "—" + if 'nic_imissed' in r: + nic_imissed = f"{r['nic_imissed']:,}" + nic_ierrors = f"{r['nic_ierrors']:,}" + nic_nombuf = f"{r['nic_rx_nombuf']:,}" + else: + nic_imissed = "—" + nic_ierrors = "—" + nic_nombuf = "—" + + lines.append(f"| {cfg_name} | {target} | {tx_pps} | {rx_pps} | {drop} | {nic_imissed} | {nic_ierrors} | {nic_nombuf} | {app_drops} | {lat_avg_s} | {lat_max_s} | {tx_mbps} | {rx_mbps} |") - lines.append(f"| {cfg_name} | {target} | {tx_pps} | {rx_pps} | {drop} | {lat_avg_s} | {lat_max_s} | {tx_mbps} | {rx_mbps} |") + lines.append("") + # ── NIC drops instrumentation self-check ──────────────────────────── + # For every config that emitted [NIC-BASELINE]/[NIC-FINAL], compare + # (FINAL - BASELINE) to the sum of per-tick [PERF] deltas. If the + # reporter pipeline is healthy they MUST match exactly, because both + # numbers come from the same counter reads (FINAL-BASELINE is just a + # telescoping sum of the tick deltas). A mismatch here is the signal + # that our NIC drop instrumentation is losing data — which is the + # question that motivated adding this check in the first place. + lines.append("### NIC Drops Instrumentation Self-Check") + lines.append("") + lines.append( + "Compares `(NIC-FINAL − NIC-BASELINE)` one-shot snapshots " + "against the sum of per-tick `[PERF]` deltas over the reporter's " + "lifetime. These MUST match exactly — a mismatch means per-tick " + "delta bookkeeping is losing data." + ) + lines.append("") + lines.append("| Config | Status | imissed (expected / actual / Δ) | ierrors (expected / actual / Δ) | rx_nombuf (expected / actual / Δ) |") + lines.append("|--------|--------|--------------------------------|----------------------------------|-----------------------------------|") + for cfg_name in ["native-dpdk", "rust-dpdk", "tokio-dpdk", "plain-rust"]: + cfg_data = configs.get(cfg_name, {}) + check = cfg_data.get("nic_consistency") + if check is None: + lines.append(f"| {cfg_name} | no data | — | — | — |") + continue + status = check["status"] + if status == "no_data": + lines.append(f"| {cfg_name} | no instrumentation | — | — | — |") + continue + if status == "no_shutdown": + # Reporter started but never got a FINAL — abnormal exit. + lines.append( + f"| {cfg_name} | no FINAL (abnormal shutdown) | — | — | — |" + ) + continue + exp = check["expected"] + act = check["actual"] + delta = check["delta"] + status_cell = "**OK**" if status == "ok" else "**MISMATCH**" + + def _fmt(counter): + d = delta[counter] + d_str = f"+{d:,}" if d > 0 else f"{d:,}" + return f"{exp[counter]:,} / {act[counter]:,} / {d_str}" + + lines.append( + f"| {cfg_name} | {status_cell} | " + f"{_fmt('imissed')} | {_fmt('ierrors')} | {_fmt('rx_nombuf')} |" + ) + lines.append("") + lines.append( + "*`expected = FINAL − BASELINE` (raw NIC counter delta across reporter " + "lifetime). `actual = sum of per-tick [PERF] delta fields`. Any Δ ≠ 0 " + "is a bug in the tick loop's bookkeeping.*" + ) + lines.append("") + + # ── Kernel ethtool deltas for plain-rust ──────────────────────────── + # The self-check above only covers DPDK configs (they embed + # PerfReporter). For plain-rust we don't have per-tick NIC counters, + # but the harness captures `ethtool -S ` pre- and post-run so + # we can at least expose kernel-visible NIC drop totals side-by-side + # with the DPDK numbers. This is the non-DPDK baseline the user asked + # for: "we could probably get kernel data for the rust native app too". + plain_rust_data = configs.get("plain-rust", {}) + kernel_delta = plain_rust_data.get("kernel_ethtool_delta") + if kernel_delta is not None: + lines.append("### plain-rust Kernel NIC Drops (ethtool -S delta)") + lines.append("") + lines.append( + "Kernel-visible NIC counters from the ena driver, captured via " + "`ethtool -S` before and after the plain-rust rate sweep. " + "These are the non-DPDK analogue of the DPDK self-check above " + "and let us compare what the kernel sees against what TRex " + "observes on the wire." + ) + lines.append("") + lines.append("| Counter | Delta | Kernel Meaning |") + lines.append("|---------|------:|----------------|") + # Human-readable descriptions of each ena counter. + descriptions = { + "rx_missed_errors": + "HW RX ring overflowed — driver didn't drain fast enough " + "(equivalent of DPDK `rte_eth_stats.imissed`)", + "rx_dropped": + "Packets dropped somewhere in the RX path (generic)", + "rx_errors": + "Total RX errors — CRC, framing, truncation, etc. " + "(equivalent of DPDK `rte_eth_stats.ierrors`)", + "rx_no_buffer_count": + "No sk_buff available to receive incoming packet " + "(equivalent of DPDK `rte_eth_stats.rx_nombuf`)", + } + for counter in ["rx_missed_errors", "rx_dropped", + "rx_errors", "rx_no_buffer_count"]: + if counter in kernel_delta: + desc = descriptions.get(counter, "") + lines.append( + f"| `{counter}` | {kernel_delta[counter]:,} | {desc} |" + ) + lines.append("") + elif "plain-rust" in configs: + lines.append("### plain-rust Kernel NIC Drops (ethtool -S delta)") + lines.append("") + lines.append( + "*ethtool snapshots not available — baseline or final file " + "missing in `$LOGS_DIR/dut-plain-rust-ethtool-*.txt`.*" + ) lines.append("") md_content = "\n".join(lines) @@ -1568,8 +2110,14 @@ DUT instance \`$DUT_INSTANCE_ID\` SSM working, build complete." Running \`$config\` benchmark... Packet sizes: \`$PACKET_SIZES\` | Duration: ${DURATION}s/step | Target PPS: \`$RATE_STEPS\`" - # Stop any running DUT apps - dut_stop_all_apps + # Only run dut_stop_all_apps at the top of the FIRST iteration — + # this is defensive in case a previous aborted run left echo/testpmd + # processes alive. For iterations 2+, the previous iteration already + # called dut_stop_all_apps at its tail (so [NIC-FINAL] was captured + # in the log) and we don't need to do it again here. + if [[ $config_idx -eq 1 ]]; then + dut_stop_all_apps + fi if [[ $config_idx -gt 1 ]]; then # Give the DUT time to settle between configs. # High-bandwidth benchmarks can overwhelm the kernel network stack @@ -1601,6 +2149,7 @@ Packet sizes: \`$PACKET_SIZES\` | Duration: ${DURATION}s/step | Target PPS: \`$R case "$config" in rust-dpdk) start_dut_rust_dpdk || start_ok=false ;; rust-dpdk-multicore) start_dut_rust_dpdk_multicore || start_ok=false ;; + tokio-dpdk) start_dut_tokio_dpdk || start_ok=false ;; native-dpdk) start_dut_native_dpdk || start_ok=false ;; rust-stdlib) start_dut_rust_stdlib || start_ok=false ;; plain-rust) start_dut_plain_rust || start_ok=false ;; @@ -1640,11 +2189,39 @@ ${dut_diag} collect_networking_diagnostics "$TREX_INSTANCE_ID" "trex" "failure-${config}" fi + # For plain-rust, capture kernel NIC counters NOW — before the + # process is killed — because ethtool counters live in the kernel + # and are independent of the echo process. For DPDK configs we + # must defer log collection until AFTER dut_stop_all_apps (see + # below) so the `[NIC-FINAL]` line has a chance to be emitted. + if [[ "$config" == "plain-rust" ]]; then + local ethtool_final + ethtool_final=$(ssm_run_command "$DUT_INSTANCE_ID" 60 \ + "set -e; for retry in 1 2 3; do IFACE=\$(ls /sys/bus/pci/devices/0000:00:06.0/net/ 2>/dev/null | head -1); if [ -n \"\$IFACE\" ]; then OUT=\$(ethtool -S \$IFACE 2>&1); if echo \"\$OUT\" | grep -q ': [0-9]'; then echo \"\$OUT\"; exit 0; fi; fi; sleep 2; done; echo 'ETHTOOL_FINAL_FAILED iface=\$IFACE'; exit 0" 2>/dev/null || echo "(SSM failed)") + echo "$ethtool_final" > "$LOGS_DIR/dut-plain-rust-ethtool-final.txt" + local final_lines + final_lines=$(echo "$ethtool_final" | wc -l) + log_info "plain-rust ethtool final captured ($final_lines lines, head: $(echo "$ethtool_final" | head -2 | tr '\n' ' '))" + fi + + # Stop the DUT BEFORE collecting the app log. This is essential + # for DPDK configs: PerfReporter's one-shot `[NIC-FINAL]` line is + # only emitted when the reporter thread is joined (either via + # `disable_perf_reporting` on clean shutdown or via `Drop` when + # the socket is dropped). If we grep the log while the DUT is + # still running, `[NIC-FINAL]` won't be there yet and the + # instrumentation self-check reports "no FINAL (abnormal shutdown)". + # We used to call dut_stop_all_apps at the top of the next + # iteration, but that was too late — the current iteration had + # already scraped the log. + dut_stop_all_apps + # Collect DUT app log for this config local log_file case "$config" in rust-dpdk) log_file="/var/log/echo-rust-dpdk.log" ;; rust-dpdk-multicore) log_file="/var/log/echo-rust-dpdk-multicore.log" ;; + tokio-dpdk) log_file="/var/log/echo-tokio-dpdk.log" ;; native-dpdk) log_file="/var/log/testpmd.log" ;; rust-stdlib) log_file="/var/log/echo-rust-stdlib.log" ;; plain-rust) log_file="/var/log/plain-echo.log" ;; @@ -1654,6 +2231,19 @@ ${dut_diag} app_log=$(ssm_run_command "$DUT_INSTANCE_ID" 30 \ "tail -50 $log_file 2>/dev/null || echo '(no log)'" 2>/dev/null || echo "(failed)") echo "$app_log" > "$LOGS_DIR/dut-${config}-app.log" + + # Also pull every [PERF] line from the full log so we can compute + # per-step App Drops in aggregate_results. Each [PERF] line is ~300 + # bytes; even at 30+ lines per config the total is well under SSM's + # output cap. Save to a separate file the aggregator reads. + # Also capture [NIC-BASELINE] / [NIC-FINAL] — one-shot lines the + # PerfReporter emits at startup and clean shutdown. They let the + # aggregator cross-check sum-of-tick-deltas against the end-minus- + # start NIC counter delta (instrumentation self-check). + local perf_lines + perf_lines=$(ssm_run_command "$DUT_INSTANCE_ID" 30 \ + "grep -E '^\[PERF\]|^\[NIC-BASELINE\]|^\[NIC-FINAL\]' $log_file 2>/dev/null || echo ''" 2>/dev/null || echo "") + echo "$perf_lines" > "$LOGS_DIR/dut-${config}-perf.log" # Post testpmd log to PR for visibility (stats-period output shows RX/TX counters) if [[ "$config" == "native-dpdk" ]]; then local testpmd_diag