ECN validation failed, no ECT(0) packets were newly acked

[larseggert]

When I run RUST_LOG=warn cargo bench --features bench --bench transfer I see

Benchmarking transfer/pacing-false/varying-seeds: Warming up for 5.0000 s0.000 WARN [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1
0.000 WARN [Client ...] Dropped received packet: Coalesced packet has different DCID; Total: 1
0.000 WARN [LossRecovery] ignoring in-1 from dropped space
0.027 WARN [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1
0.028 WARN [Client ...] Dropped received packet: Coalesced packet has different DCID; Total: 1
0.028 WARN [LossRecovery] ignoring in-1 from dropped space
0.028 WARN ECN validation failed, no ECT(0) packets were newly acked

and many more instances of the last line. That is surprising. Why is ECN validation failing over loopback?

[martinthomson]

That smells like bleaching, which seems unnecessary, but maybe loopback doesn't preserve ToS bits at all. How hard is it to test that?

[larseggert]

I don't think it's bleaching. I also see it when I run test/test.sh on the server side, and the pcap has ECN marks. I'll use that to debug.

[larseggert]

The server first gets

  -> RX Ack { largest_acknowledged: 7, ack_delay: 2, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) }

and then a few packets later

  -> RX Ack { largest_acknowledged: 9, ack_delay: 2, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) }

i.e., largest_acknowledged increased but the Ect0 count didn't. So it should disable. Question now is why the count hasn't increased in the second ACK...

[larseggert]

OK, what's happening is that the server sent 10 packets with ECT(0) per https://datatracker.ietf.org/doc/html/rfc9000#name-ecn-validation and then flipped to sending with Not-ECT waiting for the client to send an ACK to check if those ten packets made it.

The client accurately reports the marks it saw. But the validation logic in the server isn't aware that it has stopped sending ECT(0) and is hence failing the validation.

[larseggert]

Actually, I don't think the dropping the spaces is the problem after all. I think Connection::handle_ack is the issue, where self.loss_recovery.on_ack_received is called first, which ends up calling ecn::Info::validate_ack_ecn_and_update before the ACK'ed ECN counts are updated in the loop that follows.