diff --git a/.changeset/steady-log-rotation.md b/.changeset/steady-log-rotation.md new file mode 100644 index 000000000..48d339fdd --- /dev/null +++ b/.changeset/steady-log-rotation.md @@ -0,0 +1,6 @@ +--- +"@moonshot-ai/agent-core": patch +"@moonshot-ai/kimi-code": patch +--- + +Avoid surfacing diagnostic log rotation failures when a shared log file is temporarily busy. diff --git a/packages/agent-core/src/logging/sinks.ts b/packages/agent-core/src/logging/sinks.ts index ef23eb101..69b6d3f02 100644 --- a/packages/agent-core/src/logging/sinks.ts +++ b/packages/agent-core/src/logging/sinks.ts @@ -6,6 +6,7 @@ import { syncDir } from '#/utils/fs'; export const PENDING_MAX = 1000; const STDERR_NOTICE_INTERVAL_MS = 30_000; +const TRANSIENT_ROTATION_ERROR_CODES = new Set(['EBUSY', 'EPERM']); class AsyncSerialQueue { private tail: Promise = Promise.resolve(); @@ -168,28 +169,35 @@ export class RotatingFileSink implements Sink { private async rotate(): Promise { const { path, files } = this.options; + this.directorySynced = false; for (let i = files - 2; i >= 1; i--) { const from = `${path}.${i}`; const to = `${path}.${i + 1}`; try { await rename(from, to); } catch (error) { - if ((error as NodeJS.ErrnoException).code !== 'ENOENT') throw error; + if (isNotFoundError(error)) continue; + if (isTransientRotationError(error)) return; + throw error; } } try { await rename(path, `${path}.1`); } catch (error) { - if ((error as NodeJS.ErrnoException).code !== 'ENOENT') throw error; + if (isNotFoundError(error)) { + this.currentBytes = 0; + return; + } + if (isTransientRotationError(error)) return; + throw error; } // last archive may be evicted; ensure we don't keep > files try { await unlink(`${path}.${files}`); } catch (error) { - if ((error as NodeJS.ErrnoException).code !== 'ENOENT') throw error; + if (!isNotFoundError(error) && !isTransientRotationError(error)) throw error; } this.currentBytes = 0; - this.directorySynced = false; } private async statSize(p: string): Promise { @@ -219,3 +227,11 @@ export class RotatingFileSink implements Sink { } catch {} } } + +function isNotFoundError(error: unknown): boolean { + return (error as NodeJS.ErrnoException).code === 'ENOENT'; +} + +function isTransientRotationError(error: unknown): boolean { + return TRANSIENT_ROTATION_ERROR_CODES.has((error as NodeJS.ErrnoException).code ?? ''); +} diff --git a/packages/agent-core/test/logging/sinks.test.ts b/packages/agent-core/test/logging/sinks.test.ts index 48a199f21..af67cdcf7 100644 --- a/packages/agent-core/test/logging/sinks.test.ts +++ b/packages/agent-core/test/logging/sinks.test.ts @@ -1,9 +1,33 @@ -import { mkdtemp, readFile, readdir, rm, stat } from 'node:fs/promises'; +/* eslint-disable import/first -- vi.mock setup must run before RotatingFileSink imports fs promises. */ +import type * as FsPromises from 'node:fs/promises'; import { tmpdir } from 'node:os'; import { join } from 'pathe'; import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; +const fsMockState = vi.hoisted(() => ({ + blockedRename: undefined as { from: string; to: string; code: string } | undefined, +})); + +vi.mock('node:fs/promises', async () => { + const actual = await vi.importActual('node:fs/promises'); + return { + ...actual, + rename: async (...args: Parameters) => { + const [from, to] = args; + const blockedRename = fsMockState.blockedRename; + if (blockedRename && String(from) === blockedRename.from && String(to) === blockedRename.to) { + throw Object.assign(new Error(`${blockedRename.code}: busy rename`), { + code: blockedRename.code, + }); + } + return actual.rename(...args); + }, + }; +}); + +import { mkdtemp, readFile, readdir, rm, stat, writeFile } from 'node:fs/promises'; + import { PENDING_MAX, RotatingFileSink } from '#/logging/sinks'; let workDir: string; @@ -13,6 +37,7 @@ beforeEach(async () => { }); afterEach(async () => { + fsMockState.blockedRename = undefined; await rm(workDir, { recursive: true, force: true }); }); @@ -78,6 +103,57 @@ describe('RotatingFileSink', () => { } }); + it('keeps writing when rotation is temporarily blocked', async () => { + const path = join(workDir, 'app.log'); + await writeFile(path, 'seed\n', 'utf-8'); + fsMockState.blockedRename = { + from: path, + to: `${path}.1`, + code: 'EBUSY', + }; + + const stderrSpy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + try { + const sink = new RotatingFileSink({ path, maxBytes: 8, files: 2 }); + sink.enqueue('after\n'); + + expect(await sink.flush()).toBe(true); + + const text = await readFile(path, 'utf-8'); + expect(text).toContain('seed\n'); + expect(text).toContain('after\n'); + expect(stderrSpy.mock.calls.some((c) => String(c[0]).includes('[logger] write failed'))).toBe( + false, + ); + } finally { + stderrSpy.mockRestore(); + } + }); + + it('surfaces permanent EACCES rotation failures', async () => { + const path = join(workDir, 'app.log'); + await writeFile(path, 'seed\n', 'utf-8'); + fsMockState.blockedRename = { + from: path, + to: `${path}.1`, + code: 'EACCES', + }; + + const stderrSpy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + try { + const sink = new RotatingFileSink({ path, maxBytes: 8, files: 2 }); + sink.enqueue('after\n'); + + expect(await sink.flush()).toBe(false); + expect(await readFile(path, 'utf-8')).toBe('seed\n'); + expect(stderrSpy.mock.calls.some((c) => String(c[0]).includes('[logger] write failed'))).toBe( + true, + ); + } finally { + stderrSpy.mockRestore(); + } + }); + it('drops oldest when pending overflows', async () => { const path = join(workDir, 'app.log'); const sink = new RotatingFileSink({ path, maxBytes: 1_000_000, files: 2 });