Skip to content

Commit 0a4cb9c

Browse files
committed
adapter: linearize a read-then-write that matched no rows
The OCC path linearizes its `as_of` before subscribing, but the subscribe then follows Persist, and Persist runs ahead of the timestamp oracle. Group commit appends to the txns shard first, which makes the write readable and advances the table's upper, and calls `oracle.apply_write` only after. A read-then-write whose selection consolidates to empty inside that window concluded from state no oracle-timestamped read could reach yet, and returned immediately because it had nothing to write. A strict-serializable read issued after that response then still saw the rows the response said were not there. Real time orders the read last and no serial order explains the history. Only the zero-row exits are exposed. A write is linearized for free, because group commit answers the writer after applying the timestamp, and the coordinator's path takes its read timestamp from the oracle and so cannot observe state the oracle has not reached. `OccOutcome` now separates the two cases rather than encoding "nothing to write" as a `Committed` with no timestamp. `NoRowsMatched` carries the timestamp emptiness was concluded at, and the caller waits for the oracle to reach it before responding. The timestamp is absent only for a selection that reads no persisted state, which has nothing to linearize against. Waiting is what the existing `ensure_read_linearized` does, and it is preferable to applying the write timestamp ourselves: forcing the oracle forward off another writer's timestamp would stall subsequent reads of unrelated collections until they caught up. The `group_commit_before_apply_write` failpoint holds the window open, and is the same one a second `environmentd` opens on its own with no ordering against local Persist visibility. Two mzcompose tests come with this. `workflow_test_occ_zero_row_write_linearization` is the regression test. It parks the winning DELETE inside the window, confirms from a serializable read that the delete is visible in Persist and from a strict-serializable read that the oracle cannot serve it yet, and only then runs the UPDATE that has to report zero rows. Attempts where the subscribe reported progress before the append, told apart by the write conflict count, prove nothing and are retried. `workflow_mixed_mode_read_then_write` is a guard rather than a regression test. The dyncfg is sampled once per process, so a rolling restart can leave one instance sequencing on the coordinator behind in-process write locks and another under OCC. Those locks never excluded a second process, so this is not new, but what keeps the two from corrupting a row is the catalog fence, and nothing states that. The test asserts the fence keeps the commit windows disjoint, so it goes red if that stops holding.
1 parent 358e26f commit 0a4cb9c

5 files changed

Lines changed: 503 additions & 19 deletions

File tree

ci/nightly/pipeline.template.yml

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2395,6 +2395,17 @@ steps:
23952395
agents:
23962396
queue: hetzner-aarch64-4cpu-8gb
23972397

2398+
- id: occ-mixed-mode-read-then-write
2399+
label: "Read-then-write sequencing split across two environmentd processes"
2400+
depends_on: build-aarch64
2401+
timeout_in_minutes: 30
2402+
plugins:
2403+
- ./ci/plugins/mzcompose:
2404+
composition: txn-wal-fencing
2405+
run: mixed-mode-read-then-write
2406+
agents:
2407+
queue: hetzner-aarch64-4cpu-8gb
2408+
23982409
- group: "Copy"
23992410
key: copy
24002411
steps:

src/adapter/src/coord/appends.rs

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -589,6 +589,16 @@ impl GroupCommitter {
589589
let now: Timestamp = (self.now)().into();
590590
crate::coord::timeline::check_runaway_write_ts(&now, write_ts.timestamp);
591591

592+
// The append above is already readable in Persist and has advanced the
593+
// table's upper, while no oracle-timestamped read can reach it until
594+
// the line below. Anything concluding from a read that follows Persist
595+
// rather than the oracle has to cope with this window, so a test can
596+
// hold it open here. Every txns-shard write parks here while armed,
597+
// including the keepalives that advance table uppers, so arm it with a
598+
// bounded `sleep` rather than a `pause`. Used by
599+
// workflow_test_occ_zero_row_write_linearization.
600+
fail::fail_point!("group_commit_before_apply_write");
601+
592602
self.oracle.apply_write(write_ts.timestamp).await;
593603

594604
TxnsWriteAttempt::Applied

src/adapter/src/frontend_read_then_write.rs

Lines changed: 54 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -171,10 +171,22 @@ impl FrontendWriteAttemptState {
171171

172172
/// What the OCC loop produced.
173173
enum OccOutcome {
174-
/// The write is durable at `write_ts`, or there was nothing to write.
174+
/// The write is durable at `write_ts`.
175175
Committed {
176176
response: ExecuteResponse,
177-
write_ts: Option<Timestamp>,
177+
write_ts: Timestamp,
178+
},
179+
/// The selection was empty, so there was nothing to write.
180+
///
181+
/// `observed_ts` is the timestamp emptiness was concluded at, and is
182+
/// `None` only when the selection reads no persisted state. When it is
183+
/// `Some`, the caller must linearize against it before responding: the
184+
/// subscribe follows Persist, which runs ahead of the oracle, so the
185+
/// emptiness can be concluded from state no oracle-timestamped read can
186+
/// reach yet.
187+
NoRowsMatched {
188+
response: ExecuteResponse,
189+
observed_ts: Option<Timestamp>,
178190
},
179191
/// Diffs from a selection that reads no persisted state. The subscribe ran
180192
/// to completion, so they are frontier-independent and the caller chooses
@@ -505,11 +517,27 @@ impl PeekClient {
505517
// waiting for our write to commit.
506518
let response = match result {
507519
Ok(OccOutcome::Committed { response, write_ts }) => {
508-
if let Some(write_ts) = write_ts {
509-
session.apply_write(write_ts);
510-
}
520+
session.apply_write(write_ts);
511521
Ok(response)
512522
}
523+
Ok(OccOutcome::NoRowsMatched {
524+
response,
525+
observed_ts,
526+
}) => {
527+
// A write would have linearized this for us, because group
528+
// commit advances the oracle before it answers. With nothing
529+
// to write we have to do it ourselves, or we report an empty
530+
// selection from state a later strict-serializable read cannot
531+
// see yet, and that read finds the rows we said were not
532+
// there.
533+
match observed_ts {
534+
Some(observed_ts) => self
535+
.ensure_read_linearized(&timeline, observed_ts)
536+
.await
537+
.map(|()| response),
538+
None => Ok(response),
539+
}
540+
}
513541
Ok(OccOutcome::Blind { response, diffs }) => {
514542
match self
515543
.submit_blind_write(
@@ -840,8 +868,10 @@ impl PeekClient {
840868
/// are frontier-independent. Those are returned as [`OccOutcome::Blind`]
841869
/// for the caller to submit or buffer, and this never writes them.
842870
///
843-
/// Read linearization is the caller's responsibility: `as_of` must
844-
/// already be linearized (oracle read_ts >= `as_of`) on entry. See
871+
/// Read linearization is the caller's responsibility, on both ends.
872+
/// `as_of` must already be linearized (oracle read_ts >= `as_of`) on
873+
/// entry, and an [`OccOutcome::NoRowsMatched`] carrying an `observed_ts`
874+
/// must be linearized against it before the response goes out. See
845875
/// `ensure_read_linearized` at the call site.
846876
///
847877
/// Returns `(retry_count, result)` so the caller can record OCC retry
@@ -893,9 +923,9 @@ impl PeekClient {
893923
// flatten to `Timestamp::MIN` for `consolidate_updates`.
894924
state.consolidate(Timestamp::MIN);
895925
if state.all_diffs.is_empty() {
896-
break Ok(OccOutcome::Committed {
926+
break Ok(OccOutcome::NoRowsMatched {
897927
response: build_no_rows_response(&kind),
898-
write_ts: None,
928+
observed_ts: None,
899929
});
900930
}
901931
let success_response = match self.build_success_response(
@@ -940,10 +970,10 @@ impl PeekClient {
940970
&table_desc,
941971
) {
942972
ProcessResult::Continue { .. } => {}
943-
ProcessResult::NoRowsMatched => {
944-
break Some(Ok(OccOutcome::Committed {
973+
ProcessResult::NoRowsMatched { observed_ts } => {
974+
break Some(Ok(OccOutcome::NoRowsMatched {
945975
response: build_no_rows_response(&kind),
946-
write_ts: None,
976+
observed_ts: Some(observed_ts),
947977
}));
948978
}
949979
ProcessResult::Error(e) => {
@@ -1036,7 +1066,7 @@ impl PeekClient {
10361066
// fires off the cleanup message.
10371067
break Ok(OccOutcome::Committed {
10381068
response: success_response,
1039-
write_ts: Some(timestamp),
1069+
write_ts: timestamp,
10401070
});
10411071
}
10421072
WriteOutcome::Failed(err) => break Err(err),
@@ -1085,10 +1115,10 @@ impl PeekClient {
10851115
}
10861116
}
10871117
}
1088-
ProcessResult::NoRowsMatched => {
1089-
break Ok(OccOutcome::Committed {
1118+
ProcessResult::NoRowsMatched { observed_ts } => {
1119+
break Ok(OccOutcome::NoRowsMatched {
10901120
response: build_no_rows_response(&kind),
1091-
write_ts: None,
1121+
observed_ts: Some(observed_ts),
10921122
});
10931123
}
10941124
ProcessResult::Error(e) => {
@@ -1314,8 +1344,13 @@ impl OccState {
13141344

13151345
/// Result of processing a single subscribe message in the OCC loop.
13161346
enum ProcessResult {
1317-
Continue { ready_to_write: bool },
1318-
NoRowsMatched,
1347+
Continue {
1348+
ready_to_write: bool,
1349+
},
1350+
/// The consolidated selection is empty as of `observed_ts`.
1351+
NoRowsMatched {
1352+
observed_ts: Timestamp,
1353+
},
13191354
Error(AdapterError),
13201355
}
13211356

@@ -1398,7 +1433,7 @@ fn process_message(
13981433
// `src/adapter/src/active_compute_sink.rs` for
13991434
// the emission order.
14001435
if ts > as_of && state.all_diffs.is_empty() {
1401-
return ProcessResult::NoRowsMatched;
1436+
return ProcessResult::NoRowsMatched { observed_ts: ts };
14021437
}
14031438
} else {
14041439
let Some(diff_datum) = datums.next() else {

test/cluster/mzcompose.py

Lines changed: 155 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4638,6 +4638,161 @@ def subscriber() -> None:
46384638
), "statement execution was ended twice; end-of-execution ownership handoff regressed"
46394639

46404640

4641+
def workflow_test_occ_zero_row_write_linearization(c: Composition) -> None:
4642+
"""A read-then-write that reports zero rows must not retire before the write
4643+
that emptied its selection is readable through the timestamp oracle.
4644+
4645+
The OCC path linearizes only its initial `as_of`, and its internal subscribe
4646+
follows Persist visibility, which runs ahead of the oracle: the group
4647+
committer appends before it applies the write timestamp. A DELETE or UPDATE
4648+
can therefore consolidate its selection to empty against state no
4649+
oracle-timestamped read can reach yet, report zero rows through
4650+
`NoRowsMatched`, and return. A strict-serializable read issued after that
4651+
response then still sees the row the response said was not there, and no
4652+
serial order explains that history.
4653+
4654+
The `group_commit_before_apply_write` failpoint holds the winning writer
4655+
inside that window, the same one a second `environmentd` process opens on
4656+
its own with no ordering against local Persist visibility.
4657+
"""
4658+
4659+
# Every txns-shard write parks here while armed, including the keepalives
4660+
# that advance table uppers, so this has to be a bounded `sleep` and not a
4661+
# `pause`: a keepalive would take the `pause` first and the winning DELETE
4662+
# would never get to append. The window only has to outlast a peek and one
4663+
# subscribe dataflow installation.
4664+
failpoint = "group_commit_before_apply_write"
4665+
arm = f"SET failpoints = '{failpoint}=sleep(10000)'"
4666+
disarm = f"SET failpoints = '{failpoint}=off'"
4667+
4668+
def occ_writes() -> tuple[int, int]:
4669+
"""Read-then-writes the OCC path sequenced, and how many of their write
4670+
attempts lost the race for their write timestamp."""
4671+
metric = "mz_occ_read_then_write_retry_count"
4672+
metrics = c.exec(
4673+
"materialized", "curl", "localhost:6878/metrics", capture=True
4674+
).stdout
4675+
values = {
4676+
line.split()[0]: int(float(line.split()[1]))
4677+
for line in metrics.splitlines()
4678+
if line.startswith((f"{metric}_count ", f"{metric}_sum "))
4679+
}
4680+
return values[f"{metric}_count"], values[f"{metric}_sum"]
4681+
4682+
def count(cur: Cursor, key: int) -> int:
4683+
cur.execute(f"SELECT count(*) FROM t WHERE k = {key}".encode())
4684+
row = cur.fetchone()
4685+
assert row is not None
4686+
return int(row[0])
4687+
4688+
with c.override(
4689+
Materialized(
4690+
# Sampled once at startup, so this cannot be an `ALTER SYSTEM SET`.
4691+
additional_system_parameter_defaults={
4692+
"enable_adapter_frontend_occ_read_then_write": "true"
4693+
},
4694+
)
4695+
):
4696+
c.up("materialized")
4697+
c.sql("CREATE TABLE t (k int, v int)")
4698+
4699+
# Ask the process rather than the catalog which path it takes: the UPDATE
4700+
# only reaches the histogram if the frontend sequenced it.
4701+
sequenced = occ_writes()[0]
4702+
c.sql("UPDATE t SET v = v + 1 WHERE k = 0")
4703+
assert occ_writes()[0] > sequenced, (
4704+
"the UPDATE did not go through the OCC path, so this would exercise the "
4705+
"coordinator's lock-based path instead"
4706+
)
4707+
4708+
# Connections are opened before the failpoint is armed: starting a session
4709+
# appends to `mz_sessions`, which parks like any other write.
4710+
with (
4711+
c.sql_cursor() as control,
4712+
c.sql_cursor() as probe,
4713+
c.sql_cursor() as winner_cur,
4714+
c.sql_cursor() as session,
4715+
):
4716+
# A serializable read may pick a timestamp past the oracle's read
4717+
# timestamp, so it sees the winner's append while a strict-serializable
4718+
# read cannot.
4719+
probe.execute("SET transaction_isolation = 'serializable'")
4720+
4721+
# The UPDATE's subscribe can instead report progress at the table's
4722+
# pre-append upper, with the row still there, then submit a write,
4723+
# queue behind the parked committer, and conclude zero rows only once
4724+
# the oracle has caught up. That proves nothing either way, so such an
4725+
# attempt is retried; the write conflict count tells the two apart.
4726+
for attempt in range(1, 4):
4727+
key = attempt
4728+
c.sql(f"INSERT INTO t VALUES ({key}, 1)")
4729+
armed = Event()
4730+
4731+
def delete_winner(key: int = key) -> None:
4732+
armed.wait()
4733+
# Lands its append and advances t's upper, then the committer
4734+
# parks before applying that timestamp to the oracle.
4735+
winner_cur.execute(f"DELETE FROM t WHERE k = {key}".encode())
4736+
4737+
winner = PropagatingThread(target=delete_winner, name="winner")
4738+
winner.start()
4739+
control.execute(arm)
4740+
armed.set()
4741+
4742+
# The winner's append is visible in Persist from here on ...
4743+
deadline = time.time() + 120
4744+
while count(probe, key) > 0:
4745+
assert (
4746+
time.time() < deadline
4747+
), "the winning DELETE never became visible in Persist"
4748+
time.sleep(0.1)
4749+
# ... and the oracle cannot serve reads at it yet, which is what
4750+
# puts us inside the window. This witness says nothing about the
4751+
# UPDATE, so it stays valid once the zero-row path waits.
4752+
before = count(session, key)
4753+
4754+
conflicts = occ_writes()[1]
4755+
started = time.time()
4756+
session.execute(f"UPDATE t SET v = v + 1 WHERE k = {key}".encode())
4757+
matched = session.rowcount
4758+
elapsed = time.time() - started
4759+
after = count(session, key)
4760+
conflicts = occ_writes()[1] - conflicts
4761+
4762+
control.execute(disarm)
4763+
# `off` does not interrupt a `sleep` under way, so this waits out
4764+
# the rest of the window.
4765+
winner.join(timeout=120)
4766+
assert not winner.is_alive(), "the winning DELETE never finished"
4767+
4768+
print(
4769+
f"attempt {attempt}: UPDATE matched {matched} row(s) in "
4770+
f"{elapsed:.1f}s with {conflicts} write conflict(s); "
4771+
f"strict-serializable reads saw {before} row(s) before it and "
4772+
f"{after} row(s) after"
4773+
)
4774+
assert matched == 0, (
4775+
f"the UPDATE matched {matched} row(s) with the winner's delete "
4776+
"already visible, so it never took the zero-row path"
4777+
)
4778+
if before == 0 or conflicts > 0:
4779+
continue
4780+
4781+
assert after == 0, (
4782+
"the UPDATE reported zero rows matched from state the oracle had "
4783+
f"not applied yet, and a strict-serializable read after it saw "
4784+
f"{after} row(s): the zero-row response was not linearized against "
4785+
"the write that emptied the selection"
4786+
)
4787+
break
4788+
else:
4789+
raise AssertionError(
4790+
"no attempt got the UPDATE to report zero rows from the newer "
4791+
"state without first submitting a write, so the window was never "
4792+
"observed"
4793+
)
4794+
4795+
46414796
def workflow_test_refresh_mv_warmup(
46424797
c: Composition, parser: WorkflowArgumentParser
46434798
) -> None:

0 commit comments

Comments
 (0)