diff --git a/.env.example b/.env.example index 1e22f7d18..b91cf0b70 100644 --- a/.env.example +++ b/.env.example @@ -36,6 +36,10 @@ LOG_LEVEL=info # error | warn | info | debug | verbose # Console output format. Default: json in production (containers, log aggregators), # human-readable pretty otherwise. Force one with: json | pretty # LOG_FORMAT=pretty +# Process time zone. Left commented because the app reads nothing from it: stored timestamps are UTC +# on both databases (the PostgreSQL data connection pins its own session), so this only sets the zone +# log stamps and the "today" stats window are read in. The Docker image runs UTC. +# TZ=UTC # Auto-start previously authenticated sessions on server boot. Recommended `true` for a SINGLE-instance # production deployment so a crash-restart self-heals authenticated sessions; keep `false` if you run diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 7926c86ae..aa80ca99e 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -198,6 +198,9 @@ jobs: POSTGRES_USER: openwa POSTGRES_PASSWORD: openwa POSTGRES_DB: openwa + # initdb takes the server's default TimeZone from this, so the session pin has something to + # override. A UTC server would make the UTC-pin spec pass without the pin doing anything. + TZ: Asia/Jakarta ports: - 5432:5432 options: >- @@ -237,17 +240,23 @@ jobs: # database), that a paged message list has a total order (Postgres sorts a tie group # differently between two statements, so an unstable order drops rows from a page walk), and # that the data entities can build their own schema (raw SQL the ORM passes through verbatim, - # such as a partial index predicate, only case-folds on a real server). All four self-skip - # unless DATABASE_TYPE=postgres, so they are a no-op in the default test job and only execute - # here against the postgres:16 service. - - name: Postgres specs (FTS provider + boot-migration lock + list ordering + entity synchronize) + # such as a partial index predicate, only case-folds on a real server), and that the UTC pin + # holds across a backup round trip, a retention window and a local-midnight count. All five + # self-skip unless DATABASE_TYPE=postgres, so they are a no-op in the default test job and only + # execute here against the postgres:16 service. + # + # TZ is deliberately NOT UTC: the pin's whole job is to make a `timestamp` column mean the same + # instant on a host that runs in another zone, and on a UTC runner every assertion about it + # would pass for the wrong reason (the UTC-pin spec fails outright rather than pass vacuously). + - name: Postgres specs (FTS provider + boot-migration lock + list ordering + entity synchronize + UTC pin) # --runInBand: the specs issue DDL against the one shared service database, and jest's # default file-parallelism races their catalog writes (pg_type duplicate-key). The lock # spec's own two-migrator race is in-file (Promise.all) and unaffected by runInBand. The # synchronize spec additionally CREATEs and DROPs a scratch database of its own, which is # only safe serialized. - run: npx jest --runInBand src/database/migrations/__tests__/1782400000000-AddMessagesFts.pg.spec.ts src/database/migrations/__tests__/pg-boot-migrations.pg.spec.ts src/modules/message/message-list-ordering.pg.spec.ts src/database/migrations/__tests__/pg-entity-synchronize.pg.spec.ts + run: npx jest --runInBand src/database/migrations/__tests__/1782400000000-AddMessagesFts.pg.spec.ts src/database/migrations/__tests__/pg-boot-migrations.pg.spec.ts src/modules/message/message-list-ordering.pg.spec.ts src/database/migrations/__tests__/pg-entity-synchronize.pg.spec.ts src/database/postgres-utc.pg.spec.ts env: + TZ: Asia/Jakarta DATABASE_TYPE: postgres DATABASE_HOST: localhost DATABASE_PORT: '5432' diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml index e870e901d..d45542699 100644 --- a/.github/workflows/release.yml +++ b/.github/workflows/release.yml @@ -180,6 +180,9 @@ jobs: POSTGRES_USER: openwa POSTGRES_PASSWORD: openwa POSTGRES_DB: openwa + # Same as ci.yml: initdb takes the server's default TimeZone from this, so the data + # connection's session pin has something to override. + TZ: Asia/Jakarta ports: - 5432:5432 options: >- @@ -216,19 +219,22 @@ jobs: # Runtime-proves BuiltInFtsProvider on Postgres (websearch_to_tsquery + ts_headline against the # STORED body_ts tsvector), the boot-migration advisory lock (two concurrent migrators on one - # database), that a paged message list has a total order, and that the data entities can build + # database), that a paged message list has a total order, that the data entities can build # their own schema (raw SQL the ORM passes through verbatim, such as a partial index predicate, - # only case-folds on a real server). All four self-skip unless DATABASE_TYPE=postgres, so they - # are a no-op in the default test job and only execute here against the postgres:16 service. - - name: Postgres specs (FTS provider + boot-migration lock + list ordering + entity synchronize) + # only case-folds on a real server), and that the UTC pin holds across a backup round trip, a + # retention window and a local-midnight count. All five self-skip unless DATABASE_TYPE=postgres, + # so they are a no-op in the default test job and only execute here against the postgres:16 + # service. TZ is deliberately not UTC, for the reason ci.yml states. + - name: Postgres specs (FTS provider + boot-migration lock + list ordering + entity synchronize + UTC pin) # --runInBand: same reason the CI job passes it — both specs issue DDL against the one # shared service database, and jest's default file-parallelism races their catalog writes # (the first v0.19.0 tag failed this step on `relation "messages" already exists` over a # tree CI had passed minutes earlier). The lock spec's own two-migrator race is in-file # (Promise.all) and unaffected by runInBand. The synchronize spec additionally CREATEs and # DROPs a scratch database of its own, which is only safe serialized. - run: npx jest --runInBand src/database/migrations/__tests__/1782400000000-AddMessagesFts.pg.spec.ts src/database/migrations/__tests__/pg-boot-migrations.pg.spec.ts src/modules/message/message-list-ordering.pg.spec.ts src/database/migrations/__tests__/pg-entity-synchronize.pg.spec.ts + run: npx jest --runInBand src/database/migrations/__tests__/1782400000000-AddMessagesFts.pg.spec.ts src/database/migrations/__tests__/pg-boot-migrations.pg.spec.ts src/modules/message/message-list-ordering.pg.spec.ts src/database/migrations/__tests__/pg-entity-synchronize.pg.spec.ts src/database/postgres-utc.pg.spec.ts env: + TZ: Asia/Jakarta DATABASE_TYPE: postgres DATABASE_HOST: localhost DATABASE_PORT: '5432' diff --git a/CHANGELOG.md b/CHANGELOG.md index e84f4aec4..e2acd4eb2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,25 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Changed + +- The PostgreSQL data connection is pinned to UTC: parameters bind as UTC, naive timestamps read back as UTC, every pooled connection sets its session `TimeZone`, and boot fails when the effective zone is not UTC year round. + +### Fixed + +- Restoring a data archive into PostgreSQL from a gateway that does not run in UTC no longer shifts every timestamp by the host offset, and no longer shifts it again on each further restore ([#1624](https://github.com/rmyndharis/OpenWA/issues/1624)). +- Retention sweeps on PostgreSQL delete the rows their window names instead of taking up to the host's UTC offset of younger rows with them, and the `today` message counts cover the host's local day. +- Session leases on PostgreSQL compare as instants across nodes in different time zones and across a daylight-saving change. + +### Upgrade notes (behavior changes) + +- PostgreSQL deployments: the data connection issues `SET TIME ZONE 'UTC'` per connection and verifies the result at boot. A deployment where that cannot hold (a pooler that drops session state) now fails to start, naming the effective zone; set the default instead with `ALTER DATABASE "" SET TimeZone='UTC'`. SQLite deployments, and any gateway already running in UTC, are unaffected and no data moves. +- PostgreSQL deployments whose **gateway** ran outside UTC before this release: the twelve columns the app writes itself hold that host's local wall time and now read as UTC, so they appear shifted by the offset. They are `sessions.connectedAt`, `sessions.lastActiveAt`, `sessions.claimedAt`, `sessions.leaseExpiresAt`, `webhooks.lastTriggeredAt`, `webhook_outbox_events.lastAttemptAt`, `ingress_events.lastDispatchAt`, `message_batches.started_at`, `message_batches.completed_at`, `lid_mappings.updatedAt`, `chat_states.updatedAt` and `baileys_stored_messages.createdAt`. The last three carry a `DEFAULT now()` that never fires, because their only writer passes the value. With the gateway stopped, convert each with the host's old zone, which resolves daylight saving per row: `UPDATE sessions SET "connectedAt" = ("connectedAt" AT TIME ZONE 'Asia/Jakarta') AT TIME ZONE 'UTC' WHERE "connectedAt" IS NOT NULL;`. `claimedAt` and `leaseExpiresAt` are cluster runtime state: clear them, do not convert them, with every node stopped and before the first start on this release, or the lease reads shifted by the old offset and the session is unusable until it lapses. East of UTC it reads hours into the future, so every node treats the session as held elsewhere and `POST /sessions/{id}/start` answers `409`; west of UTC it reads already lapsed, so a peer can adopt a session that is still running. `UPDATE sessions SET "nodeId" = NULL, "claimedAt" = NULL, "leaseExpiresAt" = NULL, "nodeUrl" = NULL;`. Leaving `lid_mappings.updatedAt` and `chat_states.updatedAt` unconverted also mis-ranks the boot preload of both caches, which orders by that column under a cap. +- The remaining eighteen `createdAt`/`updatedAt` columns are written by PostgreSQL itself (`DEFAULT now()`) in the **server's** zone, not the gateway's. On a UTC server, which is the image default and what the bundled Compose file starts, they are already correct and must not be converted; convert them only if the server itself ran outside UTC, with the server's old zone. +- A table that has had an archive from a **SQLite** gateway restored into it holds those rows in correct UTC while the app wrote its own in local time. The two are indistinguishable within the column, so a blanket `UPDATE` would move the rows that are already right; correct such a column row by row against a known archive, or leave it as it is. +- An archive a **PostgreSQL** gateway outside UTC exported before this release is shifted the other way, and restoring it moved the whole table, `DEFAULT now()` columns included: the export read every value back through the local-time parser and the import bound the resulting ISO text into a column that drops the zone, so each restore took the table one offset backward. No row in such a table is correct, and the conversion above would move those rows a further offset the wrong way. Where the table holds nothing but restored rows, apply the inverse once per restore taken: `UPDATE sessions SET "createdAt" = ("createdAt" AT TIME ZONE 'UTC') AT TIME ZONE 'Asia/Jakarta';`. Where it also holds rows written after the restore, no blanket conversion is safe. +- Re-export after upgrading for an archive whose stamps are the instants they claim; restoring a pre-release archive carries its shift in as it is. + ## [0.23.5] - 2026-09-15 ### Security diff --git a/docker-compose.dev.yml b/docker-compose.dev.yml index b5857e463..a604cb4f5 100644 --- a/docker-compose.dev.yml +++ b/docker-compose.dev.yml @@ -44,6 +44,9 @@ services: # must match the image/entrypoint. Same convention as the production docker-compose.yml. environment: - NODE_ENV=${NODE_ENV:-development} + # Explicit for the same reason as the production compose file: the data is UTC either way, this + # only sets the zone the logs and the "today" stats window read in. + - TZ=${TZ:-UTC} - PORT=2785 - HOME=/tmp # Chromium reads its home from the passwd entry (no /home/openwa), so it needs writable, existing diff --git a/docker-compose.yml b/docker-compose.yml index ed008a12e..052d0a183 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -99,6 +99,10 @@ services: environment: # Core - NODE_ENV=${NODE_ENV:-production} + # The image already runs on UTC; stated here so it is a decision rather than an accident. Stored + # timestamps are UTC on either database whatever this says (the Postgres data connection pins its + # own session), so overriding it only moves log stamps and the local day the "today" stats count. + - TZ=${TZ:-UTC} # Writable HOME on tmpfs so Chromium's HOME-relative writes don't hit the read_only rootfs - HOME=/tmp # Chromium resolves its home from the passwd entry (no /home/openwa), ignoring $HOME, so without diff --git a/docs/05-database-design.md b/docs/05-database-design.md index 23abe4277..4d04ee131 100644 --- a/docs/05-database-design.md +++ b/docs/05-database-design.md @@ -170,6 +170,18 @@ connectedAt: Date | null; > [!NOTE] > Main DB entities (api_keys, audit_logs) use native SQLite `datetime` type since they always remain in SQLite. +#### Timestamps on PostgreSQL are UTC + +Every timestamp column on the PostgreSQL data connection is `timestamp without time zone`, which stores no zone: the value means whatever the writer intended. OpenWA pins that meaning to **UTC**, on the connection rather than on the deployment (`src/database/postgres-utc.ts`): + +- a JS `Date` parameter is bound as UTC (`parseInputDatesAsUTC`), so an app-written column such as `sessions.connectedAt` holds UTC wall-clock time whatever zone the host runs in; +- a naive timestamp is parsed back as UTC, through a parser registered for the scalar `timestamp` OID only (the `timestamp[]` OID keeps the driver's array parser; the schema has no such column); +- every pooled connection issues `SET TIME ZONE 'UTC'` on connect, through the pool's own connect hook so that a socket failure or a refused statement fails the acquire instead of the process. That is what makes the server-side `DEFAULT now()` behind each `@CreateDateColumn`/`@UpdateDateColumn` write UTC too. Boot reads the effective `TimeZone` back, at two instants six months apart so a zone that merely reads +00 in winter is caught, and fails if it is not UTC; a pin that a pooler or a server-side default overrode cannot pass unnoticed. + +Three `@CreateDateColumn`/`@UpdateDateColumn` columns are filled by the app rather than by that default: `lid_mappings.updatedAt`, `chat_states.updatedAt` and `baileys_stored_messages.createdAt` reach the database through an `upsert` that passes the value, so the default behind them never fires and they follow the binding rule above instead of the session zone. + +Comparisons therefore mean the same thing on both dialects: a retention `LessThan(cutoff)`, a lease deadline written by another node, and a backup restored from any host all line up. SQLite is unaffected; it already stores ISO text in UTC. + ## 5.2 Entity Relationship Diagram ```mermaid diff --git a/docs/10-devops-infrastructure.md b/docs/10-devops-infrastructure.md index ec3236277..7890468b9 100644 --- a/docs/10-devops-infrastructure.md +++ b/docs/10-devops-infrastructure.md @@ -275,9 +275,10 @@ volumes: > [13 - Horizontal Scaling Guide](./13-horizontal-scaling.md) for the full list and the design > sketch. What multi-node eventually buys is engine capacity, not shared engine state: live engine > handles live in exactly one process's `EngineRegistry` (`src/engine/engine-registry.service.ts`), -> and the hard requirements include a stable `NODE_ID` across restarts, NTP-synced clocks in one -> time zone without daylight saving (lease skew beyond the TTL wrongfully transfers a session), -> sticky sessions, `TRUSTED_PROXIES` for forwarded calls, Redis and Postgres. +> and the hard requirements include a stable `NODE_ID` across restarts, NTP-synced clocks (lease skew +> beyond the TTL wrongfully transfers a session; the zone each node runs in no longer matters, since +> the Postgres data connection is pinned to UTC), sticky sessions, `TRUSTED_PROXIES` for forwarded +> calls, Redis and Postgres. ### Helm Chart (Kubernetes) diff --git a/docs/11-operational-runbooks.md b/docs/11-operational-runbooks.md index 0ee84925b..86925a0dc 100644 --- a/docs/11-operational-runbooks.md +++ b/docs/11-operational-runbooks.md @@ -641,6 +641,13 @@ docker compose up -d curl -s -X POST -H "X-API-Key: " http://localhost:2785/api/auth/validate ``` +> **PostgreSQL restores are read as UTC.** From 0.23.6 the data connection binds, parses and defaults +> every timestamp in UTC, and refuses to boot when its session is not on UTC +> ([05 - Database Design](./05-database-design.md#timestamps-on-postgresql-are-utc)). A `database.sql` +> taken from a gateway that ran off UTC before 0.23.6 holds that host's local wall time in the columns +> the app wrote, so those rows read as shifted by the offset once restored. The 0.23.6 upgrade notes in +> `CHANGELOG.md` carry the conversion and name the columns it must not touch. + > `main.sqlite` carries the hashed API keys and audit log; `.api-key`, when retained by the original > installation, carries the plaintext bootstrap admin key. After restore, verify that both expected files > were present in the archive and that the client is using the original plaintext key. Re-running backup diff --git a/docs/13-horizontal-scaling.md b/docs/13-horizontal-scaling.md index a6d1ca068..50bafe9b7 100644 --- a/docs/13-horizontal-scaling.md +++ b/docs/13-horizontal-scaling.md @@ -76,15 +76,14 @@ > server images — and treat a skew larger than `SESSION_LEASE_TTL_MS` as a misconfiguration. > The status correction reads the same timestamps: a node whose clock runs more than three TTLs minus > one heartbeat ahead (160s at defaults) marks a healthy peer's sessions disconnected, even with -> `AUTO_START_SESSIONS` off, and nothing writes them back. On PostgreSQL the lease columns hold the -> writer's local wall time with no zone, so every node must run in one zone without daylight saving, -> `TZ=UTC` (the image default) being the simple choice; sharing a zone that observes daylight saving is -> not enough. Across zones the error runs both ways. A node east of a peer reads -> that peer's leases as expired by the offset, so it marks the peer's live sessions disconnected, and -> again after each of their status changes (with auto-start on, it also takes them over). A node west -> of a peer reads its leases as live for the offset, so a dead peer's sessions stay uncorrected and -> unadopted for that long. In a shared zone with daylight saving, a lease renewed in the last TTL -> before the clocks go back is stored an hour early, and peers mark that live session disconnected. +> `AUTO_START_SESSIONS` off, and nothing writes them back. The zone each node runs in is no longer +> part of this: on PostgreSQL the data connection binds, parses and defaults every timestamp in UTC +> ([05 - Database Design](./05-database-design.md#timestamps-on-postgresql-are-utc)), so two nodes in +> different zones, or one zone that observes daylight saving, still +> read each other's leases as the instants they were written at. Only the clocks have to agree. +> One exception, during an upgrade: a node still on 0.23.5 or earlier writes the lease in its own +> local wall time, so while versions are mixed the old cross-zone error above is back for as long as +> the older node keeps renewing. Running every node in `TZ=UTC` (the image default) removes it. > > **A forwarded request is throttled on both nodes.** The receiving node counts it before > forwarding, and the owner counts it again on arrival; with `REDIS_ENABLED=true` both counts land diff --git a/docs/14-migration-guide.md b/docs/14-migration-guide.md index e1d9f0380..95ad8bf91 100644 --- a/docs/14-migration-guide.md +++ b/docs/14-migration-guide.md @@ -186,6 +186,15 @@ curl -X POST 'http://localhost:2785/api/infra/import-data' \ > [!NOTE] > `skippedTables` lists optional tables absent from an older schema; the import tolerates them. +> [!NOTE] +> **Timestamps travel as UTC.** Every stamp in the archive is ISO 8601 with an explicit `Z`, and both +> dialects store it as the same instant, so an archive moves between SQLite and PostgreSQL in either +> direction without shifting and a repeated restore is a no-op. On PostgreSQL that is the connection's +> UTC pin ([05 - Database Design](./05-database-design.md#timestamps-on-postgresql-are-utc)), not a +> property of the host: a gateway restoring under `TZ=Asia/Jakarta` writes the same rows as one on UTC. +> An archive taken by 0.23.5 or earlier from a PostgreSQL gateway that ran off UTC carries that host's +> offset in its stamps; read the 0.23.6 upgrade notes in `CHANGELOG.md` before restoring one. + ### Storage Migration (Local ↔ S3/MinIO) OpenWA v0.2+ supports migrating media files between storage backends: diff --git a/src/database/data-source.ts b/src/database/data-source.ts index c1d02e1de..5b6070814 100644 --- a/src/database/data-source.ts +++ b/src/database/data-source.ts @@ -1,6 +1,7 @@ import { DataSource, DataSourceOptions } from 'typeorm'; import * as path from 'path'; import { loadCliEnv } from './load-cli-env'; +import { postgresUtcExtra } from './postgres-utc'; import { sqliteDataMainPathCollision } from '../config/env.validation'; // Load env with the same precedence as the app (process.env > .env > data/.env.generated), so the @@ -83,6 +84,9 @@ export function buildPostgresDataSourceOptions(env: NodeJS.ProcessEnv = process. } : false, extra: { + // Same UTC pin the runtime data connection carries (pg-boot-migrations.ts): a migration that + // rewrites a timestamp column must mean the same thing as the app that wrote it. + ...postgresUtcExtra(), max: parseInt(env.DATABASE_POOL_SIZE || '10', 10), // Pool resilience only. NO statement_timeout here: this connection runs migrations, and a // long CREATE INDEX / backfill must not be aborted mid-flight. diff --git a/src/database/pg-boot-migrations.spec.ts b/src/database/pg-boot-migrations.spec.ts index 741145adf..ad09c139c 100644 --- a/src/database/pg-boot-migrations.spec.ts +++ b/src/database/pg-boot-migrations.spec.ts @@ -8,6 +8,7 @@ import { POSTGRES_BOOT_MIGRATION_LOCK_KEYS, createBootDataSource, } from './pg-boot-migrations'; +import { postgresUtcExtra, utcTimestampTypes } from './postgres-utc'; // Protocol wiring of the boot-migration advisory lock: the lock must be taken BEFORE runMigrations // starts and dropped after it finishes (on success AND on migration failure), and the DataSource @@ -31,9 +32,16 @@ const PG_OPTIONS: DataSourceOptions = { describe('createBootDataSource (postgres boot migrations)', () => { // Fakes keep their inferred jest.Mock types (casts live only at the injection boundary) and // record every step in `calls`, so ordering is asserted on one linear trace. - function makeFakes(runMigrations: () => Promise = jest.fn()) { + function makeFakes(runMigrations: () => Promise = jest.fn(), sessionOffsetSeconds = 0) { const calls: string[] = []; const dataSource = { + // The UTC pin's boot assertion reads the session's effective zone. It is not part of the lock + // protocol these tests trace, so it stays out of `calls`. + query: jest.fn(() => + Promise.resolve([ + { zone: 'UTC', offset_seconds: sessionOffsetSeconds, offset_seconds_later: sessionOffsetSeconds }, + ]), + ), initialize: jest.fn(() => { calls.push('initialize'); return Promise.resolve(); @@ -100,9 +108,20 @@ describe('createBootDataSource (postgres boot migrations)', () => { await createBootDataSource(PG_OPTIONS, deps); - expect(deps.createDataSource).toHaveBeenCalledWith({ ...PG_OPTIONS, migrationsRun: false }); + expect(deps.createDataSource).toHaveBeenCalledWith({ + ...PG_OPTIONS, + migrationsRun: false, + // The UTC pin rides along with the pool settings the config already carries, rather than + // replacing them. + extra: { + ...(PG_OPTIONS.extra as Record), + types: utcTimestampTypes, + onConnect: postgresUtcExtra().onConnect, + }, + }); // The resolved config object itself is untouched — the flag stays as the built-in fallback. expect(PG_OPTIONS.migrationsRun).toBe(true); + expect(PG_OPTIONS.extra).toEqual({ statement_timeout: 30000, connectionTimeoutMillis: 10000 }); }); it('builds the lock client without a statement timeout (pg_advisory_lock must survive the wait)', async () => { @@ -284,6 +303,9 @@ describe('createBootDataSource (postgres boot migrations)', () => { const initialize = jest.spyOn(DataSource.prototype, 'initialize').mockImplementation(function (this: DataSource) { return Promise.resolve(this); }); + const query = jest + .spyOn(DataSource.prototype, 'query') + .mockResolvedValue([{ zone: 'UTC', offset_seconds: 0, offset_seconds_later: 0 }] as never); const runMigrations = jest.spyOn(DataSource.prototype, 'runMigrations').mockResolvedValue([]); const destroy = jest.spyOn(DataSource.prototype, 'destroy').mockResolvedValue(undefined); try { @@ -312,8 +334,22 @@ describe('createBootDataSource (postgres boot migrations)', () => { } finally { clientCtor.mockRestore(); initialize.mockRestore(); + query.mockRestore(); runMigrations.mockRestore(); destroy.mockRestore(); } }); + + it('refuses to migrate on a connection whose session is not on UTC', async () => { + // A pin that did not take (a pooler dropping the SET, a server-side default re-applied after it) + // would have the driver read every naive timestamp as UTC while the server keeps writing its own + // zone. Migrating on that connection would bake the mismatch into the data it rewrites. + const { calls, dataSource, deps } = makeFakes(jest.fn(), 25200); + + await expect(createBootDataSource(PG_OPTIONS, deps)).rejects.toThrow(/not on UTC/); + + expect(dataSource.runMigrations).not.toHaveBeenCalled(); + expect(deps.createLockClient).not.toHaveBeenCalled(); + expect(calls).toEqual(['initialize', 'destroy']); + }); }); diff --git a/src/database/pg-boot-migrations.ts b/src/database/pg-boot-migrations.ts index e3057208b..6699100d3 100644 --- a/src/database/pg-boot-migrations.ts +++ b/src/database/pg-boot-migrations.ts @@ -1,5 +1,6 @@ import { Client, ClientConfig } from 'pg'; import { DataSource, DataSourceOptions } from 'typeorm'; +import { assertDataConnectionUtc, postgresUtcExtra } from './postgres-utc'; // The postgres data connection runs its boot migrations while holding a session-scoped Postgres // advisory lock, so replicas that boot at the same time serialize instead of racing DDL against @@ -36,6 +37,9 @@ type PostgresOptions = Extract; * @nestjs/typeorm's default path: construct only, let the wrapper initialize as before. The * wrapper also skips its own initialize() for the postgres branch because the DataSource comes * back already initialized, and keeps applying retryAttempts/retryDelay to this whole factory. + * + * It is also where the postgres data connection's UTC pin is applied and then verified, for the same + * reason: this is the only place that connection is constructed at runtime. */ export async function createBootDataSource( options: DataSourceOptions | undefined, @@ -51,10 +55,19 @@ export async function createBootDataSource( } // This connection's migrations run HERE, under the lock — neutralize migrationsRun so the - // DataSource itself never starts them unsynchronized inside initialize(). - const dataSource = createDataSource({ ...options, migrationsRun: false }); + // DataSource itself never starts them unsynchronized inside initialize(). The UTC pin is merged in + // at the same point, because this is the one place the runtime postgres data connection is built + // (the migration CLI's own data source carries it directly). + const dataSource = createDataSource({ + ...options, + migrationsRun: false, + extra: { ...(options.extra as Record | undefined), ...postgresUtcExtra() }, + }); try { await dataSource.initialize(); + // Before any migration writes a row: a connection whose UTC pin did not take stores timestamps in + // one zone and reads them in another, which nothing downstream can detect (see postgres-utc.ts). + await assertDataConnectionUtc(dataSource); const lockClient = createLockClient(lockClientConfig(options)); try { await lockClient.connect(); @@ -95,6 +108,8 @@ function lockClientConfig(options: PostgresOptions): ClientConfig { ssl: options.ssl as ClientConfig['ssl'], // Bound a stuck connect like the pool does (app.module's extra carries the same setting). connectionTimeoutMillis: extra.connectionTimeoutMillis ?? 10000, + // No UTC pin here on purpose: this client only ever calls pg_advisory_lock/unlock, so it neither + // binds nor reads a timestamp and its session zone cannot reach a column. // This client's only statements are pg_advisory_lock/unlock, and statement_timeout applies to // ANY command — including the wait inside pg_advisory_lock — so it must be OFF here. A config // `statement_timeout: 0` would NOT do it: pg drops falsy values from the startup packet, so diff --git a/src/database/postgres-utc.pg.spec.ts b/src/database/postgres-utc.pg.spec.ts new file mode 100644 index 000000000..05e61f508 --- /dev/null +++ b/src/database/postgres-utc.pg.spec.ts @@ -0,0 +1,433 @@ +/* istanbul ignore file -- PG-gated: only runs under DATABASE_TYPE=postgres (test-postgres CI job); + skipped in the default test job, so its lines would be unread and skew the global coverage gate. */ +import 'reflect-metadata'; +import { DataSource, EntitySchema, LessThan } from 'typeorm'; +import type { ClientBase } from 'pg'; +import { assertDataConnectionUtc, postgresUtcExtra } from './postgres-utc'; +import { InfraDataService, sqliteDatetimeColumns, toSqliteDatetime } from '../modules/infra/infra-data.service'; +import { Session, SessionStatus } from '../modules/session/entities/session.entity'; +import { Webhook } from '../modules/webhook/entities/webhook.entity'; +import { Message, MessageDirection, MessageStatus } from '../modules/message/entities/message.entity'; +import { MessageBatch } from '../modules/message/entities/message-batch.entity'; +import { Template } from '../modules/template/entities/template.entity'; +import { BaileysStoredMessage } from '../engine/adapters/baileys-stored-message.entity'; +import { LidMapping } from '../engine/identity/lid-mapping.entity'; +import { ChatState } from '../engine/adapters/baileys-chat-state.entity'; +import { PluginInstance } from '../modules/integration/entities/plugin-instance.entity'; +import { ConversationMapping } from '../modules/integration/entities/conversation-mapping.entity'; +import { IngressEvent } from '../modules/integration/entities/ingress-event.entity'; +import { WebhookDeliveryFailure } from '../modules/webhook/entities/webhook-delivery-failure.entity'; +import { WebhookOutboxEvent } from '../modules/webhook/entities/webhook-outbox-event.entity'; +import { WebhookOutboxService } from '../modules/webhook/webhook-outbox.service'; +import { IntegrationDeliveryFailure } from '../modules/integration/entities/integration-delivery-failure.entity'; +import { StatusUpdate } from '../modules/status-store/entities/status-update.entity'; +import { AutomationRule } from '../modules/automation/entities/automation-rule.entity'; +import { StatsService } from '../modules/stats/stats.service'; +import type { MigrationTables } from '../modules/infra/migration-tables.types'; + +/** + * Runtime proof of the UTC pin against a real PostgreSQL, with the process deliberately OFF UTC. + * + * Off UTC the two halves of a row used to disagree: `DEFAULT now()` wrote the server's zone while the + * driver bound and parsed everything else in the process's zone, so a backup shifted by the offset on + * every restore and a retention window measured a cutoff that never happened. Everything here fails by + * exactly that offset if any one of the three pins (bind, parse, session) is removed. + * + * Gating: mirrors the repo's PG harness convention (DATABASE_TYPE=postgres, the "Test (PostgreSQL + * migrations)" CI job); the CI step additionally sets TZ, which the first test asserts rather than + * trusts, because on a UTC host every assertion below would hold for the wrong reason. + */ +const POSTGRES_ENABLED = process.env.DATABASE_TYPE === 'postgres'; + +// Fixed uuids: every primary key on this connection is a real uuid column. +const SESSION_ID = '11111111-1111-4111-8111-111111111111'; +const OLD_ID = '22222222-2222-4222-8222-222222222222'; +const YOUNG_ID = '33333333-3333-4333-8333-333333333333'; +const BEFORE_ID = '44444444-4444-4444-8444-444444444444'; +const AFTER_ID = '55555555-5555-4555-8555-555555555555'; + +/** An instant as the naive UTC text a pinned server writes into a `timestamp` column. */ +const utcWallText = (at: Date): string => at.toISOString().replace('T', ' ').replace('Z', ''); + +const ENTITIES = [ + Session, + Webhook, + Message, + MessageBatch, + Template, + BaileysStoredMessage, + LidMapping, + ChatState, + PluginInstance, + ConversationMapping, + IngressEvent, + WebhookDeliveryFailure, + WebhookOutboxEvent, + IntegrationDeliveryFailure, + StatusUpdate, + AutomationRule, +]; + +/** + * The `sessions` table as a SQLite deployment holds it: TypeORM's own `datetime` text for the + * create/update dates, and plain `text` for the columns DateTransformer writes as ISO. Spelled out + * rather than reusing the entity classes because those resolve their column types from DATABASE_TYPE + * at import time, which is `postgres` for this suite. + */ +const SqliteSession = new EntitySchema>({ + name: 'SqliteSession', + tableName: 'sessions', + columns: { + id: { primary: true, type: 'varchar' }, + name: { type: 'varchar' }, + status: { type: 'varchar' }, + phone: { type: 'varchar', nullable: true }, + pushName: { type: 'varchar', nullable: true }, + config: { type: 'text' }, + proxyUrl: { type: 'varchar', nullable: true }, + proxyType: { type: 'varchar', nullable: true }, + connectedAt: { type: 'text', nullable: true }, + lastActiveAt: { type: 'text', nullable: true }, + createdAt: { type: 'datetime', createDate: true }, + updatedAt: { type: 'datetime', updateDate: true }, + }, +}); + +(POSTGRES_ENABLED ? describe : describe.skip)('postgres UTC pin (real server, non-UTC process)', () => { + let ds: DataSource; + let sqlite: DataSource; + let infra: InfraDataService; + + const connectionOptions = { + host: process.env.DATABASE_HOST || 'localhost', + port: Number(process.env.DATABASE_PORT || 5432), + username: process.env.DATABASE_USERNAME || 'openwa', + password: process.env.DATABASE_PASSWORD || 'openwa', + database: process.env.DATABASE_NAME || 'openwa', + }; + + // exportData only reads dataDatabase.type; stats reads its memo TTL, which 0 disables so a second + // call re-queries instead of replaying the first answer. + const cfg = { + get: (key: string, def?: unknown) => + key === 'dataDatabase.type' ? 'postgres' : key === 'stats.cacheTtlMs' ? 0 : def, + }; + + beforeAll(async () => { + const admin = new DataSource({ type: 'postgres', ...connectionOptions }); + await admin.initialize(); + await admin.query('DROP SCHEMA IF EXISTS public CASCADE'); + await admin.query('CREATE SCHEMA public'); + await admin.destroy(); + + ds = new DataSource({ + type: 'postgres', + ...connectionOptions, + entities: ENTITIES, + synchronize: true, + extra: postgresUtcExtra(), + }); + await ds.initialize(); + infra = new InfraDataService(cfg as never, ds, undefined, undefined, undefined, undefined); + + sqlite = new DataSource({ type: 'better-sqlite3', database: ':memory:', entities: [SqliteSession] }); + await sqlite.initialize(); + await sqlite.synchronize(); + }, 120_000); + + afterAll(async () => { + if (ds?.isInitialized) await ds.destroy(); + if (sqlite?.isInitialized) await sqlite.destroy(); + }); + + beforeEach(async () => { + await ds.query('DELETE FROM messages'); + await ds.query('DELETE FROM webhook_outbox_events'); + await ds.query('DELETE FROM sessions'); + await sqlite.query('DELETE FROM sessions'); + }); + + /** A session whose app-written columns hold a known instant; `createdAt` comes from DEFAULT now(). */ + const seedSession = async (id: string, connectedAt: Date): Promise => { + const repo = ds.getRepository(Session); + return repo.save( + repo.create({ + id, + name: `session-${id.slice(0, 8)}`, + status: SessionStatus.READY, + config: {}, + connectedAt, + lastActiveAt: connectedAt, + }), + ); + }; + + const rawSession = async (): Promise> => { + const rows: Array> = await ds.query( + 'SELECT "connectedAt"::text AS connected, "createdAt"::text AS created FROM sessions', + ); + return rows[0]; + }; + + it('runs off UTC, on a session pinned to UTC, over a schema with no timestamp[] column', async () => { + // Without a non-UTC process every assertion in this suite would pass for the wrong reason. + expect(new Date().getTimezoneOffset()).not.toBe(0); + + const session: Array<{ zone: string; offset_seconds: number }> = await ds.query( + `SELECT current_setting('TimeZone') AS zone, EXTRACT(TIMEZONE FROM now())::int AS offset_seconds`, + ); + expect(session[0].offset_seconds).toBe(0); + + // The parser override answers OID 1114 only. It would be unsafe if the schema held a `timestamp[]` + // column, whose OID (1115) keeps pg-types' array parser. + const arrays: unknown[] = await ds.query( + `SELECT table_name, column_name FROM information_schema.columns + WHERE table_schema = 'public' AND udt_name IN ('_timestamp', '_timestamptz')`, + ); + expect(arrays).toEqual([]); + }); + + it('accepts the pinned session and rejects a zone that only reads +00 half the year', async () => { + await expect(assertDataConnectionUtc(ds)).resolves.toBeUndefined(); + + // Europe/London is what a UK server default looks like behind a pooler that discards the + // per-connection SET: +00 from late October to late March, +01 the rest of the year. Sampling the + // offset once, at whatever instant boot happens to be, passes it for half the year and lets every + // DEFAULT now() run an hour ahead of what the driver reads back for the other half. + const london = new DataSource({ + type: 'postgres', + ...connectionOptions, + extra: { ...postgresUtcExtra(), onConnect: (c: ClientBase) => c.query("SET TIME ZONE 'Europe/London'"), max: 1 }, + }); + await london.initialize(); + try { + const sampled: Array<{ jan: number; jul: number }> = await london.query( + `SELECT EXTRACT(TIMEZONE FROM TIMESTAMPTZ '2026-01-15 12:00:00+00')::int AS jan, + EXTRACT(TIMEZONE FROM TIMESTAMPTZ '2026-07-15 12:00:00+00')::int AS jul`, + ); + expect([sampled[0].jan, sampled[0].jul]).toEqual([0, 3600]); + await expect(assertDataConnectionUtc(london)).rejects.toThrow(/TimeZone is "Europe\/London"/); + } finally { + await london.destroy(); + } + }); + + it('stores an app-bound create/update date as UTC wall clock, like any other column the app writes', async () => { + // These three read as `DEFAULT now()` columns from the schema, but nothing ever lets the default + // fire: their only writer passes the value. TypeORM's upsert puts an explicitly-valued update-date + // column in the ON CONFLICT overwrite list rather than emitting `= DEFAULT`, so the row carries the + // PROCESS's convention, not the server's. That is what decides whether an operator converting a + // pre-0.23.6 database has to touch them, so it is asserted here rather than read off TypeORM. + const at = new Date('2026-01-01T00:00:00.000Z'); + await ds.query('DELETE FROM lid_mappings'); + await ds.query('DELETE FROM chat_states'); + await seedSession(SESSION_ID, at); + + const lid = { lid: '55501', phone: '628111', sessionId: null, updatedAt: at }; + const chat = { sessionId: SESSION_ID, chatId: '628111@c.us', archived: false, pinned: false, updatedAt: at }; + const stored = { sessionId: SESSION_ID, waMessageId: 'WA1', serializedMessage: '{}', createdAt: at }; + await ds.getRepository(LidMapping).upsert(lid, ['lid']); + await ds.getRepository(ChatState).upsert(chat, ['sessionId', 'chatId']); + await ds.getRepository(BaileysStoredMessage).upsert(stored, ['sessionId', 'waMessageId']); + + const text = async (table: string, column: string): Promise => { + const rows: Array<{ t: string }> = await ds.query(`SELECT "${column}"::text AS t FROM ${table}`); + return rows[0].t; + }; + // The host's wall clock would read 2026-01-01 07:00:00 here. + expect(await text('lid_mappings', 'updatedAt')).toBe('2026-01-01 00:00:00'); + expect(await text('chat_states', 'updatedAt')).toBe('2026-01-01 00:00:00'); + expect(await text('baileys_stored_messages', 'createdAt')).toBe('2026-01-01 00:00:00'); + }); + + it('stores what the app wrote and the server defaulted in the same zone', async () => { + const connectedAt = new Date('2026-01-01T00:00:00.000Z'); + await seedSession(SESSION_ID, connectedAt); + + const raw = await rawSession(); + // The app-written column is UTC wall clock, not the host's +07:00 wall clock. + expect(raw.connected).toBe('2026-01-01 00:00:00'); + // And the server-written one agrees with the process's own idea of now, within the test's runtime. + const created = new Date(`${raw.created?.replace(' ', 'T')}Z`).getTime(); + expect(Math.abs(created - Date.now())).toBeLessThan(60_000); + + const read = await ds.getRepository(Session).findOneByOrFail({ id: SESSION_ID }); + expect(read.connectedAt?.toISOString()).toBe('2026-01-01T00:00:00.000Z'); + }); + + it('carries every timestamp through export and two restores unchanged', async () => { + const connectedAt = new Date('2026-01-01T00:00:00.000Z'); + await seedSession(SESSION_ID, connectedAt); + // Instants, not raw text: an archive carries ISO milliseconds, so the microseconds `now()` writes + // are rounded off by the first restore. That rounding is bounded at one millisecond and never + // compounds; a zone shift is what this asserts against. + const stamps = async (): Promise> => { + const row = await ds.getRepository(Session).findOneByOrFail({ id: SESSION_ID }); + return { connected: row.connectedAt?.getTime(), created: row.createdAt.getTime() }; + }; + const before = await stamps(); + expect(before.connected).toBe(connectedAt.getTime()); + expect(Math.abs((before.created ?? 0) - Date.now())).toBeLessThan(60_000); + + // The archive travels as JSON, which is where a Date becomes ISO text. + const first = JSON.parse(JSON.stringify(await infra.exportData())) as { tables: MigrationTables }; + expect(await infra.importData({ tables: first.tables })).toMatchObject({ imported: true, warnings: [] }); + expect(await stamps()).toEqual(before); + + // Restoring the restore is the shape that used to compound the shift once per round. + const second = JSON.parse(JSON.stringify(await infra.exportData())) as { tables: MigrationTables }; + expect(await infra.importData({ tables: second.tables })).toMatchObject({ imported: true, warnings: [] }); + expect(await stamps()).toEqual(before); + expect(first.tables.sessions[0].connectedAt).toBe('2026-01-01T00:00:00.000Z'); + // And the column still reads as UTC wall clock rather than the host's. + expect((await rawSession()).connected).toBe('2026-01-01 00:00:00'); + }); + + it('restores a SQLite-made archive onto postgres at the same instant', async () => { + // Written by a real SQLite data connection below, which is what a SQLite deployment's export holds: + // `datetime` text for the create/update dates, DateTransformer's ISO text for the rest. + const repo = sqlite.getRepository(SqliteSession); + await repo.save({ + id: SESSION_ID, + name: 'session-s1', + status: 'ready', + phone: null, + pushName: null, + config: '{}', + proxyUrl: null, + proxyType: null, + connectedAt: new Date('2026-01-01T00:00:00.000Z').toISOString(), + lastActiveAt: null, + }); + const archivedRows: Array> = await sqlite.query('SELECT * FROM sessions'); + const [archived] = archivedRows; + expect(archived.createdAt).toMatch(/^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}(\.\d{3})?$/); + + expect(await infra.importData({ tables: { sessions: [archived] } as never })).toMatchObject({ + imported: true, + warnings: [], + }); + + const restored = await ds.getRepository(Session).findOneByOrFail({ id: SESSION_ID }); + expect(restored.connectedAt?.toISOString()).toBe('2026-01-01T00:00:00.000Z'); + expect(restored.createdAt.getTime()).toBe( + new Date(`${(archived.createdAt as string).replace(' ', 'T')}Z`).getTime(), + ); + }); + + it('restores a postgres-made archive onto SQLite at the same instant', async () => { + const connectedAt = new Date('2026-01-01T00:00:00.000Z'); + await seedSession(SESSION_ID, connectedAt); + const created = (await ds.getRepository(Session).findOneByOrFail({ id: SESSION_ID })).createdAt; + + const archive = JSON.parse(JSON.stringify(await infra.exportData())) as { tables: MigrationTables }; + const row = archive.tables.sessions[0] as unknown as Record; + + // The two steps importData takes on a SQLite target, with its own helpers: normalise the archived + // `datetime` columns, then bind through the `$N` rewrite the SQLite path uses. + const datetimeColumns = sqliteDatetimeColumns(sqlite).get('sessions') ?? []; + expect(datetimeColumns).toContain('createdAt'); + const normalised = Object.fromEntries( + Object.entries(row).map(([key, value]) => [key, datetimeColumns.includes(key) ? toSqliteDatetime(value) : value]), + ); + await sqlite.query( + `INSERT INTO sessions (id, name, status, phone, "pushName", config, "proxyUrl", "proxyType", "connectedAt", "lastActiveAt", "createdAt", "updatedAt") + VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)`, + [ + normalised.id, + normalised.name, + normalised.status, + normalised.phone ?? null, + normalised.pushName ?? null, + normalised.config, + normalised.proxyUrl ?? null, + normalised.proxyType ?? null, + normalised.connectedAt ?? null, + normalised.lastActiveAt ?? null, + normalised.createdAt, + normalised.updatedAt, + ], + ); + + const storedRows: Array> = await sqlite.query( + 'SELECT "connectedAt", "createdAt" FROM sessions', + ); + const [stored] = storedRows; + expect(stored.connectedAt).toBe('2026-01-01T00:00:00.000Z'); + expect(new Date(`${stored.createdAt.replace(' ', 'T')}Z`).getTime()).toBe(created.getTime()); + }); + + it('deletes exactly the rows a retention window names', async () => { + const outbox = ds.getRepository(WebhookOutboxEvent); + const hoursFromCutoff = (hours: number): string => + // Written the way `DEFAULT now()` writes it on a pinned server, so this measures the cutoff the + // service binds against a stored value the app did not bind. + utcWallText(new Date(Date.now() - 7 * 24 * 60 * 60 * 1000 + hours * 60 * 60 * 1000)); + for (const [id, createdAt] of [ + // Both sit within the host's +07:00 offset of the 7-day cutoff, so a cutoff bound in the wrong + // zone takes the younger one with it: silent data loss, not a late delete. + [OLD_ID, hoursFromCutoff(-3)], + [YOUNG_ID, hoursFromCutoff(3)], + ]) { + await ds.query( + `INSERT INTO webhook_outbox_events (id, "webhookId", "sessionId", event, "idempotencyKey", "deliveryId", payload, state, attempts, "createdAt") + VALUES ($1, $2, $3, 'message.received', $4, $5, '{}', 'delivered', 1, $6)`, + [id, SESSION_ID, SESSION_ID, `key-${id}`, `del-${id}`, createdAt], + ); + } + + const pruned = await new WebhookOutboxService(outbox).pruneSettled(7); + + expect(pruned).toBe(1); + expect((await outbox.find()).map(saved => saved.id)).toEqual([YOUNG_ID]); + }); + + it('counts a day of messages from the local midnight the host means', async () => { + await seedSession(SESSION_ID, new Date('2026-01-01T00:00:00.000Z')); + const messages = ds.getRepository(Message); + const localMidnight = new Date(); + localMidnight.setHours(0, 0, 0, 0); + // Stored as the server writes `createdAt` (DEFAULT now() on a pinned session), one minute either + // side of the host's local midnight. + for (const [id, offsetMs] of [ + [BEFORE_ID, -60_000], + [AFTER_ID, 60_000], + ] as Array<[string, number]>) { + await ds.query( + `INSERT INTO messages (id, "sessionId", "chatId", "from", "to", body, type, direction, status, "createdAt") + VALUES ($1, $2, '628111@c.us', 'me@c.us', '628111@c.us', 'hi', 'text', $3, $4, $5)`, + [ + id, + SESSION_ID, + MessageDirection.OUTGOING, + MessageStatus.SENT, + utcWallText(new Date(localMidnight.getTime() + offsetMs)), + ], + ); + } + + const stats = new StatsService( + ds.getRepository(Session), + messages, + { setSessionsStats: () => Promise.resolve(undefined) } as never, + cfg as never, + ); + + expect((await stats.getOverview()).messages.today).toEqual({ sent: 1, received: 0 }); + }); + + it('keeps a lease comparison honest across the restore that carries it', async () => { + const repo = ds.getRepository(Session); + await seedSession(SESSION_ID, new Date('2026-01-01T00:00:00.000Z')); + const leaseExpiresAt = new Date(Date.now() + 60_000); + await repo.update({ id: SESSION_ID }, { nodeId: 'node-a', claimedAt: new Date(), leaseExpiresAt }); + + const archive = JSON.parse(JSON.stringify(await infra.exportData())) as { tables: MigrationTables }; + expect(await infra.importData({ tables: archive.tables })).toMatchObject({ imported: true, warnings: [] }); + + // The claim is live, so it must not read as lapsed after the restore that carried it. + expect(await repo.findOneBy({ id: SESSION_ID, leaseExpiresAt: LessThan(new Date()) })).toBeNull(); + const carried = await repo.findOneByOrFail({ id: SESSION_ID }); + expect(carried.leaseExpiresAt!.getTime()).toBeGreaterThanOrEqual(leaseExpiresAt.getTime()); + }); +}); diff --git a/src/database/postgres-utc.spec.ts b/src/database/postgres-utc.spec.ts new file mode 100644 index 000000000..7ce3a606d --- /dev/null +++ b/src/database/postgres-utc.spec.ts @@ -0,0 +1,240 @@ +import * as net from 'net'; +import { defaults as pgDefaults, Pool, types as pgTypes } from 'pg'; +import { DataSource } from 'typeorm'; +import { assertDataConnectionUtc, parseTimestampAsUtc, postgresUtcExtra, utcTimestampTypes } from './postgres-utc'; +import { buildPostgresDataSourceOptions } from './data-source'; + +// pg serialises a bound parameter through this module-level helper; there is no per-client seam, so +// this is where the input half of the pin is observable without a server. +// eslint-disable-next-line @typescript-eslint/no-require-imports +const { prepareValue } = require('pg/lib/utils') as { prepareValue: (value: unknown) => unknown }; + +/** + * Just enough of the wire protocol to get a real pg pool past connect and up to its first statement, + * which on a pinned pool is the `SET TIME ZONE`. Both failure modes the pin has to survive are server + * behaviour, so they are served by a real socket rather than a stubbed client: the pool's own connect + * path is the thing under test. + */ +const frame = (type: string, body: Buffer): Buffer => { + const header = Buffer.alloc(5); + header.write(type, 0, 'ascii'); + header.writeInt32BE(body.length + 4, 1); + return Buffer.concat([header, body]); +}; +const AUTHENTICATION_OK = frame('R', Buffer.alloc(4)); // int32 0 = AuthenticationOk +const READY_FOR_QUERY = frame('Z', Buffer.from('I', 'ascii')); +const errorResponse = (message: string): Buffer => { + const field = (code: string, value: string): Buffer => + Buffer.concat([Buffer.from(code, 'ascii'), Buffer.from(value, 'utf8'), Buffer.from([0])]); + return frame( + 'E', + Buffer.concat([ + field('S', 'ERROR'), + field('V', 'ERROR'), + field('C', '0A000'), + field('M', message), + Buffer.from([0]), + ]), + ); +}; +const SIMPLE_QUERY = 0x51; // 'Q' + +interface FakeServer { + port: number; + queries: string[]; + openSockets: () => number; + close: () => Promise; +} + +/** Accepts a connection, then either cuts the socket or refuses the first statement it receives. */ +const startFakeServer = async (onFirstQuery: 'cut' | 'refuse'): Promise => { + const sockets = new Set(); + const queries: string[] = []; + const server = net.createServer(socket => { + sockets.add(socket); + socket.on('close', () => sockets.delete(socket)); + socket.on('error', () => undefined); + socket.on('data', chunk => { + if (chunk[0] !== SIMPLE_QUERY) { + socket.write(Buffer.concat([AUTHENTICATION_OK, READY_FOR_QUERY])); // startup packet + return; + } + queries.push(chunk.subarray(5, chunk.length - 1).toString('utf8')); + if (onFirstQuery === 'cut') socket.destroy(); + else socket.write(Buffer.concat([errorResponse('SET TIME ZONE is not supported'), READY_FOR_QUERY])); + }); + }); + await new Promise(resolve => server.listen(0, '127.0.0.1', resolve)); + return { + port: (server.address() as net.AddressInfo).port, + queries, + openSockets: () => sockets.size, + close: () => new Promise(resolve => server.close(() => resolve())), + }; +}; + +/** One acquire against a fake server, with the process's own uncaught-exception handlers stood aside. */ +const acquireThrough = async (fake: FakeServer): Promise<{ rejection?: string; uncaught: Error[] }> => { + const uncaught: Error[] = []; + const installed = process.listeners('uncaughtException'); + process.removeAllListeners('uncaughtException'); + process.on('uncaughtException', error => uncaught.push(error)); + + const pool = new Pool({ + host: '127.0.0.1', + port: fake.port, + user: 'openwa', + database: 'openwa', + connectionTimeoutMillis: 5000, + ...postgresUtcExtra(), + }); + pool.on('error', () => undefined); + let rejection: string | undefined; + try { + (await pool.connect()).release(); + } catch (error) { + rejection = (error as Error).message; + } + // An unhandled 'error' event lands a turn after the acquire settles. + await new Promise(resolve => setTimeout(resolve, 100)); + + process.removeAllListeners('uncaughtException'); + for (const listener of installed) process.on('uncaughtException', listener as never); + await pool.end().catch(() => undefined); + return { rejection, uncaught }; +}; + +describe('postgres UTC pin', () => { + const originalInputPin = pgDefaults.parseInputDatesAsUTC; + + afterEach(() => { + pgDefaults.parseInputDatesAsUTC = originalInputPin; + }); + + describe('reading', () => { + it('reads a naive timestamp as UTC, not as host-local time', () => { + expect((parseTimestampAsUtc('2026-01-01 00:00:00') as Date).toISOString()).toBe('2026-01-01T00:00:00.000Z'); + expect((parseTimestampAsUtc('2026-01-01 00:00:00.123456') as Date).toISOString()).toBe( + '2026-01-01T00:00:00.123Z', + ); + // The stock parser is what the shift looked like: the same text read as the PROCESS's wall + // clock, which off UTC is a different instant. Stated against the host's own zone rather than a + // fixed offset, because a jest worker cannot choose its zone: jest hands the test a COPY of + // process.env, so assigning TZ there never reaches the runtime's timezone cache. The genuinely + // off-UTC case is postgres-utc.pg.spec.ts, whose CI step sets TZ on the process itself. + const stock = pgTypes.getTypeParser(1114, 'text') as (value: string) => Date; + expect(stock('2026-01-01 00:00:00').getTime()).toBe(new Date(2026, 0, 1, 0, 0, 0).getTime()); + }); + + it('leaves text the zoned parser cannot read to the stock parser', () => { + const stock = pgTypes.getTypeParser(1114, 'text') as (value: string) => unknown; + for (const value of ['infinity', '-infinity', '0044-03-15 12:00:00 BC']) { + expect(parseTimestampAsUtc(value)).toEqual(stock(value)); + } + }); + + it('answers only the scalar text OID and leaves the timestamp[] parser alone', () => { + // `_timestamp`, which holds pg-types' ARRAY parser. Handing back the scalar parser here would + // turn `{"2026-01-01 00:00:00"}` into a single unparseable value. Typed as a plain number + // because pg's typings enumerate the OIDs they know and this is not one of them. + const timestampArrayOid: number = 1115; + + expect(utcTimestampTypes.getTypeParser(1114, 'text')).toBe(parseTimestampAsUtc); + expect(utcTimestampTypes.getTypeParser(1114)).toBe(parseTimestampAsUtc); + expect(utcTimestampTypes.getTypeParser(timestampArrayOid, 'text')).toBe( + pgTypes.getTypeParser(timestampArrayOid, 'text'), + ); + expect(utcTimestampTypes.getTypeParser(1114, 'binary')).toBe(pgTypes.getTypeParser(1114, 'binary')); + expect(utcTimestampTypes.getTypeParser(1184, 'text')).toBe(pgTypes.getTypeParser(1184, 'text')); + }); + }); + + describe('writing', () => { + it('binds a Date as UTC once the pin is applied', () => { + const at = new Date('2026-01-01T00:00:00.000Z'); + // Back to pg's own default first: importing the data source above already applied the pin, and + // the point of this test is the difference between the two. Unpinned, pg writes the parameter as + // the PROCESS's wall clock, so the naive text a `timestamp` column receives follows the host's + // zone; the instant it denotes is the same either way. + pgDefaults.parseInputDatesAsUTC = false; + expect(Date.parse(prepareValue(at) as string)).toBe(at.getTime()); + + postgresUtcExtra(); + + expect(pgDefaults.parseInputDatesAsUTC).toBe(true); + expect(prepareValue(at)).toBe('2026-01-01T00:00:00.000+00:00'); + }); + }); + + describe('wiring', () => { + it('pins every connection the migration CLI data source opens', () => { + const extra = buildPostgresDataSourceOptions({ DATABASE_TYPE: 'postgres' }).extra as { + types?: unknown; + onConnect?: unknown; + }; + expect(extra.types).toBe(utcTimestampTypes); + expect(extra.onConnect).toBe(postgresUtcExtra().onConnect); + expect(pgDefaults.parseInputDatesAsUTC).toBe(true); + }); + + it('fails the acquire, and not the process, when the socket dies during the pin', async () => { + // A failover or a pooler recycling the backend mid-statement. The pin runs inside the pool's own + // connect, so it must run with the pool's 'error' listener already attached: a client emitting + // 'error' with no listener is an uncaught exception, which takes the gateway down instead of + // rejecting one acquire. + const fake = await startFakeServer('cut'); + const { rejection, uncaught } = await acquireThrough(fake); + + expect(fake.queries).toEqual(["SET TIME ZONE 'UTC'"]); + expect(rejection).toBeTruthy(); + expect(uncaught).toEqual([]); + await fake.close(); + }); + + it('ends the connection when the server refuses the pin, instead of leaking a backend', async () => { + // What a pooler in statement mode answers. The client is fully connected by then, so an acquire + // that only reports the error leaves an authenticated backend open, once per acquire, until the + // server runs out of connections. + const fake = await startFakeServer('refuse'); + const { rejection, uncaught } = await acquireThrough(fake); + + expect(rejection).toContain('SET TIME ZONE is not supported'); + expect(uncaught).toEqual([]); + expect(fake.openSockets()).toBe(0); + await fake.close(); + }); + }); + + describe('boot assertion', () => { + const dataSourceReporting = (zone: string, offsetSeconds: number, laterOffsetSeconds = offsetSeconds): DataSource => + ({ + query: () => + Promise.resolve([{ zone, offset_seconds: offsetSeconds, offset_seconds_later: laterOffsetSeconds }]), + }) as unknown as DataSource; + + it('passes for any zone whose offset is zero year round', async () => { + await expect(assertDataConnectionUtc(dataSourceReporting('UTC', 0))).resolves.toBeUndefined(); + await expect(assertDataConnectionUtc(dataSourceReporting('Etc/UTC', 0))).resolves.toBeUndefined(); + await expect(assertDataConnectionUtc(dataSourceReporting('GMT', 0))).resolves.toBeUndefined(); + }); + + it('fails naming the zone when the session is not on UTC', async () => { + await expect(assertDataConnectionUtc(dataSourceReporting('Asia/Jakarta', 25200))).rejects.toThrow( + /TimeZone is "Asia\/Jakarta" \(offset 25200s now, 25200s in six months/, + ); + }); + + it('fails a daylight-saving zone that happens to read +00 right now', async () => { + // Europe/London, Europe/Lisbon and Atlantic/Canary sit at +00 from late October to late March. A + // boot in that window used to read offset 0 and report the pin as applied, and from the last + // Sunday in March every DEFAULT now() would then be written an hour ahead of what the driver + // reads back, with no restart in between to catch it. + await expect(assertDataConnectionUtc(dataSourceReporting('Europe/London', 0, 3600))).rejects.toThrow( + /TimeZone is "Europe\/London" \(offset 0s now, 3600s in six months/, + ); + await expect(assertDataConnectionUtc(dataSourceReporting('Europe/Lisbon', 3600, 0))).rejects.toThrow( + /TimeZone is "Europe\/Lisbon"/, + ); + }); + }); +}); diff --git a/src/database/postgres-utc.ts b/src/database/postgres-utc.ts new file mode 100644 index 000000000..3e6cfd78e --- /dev/null +++ b/src/database/postgres-utc.ts @@ -0,0 +1,132 @@ +import { ClientBase, defaults as pgDefaults, types as pgTypes } from 'pg'; +import { DataSource } from 'typeorm'; + +/** + * UTC pin for the PostgreSQL data connection. + * + * Every timestamp column on this connection is `timestamp without time zone`, which carries no zone at + * all: a stored value means whatever the writer's convention was. Three writers touch those columns and + * they did not agree. + * + * - the driver binds a JS Date as the PROCESS's local wall time (`sessions.connectedAt`, the lease + * columns, the pending-delivery stamps: every column the app itself writes), + * - the driver parses a naive timestamp back as PROCESS-local, + * - `DEFAULT now()`, which is what fills every `@CreateDateColumn`/`@UpdateDateColumn` (TypeORM does + * not bind those), writes the SERVER session's zone. + * + * Off UTC the row therefore carries two conventions at once, and comparisons that mix them are wrong by + * the offset: a retention `LessThan(cutoff)` binds the cutoff as local wall time and measures it against + * `createdAt` written in the server's zone. The same split is what shifts a backup on restore, because + * the archive's ISO text is bound as text and the server drops its zone. + * + * So the connection is pinned end to end: bind as UTC, parse as UTC, and hold the session on UTC. + */ + +/** `timestamp without time zone`. */ +const TIMESTAMP_OID = 1114; +/** `timestamp with time zone`, borrowed for its parser and never overridden. */ +const TIMESTAMPTZ_OID = 1184; + +const parseNaiveTimestamp = pgTypes.getTypeParser(TIMESTAMP_OID, 'text') as (value: string) => unknown; +const parseZonedTimestamp = pgTypes.getTypeParser(TIMESTAMPTZ_OID, 'text') as (value: string) => unknown; + +/** + * `YYYY-MM-DD HH:MM:SS[.ffffff]`, the only shape these columns hold. `infinity`, `-infinity` and a BC + * date reach the stock parser instead of having a zone appended to text it would not parse. + */ +const NAIVE_TIMESTAMP = /^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}(\.\d+)?$/; + +/** + * Read a naive timestamp as UTC, by handing it to the driver's own zoned parser with an explicit `+00` + * rather than re-implementing date parsing here. + */ +export function parseTimestampAsUtc(value: string): unknown { + return NAIVE_TIMESTAMP.test(value) ? parseZonedTimestamp(`${value}+00`) : parseNaiveTimestamp(value); +} + +/** + * The per-client parser table (pg wraps it in a `TypeOverrides` whose lookups fall through to here), so + * the override is scoped to the connections built from it instead of landing in + * `pg.types.setTypeParser`'s process-wide registry. + * + * ONLY the scalar OID is answered. The array form `_timestamp` (1115) holds pg-types' array parser, and + * answering it with a scalar parser would turn every `timestamp[]` read into garbage; the schema has no + * such column anyway (asserted in postgres-utc.pg.spec.ts), so it keeps the default parser and its + * elements keep the driver's local-time reading. + */ +export const utcTimestampTypes = { + getTypeParser(oid: number, format?: string): unknown { + if (oid === TIMESTAMP_OID && (format ?? 'text') === 'text') return parseTimestampAsUtc; + return pgTypes.getTypeParser(oid, format as Parameters[1]); + }, +}; + +const SET_SESSION_UTC = "SET TIME ZONE 'UTC'"; + +/** + * Pin a pooled session to UTC, through pg-pool's own connect hook. + * + * A statement on the connection itself, rather than the startup `options` parameter: `options` is not + * guaranteed to survive the path to the server (a pooler may drop it, and PgBouncer refuses the startup + * packet outright unless it is listed in `ignore_startup_parameters`), and on this connection it is + * already spoken for by the search_path of a non-public schema. pg-pool awaits this hook for every + * client it opens, the first one during `DataSource.initialize()` included, so none can start unpinned, + * and `connectionTimeoutMillis` still bounds the whole connect, the extra round trip included. + * + * The hook rather than a `Client` subclass that pins inside its own `connect`, because the pool owns two + * things a subclass cannot reach. It attaches the client's `error` listener BEFORE calling the hook, so + * a socket that dies during the statement (a failover, a pooler recycling the backend) fails the acquire + * instead of reaching Node as an unhandled `error` event, which ends the process. And it calls + * `client.end()` when the hook rejects, so a server that refuses the statement does not leave an + * authenticated backend open once per acquire until `max_connections` runs out. + */ +const pinSessionToUtc = (client: ClientBase): Promise => client.query(SET_SESSION_UTC); + +/** + * The `extra` block that pins a postgres data connection to UTC, for both entry points (the runtime + * module and the migration CLI data source). + * + * The input direction is a side effect rather than a returned value: pg serialises a bound Date through + * a module-level `prepareValue`, which reads this flag from the package defaults and has no per-client + * form. Setting it here keeps it next to the two halves it belongs with, and ahead of any connection + * built from the returned block. + */ +export function postgresUtcExtra(): { types: typeof utcTimestampTypes; onConnect: typeof pinSessionToUtc } { + pgDefaults.parseInputDatesAsUTC = true; + return { types: utcTimestampTypes, onConnect: pinSessionToUtc }; +} + +/** + * Fail boot when the data connection's session is not actually on UTC. + * + * The pin is only two thirds applied without this: the driver would keep reading every naive timestamp + * as UTC while `DEFAULT now()` kept writing the server's zone, so `createdAt` would be off by that + * offset in every retention window and every ordering, silently and permanently. The ways it can be + * left half-applied are real (a pooler that drops session state, a server-side default re-applied after + * the SET), so the effective setting is read back rather than assumed. + * + * The offset is what is checked, not the name: `UTC`, `Etc/UTC` and `GMT` are all correct, and a name + * check would fail a deployment that is already right. It is sampled at TWO instants six months apart, + * because a single reading of `now()` does not separate a fixed +00 zone from one that observes daylight + * saving: `Europe/London`, `Europe/Lisbon` and `Atlantic/Canary` all sit at +00 from late October to late + * March, so a winter boot would pass an unpinned session and every summer `now()` would then be written + * an hour ahead of what the driver reads back, with no restart in between to notice. The pair is taken + * relative to `now()` rather than at fixed calendar dates so it follows the zone's CURRENT rules. + */ +export async function assertDataConnectionUtc(dataSource: DataSource): Promise { + const effectiveZone: Array<{ zone: string; offset_seconds: number; offset_seconds_later: number }> = + await dataSource.query( + `SELECT current_setting('TimeZone') AS zone, + EXTRACT(TIMEZONE FROM now())::int AS offset_seconds, + EXTRACT(TIMEZONE FROM now() + interval '6 months')::int AS offset_seconds_later`, + ); + const [effective] = effectiveZone; + if (effective?.offset_seconds === 0 && effective.offset_seconds_later === 0) return; + throw new Error( + `PostgreSQL data connection is not on UTC: TimeZone is "${effective?.zone}" ` + + `(offset ${effective?.offset_seconds}s now, ${effective?.offset_seconds_later}s in six months; a zone that ` + + `observes daylight saving is not UTC even while it reads +00). OpenWA stores every timestamp column in UTC. ` + + `Set the server default to UTC (ALTER DATABASE "" SET TimeZone='UTC'), or let the connection's own ` + + `"SET TIME ZONE 'UTC'" through the pooler.`, + ); +}