From a875bea55ab960987a68aa0a20f12a9894b54ce2 Mon Sep 17 00:00:00 2001 From: Ankur Date: Wed, 16 Sep 2026 19:33:31 +0000 Subject: [PATCH] db-migrations-expand-contract: add a dedicated reproduction for the DDL-collision exception While writing the article, chapter 14's first failure mode (a concurrent statement seeing "Table CUSTOMERS not found" while DROP COLUMN runs) was described from the live load-generator run but had no dedicated, committed reproduction of its own - CustomerService's own retry would silently absorb it if triggered through the service layer. DdlCollisionExceptionTest reproduces it directly at the raw JDBC level, and the chapter and README now link to its captured transcript. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_019Fb7vW8vLyLKngBc4R3huA --- db-migrations-expand-contract/README.md | 1 + .../docs/14-the-ddl-lock-window.md | 28 ++++-- .../output/14-ddl-collision-exception.txt | 10 ++ .../DdlCollisionExceptionTest.java | 92 +++++++++++++++++++ 4 files changed, 124 insertions(+), 7 deletions(-) create mode 100644 db-migrations-expand-contract/docs/output/14-ddl-collision-exception.txt create mode 100644 db-migrations-expand-contract/src/test/java/com/ankurm/expandcontract/DdlCollisionExceptionTest.java diff --git a/db-migrations-expand-contract/README.md b/db-migrations-expand-contract/README.md index 22d3419..f170763 100644 --- a/db-migrations-expand-contract/README.md +++ b/db-migrations-expand-contract/README.md @@ -93,6 +93,7 @@ a transcript going stale fails the build. Files `11`–`13` come from the live | [`11-live-deploy-sequence.txt`](docs/output/11-live-deploy-sequence.txt) | [`scripts/run-all.sh`](scripts/run-all.sh) | | [`12-load-generator-summary.txt`](docs/output/12-load-generator-summary.txt) | [`LoadGenerator`](src/main/java/com/ankurm/expandcontract/loadgen/LoadGenerator.java), via `run-all.sh` | | [`13-schema-diagnostics-timeline.txt`](docs/output/13-schema-diagnostics-timeline.txt) | [`SchemaDiagnosticsController`](src/main/java/com/ankurm/expandcontract/diag/SchemaDiagnosticsController.java), via `run-all.sh` | +| [`14-ddl-collision-exception.txt`](docs/output/14-ddl-collision-exception.txt) | [`DdlCollisionExceptionTest`](src/test/java/com/ankurm/expandcontract/DdlCollisionExceptionTest.java) | | [`14-ddl-silent-data-loss.txt`](docs/output/14-ddl-silent-data-loss.txt) | [`DdlSilentDataLossTest`](src/test/java/com/ankurm/expandcontract/DdlSilentDataLossTest.java) | ## Findings worth the trip diff --git a/db-migrations-expand-contract/docs/14-the-ddl-lock-window.md b/db-migrations-expand-contract/docs/14-the-ddl-lock-window.md index 4a689c4..a602361 100644 --- a/db-migrations-expand-contract/docs/14-the-ddl-lock-window.md +++ b/db-migrations-expand-contract/docs/14-the-ddl-lock-window.md @@ -16,17 +16,31 @@ the handful of errors it reported. ## Failure mode 1: a statement that collides with the DDL, and says so -While `V3__drop_email_column.sql` runs, a concurrent, otherwise-correct `INSERT` or -`UPDATE` can briefly see: +While `V3__drop_email_column.sql` runs, a concurrent, otherwise-correct query can +briefly see the table disappear out from under it. +[`DdlCollisionExceptionTest`](https://ankurm.com/git.app/asmhatre/spring-boot-demo/src/branch/main/db-migrations-expand-contract/src/test/java/com/ankurm/expandcontract/DdlCollisionExceptionTest.java) +reproduces this directly, at the raw JDBC level — one thread reading the table in a +tight loop while `V3` (`DROP COLUMN`) runs concurrently on another connection: ``` -org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "CUSTOMERS" not found +successful reads while DROP COLUMN was in flight: 222 +reads that collided with the in-flight DROP COLUMN: 1 +example: org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "CUSTOMERS" not found; SQL statement: +SELECT COUNT(*) FROM customers [42102-240] ``` -This is a real, transient condition captured live, twice, in independent runs of this -module's load generator — not a bug in the application's SQL. H2's TCP server -appears to make the table briefly unavailable to other sessions while `DROP COLUMN` -executes. The fix is a narrowly scoped single retry in +Full transcript: +[`docs/output/14-ddl-collision-exception.txt`](https://ankurm.com/git.app/asmhatre/spring-boot-demo/src/branch/main/db-migrations-expand-contract/docs/output/14-ddl-collision-exception.txt). +This test bypasses `CustomerService` deliberately — its own retry would silently +absorb the very exception this test exists to show — and, like +`DdlSilentDataLossTest` below, repeats the race until it reproduces, since exactly +when it fires is OS thread scheduling, not application logic. + +This same condition is what first showed up as `create-http-500` / `update-http-500` +errors in this module's own live load-generator run, twice, in independent runs — +not a bug in the application's SQL. H2's TCP server appears to make the table +briefly unavailable to other sessions while `DROP COLUMN` executes. The fix is a +narrowly scoped single retry in [`CustomerService.withRetryForConcurrentDdl`](https://ankurm.com/git.app/asmhatre/spring-boot-demo/src/branch/main/db-migrations-expand-contract/src/main/java/com/ankurm/expandcontract/customer/CustomerService.java): ```java diff --git a/db-migrations-expand-contract/docs/output/14-ddl-collision-exception.txt b/db-migrations-expand-contract/docs/output/14-ddl-collision-exception.txt new file mode 100644 index 0000000..c9337e2 --- /dev/null +++ b/db-migrations-expand-contract/docs/output/14-ddl-collision-exception.txt @@ -0,0 +1,10 @@ +============================================================================== +Failure mode 1: a concurrent statement that collides with DROP COLUMN, and is told so +============================================================================== +captured: 2026-09-16T19:29:03.872467327Z + +attempts needed to reproduce the race: 4 of 20 +successful reads while DROP COLUMN was in flight: 222 +reads that collided with the in-flight DROP COLUMN: 1 +example: org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "CUSTOMERS" not found; SQL statement: +SELECT COUNT(*) FROM customers [42102-240] diff --git a/db-migrations-expand-contract/src/test/java/com/ankurm/expandcontract/DdlCollisionExceptionTest.java b/db-migrations-expand-contract/src/test/java/com/ankurm/expandcontract/DdlCollisionExceptionTest.java new file mode 100644 index 0000000..fa666fb --- /dev/null +++ b/db-migrations-expand-contract/src/test/java/com/ankurm/expandcontract/DdlCollisionExceptionTest.java @@ -0,0 +1,92 @@ +package com.ankurm.expandcontract; + +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; +import org.springframework.jdbc.core.simple.JdbcClient; + +import java.nio.file.Path; +import java.util.List; +import java.util.concurrent.CopyOnWriteArrayList; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.atomic.AtomicBoolean; + +import static org.assertj.core.api.Assertions.assertThat; + +/** + * The first of two failure modes covered in docs/14-the-ddl-lock-window.md, isolated here at + * the raw JDBC level rather than through {@link com.ankurm.expandcontract.customer.CustomerService}, + * because that class's {@code withRetryForConcurrentDdl} would silently absorb exactly the + * exception this test exists to show. While {@code ALTER TABLE ... DROP COLUMN} (V3) executes, + * a concurrent, otherwise-correct statement against the same table can briefly see + * {@code Table "CUSTOMERS" not found} - a real, transient condition, first noticed in this + * module's own live load-generator run and reproduced here on demand. See + * {@link DdlSilentDataLossTest} for the second, stranger failure mode the same root cause + * produces - a statement that succeeds and is still lost, with no exception at all. + */ +class DdlCollisionExceptionTest { + + private static final int MAX_ATTEMPTS = 20; + + @Test + void concurrentStatementCanSeeTableNotFoundWhileDropColumnRuns(@TempDir Path tmp) throws Exception { + Transcript t = Transcript.start("14-ddl-collision-exception", + "Failure mode 1: a concurrent statement that collides with DROP COLUMN, and is told so"); + + for (int attempt = 1; attempt <= MAX_ATTEMPTS; attempt++) { + Path db = tmp.resolve("collision-exception-" + attempt); + TestSupport.migrateTo(db, "2"); + JdbcClient jdbc = TestSupport.jdbcClient(db); + + AtomicBoolean stop = new AtomicBoolean(false); + List collisionMessages = new CopyOnWriteArrayList<>(); + List okCount = new CopyOnWriteArrayList<>(); + CountDownLatch started = new CountDownLatch(1); + + Thread reader = new Thread(() -> { + started.countDown(); + long ok = 0; + while (!stop.get()) { + try { + jdbc.sql("SELECT COUNT(*) FROM customers").query(Long.class).single(); + ok++; + } catch (Exception ex) { + Throwable root = ex; + while (root.getCause() != null) { + root = root.getCause(); + } + if (root.getMessage() != null && root.getMessage().contains("CUSTOMERS")) { + collisionMessages.add(root.getClass().getName() + ": " + root.getMessage()); + } + } + } + okCount.add(ok); + }); + reader.start(); + started.await(); + + // Deploy 4b, running live while the reader above keeps querying the same table. + TestSupport.migrateTo(db, "3"); + + stop.set(true); + reader.join(); + + if (collisionMessages.isEmpty() && attempt < MAX_ATTEMPTS) { + continue; + } + + t.line("attempts needed to reproduce the race: " + attempt + " of " + MAX_ATTEMPTS); + t.line("successful reads while DROP COLUMN was in flight: " + okCount.get(0)); + t.line("reads that collided with the in-flight DROP COLUMN: " + collisionMessages.size()); + if (!collisionMessages.isEmpty()) { + t.line("example: " + collisionMessages.get(0)); + } + t.write(); + + assertThat(collisionMessages) + .withFailMessage("expected at least one concurrent read to collide with DROP COLUMN " + + "within %d attempts", MAX_ATTEMPTS) + .isNotEmpty(); + return; + } + } +}