Skip to content

Commit 9e9cba3

Browse files
committed
fix(mirror): make read-consistency staleness check deterministic
Thread now_ms in from the caller instead of reading the wall clock inside check_mirror_read_consistency, so the BoundedStaleness lag comparison is a pure function of its inputs. This removes a race between lag injection and the staleness check that could flake boundary-condition tests on a slow runner.
1 parent cc61e5a commit 9e9cba3

6 files changed

Lines changed: 71 additions & 24 deletions

File tree

nodedb/src/control/server/pgwire/ddl/database/mirror/read.rs

Lines changed: 23 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -20,8 +20,6 @@
2020
//! This is the lowest-latency option and is correct for use cases that
2121
//! accept CRDT-style monotonic convergence (e.g. mobile/edge workloads).
2222
23-
use std::time::{Duration, SystemTime, UNIX_EPOCH};
24-
2523
use nodedb_types::error::sqlstate;
2624
use nodedb_types::{DatabaseId, MirrorOrigin, MirrorStatus};
2725

@@ -52,11 +50,17 @@ pub enum MirrorReadOutcome {
5250
/// `promoted` is true when the mirror has been promoted and the database
5351
/// is now a writable primary — in that case all consistency levels are
5452
/// served locally (no longer a mirror).
53+
/// `now_ms` is the current wall-clock time (ms since epoch), supplied by the
54+
/// caller rather than read internally so the staleness comparison is a pure
55+
/// function of its inputs — this keeps `BoundedStaleness` boundary tests
56+
/// deterministic instead of racing the wall clock between lag injection and
57+
/// the check.
5558
pub fn check_mirror_read_consistency(
5659
catalog: &SystemCatalog,
5760
mirror_db_id: DatabaseId,
5861
mirror_origin: &MirrorOrigin,
5962
consistency: ReadConsistency,
63+
now_ms: u64,
6064
) -> MirrorReadOutcome {
6165
// A promoted mirror is a normal writable database — serve all reads locally.
6266
if matches!(mirror_origin.status, MirrorStatus::Promoted) {
@@ -106,11 +110,6 @@ pub fn check_mirror_read_consistency(
106110
}
107111
};
108112

109-
let now_ms = SystemTime::now()
110-
.duration_since(UNIX_EPOCH)
111-
.unwrap_or(Duration::ZERO)
112-
.as_millis() as u64;
113-
114113
let actual_lag_ms = now_ms.saturating_sub(last_apply_ms);
115114
let max_lag_ms = max_lag.as_millis() as u64;
116115

@@ -176,7 +175,13 @@ mod tests {
176175
let db_id = DatabaseId::new(1024);
177176
let origin = sample_origin(MirrorStatus::Following);
178177

179-
match check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong) {
178+
match check_mirror_read_consistency(
179+
&catalog,
180+
db_id,
181+
&origin,
182+
ReadConsistency::Strong,
183+
now_ms(),
184+
) {
180185
MirrorReadOutcome::Reject {
181186
sqlstate_code,
182187
message,
@@ -198,7 +203,13 @@ mod tests {
198203
let db_id = DatabaseId::new(1025);
199204
let origin = sample_origin(MirrorStatus::Following);
200205

201-
match check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Eventual) {
206+
match check_mirror_read_consistency(
207+
&catalog,
208+
db_id,
209+
&origin,
210+
ReadConsistency::Eventual,
211+
now_ms(),
212+
) {
202213
MirrorReadOutcome::ServeLocally => {}
203214
MirrorReadOutcome::Reject { message, .. } => {
204215
panic!("Eventual should serve locally, got reject: {message}")
@@ -226,7 +237,7 @@ mod tests {
226237
.unwrap();
227238

228239
let bound = ReadConsistency::BoundedStaleness(Duration::from_secs(10));
229-
match check_mirror_read_consistency(&catalog, db_id, &origin, bound) {
240+
match check_mirror_read_consistency(&catalog, db_id, &origin, bound, now_ms()) {
230241
MirrorReadOutcome::ServeLocally => {}
231242
MirrorReadOutcome::Reject { message, .. } => {
232243
panic!("Fresh mirror should serve locally, got reject: {message}")
@@ -255,7 +266,7 @@ mod tests {
255266

256267
// Bound = 5 seconds; actual lag ≈ 60 seconds.
257268
let bound = ReadConsistency::BoundedStaleness(Duration::from_secs(5));
258-
match check_mirror_read_consistency(&catalog, db_id, &origin, bound) {
269+
match check_mirror_read_consistency(&catalog, db_id, &origin, bound, now_ms()) {
259270
MirrorReadOutcome::Reject {
260271
sqlstate_code,
261272
message,
@@ -282,7 +293,7 @@ mod tests {
282293
ReadConsistency::Eventual,
283294
ReadConsistency::BoundedStaleness(Duration::from_secs(1)),
284295
] {
285-
match check_mirror_read_consistency(&catalog, db_id, &origin, consistency) {
296+
match check_mirror_read_consistency(&catalog, db_id, &origin, consistency, now_ms()) {
286297
MirrorReadOutcome::ServeLocally => {}
287298
MirrorReadOutcome::Reject { message, .. } => {
288299
panic!("Promoted mirror should always serve locally, got: {message}")

nodedb/src/control/server/pgwire/handler/dispatch.rs

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -159,11 +159,16 @@ impl NodeDbPgHandler {
159159
// Consistency defaults to Strong: mirrors are not the source leader,
160160
// so reads are rejected unless the session has explicitly opted into
161161
// BoundedStaleness or Eventual.
162+
let now_ms = std::time::SystemTime::now()
163+
.duration_since(std::time::UNIX_EPOCH)
164+
.unwrap_or(std::time::Duration::ZERO)
165+
.as_millis() as u64;
162166
let outcome = check_mirror_read_consistency(
163167
catalog,
164168
task.database_id,
165169
origin,
166170
ReadConsistency::Strong,
171+
now_ms,
167172
);
168173
if let MirrorReadOutcome::Reject { message, .. } = outcome {
169174
return Err(crate::Error::StaleReadNotLeader {

nodedb/tests/mirror/test_eventual_read_serves_local.rs

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@ use nodedb::control::server::pgwire::ddl::database::{
1414
};
1515
use nodedb::types::ReadConsistency;
1616

17-
use super::helpers::{TEST_SOURCE_CLUSTER, inject_lag_record_for_id, open_tmp_catalog};
17+
use super::helpers::{TEST_SOURCE_CLUSTER, inject_lag_record_for_id, now_ms, open_tmp_catalog};
1818

1919
#[test]
2020
fn mirror_eventual_read_serves_local() {
@@ -35,7 +35,13 @@ fn mirror_eventual_read_serves_local() {
3535
};
3636

3737
// Eventual always serves locally regardless of lag.
38-
match check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Eventual) {
38+
match check_mirror_read_consistency(
39+
&catalog,
40+
db_id,
41+
&origin,
42+
ReadConsistency::Eventual,
43+
now_ms(),
44+
) {
3945
MirrorReadOutcome::ServeLocally => {}
4046
MirrorReadOutcome::Reject { message, .. } => {
4147
panic!("Eventual read must always serve locally, got reject: {message}");
@@ -57,7 +63,13 @@ fn mirror_eventual_serves_even_when_disconnected() {
5763
status: MirrorStatus::Disconnected,
5864
};
5965

60-
match check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Eventual) {
66+
match check_mirror_read_consistency(
67+
&catalog,
68+
db_id,
69+
&origin,
70+
ReadConsistency::Eventual,
71+
now_ms(),
72+
) {
6173
MirrorReadOutcome::ServeLocally => {}
6274
MirrorReadOutcome::Reject { message, .. } => {
6375
panic!("Eventual read on Disconnected mirror must still serve locally: {message}");

nodedb/tests/mirror/test_full_lifecycle.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -124,6 +124,7 @@ fn mirror_full_lifecycle() {
124124
db_id,
125125
origin,
126126
ReadConsistency::BoundedStaleness(Duration::from_secs(5)),
127+
now_ms(),
127128
) {
128129
MirrorReadOutcome::ServeLocally => {}
129130
MirrorReadOutcome::Reject { message, .. } => {
@@ -159,7 +160,7 @@ fn mirror_full_lifecycle() {
159160
ReadConsistency::Eventual,
160161
ReadConsistency::BoundedStaleness(Duration::from_millis(1)),
161162
] {
162-
match check_mirror_read_consistency(&catalog, db_id, origin, consistency) {
163+
match check_mirror_read_consistency(&catalog, db_id, origin, consistency, now_ms()) {
163164
MirrorReadOutcome::ServeLocally => {}
164165
MirrorReadOutcome::Reject { message, .. } => {
165166
panic!("Promoted mirror must serve all reads locally: {message}");

nodedb/tests/mirror/test_simulated_latency.rs

Lines changed: 19 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,7 @@
1616
1717
use std::time::Duration;
1818

19-
use nodedb_types::{DatabaseId, Lsn, MirrorMode, MirrorOrigin, MirrorStatus};
19+
use nodedb_types::{DatabaseId, Lsn, MirrorLagRecord, MirrorMode, MirrorOrigin, MirrorStatus};
2020
use tempfile::TempDir;
2121

2222
use nodedb::control::server::pgwire::ddl::database::{
@@ -51,6 +51,7 @@ fn mirror_simulated_cross_region_latency() {
5151
db_id,
5252
&origin,
5353
ReadConsistency::BoundedStaleness(Duration::from_millis(1_000)),
54+
now_ms(),
5455
) {
5556
MirrorReadOutcome::ServeLocally => {}
5657
MirrorReadOutcome::Reject { message, .. } => {
@@ -64,6 +65,7 @@ fn mirror_simulated_cross_region_latency() {
6465
db_id,
6566
&origin,
6667
ReadConsistency::BoundedStaleness(Duration::from_millis(100)),
68+
now_ms(),
6769
) {
6870
MirrorReadOutcome::Reject { sqlstate_code, .. } => {
6971
assert_eq!(
@@ -93,9 +95,21 @@ fn mirror_simulated_latency_at_threshold_boundary() {
9395
let catalog = open_tmp_catalog(&dir);
9496
let db_id = DatabaseId::new(5002);
9597

96-
// Simulate RTT exactly at the BoundedStaleness window: 199 ms lag,
97-
// 200 ms bound — must pass.
98-
inject_lag_record_for_id(&catalog, db_id, 199, 1);
98+
// Fix `now` and derive `last_apply_ms` from it so the computed lag is
99+
// exactly 199 ms — one millisecond inside the 200 ms bound — regardless of
100+
// how long lag injection takes. Passing the same `now` into the check keeps
101+
// this boundary deterministic; reading the wall clock inside the check would
102+
// add real elapsed time to the lag and flake the assertion on a slow runner.
103+
let now = now_ms();
104+
catalog
105+
.put_mirror_lag(
106+
db_id,
107+
&MirrorLagRecord {
108+
last_applied_lsn: Lsn::new(1),
109+
last_apply_ms: now.saturating_sub(199),
110+
},
111+
)
112+
.expect("inject lag record");
99113

100114
let origin = MirrorOrigin {
101115
source_cluster: TEST_SOURCE_CLUSTER.to_string(),
@@ -110,6 +124,7 @@ fn mirror_simulated_latency_at_threshold_boundary() {
110124
db_id,
111125
&origin,
112126
ReadConsistency::BoundedStaleness(Duration::from_millis(200)),
127+
now,
113128
) {
114129
MirrorReadOutcome::ServeLocally => {}
115130
MirrorReadOutcome::Reject { message, .. } => {

nodedb/tests/mirror/test_strong_read_rejected.rs

Lines changed: 7 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@ use nodedb::control::server::pgwire::ddl::database::{
1414
};
1515
use nodedb::types::ReadConsistency;
1616

17-
use super::helpers::{TEST_SOURCE_CLUSTER, open_tmp_catalog};
17+
use super::helpers::{TEST_SOURCE_CLUSTER, now_ms, open_tmp_catalog};
1818

1919
fn following_origin() -> MirrorOrigin {
2020
MirrorOrigin {
@@ -33,7 +33,8 @@ fn mirror_strong_read_rejected() {
3333
let db_id = DatabaseId::new(1001);
3434
let origin = following_origin();
3535

36-
let outcome = check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong);
36+
let outcome =
37+
check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong, now_ms());
3738

3839
match outcome {
3940
MirrorReadOutcome::Reject {
@@ -69,7 +70,8 @@ fn mirror_strong_read_rejected_degraded() {
6970
status: MirrorStatus::Degraded { lag_ms: 8_000 },
7071
};
7172

72-
let outcome = check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong);
73+
let outcome =
74+
check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong, now_ms());
7375

7476
match outcome {
7577
MirrorReadOutcome::Reject { sqlstate_code, .. } => {
@@ -97,7 +99,8 @@ fn mirror_strong_read_rejected_disconnected() {
9799
status: MirrorStatus::Disconnected,
98100
};
99101

100-
let outcome = check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong);
102+
let outcome =
103+
check_mirror_read_consistency(&catalog, db_id, &origin, ReadConsistency::Strong, now_ms());
101104

102105
match outcome {
103106
MirrorReadOutcome::Reject { sqlstate_code, .. } => {

0 commit comments

Comments
 (0)