Skip to content

Commit 85cc29e

Browse files
committed
test(crash): let long-running polls absorb retryable schema changes
query_col_idx panics as soon as its own short retry budget is exhausted, which could abort an outer poll loop (e.g. wait_for_count after reopen()) that still had budget left for a descriptor-lease drain the server explicitly asks clients to retry. Add try_query_col_idx to hand that condition back to the caller instead, and use it in the ILP timeseries wait loop so only genuine failures panic.
1 parent b44c0e2 commit 85cc29e

3 files changed

Lines changed: 76 additions & 25 deletions

File tree

‎nodedb/tests/crash_harness/mod.rs‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -29,11 +29,11 @@ pub mod ilp_client;
2929
mod pgwire;
3030
pub mod resp_client;
3131

32-
// Only `crash_ilp_timeseries_write.rs` names `Session` directly; every other
33-
// crash-test binary pulls in this module too, so the re-export is unused
34-
// there.
32+
// Only `crash_ilp_timeseries_write.rs` names `Session` and
33+
// `RetryableSchemaChange` directly; every other crash-test binary pulls in this
34+
// module too, so the re-exports are unused there.
3535
#[allow(unused_imports)]
36-
pub use pgwire::Session;
36+
pub use pgwire::{RetryableSchemaChange, Session};
3737
#[path = "../support/mod.rs"]
3838
mod support;
3939

‎nodedb/tests/crash_harness/pgwire.rs‎

Lines changed: 48 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -39,6 +39,16 @@ const SCHEMA_CHANGE_RETRY_BACKOFF: Duration = Duration::from_millis(150);
3939
/// unrelated internal errors, so the message text — which is the error
4040
/// type's own stable Display string, not free-form prose — is the only
4141
/// durable signal available.
42+
/// The server was still reporting `RetryableSchemaChanged` when the
43+
/// client-side retry budget ran out.
44+
///
45+
/// Deliberately carries no payload: it exists so a caller with its own longer
46+
/// deadline can tell "the descriptor drain has not settled yet" apart from a
47+
/// real error, and every real error still panics at the call site with the full
48+
/// server log and faultbox report attached.
49+
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
50+
pub struct RetryableSchemaChange;
51+
4252
fn is_retryable_schema_change(e: &tokio_postgres::Error) -> bool {
4353
e.as_db_error()
4454
.is_some_and(|db| db.message().contains("retryable schema change"))
@@ -306,20 +316,53 @@ impl Session<'_> {
306316
/// does (see [`is_retryable_schema_change`] and its budget constants) —
307317
/// this is the helper the tests' tight polling loops actually use, so
308318
/// it needs the same client-retry behavior, not just the one-shot path.
319+
///
320+
/// Panics once that budget is exhausted. A caller that runs this inside
321+
/// its own bounded poll should use [`Self::try_query_col_idx`] instead:
322+
/// this helper's ~750ms budget is far shorter than a typical poll
323+
/// deadline, so panicking here would abort a poll that still had seconds
324+
/// of budget left for exactly the condition the server told it to retry.
309325
pub async fn query_col_idx(&self, sql: &str, idx: usize) -> Vec<String> {
326+
match self.try_query_col_idx(sql, idx).await {
327+
Ok(rows) => rows,
328+
Err(RetryableSchemaChange) => {
329+
let tail = super::diagnostics::log_tail_section(&self.harness.server_log());
330+
let reports = super::diagnostics::faultbox_report_section(self.harness.data_dir());
331+
panic!(
332+
"query on session: retryable schema change never cleared within \
333+
{SCHEMA_CHANGE_RETRY_ATTEMPTS} attempts{}\n{reports}{tail}",
334+
self.harness.keep_data_dir_note(),
335+
)
336+
}
337+
}
338+
}
339+
340+
/// [`Self::query_col_idx`] that reports an unresolved retryable schema
341+
/// change to the caller instead of panicking on it.
342+
///
343+
/// The server's own contract says a client observing this condition
344+
/// retries the statement — it is the descriptor-lease-drain race, not a
345+
/// distinct failure. A poll loop that owns a longer deadline is the right
346+
/// place to absorb it, so this returns [`RetryableSchemaChange`] and lets
347+
/// the caller decide. Every other error still panics: those are real.
348+
pub async fn try_query_col_idx(
349+
&self,
350+
sql: &str,
351+
idx: usize,
352+
) -> Result<Vec<String>, RetryableSchemaChange> {
310353
let mut schema_change_attempts = 0usize;
311354
loop {
312355
match self.client.simple_query(sql).await {
313356
Ok(messages) => {
314-
return messages
357+
return Ok(messages
315358
.iter()
316359
.filter_map(|m| match m {
317360
tokio_postgres::SimpleQueryMessage::Row(row) => {
318361
Some(row.get(idx).unwrap_or_default().to_string())
319362
}
320363
_ => None,
321364
})
322-
.collect();
365+
.collect());
323366
}
324367
Err(e)
325368
if is_retryable_schema_change(&e)
@@ -328,23 +371,13 @@ impl Session<'_> {
328371
schema_change_attempts += 1;
329372
tokio::time::sleep(SCHEMA_CHANGE_RETRY_BACKOFF).await;
330373
}
374+
// Hand the still-unresolved drain back to the caller. Callers
375+
// polling on their own deadline retry; `query_col_idx` panics.
376+
Err(e) if is_retryable_schema_change(&e) => return Err(RetryableSchemaChange),
331377
// Same rationale as `simple_query_ready`'s error branches: the
332378
// interesting failures here are server-side, and the harness's
333379
// tempdir is gone by the time anyone reads the panic (unless
334380
// `NODEDB_TEST_KEEP_DATA_DIR` says otherwise).
335-
Err(e) if is_retryable_schema_change(&e) => {
336-
let tail = super::diagnostics::log_tail_section(&self.harness.server_log());
337-
let reports =
338-
super::diagnostics::faultbox_report_section(self.harness.data_dir());
339-
panic!(
340-
"query on session: retryable schema change never cleared within \
341-
{SCHEMA_CHANGE_RETRY_ATTEMPTS} attempts: {e}{}{}\n{reports}{tail}",
342-
e.as_db_error()
343-
.map(|db| format!(" — {}: {}", db.code().code(), db.message()))
344-
.unwrap_or_default(),
345-
self.harness.keep_data_dir_note(),
346-
)
347-
}
348381
Err(e) => {
349382
let tail = super::diagnostics::log_tail_section(&self.harness.server_log());
350383
let reports =

‎nodedb/tests/crash_ilp_timeseries_write.rs‎

Lines changed: 24 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -90,17 +90,35 @@ async fn wait_for_count(
9090
timeout: Duration,
9191
) -> Vec<String> {
9292
let deadline = Instant::now() + timeout;
93+
// Assigned by both arms of the match below before the deadline check reads
94+
// it, so no placeholder initial value is needed.
95+
let mut last: Result<Vec<String>, &str>;
9396
loop {
94-
let rows = session
95-
.query_col_idx(&format!("SELECT COUNT(*) FROM {collection}"), 0)
96-
.await;
97-
if rows.first().map(|v| v.as_str()) == Some(expected) {
98-
return rows;
97+
// A descriptor-lease drain is exactly the "not settled yet" condition
98+
// this loop exists to wait out, and it is common right after `reopen()`
99+
// while boot replay re-establishes descriptors. Panicking on it inside
100+
// the loop would abandon the remaining budget over a condition the
101+
// server explicitly asks clients to retry, so absorb it here and let
102+
// this deadline — not the session helper's much shorter one — decide
103+
// when the wait has genuinely failed.
104+
match session
105+
.try_query_col_idx(&format!("SELECT COUNT(*) FROM {collection}"), 0)
106+
.await
107+
{
108+
Ok(rows) => {
109+
if rows.first().map(|v| v.as_str()) == Some(expected) {
110+
return rows;
111+
}
112+
last = Ok(rows);
113+
}
114+
Err(crash_harness::RetryableSchemaChange) => {
115+
last = Err("retryable schema change still unresolved");
116+
}
99117
}
100118
if Instant::now() >= deadline {
101119
panic!(
102120
"SELECT COUNT(*) FROM {collection} never reached {expected} within {timeout:?}; \
103-
last observed: {rows:?}"
121+
last observed: {last:?}"
104122
);
105123
}
106124
tokio::time::sleep(Duration::from_millis(50)).await;

0 commit comments

Comments
 (0)