Repository navigation
fix(postgres)!: store timestamps as TIMESTAMPTZ so they no longer depend on the JVM zone (#135) - #145
Conversation
rawo
left a comment
There was a problem hiding this comment.
Reviewed only the #145 diff (the shared TimestampColumnTests and MySQL parts belong to #144). The core change looks right to me. ALTER ... TYPE TIMESTAMPTZ reads values in the session zone, and an in-app Liquibase run gets the JVM zone through pgjdbc's TimeZone startup parameter. Inline comments cover the rolling-deploy claim, manual application and the tests. Two cross-cutting points:
Question: which zone the conversion actually uses. pgjdbc sends TimeZone.getDefault() as a startup parameter when it opens the connection. 1.x rendered each Timestamp with the default zone at bind time. These differ when an app calls TimeZone.setDefault(...) after the pool has opened connections (the common Spring @PostConstruct / main() pattern, where Liquibase may run first), or when the session zone is changed afterwards (e.g. Hikari connectionInitSql = SET TIME ZONE ...). In those setups the in-app migration shifts existing rows. Should README/UPGRADING say "the zone the JVM had when the migration connection was opened" and list these cases? Alternatively, the changeset could take an explicit zone (a Liquibase changelog parameter, defaulting to current_setting('TimeZone')) as an override.
Question: an unmigrated schema fails silently. If a manual-migration user deploys 2.0 without 003, the new binding writes TIMESTAMPTZ parameters into TIMESTAMP columns, which the server casts to session-zone wall-clock time. getObject(OffsetDateTime) on a TIMESTAMP column then parses the offset-less text as UTC (TimestampUtils.ParsedTimestamp.offset defaults to ZoneOffset.UTC in 42.7.14). Values would be off by the zone offset with no error. The missing MySQL 002 index fails loudly by comparison. Is a cheap startup check of information_schema.columns.data_type worth adding, or at least a note in the README?
Checked and fine:
setObject(OffsetDateTime)bindsOid.TIMESTAMPTZ, which matches the new column type, so the claim (created_at) and purge (last_attempt < ?) predicates keep using their indexes.setNull(Types.TIMESTAMP_WITH_TIMEZONE)maps toOid.UNSPECIFIEDin 42.7.14, notTIMESTAMPTZ. A batch that mixed null and non-nulllast_attemptwould cost at most one re-parse (SimpleQuery.isPreparedFor), andlastAttemptis always set after processing anyway.SET LOCALinside Liquibase's changeset transaction works and doesn't leak into the pool.- 002's partial index is rebuilt under the same lock, and the docs cover that.
- Specs run sequentially (no kotest parallelism configured), so the
TimeZone.setDefaultmutation is contained. - No precision change: both paths round to microseconds.
- Small doc nit: skipping the rewrite when the session zone is UTC is a PostgreSQL 12+ optimisation, in case older servers are still supported.
| Holding the lock, it rewrites the table unless the session zone is UTC, and reads and writes, | ||
| including `publish()`, wait until it finishes. Purge delivered rows or pick a quiet period on a | ||
| large table. | ||
| - **Rolling deploys are safe.** 1.x binds `java.sql.Timestamp`, which pgjdbc sends with the JVM's |
There was a problem hiding this comment.
Should-fix (accuracy). This holds for fresh, unprepared statements. A 1.x instance's pooled connections will have server-prepared statements (pgjdbc's prepareThreshold=5), and those behave differently after the ALTER. I checked on postgres:16 with PREPARE/EXECUTE:
- A
SELECT * ... FOR UPDATE SKIP LOCKEDclaim prepared before the migration fails withERROR: cached plan must not change result type. pgjdbc 42.7.14 retries that only when the transaction isn't aborted (QueryExecutorBase.willHealOnRetryreturns false forautosave=never+FAILED). The claim runs inside the scheduler transaction, so each pooled connection loses one poll cycle with an error log.flushCacheOnDdlonly bumps the epoch on the connection that ran the DDL. It's benign, but operators will see errors. - A prepared
INSERT/UPDATEkeeps its inferred parameter typetimestamp without time zone(pg_prepared_statements.parameter_types). The+09offset pgjdbc sends is dropped, and the value is re-cast totimestamptzin the session zone. Writes stay correct only because session zone == JVM zone. They don't stay correct because "TIMESTAMPTZ honours that offset".
Suggest wording along the lines of: "1.x instances keep working, provided the session zone equals the JVM zone. Expect one cached plan must not change result type error per pooled connection on the first claim after the migration." The same applies to the CHANGELOG and README sentences.
| entry.lastAttempt shouldBe lastAttempt | ||
| } | ||
|
|
||
| test("a 1.x instance on a non-UTC JVM still writes correct instants after changeset 003") { |
There was a problem hiding this comment.
Should-fix (test). Two issues:
- This test depends on the previous one having applied 003 to the shared container. Run alone (IDE,
--testsfilter), it fails on a missing table, or on an unmigrated schema if the order ever changes. Migrating inbeforeSpec(orbeforeTestwith its own container/schema) would make each test self-contained. - It uses a brand-new
DriverManagerconnection and an unprepared statement, so it doesn't exercise the case the rolling-deploy claim is really about: a long-lived 1.x connection that prepared its claim/insert before 003 (see the UPGRADING comment). A connection opened withprepareThreshold=1that runs the 1.x insert and claim SQL beforeliquibase.update, then again after, would cover both thecached plan must not change result typeerror and thetimestamp-typed parameter path. It also never reads through the 1.x path (getTimestamp), although the docs say 1.x "write and read" correctly.
| -- only, after which the migration fails and runs again on the next start. Holding the lock, it | ||
| -- rewrites the table unless the session zone is UTC and rebuilds its indexes; reads and writes to | ||
| -- okapi_outbox, including publish(), wait until it finishes. | ||
| SET LOCAL lock_timeout = '30s'; |
There was a problem hiding this comment.
Should-fix (manual application). In Liquibase this runs inside the changeset transaction, which is fine. Applied by hand in psql's default autocommit mode, though, it only emits WARNING: SET LOCAL can only be used in transaction blocks and lock_timeout stays 0. I confirmed this on postgres:16. The script comment, README and UPGRADING tell manual users to SET TIME ZONE first but don't say to wrap the script in BEGIN; ... COMMIT; (or use psql -1). Worth stating explicitly, especially since 002 has to run outside a transaction.
|
|
||
| For an existing installation, apply `002` before starting updated workers. MySQL claims explicitly select the new index and fail if it is missing. PostgreSQL's `002` uses `CREATE INDEX CONCURRENTLY`, so run it outside a transaction when using another migration tool. The bundled Liquibase changelog handles this automatically. `CREATE INDEX CONCURRENTLY` waits for every transaction in the database that started before it, not only those on `okapi_outbox`, so long-running transactions (including old workers delivering a claimed batch) delay it, and with Liquibase they delay application startup while the changelog lock is held. Run it when no long transactions are open, or apply it ahead of the rollout. | ||
|
|
||
| PostgreSQL's `003` converts the timestamp columns from `TIMESTAMP` (the okapi JVM's local wall-clock time) to `TIMESTAMPTZ`. It reads existing values in the session `TimeZone`; pgjdbc sets that to the JVM default zone, so the bundled Liquibase changelog converts them correctly when it runs inside the application. When applying it by hand, run `SET TIME ZONE '<zone your okapi JVMs run in>'` first in the same session. It takes an `ACCESS EXCLUSIVE` lock: it first waits (up to 30 s, then fails and retries on the next start) for open transactions on `okapi_outbox`, queuing every other statement on the table meanwhile, and then, unless the session zone is UTC, rewrites the table while reads and writes wait. 1.x and 2.0 instances can run side by side after it. See [UPGRADING.md](UPGRADING.md#from-1x-to-200). |
There was a problem hiding this comment.
Should-fix (docs). Two things in this paragraph:
- "When applying it by hand, run
SET TIME ZONE... first" should also say to run it inside a transaction, otherwise the 30 slock_timeouthas no effect (see the comment on 003 line 19). - "1.x and 2.0 instances can run side by side after it" needs the same qualification as in UPGRADING: the session zone must match the JVM zone, and expect a one-off
cached plan must not change result typeerror per pooled 1.x connection.
| it by hand only after `SET TIME ZONE '<your JVM zone>'`. `PostgresOutboxStore` now binds and reads | ||
| these columns as `OffsetDateTime`. The migration takes an `ACCESS EXCLUSIVE` lock (waiting at most | ||
| 30 s for it, then failing and retrying on the next start) and, unless the session zone is UTC, | ||
| rewrites the table. 1.x instances keep working against the migrated columns. Rows written during a fall-back hour by a non-UTC JVM were |
There was a problem hiding this comment.
Nit. This line breaks the ~100-column wrapping used in the rest of the entry. "1.x instances keep working against the migrated columns" needs the same qualification as in UPGRADING (one-off cached-plan error per pooled connection; relies on session zone == JVM zone).
| try { | ||
| TimeZone.setDefault(TimeZone.getTimeZone("Asia/Tokyo")) | ||
| DriverManager.getConnection(container.jdbcUrl, container.username, container.password).use { conn -> | ||
| val liquibase = |
There was a problem hiding this comment.
Nit. Liquibase is AutoCloseable and runOkapiLiquibaseOn closes it with .use { }. Same here for consistency (the connection is closed anyway, so this is cosmetic).
|
Addressed the review in d105443:
|
…end on the JVM zone (#135) created_at, updated_at and last_attempt were TIMESTAMP WITHOUT TIME ZONE, and pgjdbc renders a java.sql.Timestamp in the JVM default zone, so each row held the writing JVM's local wall-clock time; mixed-zone fleets and DST fall-back skewed claim order, lag and purge by hours. Changeset 003 converts the columns to TIMESTAMPTZ, reading existing values in the session TimeZone, which pgjdbc sets to the JVM default zone, so the bundled changelog run by the application keeps them correct. lock_timeout bounds its ACCESS EXCLUSIVE lock wait to 30 s. PostgresOutboxStore binds and reads OffsetDateTime. BREAKING CHANGE: new migration 003 rewrites okapi_outbox on PostgreSQL under an ACCESS EXCLUSIVE lock; applied by hand it needs SET TIME ZONE to the okapi JVM zone first. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
- Document that a manual run needs a transaction (SET LOCAL is a no-op outside one), the cases where the in-app conversion uses the wrong zone, PostgreSQL 12+ for skipping the rewrite, and what really happens to 1.x pooled connections (prepared writes stay correct, a pre-prepared claim fails once). - Migration tests use a database each, close Liquibase, and cover a 1.x connection with statements server-prepared before 003 plus the 1.x read path. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
d105443 to
d4b16d2
Compare
…g on every poll (#131) (#146) Closes #131. Part of the 2.0.0 breaking-change set (labelled `critical` too). > **Stacked on #145** (#135, Postgres `TIMESTAMPTZ`), which is stacked on #144 (#138, MySQL `DATETIME`). The new `next_attempt_at` column uses the same time representation as those PRs. Merge them in order: #144, #145, then this one. ## Problem A retriable failure was retried on the **very next poll**. With the defaults (`interval` 1s, `max-retries` 5), an entry was attempted 6 times in about 6 s and then marked `FAILED`, which is terminal. So: - A short downstream outage dead-letters everything in flight. - Failing entries, always the oldest, are re-claimed first on every tick and delay healthy ones. - During an outage, every tick hits the failing endpoint with the full batch. ## Fix - **`next_attempt_at` / `OutboxEntry.nextAttemptAt`:** when a `PENDING` entry is next due. - `createPending` sets it to `createdAt`. - A retriable failure sets it to `now + RetryPolicy.backoff(retryNumber)`. - **`RetryPolicy`** gains `initialBackoff` (10s), `backoffMultiplier` (2.0), `maxBackoff` (10m) and `jitter` (0.2), all defaulted and `@JvmOverloads`, plus `backoff(retry, random)`. - Delay = `initial × multiplier^(n-1)`, capped, then shortened by up to `jitter` at random. - With the defaults, 5 retries cover about 5 minutes of outage instead of 6 seconds. - **Claim:** `RouteAwareOutboxStore.claimPending(types, limit, now)` returns only rows with `next_attempt_at <= now`, ordered by `(delivery_type, next_attempt_at, id)`. `now` comes from the processor's `Clock`, the same clock that computed the backoff, so database clock skew doesn't matter. - The new index on exactly those columns means the scan stops at `now`. Entries still backing off are never scanned or locked, however large the outage backlog. - Ordering by due time also removes the head-of-line blocking. - **Migration `004__retry_backoff`** (both databases) adds the column, backfills `PENDING` rows with `created_at`, and replaces 002's claim index. - **PostgreSQL:** the column is `NOT NULL DEFAULT CURRENT_TIMESTAMP`, so rows that 1.x instances insert during a rolling deploy stay claimable. This works without a table rewrite on PG 11+. The index goes in a separate `runInTransaction:false` changeset with `CREATE INDEX CONCURRENTLY`, dropping any invalid leftover first. - **MySQL:** the column is nullable (an `INSTANT` add on 8.0.12+), `lock_wait_timeout` is bounded, and the index is added and dropped `INPLACE, LOCK=NONE`. 1.x instances are already required to be stopped by #144, so the column needs no default. - **Spring:** new `okapi.processor.initial-backoff`, `backoff-multiplier`, `max-backoff` and `backoff-jitter` properties, validated at startup, with configuration metadata. - **Docs:** README (retry budget, ordering, properties table, migration list), CHANGELOG under *Changed (BREAKING)*, and UPGRADING. ## Breaking - **Retry timing:** retries are no longer immediate. - **API:** - `RetryPolicy`, `OutboxEntry` and `OutboxProcessorProperties` gained parameters, so Kotlin `copy`/default-argument callers must be recompiled. - `RouteAwareOutboxStore.claimPending` takes `now`. That interface is new in 2.0, so no released API changes there. - **Schema:** new migration 004. ## Out of scope The issue also suggests these. Both are additive, so they can ship in a minor release, and I'll open follow-ups: - a `requeueFailed` API or Actuator endpoint; - limiting retries by elapsed time. ## Tests - **`RetryPolicyTest`:** - exponential growth and the cap; - no overflow at retry 10 000; - jitter bounds, using a fixed random value and 1000 random samples; - the default retry window; - validation; - the entry processor scheduling `nextAttemptAt`. - **`RouteAwareOutboxProcessorTest`:** the processor passes its clock's `now` to the claim. - **Store contract tests (Postgres and MySQL):** - a not-yet-due entry isn't claimed until it is due; - a retried entry doesn't block a newer one; - `updateAfterProcessingBatch` persists `nextAttemptAt`; - end to end, a real processor and database with a controllable clock don't redeliver before the backoff and do redeliver right after it. - **Migration tests from #144 and #145:** they now also run 004. The Postgres rolling-deploy test inserts 1.x-style rows without the column after 004, and they are claimed. - **Retry-driving end-to-end tests** (`HttpEndToEndTest`, `ObservabilityEndToEndTest`) now use an explicit zero-backoff policy. - `./gradlew ktlintCheck test` passes locally, and `compileJmhKotlin` compiles. 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
… commits (#137) (#147) Closes #137. Part of the 2.0.0 breaking-change set. > Independent of the stacked schema PRs (#144 → #145 → #146), so it is based on `main`. It adds the same "From 1.x to 2.0.0" heading to `UPGRADING.md` as #144, which will be a trivial merge conflict for whichever lands second. ## Problem `OutboxProcessor.processNext` called `listener.onEntryProcessed` / `onBatchProcessed` right after `store.updateAfterProcessingBatch`, **inside the scheduler's transaction, before it commits**. When the commit then failed (connection loss, serialization failure, timeout): - The rows rolled back to `PENDING`. - `okapi.entries.delivered` and `okapi.entries.failed` had already been incremented, and they were incremented again on redelivery. - A custom listener could act on state that was never persisted. ## Fix - `OutboxProcessor.processBatch(limit)` claims, delivers and persists, then returns a `ProcessedBatch` without notifying anyone. - `OutboxProcessor.publishEvents(batch)` emits the entry events and then the batch event. - `OutboxScheduler` runs `processBatch` inside `runInTransaction` and `publishEvents` after it returns. Under the scheduler, events therefore describe committed state, and a batch whose commit fails emits nothing. - `processNext(limit)` keeps its signature and still notifies at once (`processBatch` + `publishEvents`), for callers that drive the processor themselves. Its KDoc says that inside a transaction those events come before the commit. - `onBatchProcessed`'s duration, and therefore `okapi.batch.duration`, now runs until the commit. - **Docs:** the KDoc of `OutboxProcessor`, `OutboxProcessorListener` and `OutboxScheduler`; the README metrics table and listener paragraph; a CHANGELOG entry under *Changed (BREAKING)*; an UPGRADING section. ## Breaking - **Listener timing:** under the scheduler, callbacks run after the commit, outside the processing transaction, and are skipped when the commit fails. A listener that relied on joining that transaction can't any more. - **Batch timer:** `okapi.batch.duration` includes the commit. ## Tests - `ListenerAfterCommitTest` (unit): - `processBatch` doesn't notify, and `publishEvents` does; - `processNext` still notifies at once; - the scheduler emits events only after the runner's "commit"; - a runner whose commit throws leads to no events over several ticks. - `ListenerAfterCommitEndToEndTest` (Postgres): the listener queries the row's status from a separate connection inside `onEntryProcessed` and must see `DELIVERED`, which proves the commit already happened. - **The test was checked against the fix:** with the old scheduler it fails with `expected:<DELIVERED> but was:<PENDING>`. - `./gradlew ktlintCheck test` passes locally. 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Closes #135. Part of the 2.0.0 breaking-change set.
Problem
created_at,updated_atandlast_attemptareTIMESTAMP WITHOUT TIME ZONE.PostgresOutboxStorebound them asjava.sql.Timestamp, which pgjdbc renders in the JVM default zone, so each row stored the writing JVM's local wall-clock time:Fix
003__timestamptz_columns:ALTER COLUMN … TYPE TIMESTAMPTZon all three columns.TimeZone. pgjdbc sets that to the JVM default zone, so when the bundled Liquibase changelog runs inside the application, values are read in the zone the application wrote them in.SET TIME ZONE '<JVM zone>'first. This is documented in the script, the README and UPGRADING.SET LOCAL lock_timeout = '30s'bounds the wait for theACCESS EXCLUSIVElock, so the lock queue can't stall every query on the table indefinitely. On timeout the migration fails and retries on the next start.LOCALscopes it to the changeset's transaction, so nothing leaks into a pooled connection.PostgresOutboxStorebinds and readsOffsetDateTime, so it is explicit about instants rather than relying on the JVM offset.Breaking
ACCESS EXCLUSIVElock. Unless the session zone is UTC, it also rewrites the table.SET TIME ZONEfirst.Rolling deploys
Unlike the MySQL change, a 1.x instance keeps working after the migration. pgjdbc sends a
Timestampwith the JVM's offset, andTIMESTAMPTZhonours that offset. A test covers this.Tests
PostgresTimestampColumnsTestruns the sharedTimestampColumnTestssuite:PostgresTimestamptzMigrationTest:./gradlew ktlintCheck testpasses locally.🤖 Generated with Claude Code