feat(stdlib): condense logs for events

The newly logged spans should be a bit easier to read, understand and reference. They are also a bit easier to parse programmatically.

They also got a 10-30% speedup depending on how they are nested, making them pretty much unnoticeable in performance critical code.

BREAKING CHANGES:
- Changed the internal memory structure of events. `callStack` is now `span`. `parent` is removed and replaced by a `rootEvent`. Nested properties are affected as well. Usages like `event.name` still work as expected.
- Changed the logs produced by the events. The `type` is now `event_span` instead of `event_callstack`. In these logs `callStack` is also replaced by span. Nested properties are affected as well to improve parsing and visualizing them. Please check the new logs and feel free to open an issue if you have trouble with migrating.

benchmark/events.bench.js

@@ -2,15 +2,12 @@ import { bench, mainBenchFn } from "@compas/cli";
 import {
   eventStart,
   eventStop,
-  loggerSetGlobalDestination,
   newEvent,
   newEventFromEvent,
-  newLogger,
 } from "@compas/stdlib";
 
-loggerSetGlobalDestination({
-  write() {},
-});
+const newLogger = () => ({ info: () => {}, error: () => {} });
+
 mainBenchFn(import.meta);
 
 bench("event - start", (b) => {
@@ -32,17 +29,42 @@ bench("event - start/stop", (b) => {
   }
 });
 
-bench("event - eventFromEvent", (b) => {
-  const logger = newLogger();
+for (const { loopX, loopY, loopZ } of [
+  { loopX: 2, loopY: 10, loopZ: 0 },
+  { loopX: 10, loopY: 2, loopZ: 0 },
+  { loopX: 10, loopY: 10, loopZ: 0 },
+  { loopX: 2, loopY: 10, loopZ: 2 },
+  { loopX: 10, loopY: 2, loopZ: 2 },
+  { loopX: 10, loopY: 10, loopZ: 2 },
+]) {
+  bench(`event - nested (x: ${loopX}, y: ${loopY}, z: ${loopZ})`, (b) => {
+    const logger = newLogger();
 
-  for (let i = 0; i < b.N; ++i) {
-    const e = newEvent(logger);
-    eventStart(e, "foo");
+    for (let i = 0; i < b.N; ++i) {
+      const e = newEvent(logger);
+      eventStart(e, "foo");
 
-    const subE = newEventFromEvent(e);
-    eventStart(subE, "bar");
-    eventStop(subE);
+      for (let x = 0; x < loopX; ++x) {
+        const subEventX = newEventFromEvent(e);
+        eventStart(subEventX, "bar");
 
-    eventStop(e);
-  }
-});
+        for (let y = 0; y < loopY; ++y) {
+          const subEventY = newEventFromEvent(subEventX);
+          eventStart(subEventY, "bar");
+
+          for (let z = 0; z < loopZ; ++z) {
+            const subEventZ = newEventFromEvent(subEventY);
+            eventStart(subEventZ, "bar");
+            eventStop(subEventZ);
+          }
+
+          eventStop(subEventY);
+        }
+
+        eventStop(subEventX);
+      }
+
+      eventStop(e);
+    }
+  });
+}

packages/cli/src/testing/events.test.js

@@ -16,7 +16,7 @@ test("cli/testing/events", (t) => {
     eventStart(event, "test");
     eventStop(event);
 
-    t.ok(!isNil(event.callStack?.[0]?.duration));
-    t.equal(event.callStack?.length, 2);
+    t.ok(!isNil(event.span?.duration));
+    t.equal(event.span.children?.length, 0);
   });
 });

packages/stdlib/index.d.ts

@@ -7,7 +7,7 @@ export type ConfigLoaderOptions =
   import("./src/config-loader").ConfigLoaderOptions;
 export type ConfigLoaderResult =
   import("./src/config-loader").ConfigLoaderResult;
-export type InsightEvent = import("./types/advanced-types").InsightEvent;
+export type InsightEvent = import("./src/events").InsightEvent;
 export type ProcessDirectoryOptions =
   import("./types/advanced-types.js").ProcessDirectoryOptions;
 export {

packages/stdlib/index.js

@@ -23,7 +23,7 @@
  */
 
 /**
- * @typedef {import("./types/advanced-types").InsightEvent} InsightEvent
+ * @typedef {import("./src/events").InsightEvent} InsightEvent
  */
 
 /**

packages/stdlib/src/events.d.ts

@@ -6,58 +6,70 @@
  * @param {import("./logger.js").Logger} logger Logger should have a
  *   context, like the default `ctx.log`
  * @param {AbortSignal|undefined} [signal]
- * @returns {import("../types/advanced-types.js").InsightEvent}
+ * @returns {InsightEvent}
  */
 export function newEvent(
   logger: import("./logger.js").Logger,
   signal?: AbortSignal | undefined,
-): import("../types/advanced-types.js").InsightEvent;
+): InsightEvent;
 /**
- * Create a 'child' event, reuses the logger, adds callstack to the passed event
+ * Create a 'child' event, reuses the logger, adds it als a child to the passed event
  *
  * @since 0.1.0
  *
- * @param {import("../types/advanced-types.js").InsightEvent} event
- * @returns {import("../types/advanced-types.js").InsightEvent}
+ * @param {InsightEvent} event
+ * @returns {InsightEvent}
  */
-export function newEventFromEvent(
-  event: import("../types/advanced-types.js").InsightEvent,
-): import("../types/advanced-types.js").InsightEvent;
+export function newEventFromEvent(event: InsightEvent): InsightEvent;
 /**
  * Track event start times
  *
  * @since 0.1.0
  *
- * @param {import("../types/advanced-types.js").InsightEvent} event
+ * @param {InsightEvent} event
  * @param {string} name
  * @returns {void}
  */
-export function eventStart(
-  event: import("../types/advanced-types.js").InsightEvent,
-  name: string,
-): void;
+export function eventStart(event: InsightEvent, name: string): void;
 /**
- * Rename an event, and all callStack items
+ * Rename an event
  *
  * @since 0.1.0
  *
- * @param {import("../types/advanced-types.js").InsightEvent} event
+ * @param {InsightEvent} event
  * @param {string} name
  * @returns {void}
  */
-export function eventRename(
-  event: import("../types/advanced-types.js").InsightEvent,
-  name: string,
-): void;
+export function eventRename(event: InsightEvent, name: string): void;
 /**
  * Track event end times and log if necessary
  *
  * @since 0.1.0
  *
- * @param {import("../types/advanced-types.js").InsightEvent} event
+ * @param {InsightEvent} event
  * @returns {void}
  */
-export function eventStop(
-  event: import("../types/advanced-types.js").InsightEvent,
-): void;
+export function eventStop(event: InsightEvent): void;
+export type InsightEventSpan = {
+  name: string;
+  duration?: number | undefined;
+  startTime: number;
+  stopTime?: number | undefined;
+  abortedTime?: number | undefined;
+  children: InsightEventSpan[];
+};
+/**
+ * Manually track (async) function duration.
+ *
+ * By passing the event down through (async) functions, it facilitates a unified way to
+ * have access to a task / request specific logger and insights in the duration of your
+ * functions.
+ */
+export type InsightEvent = {
+  log: import("@compas/stdlib").Logger;
+  signal?: AbortSignal | undefined;
+  rootEvent?: InsightEvent | undefined;
+  name?: string | undefined;
+  span: InsightEventSpan;
+};
 //# sourceMappingURL=events.d.ts.map