The release gate that stopped 0.14.0: a Postgres bug that hid for two months

On 23 October we tagged 0.14.0. The release workflow ran its gates first, as it always does. One of them, the full suite against a real Postgres created with the en_US.utf8 collation, went red. The publish step needs the gates, so it never ran. Nothing reached npm.

We fixed the bug, moved the tag to the fixed commit and ran the release again. It went green, and all 27 public packages went out as 0.14.0 with provenance. The fix is in the 0.14.0 changelog.

The red test was D4 of the background-tool suite. Two processes share one store. One runs a long task for a person. The other erases that person while the task runs. Then the test checks that nothing is left: no runs, no owner records, and no messages in the person's thread.

About one run in ten, the thread's messages were still there. The runs and the owner records were gone. The erasure reported success. There was no error anywhere. Under the C collation the same test passed every time.

Every prefix lookup in the Postgres store is a range: key >= prefix AND key < prefix + U+FFFF. That is a prefix only under byte order. Under a linguistic collation like en_US.utf8, U+FFFF sorts as if it were not there, so the range matches nothing. We found that in August, and the fix was to add COLLATE "C" to these comparisons. The store does not hard-code it: when it boots, it asks the database how it compares strings and decides whether the clause is needed.

That decision lived in one shared object. The journal and the work store held a reference to it and read it when they built a statement. The problem was the order: a method built its SQL first, and only the statement it then sent waited for the boot. So in a process that had just started, the first prefix lookup was built while the shape was still empty.

/** Filled in by ensureReady's probe; shared BY REFERENCE with PgRunJournal (see PrefixShape). */
private prefixShape: PrefixShape = { collate: '' };

this.runs = new PgRunJournal(q, tx, this.prefixShape);

// in PgRunJournal
async listKeys(prefix: string, opts?: { limit?: number }): Promise<string[]> {
  const c = this.shape.collate;
  const rg = pgRange('key', c, prefix, 1);
  // ...
}

An empty collate is correct under C. Under en_US.utf8 it is exactly the bug from August: the range matches nothing, with no error. So a fresh process's first listKeys, readRange, owner lookup, run listing by id prefix, deletePrefix or deleteIdPrefix answered "none". Every later call was fine, because by then the boot had run. In D4, when the erasure was the first thing the erasing process did, the lookup that finds the person's thread came back empty, and the thread stayed.

The bug was born in the same commit that fixed the first collation bug, on 17 August. It took until 23 October to surface. Four things kept it quiet.

• Under C there is nothing to see. Our local Postgres is postgres:15-alpine, which starts with byte order. There, an empty collate is the right answer, so every local run passed.
• Only the first call in a process. Once anything had waited for the boot, the shape was filled in and every statement was correct. A store that was booted before it was asked anything never showed the bug.
• The test that exposes it is recent. D4 was added on 12 October. In it, a process that has just started erases a person, and sometimes that erasure is the first thing it does.
• We saw it once and fixed the wrong place. On 10 October, gnl upgrade on an en_US.utf8 database found no organizations, because an unbooted store's first listKeys matched nothing. We made the upgrade command boot the store before that step. The command was fixed. The store was not.

The stores no longer receive the shape. They receive settled: a function that waits for the boot and then returns the shape. Every method that builds a statement from it awaits it first.

type Settled = () => Promise<PrefixShape>;

const settled: Settled = () => this.ensureReady().then(() => this.prefixShape);
this.runs = new PgRunJournal(q, tx, settled);
this.work = new PgWorkStore(q, tx, settled);

// in PgRunJournal
async listKeys(prefix: string, opts?: { limit?: number }): Promise<string[]> {
  const shape = await this.settled();
  const c = shape.collate;
  const rg = pgRange('key', c, prefix, 1);
  // ...
}

The point is not the await itself. It is that a store can no longer reach the shape any other way, so no method can read it before the boot has run. The boot uses only the raw connection pool, so waiting for it from a store cannot wait on itself.

The new test creates its own en_US.utf8 database, whatever the server's default. A booted writer fills it. Then each case opens a fresh store that nothing has booted and makes exactly one call.

// A linguistic collation, whatever the server's default: this is the database the bug lives on.
await admin(`CREATE DATABASE ${NAME} ENCODING 'UTF8' LC_COLLATE 'en_US.utf8' LC_CTYPE 'en_US.utf8' TEMPLATE template0`);

/** A store over the same database that nothing has booted: no init, no call yet. */
const fresh = () => { const s = new PostgresStorage({ connectionString: url }); opened.push(s); return s; };

it('listKeys', async () => {
  expect(await (fresh().runs as any).listKeys('pfx-r1:')).toEqual(await (writer.runs as any).listKeys('pfx-r1:'));
});

it('countRuns by id prefix', async () => {
  expect(await (fresh().runs as any).countRuns({ runIdPrefix: 'pfx-' })).toBe(2);
});

Before the fix, 9 of its 10 cases failed. After, all 10 pass. D4 itself: 0 failures in 30 runs on Postgres after the fix, against about 1 in 10 before.

MySQL had the same shape. A thread's append lock is named after the database, which the boot reads. The name was built as an argument to the transaction, before the transaction waited for the boot.

// before
private lock(threadId: string): TxOptions {
  return { lock: { name: lockName('t', this.shared.db, threadId), timeoutS: THREAD_LOCK_WAIT_S, what: `thread '${threadId}'` } };
}

// after
private async lock(threadId: string): Promise<TxOptions> {
  const { db } = await this.settled();
  return { lock: { name: lockName('t', db, threadId), timeoutS: THREAD_LOCK_WAIT_S, what: `thread '${threadId}'` } };
}

So a fresh process's first append to a thread took a lock with a different name from every later append to that thread. Two writers to one thread were not serialized. The lock name is now built after the boot, and a test checks that the first and the second append take the same lock name. It failed before the fix and passes after.

This gate did not exist by accident. The release workflow does not list its own checks. It calls our CI workflow, so a release runs exactly the gates that main runs. That includes a matrix of real backends, with Postgres in two collations: C and en_US.utf8.

We set it up this way in August, after the first collation bug. A tag push does not trigger the main CI, so until then the publish path ran only a subset of our checks. The en_US.utf8 leg had covered every commit except the ones that ship. Now a red gate stops the release before npm.

Both collations stay. en_US.utf8 is what most managed Postgres gives you. C is what a self-hosted alpine image gives you, and a fix that only works under one would break the other.

A green CI on one collation told us nothing about this bug. The code was right for C and wrong for en_US.utf8, and only in the first call of a process. A test that fails one run in ten is easy to call flaky. This one was a real bug that left a person's messages behind after an erasure.

What we take from it: run the release on the real backends, in every configuration users actually have. Treat a rare failure as a bug until it is explained. When a bug is found at one call site, fix the thing every call site reads, not the call site.