Simplify checking logs

Author: mbg

src/config/file.test.ts

@@ -34,36 +34,20 @@ test("getConfigFileInput returns input value", async (t) => {
 
   // Even though both an input and repository property are configured,
   // we prefer the direct input to the Action.
-  const targetWithArgs = target
+  await target
     .withActions(actionsEnv)
-    .withArgs(repositoryProperties);
-  await targetWithArgs.passes(t.is, testInput);
-
-  // Check for the expected log message.
-  t.true(
-    targetWithArgs
-      .getLogger()
-      .hasMessage("Using configuration file input from workflow"),
-  );
+    .withArgs(repositoryProperties)
+    .logs(t, "Using configuration file input from workflow")
+    .passes(t.is, testInput);
 });
 
 test("getConfigFileInput returns repository property value", async (t) => {
   // Since there is no direct input, we should use the repository property.
-  const target = callee(getConfigFileInput)
+  await callee(getConfigFileInput)
     .withFeatures([Feature.ConfigFileRepositoryProperty])
-    .withArgs(repositoryProperties);
-
-  await target.passes(
-    t.is,
-    repositoryProperties[RepositoryPropertyName.CONFIG_FILE],
-  );
-
-  // Check for the expected log message.
-  t.true(
-    target
-      .getLogger()
-      .hasMessage("Using configuration file input from repository property"),
-  );
+    .withArgs(repositoryProperties)
+    .logs(t, "Using configuration file input from repository property")
+    .passes(t.is, repositoryProperties[RepositoryPropertyName.CONFIG_FILE]);
 });
 
 test("getConfigFileInput ignores empty repository property value", async (t) => {
@@ -76,22 +60,13 @@ test("getConfigFileInput ignores empty repository property value", async (t) =>
 
 test("getConfigFileInput ignores repository property value when FF is off", async (t) => {
   // Since the FF is off, we should ignore the repository property value.
-  const target = callee(getConfigFileInput)
+  await callee(getConfigFileInput)
     .withFeatures([])
-    .withArgs(repositoryProperties);
-
-  await target.passes(t.is, undefined);
-
-  t.false(
-    target
-      .getLogger()
-      .hasMessage("Using configuration file input from repository property"),
-  );
-  t.true(
-    target
-      .getLogger()
-      .hasMessage(
-        "Ignoring configuration file input from repository property, because the corresponding feature flag is disabled.",
-      ),
-  );
+    .withArgs(repositoryProperties)
+    .notLogs(t, "Using configuration file input from repository property")
+    .logs(
+      t,
+      "Ignoring configuration file input from repository property, because the corresponding feature flag is disabled.",
+    )
+    .passes(t.is, undefined);
 });

src/testing-utils.ts

@@ -210,6 +210,12 @@ export function initAllState(
   };
 }
 
+type DelayedCheck<
+  Args extends readonly any[],
+  R,
+  Fs extends ReadonlyArray<AllState[number]>,
+> = (env: Readonly<BaseEnvBuilder<Args, R, Fs>>) => Promise<any>;
+
 /**
  * Wraps a function that accepts an `ActionState` for testing in different environments.
  */
@@ -221,6 +227,7 @@ abstract class BaseEnvBuilder<
   protected readonly fn: (state: ActionState<Fs>, ...args: Args) => R;
   private logger: RecordingLogger;
   protected state: ActionState<AllState>;
+  protected checks: Array<DelayedCheck<Args, R, Fs>>;
 
   constructor(
     fn: (state: ActionState<Fs>, ...args: Args) => R,
@@ -232,6 +239,7 @@ abstract class BaseEnvBuilder<
       cloneFrom !== undefined
         ? { ...cloneFrom.state, logger: this.logger }
         : initAllState({ logger: this.logger });
+    this.checks = [...(cloneFrom?.checks ?? [])];
   }
 
   /**
@@ -270,6 +278,30 @@ abstract class BaseEnvBuilder<
     result.state.actions = actions;
     return result;
   }
+
+  /**
+   * Adds a delayed check that `messages` are logged. The check will be
+   * performed after the main assertion passes.
+   */
+  public logs(t: ExecutionContext<unknown>, ...messages: string[]): this {
+    const result = this.clone();
+    result.checks.push(async (env) => {
+      checkExpectedLogMessages(t, env.getLogger().messages, messages);
+    });
+    return result;
+  }
+
+  /**
+   * Adds a delayed check that `messages` are not logged. The check will be
+   * performed after the main assertion passes.
+   */
+  public notLogs(t: ExecutionContext<unknown>, ...messages: string[]): this {
+    const result = this.clone();
+    result.checks.push(async (env) => {
+      checkUnexpectedLogMessages(t, env.getLogger().messages, messages);
+    });
+    return result;
+  }
 }
 
 class EnvBuilder<
@@ -322,8 +354,21 @@ class CallableEnvBuilder<
     assertion: (val: Awaited<R>, ...assertionArgs: AArgs) => AResult,
     ...assertionArgs: AArgs
   ): Promise<AResult> {
+    // this.call() may or may not return a promise,
+    // `Promise.resolve` turns the result into one if it isn't already,
+    // and we then await it. That ensures that `result` is an `Awaited<R>`.
     const result = await Promise.resolve(this.call());
-    return assertion(result, ...assertionArgs);
+
+    // Run the main assertion on the `result`.
+    const assertionResult = assertion(result, ...assertionArgs);
+
+    // Run other delayed checks.
+    for (const delayedCheck of this.checks) {
+      await delayedCheck(this);
+    }
+
+    // Return the result of the main assertion.
+    return assertionResult;
   }
 
   /**
@@ -337,7 +382,19 @@ class CallableEnvBuilder<
     t: ExecutionContext<unknown>,
     expectations?: ThrowsExpectation<ErrorType>,
   ): Promise<ThrownError<ErrorType>> {
-    return t.throwsAsync(() => Promise.resolve(this.call()), expectations);
+    // Run the main assertion.
+    const error = t.throwsAsync(
+      () => Promise.resolve(this.call()),
+      expectations,
+    );
+
+    // Run other delayed checks.
+    for (const delayedCheck of this.checks) {
+      await delayedCheck(this);
+    }
+
+    // Return the error.
+    return error;
   }
 }
 
@@ -542,6 +599,34 @@ export function checkExpectedLogMessages(
   }
 }
 
+/**
+ * Checks that `messages` contains none of `unexpectedMessages`.
+ */
+export function checkUnexpectedLogMessages(
+  t: ExecutionContext<any>,
+  messages: LoggedMessage[],
+  unexpectedMessages: string[],
+) {
+  const presentMessages: string[] = [];
+
+  for (const unexpectedMessage of unexpectedMessages) {
+    if (hasLoggedMessage(messages, unexpectedMessage)) {
+      presentMessages.push(unexpectedMessage);
+    }
+  }
+
+  if (presentMessages.length > 0) {
+    const listify = (lines: string[]) =>
+      lines.map((m) => ` - '${m}'`).join("\n");
+
+    t.fail(
+      `Did not expect\n\n${listify(presentMessages)}\n\nin the logger output, but found them in:\n\n${messages.map((m) => ` - '${m.message}'`).join("\n")}`,
+    );
+  } else {
+    t.pass();
+  }
+}
+
 /**
  * Asserts that `message` should not have been logged to `logger`.
  */