mz_storage/source/postgres/replication.rs
1// Copyright Materialize, Inc. and contributors. All rights reserved.
2//
3// Use of this software is governed by the Business Source License
4// included in the LICENSE file.
5//
6// As of the Change Date specified in that file, in accordance with
7// the Business Source License, use of this software will be governed
8// by the Apache License, Version 2.0.
9
10//! Renders the logical replication side of the [`PostgresSourceConnection`] ingestion dataflow.
11//!
12//! ```text
13//! o
14//! │rewind
15//! │requests
16//! ╭───┴────╮
17//! │exchange│ (collect all requests to one worker)
18//! ╰───┬────╯
19//! ┏━━v━━━━━━━━━━┓
20//! ┃ replication ┃ (single worker)
21//! ┃ reader ┃
22//! ┗━┯━━━━━━━━┯━━┛
23//! │raw │
24//! │data │
25//! ╭────┴─────╮ │
26//! │distribute│ │ (distribute to all workers)
27//! ╰────┬─────╯ │
28//! ┏━━━━━━━━━━━┷━┓ │
29//! ┃ replication ┃ │ (parallel decode)
30//! ┃ decoder ┃ │
31//! ┗━━━━━┯━━━━━━━┛ │
32//! │ replication │ progress
33//! │ updates │ output
34//! v v
35//! ```
36//!
37//! # Progress tracking
38//!
39//! In order to avoid causing excessive resource usage in the upstream server it's important to
40//! track the LSN that we have successfully committed to persist and communicate that back to
41//! PostgreSQL. Under normal operation this gauge of progress is provided by the presence of
42//! transactions themselves. Since at a given LSN offset there can be only a single message, when a
43//! transaction is received and processed we can infer that we have seen all the messages that are
44//! not beyond `commit_lsn + 1`.
45//!
46//! Things are a bit more complicated in the absence of transactions though because even though we
47//! don't receive any the server might very well be generating WAL records. This can happen if
48//! there is a separate logical database performing writes (which is the case for RDS databases),
49//! or, in servers running PostgreSQL version 15 or greater, the logical replication process
50//! includes an optimization that omits empty transactions, which can happen if you're only
51//! replicating a subset of the tables and there writes going to the other ones.
52//!
53//! If we fail to detect this situation and don't send LSN feedback in a timely manner the server
54//! will be forced to keep around WAL data that can eventually lead to disk space exhaustion.
55//!
56//! In the absence of transactions the only available piece of information in the replication
57//! stream are keepalive messages. Keepalive messages are documented[1] to contain the current end
58//! of WAL on the server. That is a useless number when it comes to progress tracking because there
59//! might be pending messages at LSNs between the last received commit_lsn and the current end of
60//! WAL.
61//!
62//! Fortunately for us, the documentation for PrimaryKeepalive messages is wrong and it actually
63//! contains the last *sent* LSN[2]. Here sent doesn't necessarily mean sent over the wire, but
64//! sent to the upstream process that is handling producing the logical stream. Therefore, if we
65//! receive a keepalive with a particular LSN we can be certain that there are no other replication
66//! messages at previous LSNs, because they would have been already generated and received. We
67//! therefore connect the keepalive messages directly to our capability.
68//!
69//! [1]: https://www.postgresql.org/docs/15/protocol-replication.html#PROTOCOL-REPLICATION-START-REPLICATION
70//! [2]: https://www.postgresql.org/message-id/CAFPTHDZS9O9WG02EfayBd6oONzK%2BqfUxS6AbVLJ7W%2BKECza2gg%40mail.gmail.com
71
72use std::cell::Cell;
73use std::collections::{BTreeMap, BTreeSet};
74use std::convert::Infallible;
75use std::pin::pin;
76use std::rc::Rc;
77use std::str::FromStr;
78use std::sync::Arc;
79use std::sync::LazyLock;
80use std::time::{Duration, SystemTime, UNIX_EPOCH};
81
82use differential_dataflow::AsCollection;
83use futures::{FutureExt, Stream as AsyncStream, StreamExt, TryStreamExt};
84use mz_dyncfg::ConfigSet;
85use mz_ore::cast::CastFrom;
86use mz_ore::future::InTask;
87use mz_postgres_util::PostgresError;
88use mz_postgres_util::{Client, Sql, execute, query_opt, simple_query_opt, sql};
89use mz_repr::{Datum, DatumVec, Diff, GlobalId, Row};
90use mz_storage_types::dyncfgs::PG_SCHEMA_VALIDATION_INTERVAL;
91use mz_storage_types::dyncfgs::PG_SOURCE_VALIDATE_TIMELINE;
92use mz_storage_types::dyncfgs::STORAGE_PERSIST_SINK_DESCRIPTION_LOOKAHEAD;
93use mz_storage_types::errors::DataflowError;
94use mz_storage_types::sources::SourceTimestamp;
95use mz_storage_types::sources::{MzOffset, PostgresSourceConnection};
96use mz_timely_util::builder_async::{
97 AsyncOutputHandle, Event as AsyncEvent, OperatorBuilder as AsyncOperatorBuilder,
98 PressOnDropButton,
99};
100use postgres_replication::LogicalReplicationStream;
101use postgres_replication::protocol::{LogicalReplicationMessage, ReplicationMessage, TupleData};
102use serde::{Deserialize, Serialize};
103use timely::container::CapacityContainerBuilder;
104use timely::dataflow::channels::pact::{Exchange, Pipeline};
105use timely::dataflow::operators::Concat;
106use timely::dataflow::operators::Operator;
107use timely::dataflow::operators::core::Map;
108use timely::dataflow::operators::{Capability, CapabilitySet};
109use timely::dataflow::{Scope, StreamVec};
110use timely::progress::Antichain;
111use tokio::sync::{mpsc, watch};
112use tokio::time::Instant;
113use tokio_postgres::error::SqlState;
114use tokio_postgres::types::PgLsn;
115use tracing::{error, trace};
116
117use crate::metrics::source::postgres::PgSourceMetrics;
118use crate::source::RawSourceCreationConfig;
119use crate::source::postgres::verify_schema;
120use crate::source::postgres::{DefiniteError, ReplicationError, SourceOutputInfo, TransientError};
121use crate::source::probe;
122use crate::source::types::{
123 Probe, ResumeUppers, SharedFuel, SignaledFuture, SourceMessage, StackedCollection,
124};
125
126/// A logical replication message from the server.
127type LogicalReplMsg = ReplicationMessage<LogicalReplicationMessage>;
128
129/// A decoded row from a transaction with source information.
130type DecodedRow = (u32, usize, Result<Row, DefiniteError>, Diff);
131
132/// An event of a transaction read from the replication stream.
133enum TransactionEvent {
134 /// A change to the export at the row's output index.
135 Update(DecodedRow),
136 /// The export receives no further events.
137 Seal(Seal),
138}
139
140/// A definite error that ends ingestion of the export at `output_index`.
141struct Seal {
142 output_index: usize,
143 resume_upper: Antichain<MzOffset>,
144 error: DefiniteError,
145}
146
147/// The data outputs of the replication reader, one per source export.
148type DataOutputs = SharedFuel<
149 MzOffset,
150 CapacityContainerBuilder<Vec<(Result<Row, DataflowError>, MzOffset, Diff)>>,
151>;
152
153/// Postgres epoch is 2000-01-01T00:00:00Z
154static PG_EPOCH: LazyLock<SystemTime> =
155 LazyLock::new(|| UNIX_EPOCH + Duration::from_secs(946_684_800));
156
157/// A request to rewind a snapshot taken at `snapshot_lsn` to the initial LSN captured at
158/// purification. This is accomplished by emitting `(data, 0, -diff)` for all updates
159/// `(data, lsn, diff)` whose `lsn <= snapshot_lsn` and that the output does not ignore (see
160/// `SourceOutputInfo::ignores`). By convention the snapshot is always emitted at LSN 0.
161/// ```text
162/// LSN 0 confirmed_flush_lsn initial_lsn snapshot_lsn
163/// │ │ │ │
164/// │ │ ignored by the │◄──────── rewound ─────────────►│
165/// │ │ export │ │
166/// │ │ │ │
167/// └──────────────── snapshot reflects all of these ─────────────────────────┘
168/// ```
169#[derive(Debug, Clone, Serialize, Deserialize)]
170pub(crate) struct RewindRequest {
171 /// The output index that should be rewound.
172 pub(crate) output_index: usize,
173 /// The LSN that the snapshot was taken at.
174 pub(crate) snapshot_lsn: MzOffset,
175}
176
177/// What the snapshot operator reports to the replication reader for each export it snapshots.
178#[derive(Debug, Clone, Serialize, Deserialize)]
179pub(crate) enum SnapshotResult {
180 /// The export can begin processing rewinds for the given export. This gets emitted at
181 /// different points, depending on which mode the source is in: non-concurrent or concurrent
182 /// (`STORAGE_PERSIST_SINK_DESCRIPTION_LOOKAHEAD` > 0).
183 ///
184 /// - In non-concurrent mode, the snapshot operator establishes a snapshot, verifies the table
185 /// schema for the export, and snapshots the upstream table before emitting the rewind requests.
186 ///
187 /// - In concurrent mode, the snapshot operator establishes a snapshot and verifies the table
188 /// schema for the export before emitting the rewind.
189 ///
190 /// The emission point is chosen in [`super::snapshot::render`].
191 Rewind(RewindRequest),
192 /// If the upstream table schema didn't match the export schema before the snapshot copy
193 /// started, the snapshot operator emits a `Seal` and skips the snapshot. The replication
194 /// operator emits the error at the minimum timestamp.
195 Seal {
196 output_index: usize,
197 error: DefiniteError,
198 },
199}
200
201/// Renders the replication dataflow. See the module documentation for more information.
202pub(crate) fn render<'scope>(
203 scope: Scope<'scope, MzOffset>,
204 config: RawSourceCreationConfig,
205 connection: PostgresSourceConnection,
206 table_info: BTreeMap<u32, BTreeMap<usize, SourceOutputInfo>>,
207 rewind_stream: StreamVec<'scope, MzOffset, SnapshotResult>,
208 slot_ready_stream: StreamVec<'scope, MzOffset, Infallible>,
209 committed_uppers: impl futures::Stream<Item = ResumeUppers<MzOffset>> + 'static,
210 metrics: PgSourceMetrics,
211) -> (
212 Vec<StackedCollection<'scope, MzOffset, Result<SourceMessage, DataflowError>>>,
213 StreamVec<'scope, MzOffset, Probe<MzOffset>>,
214 StreamVec<'scope, MzOffset, ReplicationError>,
215 PressOnDropButton,
216) {
217 let op_name = format!("ReplicationReader({})", config.id);
218 let mut builder = AsyncOperatorBuilder::new(op_name, scope.clone());
219
220 // Read at render time, matching the value the persist sink reads in the same dataflow build.
221 // A read in the async body can observe an `UpdateConfiguration` sequenced after this dataflow's
222 // creation and disagree with the sink because the `ConfigSet` is updated in place.
223 // A nonzero lookahead is the switch, see `STORAGE_PERSIST_SINK_DESCRIPTION_LOOKAHEAD`.
224 let concurrent_replication = !STORAGE_PERSIST_SINK_DESCRIPTION_LOOKAHEAD
225 .get(config.config.config_set())
226 .is_zero();
227
228 let slot_reader = u64::cast_from(config.responsible_worker("slot"));
229 // One data output port per source export, in output index order. With concurrent
230 // replication enabled a port holds the minimum capability only while its export has a
231 // pending rewind and advances with the stream otherwise. When disabled all ports are
232 // managed in lockstep and hold the minimum until every rewind resolves, so every export
233 // observes the same frontier.
234 let export_count = config.source_exports.len();
235 let mut data_outputs = Vec::with_capacity(export_count);
236 let mut data_streams = Vec::with_capacity(export_count);
237 for _ in 0..export_count {
238 let (output, stream) = builder.new_output::<CapacityContainerBuilder<Vec<_>>>();
239 data_outputs.push(output);
240 data_streams.push(stream);
241 }
242 let (definite_error_handle, definite_errors) =
243 builder.new_output::<CapacityContainerBuilder<_>>();
244 let (probe_output, probe_stream) = builder.new_output::<CapacityContainerBuilder<_>>();
245
246 let mut rewind_input =
247 builder.new_disconnected_input(rewind_stream, Exchange::new(move |_| slot_reader));
248 let mut slot_ready_input = builder.new_disconnected_input(slot_ready_stream, Pipeline);
249 let output_uppers = table_info
250 .iter()
251 .flat_map(|(_, outputs)| outputs.values().map(|o| o.resume_upper.clone()))
252 .collect::<Vec<_>>();
253 metrics.tables.set(u64::cast_from(output_uppers.len()));
254 // Same values as output_uppers above (output_uppers is derived from source_resume_uppers), but it contains an additional
255 // entry for the top-level source when legacy syntax is used.
256 let resume_lsns: BTreeMap<GlobalId, MzOffset> = config
257 .source_resume_uppers
258 .iter()
259 .filter_map(|(id, upper)| {
260 let upper = Antichain::from_iter(upper.iter().map(MzOffset::decode_row));
261 Some((*id, upper.into_option()?))
262 })
263 .collect();
264
265 let reader_table_info = table_info.clone();
266 let (button, transient_errors) = builder.build_fallible(move |caps| {
267 let mut table_info = reader_table_info;
268 let busy_signal = Arc::clone(&config.busy_signal);
269 Box::pin(SignaledFuture::new(busy_signal, async move {
270 let (id, worker_id) = (config.id, config.worker_id);
271 let (data_cap_sets, caps) = caps.split_at_mut(export_count);
272 let [definite_error_cap_set, probe_cap]: &mut [_; 2] = caps.try_into().unwrap();
273 let mut data_outputs = SharedFuel::new(data_outputs);
274
275 if !config.responsible_for("slot") {
276 // Emit 0, to mark this worker as having started up correctly.
277 for stat in config.statistics.values() {
278 stat.set_offset_known(0);
279 stat.set_offset_committed(0);
280 }
281 return Ok(());
282 }
283
284 // Determine the slot lsn.
285 let connection_config = connection
286 .connection
287 .config(
288 &config.config.connection_context.secrets_reader,
289 &config.config,
290 InTask::Yes,
291 )
292 .await?;
293
294 let slot = &connection.publication_details.slot;
295 let replication_client = connection_config
296 .connect_replication(&config.config.connection_context.ssh_tunnel_manager)
297 .await?;
298
299 let metadata_client = connection_config
300 .connect(
301 "replication metadata",
302 &config.config.connection_context.ssh_tunnel_manager,
303 )
304 .await?;
305 let metadata_client = Arc::new(metadata_client);
306
307 while let Some(_) = slot_ready_input.next().await {
308 // Wait for the slot to be created
309 }
310
311 // The slot is always created by the snapshot operator. If the slot doesn't exist,
312 // when this check runs, this operator will return an error.
313 let slot_metadata = super::fetch_slot_metadata(
314 &*metadata_client,
315 slot,
316 mz_storage_types::dyncfgs::PG_FETCH_SLOT_RESUME_LSN_INTERVAL
317 .get(config.config.config_set()),
318 )
319 .await?;
320
321 // We're the only application that should be using this replication
322 // slot. The only way that there can be another connection using
323 // this slot under normal operation is if there's a stale TCP
324 // connection from a prior incarnation of the source holding on to
325 // the slot. We don't want to wait for the WAL sender timeout and/or
326 // TCP keepalives to time out that connection, because these values
327 // are generally under the control of the DBA and may not time out
328 // the connection for multiple minutes, or at all. Instead we just
329 // force kill the connection that's using the slot.
330 //
331 // Note that there's a small risk that *we're* the zombie cluster
332 // that should not be using the replication slot. Kubernetes cannot
333 // 100% guarantee that only one cluster is alive at a time. However,
334 // this situation should not last long, and the worst that can
335 // happen is a bit of transient thrashing over ownership of the
336 // replication slot.
337 if let Some(active_pid) = slot_metadata.active_pid {
338 tracing::warn!(
339 %id, %active_pid,
340 "replication slot already in use; will attempt to kill existing connection",
341 );
342
343 match execute(
344 &**metadata_client,
345 sql!("SELECT pg_terminate_backend($1)"),
346 &[&active_pid],
347 )
348 .await
349 {
350 Ok(_) => {
351 tracing::info!(
352 "successfully killed existing connection; \
353 starting replication is likely to succeed"
354 );
355 // Note that `pg_terminate_backend` does not wait for
356 // the termination of the targeted connection to
357 // complete. We may try to start replication before the
358 // targeted connection has cleaned up its state. That's
359 // okay. If that happens we'll just try again from the
360 // top via the suspend-and-restart flow.
361 }
362 Err(e) => {
363 tracing::warn!(
364 %e,
365 "failed to kill existing replication connection; \
366 replication will likely fail to start"
367 );
368 // Continue on anyway, just in case the replication slot
369 // is actually available. Maybe PostgreSQL has some
370 // staleness when it reports `active_pid`, for example.
371 }
372 }
373 }
374
375 // The overall resumption point for this source is the minimum of the resumption points
376 // contributed by each of the outputs.
377 let resume_lsn = output_uppers
378 .iter()
379 .flat_map(|f| f.elements())
380 .map(|&lsn| {
381 // An output is either an output that has never had data committed to it or one
382 // that has and needs to resume. We differentiate between the two by checking
383 // whether an output wishes to "resume" from the minimum timestamp. In that case
384 // its contribution to the overal resumption point is the earliest point available
385 // in the slot. This information would normally be something that the storage
386 // controller figures out in the form of an as-of frontier, but at the moment the
387 // storage controller does not have visibility into what the replication slot is
388 // doing.
389 if lsn == MzOffset::from(0) {
390 slot_metadata.confirmed_flush_lsn
391 } else {
392 lsn
393 }
394 })
395 .min();
396 let Some(resume_lsn) = resume_lsn else {
397 std::future::pending::<()>().await;
398 return Ok(());
399 };
400 // If we don't set "offset_committed" now, it'll be stuck at 0 (the default value)
401 // until we finish processing the table snapshot. If the snapshot is large, that could be a long time.
402 // This confuses the ingestion lag calculation in the UI, causing it to yield erroneously high values.
403 for (id, stat) in config.statistics.iter() {
404 let lsn = resume_lsns
405 .get(id)
406 .map_or(resume_lsn, |lsn| (*lsn).max(resume_lsn));
407 stat.set_offset_committed(lsn.offset);
408 }
409 tracing::info!(
410 %id,
411 "timely-{worker_id} replication reader started lsn={resume_lsn}, \
412 waiting for snapshot to complete"
413 );
414
415 // Emitting an initial probe before we start waiting for rewinds ensures that we will
416 // have a timestamp binding in the remap collection while the snapshot is processed.
417 // This is important because otherwise the snapshot updates would need to be buffered
418 // in the reclock operator, instead of being spilled to S3 in the persist sink.
419 //
420 // Note that we need to fetch the probe LSN _after_ having created the replication
421 // slot, to make sure the fetched LSN will be included in the replication stream.
422 let probe_ts = (config.now_fn)().into();
423 let max_lsn = mz_postgres_util::fetch_max_lsn(
424 &*metadata_client,
425 connection.publication_details.get_is_physical_replica(),
426 )
427 .await?;
428 let probe = Probe {
429 probe_ts,
430 upstream_frontier: Antichain::from_elem(MzOffset::from(max_lsn)),
431 };
432 probe_output.give(&probe_cap[0], probe);
433
434 let mut rewinds = BTreeMap::new();
435 while let Some(event) = rewind_input.next().await {
436 if let AsyncEvent::Data(_, data) = event {
437 for result in data {
438 let req = match result {
439 SnapshotResult::Rewind(req) => req,
440 SnapshotResult::Seal {
441 output_index,
442 error,
443 } => {
444 let info = table_info
445 .values_mut()
446 .find_map(|outputs| outputs.remove(&output_index))
447 .expect("snapshotted exports have table info");
448 let seal = Seal {
449 output_index,
450 resume_upper: info.resume_upper,
451 error,
452 };
453 // Nothing was copied, so the error takes the place of the
454 // snapshot at the minimum.
455 seal_export(
456 &mut data_outputs,
457 &mut data_cap_sets[output_index],
458 seal,
459 MzOffset::from(0),
460 )
461 .await;
462 continue;
463 }
464 };
465 if resume_lsn > req.snapshot_lsn + 1 {
466 let err = DefiniteError::SlotCompactedPastResumePoint(
467 req.snapshot_lsn + 1,
468 resume_lsn,
469 );
470 // If the replication stream cannot be obtained from the resume point there is nothing
471 // else to do. These errors are not retractable.
472 for outputs in table_info.values() {
473 for output_index in outputs.keys() {
474 // We pick `u64::MAX` as the LSN which will (in practice) never conflict
475 // any previously revealed portions of the TVC.
476 let update = (
477 Err(DataflowError::from(err.clone())),
478 MzOffset::from(u64::MAX),
479 Diff::ONE,
480 );
481 data_outputs
482 .give(
483 *output_index,
484 &data_cap_sets[*output_index][0],
485 update,
486 )
487 .await;
488 }
489 }
490 definite_error_handle.give(
491 &definite_error_cap_set[0],
492 ReplicationError::Definite(Rc::new(err)),
493 );
494 return Ok(());
495 }
496 rewinds.insert(req.output_index, req);
497 }
498 }
499 }
500 trace!(%id, "timely-{worker_id} pending rewinds {rewinds:?}");
501
502 let mut committed_uppers = pin!(committed_uppers);
503
504 let stream_result = raw_stream(
505 &config,
506 &connection,
507 replication_client,
508 Arc::clone(&metadata_client),
509 resume_lsn,
510 committed_uppers.as_mut(),
511 &probe_output,
512 &probe_cap[0],
513 )
514 .await?;
515
516 let stream = match stream_result {
517 Ok(stream) => stream,
518 Err(err) => {
519 // If the replication stream cannot be obtained in a definite way there is
520 // nothing else to do. These errors are not retractable.
521 for outputs in table_info.values() {
522 for output_index in outputs.keys() {
523 // We pick `u64::MAX` as the LSN which will (in practice) never conflict
524 // any previously revealed portions of the TVC.
525 let update = (
526 Err(DataflowError::from(err.clone())),
527 MzOffset::from(u64::MAX),
528 Diff::ONE,
529 );
530 data_outputs
531 .give(*output_index, &data_cap_sets[*output_index][0], update)
532 .await;
533 }
534 }
535
536 definite_error_handle.give(
537 &definite_error_cap_set[0],
538 ReplicationError::Definite(Rc::new(err)),
539 );
540 return Ok(());
541 }
542 };
543 let mut stream = pin!(stream.peekable());
544
545 // Run the periodic schema validation on a separate task using a separate client,
546 // to prevent it from blocking the replication reading progress.
547 let ssh_tunnel_manager = &config.config.connection_context.ssh_tunnel_manager;
548 let client = connection_config
549 .connect("schema validation", ssh_tunnel_manager)
550 .await?;
551 let mut schema_errors = spawn_schema_validator(
552 client,
553 &config,
554 connection.publication.clone(),
555 table_info.clone(),
556 connection.publication_details.get_is_physical_replica(),
557 );
558
559 // Instead of downgrading the capability for every transaction we process we only do it
560 // if we're about to yield, which is checked at the bottom of the loop. This avoids
561 // creating excessive progress tracking traffic when there are multiple small
562 // transactions ready to go.
563 let mut data_upper = resume_lsn;
564 while let Some(event) = stream.as_mut().next().await {
565 use LogicalReplicationMessage::*;
566 use ReplicationMessage::*;
567 match event {
568 Ok(XLogData(data)) => match data.data() {
569 Begin(begin) => {
570 let commit_lsn = MzOffset::from(begin.final_lsn());
571
572 let mut tx = pin!(extract_transaction(
573 stream.by_ref(),
574 &*metadata_client,
575 commit_lsn,
576 &mut table_info,
577 &metrics,
578 &connection.publication,
579 ));
580
581 trace!(
582 %id,
583 "timely-{worker_id} extracting transaction \
584 at {commit_lsn}"
585 );
586 assert!(
587 data_upper <= commit_lsn,
588 "new_upper={data_upper} tx_lsn={commit_lsn}",
589 );
590 data_upper = commit_lsn + 1;
591 while let Some(event) = tx.try_next().await? {
592 let (output_index, event, diff) = match event {
593 TransactionEvent::Update((_oid, output_index, event, diff)) => {
594 (output_index, event, diff)
595 }
596 TransactionEvent::Seal(seal) => {
597 // If the error occurred before the snapshot LSN, the rewind
598 // won't be able to reconstruct a correct view of the
599 // snapshot. For this case, the seal happens at the minimum
600 // FromTime rather than emitting a retraction for the error
601 // followed by emission at a later timestamp.
602 //
603 // NOTE: the snapshot continues to run. There is no channel
604 // back to that operator. This is inefficient, but doesn't
605 // affect correctness.
606 let rewound = rewinds
607 .get(&seal.output_index)
608 .is_some_and(|req| commit_lsn <= req.snapshot_lsn);
609 let time = if rewound {
610 MzOffset::from(0)
611 } else {
612 commit_lsn
613 };
614 let cap_set = &mut data_cap_sets[seal.output_index];
615 seal_export(&mut data_outputs, cap_set, seal, time).await;
616 continue;
617 }
618 };
619 let event: Result<_, DataflowError> = event.map_err(Into::into);
620 if let Some(req) = rewinds.get(&output_index) {
621 if commit_lsn <= req.snapshot_lsn {
622 let update = (event.clone(), MzOffset::from(0), -diff);
623 data_outputs
624 .give(
625 output_index,
626 &data_cap_sets[output_index][0],
627 update,
628 )
629 .await;
630 }
631 }
632 let update = (event, commit_lsn, diff);
633 data_outputs
634 .give(output_index, &data_cap_sets[output_index][0], update)
635 .await;
636 }
637 }
638 _ => return Err(TransientError::BareTransactionEvent),
639 },
640 Ok(PrimaryKeepAlive(keepalive)) => {
641 trace!( %id,
642 "timely-{worker_id} received keepalive lsn={}",
643 keepalive.wal_end()
644 );
645
646 // Take the opportunity to report any schema validation errors.
647 while let Ok(error) = schema_errors.try_recv() {
648 use SchemaValidationError::*;
649 match error {
650 Postgres(PostgresError::PublicationMissing(publication)) => {
651 let err = DefiniteError::PublicationDropped(publication);
652 for outputs in table_info.values() {
653 for output_index in outputs.keys() {
654 let update = (
655 Err(DataflowError::from(err.clone())),
656 data_cap_sets[*output_index][0].time().clone(),
657 Diff::ONE,
658 );
659 data_outputs
660 .give(
661 *output_index,
662 &data_cap_sets[*output_index][0],
663 update,
664 )
665 .await;
666 }
667 }
668 definite_error_handle.give(
669 &definite_error_cap_set[0],
670 ReplicationError::Definite(Rc::new(err)),
671 );
672 return Ok(());
673 }
674 Postgres(pg_error) => Err(TransientError::from(pg_error))?,
675 PhysicalReplicaChanged { expected, actual } => {
676 // The upstream is no longer the kind of node the
677 // source was created against (e.g. a physical
678 // replica was promoted to a primary). Logical
679 // decoding cannot safely continue, so stall with a
680 // definite, non-retryable error.
681 let err =
682 DefiniteError::InvalidPhysicalReplica { expected, actual };
683 for outputs in table_info.values() {
684 for output_index in outputs.keys() {
685 let update = (
686 Err(DataflowError::from(err.clone())),
687 // We don't have a clean way to align on when the replica changed so jump straight to u64::MAX to avoid conflicts.
688 MzOffset::from(u64::MAX),
689 Diff::ONE,
690 );
691 data_outputs
692 .give(
693 *output_index,
694 &data_cap_sets[*output_index][0],
695 update,
696 )
697 .await;
698 }
699 }
700 definite_error_handle.give(
701 &definite_error_cap_set[0],
702 ReplicationError::Definite(Rc::new(err)),
703 );
704 return Ok(());
705 }
706 Schema {
707 oid,
708 output_index,
709 error,
710 } => {
711 let table = table_info.get_mut(&oid).unwrap();
712 let Some(info) = table.remove(&output_index) else {
713 continue;
714 };
715 let seal = Seal {
716 output_index,
717 resume_upper: info.resume_upper,
718 error,
719 };
720
721 let cap_set = &mut data_cap_sets[output_index];
722 let time = *cap_set[0].time();
723 seal_export(&mut data_outputs, cap_set, seal, time).await;
724 }
725 }
726 }
727 data_upper = std::cmp::max(data_upper, keepalive.wal_end().into());
728 }
729 Ok(_) => return Err(TransientError::UnknownReplicationMessage),
730 Err(err) => return Err(err),
731 }
732
733 let will_yield = stream.as_mut().peek().now_or_never().is_none();
734 if will_yield {
735 trace!(%id, "timely-{worker_id} yielding at lsn={data_upper}");
736 rewinds.retain(|_, req| data_upper <= req.snapshot_lsn);
737 let unsealed = data_cap_sets
738 .iter_mut()
739 .enumerate()
740 .filter(|(_, cap_set)| !cap_set.is_empty());
741 // A port with a pending rewind must stay at the minimum capability since
742 // negated rewind data for its export is emitted at offset 0.
743 if concurrent_replication {
744 // Every other port advances with the stream, so exports that need no
745 // rewind make progress while a snapshot runs.
746 for (output_index, cap_set) in unsealed {
747 if !rewinds.contains_key(&output_index) {
748 cap_set.downgrade([&data_upper]);
749 }
750 }
751 } else if rewinds.is_empty() {
752 for (_, cap_set) in unsealed {
753 cap_set.downgrade([&data_upper]);
754 }
755 }
756 }
757 }
758 // We never expect the replication stream to gracefully end
759 Err(TransientError::ReplicationEOF)
760 }))
761 });
762
763 // We now process the slot updates and apply the cast expressions, with one decode operator
764 // per export.
765 let mut output_info = BTreeMap::new();
766 for outputs in table_info.into_values() {
767 for (output_index, info) in outputs {
768 output_info.insert(output_index, info);
769 }
770 }
771 let mut replication_updates = Vec::with_capacity(data_streams.len());
772 let peers = u64::cast_from(scope.peers());
773 let record = Rc::new(Cell::new(0_u64));
774 for (output_index, data_stream) in data_streams.into_iter().enumerate() {
775 let info = output_info.get(&output_index).cloned();
776 let mut final_row = Row::default();
777 let mut datum_vec = DatumVec::new();
778
779 // Round robin on 1000-records basis to avoid creating tiny containers when there are a
780 // small number of updates and a large number of workers. The counter is shared by every
781 // export's exchange so rotation follows total volume.
782 let record = Rc::clone(&record);
783 let round_robin = Exchange::new(move |_| {
784 let n = record.get();
785 record.set(n.wrapping_add(1));
786 (n / 1000) % peers
787 });
788 let updates = data_stream
789 .unary(
790 round_robin,
791 &format!("PgCastReplicationRows({output_index})"),
792 |_, _| {
793 move |input, output| {
794 input.for_each_stamp(|time, data| {
795 let mut session = output.session(&time);
796 for (event, time, diff) in data.flat_map(|data| data.drain(..)) {
797 let info = info
798 .as_ref()
799 .expect("only exports with output info receive data");
800 let event = event.and_then(|row| {
801 let datums = datum_vec.borrow_with(&row);
802 super::cast_row(&info.casts, &datums, &mut final_row)?;
803 Ok(SourceMessage {
804 key: Row::default(),
805 value: final_row.clone(),
806 metadata: Row::default(),
807 })
808 });
809 session.give((event, time, diff));
810 }
811 });
812 }
813 },
814 )
815 .as_collection();
816 replication_updates.push(updates);
817 }
818
819 let errors = definite_errors.concat(transient_errors.map(ReplicationError::from));
820
821 (
822 replication_updates,
823 probe_stream,
824 errors,
825 button.press_on_drop(),
826 )
827}
828
829/// Emits the error of `seal` at `time` as the final update of its export and drops the export's
830/// capabilities.
831///
832/// The export's upper advances to the empty frontier once the error is reclocked, which persists
833/// that its ingestion has ended. A restarted dataflow excludes exports with an empty upper. One
834/// that resumed from its last upper instead would miss every upstream change since the error.
835///
836/// `time` must be bound by remap while other exports keep running, so it cannot be a placeholder
837/// like `u64::MAX`. Reclock defers an update until remap binds its time and only then drops the
838/// export's capability.
839async fn seal_export(
840 data_outputs: &mut DataOutputs,
841 cap_set: &mut CapabilitySet<MzOffset>,
842 seal: Seal,
843 time: MzOffset,
844) {
845 let Seal {
846 output_index,
847 resume_upper,
848 error,
849 } = seal;
850 // The stream resumes at the least upper of all exports, so it replays changes this export
851 // already committed. The persist sink drops updates below the export's resume upper as
852 // written, and an error dropped there would leave the export sealed without it.
853 let time = resume_upper
854 .as_option()
855 .map_or(time, |upper| std::cmp::max(time, *upper));
856 let update = (Err(error.into()), time, Diff::ONE);
857 data_outputs.give(output_index, &cap_set[0], update).await;
858 *cap_set = CapabilitySet::new();
859}
860
861/// Produces the logical replication stream while taking care of regularly sending standby
862/// keepalive messages with the provided `uppers` stream.
863///
864/// The returned stream will contain all transactions that whose commit LSN is beyond `resume_lsn`.
865async fn raw_stream<'a>(
866 config: &'a RawSourceCreationConfig,
867 connection: &'a PostgresSourceConnection,
868 replication_client: Client,
869 metadata_client: Arc<Client>,
870 resume_lsn: MzOffset,
871 uppers: impl futures::Stream<Item = ResumeUppers<MzOffset>> + 'a,
872 probe_output: &'a AsyncOutputHandle<MzOffset, CapacityContainerBuilder<Vec<Probe<MzOffset>>>>,
873 probe_cap: &'a Capability<MzOffset>,
874) -> Result<
875 Result<impl AsyncStream<Item = Result<LogicalReplMsg, TransientError>> + 'a, DefiniteError>,
876 TransientError,
877> {
878 let slot = &connection.publication_details.slot;
879 let publication = &connection.publication;
880 let is_physical_replica = connection.publication_details.get_is_physical_replica();
881
882 if let Err(err) = ensure_replication_prerequisites(
883 &metadata_client,
884 &replication_client,
885 connection,
886 config.config.config_set(),
887 )
888 .await?
889 {
890 return Ok(Err(err));
891 }
892
893 // How often a proactive standby status update message should be sent to the server.
894 //
895 // The upstream will periodically request status updates by setting the keepalive's reply field
896 // value to 1. However, we cannot rely on these messages arriving on time. For example, when
897 // the upstream is sending a big transaction its keepalive messages are queued and can be
898 // delayed arbitrarily.
899 //
900 // See: <https://www.postgresql.org/message-id/CAMsr+YE2dSfHVr7iEv1GSPZihitWX-PMkD9QALEGcTYa+sdsgg@mail.gmail.com>
901 //
902 // For this reason we query the server's timeout value and proactively send a keepalive at
903 // twice the frequency to have a healthy margin from the deadline.
904 //
905 // Note: We must use the metadata client here which is NOT in replication mode. Some Aurora
906 // Postgres versions disallow SHOW commands from within replication connection.
907 // See: https://github.com/readysettech/readyset/discussions/28#discussioncomment-4405671
908 let row = simple_query_opt(&*metadata_client, sql!("SHOW wal_sender_timeout;"))
909 .await?
910 .unwrap();
911 let wal_sender_timeout = match row.get("wal_sender_timeout") {
912 // When this parameter is zero the timeout mechanism is disabled
913 Some("0") => None,
914 Some(value) => Some(
915 mz_repr::adt::interval::Interval::from_str(value)
916 .unwrap()
917 .duration()
918 .unwrap(),
919 ),
920 None => panic!("ubiquitous parameter missing"),
921 };
922
923 // This interval controls the cadence at which we send back status updates and, crucially,
924 // request PrimaryKeepAlive messages. PrimaryKeepAlive messages drive the frontier forward in
925 // the absence of data updates and we don't want a large `wal_sender_timeout` value to slow us
926 // down. For this reason the feedback interval is set to one second, or less if the
927 // wal_sender_timeout is less than 2 seconds.
928 let feedback_interval = match wal_sender_timeout {
929 Some(t) => std::cmp::min(Duration::from_secs(1), t.checked_div(2).unwrap()),
930 None => Duration::from_secs(1),
931 };
932
933 let mut feedback_timer = tokio::time::interval(feedback_interval);
934 // 'Delay' ensures we always tick at least 'feedback_interval'.
935 feedback_timer.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Delay);
936
937 // Postgres will return all transactions that commit *at or after* after the provided LSN,
938 // following the timely upper semantics.
939 let lsn = PgLsn::from(resume_lsn.offset);
940 let query = sql!(
941 "START_REPLICATION SLOT {} LOGICAL {} (\"proto_version\" '1', \"publication_names\" {})",
942 Sql::ident(slot),
943 Sql::raw_unchecked(lsn.to_string()),
944 Sql::literal(publication)
945 );
946 let copy_stream = match replication_client.copy_both_simple(query.as_str()).await {
947 Ok(copy_stream) => copy_stream,
948 Err(err) if err.code() == Some(&SqlState::OBJECT_NOT_IN_PREREQUISITE_STATE) => {
949 return Ok(Err(DefiniteError::InvalidReplicationSlot));
950 }
951 Err(err) => return Err(err.into()),
952 };
953
954 // According to the documentation [1] we must check that the slot LSN matches our
955 // expectations otherwise we risk getting silently fast-forwarded to a future LSN. In order
956 // to avoid a TOCTOU issue we must do this check after starting the replication stream. We
957 // cannot use the replication client to do that because it's already in CopyBoth mode.
958 // [1] https://www.postgresql.org/docs/15/protocol-replication.html#PROTOCOL-REPLICATION-START-REPLICATION-SLOT-LOGICAL
959 let slot_metadata = super::fetch_slot_metadata(
960 &*metadata_client,
961 slot,
962 mz_storage_types::dyncfgs::PG_FETCH_SLOT_RESUME_LSN_INTERVAL
963 .get(config.config.config_set()),
964 )
965 .await?;
966 let min_resume_lsn = slot_metadata.confirmed_flush_lsn;
967 tracing::info!(
968 %config.id,
969 "started replication using backend PID={:?}. wal_sender_timeout={:?}",
970 slot_metadata.active_pid, wal_sender_timeout
971 );
972
973 let (probe_tx, mut probe_rx) = watch::channel(None);
974 let timestamp_interval = config.timestamp_interval;
975 let now_fn = config.now_fn.clone();
976 let max_lsn_task_handle =
977 mz_ore::task::spawn(|| format!("pg_current_wal_lsn:{}", config.id), async move {
978 let mut probe_ticker = probe::Ticker::new(move || timestamp_interval, now_fn);
979
980 while !probe_tx.is_closed() {
981 let probe_ts = probe_ticker.tick().await;
982 let probe_or_err =
983 mz_postgres_util::fetch_max_lsn(&*metadata_client, is_physical_replica)
984 .await
985 .map(|lsn| Probe {
986 probe_ts,
987 upstream_frontier: Antichain::from_elem(MzOffset::from(lsn)),
988 });
989 let _ = probe_tx.send(Some(probe_or_err));
990 }
991 })
992 .abort_on_drop();
993
994 let stream = async_stream::try_stream!({
995 // Ensure we don't pre-drop the task
996 let _max_lsn_task_handle = max_lsn_task_handle;
997
998 // ensure we don't drop the replication client!
999 let _replication_client = replication_client;
1000
1001 let mut uppers = pin!(uppers);
1002 let mut last_committed_upper = resume_lsn;
1003
1004 let mut stream = pin!(LogicalReplicationStream::new(copy_stream));
1005
1006 if !(resume_lsn == MzOffset::from(0) || min_resume_lsn <= resume_lsn) {
1007 let err = TransientError::OvercompactedReplicationSlot {
1008 available_lsn: min_resume_lsn,
1009 requested_lsn: resume_lsn,
1010 };
1011 error!("timely-{} ({}) {err}", config.worker_id, config.id);
1012 Err(err)?;
1013 }
1014
1015 loop {
1016 tokio::select! {
1017 Some(next_message) = stream.next() => match next_message {
1018 Ok(ReplicationMessage::XLogData(data)) => {
1019 yield ReplicationMessage::XLogData(data);
1020 Ok(())
1021 }
1022 Ok(ReplicationMessage::PrimaryKeepAlive(keepalive)) => {
1023 yield ReplicationMessage::PrimaryKeepAlive(keepalive);
1024 Ok(())
1025 }
1026 Err(err) => Err(err.into()),
1027 _ => Err(TransientError::UnknownReplicationMessage),
1028 },
1029 _ = feedback_timer.tick() => {
1030 let ts: i64 = PG_EPOCH.elapsed().unwrap().as_micros().try_into().unwrap();
1031 let lsn = PgLsn::from(last_committed_upper.offset);
1032 trace!("timely-{} ({}) sending keepalive {lsn:?}", config.worker_id, config.id);
1033 // Postgres only sends PrimaryKeepAlive messages when *it* wants a reply, which
1034 // happens when out status update is late. Since we send them proactively this
1035 // may never happen. It is therefore *crucial* that we set the last parameter
1036 // (the reply flag) to 1 here. This will cause the upstream server to send us a
1037 // PrimaryKeepAlive message promptly which will give us frontier advancement
1038 // information in the absence of data updates.
1039 let res = stream.as_mut().standby_status_update(lsn, lsn, lsn, ts, 1).await;
1040 res.map_err(|e| e.into())
1041 },
1042 Some(uppers) = uppers.next() => {
1043 if let Some(lsn) = uppers.source.as_ref().and_then(|upper| upper.as_option()) {
1044 if last_committed_upper < *lsn {
1045 last_committed_upper = *lsn;
1046 }
1047 }
1048 // `offset_committed` was seeded with `resume_lsn`, so never report below it.
1049 for (id, upper) in &uppers.exports {
1050 let stat = config.statistics.get(id);
1051 if let (Some(lsn), Some(stat)) = (upper.as_option(), stat) {
1052 stat.set_offset_committed(std::cmp::max(*lsn, resume_lsn).offset);
1053 }
1054 }
1055 Ok(())
1056 },
1057 Ok(()) = probe_rx.changed() => match &*probe_rx.borrow() {
1058 Some(Ok(probe)) => {
1059 if let Some(offset_known) = probe.upstream_frontier.as_option() {
1060 for stat in config.statistics.values() {
1061 stat.set_offset_known(offset_known.offset);
1062 }
1063 }
1064 probe_output.give(probe_cap, probe);
1065 Ok(())
1066 },
1067 Some(Err(err)) => Err(anyhow::anyhow!("{err}").into()),
1068 None => Ok(()),
1069 },
1070 else => return
1071 }?;
1072 }
1073 });
1074 Ok(Ok(stream))
1075}
1076
1077/// The outputs of relation `rel` that a message committed at `commit_lsn` applies to.
1078fn outputs_at(
1079 table_info: &BTreeMap<u32, BTreeMap<usize, SourceOutputInfo>>,
1080 rel: u32,
1081 commit_lsn: MzOffset,
1082) -> impl Iterator<Item = (&usize, &SourceOutputInfo)> {
1083 table_info
1084 .get(&rel)
1085 .into_iter()
1086 .flatten()
1087 .filter(move |(_, info)| !info.ignores(commit_lsn))
1088}
1089
1090/// Extracts a single transaction from the replication stream delimited by a BEGIN and COMMIT
1091/// message. The BEGIN message must have already been consumed from the stream before calling this
1092/// function.
1093fn extract_transaction<'a>(
1094 stream: impl AsyncStream<Item = Result<LogicalReplMsg, TransientError>> + 'a,
1095 metadata_client: &'a Client,
1096 commit_lsn: MzOffset,
1097 table_info: &'a mut BTreeMap<u32, BTreeMap<usize, SourceOutputInfo>>,
1098 metrics: &'a PgSourceMetrics,
1099 publication: &'a str,
1100) -> impl AsyncStream<Item = Result<TransactionEvent, TransientError>> + 'a {
1101 use LogicalReplicationMessage::*;
1102 let mut row = Row::default();
1103 async_stream::try_stream!({
1104 let mut stream = pin!(stream);
1105 metrics.transactions.inc();
1106 metrics.lsn.set(commit_lsn.offset);
1107 while let Some(event) = stream.try_next().await? {
1108 // We can ignore keepalive messages while processing a transaction because the
1109 // commit_lsn will drive progress.
1110 let message = match event {
1111 ReplicationMessage::XLogData(data) => data.into_data(),
1112 ReplicationMessage::PrimaryKeepAlive(_) => {
1113 metrics.ignored.inc();
1114 continue;
1115 }
1116 _ => Err(TransientError::UnknownReplicationMessage)?,
1117 };
1118 metrics.total.inc();
1119 match message {
1120 Insert(body) if !table_info.contains_key(&body.rel_id()) => metrics.ignored.inc(),
1121 Update(body) if !table_info.contains_key(&body.rel_id()) => metrics.ignored.inc(),
1122 Delete(body) if !table_info.contains_key(&body.rel_id()) => metrics.ignored.inc(),
1123 Relation(body) if !table_info.contains_key(&body.rel_id()) => metrics.ignored.inc(),
1124 Insert(body) => {
1125 metrics.inserts.inc();
1126 let rel = body.rel_id();
1127 for (output, info) in outputs_at(table_info, rel, commit_lsn) {
1128 let tuple_data = body.tuple().tuple_data();
1129 let Some(ref projection) = info.projection else {
1130 panic!("missing projection for {rel}");
1131 };
1132 let datums = projection.iter().map(|idx| &tuple_data[*idx]);
1133 let row = unpack_tuple(datums, &mut row);
1134 yield TransactionEvent::Update((rel, *output, row, Diff::ONE));
1135 }
1136 }
1137 Update(body) => match body.old_tuple() {
1138 Some(old_tuple) => {
1139 metrics.updates.inc();
1140 let new_tuple = body.new_tuple();
1141 let rel = body.rel_id();
1142 for (output, info) in outputs_at(table_info, rel, commit_lsn) {
1143 let Some(ref projection) = info.projection else {
1144 panic!("missing projection for {rel}");
1145 };
1146 let old_tuple =
1147 projection.iter().map(|idx| &old_tuple.tuple_data()[*idx]);
1148 // If the new tuple contains unchanged toast values we reference the old ones
1149 let new_tuple = std::iter::zip(
1150 projection.iter().map(|idx| &new_tuple.tuple_data()[*idx]),
1151 old_tuple.clone(),
1152 )
1153 .map(|(new, old)| match new {
1154 TupleData::UnchangedToast => old,
1155 _ => new,
1156 });
1157 let old_row = unpack_tuple(old_tuple, &mut row);
1158 let new_row = unpack_tuple(new_tuple, &mut row);
1159
1160 yield TransactionEvent::Update((
1161 rel,
1162 *output,
1163 old_row,
1164 Diff::MINUS_ONE,
1165 ));
1166 yield TransactionEvent::Update((rel, *output, new_row, Diff::ONE));
1167 }
1168 }
1169 None => {
1170 let rel = body.rel_id();
1171 for (output, _) in outputs_at(table_info, rel, commit_lsn) {
1172 yield TransactionEvent::Update((
1173 rel,
1174 *output,
1175 Err(DefiniteError::DefaultReplicaIdentity),
1176 Diff::ONE,
1177 ));
1178 }
1179 }
1180 },
1181 Delete(body) => match body.old_tuple() {
1182 Some(old_tuple) => {
1183 metrics.deletes.inc();
1184 let rel = body.rel_id();
1185 for (output, info) in outputs_at(table_info, rel, commit_lsn) {
1186 let Some(ref projection) = info.projection else {
1187 panic!("missing projection for {rel}");
1188 };
1189 let datums = projection.iter().map(|idx| &old_tuple.tuple_data()[*idx]);
1190 let row = unpack_tuple(datums, &mut row);
1191 yield TransactionEvent::Update((rel, *output, row, Diff::MINUS_ONE));
1192 }
1193 }
1194 None => {
1195 let rel = body.rel_id();
1196 for (output, _) in outputs_at(table_info, rel, commit_lsn) {
1197 yield TransactionEvent::Update((
1198 rel,
1199 *output,
1200 Err(DefiniteError::DefaultReplicaIdentity),
1201 Diff::ONE,
1202 ));
1203 }
1204 }
1205 },
1206 Relation(body) => {
1207 let rel_id = body.rel_id();
1208 if let Some(outputs) = table_info.get_mut(&body.rel_id()) {
1209 // Because the replication stream doesn't include columns' attnums, we need
1210 // to check the current local schema against the current remote schema to
1211 // ensure e.g. we haven't received a schema update with the same terminal
1212 // column name which is actually a different column.
1213 let upstream_info = mz_postgres_util::publication_info(
1214 metadata_client,
1215 publication,
1216 Some(&[rel_id]),
1217 )
1218 .await?;
1219
1220 let mut schema_errors = vec![];
1221
1222 outputs.retain(|output_index, info| {
1223 match verify_schema(rel_id, info, &upstream_info) {
1224 Ok(()) => true,
1225 Err(error) => {
1226 schema_errors.push(TransactionEvent::Seal(Seal {
1227 output_index: *output_index,
1228 resume_upper: info.resume_upper.clone(),
1229 error,
1230 }));
1231 false
1232 }
1233 }
1234 });
1235 // Recalculate projection vector for the retained valid outputs. Here we
1236 // must use the column names in the RelationBody message and not the
1237 // upstream_info obtained above, since that one represents the current
1238 // schema upstream which may be many versions head of the one we're about
1239 // to receive after this Relation message.
1240 let column_positions: BTreeMap<_, _> = body
1241 .columns()
1242 .iter()
1243 .enumerate()
1244 .map(|(idx, col)| (col.name().unwrap(), idx))
1245 .collect();
1246 for info in outputs.values_mut() {
1247 let projection: Option<Vec<_>> = info
1248 .desc
1249 .columns
1250 .iter()
1251 .map(|col| column_positions.get(&*col.name).copied())
1252 .collect();
1253 match projection {
1254 Some(projection) => info.projection = Some(projection),
1255 // This message describes a schema from before the output was
1256 // created, which need not cover `desc`. Retaining the previous
1257 // projection is safe: messages at these LSNs are ignored, and the
1258 // schema change that made the columns diverge invalidates the
1259 // upstream's relation cache, so another Relation message arrives
1260 // ahead of the first message that isn't ignored.
1261 None if info.ignores(commit_lsn) => (),
1262 None => panic!(
1263 "Relation message for {rel_id} at {commit_lsn} does not \
1264 cover the captured schema of {}",
1265 info.desc.name
1266 ),
1267 }
1268 }
1269 for schema_error in schema_errors {
1270 yield schema_error;
1271 }
1272 }
1273 }
1274 Truncate(body) => {
1275 for &rel_id in body.rel_ids() {
1276 if let Some(outputs) = table_info.get_mut(&rel_id) {
1277 let mut ignored = BTreeMap::new();
1278 for (output, info) in std::mem::take(outputs) {
1279 if info.ignores(commit_lsn) {
1280 ignored.insert(output, info);
1281 continue;
1282 }
1283 yield TransactionEvent::Seal(Seal {
1284 output_index: output,
1285 resume_upper: info.resume_upper,
1286 error: DefiniteError::TableTruncated,
1287 });
1288 }
1289 *outputs = ignored;
1290 }
1291 }
1292 }
1293 Commit(body) => {
1294 if commit_lsn != body.commit_lsn().into() {
1295 Err(TransientError::InvalidTransaction)?
1296 }
1297 return;
1298 }
1299 // TODO: We should handle origin messages and emit an error as they indicate that
1300 // the upstream performed a point in time restore so all bets are off about the
1301 // continuity of the stream.
1302 Origin(_) | Type(_) => metrics.ignored.inc(),
1303 Begin(_) => Err(TransientError::NestedTransaction)?,
1304 // The enum is marked as non_exhaustive. Better to be conservative
1305 _ => Err(TransientError::UnknownLogicalReplicationMessage)?,
1306 }
1307 }
1308 Err(TransientError::ReplicationEOF)?;
1309 })
1310}
1311
1312/// Unpacks an iterator of TupleData into a list of nullable bytes or an error if this can't be
1313/// done.
1314#[inline]
1315fn unpack_tuple<'a, I>(tuple_data: I, row: &mut Row) -> Result<Row, DefiniteError>
1316where
1317 I: IntoIterator<Item = &'a TupleData>,
1318 I::IntoIter: ExactSizeIterator,
1319{
1320 let iter = tuple_data.into_iter();
1321 let mut packer = row.packer();
1322 for data in iter {
1323 let datum = match data {
1324 TupleData::Text(bytes) => super::decode_utf8_text(bytes)?,
1325 TupleData::Null => Datum::Null,
1326 TupleData::UnchangedToast => return Err(DefiniteError::MissingToast),
1327 TupleData::Binary(_) => return Err(DefiniteError::UnexpectedBinaryData),
1328 };
1329 packer.push(datum);
1330 }
1331 Ok(row.clone())
1332}
1333
1334/// Ensures the upstream still meets the conditions the replication stream depends on. Once
1335/// violated, these conditions stay violated. It returns an outer transient error in case of
1336/// connection issues and an inner definite error for the first violated condition.
1337pub(super) async fn ensure_replication_prerequisites(
1338 metadata_client: &Client,
1339 replication_client: &Client,
1340 connection: &PostgresSourceConnection,
1341 config_set: &ConfigSet,
1342) -> Result<Result<(), DefiniteError>, TransientError> {
1343 if let Err(err) = ensure_publication_exists(metadata_client, &connection.publication).await? {
1344 return Ok(Err(err));
1345 }
1346
1347 // This runs before the timeline ID check on purpose. Promoting a physical replica to a primary
1348 // both flips pg_is_in_recovery() and switches the timeline, so either check could fire. Running
1349 // this one first means a promotion always surfaces as the specific InvalidPhysicalReplica error
1350 // (rather than the more generic timeline mismatch), which is the clearer signal for an operator.
1351 let is_physical_replica = connection.publication_details.get_is_physical_replica();
1352 if let Err(err) = ensure_physical_replica(metadata_client, is_physical_replica).await? {
1353 return Ok(Err(err));
1354 }
1355
1356 // Sources created before the timeline ID was recorded have none to check against.
1357 if let Some(expected_timeline_id) = &connection.publication_details.timeline_id {
1358 if let Err(err) =
1359 ensure_replication_timeline_id(replication_client, expected_timeline_id, config_set)
1360 .await?
1361 {
1362 return Ok(Err(err));
1363 }
1364 }
1365
1366 Ok(Ok(()))
1367}
1368
1369/// Ensures the publication exists on the server. It returns an outer transient error in case of
1370/// connection issues and an inner definite error if the publication is dropped.
1371async fn ensure_publication_exists(
1372 client: &Client,
1373 publication: &str,
1374) -> Result<Result<(), DefiniteError>, TransientError> {
1375 // Figure out the last written LSN and then add one to convert it into an upper.
1376 let result = query_opt(
1377 &**client,
1378 sql!("SELECT 1 FROM pg_publication WHERE pubname = $1;"),
1379 &[&publication],
1380 )
1381 .await?;
1382 match result {
1383 Some(_) => Ok(Ok(())),
1384 None => Ok(Err(DefiniteError::PublicationDropped(
1385 publication.to_owned(),
1386 ))),
1387 }
1388}
1389
1390/// Ensure the active replication timeline_id matches the one we expect such that we can safely
1391/// resume replication. It returns an outer transient error in case of
1392/// connection issues and an inner definite error if the timeline id does not match.
1393async fn ensure_replication_timeline_id(
1394 replication_client: &Client,
1395 expected_timeline_id: &u64,
1396 config_set: &ConfigSet,
1397) -> Result<Result<(), DefiniteError>, TransientError> {
1398 let timeline_id = mz_postgres_util::get_timeline_id(replication_client).await?;
1399 if timeline_id == *expected_timeline_id {
1400 Ok(Ok(()))
1401 } else {
1402 if PG_SOURCE_VALIDATE_TIMELINE.get(config_set) {
1403 Ok(Err(DefiniteError::InvalidTimelineId {
1404 expected: *expected_timeline_id,
1405 actual: timeline_id,
1406 }))
1407 } else {
1408 tracing::warn!(
1409 "Timeline ID mismatch ignored: expected={expected_timeline_id} actual={timeline_id}"
1410 );
1411 Ok(Ok(()))
1412 }
1413 }
1414}
1415
1416async fn ensure_physical_replica(
1417 metadata_client: &Client,
1418 expected_is_physical_replica: bool,
1419) -> Result<Result<(), DefiniteError>, TransientError> {
1420 let is_physical_replica = mz_postgres_util::get_is_in_recovery(metadata_client).await?;
1421 if is_physical_replica == expected_is_physical_replica {
1422 Ok(Ok(()))
1423 } else {
1424 Ok(Err(DefiniteError::InvalidPhysicalReplica {
1425 expected: expected_is_physical_replica,
1426 actual: is_physical_replica,
1427 }))
1428 }
1429}
1430
1431enum SchemaValidationError {
1432 Postgres(PostgresError),
1433 Schema {
1434 oid: u32,
1435 output_index: usize,
1436 error: DefiniteError,
1437 },
1438 /// The upstream's physical-replica status changed out from under us (e.g. a
1439 /// physical replica was promoted to a primary). `expected` is the status the
1440 /// source was created against; `actual` is what the upstream reports now.
1441 PhysicalReplicaChanged {
1442 expected: bool,
1443 actual: bool,
1444 },
1445}
1446
1447impl SchemaValidationError {
1448 /// The `(oid, output_index)` of the one output this error ends, or `None`
1449 /// if it ends the whole source.
1450 fn output(&self) -> Option<(u32, usize)> {
1451 match self {
1452 Self::Schema {
1453 oid, output_index, ..
1454 } => Some((*oid, *output_index)),
1455 Self::Postgres(_) | Self::PhysicalReplicaChanged { .. } => None,
1456 }
1457 }
1458}
1459
1460fn spawn_schema_validator(
1461 client: Client,
1462 config: &RawSourceCreationConfig,
1463 publication: String,
1464 table_info: BTreeMap<u32, BTreeMap<usize, SourceOutputInfo>>,
1465 is_physical_replica: bool,
1466) -> mpsc::UnboundedReceiver<SchemaValidationError> {
1467 let (tx, rx) = mpsc::unbounded_channel();
1468 let source_id = config.id;
1469 let config_set = Arc::clone(config.config.config_set());
1470
1471 mz_ore::task::spawn(
1472 || format!("schema-validator:{}", source_id),
1473 run_schema_validator(
1474 tx,
1475 move || PG_SCHEMA_VALIDATION_INTERVAL.get(&config_set),
1476 async move || {
1477 validate_schemas(
1478 source_id,
1479 &client,
1480 &publication,
1481 &table_info,
1482 is_physical_replica,
1483 )
1484 .await
1485 },
1486 ),
1487 );
1488
1489 rx
1490}
1491
1492/// Runs `validate` once per `interval` and sends each failure to `tx` once.
1493///
1494/// Stops after the first failure that ends the whole source, or once the
1495/// receiver is dropped.
1496async fn run_schema_validator(
1497 tx: mpsc::UnboundedSender<SchemaValidationError>,
1498 interval: impl Fn() -> Duration,
1499 mut validate: impl AsyncFnMut() -> Vec<SchemaValidationError>,
1500) {
1501 // The replication loop drains `tx` only when the replication stream yields
1502 // a keepalive, so while the stream is silent every send stays queued.
1503 // Sending each failure once bounds the queue by the number of outputs plus
1504 // one.
1505 let mut reported = BTreeSet::new();
1506 while !tx.is_closed() {
1507 let validation_start = Instant::now();
1508 for error in validate().await {
1509 match error.output() {
1510 Some(output) => {
1511 if reported.insert(output) {
1512 let _ = tx.send(error);
1513 }
1514 }
1515 None => {
1516 let _ = tx.send(error);
1517 return;
1518 }
1519 }
1520 }
1521 let wait = interval().saturating_sub(validation_start.elapsed());
1522 tokio::time::sleep(wait).await;
1523 }
1524}
1525
1526/// Validates the upstream against the source's expectations once.
1527async fn validate_schemas(
1528 source_id: GlobalId,
1529 client: &Client,
1530 publication: &str,
1531 table_info: &BTreeMap<u32, BTreeMap<usize, SourceOutputInfo>>,
1532 is_physical_replica: bool,
1533) -> Vec<SchemaValidationError> {
1534 trace!(%source_id, "validating schemas");
1535 let mut errors = Vec::new();
1536
1537 // Detect a physical replica being promoted to a primary (or vice
1538 // versa) while the stream is live. The startup check in raw_stream
1539 // only catches this across a restart, so we re-check periodically
1540 // here to surface a definite error proactively.
1541 match mz_postgres_util::get_is_in_recovery(&**client).await {
1542 Ok(actual) if actual != is_physical_replica => {
1543 errors.push(SchemaValidationError::PhysicalReplicaChanged {
1544 expected: is_physical_replica,
1545 actual,
1546 });
1547 }
1548 Ok(_) => {}
1549 Err(error) => {
1550 errors.push(SchemaValidationError::Postgres(error));
1551 return errors;
1552 }
1553 }
1554
1555 let upstream_info = match mz_postgres_util::publication_info(
1556 &**client,
1557 publication,
1558 Some(&table_info.keys().copied().collect::<Vec<_>>()),
1559 )
1560 .await
1561 {
1562 Ok(info) => info,
1563 Err(error) => {
1564 errors.push(SchemaValidationError::Postgres(error));
1565 return errors;
1566 }
1567 };
1568
1569 for (&oid, outputs) in table_info.iter() {
1570 for (&output_index, info) in outputs {
1571 if let Err(error) = verify_schema(oid, info, &upstream_info) {
1572 trace!(
1573 %source_id,
1574 "schema of output index {output_index} for oid {oid} invalid",
1575 );
1576 errors.push(SchemaValidationError::Schema {
1577 oid,
1578 output_index,
1579 error,
1580 });
1581 } else {
1582 trace!(
1583 %source_id,
1584 "schema of output index {output_index} for oid {oid} valid",
1585 );
1586 }
1587 }
1588 }
1589 errors
1590}
1591
1592#[cfg(test)]
1593mod tests {
1594 use std::cell::Cell;
1595
1596 use super::*;
1597
1598 fn connection_error() -> SchemaValidationError {
1599 SchemaValidationError::Postgres(PostgresError::Generic(anyhow::anyhow!(
1600 "connection closed"
1601 )))
1602 }
1603
1604 #[mz_ore::test(tokio::test(start_paused = true))]
1605 async fn schema_validator_stops_after_source_error() {
1606 let (tx, mut rx) = mpsc::unbounded_channel();
1607 let rounds = Cell::new(0);
1608 let validator = run_schema_validator(
1609 tx,
1610 || Duration::from_secs(15),
1611 async || {
1612 rounds.set(rounds.get() + 1);
1613 assert!(rounds.get() <= 10, "validator retries without waiting");
1614 vec![connection_error()]
1615 },
1616 );
1617 let _ = tokio::time::timeout(Duration::from_secs(59), validator).await;
1618 assert_eq!(rounds.get(), 1);
1619 assert!(matches!(
1620 rx.try_recv(),
1621 Ok(SchemaValidationError::Postgres(_))
1622 ));
1623 assert!(rx.try_recv().is_err(), "only one error is queued");
1624 }
1625
1626 #[mz_ore::test(tokio::test(start_paused = true))]
1627 async fn schema_validator_reports_each_output_once() {
1628 let (tx, mut rx) = mpsc::unbounded_channel();
1629 let rounds = Cell::new(0);
1630 let validator = run_schema_validator(
1631 tx,
1632 || Duration::from_secs(15),
1633 async || {
1634 rounds.set(rounds.get() + 1);
1635 // The table leaves the publication, comes back, and leaves again,
1636 // all before the replication loop drains the queue.
1637 if rounds.get() % 2 == 1 {
1638 vec![SchemaValidationError::Schema {
1639 oid: 1,
1640 output_index: 0,
1641 error: DefiniteError::TableDropped,
1642 }]
1643 } else {
1644 Vec::new()
1645 }
1646 },
1647 );
1648 let _ = tokio::time::timeout(Duration::from_secs(59), validator).await;
1649 assert_eq!(rounds.get(), 4);
1650 assert!(matches!(
1651 rx.try_recv(),
1652 Ok(SchemaValidationError::Schema {
1653 oid: 1,
1654 output_index: 0,
1655 error: DefiniteError::TableDropped,
1656 })
1657 ));
1658 assert!(rx.try_recv().is_err(), "the output is reported once");
1659 }
1660}