From e8029673af6842cba9d235803e6ed6c94222f53e Mon Sep 17 00:00:00 2001 From: Matthew Sessions Date: Thu, 25 Dec 2025 14:13:45 -0700 Subject: [PATCH] added loggin --- .../src/jobs/basic-debounce.ts | 1 + .../effect-worker-v2/src/jobs/basic-task.ts | 1 + .../effect-worker-v2/src/jobs/heartbeat.ts | 5 +- packages/core/src/tracker/tracker.ts | 4 - packages/jobs/package.json | 2 +- packages/jobs/src/definitions/continuous.ts | 24 ++- packages/jobs/src/definitions/debounce.ts | 23 +++ packages/jobs/src/definitions/task.ts | 23 +++ .../jobs/src/handlers/continuous/handler.ts | 97 ++++++---- .../jobs/src/handlers/debounce/handler.ts | 83 +++++---- packages/jobs/src/handlers/task/handler.ts | 47 +++-- packages/jobs/src/index.ts | 2 + packages/jobs/src/registry/index.ts | 2 + packages/jobs/src/registry/types.ts | 38 +++- packages/jobs/src/services/execution.ts | 26 +-- packages/jobs/src/services/job-logging.ts | 105 +++++++++++ reports/063-jobs-effectful-logging-design.md | 168 ++++++++++++++---- 17 files changed, 509 insertions(+), 142 deletions(-) create mode 100644 packages/jobs/src/services/job-logging.ts diff --git a/examples/effect-worker-v2/src/jobs/basic-debounce.ts b/examples/effect-worker-v2/src/jobs/basic-debounce.ts index 9b85f24..8769a1e 100644 --- a/examples/effect-worker-v2/src/jobs/basic-debounce.ts +++ b/examples/effect-worker-v2/src/jobs/basic-debounce.ts @@ -38,6 +38,7 @@ export const debounceExample = Debounce.make({ // Flush after 5 seconds of inactivity flushAfter: "5 seconds", + logging: true, // Or flush immediately when 10 events accumulated maxEvents: 10, diff --git a/examples/effect-worker-v2/src/jobs/basic-task.ts b/examples/effect-worker-v2/src/jobs/basic-task.ts index e66cf63..53f4684 100644 --- a/examples/effect-worker-v2/src/jobs/basic-task.ts +++ b/examples/effect-worker-v2/src/jobs/basic-task.ts @@ -18,6 +18,7 @@ export const basicTask = Task.make({ eventSchema: TaskEvent, stateSchema: TaskState, + logging: true, onEvent: (event, ctx) => Effect.gen(function* () { yield* Effect.log("Handling event"); diff --git a/examples/effect-worker-v2/src/jobs/heartbeat.ts b/examples/effect-worker-v2/src/jobs/heartbeat.ts index 0cdd6ee..bc70dee 100644 --- a/examples/effect-worker-v2/src/jobs/heartbeat.ts +++ b/examples/effect-worker-v2/src/jobs/heartbeat.ts @@ -39,7 +39,7 @@ export type HeartbeatState = typeof HeartbeatState.Type; */ export const heartbeat = Continuous.make({ stateSchema: HeartbeatState, - + logging: true, // Run every 10 seconds schedule: Continuous.every("4 seconds"), @@ -56,6 +56,7 @@ export const heartbeat = Continuous.make({ Effect.gen(function* () { // Get current state (Effect-based) const currentState = yield* ctx.state; + const runCount = ctx.runCount; yield* Effect.log( `Heartbeat #${ctx.runCount}: ${currentState.name} - count=${currentState.count}`, @@ -70,7 +71,7 @@ export const heartbeat = Continuous.make({ })); // Example: auto-terminate after 10 heartbeats - if (currentState.count >= 2000) { + if (runCount >= 20) { yield* Effect.log( `Heartbeat ${currentState.name} reached max count, terminating`, ); diff --git a/packages/core/src/tracker/tracker.ts b/packages/core/src/tracker/tracker.ts index 6a6d553..88c5bea 100644 --- a/packages/core/src/tracker/tracker.ts +++ b/packages/core/src/tracker/tracker.ts @@ -75,10 +75,8 @@ export const emitEvent = ( ): Effect.Effect => Effect.flatMap(Effect.serviceOption(EventTracker), (option) => { if (option._tag === "Some") { - console.log(`[Tracker] emitEvent: type=${event.type}, eventId=${event.eventId}`); return option.value.emit(event); } else { - console.log(`[Tracker] emitEvent: tracker not available, event type=${event.type} dropped`); return Effect.void; } }); @@ -91,10 +89,8 @@ export const flushEvents: Effect.Effect = Effect.flatMap( Effect.serviceOption(EventTracker), (option) => { if (option._tag === "Some") { - console.log("[Tracker] flushEvents: flushing..."); return option.value.flush(); } else { - console.log("[Tracker] flushEvents: tracker not available, nothing to flush"); return Effect.void; } }, diff --git a/packages/jobs/package.json b/packages/jobs/package.json index d458ab6..c27591d 100644 --- a/packages/jobs/package.json +++ b/packages/jobs/package.json @@ -1,6 +1,6 @@ { "name": "@durable-effect/jobs", - "version": "0.0.1-next.3", + "version": "0.0.1-next.4", "type": "module", "main": "./dist/index.js", "types": "./dist/index.d.ts", diff --git a/packages/jobs/src/definitions/continuous.ts b/packages/jobs/src/definitions/continuous.ts index bdd39d8..28865d4 100644 --- a/packages/jobs/src/definitions/continuous.ts +++ b/packages/jobs/src/definitions/continuous.ts @@ -5,6 +5,7 @@ import type { UnregisteredContinuousDefinition, ContinuousSchedule, ContinuousContext, + LoggingOption, } from "../registry/types"; import type { JobRetryConfig } from "../retry/types"; @@ -49,11 +50,31 @@ export interface ContinuousMakeConfig { */ readonly retry?: JobRetryConfig; + /** + * Control logging for this job. + * + * - `false` (default): Only log errors (LogLevel.Error) + * - `true`: Enable all logs (LogLevel.Debug) + * - `LogLevel.*`: Use a specific log level + * - `LogLevel.None`: Suppress all logs + * + * @example + * ```ts + * import { LogLevel } from "effect"; + * + * // Enable debug logging + * logging: true, + * + * // Only warnings and above + * logging: LogLevel.Warning, + * ``` + */ + readonly logging?: LoggingOption; + /** * The function to execute on schedule. */ execute(ctx: ContinuousContext): Effect.Effect; - } /** @@ -103,6 +124,7 @@ export const Continuous = { schedule: config.schedule, startImmediately: config.startImmediately, retry: config.retry, + logging: config.logging, execute: config.execute, }), diff --git a/packages/jobs/src/definitions/debounce.ts b/packages/jobs/src/definitions/debounce.ts index d16e5da..34fd06b 100644 --- a/packages/jobs/src/definitions/debounce.ts +++ b/packages/jobs/src/definitions/debounce.ts @@ -5,6 +5,7 @@ import type { UnregisteredDebounceDefinition, DebounceEventContext, DebounceExecuteContext, + LoggingOption, } from "../registry/types"; import type { JobRetryConfig } from "../retry/types"; @@ -52,6 +53,27 @@ export interface DebounceMakeConfig { */ readonly retry?: JobRetryConfig; + /** + * Control logging for this job. + * + * - `false` (default): Only log errors (LogLevel.Error) + * - `true`: Enable all logs (LogLevel.Debug) + * - `LogLevel.*`: Use a specific log level + * - `LogLevel.None`: Suppress all logs + * + * @example + * ```ts + * import { LogLevel } from "effect"; + * + * // Enable debug logging + * logging: true, + * + * // Only warnings and above + * logging: LogLevel.Warning, + * ``` + */ + readonly logging?: LoggingOption; + /** * Reducer for each incoming event. Defaults to returning the latest event. */ @@ -90,6 +112,7 @@ export const Debounce = { flushAfter: config.flushAfter, maxEvents: config.maxEvents, retry: config.retry, + logging: config.logging, onEvent: config.onEvent ?? ((ctx: DebounceEventContext) => diff --git a/packages/jobs/src/definitions/task.ts b/packages/jobs/src/definitions/task.ts index 4827407..492557c 100644 --- a/packages/jobs/src/definitions/task.ts +++ b/packages/jobs/src/definitions/task.ts @@ -7,6 +7,7 @@ import type { TaskExecuteContext, TaskIdleContext, TaskErrorContext, + LoggingOption, } from "../registry/types"; // ============================================================================= @@ -151,6 +152,27 @@ export interface TaskMakeConfig { error: Err, ctx: TaskErrorContext ) => Effect.Effect; + + /** + * Control logging for this job. + * + * - `false` (default): Only log errors (LogLevel.Error) + * - `true`: Enable all logs (LogLevel.Debug) + * - `LogLevel.*`: Use a specific log level + * - `LogLevel.None`: Suppress all logs + * + * @example + * ```ts + * import { LogLevel } from "effect"; + * + * // Enable debug logging + * logging: true, + * + * // Only warnings and above + * logging: LogLevel.Warning, + * ``` + */ + readonly logging?: LoggingOption; } /** @@ -257,6 +279,7 @@ export const Task = { execute: config.execute, onIdle: config.onIdle, onError: config.onError, + logging: config.logging, }), } as const; diff --git a/packages/jobs/src/handlers/continuous/handler.ts b/packages/jobs/src/handlers/continuous/handler.ts index 3c7e24a..28e0dfb 100644 --- a/packages/jobs/src/handlers/continuous/handler.ts +++ b/packages/jobs/src/handlers/continuous/handler.ts @@ -23,6 +23,7 @@ import { type JobError, } from "../../errors"; import { RetryExecutor } from "../../retry"; +import { withJobLogging } from "../../services/job-logging"; import type { ContinuousRequest } from "../../runtime/types"; import type { ContinuousDefinition, ContinuousContext } from "../../registry/types"; import type { ContinuousHandlerI, ContinuousResponse } from "./types"; @@ -345,18 +346,27 @@ export const ContinuousHandlerLayer = Layer.effect( Effect.gen(function* () { const def = yield* getDefinition(request.name); - switch (request.action) { - case "start": - return yield* handleStart(def, request); - case "terminate": - return yield* handleTerminate(request); - case "trigger": - return yield* handleTrigger(def); - case "status": - return yield* handleStatus(); - case "getState": - return yield* handleGetState(def); - } + const handlerEffect = Effect.gen(function* () { + switch (request.action) { + case "start": + return yield* handleStart(def, request); + case "terminate": + return yield* handleTerminate(request); + case "trigger": + return yield* handleTrigger(def); + case "status": + return yield* handleStatus(); + case "getState": + return yield* handleGetState(def); + } + }); + + return yield* withJobLogging(handlerEffect, { + logging: def.logging, + jobType: "continuous", + jobName: def.name, + instanceId: runtime.instanceId, + }); }).pipe( Effect.catchTag("StorageError", (e) => Effect.fail( @@ -393,33 +403,42 @@ export const ContinuousHandlerLayer = Layer.effect( const def = yield* getDefinition(meta.name); - const isRetrying = yield* retryExecutor.isRetrying().pipe( - Effect.catchAll(() => Effect.succeed(false)), - ); - - let runCount: number; - if (isRetrying) { - runCount = yield* getRunCount(); - } else { - runCount = yield* incrementRunCount(); - } - - const result = yield* runExecution(def, runCount, meta.id); - - if (result.retryScheduled) { - return; - } - - if (result.terminated) { - // Terminated - CleanupService has already purged everything - return; - } - - const currentMeta = yield* metadata.get(); - if (currentMeta && currentMeta.status === "running") { - yield* updateLastExecutedAt(); - yield* scheduleNext(def); - } + const alarmEffect = Effect.gen(function* () { + const isRetrying = yield* retryExecutor.isRetrying().pipe( + Effect.catchAll(() => Effect.succeed(false)), + ); + + let runCount: number; + if (isRetrying) { + runCount = yield* getRunCount(); + } else { + runCount = yield* incrementRunCount(); + } + + const result = yield* runExecution(def, runCount, meta.id); + + if (result.retryScheduled) { + return; + } + + if (result.terminated) { + // Terminated - CleanupService has already purged everything + return; + } + + const currentMeta = yield* metadata.get(); + if (currentMeta && currentMeta.status === "running") { + yield* updateLastExecutedAt(); + yield* scheduleNext(def); + } + }); + + yield* withJobLogging(alarmEffect, { + logging: def.logging, + jobType: "continuous", + jobName: def.name, + instanceId: runtime.instanceId, + }); }).pipe( Effect.catchTag("StorageError", (e) => Effect.fail( diff --git a/packages/jobs/src/handlers/debounce/handler.ts b/packages/jobs/src/handlers/debounce/handler.ts index 7d5d543..485a452 100644 --- a/packages/jobs/src/handlers/debounce/handler.ts +++ b/packages/jobs/src/handlers/debounce/handler.ts @@ -24,6 +24,7 @@ import { type JobError, } from "../../errors"; import { RetryExecutor } from "../../retry"; +import { withJobLogging } from "../../services/job-logging"; import type { DebounceRequest } from "../../runtime/types"; import type { DebounceDefinition, DebounceExecuteContext } from "../../registry/types"; import type { DebounceHandlerI, DebounceResponse } from "./types"; @@ -335,22 +336,31 @@ export const DebounceHandlerLayer = Layer.effect( Effect.gen(function* () { const def = yield* getDefinition(request.name); - switch (request.action) { - case "add": - return yield* handleAdd(def, request); - case "flush": - return yield* handleFlush(def, "manual"); - case "clear": - return yield* handleClear(); - case "status": - return yield* handleStatus(); - case "getState": - return yield* handleGetState(def); - default: - return yield* Effect.fail( - new UnknownJobTypeError({ type: `debounce/${(request as any).action}` }) - ); - } + const handlerEffect = Effect.gen(function* () { + switch (request.action) { + case "add": + return yield* handleAdd(def, request); + case "flush": + return yield* handleFlush(def, "manual"); + case "clear": + return yield* handleClear(); + case "status": + return yield* handleStatus(); + case "getState": + return yield* handleGetState(def); + default: + return yield* Effect.fail( + new UnknownJobTypeError({ type: `debounce/${(request as any).action}` }) + ); + } + }); + + return yield* withJobLogging(handlerEffect, { + logging: def.logging, + jobType: "debounce", + jobName: def.name, + instanceId: runtime.instanceId, + }); }).pipe( Effect.catchTag("StorageError", (e) => Effect.fail( @@ -383,22 +393,31 @@ export const DebounceHandlerLayer = Layer.effect( const def = yield* getDefinition(meta.name); - // Check if this is a retry alarm - const isRetrying = yield* retryExecutor.isRetrying().pipe( - Effect.catchAll(() => Effect.succeed(false)), - ); - - // Reset retry state if manual trigger while retrying - if (!isRetrying) { - yield* retryExecutor.reset().pipe(Effect.ignore); - } - - const result = yield* handleFlush(def, "flushAfter"); - void result; - - // Note: handleFlush already purges on success. - // If retryScheduled, handleFlush returns retryScheduled=true. - // We don't need to do anything else. + const alarmEffect = Effect.gen(function* () { + // Check if this is a retry alarm + const isRetrying = yield* retryExecutor.isRetrying().pipe( + Effect.catchAll(() => Effect.succeed(false)), + ); + + // Reset retry state if manual trigger while retrying + if (!isRetrying) { + yield* retryExecutor.reset().pipe(Effect.ignore); + } + + const result = yield* handleFlush(def, "flushAfter"); + void result; + + // Note: handleFlush already purges on success. + // If retryScheduled, handleFlush returns retryScheduled=true. + // We don't need to do anything else. + }); + + yield* withJobLogging(alarmEffect, { + logging: def.logging, + jobType: "debounce", + jobName: def.name, + instanceId: runtime.instanceId, + }); }).pipe( Effect.catchTag("StorageError", (e) => Effect.fail( diff --git a/packages/jobs/src/handlers/task/handler.ts b/packages/jobs/src/handlers/task/handler.ts index c809eb1..4bbfede 100644 --- a/packages/jobs/src/handlers/task/handler.ts +++ b/packages/jobs/src/handlers/task/handler.ts @@ -23,6 +23,7 @@ import { type JobError, } from "../../errors"; import { RetryExecutor } from "../../retry"; +import { withJobLogging } from "../../services/job-logging"; import type { TaskRequest } from "../../runtime/types"; import type { StoredTaskDefinition } from "../../registry/types"; import type { TaskHandlerI, TaskResponse } from "./types"; @@ -418,18 +419,27 @@ export const TaskHandlerLayer = Layer.effect( Effect.gen(function* () { const def = yield* getDefinition(request.name); - switch (request.action) { - case "send": - return yield* handleSend(def, request); - case "trigger": - return yield* handleTrigger(def); - case "terminate": - return yield* handleTerminate(); - case "status": - return yield* handleStatus(); - case "getState": - return yield* handleGetState(def); - } + const handlerEffect = Effect.gen(function* () { + switch (request.action) { + case "send": + return yield* handleSend(def, request); + case "trigger": + return yield* handleTrigger(def); + case "terminate": + return yield* handleTerminate(); + case "status": + return yield* handleStatus(); + case "getState": + return yield* handleGetState(def); + } + }); + + return yield* withJobLogging(handlerEffect, { + logging: def.logging, + jobType: "task", + jobName: def.name, + instanceId: runtime.instanceId, + }); }).pipe( Effect.catchTag("StorageError", (e) => Effect.fail( @@ -452,8 +462,17 @@ export const TaskHandlerLayer = Layer.effect( const def = yield* getDefinition(meta.name); - yield* incrementExecuteCount(); - yield* runExecution(def, 0, "execute", undefined, meta.id); + const alarmEffect = Effect.gen(function* () { + yield* incrementExecuteCount(); + yield* runExecution(def, 0, "execute", undefined, meta.id); + }); + + yield* withJobLogging(alarmEffect, { + logging: def.logging, + jobType: "task", + jobName: def.name, + instanceId: runtime.instanceId, + }); }).pipe( Effect.catchTag("StorageError", (e) => Effect.fail( diff --git a/packages/jobs/src/index.ts b/packages/jobs/src/index.ts index 33da39e..609cd6b 100644 --- a/packages/jobs/src/index.ts +++ b/packages/jobs/src/index.ts @@ -185,6 +185,8 @@ export { type TaskEventOf, // Types - Stored (for handlers) type StoredTaskDefinition, + // Types - Logging + type LoggingOption, } from "./registry"; // ============================================================================= diff --git a/packages/jobs/src/registry/index.ts b/packages/jobs/src/registry/index.ts index 5621324..106a68d 100644 --- a/packages/jobs/src/registry/index.ts +++ b/packages/jobs/src/registry/index.ts @@ -71,4 +71,6 @@ export type { // Registry types JobRegistry, InferRegistry, + // Logging types + LoggingOption, } from "./types"; diff --git a/packages/jobs/src/registry/types.ts b/packages/jobs/src/registry/types.ts index 5496e2d..7c1fb9b 100644 --- a/packages/jobs/src/registry/types.ts +++ b/packages/jobs/src/registry/types.ts @@ -1,9 +1,23 @@ // packages/jobs/src/registry/types.ts -import type { Schema } from "effect"; +import type { Schema, LogLevel } from "effect"; import type { Effect, Duration } from "effect"; import type { JobRetryConfig } from "../retry/types"; +// ============================================================================= +// Logging Types +// ============================================================================= + +/** + * Logging configuration option. + * + * - `true` → LogLevel.Debug (all logs) + * - `false` → LogLevel.Error (only failures logged) - DEFAULT + * - `LogLevel.None` → Completely silent + * - `LogLevel.*` → Custom level + */ +export type LoggingOption = boolean | LogLevel.LogLevel; + // ============================================================================= // Schedule Types // ============================================================================= @@ -46,6 +60,12 @@ export interface UnregisteredContinuousDefinition< * - Failed executions fail immediately */ readonly retry?: JobRetryConfig; + /** + * Configure logging level for this job. + * + * @default false (LogLevel.Error - failures only) + */ + readonly logging?: LoggingOption; /** Function to execute on schedule */ execute(ctx: ContinuousContext): Effect.Effect; } @@ -78,6 +98,12 @@ export interface UnregisteredDebounceDefinition< * - Failed flush fails immediately */ readonly retry?: JobRetryConfig; + /** + * Configure logging level for this job. + * + * @default false (LogLevel.Error - failures only) + */ + readonly logging?: LoggingOption; execute(ctx: DebounceExecuteContext): Effect.Effect; onEvent?(ctx: DebounceEventContext): Effect.Effect; } @@ -163,6 +189,13 @@ export interface UnregisteredTaskDefinition< * If not provided, errors are logged and task continues. */ onError?(error: Err, ctx: TaskErrorContext): Effect.Effect; + + /** + * Configure logging level for this job. + * + * @default false (LogLevel.Error - failures only) + */ + readonly logging?: LoggingOption; } /** @@ -202,6 +235,7 @@ export interface StoredContinuousDefinition { readonly schedule: ContinuousSchedule; readonly startImmediately?: boolean; readonly retry?: StoredJobRetryConfig; + readonly logging?: LoggingOption; execute(ctx: ContinuousContext): Effect.Effect; } @@ -216,6 +250,7 @@ export interface StoredDebounceDefinition { readonly flushAfter: Duration.DurationInput; readonly maxEvents?: number; readonly retry?: StoredJobRetryConfig; + readonly logging?: LoggingOption; execute(ctx: DebounceExecuteContext): Effect.Effect; onEvent?(ctx: DebounceEventContext): Effect.Effect; } @@ -242,6 +277,7 @@ export interface StoredTaskDefinition { readonly name: string; readonly stateSchema: Schema.Schema; readonly eventSchema: Schema.Schema; + readonly logging?: LoggingOption; onEvent(event: E, ctx: TaskEventContext): Effect.Effect; execute(ctx: TaskExecuteContext): Effect.Effect; onIdle?(ctx: TaskIdleContext): Effect.Effect; diff --git a/packages/jobs/src/services/execution.ts b/packages/jobs/src/services/execution.ts index 9289069..5f52416 100644 --- a/packages/jobs/src/services/execution.ts +++ b/packages/jobs/src/services/execution.ts @@ -21,6 +21,7 @@ import { createEntityStateService } from "./entity-state"; import { CleanupService } from "./cleanup"; import { AlarmService } from "./alarm"; import { ExecutionError, TerminateSignal } from "../errors"; +import { withLogSpan } from "./job-logging"; // ============================================================================= // Types @@ -130,17 +131,18 @@ export const JobExecutionServiceLayer = Layer.effect( execute: ( options: ExecuteOptions, ): Effect.Effect => - Effect.gen(function* () { - const { - jobType, - jobName, - schema, - retryConfig, - run, - createContext, - onRetryExhausted, - id, - } = options; + withLogSpan( + Effect.gen(function* () { + const { + jobType, + jobName, + schema, + retryConfig, + run, + createContext, + onRetryExhausted, + id, + } = options; // Track execution start time for duration calculation const startTime = Date.now(); @@ -416,6 +418,8 @@ export const JobExecutionServiceLayer = Layer.effect( terminateReason, }; }), + "execution" + ), }; }), ); diff --git a/packages/jobs/src/services/job-logging.ts b/packages/jobs/src/services/job-logging.ts new file mode 100644 index 0000000..92a36b2 --- /dev/null +++ b/packages/jobs/src/services/job-logging.ts @@ -0,0 +1,105 @@ +// packages/jobs/src/services/job-logging.ts + +import { Effect, Logger, LogLevel } from "effect"; +import type { LoggingOption } from "../registry/types"; + +// ============================================================================= +// Log Level Resolution +// ============================================================================= + +/** + * Resolve logging option to an Effect LogLevel. + * + * - undefined/false → LogLevel.Error (failures only - default) + * - true → LogLevel.Debug (all logs) + * - LogLevel.* → Use as-is + */ +export const resolveLogLevel = (option?: LoggingOption): LogLevel.LogLevel => { + if (option === undefined || option === false) { + return LogLevel.Error; // Default: only log failures + } + if (option === true) { + return LogLevel.Debug; // Shorthand for all logs + } + return option; // Use the provided LogLevel directly +}; + +// ============================================================================= +// Job Logging Wrapper +// ============================================================================= + +/** + * Configuration for job logging. + */ +export interface JobLoggingConfig { + readonly logging?: LoggingOption; + readonly jobType: string; + readonly jobName: string; + readonly instanceId: string; +} + +/** + * Wrap an effect with job-scoped logging. + * + * - Adds job context as annotations (propagates to all nested logs) + * - Controls log level based on job's logging config + * - Default (false): Only errors logged + * - Use LogLevel.None for truly silent operation + * + * @example + * ```ts + * const handler = withJobLogging( + * Effect.gen(function* () { + * yield* Effect.logInfo("Job started"); + * // ... handler logic ... + * }), + * { + * logging: def.logging, + * jobType: "continuous", + * jobName: def.name, + * instanceId: runtime.instanceId, + * } + * ); + * ``` + */ +export const withJobLogging = ( + effect: Effect.Effect, + config: JobLoggingConfig +): Effect.Effect => + effect.pipe( + // Add all annotations at once using object form + Effect.annotateLogs({ + jobType: config.jobType, + jobName: config.jobName, + instanceId: config.instanceId, + }), + // Control log level based on config + Logger.withMinimumLogLevel(resolveLogLevel(config.logging)) + ); + +// ============================================================================= +// Log Span Helper +// ============================================================================= + +/** + * Wrap an execution with a log span to measure duration. + * Duration is automatically added to all logs within the span. + * + * @example + * ```ts + * yield* withLogSpan( + * Effect.gen(function* () { + * yield* Effect.logDebug("Execution starting"); + * const result = yield* runExecution(def, runCount); + * yield* Effect.logDebug("Execution completed"); + * return result; + * }), + * "execution" + * ); + * // Output includes: execution=145ms + * ``` + */ +export const withLogSpan = ( + effect: Effect.Effect, + spanName: string +): Effect.Effect => effect.pipe(Effect.withLogSpan(spanName)); diff --git a/reports/063-jobs-effectful-logging-design.md b/reports/063-jobs-effectful-logging-design.md index b732233..39a2a92 100644 --- a/reports/063-jobs-effectful-logging-design.md +++ b/reports/063-jobs-effectful-logging-design.md @@ -108,11 +108,20 @@ Effect.provide(program, Logger.structured) ### Recommended Pattern for Jobs ```typescript +type LoggingOption = boolean | LogLevel.LogLevel; + +// Resolve user-friendly options to LogLevel +const resolveLogLevel = (option?: LoggingOption): LogLevel.LogLevel => { + if (option === undefined || option === false) return LogLevel.Error; // Default: failures only + if (option === true) return LogLevel.Debug; // All logs + return option; // Use provided LogLevel +}; + // Wrap job execution with log level control and annotations const withJobLogging = ( effect: Effect.Effect, config: { - logging?: boolean; + logging?: LoggingOption; jobType: string; jobName: string; instanceId: string; @@ -124,9 +133,7 @@ const withJobLogging = ( jobName: config.jobName, instanceId: config.instanceId, }), - config.logging - ? Logger.withMinimumLogLevel(LogLevel.Debug) - : Logger.withMinimumLogLevel(LogLevel.None) + Logger.withMinimumLogLevel(resolveLogLevel(config.logging)) ) ``` @@ -135,6 +142,8 @@ const withJobLogging = ( ### Add `logging` Option to Each Job Type ```typescript +import { LogLevel } from "effect"; + // In ContinuousMakeConfig export interface ContinuousMakeConfig { readonly stateSchema: Schema.Schema; @@ -142,25 +151,46 @@ export interface ContinuousMakeConfig { readonly startImmediately?: boolean; readonly retry?: JobRetryConfig; /** - * Enable debug logging for this job. - * @default false + * Configure logging level for this job. + * + * - `true` → LogLevel.Debug (all logs) + * - `false` → LogLevel.Error (only failures logged) - DEFAULT + * - `LogLevel.None` → Completely silent + * - `LogLevel.Info` → Info and above + * - `LogLevel.Warning` → Warn and above + * - etc. + * + * @default false (LogLevel.Error - failures only) */ - readonly logging?: boolean; + readonly logging?: boolean | LogLevel.LogLevel; execute(ctx: ContinuousContext): Effect.Effect; } // Same for DebounceMakeConfig, TaskMakeConfig ``` +### Log Level Resolution + +| Value | Resolved Level | What Gets Logged | +|-------|----------------|------------------| +| `undefined` / `false` | `LogLevel.Error` | Errors and failures only (default) | +| `true` | `LogLevel.Debug` | Everything | +| `LogLevel.None` | `LogLevel.None` | Nothing (truly silent) | +| `LogLevel.Info` | `LogLevel.Info` | Info, Warn, Error, Fatal | +| `LogLevel.Warning` | `LogLevel.Warning` | Warn, Error, Fatal | +| `LogLevel.Error` | `LogLevel.Error` | Error, Fatal | + ### Stored Definition Types ```typescript +import { LogLevel } from "effect"; + // In StoredContinuousDefinition export interface StoredContinuousDefinition { readonly _tag: "ContinuousDefinition"; readonly name: string; // ... existing fields ... - readonly logging?: boolean; // NEW + readonly logging?: boolean | LogLevel.LogLevel; // NEW } ``` @@ -241,17 +271,37 @@ Use Effect's built-in log level control with annotations in object form: import { Effect, Logger, LogLevel } from "effect"; +type LoggingOption = boolean | LogLevel.LogLevel; + +/** + * Resolve logging option to an Effect LogLevel. + * + * - undefined/false → LogLevel.Error (failures only - default) + * - true → LogLevel.Debug (all logs) + * - LogLevel.* → Use as-is + */ +const resolveLogLevel = (option?: LoggingOption): LogLevel.LogLevel => { + if (option === undefined || option === false) { + return LogLevel.Error; // Default: only log failures + } + if (option === true) { + return LogLevel.Debug; // Shorthand for all logs + } + return option; // Use the provided LogLevel directly +}; + /** * Wrap an effect with job-scoped logging. * * - Adds job context as annotations (propagates to all nested logs) * - Controls log level based on job's logging config - * - When logging is disabled, sets level to None (zero overhead) + * - Default (false): Only errors logged + * - Use LogLevel.None for truly silent operation */ export const withJobLogging = ( effect: Effect.Effect, config: { - logging?: boolean; + logging?: LoggingOption; jobType: string; jobName: string; instanceId: string; @@ -264,10 +314,8 @@ export const withJobLogging = ( jobName: config.jobName, instanceId: config.instanceId, }), - // Control log level - None disables all logging (zero overhead) - config.logging - ? Logger.withMinimumLogLevel(LogLevel.Debug) - : Logger.withMinimumLogLevel(LogLevel.None) + // Control log level based on config + Logger.withMinimumLogLevel(resolveLogLevel(config.logging)) ); /** @@ -338,9 +386,11 @@ yield* Effect.gen(function* () { ```typescript // registry/types.ts +import { LogLevel } from "effect"; + export interface UnregisteredContinuousDefinition { // ... existing fields ... - readonly logging?: boolean; + readonly logging?: boolean | LogLevel.LogLevel; } // Same for UnregisteredDebounceDefinition, UnregisteredTaskDefinition @@ -352,10 +402,18 @@ export interface UnregisteredContinuousDefinition { // services/job-logging.ts import { Effect, Logger, LogLevel } from "effect"; +type LoggingOption = boolean | LogLevel.LogLevel; + +const resolveLogLevel = (option?: LoggingOption): LogLevel.LogLevel => { + if (option === undefined || option === false) return LogLevel.Error; + if (option === true) return LogLevel.Debug; + return option; +}; + export const withJobLogging = ( effect: Effect.Effect, config: { - logging?: boolean; + logging?: LoggingOption; jobType: string; jobName: string; instanceId: string; @@ -367,9 +425,7 @@ export const withJobLogging = ( jobName: config.jobName, instanceId: config.instanceId, }), - config.logging - ? Logger.withMinimumLogLevel(LogLevel.Debug) - : Logger.withMinimumLogLevel(LogLevel.None) + Logger.withMinimumLogLevel(resolveLogLevel(config.logging)) ); export const withExecutionSpan = ( @@ -383,14 +439,21 @@ export const withExecutionSpan = ( ```typescript // definitions/continuous.ts +import { LogLevel } from "effect"; + export interface ContinuousMakeConfig { // ... existing fields ... /** - * Enable debug logging for this job. - * When enabled, logs job lifecycle, execution, and retry events. + * Configure logging level for this job. + * + * - `true` → All logs (Debug level) + * - `false` → Failures only (Error level) - DEFAULT + * - `LogLevel.None` → Completely silent + * - `LogLevel.*` → Custom level + * * @default false */ - readonly logging?: boolean; + readonly logging?: boolean | LogLevel.LogLevel; } export const Continuous = { @@ -467,31 +530,60 @@ const handleStart = (def, request) => ## Example: User Experience ```typescript -// User enables logging for a specific job -const tokenRefresher = Continuous.make({ +import { LogLevel } from "effect"; + +// Default: Only errors are logged +const defaultJob = Continuous.make({ stateSchema: TokenState, schedule: Continuous.every("5 minutes"), - logging: true, // <-- Enable logging - execute: (ctx) => - Effect.gen(function* () { - const token = yield* refreshToken(); - yield* ctx.setState({ token, refreshedAt: Date.now() }); - }), + // logging: false (default) - only failures logged + execute: (ctx) => Effect.gen(function* () { ... }), +}); + +// Full debug logging +const debugJob = Continuous.make({ + stateSchema: TokenState, + schedule: Continuous.every("5 minutes"), + logging: true, // All logs (Debug level) + execute: (ctx) => Effect.gen(function* () { ... }), +}); + +// Custom level - Info and above +const infoJob = Continuous.make({ + stateSchema: TokenState, + schedule: Continuous.every("5 minutes"), + logging: LogLevel.Info, // Info, Warn, Error, Fatal + execute: (ctx) => Effect.gen(function* () { ... }), +}); + +// Completely silent +const silentJob = Continuous.make({ + stateSchema: TokenState, + schedule: Continuous.every("5 minutes"), + logging: LogLevel.None, // No logs at all + execute: (ctx) => Effect.gen(function* () { ... }), }); ``` -**Output when logging is enabled:** +**Output with `logging: true` (Debug level):** ``` -timestamp=2024-01-15T10:30:00.000Z level=INFO fiber=#0 message="Job started" jobType=continuous jobName=tokenRefresher instanceId=abc123 -timestamp=2024-01-15T10:30:00.005Z level=DEBUG fiber=#0 message="Execution starting" jobType=continuous jobName=tokenRefresher instanceId=abc123 runCount=1 attempt=1 -timestamp=2024-01-15T10:30:00.150Z level=DEBUG fiber=#0 message="Execution completed" jobType=continuous jobName=tokenRefresher instanceId=abc123 execution=145ms -timestamp=2024-01-15T10:30:00.152Z level=DEBUG fiber=#0 message="Next execution scheduled" jobType=continuous jobName=tokenRefresher instanceId=abc123 nextRunAt=2024-01-15T10:35:00.000Z +timestamp=... level=INFO fiber=#0 message="Job started" jobType=continuous jobName=tokenRefresher instanceId=abc123 +timestamp=... level=DEBUG fiber=#0 message="Execution starting" jobType=continuous jobName=tokenRefresher instanceId=abc123 runCount=1 attempt=1 +timestamp=... level=DEBUG fiber=#0 message="Execution completed" jobType=continuous jobName=tokenRefresher instanceId=abc123 execution=145ms +timestamp=... level=DEBUG fiber=#0 message="Next execution scheduled" jobType=continuous jobName=tokenRefresher instanceId=abc123 nextRunAt=2024-01-15T10:35:00.000Z ``` -Note: The `execution=145ms` is automatically added by `Effect.withLogSpan("execution")`. +**Output with `logging: false` (default - Error level only):** -**Debounce example:** +``` +(no output on success) + +// On failure: +timestamp=... level=ERROR fiber=#0 message="Execution failed" jobType=continuous jobName=tokenRefresher instanceId=abc123 error="Connection timeout" +``` + +**Debounce with `logging: true`:** ``` timestamp=... level=INFO fiber=#0 message="Debounce started" jobType=debounce jobName=webhookBatch instanceId=xyz789 flushAt=2024-01-15T10:35:00.000Z @@ -500,6 +592,8 @@ timestamp=... level=DEBUG fiber=#0 message="Max events reached, flushing" jobTyp timestamp=... level=INFO fiber=#0 message="Debounce flushed" jobType=debounce jobName=webhookBatch instanceId=xyz789 eventCount=10 reason=maxEvents flush=523ms ``` +Note: The `execution=145ms` and `flush=523ms` are automatically added by `Effect.withLogSpan()`. + ## Files to Modify | File | Change |