diff --git a/backend/tests/integration/setup/globalSetup.ts b/backend/tests/integration/setup/globalSetup.ts index 83ff035..fbdd4c6 100755 --- a/backend/tests/integration/setup/globalSetup.ts +++ b/backend/tests/integration/setup/globalSetup.ts @@ -23,9 +23,52 @@ async function waitForDb(retries = 20): Promise { ); } +/** + * Every address the database host resolves to, and which server answered (#154). + * + * This is the measurement that issue has needed twice and never had. The + * schema in a failing run comes back — a suite fails on a missing `orders`, + * and a later suite truncating that same table passes — which a database + * losing its schema cannot do. More than one server answering to one name can, + * and Docker's embedded DNS round-robins every container sharing an alias, so + * a leftover service container from an earlier run fits every observation + * including the empty `dmesg`. + * + * **More than one address printed here is the answer outright.** One address, + * and this reading is wrong too — the next suspect is a single container being + * restarted with a fresh data directory, which the postmaster start time + * recorded alongside will show. + * + * Logged unconditionally rather than only on failure: a passing run's addresses + * are the control, and without them a failing run's have nothing to be compared + * against. Never throws — a diagnostic that can fail the run it was added to + * explain is worse than none. + */ +async function reportDatabaseIdentity(): Promise { + const host = process.env.TEST_PGHOST || 'localhost'; + try { + const { lookup } = await import('dns/promises'); + const addresses = await lookup(host, { all: true }); + const rendered = addresses.map((a) => a.address).join(', '); + console.info( + `[#154] "${host}" resolves to ${addresses.length} address(es): ${rendered}` + + (addresses.length > 1 ? ' <-- more than one server can answer; this is the bug' : '') + ); + } catch (err) { + console.info(`[#154] could not resolve "${host}": ${err instanceof Error ? err.message : String(err)}`); + } +} + export default async function globalSetup(): Promise { await waitForDb(); - const { migrate, closeDb, assertSchemaPresent } = await import('./testDb'); + const { migrate, closeDb, assertSchemaPresent, describeBackend } = await import('./testDb'); + + await reportDatabaseIdentity(); + // Recorded before migrating so the run's baseline is in the log even if the + // migration is the thing that fails. A suite that later reports a different + // postmaster start time is talking to a different instance. + console.info(`[#154] ${await describeBackend('globalSetup reached')}`); + await migrate(); // Cheap, once, and it establishes the fact the rest of the run depends on: diff --git a/backend/tests/integration/setup/testDb.ts b/backend/tests/integration/setup/testDb.ts index 98018a5..bf30b09 100755 --- a/backend/tests/integration/setup/testDb.ts +++ b/backend/tests/integration/setup/testDb.ts @@ -75,21 +75,68 @@ async function missingTables(): Promise { * can be fixed from here: whatever the cause, the next occurrence should read as * "the database lost its schema" on the first line. */ +/** + * Which Postgres actually answered, rather than which one we asked for (#154). + * + * The reason this exists: the schema in a failing run **comes back**. A suite + * fails because `orders` does not exist, and a later suite truncating the same + * table passes. A dropped database does not un-drop itself, so more than one + * server must be answering to the same name — Docker's embedded DNS round-robins + * every container sharing an alias, so a leftover service container from an + * earlier run would produce exactly this. + * + * `pg_postmaster_start_time()` is what settles it and needs no special rights: + * two Postgres instances cannot share one. Differing values across a single run + * are proof outright, where a differing `inet_server_addr` alone could be argued + * to be one container that moved. + * + * Never throws. This is a diagnostic, and a diagnostic that can fail a run it + * was added to explain is worse than no diagnostic. + */ +export async function describeBackend(label: string): Promise { + try { + const { rows } = await testPool.query<{ + addr: string | null; + started: string; + pid: number; + db: string; + }>( + `SELECT inet_server_addr()::text AS addr, + pg_postmaster_start_time()::text AS started, + pg_backend_pid() AS pid, + current_database() AS db` + ); + const row = rows[0]; + if (!row) return `${label}: no row returned`; + return `${label}: db=${row.db} addr=${row.addr ?? 'local'} postmaster_start=${row.started} pid=${row.pid}`; + } catch (err) { + return `${label}: could not be identified (${err instanceof Error ? err.message : String(err)})`; + } +} + export async function assertSchemaPresent(context: string): Promise { const missing = await missingTables(); if (missing.length === 0) return; + // Gathered only on the failure path, which is the one worth paying for, and + // is where #154 has repeatedly lacked the one fact that would identify it. + const backend = await describeBackend('Answering server'); + throw new Error( `The test database has no schema (${context}). ` + `Missing ${missing.length} of ${REQUIRED_TABLES.length} tables: ${missing.join(', ')}. +` + + `${backend} + ` + `Migrations ran at the start of this run, so the schema existed and has since gone. ` + - `Nothing in this suite drops tables — TRUNCATE does not — so the database itself was ` + - `replaced or restarted underneath the run. On CI the likeliest cause is the Postgres ` + - `service container being recreated, which comes back with an empty data directory. ` + + `Nothing in this suite drops tables — TRUNCATE does not. Compare the postmaster start ` + + `time above against the one globalSetup logged: if they differ, this is a different ` + + `Postgres instance answering to the same name rather than one database losing its ` + + `schema, and the schema was never lost at all. ` + `See #154.` ); }