Repository navigation
feat: add always-on performance instrumentation (Phase 1) - #23
Conversation
Implement high-performance, lock-free instrumentation for DPDK UDP sockets to provide visibility into packet processing performance before optimization. New dpdk-udp/src/perf.rs module: - PerfCounters: cache-line aligned AtomicU64 counters for RX/TX packets, bytes, drops, ARP/ICMP handling, ring utilization, and worker stats - LatencySampler: fixed-size ring buffer with 1-in-N sampling for percentile tracking (p50/p95/p99/p99.9) with < 1% overhead - PerfReporter: background thread emitting structured key=value log lines to stderr at configurable intervals - PerfSnapshot: programmatic API for reading perf data Wired into hot paths: - send_to_addr: tx_packets, tx_bytes, tx_failures, arp_cache_hits/misses - recv_from_inline: rx_bursts, rx_burst_sum, rx_packets, rx_bytes, rx_arp_handled, rx_icmp_handled, rx_drops_parse_fail - Latency sampling at rx_burst return → recv_from return - Multi-core topology: rx_drops_ring_full, worker_idle_polls, worker_packets_processed, app_ring_enqueue_fail UdpSocket API additions: - perf_counters() / perf_counters_arc() - enable_perf_reporting(interval) / disable_perf_reporting() - perf_snapshot() - latency_sampler() Echo app: --perf-interval <seconds> flag for runtime reporting. 12 unit tests covering concurrent counters, percentile accuracy, reporter lifecycle, and rate computation. https://claude.ai/code/session_016N4yPU5RzaxmK1Vtu4Hr6y
[CI] Stage: DeployInfrastructure ready.
|
[CI] Stage: SummaryAll tests PASSED. ARP seeding: kernel /proc/net/arp (automatic)
|
✅ Integration Tests Passed (Run 22986576346)Branch: Test Results
Application Logsreceiver-echo-server.logsender-echo-server.logsender-test-client.logreceiver-test-client-iperf.logsender-test-client-iperf.log
|
[Perf] Stage: DeployDeploying |
Instrumentation MetricsIntegration Tests: ✅ All Passed (Run #22986576346)
Phase 1 Implementation SummaryNew module
Counters wired into hot paths:
Echo app: Unit tests: 12 tests covering concurrent counters, percentile accuracy, reporter lifecycle. Performance test run: https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/22987432396 |
[Perf] Stage: Instances Ready
|
[Perf] Stage: TRex ConfigStarting TRex configuration (MAC discovery + NIC binding)... |
[Perf] Stage: TRex Config OK
|
[Perf] Stage: TRex StartedTRex server running. Beginning benchmarks... |
[Perf] DUT ReadyDUT instance |
[Perf] Stage: Benchmark (1/5)Running |
[Perf] Benchmark Diag:
|
[Perf] Benchmark Diag:
|
[Perf] Stage: Benchmark (2/5)Running |
[Perf] Benchmark Diag:
|
[Perf] Benchmark Diag:
|
[Perf] Stage: Benchmark (3/5)Running |
[Perf] Benchmark Diag:
|
[Perf] Benchmark Diag:
|
[Perf] Stage: Benchmark (4/5)Running |
[Perf] Benchmark Diag:
|
[Perf] Benchmark Diag:
|
[Perf] Stage: Benchmark (5/5)Running |
[Perf] Benchmark Diag:
|
[Perf] Benchmark Diag:
|
[Perf] Diag: testpmd logtestpmd output (last 30 lines) |
[Perf] Stage: Results[05:59:13] INFO Generating markdown summary... Performance Test Results — c5n.2xlargeCommit: 1400B packets
512B packets
64B packets
|
Performance Test Results (Run #22987432396) — All Passed ✅Key Results: rust-dpdk single-core (1400B) — with instrumentation enabled
Comparison: native-dpdk baseline (1400B)
rust-dpdk-multicore (1400B) — confirms known performance gap (Phase 2/3 target)
AnalysisSingle-core (rust-dpdk) with instrumentation: Performance is consistent with pre-instrumentation baseline. At 350K PPS the drop rate is 0.15% with 284us avg latency — instrumentation overhead is not measurable at this scale. The ~2x latency gap vs native-dpdk (284us vs 161us) is the pre-existing gap that Phase 2 (mutex elimination, ARP fast-path) will address. Multi-core: Confirms the severe degradation documented in requirements (75% drop at 350K PPS, 166ms max latency). This is the target for Phase 3 (slab pool, per-worker SPSC, worker-direct TX). No regressions introduced by instrumentation. |
- Add `perf-counters` cargo feature (default=on) to dpdk-udp: all hot-path counter increments compile to no-ops with `--no-default-features`, eliminating instrumentation overhead for latency-critical deployments - Fix TX ring full backpressure in multicore mode: - Increase ring capacity from 4096 to 16384 slots - Increase TX drain batch from 32 to 256 frames per cycle - Add second TX drain pass after RX processing to halve echo latency - Auto-enable perf reporting (10s interval) when multicore pipeline starts - Pass --perf-interval 10 to multicore echo server in perf tests - Show last 20 lines of app logs inline in CI PR comments (not hidden in collapsible), with full 200-line log in expandable section below https://claude.ai/code/session_016N4yPU5RzaxmK1Vtu4Hr6y
[Perf] Stage: Benchmark (5/5)Running |
[Perf] Benchmark Diag:
|
[Perf] Benchmark Diag:
|
[Perf] Diag: testpmd logtestpmd output (last 30 lines) |
[Perf] Stage: Results[15:11:12] INFO Generating markdown summary... Performance Test Results — c5n.2xlargeCommit: 1400B packets
512B packets
64B packets
Failed Configs
|
Performance Test Failure (Run 23004302078)Branch: failure-summary.json{
"failed_step": "perf-test",
"error": "Script exited with code 1",
"exit_code": 2,
"timestamp": "2026-03-12T15:12:06.671314Z",
"trex_instance_id": "i-0508af5e670703c34",
"dut_instance_id": "i-0b73305cbeed90a2c",
"commit": "148d2410a310ac0b118c165c81a3f944f6df404c",
"run_url": "https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/23004302078"
}```
<details><summary>dut-environment.txt</summary>
=== System Info === Network devices using kernel driver0000:00:05.0 'Elastic Network Adapter (ENA) ec20' if=ens5 drv=ena unused=vfio-pci Active No 'Baseband' devices detectedNo 'Crypto' devices detectedNo 'DMA' devices detectedNo 'Eventdev' devices detectedNo 'Mempool' devices detectedNo 'Compress' devices detectedNo 'Misc (rawdev)' devices detectedNo 'Regex' devices detected=== Network Interfaces === === System Info === (failed) plain-echo listening on 10.0.1.218:9000 Send error: tx queue full Send error: TX ring full 🚀 DPDK-STDLIB Echo Server (failed) plain-echo listening on 10.0.1.218:9000 Send error: tx queue full Send error: TX ring full 🚀 DPDK-STDLIB Echo Server === Interface State === Network devices using kernel driver0000:00:05.0 'Elastic Network Adapter (ENA) ec20' if=ens5 drv=ena unused=vfio-pci Active No 'Baseband' devices detectedNo 'Crypto' devices detectedNo 'DMA' devices detectedNo 'Eventdev' devices detectedNo 'Mempool' devices detectedNo 'Compress' devices detectedNo 'Misc (rawdev)' devices detectedNo 'Regex' devices detected=== Ethtool Stats (ens6) === (failed) (failed) === Interface State === (failed) (failed) |
[Perf] Stage: DeployDeploying |
Performance Test Failure (Run 23011396603)Branch: failure-summary.json{
"failed_step": "perf-test",
"error": "Script exited with code 2",
"exit_code": 2,
"timestamp": "2026-03-12T16:19:50.499106Z",
"trex_instance_id": "",
"dut_instance_id": "",
"commit": "148d2410a310ac0b118c165c81a3f944f6df404c",
"run_url": "https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/23011396603"
}```
### Application Logs (last 20 lines)
<details><summary>Full Application Logs (last 200 lines each)</summary>
</details>
<details><summary>Network & PCI State</summary>
</details>
<details><summary>Kernel Console (dmesg)</summary>
</details> |
[Perf] Stage: DeployDeploying |
Performance Test Failure (Run 23014287878)Branch: failure-summary.json{
"failed_step": "perf-test",
"error": "Script exited with code 2",
"exit_code": 2,
"timestamp": "2026-03-12T17:25:50.839791Z",
"trex_instance_id": "",
"dut_instance_id": "",
"commit": "148d2410a310ac0b118c165c81a3f944f6df404c",
"run_url": "https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/23014287878"
}```
### Application Logs (last 20 lines)
<details><summary>Full Application Logs (last 200 lines each)</summary>
</details>
<details><summary>Network & PCI State</summary>
</details>
<details><summary>Kernel Console (dmesg)</summary>
</details> |
[Perf] Stage: DeployDeploying |
Performance Test Failure (Run 23015349931)Branch: failure-summary.json{
"failed_step": "perf-test",
"error": "Script exited with code 2",
"exit_code": 2,
"timestamp": "2026-03-12T17:50:51.549752Z",
"trex_instance_id": "",
"dut_instance_id": "",
"commit": "148d2410a310ac0b118c165c81a3f944f6df404c",
"run_url": "https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/23015349931"
}```
### Application Logs (last 20 lines)
<details><summary>Full Application Logs (last 200 lines each)</summary>
</details>
<details><summary>Network & PCI State</summary>
</details>
<details><summary>Kernel Console (dmesg)</summary>
</details> |
The perf test script's stack cleanup loop had a bug where after the 900s timeout, it would blindly proceed to `cdk deploy` even if the old stack was still in DELETE_IN_PROGRESS. This caused all 4 recent perf runs to fail with "Stack is in DELETE_IN_PROGRESS state and can not be updated." The fix adds post-timeout escalation: - If stack is still DELETE_IN_PROGRESS after 900s, use `--retain-resources` on all undeletable resources to force cleanup - Wait up to 120s more for the retain-resources delete to finish - Fail with a clear error if the stack still can't be deleted, instead of attempting a doomed `cdk deploy` - Also handle DELETE_FAILED state after timeout with retain-resources https://claude.ai/code/session_016N4yPU5RzaxmK1Vtu4Hr6y
[Perf] Stage: DeployDeploying |
[CI] Stage: DeployInfrastructure ready.
|
Performance Test Failure (Run 23019600299)Branch: failure-summary.json{
"failed_step": "perf-test",
"error": "Script exited with code 2",
"exit_code": 2,
"timestamp": "2026-03-12T19:36:39.400820Z",
"trex_instance_id": "",
"dut_instance_id": "",
"commit": "de447c0d331423ad64fa8ef53b15b8cd7fbd8eec",
"run_url": "https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/23019600299"
}```
### Application Logs (last 20 lines)
<details><summary>Full Application Logs (last 200 lines each)</summary>
</details>
<details><summary>Network & PCI State</summary>
</details>
<details><summary>Kernel Console (dmesg)</summary>
</details> |
[CI] Stage: SummaryAll tests PASSED. ARP seeding: kernel /proc/net/arp (automatic)
|
When CDK deploy fails, the script now captures CloudFormation events (FAILED/ROLLBACK resources) and posts them to the PR as a comment. This gives visibility into which resource failed and why, instead of just "CDK deploy failed" with no diagnostics. https://claude.ai/code/session_016N4yPU5RzaxmK1Vtu4Hr6y
[Perf] Stage: DeployDeploying |
✅ Integration Tests Passed (Run 23019595293)Branch: Test Results
Application Logs (last 20 lines)receiver-echo-server.log sender-echo-server.log sender-test-client.log receiver-test-client-iperf.log sender-test-client-iperf.log Full Application Logs (last 200 lines each)receiver-echo-server.logsender-echo-server.logsender-test-client.logreceiver-test-client-iperf.logsender-test-client-iperf.log
|
[CI] Stage: DeployInfrastructure ready.
|
Performance Test Failure (Run 23020644756)Branch: failure-summary.json{
"failed_step": "perf-test",
"error": "Script exited with code 2",
"exit_code": 2,
"timestamp": "2026-03-12T20:03:32.969960Z",
"trex_instance_id": "",
"dut_instance_id": "",
"commit": "1b11ee6772b6db6a9852e2373d0f5a9cf3442512",
"run_url": "https://github.com/gspivey/dpdk-stdlib-rust/actions/runs/23020644756"
}```
### Application Logs (last 20 lines)
<details><summary>Full Application Logs (last 200 lines each)</summary>
</details>
<details><summary>Network & PCI State</summary>
</details>
<details><summary>Kernel Console (dmesg)</summary>
</details> |
[CI] Stage: SummaryAll tests PASSED. ARP seeding: kernel /proc/net/arp (automatic)
|
✅ Integration Tests Passed (Run 23020643885)Branch: Test Results
Application Logs (last 20 lines)receiver-echo-server.log sender-echo-server.log sender-test-client.log receiver-test-client-iperf.log sender-test-client-iperf.log Full Application Logs (last 200 lines each)receiver-echo-server.logsender-echo-server.logsender-test-client.logreceiver-test-client-iperf.logsender-test-client-iperf.log
|
## Roadmap Item Implements ROADMAP item #23: `dpdk-stdlib-tcp: Engine — on_tick (tx-drain and RTO)` Spec: `.kiro/specs/tcp-support/` · tasks 5.14, 5.15 ## Changes ### Task 5.14: TX Drain - Drain `tx_ring` → `send_buf` → segment respecting `effective_window(rwnd)` → transmit - Segments at MSS boundaries, respects Nagle algorithm - Wakes condvar + `write_waker` when send window opens (enables blocked writers to resume) - Only runs for ESTABLISHED and CLOSE_WAIT connections ### Task 5.15: RTO (Retransmission Timeout) - Retransmit oldest unacked segment on RTO expiry - Double RTO on each retransmit (exponential backoff, capped at 60s) - Collapse cwnd to 1 MSS on timeout (RFC 5681) - Abort after `max_retries` (default 15) → latch `TimedOut` on ConnectionHandle - Fulfil pending connect oneshot on abort ### Config Addition - Added `max_retries: u32` field to `EngineConfig` (default 15) ## Tests Added 14 new unit tests covering: - TX drain: basic data send, effective window limiting, MSS segmentation, RTO arming, retransmit queue population, snd_nxt advancement, write_waker notification, zero-window blocking, Nagle buffering, TCP_NODELAY override - RTO: retransmission on expiry, exponential backoff, abort after max retries (with TimedOut latch), cwnd collapse, empty retransmit queue safety, state filtering (SYN_SENT doesn't drain) ## Tradeoffs - The retransmit implementation reads payload from `send_buf` via iterator (not zero-copy from the original VecDeque). This is acceptable at MVP; a contiguous-slice optimization can be added later if profiling shows overhead. ## Verification All 945 workspace tests pass (`cargo build && cargo test`). --------- Co-authored-by: Agent Router <agent@agent-router.dev>
Summary
dpdk-udp/src/perf.rsmodule with lock-freePerfCounters(cache-line alignedAtomicU64),LatencySampler(1-in-1000 sampling with percentile computation),PerfReporter(background thread emitting structured key=value log lines), andPerfSnapshotAPIperf_counters(),enable_perf_reporting(interval),disable_perf_reporting(),perf_snapshot(),latency_sampler()--perf-interval <seconds>flag to enable runtime performance reportingDesign decisions
fetch_add(1, Relaxed)— the cheapest atomic operation with no memory fencePerfCountersis#[repr(align(64))]to prevent false sharing across coresAtomicU64ring buffer with 1-in-1000 sampling rate (~350 clock reads/sec at 350K PPS — negligible overhead)[PERF] interval=10s rx_pps=... tx_pps=... lat_avg_us=... lat_p99_us=...Test plan
https://claude.ai/code/session_016N4yPU5RzaxmK1Vtu4Hr6y