Repository navigation
fix(mysql)!: store timestamps as UTC DATETIME(6) so the outbox survives 2038 (#138) - #144
Conversation
…es 2038 (#138) MySQL TIMESTAMP ends at 2038-01-19 03:14:07 UTC, after which every publish() fails. Changeset 003 converts created_at, updated_at and last_attempt to DATETIME(6) holding UTC, pinning the session time zone to UTC for the conversion and restoring it afterwards. MysqlOutboxStore binds and reads the columns as UTC LocalDateTime, which Connector/J passes through unconverted, so stored values no longer depend on the JVM, session or driver zone. BREAKING CHANGE: new migration 003 rebuilds okapi_outbox on MySQL and must be applied before starting updated workers; the columns now hold UTC wall-clock DATETIME values. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
rawo
left a comment
There was a problem hiding this comment.
The core of the fix looks right to me. Pinning time_zone = '+00:00' around MODIFY is the correct way to turn the TIMESTAMP instants into UTC wall-clock DATETIME values, and the migration test would fail without the pin. Binding and reading LocalDateTime makes stored values independent of the JVM, session and connectionTimeZone settings. All my comments are about the upgrade path and the docs. I didn't find a code bug.
Cross-cutting (should-fix, docs): existing rows may already be shifted before the migration runs. The migration keeps the stored TIMESTAMP instants. But 1.x could store wrong instants and still read them back correctly. With Connector/J defaults (connectionTimeZone=LOCAL, preserveInstants=true, no forceConnectionTimeZoneToSession), setTimestamp renders the instant in the JVM zone, and the server parses that literal in the session zone. Example: JVM Europe/Warsaw (+02:00), server/session UTC. 1.x writes 12:00Z as '14:00' and stores 14:00Z. 1.x reads it back through the reverse shift and sees 12:00Z. After 003 plus 2.0, the row reads as 14:00Z, two hours in the future. Effects on such a setup:
- old pending rows are claimed after newer ones until the offset passes (FIFO inversion);
- lag metrics are off, possibly negative;
- purging delivered rows is delayed by the offset.
This is the misconfiguration #138 describes, so it isn't rare. A sentence in UPGRADING would cover it: if the JVM zone differed from the MySQL session zone and connectionTimeZone wasn't set, drain the outbox before upgrading or accept the transient shift. A small UPDATE recipe is another option. I'm confident about the driver behaviour, but I haven't run this exact scenario.
Checked and fine:
- The changeset is safe to re-run after a crash between the
ALTERand the DATABASECHANGELOG insert:DATETIME→DATETIMEdoesn't shift values. MODIFYkeeps the indexes, so theFORCE INDEXclaims still find theirs. ComparingDATETIMEwith a boundLocalDateTimekeeps index use forremoveDeliveredBeforeon(status, last_attempt).TimeZone.setDefaultinTimestampColumnTestsis OK for now. No kotest/JUnit parallelism is configured.MysqlDataSourceopens a fresh connection perwithTransaction, so the driver really sees the changed default zone, and with the oldTimestampbinding the test would fail. If spec concurrency is ever enabled, this test needs isolation.- The CHANGELOG entry is under Unreleased → Changed (BREAKING), which is the right place.
Question: CI only covers mysql:8.0. The README says "MySQL 8+", and the Exposed runner mentions MariaDB. Has 003 been run on MySQL 8.4/9.x or MariaDB? The session-zone semantics of MODIFY should be the same there, but MariaDB's explicit_defaults_for_timestamp/ON UPDATE handling differs. A quick run would confirm that the defaults and the ON UPDATE behaviour end up dropped as intended.
| `TIMESTAMP(6)` to `DATETIME(6)` holding UTC. With the bundled Liquibase changelog it runs | ||
| automatically at startup; otherwise apply | ||
| [`003__datetime_columns.sql`](okapi-mysql/src/main/resources/com/softwaremill/okapi/db/mysql/003__datetime_columns.sql) | ||
| yourself, **including its `SET time_zone` statements**, before starting 2.0.0 workers. |
There was a problem hiding this comment.
should-fix (docs): say that 1.x instances must be stopped once 003 runs, not only that 2.0 must not start before it.
The Spring Boot autoconfig runs 003 when the first 2.0 instance starts. In a rolling deploy, 1.x instances are still publishing and claiming at that point. After the migration, 1.x still binds java.sql.Timestamp. Connector/J renders a Timestamp in connectionTimeZone (by default the JVM zone) and the DATETIME column stores that text unconverted. So with a non-UTC JVM, every row 1.x writes or updates in that window gets a local wall-clock value that 2.0 then reads as UTC. 1.x also misreads the rows 2.0 wrote. The wrong values stay in the table for good.
Suggest stating it here, in the README and in the CHANGELOG: either stop every 1.x instance before 003 runs (no rolling deploy across this version), or note that mixed operation is only safe when the 1.x JVMs run in UTC.
| yourself, **including its `SET time_zone` statements**, before starting 2.0.0 workers. | ||
|
|
||
| - The `ALTER TABLE` rebuilds `okapi_outbox` and blocks writes to it, including `publish()`, until | ||
| it finishes. Purge delivered rows first or schedule it for a quiet period on a large table. |
There was a problem hiding this comment.
should-fix (docs): "blocks writes until it finishes" understates it.
Changing a column's type is ALGORITHM=COPY, so the copy phase permits reads and blocks DML. Two more things matter more in practice:
- Before it can start, the
ALTERmust take a metadata lock, so it waits for every open transaction that has touchedokapi_outbox. That includes a 1.x worker that is holding its claim transaction open across an HTTP/Kafka delivery, and any business transaction that calledpublish()and hasn't committed yet. - While it waits in the MDL queue, every new statement on the table queues behind it, plain reads included: lag metrics,
publish(), everything. MySQL's defaultlock_wait_timeoutis one year, so with Liquibase at startup this can hang the deploy and the app's write path, not just slow it down.
FOR UPDATE SKIP LOCKED claims are blocked during the copy too, not just plain writes.
This is the MySQL counterpart of the CREATE INDEX CONCURRENTLY caveat the README already documents for Postgres 002. Suggest documenting it the same way: stop workers and let in-flight transactions finish. You could also put a bounded SET SESSION lock_wait_timeout = ... in the changeset (and restore it like time_zone) so a blocked migration fails fast instead of stalling the table. README L223 needs the same wording.
| - The `ALTER TABLE` rebuilds `okapi_outbox` and blocks writes to it, including `publish()`, until | ||
| it finishes. Purge delivered rows first or schedule it for a quiet period on a large table. | ||
| - Queries or dashboards that read these columns directly now get UTC wall-clock values, not values | ||
| converted to the session time zone. |
There was a problem hiding this comment.
should-fix (docs), related to the review body: besides direct readers, existing rows may themselves read back shifted after the upgrade. That happens when 1.x ran with JVM zone ≠ MySQL session zone and connectionTimeZone unset: 1.x stored shifted instants and hid the shift on read. Worth a bullet here, e.g. "drain the outbox first if your JVM and MySQL time zones differed".
| SET @okapi_previous_time_zone = @@session.time_zone; | ||
| SET time_zone = '+00:00'; | ||
|
|
||
| ALTER TABLE okapi_outbox |
There was a problem hiding this comment.
nit: 002 states its algorithm explicitly (ALGORITHM=INPLACE, LOCK=NONE). Adding ALGORITHM=COPY, LOCK=SHARED here would make the locking behaviour that the docs describe visible in the SQL. MySQL would also reject the statement instead of picking something else if that combination isn't possible. It doesn't change behaviour on 8.0.
| MODIFY updated_at DATETIME(6) NOT NULL, | ||
| MODIFY last_attempt DATETIME(6) NULL; | ||
|
|
||
| SET time_zone = @okapi_previous_time_zone; |
There was a problem hiding this comment.
nit: the restore only runs if the ALTER succeeds. If the ALTER fails (lock wait timeout, disk full during the copy), Liquibase stops at that statement, and the connection goes back to the pool still at +00:00. Low impact, because a failed changelog normally aborts startup and the pool goes with it. But the header comment reads as if the pooled connection is always restored. Maybe soften it to "restore it afterwards on success", or note that a failed run should be retried on a fresh connection.
| conn.createStatement().use { stmt -> | ||
| stmt.executeQuery( | ||
| "SELECT @@session.time_zone AS tz, DATA_TYPE AS t FROM information_schema.COLUMNS " + | ||
| "WHERE TABLE_NAME = 'okapi_outbox' AND COLUMN_NAME = 'created_at'", |
There was a problem hiding this comment.
nit: this only checks DATA_TYPE of created_at. Since the changeset also changes the defaults and nullability of all three columns, please assert for created_at, updated_at and last_attempt:
DATA_TYPE = 'datetime'andDATETIME_PRECISION = 6;IS_NULLABLE(onlylast_attemptis nullable);COLUMN_DEFAULT IS NULLand anEXTRAwith noon update(the CHANGELOG promises the defaults are dropped).
Also add TABLE_SCHEMA = DATABASE() to the filter. A wrong precision (e.g. DATETIME without (6)) would currently only show up indirectly, through the .25 assertion on created_at.
- Bound the metadata-lock wait of the ALTER with lock_wait_timeout = 30 and restore it, and make ALGORITHM=COPY, LOCK=SHARED explicit; the header comment now says settings are restored on success only. - Document that every 1.x instance must be stopped before 003 runs, that rows 1.x wrote while the JVM and MySQL session zones differed read back shifted (drain first), and the real locking behaviour, in UPGRADING, README and CHANGELOG. - The migration test checks type, precision, nullability, defaults and EXTRA of all three columns and that lock_wait_timeout is restored. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
|
Addressed the review in 65decfd:
|
…end on the JVM zone (#135) (#145) Closes #135. Part of the 2.0.0 breaking-change set. > **Stacked on #144** (#138, MySQL `DATETIME`). It reuses that PR's shared `TimestampColumnTests` suite and its 2.0.0 UPGRADING section. Merge #144 first, and GitHub then retargets this PR to `main`. ## Problem `created_at`, `updated_at` and `last_attempt` are `TIMESTAMP WITHOUT TIME ZONE`. `PostgresOutboxStore` bound them as `java.sql.Timestamp`, which pgjdbc renders in the **JVM default zone**, so each row stored the writing JVM's local wall-clock time: - **Fleets with JVMs in different zones** get claim order, the lag gauge and the purge cutoff skewed by hours. - **DST fall-back:** two different instants are stored as the same value and read back an hour off. ## Fix - **Migration `003__timestamptz_columns`:** `ALTER COLUMN … TYPE TIMESTAMPTZ` on all three columns. - Postgres converts each existing value using the **session** `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. - Anyone applying the script by hand must run `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 the `ACCESS EXCLUSIVE` lock, so the lock queue can't stall every query on the table indefinitely. On timeout the migration fails and retries on the next start. `LOCAL` scopes it to the changeset's transaction, so nothing leaks into a pooled connection. - **`PostgresOutboxStore`** binds and reads `OffsetDateTime`, so it is explicit about instants rather than relying on the JVM offset. - **Docs:** the README migration list, a CHANGELOG entry under *Changed (BREAKING)*, and an UPGRADING section. That section covers manual application, fleets that ran in mixed zones (drain the outbox first), locking, and why a rolling deploy is safe. ## Breaking - The migration takes an `ACCESS EXCLUSIVE` lock. Unless the session zone is UTC, it also rewrites the table. - Applying it by hand requires `SET TIME ZONE` first. ## Rolling deploys Unlike the MySQL change, a 1.x instance keeps working after the migration. pgjdbc sends a `Timestamp` with the JVM's offset, and `TIMESTAMPTZ` honours that offset. A test covers this. ## Tests - `PostgresTimestampColumnsTest` runs the shared `TimestampColumnTests` suite: - values past 2038; - the purge cutoff; - a value written with JVM zone Europe/Warsaw and session zone Asia/Kolkata, at a DST fall-back instant, is stored as UTC and reads back correctly under America/Los_Angeles. - **The suite was checked against the fix:** against the old schema and binding, two of its three tests fail (on this machine's non-UTC JVM). - `PostgresTimestamptzMigrationTest`: - **Upgrade path:** with the JVM at Asia/Tokyo, apply 001+002, write a row exactly as 1.x did, apply 003, and check that the instants are unchanged. - **Mixed versions:** a 1.x-style write from an America/New_York JVM after 003 reads back as the correct instant. - `./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>
…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 #138. Part of the 2.0.0 breaking-change set.
Problem
The MySQL schema uses
TIMESTAMP(6)forcreated_at,updated_atandlast_attempt.TIMESTAMPends at2038-01-19 03:14:07 UTC. After that, everypublish()fails under strict mode, and with it every business transaction that publishes.Fix
003__datetime_columnsconverts the three columns toDATETIME(6), which holds UTC.ALTER … MODIFYconverts existingTIMESTAMPvalues through the session time zone. So the changeset pinstime_zone = '+00:00'for the conversion and then restores the previous value: Liquibase may run on a pooled connection that the app reuses.CURRENT_TIMESTAMPcolumn defaults are dropped. okapi always writes these columns, and aDATETIMEdefault would be in session-local time.MysqlOutboxStorebinds and reads these columns as UTCLocalDateTimeinstead ofjava.sql.Timestamp. Connector/J passesLocalDateTimethrough unconverted, while aTimestampis shifted by the JVM zone orconnectionTimeZone. Stored values are therefore UTC regardless of JVM, session or driver settings, so noconnectionTimeZone/preserveInstantsconfiguration is needed (the issue suggested requiring that).UPGRADING.md.Breaking
okapi_outbox, and writes to it, includingpublish(), wait for it. It must be applied before starting 2.0.0 workers.DATETIMEvalues.Tests
TimestampColumnTests: a shared suite, which Postgres (Postgres: TIMESTAMP WITHOUT TIME ZONE + java.sql.Timestamp stores JVM-local time; mixed-TZ fleets/DST corrupt ordering, lag, purge #135) will reuse. It runs here throughMysqlTimestampColumnsTest:Europe/Warsawand session zone+05:00(at a DST fall-back instant) is stored as UTC, and reads back correctly underAmerica/Los_Angeles.MysqlDatetimeMigrationTest, the upgrade path:+05:00and inserts a row through the oldTIMESTAMPcolumns;datetime, and the session zone is restored to+05:00../gradlew ktlintCheck testpasses locally.🤖 Generated with Claude Code