fix(logs): preserve log tails across short reads (#105066)

* fix(logs): preserve log tails across short reads

* test(logging): track log-tail temp files

---------

Co-authored-by: Peter Steinberger <peter@steipete.me>
Co-authored-by: Peter Steinberger <steipete@gmail.com>
This commit is contained in:
qingminlong
2026-07-14 14:47:53 -07:00
committed by GitHub
co-authored by Peter Steinberger Peter Steinberger
parent cea0d98efb
commit c94da0df6f
4 changed files with 95 additions and 9 deletions
+34
View File
@@ -26,6 +26,12 @@ vi.mock("../channels/plugins/index.js", () => ({
import { channelsLogsCommand } from "./channels/logs.js";
const runtime = createTestRuntime();
type PositionalRead = (
buffer: Buffer,
offset: number,
length: number,
position: number | null,
) => Promise<{ bytesRead: number; buffer: Buffer }>;
function logLine(params: { module: string; message: string }) {
return JSON.stringify({
@@ -62,6 +68,7 @@ describe("channelsLogsCommand", () => {
});
afterEach(async () => {
vi.restoreAllMocks();
setLoggerOverride(null);
await fs.rm(tempDir, { recursive: true, force: true });
});
@@ -142,6 +149,33 @@ describe("channelsLogsCommand", () => {
expect(payload.lines.map((line) => line.message)).toEqual(["current sent"]);
});
it("fills short positional reads before parsing channel log lines", async () => {
const realOpen = fs.open.bind(fs);
const readLengths: number[] = [];
vi.spyOn(fs, "open").mockImplementation(async (...args) => {
const handle = await realOpen(...args);
const realRead = handle.read.bind(handle) as PositionalRead;
const shortRead = vi.fn<PositionalRead>((buffer, offset, length, position) => {
readLengths.push(length);
return realRead(buffer, offset, Math.min(length, 4), position);
});
Object.defineProperty(handle, "read", { configurable: true, value: shortRead });
return handle;
});
await fs.writeFile(
logPath,
[
logLine({ module: "gateway/channels/slack/send", message: "first" }),
logLine({ module: "gateway/channels/slack/send", message: "second" }),
].join("\n"),
);
await channelsLogsCommand({ channel: "slack", json: true }, runtime);
expect(readJsonPayload().lines.map((line) => line.message)).toEqual(["first", "second"]);
expect(readLengths.length).toBeGreaterThan(1);
});
it("returns the first line of the tail window when start aligns with a line boundary", async () => {
// MAX_BYTES in readTailLines is 1_000_000. We build a file of 2_000_000 bytes
// made of 10_000 lines each exactly 200 bytes (199 payload + "\n"), so the
+3 -3
View File
@@ -5,7 +5,7 @@ import { theme } from "../../../packages/terminal-core/src/theme.js";
import { normalizeChannelId as normalizeBundledChannelId } from "../../channels/registry.js";
import { parseStrictPositiveInteger } from "../../infra/parse-finite-number.js";
import { getResolvedLoggerSettings } from "../../logging.js";
import { resolveLogFile } from "../../logging/log-tail.js";
import { readLogWindowFully, resolveLogFile } from "../../logging/log-tail.js";
import { parseLogLine } from "../../logging/parse-log-line.js";
import { listManifestChannelContributionIds } from "../../plugins/manifest-contribution-ids.js";
import { defaultRuntime, type RuntimeEnv, writeRuntimeJson } from "../../runtime.js";
@@ -87,8 +87,8 @@ async function readTailLines(file: string, limit: number): Promise<string[]> {
return [];
}
const buffer = Buffer.alloc(length);
const readResult = await handle.read(buffer, 0, length, start);
const text = buffer.toString("utf8", 0, readResult.bytesRead);
const bytesRead = await readLogWindowFully(handle, buffer, start);
const text = buffer.toString("utf8", 0, bytesRead);
let lines = text.split("\n");
if (start > 0 && prefix !== "\n") {
lines = lines.slice(1);
+33 -3
View File
@@ -1,11 +1,19 @@
// Log tail tests cover reading, parsing, and limiting recent log entries.
import fs from "node:fs/promises";
import os from "node:os";
import path from "node:path";
import { afterEach, describe, expect, it, vi } from "vitest";
import { useAutoCleanupTempDirTracker } from "../../test/helpers/temp-dir.js";
import { resetLogger, setLoggerOverride } from "../logging.js";
const tempDirs = useAutoCleanupTempDirTracker(afterEach);
const resolvedRedaction = { mode: "tools" as const, patterns: [/custom-secret-[a-z]+/g] };
type PositionalRead = (
buffer: Buffer,
offset: number,
length: number,
position: number | null,
) => Promise<{ bytesRead: number; buffer: Buffer }>;
const { redactSensitiveLinesMock, resolveRedactOptionsMock } = vi.hoisted(() => ({
redactSensitiveLinesMock: vi.fn((lines: string[], options?: unknown) =>
@@ -28,6 +36,7 @@ vi.mock("./redact.js", async () => {
describe("readConfiguredLogTail", () => {
afterEach(() => {
vi.restoreAllMocks();
resolveRedactOptionsMock.mockClear();
redactSensitiveLinesMock.mockClear();
resetLogger();
@@ -36,7 +45,7 @@ describe("readConfiguredLogTail", () => {
it("applies redaction once per request across all returned lines", async () => {
const { readConfiguredLogTail } = await import("./log-tail.js");
const tempDir = await fs.mkdtemp(path.join(os.tmpdir(), "openclaw-log-tail-"));
const tempDir = tempDirs.make("openclaw-log-tail-");
const file = path.join(tempDir, "openclaw-2026-01-22.log");
await fs.writeFile(file, "custom-secret-abcdefghijklmnopqrstuvwxyz\nsecond line\n");
@@ -51,7 +60,28 @@ describe("readConfiguredLogTail", () => {
resolvedRedaction,
);
expect(result.lines).toEqual(["custom…wxyz", "second line"]);
});
await fs.rm(tempDir, { recursive: true, force: true });
it("fills short positional reads before splitting log lines", async () => {
const { readConfiguredLogTail } = await import("./log-tail.js");
const tempDir = tempDirs.make("openclaw-log-tail-");
const file = path.join(tempDir, "openclaw-2026-01-22.log");
const realOpen = fs.open.bind(fs);
vi.spyOn(fs, "open").mockImplementation(async (...args) => {
const handle = await realOpen(...args);
const realRead = handle.read.bind(handle) as PositionalRead;
const shortRead = vi.fn<PositionalRead>((buffer, offset, length, position) =>
realRead(buffer, offset, Math.min(length, 4), position),
);
Object.defineProperty(handle, "read", { configurable: true, value: shortRead });
return handle;
});
await fs.writeFile(file, "old line\nrecent one\nrecent two\n");
setLoggerOverride({ file });
const result = await readConfiguredLogTail();
expect(result.lines).toEqual(["old line", "recent one", "recent two"]);
});
});
+25 -3
View File
@@ -1,5 +1,5 @@
// Log tail helpers read recent log lines with optional parsing and redaction.
import fs from "node:fs/promises";
import fs, { type FileHandle } from "node:fs/promises";
import path from "node:path";
import { getResolvedLoggerSettings } from "../logging.js";
import { clamp } from "../utils.js";
@@ -26,6 +26,28 @@ function isRollingLogFile(file: string): boolean {
return ROLLING_LOG_RE.test(path.basename(file));
}
/** Fills a bounded positional-read buffer unless the file reaches EOF. */
export async function readLogWindowFully(
handle: FileHandle,
buffer: Buffer,
position: number,
): Promise<number> {
let bytesRead = 0;
while (bytesRead < buffer.length) {
const result = await handle.read(
buffer,
bytesRead,
buffer.length - bytesRead,
position + bytesRead,
);
if (result.bytesRead === 0) {
break;
}
bytesRead += result.bytesRead;
}
return bytesRead;
}
/** Resolves a rolling daily log path to the newest existing rolling log when needed. */
export async function resolveLogFile(file: string): Promise<string> {
const stat = await fs.stat(file).catch(() => null);
@@ -126,8 +148,8 @@ async function readLogSlice(params: {
const length = Math.max(0, size - start);
const buffer = Buffer.alloc(length);
const readResult = await handle.read(buffer, 0, length, start);
const text = buffer.toString("utf8", 0, readResult.bytesRead);
const bytesRead = await readLogWindowFully(handle, buffer, start);
const text = buffer.toString("utf8", 0, bytesRead);
let lines = text.split("\n");
if (start > 0 && prefix !== "\n") {
// Drop the first partial line when starting in the middle of a file.