Flaky test: `single_ack_eliciting_packet_triggers_ack_after_delay`

[Darksonn]

The single_ack_eliciting_packet_triggers_ack_after_delay test just failed in Tokio's CI on tokio-rs/tokio#6899 which should not have impacted this test.

failures:

---- tests::single_ack_eliciting_packet_triggers_ack_after_delay stdout ----
2024-10-16T14:39:26.074622Z  INFO quinn_proto::tests::util: connecting
2024-10-16T14:39:26.074699Z TRACE client: quinn_proto::endpoint: initial_dcid=3426b078460b06cd9e6aabaabacd0c960910f9ec
2024-10-16T14:39:26.075843Z TRACE client: quinn_proto::connection: wrote 271 Initial CRYPTO bytes
2024-10-16T14:39:26.075918Z TRACE client:send{space=Initial pn=0}: quinn_proto::connection: CRYPTO: off 0 len 271
2024-10-16T14:39:26.075939Z TRACE client:send{space=Initial pn=0}: quinn_proto::connection::packet_builder: PADDING * 870
2024-10-16T14:39:26.075984Z TRACE client: quinn_proto::connection: sending 1200 bytes in 1 datagrams
2024-10-16T14:39:26.076529Z TRACE server:first recv:frame{ty=CRYPTO}: quinn_proto::connection: consumed 271 CRYPTO bytes
2024-10-16T14:39:26.079346Z TRACE server:first recv: quinn_proto::connection: Handshake keys ready
2024-10-16T14:39:26.079363Z TRACE server:first recv: quinn_proto::connection: wrote 90 Initial CRYPTO bytes
2024-10-16T14:39:26.079475Z TRACE server:first recv: quinn_proto::connection: Data keys ready
2024-10-16T14:39:26.079566Z TRACE server:first recv: quinn_proto::connection: wrote 635 Handshake CRYPTO bytes
2024-10-16T14:39:26.079643Z TRACE server: quinn_proto::endpoint: new connection id=0 icid=3426b078460b06cd9e6aabaabacd0c960910f9ec
2024-10-16T14:39:26.079716Z TRACE server:send{space=Initial pn=0}: quinn_proto::connection: ACK ArrayRangeSet([0..1]), Delay = 0us
2024-10-16T14:39:26.079743Z TRACE server:send{space=Initial pn=0}: quinn_proto::connection: CRYPTO: off 0 len 90
2024-10-16T14:39:26.079814Z TRACE server:send{space=Handshake pn=0}: quinn_proto::connection: CRYPTO: off 0 len 635
2024-10-16T14:39:26.079838Z TRACE server:send{space=Handshake pn=0}: quinn_proto::connection::packet_builder: PADDING * 374
2024-10-16T14:39:26.079879Z TRACE server: quinn_proto::connection: sending 1200 bytes in 1 datagrams
2024-10-16T14:39:26.079971Z TRACE server:send{space=Data pn=0}: quinn_proto::connection: NEW_CONNECTION_ID sequence=1 id=41c37c7d408d1348
2024-10-16T14:39:26.080002Z TRACE server:send{space=Data pn=0}: quinn_proto::connection: NEW_CONNECTION_ID sequence=2 id=db644b1873534bf3
2024-10-16T14:39:26.080029Z TRACE server:send{space=Data pn=0}: quinn_proto::connection: NEW_CONNECTION_ID sequence=3 id=7b31918fa7361050
2024-10-16T14:39:26.080056Z TRACE server:send{space=Data pn=0}: quinn_proto::connection: NEW_CONNECTION_ID sequence=4 id=26734e01f51b7d56
2024-10-16T14:39:26.080109Z TRACE server: quinn_proto::connection: sending 138 bytes in 1 datagrams
2024-10-16T14:39:26.080175Z TRACE client: quinn_proto::connection: got Initial packet (145 bytes) from [::1]:4500 using id 373a1d00fb4ed8fd
2024-10-16T14:39:26.080223Z TRACE client:recv{space=Initial pn=0}: quinn_proto::connection: switching remote CID to d105da0e0ee7f035
2024-10-16T14:39:26.080294Z TRACE client:recv{space=Initial pn=0}:frame{ty=CRYPTO}: quinn_proto::connection: consumed 90 CRYPTO bytes
2024-10-16T14:39:26.081782Z TRACE client:recv{space=Initial pn=0}: quinn_proto::connection: Handshake keys ready
2024-10-16T14:39:26.081821Z TRACE client: quinn_proto::connection: got Handshake packet (1055 bytes) from [::1]:4500 using id 373a1d00fb4ed8fd
2024-10-16T14:39:26.081885Z TRACE client:recv{space=Handshake pn=0}:frame{ty=CRYPTO}: quinn_proto::connection: consumed 635 CRYPTO bytes
2024-10-16T14:39:26.082565Z TRACE client:recv{space=Handshake pn=0}: quinn_proto::connection: Data keys ready
2024-10-16T14:39:26.082656Z TRACE client:recv{space=Handshake pn=0}: quinn_proto::connection: wrote 52 Handshake CRYPTO bytes
2024-10-16T14:39:26.082719Z TRACE client:recv{space=Handshake pn=0}: quinn_proto::connection: established
2024-10-16T14:39:26.082752Z TRACE client: quinn_proto::connection: got Data packet (138 bytes) from [::1]:4500 using id 373a1d00fb4ed8fd
2024-10-16T14:39:26.082812Z TRACE client:recv{space=Data pn=0}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 1, retire_prior_to: 0, id: [65, 195, 124, 125, 64, 141, 19, 72], reset_token: ResetToken([68, 159, 251, 49, 63, 65, 219, 8, 246, 149, 85, 64, 187, 34, 138, 207]) })
2024-10-16T14:39:26.082840Z TRACE client:recv{space=Data pn=0}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=1 id=41c37c7d408d1348 retire_prior_to=0
2024-10-16T14:39:26.082891Z TRACE client:recv{space=Data pn=0}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 2, retire_prior_to: 0, id: [219, 100, 75, 24, 115, 83, 75, 243], reset_token: ResetToken([13, 50, 58, 133, 125, 74, 211, 189, 68, 169, 160, 42, 167, 233, 193, 147]) })
2024-10-16T14:39:26.082916Z TRACE client:recv{space=Data pn=0}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=2 id=db644b1873534bf3 retire_prior_to=0
2024-10-16T14:39:26.082967Z TRACE client:recv{space=Data pn=0}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 3, retire_prior_to: 0, id: [123, 49, 145, 143, 167, 54, 16, 80], reset_token: ResetToken([136, 152, 150, 226, 252, 45, 255, 47, 122, 98, 132, 190, 144, 69, 158, 96]) })
2024-10-16T14:39:26.082991Z TRACE client:recv{space=Data pn=0}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=3 id=7b31918fa7361050 retire_prior_to=0
2024-10-16T14:39:26.083044Z TRACE client:recv{space=Data pn=0}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 4, retire_prior_to: 0, id: [38, 115, 78, 1, 245, 27, 125, 86], reset_token: ResetToken([164, 219, 91, 84, 95, 55, 114, 79, 92, 216, 21, 252, 218, 139, 103, 229]) })
2024-10-16T14:39:26.083070Z TRACE client:recv{space=Data pn=0}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=4 id=26734e01f51b7d56 retire_prior_to=0
2024-10-16T14:39:26.083145Z TRACE client:send{space=Initial pn=1}: quinn_proto::connection: ACK ArrayRangeSet([0..1]), Delay = 0us
2024-10-16T14:39:26.083198Z TRACE client: quinn_proto::connection: discarding Initial keys
2024-10-16T14:39:26.083236Z TRACE client:send{space=Handshake pn=0}: quinn_proto::connection: ACK ArrayRangeSet([0..1]), Delay = 0us
2024-10-16T14:39:26.083256Z TRACE client:send{space=Handshake pn=0}: quinn_proto::connection: CRYPTO: off 0 len 52
2024-10-16T14:39:26.083278Z TRACE client:send{space=Handshake pn=0}: quinn_proto::connection::packet_builder: PADDING * 1044
2024-10-16T14:39:26.083322Z TRACE client: quinn_proto::connection: sending 1200 bytes in 1 datagrams
2024-10-16T14:39:26.083360Z TRACE client:send{space=Data pn=0}: quinn_proto::connection::packet_builder: PADDING * 1298
2024-10-16T14:39:26.083421Z TRACE client: quinn_proto::connection: writing MTUD probe probe_size=1326
2024-10-16T14:39:26.083438Z TRACE client: quinn_proto::connection: sending 1326 bytes in 1 datagrams
2024-10-16T14:39:26.083543Z TRACE client:send{space=Data pn=1}: quinn_proto::connection: NEW_CONNECTION_ID sequence=1 id=6643870c980dea9a
2024-10-16T14:39:26.083574Z TRACE client:send{space=Data pn=1}: quinn_proto::connection: NEW_CONNECTION_ID sequence=2 id=5eed99a582064533
2024-10-16T14:39:26.083598Z TRACE client:send{space=Data pn=1}: quinn_proto::connection: NEW_CONNECTION_ID sequence=3 id=b184fbc48c1fe7a5
2024-10-16T14:39:26.083620Z TRACE client:send{space=Data pn=1}: quinn_proto::connection: NEW_CONNECTION_ID sequence=4 id=445e6b5f13b2f56a
2024-10-16T14:39:26.083670Z TRACE client: quinn_proto::connection: sending 138 bytes in 1 datagrams
2024-10-16T14:39:26.083733Z TRACE server: quinn_proto::connection: got Initial packet (51 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.083830Z TRACE server: quinn_proto::connection: got Handshake packet (1149 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.083876Z TRACE server:recv{space=Handshake pn=0}: quinn_proto::connection: discarding Initial keys
2024-10-16T14:39:26.083944Z TRACE server:recv{space=Handshake pn=0}:frame{ty=CRYPTO}: quinn_proto::connection: consumed 52 CRYPTO bytes
2024-10-16T14:39:26.084559Z TRACE server:recv{space=Handshake pn=0}: quinn_proto::connection: wrote 356 Data CRYPTO bytes
2024-10-16T14:39:26.084583Z TRACE server:recv{space=Handshake pn=0}: quinn_proto::connection: discarding Handshake keys
2024-10-16T14:39:26.084604Z TRACE server:recv{space=Handshake pn=0}: quinn_proto::connection: established
2024-10-16T14:39:26.084632Z TRACE server: quinn_proto::connection: got Data packet (1326 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.084688Z TRACE server:recv{space=Data pn=0}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.084722Z TRACE server:recv{space=Data pn=0}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.085182Z TRACE server: quinn_proto::connection: got Data packet (138 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.085246Z TRACE server:recv{space=Data pn=1}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 1, retire_prior_to: 0, id: [102, 67, 135, 12, 152, 13, 234, 154], reset_token: ResetToken([99, 189, 54, 190, 16, 246, 247, 22, 176, 45, 222, 39, 131, 164, 169, 11]) })
2024-10-16T14:39:26.085273Z TRACE server:recv{space=Data pn=1}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=1 id=6643870c980dea9a retire_prior_to=0
2024-10-16T14:39:26.085331Z TRACE server:recv{space=Data pn=1}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 2, retire_prior_to: 0, id: [94, 237, 153, 165, 130, 6, 69, 51], reset_token: ResetToken([116, 155, 93, 216, 242, 220, 8, 195, 202, 74, 185, 19, 213, 151, 220, 177]) })
2024-10-16T14:39:26.085358Z TRACE server:recv{space=Data pn=1}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=2 id=5eed99a582064533 retire_prior_to=0
2024-10-16T14:39:26.085401Z TRACE server:recv{space=Data pn=1}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 3, retire_prior_to: 0, id: [177, 132, 251, 196, 140, 31, 231, 165], reset_token: ResetToken([254, 229, 21, 46, 57, 100, 238, 236, 147, 11, 2, 56, 169, 182, 195, 146]) })
2024-10-16T14:39:26.085427Z TRACE server:recv{space=Data pn=1}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=3 id=b184fbc48c1fe7a5 retire_prior_to=0
2024-10-16T14:39:26.085476Z TRACE server:recv{space=Data pn=1}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 4, retire_prior_to: 0, id: [68, 94, 107, 95, 19, 178, 245, 106], reset_token: ResetToken([23, 90, 82, 236, 211, 41, 141, 86, 58, 121, 234, 125, 214, 57, 64, 52]) })
2024-10-16T14:39:26.085502Z TRACE server:recv{space=Data pn=1}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=4 id=445e6b5f13b2f56a retire_prior_to=0
2024-10-16T14:39:26.085580Z TRACE server:send{space=Data pn=1}: quinn_proto::connection: ACK ArrayRangeSet([0..2]), Delay = 0us
2024-10-16T14:39:26.085607Z TRACE server:send{space=Data pn=1}: quinn_proto::connection: CRYPTO: off 0 len 356
2024-10-16T14:39:26.085627Z TRACE server:send{space=Data pn=1}: quinn_proto::connection: RETIRE_CONNECTION_ID sequence=0
2024-10-16T14:39:26.085674Z TRACE server: quinn_proto::connection: sending 397 bytes in 1 datagrams
2024-10-16T14:39:26.085711Z TRACE server:send{space=Data pn=2}: quinn_proto::connection::packet_builder: PADDING * 1298
2024-10-16T14:39:26.085763Z TRACE server: quinn_proto::connection: writing MTUD probe probe_size=1326
2024-10-16T14:39:26.085780Z TRACE server: quinn_proto::connection: sending 1326 bytes in 1 datagrams
2024-10-16T14:39:26.085853Z TRACE client: quinn_proto::connection: got Data packet (397 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.085913Z TRACE client:recv{space=Data pn=1}: quinn_proto::connection: got frame HandshakeDone
2024-10-16T14:39:26.085933Z TRACE client:recv{space=Data pn=1}:frame{ty=HANDSHAKE_DONE}: quinn_proto::connection: discarding Handshake keys
2024-10-16T14:39:26.085986Z TRACE client:recv{space=Data pn=1}: quinn_proto::connection: got frame Ack(Ack { largest: 1, delay: 0, ecn: Some(EcnCounts { ect0: 2, ect1: 0, ce: 0 }), ranges: "[0..=1]" })
2024-10-16T14:39:26.086021Z TRACE client:recv{space=Data pn=1}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1326
2024-10-16T14:39:26.086077Z TRACE client:recv{space=Data pn=1}: quinn_proto::connection: got crypto frame offset=0 len=356
2024-10-16T14:39:26.086105Z TRACE client:recv{space=Data pn=1}:frame{ty=CRYPTO}: quinn_proto::connection: consumed 356 CRYPTO bytes
2024-10-16T14:39:26.086320Z TRACE client:recv{space=Data pn=1}: quinn_proto::connection: got frame RetireConnectionId { sequence: 0 }
2024-10-16T14:39:26.086362Z TRACE client: quinn_proto::connection: got Data packet (1326 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.086421Z TRACE client:recv{space=Data pn=2}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.086457Z TRACE client:recv{space=Data pn=2}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.086944Z TRACE client:send{space=Data pn=2}: quinn_proto::connection: ACK ArrayRangeSet([0..3]), Delay = 0us
2024-10-16T14:39:26.086995Z TRACE client: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.087037Z TRACE client:send{space=Data pn=3}: quinn_proto::connection::packet_builder: PADDING * 1361
2024-10-16T14:39:26.087096Z TRACE client: quinn_proto::connection: writing MTUD probe probe_size=1389
2024-10-16T14:39:26.087113Z TRACE client: quinn_proto::connection: sending 1389 bytes in 1 datagrams
2024-10-16T14:39:26.087136Z TRACE client: quinn_proto::endpoint: peer retired CID 0: 373a1d00fb4ed8fd
2024-10-16T14:39:26.087198Z TRACE client:send{space=Data pn=4}: quinn_proto::connection: NEW_CONNECTION_ID sequence=5 id=5e175d265a7298ac
2024-10-16T14:39:26.087252Z TRACE client: quinn_proto::connection: sending 54 bytes in 1 datagrams
2024-10-16T14:39:26.087317Z TRACE server: quinn_proto::connection: got Data packet (34 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.087[386](https://github.com/tokio-rs/tokio/actions/runs/11367899879/job/31621769987?pr=6899#step:8:387)Z TRACE server:recv{space=Data pn=2}: quinn_proto::connection: got frame Ack(Ack { largest: 2, delay: 0, ecn: Some(EcnCounts { ect0: 3, ect1: 0, ce: 0 }), ranges: "[0..=2]" })
2024-10-16T14:39:26.087433Z TRACE server:recv{space=Data pn=2}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1326
2024-10-16T14:39:26.087492Z TRACE server: quinn_proto::connection: got Data packet (1389 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.087548Z TRACE server:recv{space=Data pn=3}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.087580Z TRACE server:recv{space=Data pn=3}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.088040Z TRACE server: quinn_proto::connection: got Data packet (54 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.088089Z TRACE server:recv{space=Data pn=4}: quinn_proto::connection: got frame NewConnectionId(NewConnectionId { sequence: 5, retire_prior_to: 0, id: [94, 23, 93, 38, 90, 114, 152, 172], reset_token: ResetToken([181, 122, 224, 225, 132, 247, 202, 0, 6, 60, 231, 240, 66, 190, 250, 129]) })
2024-10-16T14:39:26.088115Z TRACE server:recv{space=Data pn=4}:frame{ty=NEW_CONNECTION_ID}: quinn_proto::connection: sequence=5 id=5e175d265a7298ac retire_prior_to=0
2024-10-16T14:39:26.088177Z TRACE server:send{space=Data pn=3}: quinn_proto::connection: ACK ArrayRangeSet([2..5]), Delay = 0us
2024-10-16T14:39:26.088219Z TRACE server: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.088253Z TRACE server:send{space=Data pn=4}: quinn_proto::connection::packet_builder: PADDING * 1361
2024-10-16T14:39:26.088304Z TRACE server: quinn_proto::connection: writing MTUD probe probe_size=1389
2024-10-16T14:39:26.088318Z TRACE server: quinn_proto::connection: sending 1389 bytes in 1 datagrams
2024-10-16T14:39:26.088371Z TRACE client: quinn_proto::connection: got Data packet (34 bytes) from [::1]:4500 using id 664[387](https://github.com/tokio-rs/tokio/actions/runs/11367899879/job/31621769987?pr=6899#step:8:388)0c980dea9a
2024-10-16T14:39:26.088428Z TRACE client:recv{space=Data pn=3}: quinn_proto::connection: got frame Ack(Ack { largest: 4, delay: 0, ecn: Some(EcnCounts { ect0: 5, ect1: 0, ce: 0 }), ranges: "[2..=4]" })
2024-10-16T14:39:26.088466Z TRACE client:recv{space=Data pn=3}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1[389](https://github.com/tokio-rs/tokio/actions/runs/11367899879/job/31621769987?pr=6899#step:8:390)
2024-10-16T14:39:26.088522Z TRACE client: quinn_proto::connection: got Data packet (1389 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.088573Z TRACE client:recv{space=Data pn=4}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.088619Z TRACE client:recv{space=Data pn=4}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.089062Z TRACE client:send{space=Data pn=5}: quinn_proto::connection: ACK ArrayRangeSet([3..5]), Delay = 0us
2024-10-16T14:39:26.089103Z TRACE client: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.089131Z TRACE client:send{space=Data pn=6}: quinn_proto::connection::packet_builder: PADDING * 1392
2024-10-16T14:39:26.089170Z TRACE client: quinn_proto::connection: writing MTUD probe probe_size=1420
2024-10-16T14:39:26.089179Z TRACE client: quinn_proto::connection: sending 1420 bytes in 1 datagrams
2024-10-16T14:39:26.089220Z TRACE server: quinn_proto::connection: got Data packet (34 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.089261Z TRACE server:recv{space=Data pn=5}: quinn_proto::connection: got frame Ack(Ack { largest: 4, delay: 0, ecn: Some(EcnCounts { ect0: 5, ect1: 0, ce: 0 }), ranges: "[3..=4]" })
2024-10-16T14:39:26.089287Z TRACE server:recv{space=Data pn=5}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1389
2024-10-16T14:39:26.089322Z TRACE server: quinn_proto::connection: got Data packet (1420 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.089359Z TRACE server:recv{space=Data pn=6}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.089381Z TRACE server:recv{space=Data pn=6}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.089863Z TRACE server:send{space=Data pn=5}: quinn_proto::connection: ACK ArrayRangeSet([5..7]), Delay = 0us
2024-10-16T14:39:26.089903Z TRACE server: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.089929Z TRACE server:send{space=Data pn=6}: quinn_proto::connection::packet_builder: PADDING * 1392
2024-10-16T14:39:26.089965Z TRACE server: quinn_proto::connection: writing MTUD probe probe_size=1420
2024-10-16T14:39:26.089975Z TRACE server: quinn_proto::connection: sending 1420 bytes in 1 datagrams
2024-10-16T14:39:26.090018Z TRACE client: quinn_proto::connection: got Data packet (34 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.090059Z TRACE client:recv{space=Data pn=5}: quinn_proto::connection: got frame Ack(Ack { largest: 6, delay: 0, ecn: Some(EcnCounts { ect0: 7, ect1: 0, ce: 0 }), ranges: "[5..=6]" })
2024-10-16T14:39:26.090085Z TRACE client:recv{space=Data pn=5}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1420
2024-10-16T14:39:26.090121Z TRACE client: quinn_proto::connection: got Data packet (1420 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.090158Z TRACE client:recv{space=Data pn=6}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.090180Z TRACE client:recv{space=Data pn=6}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.090480Z TRACE client:send{space=Data pn=7}: quinn_proto::connection: ACK ArrayRangeSet([5..7]), Delay = 0us
2024-10-16T14:39:26.090512Z TRACE client: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.090537Z TRACE client:send{space=Data pn=8}: quinn_proto::connection::packet_builder: PADDING * 1424
2024-10-16T14:39:26.090572Z TRACE client: quinn_proto::connection: writing MTUD probe probe_size=1452
2024-10-16T14:39:26.090582Z TRACE client: quinn_proto::connection: sending 1452 bytes in 1 datagrams
2024-10-16T14:39:26.090620Z TRACE server: quinn_proto::connection: got Data packet (34 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.090660Z TRACE server:recv{space=Data pn=7}: quinn_proto::connection: got frame Ack(Ack { largest: 6, delay: 0, ecn: Some(EcnCounts { ect0: 7, ect1: 0, ce: 0 }), ranges: "[5..=6]" })
2024-10-16T14:39:26.090684Z TRACE server:recv{space=Data pn=7}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1420
2024-10-16T14:39:26.090720Z TRACE server: quinn_proto::connection: got Data packet (1452 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.090757Z TRACE server:recv{space=Data pn=8}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.090779Z TRACE server:recv{space=Data pn=8}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.091083Z TRACE server:send{space=Data pn=7}: quinn_proto::connection: ACK ArrayRangeSet([7..9]), Delay = 0us
2024-10-16T14:39:26.091114Z TRACE server: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.091139Z TRACE server:send{space=Data pn=8}: quinn_proto::connection::packet_builder: PADDING * 1424
2024-10-16T14:39:26.091180Z TRACE server: quinn_proto::connection: writing MTUD probe probe_size=1452
2024-10-16T14:39:26.091190Z TRACE server: quinn_proto::connection: sending 1452 bytes in 1 datagrams
2024-10-16T14:39:26.091232Z TRACE client: quinn_proto::connection: got Data packet (34 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.091271Z TRACE client:recv{space=Data pn=7}: quinn_proto::connection: got frame Ack(Ack { largest: 8, delay: 0, ecn: Some(EcnCounts { ect0: 9, ect1: 0, ce: 0 }), ranges: "[7..=8]" })
2024-10-16T14:39:26.091296Z TRACE client:recv{space=Data pn=7}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1452
2024-10-16T14:39:26.091332Z TRACE client: quinn_proto::connection: got Data packet (1452 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.091369Z TRACE client:recv{space=Data pn=8}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.091[391](https://github.com/tokio-rs/tokio/actions/runs/11367899879/job/31621769987?pr=6899#step:8:392)Z TRACE client:recv{space=Data pn=8}: quinn_proto::connection: got frame ImmediateAck
2024-10-16T14:39:26.091704Z TRACE client:send{space=Data pn=9}: quinn_proto::connection: ACK ArrayRangeSet([7..9]), Delay = 0us
2024-10-16T14:39:26.091737Z TRACE client: quinn_proto::connection: sending 34 bytes in 1 datagrams
2024-10-16T14:39:26.091774Z TRACE server: quinn_proto::connection: got Data packet (34 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.091814Z TRACE server:recv{space=Data pn=9}: quinn_proto::connection: got frame Ack(Ack { largest: 8, delay: 0, ecn: Some(EcnCounts { ect0: 9, ect1: 0, ce: 0 }), ranges: "[7..=8]" })
2024-10-16T14:39:26.091839Z TRACE server:recv{space=Data pn=9}:frame{ty=ACK}: quinn_proto::connection::mtud: new MTU detected current_mtu=1452
2024-10-16T14:39:26.091913Z TRACE client: quinn_proto::connection: executing key update
2024-10-16T14:39:26.091981Z TRACE client:send{space=Data pn=10}: quinn_proto::connection: PING
2024-10-16T14:39:26.091996Z TRACE client:send{space=Data pn=10}: quinn_proto::connection::packet_builder: PADDING * 3
2024-10-16T14:39:26.092025Z TRACE client: quinn_proto::connection: sending 30 bytes in 1 datagrams
2024-10-16T14:39:26.092063Z TRACE server: quinn_proto::connection: got Data packet (30 bytes) from [::1]:44502 using id d105da0e0ee7f035
2024-10-16T14:39:26.092083Z TRACE server: quinn_proto::connection: key update authenticated
2024-10-16T14:39:26.092090Z TRACE server: quinn_proto::connection: executing key update
2024-10-16T14:39:26.092161Z TRACE server:recv{space=Data pn=10}: quinn_proto::connection: got frame Ping
2024-10-16T14:39:26.092224Z TRACE quinn_proto::tests::util: advancing to 25ms for server
2024-10-16T14:39:26.092244Z TRACE server: quinn_proto::connection: timeout timer=MaxAckDelay
2024-10-16T14:39:26.092255Z TRACE server: quinn_proto::connection: max ack delay reached
2024-10-16T14:39:26.092310Z TRACE server:send{space=Data pn=9}: quinn_proto::connection: ACK ArrayRangeSet([9..11]), Delay = 25000us
2024-10-16T14:39:26.092364Z TRACE server: quinn_proto::connection: sending 35 bytes in 1 datagrams
2024-10-16T14:39:26.092479Z TRACE client: quinn_proto::connection: got Data packet (35 bytes) from [::1]:4500 using id 6643870c980dea9a
2024-10-16T14:39:26.092553Z TRACE client:recv{space=Data pn=9}: quinn_proto::connection: got frame Ack(Ack { largest: 10, delay: 3125, ecn: Some(EcnCounts { ect0: 11, ect1: 0, ce: 0 }), ranges: "[9..=10]" })
2024-10-16T14:39:26.092623Z TRACE quinn_proto::tests::util: advancing to 78ms for server
2024-10-16T14:39:26.092642Z TRACE server: quinn_proto::connection: timeout timer=KeyDiscard
2024-10-16T14:39:26.092661Z TRACE quinn_proto::tests::util: advancing to 103ms for client
2024-10-16T14:39:26.092671Z TRACE client: quinn_proto::connection: timeout timer=KeyDiscard
thread 'tests::single_ack_eliciting_packet_triggers_ack_after_delay' panicked at quinn-proto\src\tests\mod.rs:2475:5:
assertion `left == right` failed
  left: Instant { t: 441.7954904s }
 right: Instant { t: 441.7174904s }
stack backtrace:
   0: std::panicking::begin_panic_handler
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library\std\src\panicking.rs:665
   1: core::panicking::panic_fmt
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library\core\src\panicking.rs:74
   2: core::panicking::assert_failed_inner
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library\core\src\panicking.rs:[410](https://github.com/tokio-rs/tokio/actions/runs/11367899879/job/31621769987?pr=6899#step:8:411)
   3: core::panicking::assert_failed<std::time::Instant,std::time::Instant>
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c\library\core\src\panicking.rs:365
   4: quinn_proto::tests::single_ack_eliciting_packet_triggers_ack_after_delay
             at .\src\tests\mod.rs:2475
   5: quinn_proto::tests::single_ack_eliciting_packet_triggers_ack_after_delay::closure$0
             at .\src\tests\mod.rs:2438
   6: core::ops::function::FnOnce::call_once<quinn_proto::tests::single_ack_eliciting_packet_triggers_ack_after_delay::closure_env$0,tuple$<> >
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c\library\core\src\ops\function.rs:250
   7: core::ops::function::FnOnce::call_once
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library\core\src\ops\function.rs:250
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.


failures:
    tests::single_ack_eliciting_packet_triggers_ack_after_delay

[Ralith]

Thanks for the report! I concur that this shouldn't have been affected. Most notably, it's a quinn-proto test, and those don't involve tokio at all. You could probably avoid exposure to this issue by only running tests from the quinn crate, if that suits your purposes.

[Darksonn]

Yeah, it may make sense to disable those on our sides. Be aware that this is the first time I see this in Tokio's CI, so either it's a new bug, or it's flaking extremely rarely.