fix(client): timestamp probes after successful send

Moves the client userspace probe sent_at measurement to immediately
after a successful UDP send, improving raw RTT and the userspace
upstream-OWD fallback by excluding the socket send-call interval and
the small amount of local work preceding it.

All fallible probe-commit preflight (timeout deadline checked_add,
capacity/collision checks) still runs before the send, from a private
pre-send anchor (SessionMachine::finalize_probe_commit). The public
sent_at is now supplied afterward to an infallible
SessionMachine::commit_probe_sent, so DurationOverflow still guarantees
nothing was transmitted and a WouldBlock try_send still commits
nothing.

The operational probe timeout deadline stays anchored to the pre-send
timestamp on purpose, not to the new post-send sent_at, preserving
existing timeout/loss timing. Linux kernel TX_SOFTWARE plausibility
keeps its own pre-send wall-clock lower bound
(PendingProbe::tx_not_before_wall) instead of the post-send sent_at,
since a legitimate TX_SOFTWARE timestamp can be generated while the
send syscall is still in flight and would otherwise be wrongly
rejected.

Also flags (without touching production code) that irtt-stats'
ReplySample::from_reply_parts feeds the public sent_at directly into
IpdvSample.client_send_mono/client_send_wall_ns, so the upstream/send
IPDV component naturally shifts along with the sent_at semantics
change; per scope this is reported rather than compensated for.
This commit is contained in:
Nils Andreas Svee committed 2026-08-15 19:26:57 +07:00
1 parent 0ca36f2192
commit a3896376da
10 files changed
+502 -128

No files matched your search

@@ -3,6 +3,7 @@ use super::*;
fn probe_timestamps(permission_at: Instant, sent_at: ClientTimestamp) -> ProbeSendTimestamps {
ProbeSendTimestamps {
permission_at,
send_anchor: sent_at,
sent_at,
send_call_start: sent_at.mono,
send_finished_at: sent_at.mono,
@@ -176,12 +177,21 @@ fn blocking_probe_separates_permission_committed_send_and_send_call_timing() {
.unwrap(),
);
let permission_at = opened_mono + Duration::from_millis(500);
let sent_at = ClientTimestamp {
// Distinct pre-send anchor and post-send `sent_at`: the anchor drives
// the operational timeout deadline, while `sent_at` (captured after the
// send call) is the public measurement/timer_error endpoint. They are
// deliberately decoupled by this PR.
let send_anchor = ClientTimestamp {
wall: SystemTime::now(),
mono: opened_mono + Duration::from_millis(525),
};
let sent_at = ClientTimestamp {
wall: SystemTime::now(),
mono: opened_mono + Duration::from_millis(534),
};
let timestamps = ProbeSendTimestamps {
permission_at,
send_anchor,
sent_at,
send_call_start: opened_mono + Duration::from_millis(526),
send_finished_at: opened_mono + Duration::from_millis(533),
@@ -200,11 +210,14 @@ fn blocking_probe_separates_permission_committed_send_and_send_call_timing() {
}] if *scheduled_at == opened_mono
&& *event_sent_at == sent_at
&& *send_call == Duration::from_millis(7)
&& *timer_error == Duration::from_millis(525)
&& *timer_error == Duration::from_millis(534)
));
assert_eq!(client.next_send_deadline(), Some(opened_mono + interval));
assert_eq!(client.runtime.packets_sent(), 1);
let timeout_at = sent_at.mono + client.probe_timeout();
// The timeout deadline is anchored to the pre-send `send_anchor`, not
// to the post-send `sent_at` captured 9ms later.
let timeout_at = send_anchor.mono + client.probe_timeout();
assert_ne!(timeout_at, sent_at.mono + client.probe_timeout());
assert!(client
.poll_timeouts_at(timeout_at - Duration::from_nanos(1))
.unwrap()
@@ -236,6 +249,7 @@ fn blocking_send_call_excludes_wrapped_history_cleanup() {
client.runtime.seed_wrapped_probe_history_for_test(sent_at);
let timestamps = ProbeSendTimestamps {
permission_at: scheduled_at,
send_anchor: sent_at,
sent_at,
send_call_start: scheduled_at + Duration::from_millis(6),
send_finished_at: scheduled_at + Duration::from_millis(13),
@@ -343,6 +357,7 @@ fn managed_probe_skips_missed_schedule_slots() {
};
let timestamps = ProbeSendTimestamps {
permission_at,
send_anchor: delayed_send,
sent_at: delayed_send,
send_call_start: first_deadline + Duration::from_millis(49),
send_finished_at: first_deadline + Duration::from_millis(55),
@@ -72,7 +72,14 @@ fn compute_one_way_omits_samples_when_client_wall_time_overflows_i64() {
};
assert_eq!(
compute_one_way(&sent_at, &received_at, None, &ReceiveMeta::default(), &ts),
compute_one_way(
&sent_at,
sent_at.wall,
&received_at,
None,
&ReceiveMeta::default(),
&ts
),
None
);
}
@@ -93,8 +100,15 @@ fn compute_one_way_returns_available_direction_samples() {
..Default::default()
};
let sample =
compute_one_way(&sent_at, &received_at, None, &ReceiveMeta::default(), &ts).unwrap();
let sample = compute_one_way(
&sent_at,
sent_at.wall,
&received_at,
None,
&ReceiveMeta::default(),
&ts,
)
.unwrap();
assert_eq!(
sample.client_to_server,
Some(SignedDuration::from_nanos(15_000_000))
@@ -121,8 +135,15 @@ fn compute_one_way_preserves_negative_client_to_server_delay() {
..Default::default()
};
let sample =
compute_one_way(&sent_at, &received_at, None, &ReceiveMeta::default(), &ts).unwrap();
let sample = compute_one_way(
&sent_at,
sent_at.wall,
&received_at,
None,
&ReceiveMeta::default(),
&ts,
)
.unwrap();
assert_eq!(
sample.client_to_server,
@@ -150,8 +171,15 @@ fn compute_one_way_preserves_negative_server_to_client_delay() {
..Default::default()
};
let sample =
compute_one_way(&sent_at, &received_at, None, &ReceiveMeta::default(), &ts).unwrap();
let sample = compute_one_way(
&sent_at,
sent_at.wall,
&received_at,
None,
&ReceiveMeta::default(),
&ts,
)
.unwrap();
assert_eq!(
sample.client_to_server,