From ba2764a256789406ac7d7f5107af8d011eb1c699 Mon Sep 17 00:00:00 2001 From: Vincent Koc Date: Tue, 4 Aug 2026 06:53:49 +0800 Subject: [PATCH] test(qa): cover remote logging boundaries (#118951) * test(qa): cover remote logging boundaries * test(qa): tolerate gateway log interleaving * test(qa): satisfy logging type guards * test(qa): always stop log follow child --- qa/scenarios/cli/remote-log-tailing.yaml | 30 +++ .../runtime/logging-file-boundary.yaml | 26 ++ .../logging-file-boundary-runtime.test.ts | 21 ++ .../runtime/logging-file-boundary-runtime.ts | 136 ++++++++++ .../remote-log-tailing-runtime.test.ts | 36 +++ .../runtime/remote-log-tailing-runtime.ts | 234 ++++++++++++++++++ 6 files changed, 483 insertions(+) create mode 100644 qa/scenarios/cli/remote-log-tailing.yaml create mode 100644 qa/scenarios/runtime/logging-file-boundary.yaml create mode 100644 test/e2e/qa-lab/runtime/logging-file-boundary-runtime.test.ts create mode 100644 test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts create mode 100644 test/e2e/qa-lab/runtime/remote-log-tailing-runtime.test.ts create mode 100644 test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts diff --git a/qa/scenarios/cli/remote-log-tailing.yaml b/qa/scenarios/cli/remote-log-tailing.yaml new file mode 100644 index 000000000000..7d7276229595 --- /dev/null +++ b/qa/scenarios/cli/remote-log-tailing.yaml @@ -0,0 +1,30 @@ +title: Remote gateway log tailing + +scenario: + id: remote-log-tailing + surface: cli + coverage: + primary: + - cli.remote-log-tailing + - observability.gateway-rpc-logs-tail + - observability.openclaw-logs + objective: Verify authenticated remote log tailing through the real Gateway and packaged CLI. + successCriteria: + - The Gateway logs.tail RPC honors line, byte, and cursor bounds. + - The packaged CLI accepts an explicit remote URL and token and emits JSON records. + - Follow mode receives a later record and exits after the QA owner sends SIGINT. + docsRefs: + - docs/cli/logs.md + - docs/gateway/index.md + codeRefs: + - src/cli/logs-cli.ts + - src/gateway/server-methods/logs.ts + - src/logging/log-tail.ts + - test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts + execution: + kind: script + path: test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts + summary: Starts an authenticated Gateway and exercises logs.tail through RPC and the packaged CLI. + args: + - --artifact-base + - ${outputDir} diff --git a/qa/scenarios/runtime/logging-file-boundary.yaml b/qa/scenarios/runtime/logging-file-boundary.yaml new file mode 100644 index 000000000000..90ced80f4cdc --- /dev/null +++ b/qa/scenarios/runtime/logging-file-boundary.yaml @@ -0,0 +1,26 @@ +title: Logging file boundary + +scenario: + id: logging-file-boundary + surface: runtime + coverage: + primary: + - observability.rolling-gateway-jsonl-file-logs + - observability.trace-correlation-fields + objective: Verify the actual file logger rotates bounded JSONL while preserving diagnostic trace correlation. + successCriteria: + - A tiny configured file limit rotates the active JSONL log into the .1 archive. + - Every retained line in the active and archived files is valid JSON. + - Trace, span, parent, and flags fields survive in the file record and match the linked diagnostic event. + codeRefs: + - src/logging/logger.ts + - src/logging/logger-file-transport.ts + - src/infra/diagnostic-trace-context.ts + - test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts + execution: + kind: script + path: test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts + summary: Runs the real logger with a tiny file cap and validates JSONL rotation and trace correlation. + args: + - --artifact-base + - ${outputDir} diff --git a/test/e2e/qa-lab/runtime/logging-file-boundary-runtime.test.ts b/test/e2e/qa-lab/runtime/logging-file-boundary-runtime.test.ts new file mode 100644 index 000000000000..dc535e99083f --- /dev/null +++ b/test/e2e/qa-lab/runtime/logging-file-boundary-runtime.test.ts @@ -0,0 +1,21 @@ +import { afterEach, describe, expect, it } from "vitest"; +import { useAutoCleanupTempDirTracker } from "../../../helpers/temp-dir.js"; +import { runLoggingFileBoundary } from "./logging-file-boundary-runtime.js"; + +const tempDirs = useAutoCleanupTempDirTracker(afterEach); + +describe("logging file boundary runtime", () => { + it("rotates valid JSONL and preserves linked trace fields", async () => { + const root = tempDirs.make("openclaw-logging-boundary-"); + const result = await runLoggingFileBoundary(root); + + expect(result.currentRecords).toBeGreaterThan(0); + expect(result.archivedRecords).toBeGreaterThan(0); + expect(result.trace).toEqual({ + traceId: "4bf92f3577b34da6a3ce929d0e0e4736", + spanId: "00f067aa0ba902b7", + parentSpanId: "1111111111111111", + traceFlags: "01", + }); + }); +}); diff --git a/test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts b/test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts new file mode 100644 index 000000000000..a0793d22c6f0 --- /dev/null +++ b/test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts @@ -0,0 +1,136 @@ +import { readFile, mkdir } from "node:fs/promises"; +import path from "node:path"; +import { + onInternalDiagnosticEvent, + resetDiagnosticEventsForTest, + type DiagnosticEventPayload, +} from "../../../../src/infra/diagnostic-events.js"; +import { + createDiagnosticTraceContext, + runWithDiagnosticTraceContext, +} from "../../../../src/infra/diagnostic-trace-context.js"; +import { + getChildLogger, + resetLogger, + setLoggerOverride, + testApi, +} from "../../../../src/logging/logger.js"; +import { createQaScriptEvidenceWriter } from "./script-evidence.js"; + +function artifactBase(argv: readonly string[]): string { + const index = argv.indexOf("--artifact-base"); + const value = index >= 0 ? argv[index + 1] : undefined; + if (!value) { + throw new Error("--artifact-base is required"); + } + return path.resolve(value); +} + +function rotatedPath(file: string): string { + const ext = path.extname(file); + return `${file.slice(0, -ext.length)}.1${ext}`; +} + +export async function runLoggingFileBoundary(outputRoot: string) { + await mkdir(outputRoot, { recursive: true }); + const logPath = path.join(outputRoot, "openclaw.jsonl"); + const trace = createDiagnosticTraceContext({ + traceId: "4bf92f3577b34da6a3ce929d0e0e4736", + spanId: "00f067aa0ba902b7", + parentSpanId: "1111111111111111", + traceFlags: "01", + }); + const diagnostics: Extract[] = []; + resetDiagnosticEventsForTest(); + resetLogger(); + testApi.resetFileLogTransportForTests(); + setLoggerOverride({ level: "info", file: logPath, maxFileBytes: 512 }); + const unsubscribe = onInternalDiagnosticEvent((event) => { + if (event.type === "log.record") { + diagnostics.push(event); + } + }); + try { + runWithDiagnosticTraceContext(trace, () => { + const logger = getChildLogger({ subsystem: "qa-file-boundary" }); + logger.info(`rotation-fill-${"x".repeat(700)}`); + logger.info({ marker: "correlated" }, "qa-correlated-record"); + }); + await testApi.flushFileLogQueueForTests(); + await new Promise((resolve) => { + setImmediate(resolve); + }); + const current = (await readFile(logPath, "utf8")) + .trim() + .split("\n") + .map((line) => JSON.parse(line)); + const archived = (await readFile(rotatedPath(logPath), "utf8")) + .trim() + .split("\n") + .map((line) => JSON.parse(line)); + const fileRecord = current.find( + (record: Record) => record.message === "qa-correlated-record", + ) as Record | undefined; + const diagnostic = diagnostics.find((event) => event.message === "qa-correlated-record"); + if (!fileRecord || !diagnostic) { + throw new Error("correlated file and diagnostic records were not both emitted"); + } + const expected = { + traceId: trace.traceId, + spanId: trace.spanId, + parentSpanId: trace.parentSpanId, + traceFlags: trace.traceFlags, + }; + for (const [key, value] of Object.entries(expected)) { + if (fileRecord[key] !== value || diagnostic.trace?.[key as keyof typeof expected] !== value) { + throw new Error(`trace correlation mismatch for ${key}`); + } + } + return { currentRecords: current.length, archivedRecords: archived.length, trace: expected }; + } finally { + unsubscribe(); + setLoggerOverride(null); + resetLogger(); + testApi.resetFileLogTransportForTests(); + resetDiagnosticEventsForTest(); + } +} + +async function main() { + const repoRoot = process.cwd(); + const outputRoot = artifactBase(process.argv.slice(2)); + const startedAt = Date.now(); + const writer = createQaScriptEvidenceWriter({ + artifactBase: outputRoot, + logFileName: "logging-file-boundary.log", + primaryModel: "none", + providerMode: "mock-openai", + repoRoot, + target: { + id: "logging-file-boundary", + sourcePath: "qa/scenarios/runtime/logging-file-boundary.yaml", + title: "Logging file boundary", + codeRefs: [ + "test/e2e/qa-lab/runtime/logging-file-boundary-runtime.ts", + "src/logging/logger-file-transport.ts", + ], + }, + }); + try { + const result = await runLoggingFileBoundary(outputRoot); + writer.appendLog(`${JSON.stringify(result)}\n`); + await writer.write({ durationMs: Date.now() - startedAt, status: "pass" }); + } catch (error) { + writer.appendLog(`${String(error)}\n`); + await writer.write({ + details: error instanceof Error ? error.message : String(error), + durationMs: Date.now() - startedAt, + status: "fail", + }); + throw error; + } +} + +if (import.meta.url === new URL(process.argv[1] ?? "", "file:").href) { + await main(); +} diff --git a/test/e2e/qa-lab/runtime/remote-log-tailing-runtime.test.ts b/test/e2e/qa-lab/runtime/remote-log-tailing-runtime.test.ts new file mode 100644 index 000000000000..0efae92fab8b --- /dev/null +++ b/test/e2e/qa-lab/runtime/remote-log-tailing-runtime.test.ts @@ -0,0 +1,36 @@ +import { spawn } from "node:child_process"; +import { once } from "node:events"; +import { readFileSync } from "node:fs"; +import path from "node:path"; +import { describe, expect, it } from "vitest"; +import { withOwnedFollowChild } from "./remote-log-tailing-runtime.js"; + +describe("remote log tailing scenario", () => { + it("declares packaged CLI, RPC bounds, cursor, follow, and owned SIGINT proof", () => { + const source = readFileSync( + path.join(process.cwd(), "test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts"), + "utf8", + ); + expect(source).toContain('"logs.tail"'); + expect(source).toContain("first.cursor"); + expect(source).toContain('"--max-bytes"'); + expect(source).toContain('"--follow"'); + expect(source).toContain("withOwnedFollowChild(child"); + expect(source).toContain('path.join(repoRoot, "dist", "index.js")'); + }); + + it("stops and awaits the follow child when the owned operation fails", async () => { + const child = spawn(process.execPath, ["-e", "setInterval(() => {}, 1000)"], { + stdio: "ignore", + }); + await once(child, "spawn"); + + await expect( + withOwnedFollowChild(child, async () => { + throw new Error("forced follow failure"); + }), + ).rejects.toThrow("forced follow failure"); + + expect(child.signalCode).not.toBeNull(); + }); +}); diff --git a/test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts b/test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts new file mode 100644 index 000000000000..d05fe21d697f --- /dev/null +++ b/test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts @@ -0,0 +1,234 @@ +import { spawn, type ChildProcess } from "node:child_process"; +import { appendFile, mkdir } from "node:fs/promises"; +import path from "node:path"; +import { startQaGatewayChild } from "../../../../extensions/qa-lab/api.js"; +import { createQaScriptEvidenceWriter } from "./script-evidence.js"; + +const SOURCE_PATH = "test/e2e/qa-lab/runtime/remote-log-tailing-runtime.ts"; + +function artifactBase(argv: readonly string[]): string { + const index = argv.indexOf("--artifact-base"); + const value = index >= 0 ? argv[index + 1] : undefined; + if (!value) { + throw new Error("--artifact-base is required"); + } + return path.resolve(value); +} + +function logLine(message: string): string { + return `${JSON.stringify({ + time: new Date().toISOString(), + level: "info", + subsystem: "qa-remote-logs", + message, + })}\n`; +} + +function hasExited(child: ChildProcess): boolean { + return child.exitCode !== null || child.signalCode !== null; +} + +function waitForClose(child: ChildProcess, timeoutMs: number): Promise { + if (hasExited(child)) { + return Promise.resolve(); + } + return new Promise((resolve, reject) => { + const onClose = () => { + clearTimeout(timer); + resolve(); + }; + const timer = setTimeout(() => { + child.off("close", onClose); + reject(new Error("follow child did not close before timeout")); + }, timeoutMs); + child.once("close", onClose); + }); +} + +async function stopFollowChild(child: ChildProcess): Promise { + if (hasExited(child)) { + return; + } + child.kill("SIGINT"); + try { + await waitForClose(child, 5_000); + } catch { + if (hasExited(child)) { + return; + } + child.kill("SIGKILL"); + await waitForClose(child, 5_000); + } +} + +export async function withOwnedFollowChild( + child: ChildProcess, + operation: () => Promise, +): Promise { + try { + return await operation(); + } finally { + await stopFollowChild(child); + } +} + +export async function runRemoteLogTailing(repoRoot: string, outputRoot: string) { + const logPath = path.join(outputRoot, "gateway.jsonl"); + await mkdir(outputRoot, { recursive: true }); + const gateway = await startQaGatewayChild({ + repoRoot, + command: { + executablePath: process.execPath, + argsPrefix: [path.join(repoRoot, "dist", "index.js")], + cwd: repoRoot, + usePackagedPlugins: true, + }, + transportBaseUrl: "http://127.0.0.1:9", + controlUiEnabled: false, + mutateConfig: (config) => ({ + ...config, + logging: { ...config.logging, file: logPath, level: "info" }, + }), + }); + try { + await appendFile(logPath, logLine("qa-line-one")); + await appendFile(logPath, logLine("qa-line-two")); + await appendFile(logPath, logLine("qa-line-three")); + + const first = (await gateway.call("logs.tail", { limit: 2, maxBytes: 4096 })) as { + cursor: number; + lines: string[]; + truncated: boolean; + }; + if (first.lines.length !== 2 || !first.lines.some((line) => line.includes("qa-line-three"))) { + throw new Error(`logs.tail did not honor limit: ${JSON.stringify(first)}`); + } + const bounded = (await gateway.call("logs.tail", { limit: 20, maxBytes: 96 })) as { + cursor: number; + lines: string[]; + truncated: boolean; + }; + if (!bounded.truncated || bounded.cursor <= 0) { + throw new Error(`logs.tail did not honor maxBytes: ${JSON.stringify(bounded)}`); + } + await appendFile(logPath, logLine("qa-cursor-line")); + const cursorTail = (await gateway.call("logs.tail", { + cursor: first.cursor, + limit: 20, + maxBytes: 4096, + })) as { lines: string[] }; + if ( + !cursorTail.lines.some((line) => line.includes("qa-cursor-line")) || + cursorTail.lines.some((line) => /qa-line-(?:one|two|three)/.test(line)) + ) { + throw new Error(`logs.tail did not honor cursor: ${JSON.stringify(cursorTail)}`); + } + + const cliJson = await gateway.runCli([ + "logs", + "--url", + gateway.wsUrl, + "--token", + gateway.token, + "--json", + "--limit", + "2", + "--max-bytes", + "4096", + ]); + const cliRecords = cliJson + .trim() + .split("\n") + .map((line) => JSON.parse(line) as { type?: string; message?: string }); + if (!cliRecords.some((record) => record.type === "meta")) { + throw new Error(`packaged logs CLI omitted metadata: ${cliJson}`); + } + if (!cliRecords.some((record) => record.message === "qa-cursor-line")) { + throw new Error(`packaged logs CLI omitted the tailed record: ${cliJson}`); + } + + const child = spawn( + process.execPath, + [ + path.join(repoRoot, "dist", "index.js"), + "logs", + "--url", + gateway.wsUrl, + "--token", + gateway.token, + "--json", + "--follow", + "--interval", + "50", + "--limit", + "1", + "--max-bytes", + "4096", + ], + { cwd: repoRoot, env: gateway.runtimeEnv, stdio: ["ignore", "pipe", "pipe"] }, + ); + let stdout = ""; + let stderr = ""; + child.stdout.on("data", (chunk) => { + stdout += String(chunk); + }); + child.stderr.on("data", (chunk) => { + stderr += String(chunk); + }); + const followOutput = await withOwnedFollowChild(child, async () => { + await new Promise((resolve) => { + setTimeout(resolve, 250); + }); + await appendFile(logPath, logLine("qa-follow-line")); + const deadline = Date.now() + 10_000; + while (!stdout.includes("qa-follow-line") && Date.now() < deadline) { + await new Promise((resolve) => { + setTimeout(resolve, 50); + }); + } + if (!stdout.includes("qa-follow-line")) { + throw new Error(`follow did not receive appended record: ${stderr}`); + } + return stdout; + }); + return { first, bounded, cursorTail, cliRecords, followOutput }; + } finally { + await gateway.stop(); + } +} + +async function main() { + const repoRoot = process.cwd(); + const outputRoot = artifactBase(process.argv.slice(2)); + const startedAt = Date.now(); + const writer = createQaScriptEvidenceWriter({ + artifactBase: outputRoot, + logFileName: "remote-log-tailing.log", + primaryModel: "none", + providerMode: "mock-openai", + repoRoot, + target: { + id: "remote-log-tailing", + sourcePath: "qa/scenarios/cli/remote-log-tailing.yaml", + title: "Remote gateway log tailing", + codeRefs: [SOURCE_PATH, "src/cli/logs-cli.ts", "src/gateway/server-methods/logs.ts"], + }, + }); + try { + const result = await runRemoteLogTailing(repoRoot, outputRoot); + writer.appendLog(`${JSON.stringify(result)}\n`); + await writer.write({ durationMs: Date.now() - startedAt, status: "pass" }); + } catch (error) { + writer.appendLog(`${String(error)}\n`); + await writer.write({ + details: error instanceof Error ? error.message : String(error), + durationMs: Date.now() - startedAt, + status: "fail", + }); + throw error; + } +} + +if (import.meta.url === new URL(process.argv[1] ?? "", "file:").href) { + await main(); +}