mirror of
https://github.com/openclaw/openclaw.git
synced 2026-10-04 02:00:10 +00:00
fix(gateway): debug log floods with event-loop-health scheduler lines (#161895)
* fix(gateway): debug log floods with event-loop-health scheduler lines Since event-loop sampling moved onto the Gateway scheduler as a 20 ms cadence job, the scheduler's per-run "running <id>" debug line fires about 47 times a second. With logging.level "debug" that line is about 98% of the file log, so the default rolling log keeps only about 8 hours. Log repeating cadence runs at trace and keep one-shot runs at debug. Run failures still log at error. Closes #161891 * test(hooks): give the Gmail watcher's logger mock a trace method The Gmail watcher renews through a Gateway scheduler cadence job, whose per-run line is now logged at trace. The test's subsystem logger mock had no trace method, so every renewal threw "log.trace is not a function".
This commit is contained in:
parent
fbb4b36376
commit
b2fc927ff4
3 changed files with 33 additions and 2 deletions
|
|
@ -11,7 +11,7 @@ const mocks = vi.hoisted(() => ({
|
|||
runCommandWithTimeout: vi.fn(),
|
||||
killProcessTree: vi.fn(),
|
||||
spawn: vi.fn(),
|
||||
log: { debug: vi.fn(), error: vi.fn(), warn: vi.fn(), info: vi.fn() },
|
||||
log: { debug: vi.fn(), trace: vi.fn(), error: vi.fn(), warn: vi.fn(), info: vi.fn() },
|
||||
defaultRuntime: {
|
||||
log: vi.fn(),
|
||||
error: vi.fn(),
|
||||
|
|
|
|||
|
|
@ -7,6 +7,11 @@ import {
|
|||
createTestGatewayScheduler,
|
||||
} from "../test-utils/gateway-scheduler-clock.js";
|
||||
|
||||
const schedulerLog = vi.hoisted(() => ({ debug: vi.fn(), trace: vi.fn(), error: vi.fn() }));
|
||||
vi.mock("../logging/subsystem.js", () => ({
|
||||
createSubsystemLogger: () => schedulerLog,
|
||||
}));
|
||||
|
||||
function fixture() {
|
||||
const time = createGatewaySchedulerClock(1_000);
|
||||
const scheduler = createTestGatewayScheduler(time.clock);
|
||||
|
|
@ -331,6 +336,26 @@ describe("Gateway timed work", () => {
|
|||
await scheduler.stop();
|
||||
});
|
||||
|
||||
it("logs one-shot runs at debug and repeating cadence runs only at trace", async () => {
|
||||
const { time, scheduler } = fixture();
|
||||
schedulerLog.debug.mockClear();
|
||||
schedulerLog.trace.mockClear();
|
||||
const sample = vi.fn();
|
||||
scheduler.schedule({ id: "event-loop-health", delayMs: 20, everyMs: 20, run: sample });
|
||||
scheduler.schedule({ id: "approval", delayMs: 30, run: () => {} });
|
||||
await time.advanceBy(20);
|
||||
await time.advanceBy(20);
|
||||
await time.advanceBy(20);
|
||||
expect(sample).toHaveBeenCalledTimes(3);
|
||||
expect(schedulerLog.debug.mock.calls).toEqual([["running approval"]]);
|
||||
expect(schedulerLog.trace.mock.calls).toEqual([
|
||||
["running event-loop-health"],
|
||||
["running event-loop-health"],
|
||||
["running event-loop-health"],
|
||||
]);
|
||||
await scheduler.stop();
|
||||
});
|
||||
|
||||
it("retains a distant deadline across the host timer delay ceiling", async () => {
|
||||
const { time, scheduler } = fixture();
|
||||
const run = vi.fn();
|
||||
|
|
|
|||
|
|
@ -274,7 +274,13 @@ export class GatewayScheduler {
|
|||
}
|
||||
|
||||
private run(job: ScheduledWork): Promise<void> {
|
||||
log.debug(`running ${job.id}`);
|
||||
// Cadence jobs can run every few milliseconds (event-loop sampling runs every 20ms),
|
||||
// so only one-shot runs are worth a debug line.
|
||||
if (job.everyMs === undefined) {
|
||||
log.debug(`running ${job.id}`);
|
||||
} else {
|
||||
log.trace(`running ${job.id}`);
|
||||
}
|
||||
const done = createDeferredCore();
|
||||
const work = new AsyncWorkScope();
|
||||
job.running = done.promise;
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue