Skip to content

Commit c9f5ea6

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. That is load-bearing, because the oracle is monotone and durable. A write that lands far ahead of the clock is applied to the oracle, and from then on every write and strict-serializable read on the timeline blocks until the clock catches up. Restarting does not help. The oracle row is durable, and 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 pick a timestamp near the clock and never consult the oracle, so an acknowledged write stays invisible until the clock arrives. The frontend read-then-write path can produce such a target today. It writes at the frontier its subscribe observed, and a selection over a materialized view with a `REFRESH` option settles until the next refresh, so 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 same ceiling `check_runaway_write_ts` already measured against, is refused before the append, and the session turns that into a statement error. This is a backstop rather than a fix: the right answer is for the caller to pick a timestamp near the clock and use the frontier only to certify what it read, which is a larger change to the OCC loop. 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 it degrades to that log line in production. Boot reports a catalog upper that is already past the bound, which is the one channel that survives a restart and was silent. Boot 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. The wall-clock bound on `write_ts` also holds in every oracle implementation and is pinned by the shared conformance test, but was stated in none of them, so the trait now carries it. Along with it: `peek_write_ts` does not advance the timestamp, `apply_write` raises both timestamps rather than only bounding future reads, and it is the door through which a timestamp the oracle did not allocate enters, which is why the bound is a property of the `EpochMilliseconds` timeline rather than of the oracle. Tests: an integration test that drives the far-future target from a materialized view with two refreshes, one a few seconds out so the view is readable at all and one far away so the write target is deterministic, and asserts the statement is refused, the oracle did not move, and the timeline still takes writes and reads afterwards.
1 parent 946b68f commit c9f5ea6

7 files changed

Lines changed: 201 additions & 19 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
@@ -248,6 +248,13 @@ fn classify_write_result(
248248
.requested_error()
249249
.unwrap_or(AdapterError::Canceled),
250250
),
251+
WriteResult::TimestampTooFarAhead {
252+
target_timestamp,
253+
limit,
254+
} => WriteOutcome::Failed(AdapterError::ReadThenWriteTimestampTooFarAhead {
255+
target_timestamp,
256+
limit,
257+
}),
251258
WriteResult::ReadOnly => WriteOutcome::Failed(AdapterError::ReadOnly),
252259
WriteResult::TargetChanged => {
253260
// 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
@@ -1721,3 +1721,79 @@ fn test_zero_row_write_does_not_wait_for_keepalive() {
17211721
interval rather than a nudged group commit (total {elapsed:?})"
17221722
);
17231723
}
1724+
1725+
/// A read-then-write whose write timestamp would run past what the write timeline
1726+
/// may be advanced to has to be refused, not committed.
1727+
///
1728+
/// The OCC path derives its write timestamp from the frontier its subscribe observed,
1729+
/// and a selection over a materialized view with a `REFRESH` option settles until the
1730+
/// next refresh, so that frontier is legitimately hours or days ahead of the clock.
1731+
/// Committing there advances the timeline's oracle with it, and the oracle is monotone
1732+
/// and durable, so every later write and strict-serializable read on the timeline blocks
1733+
/// until the clock catches up, restarts included. Under `serializable` it is worse than a
1734+
/// block: reads pick a timestamp near the clock, so the acknowledged write stays
1735+
/// invisible.
1736+
///
1737+
/// The MV here refreshes once a few seconds out and once far away. Past the near
1738+
/// refresh it is readable, and its upper is then the far one, which is what makes the
1739+
/// write target far future deterministically rather than by racing a refresh interval.
1740+
#[mz_ore::test]
1741+
#[allow(clippy::disallowed_methods)]
1742+
fn test_far_future_write_timestamp_is_refused() {
1743+
let server = frontend_occ_harness()
1744+
.unsafe_mode()
1745+
.with_system_parameter_default("enable_refresh_every_mvs".to_string(), "true".to_string())
1746+
.start_blocking();
1747+
let mut client = server.connect(postgres::NoTls).unwrap();
1748+
1749+
client.batch_execute("CREATE TABLE src (a INT)").unwrap();
1750+
client
1751+
.batch_execute("INSERT INTO src VALUES (1), (2), (3)")
1752+
.unwrap();
1753+
client.batch_execute("CREATE TABLE dst (a INT)").unwrap();
1754+
client
1755+
.batch_execute(
1756+
"CREATE MATERIALIZED VIEW mv \
1757+
WITH (REFRESH AT mz_now()::text::int8 + 3000, REFRESH AT '3000-01-01') \
1758+
AS SELECT a FROM src",
1759+
)
1760+
.unwrap();
1761+
1762+
// Reaching the write at all means waiting for the near refresh: until then the MV
1763+
// holds no readable content and the read parks instead.
1764+
client
1765+
.batch_execute("SET statement_timeout = '60s'")
1766+
.unwrap();
1767+
1768+
let err = client
1769+
.execute("INSERT INTO dst SELECT a FROM mv", &[])
1770+
.expect_err("a write at a far-future timestamp must be refused");
1771+
let message = server_error_message(&err);
1772+
assert!(
1773+
message.contains("past the highest timestamp the write timeline may be advanced to"),
1774+
"unexpected error for a far-future write: {message}"
1775+
);
1776+
1777+
// The refusal has to happen before the append, so the oracle never learns the
1778+
// far-future timestamp. Checked before anything reads `dst`, because a read cannot be
1779+
// served once the oracle is out there.
1780+
let skew: i64 = client
1781+
.query_one(
1782+
"SELECT mz_now()::text::bigint - (extract(epoch FROM now()) * 1000)::bigint",
1783+
&[],
1784+
)
1785+
.unwrap()
1786+
.get(0);
1787+
assert!(
1788+
skew.abs() < 60_000,
1789+
"the oracle is {skew}ms from wall clock, so the refused write reached it anyway"
1790+
);
1791+
1792+
// The timeline is still usable, both for writes and for reads of the target.
1793+
client.batch_execute("INSERT INTO dst VALUES (4)").unwrap();
1794+
let rows = client
1795+
.query_one("SELECT count(*) FROM dst", &[])
1796+
.unwrap()
1797+
.get::<_, i64>(0);
1798+
assert_eq!(rows, 1, "the refused write must not have landed");
1799+
}

src/timestamp-oracle/src/lib.rs

Lines changed: 27 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -41,16 +41,29 @@ pub struct WriteTimestamp<T = mz_repr::Timestamp> {
4141
///
4242
/// Specifically, all read timestamps will be greater or equal to all previously
4343
/// reported completed write timestamps, and strictly less than all subsequently
44-
/// emitted write timestamps.
44+
/// emitted write timestamps. The read timestamp never exceeds the write
45+
/// timestamp.
4546
#[async_trait]
4647
pub trait TimestampOracle<T>: std::fmt::Debug {
4748
/// Acquire a new timestamp for writing.
4849
///
4950
/// This timestamp will be strictly greater than all prior values of
5051
/// `self.read_ts()` and `self.write_ts()`.
52+
///
53+
/// An implementation built with a wall-clock [`NowFn`] must return
54+
/// `max(previous_write_ts + 1, now())`, so it runs ahead of that clock only by the
55+
/// number of allocations that landed within one of its ticks. An in-memory oracle
56+
/// with no clock is exempt, it only has to keep the monotonicity above. Callers
57+
/// depend on the bound to keep a write timeline from
58+
/// running away: the oracle is monotone and durable, so a timestamp handed out far
59+
/// ahead of the clock stalls every later write and linearized read on the timeline
60+
/// until the clock catches up, restarts included. `timestamp_oracle_impl_test` pins
61+
/// this, by asserting the returned value exactly rather than as a range.
5162
async fn write_ts(&self) -> WriteTimestamp<T>;
5263

53-
/// Peek the current write timestamp.
64+
/// Peek the current write timestamp without advancing it.
65+
///
66+
/// The value never decreases from one call to the next.
5467
async fn peek_write_ts(&self) -> T;
5568

5669
/// Acquire a new timestamp for reading.
@@ -62,9 +75,18 @@ pub trait TimestampOracle<T>: std::fmt::Debug {
6275

6376
/// Mark a write at `write_ts` completed.
6477
///
65-
/// All subsequent values of `self.read_ts()` will be greater or equal to
66-
/// `write_ts`.
67-
async fn apply_write(&self, lower_bound: T);
78+
/// Neither timestamp is lowered and both end at or above `write_ts`, so all
79+
/// subsequent values of `self.read_ts()` are greater or equal to `write_ts`. A
80+
/// timestamp already above `write_ts` stays where it is, so this is not a way to
81+
/// learn what the oracle will hand out next.
82+
///
83+
/// NOTE: This is the door through which a timestamp that `write_ts` did not allocate
84+
/// enters the oracle, so the wall-clock bound above holds only for a timeline whose
85+
/// `apply_write` arguments are themselves clock- or oracle-derived. That is the case
86+
/// for `EpochMilliseconds`. A source-driven timeline is deliberately ratcheted to its
87+
/// inputs' frontiers instead, and is built with a clock pinned to the minimum
88+
/// timestamp.
89+
async fn apply_write(&self, write_ts: T);
6890
}
6991

7092
/// A [`NowFn`] that is generic over the timestamp.

0 commit comments

Comments
 (0)