Skip to content

Commit 229a3c6

Browse files
committed
adapter: refuse a write timestamp past the write timeline's bound
`GroupCommitter::commit_timestamped` documented an obligation it never discharged. Its doc lists the wall-clock throttle among the things it skips, "`target_timestamp` is the caller's to choose, and it must not run the write timeline ahead of the clock", and then it committed whatever it was handed. The oracle is monotone and durable, so that matters. A write far ahead of the clock is applied to the oracle, and every later write and strict-serializable read on the timeline then blocks until the clock catches up. Restarting does not help, since the same timestamp also reaches the catalog shard's upper, which boot re-applies to the oracle. Under `serializable` it is worse than a block: those reads never consult the oracle, so they pick a timestamp near the clock and the acknowledged write stays invisible. The frontend read-then-write path can produce such a target today. It writes at the frontier its subscribe observed, and for a selection over a materialized view with a `REFRESH` option that frontier is legitimately hours or days out. So enforce the bound where it is stated. A target above `write_ts_upper_bound(now)`, the ceiling `check_runaway_write_ts` already measures against, is refused before the append and surfaces as a statement error. This is a backstop rather than a fix. The right answer is for the caller to take its timestamp from the oracle and use the frontier only to certify what it read. What this guarantees is that the worst outcome is one failed statement instead of a stalled timeline. Two smaller things in the same area. `check_runaway_write_ts` soft panics instead of logging, so a runaway fails a test rather than leaving a line in a log, and degrades to that log line in production. Boot reports a catalog upper that is already past the bound, the one channel that survives a restart and was silent. It does not refuse to start, because the timeline is stalled either way and a process that will not boot turns that into an outage plus a crash loop. Tests: an integration test drives the far-future target from a materialized view with two refreshes, one seconds out so the view is readable at all and one far away so the target is deterministic. It asserts the statement is refused, the oracle did not move, and the timeline still takes writes.
1 parent 00299a0 commit 229a3c6

6 files changed

Lines changed: 174 additions & 14 deletions

File tree

src/adapter/src/coord.rs

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4828,6 +4828,20 @@ pub fn serve(
48284828
.expect("inserted above")
48294829
.oracle;
48304830

4831+
// The catalog shard's upper is durable, so a write that once landed far ahead of the
4832+
// clock is re-applied to the oracle here on every boot and cannot be waited out. We
4833+
// report it rather than refusing to start: the timeline is stalled either way, and a
4834+
// process that will not boot turns that into a total outage plus a crash loop.
4835+
let boot_now: mz_repr::Timestamp = (now)().into();
4836+
if catalog_upper > timeline::write_ts_upper_bound(&boot_now) {
4837+
tracing::error!(
4838+
%catalog_upper, %boot_now,
4839+
"catalog upper is far ahead of the wall clock, so writes and \
4840+
strict-serializable reads on the EpochMilliseconds timeline will block \
4841+
until the clock catches up",
4842+
);
4843+
}
4844+
48314845
let mut boot_ts = if read_only_controllers {
48324846
let read_ts = epoch_millis_oracle.read_ts().await;
48334847
std::cmp::max(read_ts, catalog_upper)

src/adapter/src/coord/appends.rs

Lines changed: 25 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,7 @@ use tokio::sync::{Notify, OwnedMutexGuard, OwnedSemaphorePermit, Semaphore, mpsc
6464
use tracing::{Instrument, Span, info, warn};
6565

6666
use crate::catalog::{BuiltinTableUpdate, Catalog, CatalogUpperHandle};
67+
use crate::coord::timeline::write_ts_upper_bound;
6768
use crate::coord::{Coordinator, Message, PendingTxn, PlanValidity};
6869
use crate::metrics::Metrics;
6970
use crate::session::{EndTransactionAction, GroupCommitWriteLocks, Session, WriteLocks};
@@ -174,6 +175,12 @@ pub enum WriteResult {
174175
target_timestamp: Timestamp,
175176
next_eligible_timestamp: Timestamp,
176177
},
178+
/// The requested timestamp ran further ahead of the wall clock than the write
179+
/// timeline may be advanced, so the write was refused before it was attempted.
180+
TimestampTooFarAhead {
181+
target_timestamp: Timestamp,
182+
limit: Timestamp,
183+
},
177184
/// The write was canceled before it entered the committer.
178185
Canceled,
179186
/// The coordinator cannot accept writes.
@@ -438,8 +445,11 @@ impl GroupCommitter {
438445
///
439446
/// What [`Self::commit`] does that this skips, and why that is safe:
440447
///
441-
/// * The wall-clock throttle. `target_timestamp` is the caller's to choose,
442-
/// and it must not run the write timeline ahead of the clock.
448+
/// * The wall-clock throttle. `target_timestamp` is the caller's to choose, so
449+
/// instead of sleeping until the clock catches up we refuse a target above
450+
/// [`write_ts_upper_bound`] outright. Sleeping is the wrong answer for a caller
451+
/// whose target can be hours out, and committing there would advance the oracle
452+
/// with it.
443453
/// * A [`GroupCommitPermit`]. The caller bounds how many of these are in
444454
/// flight, and that is the backpressure for this path.
445455
/// * Merging queued commits. There is nothing to merge into: these diffs
@@ -466,6 +476,19 @@ impl GroupCommitter {
466476
return ControlFlow::Continue(());
467477
}
468478

479+
// The oracle is monotone and durable, so a write above the bound is not a delay we
480+
// can wait out. It would strand the timeline past every restart until the wall
481+
// clock caught up, and the write is applied to the oracle below.
482+
let now: Timestamp = (self.now)().into();
483+
let limit = write_ts_upper_bound(&now);
484+
if target_timestamp > limit {
485+
result.send(WriteResult::TimestampTooFarAhead {
486+
target_timestamp,
487+
limit,
488+
});
489+
return ControlFlow::Continue(());
490+
}
491+
469492
let write_ts = WriteTimestamp {
470493
timestamp: target_timestamp,
471494
advance_to: target_timestamp.step_forward(),

src/adapter/src/coord/timeline.rs

Lines changed: 22 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,7 @@ use mz_storage_types::sources::Timeline;
2525
use mz_timestamp_oracle::batching_oracle::BatchingTimestampOracle;
2626
use mz_timestamp_oracle::{self, TimestampOracle, TimestampOracleConfig, WriteTimestamp};
2727
use timely::progress::Timestamp as _;
28-
use tracing::{Instrument, debug, error, info};
28+
use tracing::{Instrument, debug, info};
2929

3030
use crate::AdapterError;
3131
use crate::catalog::Catalog;
@@ -347,25 +347,35 @@ impl Coordinator {
347347
}
348348
}
349349

350-
/// Convenience function for calculating the current upper bound that we want to
351-
/// prevent the global timestamp from exceeding.
352-
fn upper_bound(now: &mz_repr::Timestamp) -> mz_repr::Timestamp {
350+
/// The highest timestamp the `EpochMilliseconds` write timeline may be advanced to
351+
/// while the wall clock reads `now`.
352+
///
353+
/// A write above this is a runaway: the oracle is monotone and durable, so every later
354+
/// write and strict-serializable read on the timeline blocks until the wall clock catches
355+
/// up, across restarts. Group commit stays under it by allocating from the oracle, which
356+
/// clamps to the clock. A caller that chooses its own write timestamp has to be checked
357+
/// against it, see `GroupCommitter::commit_timestamped`.
358+
pub(crate) fn write_ts_upper_bound(now: &mz_repr::Timestamp) -> mz_repr::Timestamp {
353359
const TIMESTAMP_INTERVAL_MS: u64 = 5000;
354360
const TIMESTAMP_INTERVAL_UPPER_BOUND: u64 = 2;
355361

356362
now.saturating_add(TIMESTAMP_INTERVAL_MS * TIMESTAMP_INTERVAL_UPPER_BOUND)
357363
}
358364

359-
/// Logs an error when `timestamp` is further ahead of `now` than a local write timestamp
360-
/// should ever be, the signal that the `EpochMilliseconds` timeline has run away (e.g. after a
361-
/// wall-clock regression).
365+
/// Reports a write timestamp that is further ahead of `now` than
366+
/// [`write_ts_upper_bound`] allows, the signal that the `EpochMilliseconds` timeline has
367+
/// run away (e.g. after a wall-clock regression, or from a durably poisoned oracle).
368+
///
369+
/// This is a detector, not a guard: the timestamp has already been chosen, and every
370+
/// caller that can still refuse one checks the bound itself. It soft panics so that a
371+
/// runaway fails a test rather than only leaving a line in a log, and in production it
372+
/// degrades to that log line.
362373
pub(crate) fn check_runaway_write_ts(now: &mz_repr::Timestamp, timestamp: mz_repr::Timestamp) {
363-
let upper_bound = upper_bound(now);
374+
let upper_bound = write_ts_upper_bound(now);
364375
if timestamp > upper_bound {
365-
error!(
366-
%now,
367-
"Setting local write timestamp to {timestamp}, which is more than \
368-
the desired upper bound {upper_bound}."
376+
mz_ore::soft_panic_or_log!(
377+
"setting local write timestamp to {timestamp}, which is more than \
378+
the desired upper bound {upper_bound} (now={now})"
369379
);
370380
}
371381
}

src/adapter/src/error.rs

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -140,6 +140,17 @@ pub enum AdapterError {
140140
/// The statement is retryable: every attempt was refused before anything
141141
/// was appended, so nothing it intended has been committed.
142142
ReadThenWriteContention,
143+
/// A frontend read-then-write's write timestamp ran further ahead of the wall
144+
/// clock than the write timeline may be advanced.
145+
///
146+
/// Nothing was appended. Committing there would advance the timeline's oracle
147+
/// to that timestamp, and the oracle is monotone and durable, so every later
148+
/// write and strict-serializable read would block until the wall clock caught
149+
/// up, restarts included.
150+
ReadThenWriteTimestampTooFarAhead {
151+
target_timestamp: mz_repr::Timestamp,
152+
limit: mz_repr::Timestamp,
153+
},
143154
CollectionUnreadable {
144155
id: String,
145156
},
@@ -836,6 +847,12 @@ impl AdapterError {
836847
"Concurrent writes to the target table kept this statement from \
837848
committing. Retry the statement, or lower the write concurrency.".into()
838849
),
850+
AdapterError::ReadThenWriteTimestampTooFarAhead { .. } => Some(
851+
"The selection reads a collection whose contents are already settled far \
852+
into the future, for example a materialized view with a REFRESH option. \
853+
Read it into a table first, or select from it at a time it is still \
854+
changing.".into()
855+
),
839856
AdapterError::CollectionUnreadable { .. } => Some(
840857
"This could be because the collection has recently been dropped.".into()
841858
),
@@ -900,6 +917,9 @@ impl AdapterError {
900917
SqlState::T_R_SERIALIZATION_FAILURE
901918
}
902919
AdapterError::ReadThenWriteContention => SqlState::T_R_SERIALIZATION_FAILURE,
920+
AdapterError::ReadThenWriteTimestampTooFarAhead { .. } => {
921+
SqlState::FEATURE_NOT_SUPPORTED
922+
}
903923
AdapterError::CollectionUnreadable { .. } => SqlState::NO_DATA_FOUND,
904924
AdapterError::NoClusterReplicasAvailable { .. } => SqlState::FEATURE_NOT_SUPPORTED,
905925
AdapterError::OperationProhibitsTransaction(_) => SqlState::ACTIVE_SQL_TRANSACTION,
@@ -1281,6 +1301,16 @@ impl fmt::Display for AdapterError {
12811301
"read-then-write exceeded maximum retry attempts under contention"
12821302
)
12831303
}
1304+
AdapterError::ReadThenWriteTimestampTooFarAhead {
1305+
target_timestamp,
1306+
limit,
1307+
} => {
1308+
write!(
1309+
f,
1310+
"read-then-write would have to commit at {target_timestamp}, past the \
1311+
highest timestamp the write timeline may be advanced to ({limit})"
1312+
)
1313+
}
12841314
AdapterError::CollectionUnreadable { id } => {
12851315
write!(f, "collection '{id}' is not readable at any timestamp")
12861316
}

src/adapter/src/frontend_read_then_write.rs

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -278,6 +278,13 @@ fn classify_write_result(
278278
.requested_error()
279279
.unwrap_or(AdapterError::Canceled),
280280
),
281+
WriteResult::TimestampTooFarAhead {
282+
target_timestamp,
283+
limit,
284+
} => WriteOutcome::Failed(AdapterError::ReadThenWriteTimestampTooFarAhead {
285+
target_timestamp,
286+
limit,
287+
}),
281288
WriteResult::ReadOnly => WriteOutcome::Failed(AdapterError::ReadOnly),
282289
WriteResult::TargetChanged => {
283290
// A concurrent DDL gave the table a new generation after we

src/environmentd/tests/read_then_write.rs

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1952,3 +1952,79 @@ fn test_rejected_in_non_writable_transaction() {
19521952
.get::<_, i32>(0);
19531953
assert_eq!(count, 0, "no rejected write may have landed");
19541954
}
1955+
1956+
/// A read-then-write whose write timestamp would run past what the write timeline
1957+
/// may be advanced to has to be refused, not committed.
1958+
///
1959+
/// The OCC path derives its write timestamp from the frontier its subscribe observed,
1960+
/// and a selection over a materialized view with a `REFRESH` option settles until the
1961+
/// next refresh, so that frontier is legitimately hours or days ahead of the clock.
1962+
/// Committing there advances the timeline's oracle with it, and the oracle is monotone
1963+
/// and durable, so every later write and strict-serializable read on the timeline blocks
1964+
/// until the clock catches up, restarts included. Under `serializable` it is worse than a
1965+
/// block: reads pick a timestamp near the clock, so the acknowledged write stays
1966+
/// invisible.
1967+
///
1968+
/// The MV here refreshes once a few seconds out and once far away. Past the near
1969+
/// refresh it is readable, and its upper is then the far one, which is what makes the
1970+
/// write target far future deterministically rather than by racing a refresh interval.
1971+
#[mz_ore::test]
1972+
#[allow(clippy::disallowed_methods)]
1973+
fn test_far_future_write_timestamp_is_refused() {
1974+
let server = frontend_occ_harness()
1975+
.unsafe_mode()
1976+
.with_system_parameter_default("enable_refresh_every_mvs".to_string(), "true".to_string())
1977+
.start_blocking();
1978+
let mut client = server.connect(postgres::NoTls).unwrap();
1979+
1980+
client.batch_execute("CREATE TABLE src (a INT)").unwrap();
1981+
client
1982+
.batch_execute("INSERT INTO src VALUES (1), (2), (3)")
1983+
.unwrap();
1984+
client.batch_execute("CREATE TABLE dst (a INT)").unwrap();
1985+
client
1986+
.batch_execute(
1987+
"CREATE MATERIALIZED VIEW mv \
1988+
WITH (REFRESH AT mz_now()::text::int8 + 3000, REFRESH AT '3000-01-01') \
1989+
AS SELECT a FROM src",
1990+
)
1991+
.unwrap();
1992+
1993+
// Reaching the write at all means waiting for the near refresh: until then the MV
1994+
// holds no readable content and the read parks instead.
1995+
client
1996+
.batch_execute("SET statement_timeout = '60s'")
1997+
.unwrap();
1998+
1999+
let err = client
2000+
.execute("INSERT INTO dst SELECT a FROM mv", &[])
2001+
.expect_err("a write at a far-future timestamp must be refused");
2002+
let message = server_error_message(&err);
2003+
assert!(
2004+
message.contains("past the highest timestamp the write timeline may be advanced to"),
2005+
"unexpected error for a far-future write: {message}"
2006+
);
2007+
2008+
// The refusal has to happen before the append, so the oracle never learns the
2009+
// far-future timestamp. Checked before anything reads `dst`, because a read cannot be
2010+
// served once the oracle is out there.
2011+
let skew: i64 = client
2012+
.query_one(
2013+
"SELECT mz_now()::text::bigint - (extract(epoch FROM now()) * 1000)::bigint",
2014+
&[],
2015+
)
2016+
.unwrap()
2017+
.get(0);
2018+
assert!(
2019+
skew.abs() < 60_000,
2020+
"the oracle is {skew}ms from wall clock, so the refused write reached it anyway"
2021+
);
2022+
2023+
// The timeline is still usable, both for writes and for reads of the target.
2024+
client.batch_execute("INSERT INTO dst VALUES (4)").unwrap();
2025+
let rows = client
2026+
.query_one("SELECT count(*) FROM dst", &[])
2027+
.unwrap()
2028+
.get::<_, i64>(0);
2029+
assert_eq!(rows, 1, "the refused write must not have landed");
2030+
}

0 commit comments

Comments
 (0)