Add more time functions

benchmark.js

@@ -0,0 +1,54 @@
+const { LoggingBase } = require("./out/index.js");
+let results = {};
+
+function benchmark(name, count, runner) {
+   console.profile(name);
+   const start = process.hrtime.bigint()
+
+   runner(count);
+
+   const diffNS = process.hrtime.bigint() - start;
+   const diffMS = Number(diffNS / 1000n / 1000n);
+   console.profileEnd(name)
+
+   results[name]= {
+      count,
+      time: diffMS,
+      timePerI: (diffMS / count).toFixed(4)
+   }
+}
+
+benchmark("simple", 10000000, (cnt) => {
+   const l = new LoggingBase({
+      console: false
+   });
+   for (let i = 0; i < cnt; i++) {
+      l.log("simple log")
+   }
+})
+
+benchmark("complex", 1000000, (cnt) => {
+   const l = new LoggingBase({
+      console: false
+   });
+   for (let i = 0; i < cnt; i++) {
+      l.log("complex log", {
+         a: 1,
+         b: {
+            c:"test"
+         }
+      })
+   }
+})
+
+benchmark("very long", 10000000, (cnt) => {
+   const l = new LoggingBase({
+      console: false
+   });
+   const longText = "complex log".repeat(100);
+   for (let i = 0; i < cnt; i++) {
+      l.log(longText)
+   }
+})
+
+console.table(results)

meta.json

@@ -1,6 +1,6 @@
 {
    "name": "logging",
-   "version": "3.0.3",
+   "version": "3.1.2",
    "description": "",
    "author": "Fabian Stamm <dev@fabianstamm.de>",
    "contributors": [],

package.json

@@ -1,15 +1,17 @@
 {
    "name": "@hibas123/logging",
-   "version": "3.0.3",
+   "version": "4.0.2",
    "description": "",
-   "main": "out/index.js",
-   "types": "out/index.d.ts",
+   "type": "module",
+   "main": "esm/index.js",
+   "types": "esm/index.d.ts",
    "module": "esm/index.js",
    "scripts": {
-      "prepublish": "npm run build",
-      "build": "tsc && tsc -p tsconfig.esm.json",
-      "test": "tsc && node out/test.js",
-      "postpublish": "denreg publish"
+      "prepublishOnly": "npm run build",
+      "build": "tsc",
+      "test": "tsc && node esm/test.js",
+      "bench": "tsc && node benchmark.js",
+      "prof": "tsc && ndb --prof benchmark.js"
    },
    "repository": {
       "type": "git",
@@ -19,16 +21,15 @@
    "license": "MIT",
    "files": [
       "src/",
-      "out/",
       "esm/",
       "tsconfig.json",
       "readme.md"
    ],
    "devDependencies": {
-      "concurrently": "^6.0.2",
-      "nodemon": "^2.0.7",
-      "ts-node": "^9.1.1",
-      "typescript": "^4.2.4"
-   },
-   "dependencies": {}
+      "concurrently": "^9.2.1",
+      "ndb": "^1.1.5",
+      "nodemon": "^3.1.10",
+      "ts-node": "^10.9.2",
+      "typescript": "^5.9.3"
+   }
 }

src/base.ts

@@ -6,28 +6,13 @@ import {
    Format,
    FormatConfig,
    Formatted,
+   ILoggingInterface,
    LoggingTypes,
    Message,
 } from "./types.js";
 
 const browser = typeof window !== "undefined";
 
-export interface ILoggingTimer {
-   end: () => number;
-}
-
-export interface ILoggingInterface {
-   debug(...message: any[]): void;
-   log(...message: any[]): void;
-   warn(...message: any[]): void;
-   error(...message: any[]): void;
-
-   time(name?: string): ILoggingTimer;
-   timeEnd(id: string): number;
-
-   getChild(name: string): ILoggingInterface;
-}
-
 export interface ILoggingOptions {
    /**
     * Name will be prefixed on Console output and added to logfiles, if not specified here
@@ -46,6 +31,7 @@ export interface ILoggingOptions {
 
 export interface INativeFunctions {
    startTimer(): any;
+   diffTime(start: any, end: any): number;
    endTimer(start: any): number;
 }
 
@@ -57,6 +43,9 @@ export const DefaultNativeFunctions = {
          return Date.now();
       }
    },
+   diffTime: (start: any, end: any) => {
+      return end - start;
+   },
    endTimer: (start: any) => {
       if (browser && window.performance && window.performance.now) {
          return window.performance.now() - start;
@@ -74,7 +63,7 @@ const InitialisedAdapters = Symbol("@hibas123/logging:initialisedAdapters");
 
 export abstract class LoggingInterface implements ILoggingInterface {
    #names: string[];
-   #timerMap = new Map<string, { name: string; start: any }>();
+   #timerMap = new Map<string, { name: string; start: any, marks: { time: any, name: string }[] }>();
 
    get names() {
       return [...this.#names];
@@ -89,6 +78,12 @@ export abstract class LoggingInterface implements ILoggingInterface {
 
    constructor(names: string[]) {
       this.#names = names;
+
+      for (const key in this) {
+         if (typeof this[key] === "function") {
+            this[key] = (this[key] as never as Function).bind(this);
+         }
+      }
    }
 
    debug(...message: any[]) {
@@ -132,13 +127,18 @@ export abstract class LoggingInterface implements ILoggingInterface {
    time(id?: string) {
       if (!id) id = Math.floor(Math.random() * 899999 + 100000).toString();
 
-      this.#timerMap.set(id, {
+      let timer = {
          name: id,
          start: LoggingBase.nativeFunctions.startTimer(),
-      });
+         marks: [],
+      };
+      this.#timerMap.set(id, timer);
 
       return {
          id,
+         mark: (label: string) => {
+            timer.marks.push({ time: LoggingBase.nativeFunctions.startTimer(), name: label });
+         },
          end: () => this.timeEnd(id),
       };
    }
@@ -146,7 +146,8 @@ export abstract class LoggingInterface implements ILoggingInterface {
    timeEnd(id: string) {
       let timer = this.#timerMap.get(id);
       if (timer) {
-         let diff = LoggingBase.nativeFunctions.endTimer(timer.start);
+         let end_time = LoggingBase.nativeFunctions.startTimer();
+         let diff = LoggingBase.nativeFunctions.diffTime(timer.start, end_time);
 
          this.message(LoggingTypes.Debug, this.#names, [
             Format.green(`[${timer.name}]`),
@@ -155,6 +156,27 @@ export abstract class LoggingInterface implements ILoggingInterface {
             "ms",
          ]);
 
+         if (timer.marks.length > 0) {
+            let last_mark = timer.start;
+            for (let mark of timer.marks) {
+               let diff = LoggingBase.nativeFunctions.diffTime(last_mark, mark.time);
+               this.message(LoggingTypes.Debug, [...this.#names, timer.name], [
+                  Format.green(`[${mark.name}]`),
+                  `->`,
+                  Format.blue(diff.toFixed(4)),
+                  "ms",
+               ]);
+               last_mark = mark.time;
+            }
+            let diff = LoggingBase.nativeFunctions.diffTime(last_mark, end_time);
+            this.message(LoggingTypes.Debug, [...this.#names, timer.name], [
+               Format.green(`[end]`),
+               `->`,
+               Format.blue(diff.toFixed(4)),
+               "ms",
+            ]);
+         }
+
          return diff;
       }
       return -1;
@@ -179,7 +201,10 @@ export class LoggingBase extends LoggingInterface {
       }
 
       getChild(name: string) {
-         return new LoggingBase.DecoupledLogging([this.names, name], this.#lg);
+         return new LoggingBase.DecoupledLogging(
+            [...this.names, name],
+            this.#lg
+         );
       }
    };
 
@@ -208,12 +233,6 @@ export class LoggingBase extends LoggingInterface {
       if (options.console) {
          this.addAdapter(consoleAdapter);
       }
-
-      for (const key in this) {
-         if (typeof this[key] === "function") {
-            this[key] = ((this[key] as never) as Function).bind(this);
-         }
-      }
    }
 
    async addAdapter(adapter: Adapter) {
@@ -234,7 +253,7 @@ export class LoggingBase extends LoggingInterface {
       if (!init) {
          add();
       } else {
-         Promise.resolve(init).then(add);
+         await Promise.resolve(init).then(add);
       }
    }
 
@@ -255,7 +274,8 @@ export class LoggingBase extends LoggingInterface {
       }
 
       const date = new Date();
-      const date_str = date.toISOString().replace(/T/, " ").replace(/\..+/, "");
+      const isoStr = date.toISOString();
+      const date_str = isoStr.substring(0, 10) + " " + isoStr.substring(11, 19);
 
       let file: string | undefined = undefined;
       if (this.#resolve_filename) {
@@ -284,8 +304,7 @@ export class LoggingBase extends LoggingInterface {
 
             file_raw.file = newF;
          }
-         file = `${file_raw.file || "<unknown>"}:${file_raw.line}:${
-            file_raw.column || 0
+         file = `${file_raw.file || "<unknown>"}:${file_raw.line}:${file_raw.column || 0
             }`;
       }
 
@@ -331,23 +350,14 @@ export class LoggingBase extends LoggingInterface {
          new Formatted(": "),
       ];
 
-      // let linePrefix = [
-      //    ...namePrefix,
-      //    new Formatted(date_str, this.#format_map.date),
-      //    new Formatted("  "),
-      //    new Formatted(type_str, type_format),
-      //    ...(file
-      //       ? [new Formatted("  "), new Formatted(file, this.#format_map.file)]
-      //       : []),
-      //    new Formatted("| "),
-      // ];
-
       let formattedMessage: Formatted<string>[] = [...linePrefix];
       message.forEach((msg, idx) => {
-         let format = new Formatted();
+         let format: Formatted;
          if (msg instanceof Formatted) {
             format = msg;
             msg = msg.content;
+         } else {
+            format = new Formatted();
          }
 
          if (typeof msg !== "string") {
@@ -358,9 +368,8 @@ export class LoggingBase extends LoggingInterface {
             }) as string;
          }
 
-         removeColors(msg)
-            .split("\n")
-            .forEach((text, index, { length }) => {
+         // removeColors(msg) // Remove colors is uncommented for now, since there are no real benefits of having it and it reduces performance
+         msg.split("\n").forEach((text, index, { length }) => {
             if (index != length - 1) {
                formattedMessage.push(
                   new Formatted(text + "\n", format),
@@ -381,26 +390,30 @@ export class LoggingBase extends LoggingInterface {
          type,
       };
 
-      this.#adapters.forEach((adapter) => adapter.onMessage(msg));
+      this.#adapters.forEach((adapter) => {
+         if (adapter.level <= type) {
+            adapter.onMessage(msg);
+         }
+      });
    }
 
    async close() {
       if (this.#closed) return;
       this.#closed = true;
 
-      this.#adapters.forEach((adapter) => {
+      for (const adapter of this.#adapters) {
          const cnt = LoggingBase[InitialisedAdapters].get(adapter);
          if (!cnt) {
             //TODO: should not happen!
          } else {
             if (cnt <= 1) {
-               adapter.close();
+               if (adapter.close) await adapter.close();
                LoggingBase[InitialisedAdapters].delete(adapter);
             } else {
                LoggingBase[InitialisedAdapters].set(adapter, cnt - 1);
             }
          }
-      });
+      }
    }
 }
 
@@ -442,13 +455,15 @@ function getCallerFile() {
             };
          }
       }
-   } catch (err) {}
+   } catch (err) { }
    return { file: undefined, line: 0 };
 }
 
-function getCallerFromExisting(
-   err: Error
-): { file: string; line: number; column?: number } {
+function getCallerFromExisting(err: Error): {
+   file: string;
+   line: number;
+   column?: number;
+} {
    if (!err || !err.stack) return { file: "NOFILE", line: 0 };
    let lines = err.stack.split("\n");
    lines.shift(); // removing first line
@@ -479,6 +494,7 @@ function getCallerFromExisting(
 
 export function removeColors(text: string) {
    text = text.replace(
+      // Putting regex here directly instead of externally actually improves performance. The cause of that is not clear for now.
       /[\u001b\u009b][[()#;?]*(?:[0-9]{1,4}(?:;[0-9]{0,4})*)?[0-9A-ORZcf-nqry=><]/g,
       ""
    );

src/consolewriter.ts

@@ -5,6 +5,7 @@ import {
    TerminalFormats,
    Formatted,
    IFormatted,
+   LoggingTypes,
 } from "./types.js";
 
 declare const Deno: any;
@@ -15,11 +16,15 @@ const deno = typeof Deno !== "undefined";
 const NodeJS = typeof process !== undefined;
 
 export class ConsoleAdapter implements Adapter {
-   constructor(private colors: boolean = true) {}
+   level: LoggingTypes = LoggingTypes.Debug;
+   constructor(private colors: boolean = true) { }
 
-   init() {}
-   flush() {}
+   init() { }
+   flush() { }
 
+   setLevel(level: LoggingTypes) {
+      this.level = level;
+   }
    // TODO: Check if required!
    // private escape(text: string): string {
    //    return text
@@ -127,22 +132,22 @@ export class ConsoleAdapter implements Adapter {
                let color = "";
                switch (format.color) {
                   case Colors.RED:
-                     color = "red";
+                     color = "#ff5f5f";
                      break;
                   case Colors.GREEN:
-                     color = "green";
+                     color = "#62ff5f";
                      break;
                   case Colors.YELLOW:
-                     color = "gold";
+                     color = "#ffea37";
                      break;
                   case Colors.BLUE:
-                     color = "blue";
+                     color = "#379aff";
                      break;
                   case Colors.MAGENTA:
-                     color = "magenta";
+                     color = "#f837ff";
                      break;
                   case Colors.CYAN:
-                     color = "cyan";
+                     color = "#37e4ff";
                      break;
                   case Colors.WHITE:
                      color = "white";
@@ -156,22 +161,22 @@ export class ConsoleAdapter implements Adapter {
                let color = "";
                switch (format.bgcolor) {
                   case Colors.RED:
-                     color = "red";
+                     color = "#ff5f5f";
                      break;
                   case Colors.GREEN:
-                     color = "green";
+                     color = "#62ff5f";
                      break;
                   case Colors.YELLOW:
-                     color = "gold";
+                     color = "#ffea37";
                      break;
                   case Colors.BLUE:
-                     color = "blue";
+                     color = "#379aff";
                      break;
                   case Colors.MAGENTA:
-                     color = "magenta";
+                     color = "#f837ff";
                      break;
                   case Colors.CYAN:
-                     color = "cyan";
+                     color = "#37e4ff";
                      break;
                   case Colors.WHITE:
                      color = "white";

src/index.ts

@@ -14,6 +14,8 @@ export {
    TerminalFormats,
    Formatted,
    IFormatted,
+   ILoggingInterface,
+   ILoggingTimer,
 } from "./types.js";
 
 const Logging = new LoggingBase();

src/types.ts

@@ -203,7 +203,7 @@ export class DefaultFormatConfig implements FormatConfig {
 
    date = new Formatted()._color(IColors.NONE);
    file = new Formatted()._color(IColors.NONE);
-   names = new Formatted()._bold()._color(IColors.GREEN);
+   names = new Formatted()._bold()._color(IColors.CYAN);
    names_delimiter = new Formatted(" -> ")._bold();
 }
 
@@ -216,6 +216,8 @@ export interface Message {
 }
 
 export interface Adapter {
+   readonly level: LoggingTypes;
+
    /**
     * This function initialises the Adapter. It might be called multiple times, when added to multiple instances
     * @param observable An observable to subscribe to messages
@@ -225,6 +227,8 @@ export interface Adapter {
    flush(sync: true): void;
    flush(sync: false): void | Promise<void>;
 
+   setLevel(level: LoggingTypes): void;
+
    onMessage(message: Message): void;
 
    /**
@@ -234,3 +238,20 @@ export interface Adapter {
     */
    close?(): void;
 }
+
+export interface ILoggingTimer {
+   mark: (label: string) => void;
+   end: () => number;
+}
+
+export interface ILoggingInterface {
+   debug(...message: any[]): void;
+   log(...message: any[]): void;
+   warn(...message: any[]): void;
+   error(...message: any[]): void;
+
+   time(name?: string): ILoggingTimer;
+   timeEnd(id: string): number;
+
+   getChild(name: string): ILoggingInterface;
+}

tsconfig.esm.json

@@ -1,11 +0,0 @@
-{
-   "extends": "./tsconfig.json",
-   "compilerOptions": {
-      "module": "ESNext",
-      "target": "ES2017",
-      "moduleResolution": "node",
-      "outDir": "esm"
-   },
-   "exclude": ["node_modules"],
-   "include": ["src"]
-}

tsconfig.json

@@ -1,12 +1,12 @@
 {
    "compilerOptions": {
-      "module": "commonjs",
-      "target": "esnext",
+      "module": "ESNext",
+      "target": "ESNext",
+      "moduleResolution": "node",
+      "outDir": "esm",
       "noImplicitAny": false,
       "sourceMap": true,
-      "outDir": "out",
-      "declaration": true,
-      "typeRoots": ["node_modules/@types"]
+      "declaration": true
    },
    "exclude": ["node_modules"],
    "include": ["src"]