mirror of
https://github.com/openclaw/openclaw.git
synced 2026-05-06 06:10:44 +00:00
fix(logging): rotate file logs instead of suppressing
This commit is contained in:
@@ -104,6 +104,10 @@ Docs: https://docs.openclaw.ai
|
||||
OpenClaw config path in bundled runtimes, so packaged gateways stop falling
|
||||
back to `/tmp/openclaw`. Fixes #59370, #67168, and #61295. Thanks @KeaneYan,
|
||||
@Pan9hu, and @zsjlovelike.
|
||||
- Logging: rotate file logs at `logging.maxFileBytes`, keep bounded numbered
|
||||
archives, and make long-lived rolling loggers follow the current-day file
|
||||
instead of suppressing diagnostics or writing stale dated files. Fixes #58583
|
||||
and #62381. Thanks @jpeghead and @zhaoleink.
|
||||
- Agents/groups: treat clean empty assistant stops as silent `NO_REPLY` only for always-on groups where silent replies are allowed, while keeping direct and mention-gated sessions on the incomplete-turn retry path. Thanks @MagnaAI.
|
||||
- macOS/Node: keep native remote app nodes from advertising `browser.proxy`,
|
||||
start browser-capable CLI node services through the restored
|
||||
|
||||
@@ -858,7 +858,7 @@ Notes:
|
||||
- Default log file: `/tmp/openclaw/openclaw-YYYY-MM-DD.log`.
|
||||
- Set `logging.file` for a stable path.
|
||||
- `consoleLevel` bumps to `debug` when `--verbose`.
|
||||
- `maxFileBytes`: maximum log file size in bytes before writes are suppressed (positive integer; default: `524288000` = 500 MB). Use external log rotation for production deployments.
|
||||
- `maxFileBytes`: maximum active log file size in bytes before rotation (positive integer; default: `104857600` = 100 MB). OpenClaw keeps up to five numbered archives beside the active file.
|
||||
|
||||
---
|
||||
|
||||
|
||||
@@ -19,6 +19,8 @@ OpenClaw has two log “surfaces”:
|
||||
|
||||
- Default rolling log file is under `/tmp/openclaw/` (one file per day): `openclaw-YYYY-MM-DD.log`
|
||||
- Date uses the gateway host's local timezone.
|
||||
- Active log files rotate at `logging.maxFileBytes` (default: 100 MB), keeping
|
||||
up to five numbered archives and continuing to write a fresh active file.
|
||||
- The log file path and level can be configured via `~/.openclaw/openclaw.json`:
|
||||
- `logging.file`
|
||||
- `logging.level`
|
||||
|
||||
@@ -23,6 +23,11 @@ By default, the Gateway writes a rolling log file under:
|
||||
|
||||
The date uses the gateway host's local timezone.
|
||||
|
||||
Each file rotates when it reaches `logging.maxFileBytes` (default: 100 MB).
|
||||
OpenClaw keeps up to five numbered archives beside the active file, such as
|
||||
`openclaw-YYYY-MM-DD.1.log`, and keeps writing to a fresh active log instead of
|
||||
suppressing diagnostics.
|
||||
|
||||
You can override this in `~/.openclaw/openclaw.json`:
|
||||
|
||||
```json
|
||||
|
||||
@@ -221,7 +221,7 @@ export type SessionMaintenanceConfig = {
|
||||
export type LoggingConfig = {
|
||||
level?: "silent" | "fatal" | "error" | "warn" | "info" | "debug" | "trace";
|
||||
file?: string;
|
||||
/** Maximum size of a single log file in bytes before writes are suppressed. Default: 500 MB. */
|
||||
/** Maximum size of a single log file in bytes before rotation. Default: 100 MB. */
|
||||
maxFileBytes?: number;
|
||||
consoleLevel?: "silent" | "fatal" | "error" | "warn" | "info" | "debug" | "trace";
|
||||
consoleStyle?: "pretty" | "compact" | "json";
|
||||
|
||||
@@ -1,4 +1,5 @@
|
||||
import fs from "node:fs";
|
||||
import path from "node:path";
|
||||
import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest";
|
||||
import {
|
||||
getLogger,
|
||||
@@ -8,9 +9,15 @@ import {
|
||||
} from "../logging.js";
|
||||
import { createSuiteLogPathTracker } from "./log-test-helpers.js";
|
||||
|
||||
const DEFAULT_MAX_FILE_BYTES = 500 * 1024 * 1024;
|
||||
const DEFAULT_MAX_FILE_BYTES = 100 * 1024 * 1024;
|
||||
const logPathTracker = createSuiteLogPathTracker("openclaw-log-cap-");
|
||||
|
||||
function rotatedLogPath(file: string, index: number): string {
|
||||
const ext = path.extname(file);
|
||||
const base = file.slice(0, file.length - ext.length);
|
||||
return `${base}.${index}${ext}`;
|
||||
}
|
||||
|
||||
describe("log file size cap", () => {
|
||||
let logPath = "";
|
||||
|
||||
@@ -27,6 +34,7 @@ describe("log file size cap", () => {
|
||||
afterEach(() => {
|
||||
resetLogger();
|
||||
setLoggerOverride(null);
|
||||
vi.useRealTimers();
|
||||
vi.restoreAllMocks();
|
||||
try {
|
||||
fs.rmSync(logPath, { force: true });
|
||||
@@ -39,7 +47,7 @@ describe("log file size cap", () => {
|
||||
await logPathTracker.cleanup();
|
||||
});
|
||||
|
||||
it("defaults maxFileBytes to 500 MB when unset", () => {
|
||||
it("defaults maxFileBytes to 100 MB when unset", () => {
|
||||
setLoggerOverride({ level: "info", file: logPath });
|
||||
expect(getResolvedLoggerSettings().maxFileBytes).toBe(DEFAULT_MAX_FILE_BYTES);
|
||||
});
|
||||
@@ -49,27 +57,42 @@ describe("log file size cap", () => {
|
||||
expect(getResolvedLoggerSettings().maxFileBytes).toBe(2048);
|
||||
});
|
||||
|
||||
it("suppresses file writes after cap is reached and warns once", () => {
|
||||
it("rotates file writes after cap is reached and keeps logging", () => {
|
||||
const stderrSpy = vi.spyOn(process.stderr, "write").mockImplementation(
|
||||
() => true as unknown as ReturnType<typeof process.stderr.write>, // preserve stream contract in test spy
|
||||
);
|
||||
setLoggerOverride({ level: "info", file: logPath, maxFileBytes: 1024 });
|
||||
setLoggerOverride({ level: "info", file: logPath, maxFileBytes: 256 });
|
||||
const logger = getLogger();
|
||||
|
||||
for (let i = 0; i < 200; i++) {
|
||||
logger.error(`network-failure-${i}-${"x".repeat(80)}`);
|
||||
}
|
||||
const sizeAfterCap = fs.statSync(logPath).size;
|
||||
for (let i = 0; i < 20; i++) {
|
||||
logger.error(`post-cap-${i}-${"y".repeat(80)}`);
|
||||
}
|
||||
const sizeAfterExtraLogs = fs.statSync(logPath).size;
|
||||
logger.error(`network-failure-${"x".repeat(400)}`);
|
||||
logger.error("post-rotation-diagnostic");
|
||||
|
||||
expect(sizeAfterExtraLogs).toBe(sizeAfterCap);
|
||||
expect(sizeAfterCap).toBeLessThanOrEqual(1024 + 512);
|
||||
const capWarnings = stderrSpy.mock.calls
|
||||
const currentContent = fs.readFileSync(logPath, "utf8");
|
||||
const archiveContent = fs.readFileSync(rotatedLogPath(logPath, 1), "utf8");
|
||||
expect(currentContent).toContain("post-rotation-diagnostic");
|
||||
expect(currentContent).not.toContain("network-failure");
|
||||
expect(archiveContent).toContain("network-failure");
|
||||
const rotationWarnings = stderrSpy.mock.calls
|
||||
.map(([firstArg]) => String(firstArg))
|
||||
.filter((line) => line.includes("log file size cap reached"));
|
||||
expect(capWarnings).toHaveLength(1);
|
||||
.filter((line) => line.includes("log file rotation failed"));
|
||||
expect(rotationWarnings).toHaveLength(0);
|
||||
});
|
||||
|
||||
it("keeps cached default rolling loggers on the current-day file", () => {
|
||||
const logDir = path.dirname(logPath);
|
||||
const firstDay = path.join(logDir, "openclaw-2026-01-01.log");
|
||||
const secondDay = path.join(logDir, "openclaw-2026-01-02.log");
|
||||
vi.useFakeTimers();
|
||||
vi.setSystemTime(new Date("2026-01-01T08:00:00Z"));
|
||||
setLoggerOverride({ level: "info", file: firstDay });
|
||||
const logger = getLogger();
|
||||
|
||||
logger.info({ message: "first day" });
|
||||
vi.setSystemTime(new Date("2026-01-02T08:00:00Z"));
|
||||
logger.info({ message: "second day" });
|
||||
|
||||
expect(fs.readFileSync(firstDay, "utf8")).toContain("first day");
|
||||
expect(fs.readFileSync(secondDay, "utf8")).toContain("second day");
|
||||
expect(fs.readFileSync(firstDay, "utf8")).not.toContain("second day");
|
||||
});
|
||||
});
|
||||
|
||||
@@ -8,7 +8,7 @@ import {
|
||||
import { createSuiteLogPathTracker } from "./log-test-helpers.js";
|
||||
import { loggingState } from "./state.js";
|
||||
|
||||
const defaultMaxFileBytes = 500 * 1024 * 1024;
|
||||
const defaultMaxFileBytes = 100 * 1024 * 1024;
|
||||
const logPathTracker = createSuiteLogPathTracker("openclaw-test-env-log-level-");
|
||||
|
||||
describe("OPENCLAW_LOG_LEVEL", () => {
|
||||
|
||||
@@ -55,7 +55,8 @@ export const DEFAULT_LOG_FILE = resolveDefaultLogFile(DEFAULT_LOG_DIR); // legac
|
||||
const LOG_PREFIX = "openclaw";
|
||||
const LOG_SUFFIX = ".log";
|
||||
const MAX_LOG_AGE_MS = 24 * 60 * 60 * 1000; // 24h
|
||||
const DEFAULT_MAX_LOG_FILE_BYTES = 500 * 1024 * 1024; // 500 MB
|
||||
const DEFAULT_MAX_LOG_FILE_BYTES = 100 * 1024 * 1024; // 100 MB
|
||||
const MAX_ROTATED_LOG_FILES = 5;
|
||||
|
||||
type LogObj = { date?: Date } & Record<string, unknown>;
|
||||
|
||||
@@ -397,39 +398,45 @@ function buildLogger(settings: ResolvedSettings): TsLogger<LogObj> {
|
||||
return logger;
|
||||
}
|
||||
|
||||
fs.mkdirSync(path.dirname(settings.file), { recursive: true });
|
||||
const rollingFile = isRollingPath(settings.file);
|
||||
let activeFile = resolveActiveLogFile(settings.file);
|
||||
fs.mkdirSync(path.dirname(activeFile), { recursive: true });
|
||||
// Clean up stale rolling logs when using a dated log filename.
|
||||
if (isRollingPath(settings.file)) {
|
||||
pruneOldRollingLogs(path.dirname(settings.file));
|
||||
if (rollingFile) {
|
||||
pruneOldRollingLogs(path.dirname(activeFile));
|
||||
}
|
||||
let currentFileBytes = getCurrentLogFileBytes(settings.file);
|
||||
let warnedAboutSizeCap = false;
|
||||
let currentFileBytes = getCurrentLogFileBytes(activeFile);
|
||||
let warnedAboutRotationFailure = false;
|
||||
|
||||
logger.attachTransport((logObj: LogObj) => {
|
||||
try {
|
||||
const nextActiveFile = resolveActiveLogFile(settings.file);
|
||||
if (nextActiveFile !== activeFile) {
|
||||
activeFile = nextActiveFile;
|
||||
fs.mkdirSync(path.dirname(activeFile), { recursive: true });
|
||||
if (rollingFile) {
|
||||
pruneOldRollingLogs(path.dirname(activeFile));
|
||||
}
|
||||
currentFileBytes = getCurrentLogFileBytes(activeFile);
|
||||
}
|
||||
const time = formatTimestamp(logObj.date ?? new Date(), { style: "long" });
|
||||
const line = redactSensitiveText(JSON.stringify({ ...logObj, time }));
|
||||
const payload = `${line}\n`;
|
||||
const payloadBytes = Buffer.byteLength(payload, "utf8");
|
||||
const nextBytes = currentFileBytes + payloadBytes;
|
||||
if (nextBytes > settings.maxFileBytes) {
|
||||
if (!warnedAboutSizeCap) {
|
||||
warnedAboutSizeCap = true;
|
||||
const warningLine = JSON.stringify({
|
||||
time: formatTimestamp(new Date(), { style: "long" }),
|
||||
level: "warn",
|
||||
subsystem: "logging",
|
||||
message: `log file size cap reached; suppressing writes file=${settings.file} maxFileBytes=${settings.maxFileBytes}`,
|
||||
});
|
||||
appendLogLine(settings.file, `${warningLine}\n`);
|
||||
if (currentFileBytes > 0 && nextBytes > settings.maxFileBytes) {
|
||||
if (rotateLogFile(activeFile)) {
|
||||
currentFileBytes = getCurrentLogFileBytes(activeFile);
|
||||
warnedAboutRotationFailure = false;
|
||||
} else if (!warnedAboutRotationFailure) {
|
||||
warnedAboutRotationFailure = true;
|
||||
process.stderr.write(
|
||||
`[openclaw] log file size cap reached; suppressing writes file=${settings.file} maxFileBytes=${settings.maxFileBytes}\n`,
|
||||
`[openclaw] log file rotation failed; continuing writes file=${activeFile} maxFileBytes=${settings.maxFileBytes}\n`,
|
||||
);
|
||||
}
|
||||
return;
|
||||
}
|
||||
if (appendLogLine(settings.file, payload)) {
|
||||
currentFileBytes = nextBytes;
|
||||
if (appendLogLine(activeFile, payload)) {
|
||||
currentFileBytes += payloadBytes;
|
||||
}
|
||||
} catch {
|
||||
// never block on logging failures
|
||||
@@ -554,8 +561,19 @@ function formatLocalDate(date: Date): string {
|
||||
}
|
||||
|
||||
function defaultRollingPathForToday(): string {
|
||||
const today = formatLocalDate(new Date());
|
||||
return path.join(DEFAULT_LOG_DIR, `${LOG_PREFIX}-${today}${LOG_SUFFIX}`);
|
||||
return rollingPathForDate(DEFAULT_LOG_DIR, new Date());
|
||||
}
|
||||
|
||||
function rollingPathForDate(dir: string, date: Date): string {
|
||||
const today = formatLocalDate(date);
|
||||
return path.join(dir, `${LOG_PREFIX}-${today}${LOG_SUFFIX}`);
|
||||
}
|
||||
|
||||
function resolveActiveLogFile(file: string): string {
|
||||
if (!isRollingPath(file)) {
|
||||
return file;
|
||||
}
|
||||
return rollingPathForDate(path.dirname(file), new Date());
|
||||
}
|
||||
|
||||
function isRollingPath(file: string): boolean {
|
||||
@@ -592,3 +610,29 @@ function pruneOldRollingLogs(dir: string): void {
|
||||
// ignore missing dir or read errors
|
||||
}
|
||||
}
|
||||
|
||||
function rotatedLogPath(file: string, index: number): string {
|
||||
const ext = path.extname(file);
|
||||
const base = file.slice(0, file.length - ext.length);
|
||||
return `${base}.${index}${ext}`;
|
||||
}
|
||||
|
||||
function rotateLogFile(file: string): boolean {
|
||||
try {
|
||||
fs.mkdirSync(path.dirname(file), { recursive: true });
|
||||
fs.rmSync(rotatedLogPath(file, MAX_ROTATED_LOG_FILES), { force: true });
|
||||
for (let index = MAX_ROTATED_LOG_FILES - 1; index >= 1; index -= 1) {
|
||||
const from = rotatedLogPath(file, index);
|
||||
if (!fs.existsSync(from)) {
|
||||
continue;
|
||||
}
|
||||
fs.renameSync(from, rotatedLogPath(file, index + 1));
|
||||
}
|
||||
if (fs.existsSync(file)) {
|
||||
fs.renameSync(file, rotatedLogPath(file, 1));
|
||||
}
|
||||
return true;
|
||||
} catch {
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
||||
@@ -1,9 +1,14 @@
|
||||
import { afterEach, describe, expect, it, vi } from "vitest";
|
||||
import fs from "node:fs";
|
||||
import path from "node:path";
|
||||
import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "vitest";
|
||||
import { setConsoleSubsystemFilter, shouldLogSubsystemToConsole } from "./console.js";
|
||||
import { createSuiteLogPathTracker } from "./log-test-helpers.js";
|
||||
import { resetLogger, setLoggerOverride } from "./logger.js";
|
||||
import { loggingState } from "./state.js";
|
||||
import { createSubsystemLogger } from "./subsystem.js";
|
||||
|
||||
const logPathTracker = createSuiteLogPathTracker("openclaw-subsystem-log-");
|
||||
|
||||
function installConsoleMethodSpy(method: "warn" | "error") {
|
||||
const spy = vi.fn();
|
||||
loggingState.rawConsole = {
|
||||
@@ -15,11 +20,20 @@ function installConsoleMethodSpy(method: "warn" | "error") {
|
||||
return spy;
|
||||
}
|
||||
|
||||
beforeAll(async () => {
|
||||
await logPathTracker.setup();
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
setConsoleSubsystemFilter(null);
|
||||
setLoggerOverride(null);
|
||||
loggingState.rawConsole = null;
|
||||
resetLogger();
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
afterAll(async () => {
|
||||
await logPathTracker.cleanup();
|
||||
});
|
||||
|
||||
describe("createSubsystemLogger().isEnabled", () => {
|
||||
@@ -190,4 +204,22 @@ describe("createSubsystemLogger().isEnabled", () => {
|
||||
|
||||
expect(warn).toHaveBeenCalledTimes(1);
|
||||
});
|
||||
|
||||
it("keeps long-lived subsystem loggers on the current-day rolling file", () => {
|
||||
const logDir = path.dirname(logPathTracker.nextPath());
|
||||
const firstDay = path.join(logDir, "openclaw-2026-01-01.log");
|
||||
const secondDay = path.join(logDir, "openclaw-2026-01-02.log");
|
||||
vi.useFakeTimers();
|
||||
vi.setSystemTime(new Date("2026-01-01T08:00:00Z"));
|
||||
setLoggerOverride({ level: "info", consoleLevel: "silent", file: firstDay });
|
||||
const log = createSubsystemLogger("diagnostics");
|
||||
|
||||
log.info("first day subsystem log");
|
||||
vi.setSystemTime(new Date("2026-01-02T08:00:00Z"));
|
||||
log.info("second day subsystem log");
|
||||
|
||||
expect(fs.readFileSync(firstDay, "utf8")).toContain("first day subsystem log");
|
||||
expect(fs.readFileSync(secondDay, "utf8")).toContain("second day subsystem log");
|
||||
expect(fs.readFileSync(firstDay, "utf8")).not.toContain("second day subsystem log");
|
||||
});
|
||||
});
|
||||
|
||||
@@ -324,7 +324,6 @@ function logToFile(
|
||||
|
||||
export function createSubsystemLogger(subsystem: string): SubsystemLogger {
|
||||
const resolvedSubsystem = normalizeSubsystemLabel(subsystem);
|
||||
let fileLogger: TsLogger<LogObj> | null = null;
|
||||
|
||||
const emitLog = (level: LogLevel, message: string, meta?: Record<string, unknown>) => {
|
||||
const consoleSettings = getConsoleSettings();
|
||||
@@ -347,10 +346,7 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
|
||||
fileMeta = Object.keys(rest).length > 0 ? rest : undefined;
|
||||
}
|
||||
if (fileEnabled) {
|
||||
if (!fileLogger) {
|
||||
fileLogger = getChildLogger({ subsystem: resolvedSubsystem });
|
||||
}
|
||||
logToFile(fileLogger, level, message, fileMeta);
|
||||
logToFile(getChildLogger({ subsystem: resolvedSubsystem }), level, message, fileMeta);
|
||||
}
|
||||
if (!consoleEnabled) {
|
||||
return;
|
||||
@@ -413,10 +409,7 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
|
||||
},
|
||||
raw(message) {
|
||||
if (isFileLogLevelEnabled("info")) {
|
||||
if (!fileLogger) {
|
||||
fileLogger = getChildLogger({ subsystem: resolvedSubsystem });
|
||||
}
|
||||
logToFile(fileLogger, "info", message, { raw: true });
|
||||
logToFile(getChildLogger({ subsystem: resolvedSubsystem }), "info", message, { raw: true });
|
||||
}
|
||||
if (
|
||||
shouldLogToConsole("info", { level: getConsoleSettings().level }) &&
|
||||
|
||||
Reference in New Issue
Block a user