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

qingminglong · steipete · web-flow · commit c94da0df6f38 · 2026-07-14T14:47:53.000-07:00
* fix(logs): preserve log tails across short reads

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

---------

Co-authored-by: Peter Steinberger &lt;peter@steipete.me&gt;
Co-authored-by: Peter Steinberger &lt;steipete@gmail.com&gt;
diff --git a/src/commands/channels.logs.test.ts b/src/commands/channels.logs.test.ts
@@ -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
diff --git a/src/commands/channels/logs.ts b/src/commands/channels/logs.ts
@@ -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);
diff --git a/src/logging/log-tail.test.ts b/src/logging/log-tail.test.ts
@@ -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"]);
+  });
+
+  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();
 
-    await fs.rm(tempDir, { recursive: true, force: true });
+    expect(result.lines).toEqual(["old line", "recent one", "recent two"]);
   });
 });
diff --git a/src/logging/log-tail.ts b/src/logging/log-tail.ts
@@ -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.
