Skip to content

Commit 415fdd9

Browse files
authored
feat: add verbose log level between info and debug for improved observability (#529)
# Add verbose log level and improve task execution logging This PR introduces a new `verbose` log level between `info` and `debug` to provide better granularity for operational logging. The change: - Adds a `verbose` method to the `Logger` interface - Updates the logging hierarchy to: `error < warn < info < verbose < debug` - Moves frequent operational logs from `debug` to `verbose` level - Adds execution duration tracking for step tasks - Improves log messages for task execution with timing information - Adds comprehensive unit tests for the new logging level The verbose level allows us to keep operational visibility without the excessive detail of debug logs, making it easier to monitor production systems.
1 parent 1983cfa commit 415fdd9

File tree

12 files changed

+168
-7
lines changed

12 files changed

+168
-7
lines changed

pkgs/edge-worker/deno.lock

Lines changed: 7 additions & 0 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

pkgs/edge-worker/src/core/BatchProcessor.ts

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,15 +18,15 @@ export class BatchProcessor<TMessage extends IMessage> {
1818
}
1919

2020
async processBatch() {
21-
this.logger.debug('Polling for new batch of messages...');
21+
this.logger.verbose('Polling for new batch of messages...');
2222
const messageRecords = await this.poller.poll();
2323

2424
if (this.signal.aborted) {
2525
this.logger.info('Discarding messageRecords because worker is stopping');
2626
return;
2727
}
2828

29-
this.logger.debug(`Starting ${messageRecords.length} messages`);
29+
this.logger.verbose(`Starting ${messageRecords.length} tasks`);
3030

3131
const startPromises = messageRecords.map((message) =>
3232
this.executionController.start(message)

pkgs/edge-worker/src/flow/StepTaskExecutor.ts

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -62,13 +62,17 @@ export class StepTaskExecutor<TFlow extends AnyFlow, TContext extends StepTaskHa
6262
throw new Error(`No step definition found for slug=${stepSlug}`);
6363
}
6464

65+
// Measure handler execution duration
66+
const startTime = Date.now();
6567

6668
// !!! HANDLER EXECUTION !!!
6769
const result = await stepDef.handler(this.stepTask.input, this.context);
6870
// !!! HANDLER EXECUTION !!!
6971

70-
this.logger.debug(
71-
`step task ${this.msgId} completed successfully, marking as complete`
72+
const durationMs = Date.now() - startTime;
73+
74+
this.logger.verbose(
75+
`step task ${this.msgId} completed in ${durationMs}ms`
7276
);
7377
await this.adapter.completeTask(this.stepTask, result);
7478

@@ -92,7 +96,7 @@ export class StepTaskExecutor<TFlow extends AnyFlow, TContext extends StepTaskHa
9296
// Do not mark as failed - the worker was aborted and stopping,
9397
// the task will be picked up by another worker later
9498
} else {
95-
this.logger.error(
99+
this.logger.verbose(
96100
`step task ${this.msgId} failed with error: ${error}`
97101
);
98102
await this.adapter.failTask(this.stepTask, error);

pkgs/edge-worker/src/platform/logging.ts

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,8 @@ export function createLoggingFactory() {
1212
const loggers: Map<string, Logger> = new Map();
1313

1414
// Simple level filtering
15-
const levels = { error: 0, warn: 1, info: 2, debug: 3 };
15+
// Hierarchy: error < warn < info < verbose < debug
16+
const levels = { error: 0, warn: 1, info: 2, verbose: 3, debug: 4 };
1617

1718
/**
1819
* Creates a new logger for a specific module
@@ -42,6 +43,17 @@ export function createLoggingFactory() {
4243
);
4344
}
4445
},
46+
verbose: (message, ...args) => {
47+
const levelValue =
48+
levels[logLevel as keyof typeof levels] ?? levels.info;
49+
if (levelValue >= levels.verbose) {
50+
// Use console.log for verbose messages
51+
console.log(
52+
`worker_id=${sharedWorkerId} module=${module} ${message}`,
53+
...args
54+
);
55+
}
56+
},
4557
warn: (message, ...args) => {
4658
const levelValue =
4759
levels[logLevel as keyof typeof levels] ?? levels.info;

pkgs/edge-worker/src/platform/types.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import type { Worker } from '../core/Worker.js';
55
*/
66
export interface Logger {
77
debug(message: string, ...args: unknown[]): void;
8+
verbose(message: string, ...args: unknown[]): void;
89
info(message: string, ...args: unknown[]): void;
910
warn(message: string, ...args: unknown[]): void;
1011
error(message: string, ...args: unknown[]): void;

pkgs/edge-worker/tests/fakes.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ const noop = () => {};
44

55
export const fakeLogger: Logger = {
66
debug: noop,
7+
verbose: noop,
78
info: noop,
89
warn: noop,
910
error: noop,

pkgs/edge-worker/tests/integration/_helpers.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,7 @@ export function startWorker<TFlow extends AnyFlow>(
6666

6767
const consoleLogger = {
6868
debug: console.log,
69+
verbose: console.log,
6970
info: console.log,
7071
warn: console.warn,
7172
error: console.error,

pkgs/edge-worker/tests/integration/flow/compilationAtStartup.test.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ const TestCompilationFlow = new Flow<{ value: number }>({ slug: 'test_compilatio
1818
function createLogger(module: string) {
1919
return {
2020
debug: console.log.bind(console, `[${module}]`),
21+
verbose: console.log.bind(console, `[${module}]`),
2122
info: console.log.bind(console, `[${module}]`),
2223
warn: console.warn.bind(console, `[${module}]`),
2324
error: console.error.bind(console, `[${module}]`),

pkgs/edge-worker/tests/unit/FlowWorkerLifecycle.compilation.test.ts

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -55,6 +55,7 @@ const createMockFlow = () => TestFlow;
5555

5656
const createLogger = (): Logger => ({
5757
debug: () => {},
58+
verbose: () => {},
5859
info: () => {},
5960
error: () => {},
6061
warn: () => {},
@@ -128,6 +129,7 @@ Deno.test('FlowWorkerLifecycle - logs skip message when ensureCompiledOnStartup
128129
const logs: string[] = [];
129130
const testLogger: Logger = {
130131
debug: () => {},
132+
verbose: () => {},
131133
info: (msg: string) => logs.push(msg),
132134
error: () => {},
133135
warn: () => {},
@@ -154,6 +156,7 @@ Deno.test('FlowWorkerLifecycle - does not log skip message when ensureCompiledOn
154156
const logs: string[] = [];
155157
const testLogger: Logger = {
156158
debug: () => {},
159+
verbose: () => {},
157160
info: (msg: string) => logs.push(msg),
158161
error: () => {},
159162
warn: () => {},

pkgs/edge-worker/tests/unit/FlowWorkerLifecycle.deprecation.test.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -185,6 +185,7 @@ Deno.test('FlowWorkerLifecycle - should log appropriate message when transitioni
185185
const logs: string[] = [];
186186
const testLogger: Logger = {
187187
debug: () => {},
188+
verbose: () => {},
188189
info: (msg: string) => logs.push(msg),
189190
error: () => {},
190191
warn: () => {},

0 commit comments

Comments
 (0)