Merge pull request 'test(ci): record which Postgres actually answered (#154)' (#326) from fix/154-identify-the-answering-postgres into main

Reviewed-on: #326

backend/tests/integration/setup/globalSetup.ts

@@ -23,9 +23,52 @@ async function waitForDb(retries = 20): Promise<void> {
   );
 }
 
+/**
+ * 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<void> {
+  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<void> {
   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:

backend/tests/integration/setup/testDb.ts

@@ -75,21 +75,68 @@ async function missingTables(): Promise<string[]> {
  * 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<string> {
+  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<void> {
   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 ` +
+      `Nothing in this suite drops tables — TRUNCATE does not. Compare the postmaster start ` +
-      `replaced or restarted underneath the run. On CI the likeliest cause is the Postgres ` +
+      `time above against the one globalSetup logged: if they differ, this is a different ` +
-      `service container being recreated, which comes back with an empty data directory. ` +
+      `Postgres instance answering to the same name rather than one database losing its ` +
+      `schema, and the schema was never lost at all. ` +
       `See #154.`
   );
 }