fix: log stdout/stderr on action failures (#176)

Author: benjie

CONTRIBUTING.md

@@ -36,6 +36,15 @@ volumes:
     driver: local
 ```
 
+### Creating the database
+
+You'll then need to connect to the database and issue the following commands:
+
+```sql
+create role gmtestuser with login password 'gmtestpass';
+create database graphile_migrate_test owner gmtestuser;
+```
+
 ## ASK FIRST!
 
 There's nothing worse than having your PR with 3 days of work in it rejected

__tests__/actions-live.test.ts

@@ -0,0 +1,95 @@
+import "./helpers"; // Has side-effects; must come first
+
+import { Logger, LogLevel, LogMeta } from "@graphile/logger";
+import * as mockFs from "mock-fs";
+
+import { executeActions } from "../src/actions";
+import { _migrate } from "../src/commands/migrate";
+import { parseSettings } from "../src/settings";
+import { mockPgClient, TEST_DATABASE_URL } from "./helpers";
+
+beforeAll(() => {
+  // eslint-disable-next-line no-console
+  console.log("[mock-fs callsites hack]"); // Without this, jest fails due to 'callsites'
+  mockFs({});
+});
+
+afterAll(() => {
+  mockFs.restore();
+});
+
+it("logs output from command actions on success", async () => {
+  const logs: Array<{
+    scope: any;
+    level: LogLevel;
+    message: string;
+    meta?: LogMeta;
+  }> = [];
+  const logger = new Logger(scope => (level, message, meta) => {
+    logs.push({ scope, level, message, meta });
+  });
+  const parsedSettings = await parseSettings({
+    connectionString: TEST_DATABASE_URL,
+    afterAllMigrations: [
+      { _: "command", command: "echo 'success' && echo 'err' >&2" },
+    ],
+    logger,
+  });
+  mockPgClient.query.mockClear();
+  await executeActions(
+    parsedSettings,
+    false,
+    parsedSettings.afterAllMigrations,
+  );
+  expect(mockPgClient.query).toHaveBeenCalledTimes(0);
+  expect(logs).toHaveLength(2);
+  expect(logs[0]).toMatchObject({
+    level: "info",
+    message: "success\n",
+  });
+  expect(logs[1]).toMatchObject({
+    level: "error",
+    message: "err\n",
+  });
+});
+
+it("logs output from command actions on failure", async () => {
+  const logs: Array<{
+    scope: any;
+    level: LogLevel;
+    message: string;
+    meta?: LogMeta;
+  }> = [];
+  const logger = new Logger(scope => (level, message, meta) => {
+    logs.push({ scope, level, message, meta });
+  });
+  const parsedSettings = await parseSettings({
+    connectionString: TEST_DATABASE_URL,
+    afterAllMigrations: [
+      { _: "command", command: "echo 'success' && echo 'err' >&2 && false" },
+    ],
+    logger,
+  });
+  mockPgClient.query.mockClear();
+  let err;
+  try {
+    await executeActions(
+      parsedSettings,
+      false,
+      parsedSettings.afterAllMigrations,
+    );
+  } catch (e) {
+    err = e;
+  }
+  expect(err).toBeTruthy();
+  expect(mockPgClient.query).toHaveBeenCalledTimes(0);
+  expect(logs).toHaveLength(2);
+  expect(logs[0]).toMatchObject({
+    level: "info",
+    message: "success\n",
+  });
+  expect(logs[1]).toMatchObject({
+    level: "error",
+    message: "err\n",
+  });
+});

src/actions.ts

@@ -93,7 +93,7 @@ export async function executeActions(
       );
     } else if (actionSpec._ === "command") {
       // Run the command
-      const { stdout, stderr } = await exec(actionSpec.command, {
+      const promise = exec(actionSpec.command, {
         env: mergeWithoutClobbering(
           {
             ...process.env,
@@ -120,11 +120,23 @@ export async function executeActions(
         // 50MB of log data should be enough for any reasonable migration... right?
         maxBuffer: 50 * 1024 * 1024,
       });
-      if (stdout) {
-        parsedSettings.logger.info(stdout);
-      }
-      if (stderr) {
-        parsedSettings.logger.error(stderr);
+      try {
+        const { stdout, stderr } = await promise;
+        if (stdout) {
+          parsedSettings.logger.info(stdout);
+        }
+        if (stderr) {
+          parsedSettings.logger.error(stderr);
+        }
+      } catch (e) {
+        const { stdout, stderr } = e;
+        if (stdout) {
+          parsedSettings.logger.info(stdout);
+        }
+        if (stderr) {
+          parsedSettings.logger.error(stderr);
+        }
+        throw e;
       }
     }
   }