From 0662f62db82026e44cfff7ec42776eb6c2c06cfa Mon Sep 17 00:00:00 2001 From: Elizabeth Date: Mon, 2 Jun 2025 22:54:40 -0700 Subject: Significant logging improvements --- u/process/run.ts | 9 +-- u/server/activity/health.ts | 2 +- u/server/filter/json.ts | 12 ++-- u/server/filter/mod.ts | 2 +- u/server/request.ts | 2 +- u/trace/logger.ts | 169 +++++++++++++++++++++++++------------------- u/trace/trace.ts | 7 +- u/trace/util.ts | 23 +++--- 8 files changed, 129 insertions(+), 97 deletions(-) diff --git a/u/process/run.ts b/u/process/run.ts index 7a74c3e..b09e64e 100644 --- a/u/process/run.ts +++ b/u/process/run.ts @@ -3,6 +3,7 @@ import { type IEither, type ITraceable, LogLevel, + type LogTraceSupplier, TraceUtil, } from "@emprespresso/pengueno"; @@ -13,8 +14,8 @@ type CommandOutputDecoded = { stderrText: string; }; -export const getStdout = ( - c: ITraceable, +export const getStdout = ( + c: ITraceable, options: Deno.CommandOptions = {}, ): Promise> => c @@ -44,8 +45,8 @@ export const getStdout = ( return { code, stdoutText, stderrText }; }) .mapLeft((e) => { - tEitherOut.trace.addTrace(LogLevel.ERROR).trace(`o.o wat ${e}`); - return new Error(`${e}`); + tEitherOut.trace.addTrace(LogLevel.ERROR).trace(e); + return e; }) .flatMap((decodedOutput): IEither => { const { code, stdoutText, stderrText } = decodedOutput; diff --git a/u/server/activity/health.ts b/u/server/activity/health.ts index 3b4a23a..95dfa97 100644 --- a/u/server/activity/health.ts +++ b/u/server/activity/health.ts @@ -46,7 +46,7 @@ export class HealthCheckActivityImpl implements IHealthCheckActivity { return; } h.trace.trace(healthCheckMetric.failure); - h.trace.addTrace(LogLevel.ERROR).trace(`${value}`); + h.trace.addTrace(LogLevel.ERROR).trace(value); }), ), ) diff --git a/u/server/filter/json.ts b/u/server/filter/json.ts index 79eabac..06cf1bf 100644 --- a/u/server/filter/json.ts +++ b/u/server/filter/json.ts @@ -22,12 +22,13 @@ export const jsonModel = ): RequestFilter => (r: ITraceable) => r - .bimap(TraceUtil.withMetricTrace(ParseJsonMetric)) + .bimap(TraceUtil.withFunctionTrace(jsonModel)) + .bimap(TraceUtil.withMetricTrace(ParseJsonMetric)) .map((j) => - Either.fromFailableAsync(j.get().json()).then( + Either.fromFailableAsync(() => j.get().json()).then( (either) => either.mapLeft((errReason) => { - j.trace.addTrace(LogLevel.WARN).trace(`${errReason}`); + j.trace.addTrace(LogLevel.WARN).trace(errReason); return new PenguenoError( "seems to be invalid JSON (>//<) can you fix?", 400, @@ -37,9 +38,8 @@ export const jsonModel = ) .peek( TraceUtil.promiseify((traceableEither) => - traceableEither.get().mapBoth( - () => traceableEither.trace.trace(ParseJsonMetric.failure), - () => traceableEither.trace.trace(ParseJsonMetric.success), + traceableEither.get().fold(({ isLeft }) => + traceableEither.trace.trace(ParseJsonMetric[isLeft ? "failure" : "success"]) ), ), ) diff --git a/u/server/filter/mod.ts b/u/server/filter/mod.ts index 3b247fc..0e0a4cb 100644 --- a/u/server/filter/mod.ts +++ b/u/server/filter/mod.ts @@ -14,7 +14,7 @@ export enum ErrorSource { export class PenguenoError extends Error { public readonly source: ErrorSource; constructor( - message: string, + override readonly message: string, public readonly status: number, ) { super(message); diff --git a/u/server/request.ts b/u/server/request.ts index 5dd9d7b..10357ca 100644 --- a/u/server/request.ts +++ b/u/server/request.ts @@ -43,7 +43,7 @@ export class PenguenoRequest extends Request { const logTraceable = LogTraceable.of( new PenguenoRequest(url, { ...request }, id, new Date()), ).bimap( - TraceUtil.withTrace(`Id=${id} Method=${request.method} Path=${pathname}`), + TraceUtil.withTrace(`RequestId = ${id}, Method = ${request.method}, Path = ${pathname}`), ); return LogMetricTraceable.ofLogTraceable(logTraceable); } diff --git a/u/trace/logger.ts b/u/trace/logger.ts index 8e62b02..29cabd4 100644 --- a/u/trace/logger.ts +++ b/u/trace/logger.ts @@ -2,89 +2,27 @@ import { isDebug, type ITrace, type ITraceWith, - type SideEffect, type Supplier, } from "@emprespresso/pengueno"; -export interface ILogger { - log: (...args: unknown[]) => void; - debug: (...args: unknown[]) => void; - warn: (...args: unknown[]) => void; - error: (...args: unknown[]) => void; - sys: (...args: unknown[]) => void; -} -export enum LogLevel { - UNKNOWN = "UNKNOWN", - INFO = "INFO", - WARN = "WARN", - DEBUG = "DEBUG", - ERROR = "ERROR", - SYS = "SYS", -} -const logLevelOrder: Array = [ - LogLevel.DEBUG, - LogLevel.INFO, - LogLevel.WARN, - LogLevel.ERROR, -]; -export const isLogLevel = (l: string): l is LogLevel => - logLevelOrder.some((level) => level === l); - -const defaultAllowedLevels = () => - [ - LogLevel.UNKNOWN, - ...(isDebug() ? [LogLevel.DEBUG] : []), - LogLevel.INFO, - LogLevel.WARN, - LogLevel.ERROR, - LogLevel.SYS, - ] as Array; - -export const logWithLevel = ( - logger: ILogger, - level: LogLevel, -): SideEffect => { - switch (level) { - case LogLevel.UNKNOWN: - case LogLevel.INFO: - return logger.log; - case LogLevel.DEBUG: - return logger.debug; - case LogLevel.WARN: - return logger.warn; - case LogLevel.ERROR: - return logger.error; - case LogLevel.SYS: - return logger.sys; - } -}; - -export type LogTraceSupplier = ITraceWith>; - -const defaultTrace = () => `[${new Date().toISOString()}]`; -export const LoggerImpl = { - log: console.log, - debug: console.debug, - warn: console.warn, - error: console.error, - sys: console.log, -}; +export type LogTraceSupplier = ITraceWith | Error>; +const defaultTrace = () => `TimeStamp = ${new Date().toISOString()}`; export class LogTrace implements ITrace { constructor( - private readonly logger: ILogger = LoggerImpl, + private readonly logger: ILogger = new LoggerImpl(), private readonly traces: Array = [defaultTrace], + private readonly defaultLevel: LogLevel = LogLevel.INFO, private readonly allowedLevels: Supplier< Array > = defaultAllowedLevels, - private readonly defaultLevel: LogLevel = LogLevel.INFO, ) {} public addTrace(trace: LogTraceSupplier): ITrace { return new LogTrace( this.logger, this.traces.concat(trace), - this.allowedLevels, this.defaultLevel, + this.allowedLevels, ); } @@ -95,11 +33,7 @@ export class LogTrace implements ITrace { if (!this.allowedLevels().includes(_level)) return; const level = _level === LogLevel.UNKNOWN ? this.defaultLevel : _level; - const line = { level, message: traces.at(-1), traces: traces.slice(0, -1) }; - logWithLevel( - this.logger, - level, - )(line); + this.logger.log(level, ...traces); } private foldTraces(_traces: Array) { @@ -111,10 +45,99 @@ export class LogTrace implements ITrace { .reduce((acc, level) => Math.max(logLevelOrder.indexOf(level), acc), -1); const level = logLevelOrder[_level] ?? LogLevel.UNKNOWN; - const traces = _logTraces.filter((trace) => !isLogLevel(trace)); + const traces = _logTraces.filter((trace) => !isLogLevel(trace)).map((trace) => { + if (typeof trace === 'object') { + return `TracedException.Name = ${trace.name}, TracedException.Message = ${trace.message}, TracedException.Stack = ${trace.stack}` + } + return trace; + }); return { level, traces, }; } } + +export enum LogLevel { + UNKNOWN = "UNKNOWN", + INFO = "INFO", + WARN = "WARN", + DEBUG = "DEBUG", + ERROR = "ERROR", + SYS = "SYS", +} +const logLevelOrder: Array = [ + LogLevel.DEBUG, + LogLevel.INFO, + LogLevel.WARN, + LogLevel.ERROR, + LogLevel.SYS, +]; +export const isLogLevel = (l: unknown): l is LogLevel => + typeof l === "string" && logLevelOrder.some((level) => level === l); + + +const defaultAllowedLevels = () => + [ + LogLevel.UNKNOWN, + ...(isDebug() ? [LogLevel.DEBUG] : []), + LogLevel.INFO, + LogLevel.WARN, + LogLevel.ERROR, + LogLevel.SYS, + ] as Array; + +export interface ILogger { + readonly log: (level: LogLevel, ...args: string[]) => void; +} +class LoggerImpl implements ILogger { + private readonly textEncoder = new TextEncoder(); + + public log(level: LogLevel, ...msg: string[]) { + const message = JSON.stringify({ + level, + msg, + }, null, 2); + const styled = `${this.getStyle(level)}${message}${ANSI.RESET}\n`; + this.getStream(level).writeSync(this.textEncoder.encode(styled)); + } + + private getStream(level: LogLevel) { + if (level === LogLevel.ERROR) { + return Deno.stderr; + } + return Deno.stdout; + } + + private getStyle(level: LogLevel) { + switch (level) { + case LogLevel.UNKNOWN: + case LogLevel.INFO: + return `${ANSI.MAGENTA}`; + case LogLevel.DEBUG: + return `${ANSI.CYAN}`; + case LogLevel.WARN: + return `${ANSI.BRIGHT_YELLOW}`; + case LogLevel.ERROR: + return `${ANSI.BRIGHT_RED}`; + case LogLevel.SYS: + return `${ANSI.DIM}${ANSI.BLUE}`; + } + } +} + +export const ANSI = { + RESET: "\x1b[0m", + BOLD: "\x1b[1m", + DIM: "\x1b[2m", + RED: "\x1b[31m", + GREEN: "\x1b[32m", + YELLOW: "\x1b[33m", + BLUE: "\x1b[34m", + MAGENTA: "\x1b[35m", + CYAN: "\x1b[36m", + WHITE: "\x1b[37m", + BRIGHT_RED: "\x1b[91m", + BRIGHT_YELLOW: "\x1b[93m", + GRAY: "\x1b[90m", +}; diff --git a/u/trace/trace.ts b/u/trace/trace.ts index 6cad5b0..5629c28 100644 --- a/u/trace/trace.ts +++ b/u/trace/trace.ts @@ -3,6 +3,7 @@ import { type ITrace, type ITraceable, type ITraceWith, + LogLevel, LogTrace, type LogTraceSupplier, MetricsTrace, @@ -19,8 +20,10 @@ export class LogTraceable extends TraceableImpl { } const getEmbeddedMetricConsumer = - (logTrace: ITrace) => (metrics: Array) => - logTrace.trace(`${JSON.stringify(metrics, null)}`); + (logTrace: ITrace) => + (metrics: Array) => + logTrace.addTrace(LogLevel.SYS).trace(`Metrics = ${JSON.stringify(metrics)}`); + export class EmbeddedMetricsTraceable extends TraceableImpl< T, MetricsTraceSupplier diff --git a/u/trace/util.ts b/u/trace/util.ts index 3f9e5b8..e2200b9 100644 --- a/u/trace/util.ts +++ b/u/trace/util.ts @@ -1,16 +1,21 @@ -import type { - Callable, - IMetric, - ITraceableMapper, - ITraceableTuple, - MetricsTraceSupplier, +import { +ANSI, + type Callable, + type IMetric, + type ITraceableMapper, + type ITraceableTuple, + type MetricsTraceSupplier, } from "@emprespresso/pengueno"; export class TraceUtil { static withTrace( trace: string, + ansi?: Array ): ITraceableMapper>, Trace> { - return (t) => [t.get(), `[${trace}]`]; + if (ansi) { + return (t) => [t.get(), `${ansi.join("")}${trace}${ANSI.RESET}`]; + } + return (t) => [t.get(), trace]; } static withMetricTrace( @@ -22,13 +27,13 @@ export class TraceUtil { static withFunctionTrace( f: F, ): ITraceableMapper>, Trace> { - return TraceUtil.withTrace(f.name); + return TraceUtil.withTrace(`fn.${f.name}`); } static withClassTrace( c: C, ): ITraceableMapper>, Trace> { - return TraceUtil.withTrace(c.constructor.name); + return TraceUtil.withTrace(`class.${c.constructor.name}`); } static promiseify( -- cgit v1.2.3-70-g09d2