commit 61adc575d1d9a61db305b66d030d6cd1049d8eba
parent 4da3a1023b13ca36c1f6a59213cf11a98b8872db
Author: Florian Dold <dold@taler.net>
Date: Sat, 5 Sep 2026 18:17:22 +0200
taler-harness: make integration test log auditing configurable
Diffstat:
5 files changed, 171 insertions(+), 19 deletions(-)
diff --git a/packages/taler-harness/README.md b/packages/taler-harness/README.md
@@ -121,14 +121,22 @@ before treating it as a product regression.
### Service warnings and errors
-After every integration test, the harness parses structured `WARN`, `WARNING`,
-and `ERROR` records from that test's `*-stderr.log` files (`WARN` is normalized
-to `WARNING`). This includes the Taler/GNUnet layout, Libeufin's Kotlin logging
+By default, after every integration test the harness parses structured `WARN`,
+`WARNING`, and `ERROR` records from that test's `*-stderr.log` files (`WARN` is
+normalized to `WARNING`). This includes the Taler/GNUnet layout, Libeufin's Kotlin logging
layout, and diagnostics with a case-insensitive `ERROR:`, `WARNING:`, or
-`WARN:` severity prefix. Any
-unexpected record fails the test. Text such as `ERROR` in an INFO or TRACE
-message does not count: the parser uses a structured severity field or prefix,
-not a substring search.
+`WARN:` severity prefix. Unexpected records are reported without failing the
+test. Control this behavior with `taler-harness run-integrationtests --log-audit=MODE`:
+
+- `warn` (default): print unexpected entries and retain them in `results.json`,
+ without failing the test. Log scan errors are reported as warnings.
+- `error`: unexpected entries or log scan errors fail an otherwise passing test.
+- `no`: skip log auditing, including postmortem scans. Raw service log files are
+ still written.
+
+Assertions, crashes, and timeouts still fail tests in every mode.
+Text such as `ERROR` in an INFO or TRACE message does not count: the parser uses
+a structured severity field or prefix, not a substring search.
First investigate a diagnostic and fix its cause or severity. If a test
deliberately exercises the condition, declare an exact, bounded expectation
@@ -150,9 +158,10 @@ justification. Catch-all file patterns, unanchored expressions, and global or
sticky expressions are rejected. Keep dynamic expressions as narrow as
possible and never add an expectation merely to make the suite green.
-Diagnostics are printed even in quiet mode and retained in `results.json` with
-their file and line number. The runner also performs a parent-side scan when a
-worker crashes or times out, after giving the child time to flush its logs.
+With auditing enabled, diagnostics are printed even in quiet mode and retained
+in `results.json` with their file and line number. The runner also performs a
+parent-side scan when a worker crashes or times out, after giving the child time
+to flush its logs.
Those entries are labeled as postmortem diagnostics rather than unexpected:
the parent cannot recover expectations that existed only in the terminated
worker, while the crash or timeout already makes the test fail.
diff --git a/packages/taler-harness/src/harness/harness.ts b/packages/taler-harness/src/harness/harness.ts
@@ -3105,6 +3105,8 @@ export class MerchantService implements MerchantServiceInterface {
type TestStatus = "pass" | "fail" | "skip";
+export type LogAuditMode = "error" | "warn" | "no";
+
export interface TestRunResult {
/**
* Name of the test.
@@ -3146,6 +3148,7 @@ export async function runTestWithState(
testMain: (t: GlobalTestState) => Promise<void>,
testName: string,
linger: boolean = false,
+ logAudit: LogAuditMode = "warn",
): Promise<TestRunResult> {
const startMs = new Date().getTime();
@@ -3243,12 +3246,12 @@ export async function runTestWithState(
}
}
let unexpectedLogEntries: ServiceLogEntry[] | undefined;
- if (!shouldLingerInTest()) {
+ if (logAudit !== "no" && !shouldLingerInTest()) {
try {
const entries = gc.readUnexpectedServiceLogs();
if (entries.length > 0) {
unexpectedLogEntries = entries;
- if (status === "pass") {
+ if (logAudit === "error" && status === "pass") {
status = "fail";
reason = "unexpected WARNING/ERROR entries in service logs";
}
@@ -3257,7 +3260,9 @@ export async function runTestWithState(
const scanFailure = `service log scan failed: ${
error instanceof Error ? error.message : String(error)
}`;
- if (status === "pass") {
+ if (logAudit === "warn") {
+ logger.warn(scanFailure);
+ } else if (status === "pass") {
status = "fail";
reason = scanFailure;
} else {
diff --git a/packages/taler-harness/src/harness/log-diagnostics.test.ts b/packages/taler-harness/src/harness/log-diagnostics.test.ts
@@ -21,6 +21,7 @@ import path from "node:path";
import { test, type TestContext } from "node:test";
import {
GlobalTestState,
+ LogAuditMode,
readServiceLogEntries,
runTestWithState,
} from "./harness.js";
@@ -263,6 +264,8 @@ test("unexpected service diagnostics fail an otherwise passing test", async (t)
);
},
"unexpected-service-log",
+ false,
+ "error",
);
assert.equal(result.status, "fail");
@@ -293,8 +296,114 @@ test("service output is flushed before post-test scanning", async (t) => {
await child.wait();
},
"service-log-flush",
+ false,
+ "error",
);
assert.equal(result.status, "pass");
assert.equal(result.unexpectedLogEntries, undefined);
});
+
+for (const mode of [undefined, "warn"] as const) {
+ test(`unexpected diagnostics do not fail a test in ${mode ?? "default"} mode`, async (t) => {
+ const testDir = makeTestDir(t);
+ const result = await runTestWithState(
+ new GlobalTestState({ testDir }),
+ async () => {
+ fs.writeFileSync(
+ path.join(testDir, "service-stderr.log"),
+ "ERROR: unexpected diagnostic\n",
+ );
+ },
+ "warn-service-log",
+ false,
+ mode,
+ );
+ assert.equal(result.status, "pass");
+ assert.equal(result.reason, undefined);
+ assert.equal(
+ result.unexpectedLogEntries?.[0].message,
+ "unexpected diagnostic",
+ );
+ });
+}
+
+test("no audit mode skips scanning and still shuts down services", async (t) => {
+ const testDir = makeTestDir(t);
+ const state = new GlobalTestState({ testDir });
+ const scan = t.mock.method(state, "readUnexpectedServiceLogs", () => {
+ throw Error("scan must not run");
+ });
+ const shutdown = t.mock.method(state, "shutdown");
+ const result = await runTestWithState(
+ state,
+ async () => {
+ fs.writeFileSync(
+ path.join(testDir, "service-stderr.log"),
+ "ERROR: broken\n",
+ );
+ },
+ "no-log-audit",
+ false,
+ "no",
+ );
+ assert.equal(result.status, "pass");
+ assert.equal(result.unexpectedLogEntries, undefined);
+ assert.equal(scan.mock.callCount(), 0);
+ assert.equal(shutdown.mock.callCount(), 1);
+ assert.equal(
+ fs.readFileSync(path.join(testDir, "service-stderr.log"), "utf8"),
+ "ERROR: broken\n",
+ );
+});
+
+for (const mode of ["error", "warn", "no"] satisfies LogAuditMode[]) {
+ test(`actual failures remain failures in ${mode} mode`, async (t) => {
+ const testDir = makeTestDir(t);
+ const result = await runTestWithState(
+ new GlobalTestState({ testDir }),
+ async () => {
+ fs.writeFileSync(
+ path.join(testDir, "service-stderr.log"),
+ "ERROR: broken\n",
+ );
+ throw Error("assertion failed");
+ },
+ "actual-failure",
+ false,
+ mode,
+ );
+ assert.equal(result.status, "fail");
+ assert.equal(result.reason, "assertion failed");
+ assert.equal(
+ result.unexpectedLogEntries?.length ?? 0,
+ mode === "no" ? 0 : 1,
+ );
+ });
+
+ for (const fails of [false, true]) {
+ test(`scan errors in ${mode} mode with a ${fails ? "failing" : "passing"} test`, async (t) => {
+ const state = new GlobalTestState({ testDir: makeTestDir(t) });
+ t.mock.method(state, "readUnexpectedServiceLogs", () => {
+ throw Error("scan broken");
+ });
+ const result = await runTestWithState(
+ state,
+ async () => {
+ if (fails) throw Error("assertion failed");
+ },
+ "scan-error",
+ false,
+ mode,
+ );
+ assert.equal(result.status, fails || mode === "error" ? "fail" : "pass");
+ const reasons = fails ? ["assertion failed"] : [];
+ if (mode === "error")
+ reasons.push("service log scan failed: scan broken");
+ assert.equal(
+ result.reason,
+ reasons.length ? reasons.join("; ") : undefined,
+ );
+ });
+ }
+}
diff --git a/packages/taler-harness/src/index.ts b/packages/taler-harness/src/index.ts
@@ -2030,7 +2030,15 @@ talerHarnessCli
.flag("reuseWorker", ["--reuse-worker"], {
help: "Reuse one child process across tests (faster, less isolation).",
})
+ .maybeOption("logAudit", ["--log-audit"], clk.STRING, {
+ help: "Service log auditing: error (fail on unexpected entries), warn (report only, default), no (disable auditing).",
+ default: "warn",
+ })
.action(async (args) => {
+ const logAudit = args.runIntegrationtests.logAudit ?? "warn";
+ if (logAudit !== "error" && logAudit !== "warn" && logAudit !== "no") {
+ throw Error("invalid --log-audit value: expected error, warn, or no");
+ }
const noTimeout =
process.env["TALER_TEST_NO_TIMEOUT"] === "1" ? true : undefined;
await runTests({
@@ -2044,6 +2052,7 @@ talerHarnessCli
strictTodo: args.runIntegrationtests.strictTodo ?? false,
noTimeout: noTimeout ?? args.runIntegrationtests.noTimeout,
reuseWorker: args.runIntegrationtests.reuseWorker ?? false,
+ logAudit,
testDir: args.runIntegrationtests.testDir,
});
});
diff --git a/packages/taler-harness/src/integrationtests/testrunner.ts b/packages/taler-harness/src/integrationtests/testrunner.ts
@@ -28,6 +28,7 @@ import * as path from "node:path";
import url from "node:url";
import {
GlobalTestState,
+ LogAuditMode,
readServiceLogEntries,
runTestWithState,
shouldLingerInTest,
@@ -547,6 +548,8 @@ const allTests: TestMainFunction[] = [
];
export interface TestRunSpec {
+ /** Service log audit policy, defaulting to warn. */
+ logAudit?: LogAuditMode;
includePattern?: string;
suiteSpec?: string;
testDir?: string;
@@ -617,6 +620,7 @@ function validateTestMetadata(testCases: TestMainFunction[]): void {
interface RunTestChildInstruction {
testName: string;
testRootDir: string;
+ logAudit: LogAuditMode;
}
interface ReusableWorkerResultMessage {
@@ -760,6 +764,7 @@ async function waitForWorkerClose(
}
export async function runTests(spec: TestRunSpec) {
+ const logAudit = spec.logAudit ?? "warn";
validateTestMetadata(allTests);
if (spec.reuseWorker && shouldLingerInTest()) {
throw Error("--reuse-worker cannot be combined with TALER_TEST_LINGER");
@@ -861,6 +866,7 @@ export async function runTests(spec: TestRunSpec) {
const testInstr: RunTestChildInstruction = {
testName,
testRootDir,
+ logAudit,
};
const myFilename = url.fileURLToPath(import.meta.url);
@@ -1004,11 +1010,18 @@ export async function runTests(spec: TestRunSpec) {
if (needsPostMortemLogScan) {
await waitForWorkerClose(currentChild);
- try {
- result.postmortemLogEntries = readServiceLogEntries(testDir);
- } catch (error) {
- const detail = error instanceof Error ? error.message : String(error);
- result.reason = `${result.reason}; service log scan failed: ${detail}`;
+ if (logAudit !== "no") {
+ try {
+ result.postmortemLogEntries = readServiceLogEntries(testDir);
+ } catch (error) {
+ const detail = error instanceof Error ? error.message : String(error);
+ const scanFailure = `service log scan failed: ${detail}`;
+ if (logAudit === "warn") {
+ logger.warn(scanFailure);
+ } else {
+ result.reason = `${result.reason}; ${scanFailure}`;
+ }
+ }
}
}
@@ -1173,6 +1186,7 @@ export function getTestInfo(): TestInfo[] {
async function runChildInstruction({
testRootDir,
testName,
+ logAudit,
}: RunTestChildInstruction): Promise<TestRunResult> {
const testMain = allTests.find((test) => getTestName(test) === testName);
if (!testMain) {
@@ -1182,7 +1196,13 @@ async function runChildInstruction({
const testDir = path.join(testRootDir, testName);
logger.info(`running test ${testName}`);
const gc = new GlobalTestState({ testDir });
- const testResult = await runTestWithState(gc, testMain, testName);
+ const testResult = await runTestWithState(
+ gc,
+ testMain,
+ testName,
+ false,
+ logAudit,
+ );
logger.info(`done test ${testName}: ${testResult.status}`);
return testResult;
}
