refactor: print current StateSignaling variant in debug_assert

[mxinden]

CI paniced in StateSignaling::handshake_done called from Connection::handle_lost_packets. Unable to reproduce locally. To ease debugging future CI failures, print the current state on panic.

thread 'idle_timeout_crazy_rtt' panicked at neqo-transport\src\connection\state.rs:212:13:
StateSignaling must be in Idle state.
stack backtrace:
   0: std::panicking::begin_panic_handler
             at /rustc/8df7e723ea729a7f917501cc2d91d640b7021373/library\std\src\panicking.rs:646
   1: core::panicking::panic_fmt
             at /rustc/8df7e723ea729a7f917501cc2d91d640b7021373/library\core\src\panicking.rs:72
   2: enum2$<neqo_transport::connection::state::StateSignaling>::handshake_done
             at .\src\connection\state.rs:212
   3: neqo_transport::connection::Connection::handle_lost_packets
             at .\src\connection\mod.rs:2847
   4: neqo_transport::connection::Connection::process_timer
             at .\src\connection\mod.rs:966
   5: neqo_transport::connection::Connection::process_output
             at .\src\connection\mod.rs:1085
   6: neqo_transport::connection::Connection::process
             at .\src\connection\mod.rs:1108
   7: test_fixture::sim::connection::impl$1::process
             at D:\a\neqo\neqo\test-fixture\src\sim\connection.rs:146
   8: test_fixture::sim::Simulator::process_loop
             at D:\a\neqo\neqo\test-fixture\src\sim\mod.rs:193
   9: test_fixture::sim::ReadySimulator::run
             at D:\a\neqo\neqo\test-fixture\src\sim\mod.rs:284
  10: test_fixture::sim::Simulator::run
             at D:\a\neqo\neqo\test-fixture\src\sim\mod.rs:265
  11: network::idle_timeout_crazy_rtt
             at D:\a\neqo\neqo\test-fixture\src\sim\mod.rs:69
  12: network::idle_timeout_crazy_rtt::closure$0
             at D:\a\neqo\neqo\test-fixture\src\sim\mod.rs:58
  13: core::ops::function::FnOnce::call_once<network::idle_timeout_crazy_rtt::closure_env$0,tuple$<> >
             at /rustc/8df7e723ea729a7f917501cc2d91d640b7021373\library\core\src\ops\function.rs:250
  14: core::ops::function::FnOnce::call_once
             at /rustc/8df7e723ea729a7f917501cc2d91d640b7021373/library\core\src\ops\function.rs:250
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

https://github.com/mozilla/neqo/actions/runs/8496770595/job/23274538553

---

Might be related to #974.

[github-actions]

Benchmark results

Performance differences relative to 27a7250.

• drain a timer quickly time: [356.28 ns 364.05 ns 371.18 ns]
  change: [-0.4408% +1.5179% +3.6097%] (p = 0.15 > 0.05)
  No change in performance detected.

• coalesce_acked_from_zero 1+1 entries
  time: [195.58 ns 196.03 ns 196.52 ns]
  change: [-0.2926% +0.1644% +0.6644%] (p = 0.51 > 0.05)
  No change in performance detected.

• coalesce_acked_from_zero 3+1 entries
  time: [235.00 ns 235.57 ns 236.18 ns]
  change: [-0.3042% -0.0055% +0.2806%] (p = 0.97 > 0.05)
  No change in performance detected.

• coalesce_acked_from_zero 10+1 entries
  time: [234.85 ns 235.87 ns 237.01 ns]
  change: [-0.1495% +0.7967% +2.2841%] (p = 0.19 > 0.05)
  No change in performance detected.

• coalesce_acked_from_zero 1000+1 entries
  time: [216.56 ns 216.68 ns 216.82 ns]
  change: [-0.9068% -0.2309% +0.3978%] (p = 0.52 > 0.05)
  No change in performance detected.

• RxStreamOrderer::inbound_frame()
  time: [118.24 ms 118.31 ms 118.39 ms]
  change: [-0.4325% -0.3487% -0.2627%] (p = 0.00 < 0.05)
  Change within noise threshold.

• transfer/Run multiple transfers with varying seeds
  time: [119.52 ms 119.80 ms 120.06 ms]
  thrpt: [33.316 MiB/s 33.390 MiB/s 33.466 MiB/s]
  change:
  time: [-2.7240% -2.4213% -2.1161%] (p = 0.00 < 0.05)
  thrpt: [+2.1618% +2.4813% +2.8003%]
  Change within noise threshold.

• transfer/Run multiple transfers with the same seed
  time: [120.37 ms 120.52 ms 120.67 ms]
  thrpt: [33.148 MiB/s 33.190 MiB/s 33.232 MiB/s]
  change:
  time: [-2.5571% -2.3973% -2.2203%] (p = 0.00 < 0.05)
  thrpt: [+2.2707% +2.4561% +2.6242%]
  Change within noise threshold.

• 1-conn/1-100mb-resp (aka. Download)/client
  time: [1.1380 s 1.1416 s 1.1453 s]
  thrpt: [87.314 MiB/s 87.598 MiB/s 87.877 MiB/s]
  change:
  time: [+0.2714% +1.6823% +2.9037%] (p = 0.03 < 0.05)
  thrpt: [-2.8218% -1.6545% -0.2707%]
  Change within noise threshold.

• 1-conn/10_000-1b-seq-resp (aka. RPS)/client
  time: [427.66 ms 429.80 ms 431.98 ms]
  thrpt: [23.149 Kelem/s 23.266 Kelem/s 23.383 Kelem/s]
  change:
  time: [-0.3513% +0.3402% +1.0639%] (p = 0.35 > 0.05)
  thrpt: [-1.0527% -0.3390% +0.3526%]
  No change in performance detected.

• 100-seq-conn/1-1b-resp (aka. HPS)/client
  time: [3.3775 s 3.3807 s 3.3839 s]
  thrpt: [29.551 elem/s 29.580 elem/s 29.608 elem/s]
  change:
  time: [+0.1473% +0.2716% +0.4075%] (p = 0.00 < 0.05)
  thrpt: [-0.4059% -0.2709% -0.1471%]
  Change within noise threshold.

Client/server transfer results

Transfer of 134217728 bytes over loopback.

Client	Server	CC	Pacing	Mean [ms]	Min [ms]	Max [ms]	Relative
msquic	msquic			826.6 ± 333.6	440.4	1422.7	1.00
neqo	msquic	reno	on	2141.4 ± 210.2	1930.0	2516.4	1.00
neqo	msquic	reno		2138.6 ± 171.4	1918.0	2458.8	1.00
neqo	msquic	cubic	on	2183.0 ± 236.9	1922.5	2526.1	1.00
neqo	msquic	cubic		2078.6 ± 310.5	1749.6	2599.0	1.00
msquic	neqo	reno	on	4691.4 ± 378.8	4215.9	5210.7	1.00
msquic	neqo	reno		4412.2 ± 278.7	4078.9	4954.5	1.00
msquic	neqo	cubic	on	4524.7 ± 224.8	4249.5	4981.1	1.00
msquic	neqo	cubic		4413.8 ± 291.7	4066.1	5146.7	1.00
neqo	neqo	reno	on	3870.4 ± 316.7	3517.5	4445.2	1.00
neqo	neqo	reno		3765.7 ± 354.9	3307.7	4463.3	1.00
neqo	neqo	cubic	on	4481.6 ± 246.7	4134.7	4943.6	1.00
neqo	neqo	cubic		4290.3 ± 241.8	3991.9	4856.3	1.00

⬇️ Download logs