Significant logging improvements

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 = <Trace>(
-  c: ITraceable<Command, Trace>,
+export const getStdout = (
+  c: ITraceable<Command, LogTraceSupplier>,
   options: Deno.CommandOptions = {},
 ): Promise<IEither<Error, string>> =>
   c
@@ -44,8 +45,8 @@ export const getStdout = <Trace>(
             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<Error, string> => {
               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<MessageT> =>
   (r: ITraceable<PenguenoRequest, ServerTrace>) =>
     r
-      .bimap(TraceUtil.withMetricTrace(ParseJsonMetric))
+        .bimap(TraceUtil.withFunctionTrace(jsonModel))
+        .bimap(TraceUtil.withMetricTrace(ParseJsonMetric))
       .map((j) =>
-        Either.fromFailableAsync<Error, MessageT>(j.get().json()).then(
+        Either.fromFailableAsync<Error, MessageT>(() => 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> = [
-  LogLevel.DEBUG,
-  LogLevel.INFO,
-  LogLevel.WARN,
-  LogLevel.ERROR,
-];
-export const isLogLevel = (l: string): l is LogLevel =>
-  logLevelOrder.some((level) => <string>level === l);
-
-const defaultAllowedLevels = () =>
-  [
-    LogLevel.UNKNOWN,
-    ...(isDebug() ? [LogLevel.DEBUG] : []),
-    LogLevel.INFO,
-    LogLevel.WARN,
-    LogLevel.ERROR,
-    LogLevel.SYS,
-  ] as Array<LogLevel>;
-
-export const logWithLevel = (
-  logger: ILogger,
-  level: LogLevel,
-): SideEffect<unknown> => {
-  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<Supplier<string>>;
-
-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<Supplier<string> | Error>;
+const defaultTrace = () => `TimeStamp = ${new Date().toISOString()}`;
 export class LogTrace implements ITrace<LogTraceSupplier> {
   constructor(
-    private readonly logger: ILogger = LoggerImpl,
+    private readonly logger: ILogger = new LoggerImpl(),
     private readonly traces: Array<LogTraceSupplier> = [defaultTrace],
+    private readonly defaultLevel: LogLevel = LogLevel.INFO,
     private readonly allowedLevels: Supplier<
       Array<LogLevel>
     > = defaultAllowedLevels,
-    private readonly defaultLevel: LogLevel = LogLevel.INFO,
   ) {}
 
   public addTrace(trace: LogTraceSupplier): ITrace<LogTraceSupplier> {
     return new LogTrace(
       this.logger,
       this.traces.concat(trace),
-      this.allowedLevels,
       this.defaultLevel,
+      this.allowedLevels,
     );
   }
 
@@ -95,11 +33,7 @@ export class LogTrace implements ITrace<LogTraceSupplier> {
     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<LogTraceSupplier>) {
@@ -111,10 +45,99 @@ export class LogTrace implements ITrace<LogTraceSupplier> {
       .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> = [
+  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<LogLevel>;
+
+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<T> extends TraceableImpl<T, LogTraceSupplier> {
 }
 
 const getEmbeddedMetricConsumer =
-  (logTrace: ITrace<LogTraceSupplier>) => (metrics: Array<MetricValue>) =>
-    logTrace.trace(`<metrics>${JSON.stringify(metrics, null)}</metrics>`);
+  (logTrace: ITrace<LogTraceSupplier>) =>
+  (metrics: Array<MetricValue>) =>
+    logTrace.addTrace(LogLevel.SYS).trace(`Metrics = <metrics>${JSON.stringify(metrics)}</metrics>`);
+
 export class EmbeddedMetricsTraceable<T> 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<T, Trace>(
     trace: string,
+    ansi?: Array<keyof typeof ANSI>
   ): ITraceableMapper<T, ITraceableTuple<T, Trace | Array<Trace>>, Trace> {
-    return (t) => [t.get(), `[${trace}]`];
+      if (ansi) {
+          return (t) => [t.get(), `${ansi.join("")}${trace}${ANSI.RESET}`];
+      }
+      return (t) => [t.get(), trace];
   }
 
   static withMetricTrace<T, Trace extends MetricsTraceSupplier>(
@@ -22,13 +27,13 @@ export class TraceUtil {
   static withFunctionTrace<F extends Callable, T, Trace>(
     f: F,
   ): ITraceableMapper<T, ITraceableTuple<T, Trace | Array<Trace>>, Trace> {
-    return TraceUtil.withTrace(f.name);
+    return TraceUtil.withTrace(`fn.${f.name}`);
   }
 
   static withClassTrace<C extends object, T, Trace>(
     c: C,
   ): ITraceableMapper<T, ITraceableTuple<T, Trace | Array<Trace>>, Trace> {
-    return TraceUtil.withTrace(c.constructor.name);
+    return TraceUtil.withTrace(`class.${c.constructor.name}`);
   }
 
   static promiseify<T, U, Trace>(