Implicit contexts

CHANGES.md

@@ -8,6 +8,12 @@ Version 0.7.0
 
 To be released.
 
+ -  Introduced implicit contexts.
+
+     -  Added `withContext()` function.
+     -  Added `Config.contextLocalStorage` option.
+     -  Added `ContextLocalStorage` interface.
+
 
 Version 0.6.4
 -------------

logtape/config.ts

@@ -1,3 +1,4 @@
+import type { ContextLocalStorage } from "./context.ts";
 import { type FilterLike, toFilter } from "./filter.ts";
 import type { LogLevel } from "./level.ts";
 import { LoggerImpl } from "./logger.ts";
@@ -23,6 +24,12 @@ export interface Config<TSinkId extends string, TFilterId extends string> {
    */
   loggers: LoggerConfig<TSinkId, TFilterId>[];
 
+  /**
+   * The context-local storage to use for implicit contexts.
+   * @since 0.7.0
+   */
+  contextLocalStorage?: ContextLocalStorage<Record<string, unknown>>;
+
   /**
    * Whether to reset the configuration before applying this one.
    */
@@ -177,6 +184,8 @@ export async function configure<
     strongRefs.add(logger);
   }
 
+  LoggerImpl.getLogger().contextLocalStorage = config.contextLocalStorage;
+
   for (const sink of Object.values<Sink>(config.sinks)) {
     if (Symbol.asyncDispose in sink) {
       asyncDisposables.add(sink as AsyncDisposable);
@@ -230,7 +239,9 @@ export function getConfig(): Config<string, string> | null {
  */
 export async function reset(): Promise<void> {
   await dispose();
-  LoggerImpl.getLogger([]).resetDescendants();
+  const rootLogger = LoggerImpl.getLogger([]);
+  rootLogger.resetDescendants();
+  delete rootLogger.contextLocalStorage;
   strongRefs.clear();
   currentConfig = null;
 }

logtape/context.test.ts

@@ -0,0 +1,154 @@
+import { assertEquals } from "@std/assert/assert-equals";
+import { assertThrows } from "@std/assert/assert-throws";
+import { delay } from "@std/async/delay";
+import { AsyncLocalStorage } from "node:async_hooks";
+import { configure, reset } from "./config.ts";
+import { withContext } from "./context.ts";
+import { getLogger } from "./logger.ts";
+import type { LogRecord } from "./record.ts";
+
+Deno.test("withContext()", async (t) => {
+  const buffer: LogRecord[] = [];
+
+  await t.step("set up", async () => {
+    await configure({
+      sinks: {
+        buffer: buffer.push.bind(buffer),
+      },
+      loggers: [
+        { category: "my-app", sinks: ["buffer"], level: "debug" },
+        { category: ["logtape", "meta"], sinks: [], level: "warning" },
+      ],
+      contextLocalStorage: new AsyncLocalStorage(),
+      reset: true,
+    });
+  });
+
+  await t.step("test", () => {
+    getLogger("my-app").debug("hello", { foo: 1, bar: 2 });
+    assertEquals(buffer, [
+      {
+        category: ["my-app"],
+        level: "debug",
+        message: ["hello"],
+        rawMessage: "hello",
+        properties: { foo: 1, bar: 2 },
+        timestamp: buffer[0].timestamp,
+      },
+    ]);
+    buffer.pop();
+    const rv = withContext({ foo: 3, baz: 4 }, () => {
+      getLogger("my-app").debug("world", { foo: 1, bar: 2 });
+      return 123;
+    });
+    assertEquals(rv, 123);
+    assertEquals(buffer, [
+      {
+        category: ["my-app"],
+        level: "debug",
+        message: ["world"],
+        rawMessage: "world",
+        properties: { foo: 1, bar: 2, baz: 4 },
+        timestamp: buffer[0].timestamp,
+      },
+    ]);
+    buffer.pop();
+    getLogger("my-app").debug("hello", { foo: 1, bar: 2 });
+    assertEquals(buffer, [
+      {
+        category: ["my-app"],
+        level: "debug",
+        message: ["hello"],
+        rawMessage: "hello",
+        properties: { foo: 1, bar: 2 },
+        timestamp: buffer[0].timestamp,
+      },
+    ]);
+  });
+
+  await t.step("nesting", () => {
+    while (buffer.length > 0) buffer.pop();
+    withContext({ foo: 1, bar: 2 }, () => {
+      withContext({ foo: 3, baz: 4 }, () => {
+        getLogger("my-app").debug("hello");
+      });
+    });
+    assertEquals(buffer, [
+      {
+        category: ["my-app"],
+        level: "debug",
+        message: ["hello"],
+        rawMessage: "hello",
+        properties: { foo: 3, bar: 2, baz: 4 },
+        timestamp: buffer[0].timestamp,
+      },
+    ]);
+  });
+
+  await t.step("concurrent runs", async () => {
+    while (buffer.length > 0) buffer.pop();
+    await Promise.all([
+      (async () => {
+        await delay(Math.random() * 100);
+        withContext({ foo: 1 }, () => {
+          getLogger("my-app").debug("foo");
+        });
+      })(),
+      (async () => {
+        await delay(Math.random() * 100);
+        withContext({ bar: 2 }, () => {
+          getLogger("my-app").debug("bar");
+        });
+      })(),
+      (async () => {
+        await delay(Math.random() * 100);
+        withContext({ baz: 3 }, () => {
+          getLogger("my-app").debug("baz");
+        });
+      })(),
+      (async () => {
+        await delay(Math.random() * 100);
+        withContext({ qux: 4 }, () => {
+          getLogger("my-app").debug("qux");
+        });
+      })(),
+    ]);
+    assertEquals(buffer.length, 4);
+    for (const log of buffer) {
+      if (log.message[0] === "foo") {
+        assertEquals(log.properties, { foo: 1 });
+      } else if (log.message[0] === "bar") {
+        assertEquals(log.properties, { bar: 2 });
+      } else if (log.message[0] === "baz") {
+        assertEquals(log.properties, { baz: 3 });
+      } else {
+        assertEquals(log.properties, { qux: 4 });
+      }
+    }
+  });
+
+  await t.step("tear down", async () => {
+    await reset();
+  });
+
+  await t.step("set up", async () => {
+    await configure({
+      sinks: {
+        buffer: buffer.push.bind(buffer),
+      },
+      loggers: [
+        { category: "my-app", sinks: ["buffer"], level: "debug" },
+        { category: ["logtape", "meta"], sinks: [], level: "warning" },
+      ],
+      reset: true,
+    });
+  });
+
+  await t.step("without settings", () => {
+    assertThrows(() => withContext({}, () => {}), TypeError);
+  });
+
+  await t.step("tear down", async () => {
+    await reset();
+  });
+});

logtape/context.ts

@@ -0,0 +1,50 @@
+import { LoggerImpl } from "./logger.ts";
+
+/**
+ * A generic interface for a context-local storage.  It resembles
+ * the {@link AsyncLocalStorage} API from Node.js.
+ * @typeParam T The type of the context-local store.
+ * @since 0.7.0
+ */
+export interface ContextLocalStorage<T> {
+  /**
+   * Runs a callback with the given store as the context-local store.
+   * @param store The store to use as the context-local store.
+   * @param callback The callback to run.
+   * @returns The return value of the callback.
+   */
+  run<R>(store: T, callback: () => R): R;
+
+  /**
+   * Returns the current context-local store.
+   * @returns The current context-local store, or `undefined` if there is no
+   *          store.
+   */
+  getStore(): T | undefined;
+}
+
+/**
+ * Runs a callback with the given implicit context.  Every single log record
+ * in the callback will have the given context.
+ * @param context The context to inject.
+ * @param callback The callback to run.
+ * @returns The return value of the callback.
+ * @since 0.7.0
+ */
+export function withContext<T>(
+  context: Record<string, unknown>,
+  callback: () => T,
+): T {
+  const rootLogger = LoggerImpl.getLogger();
+  if (rootLogger.contextLocalStorage == null) {
+    throw new TypeError(
+      "Context-local storage is not configured.  " +
+        "Specify contextLocalStorage option in the configure() function.",
+    );
+  }
+  const parentContext = rootLogger.contextLocalStorage.getStore() ?? {};
+  return rootLogger.contextLocalStorage.run(
+    { ...parentContext, ...context },
+    callback,
+  );
+}

logtape/logger.ts

@@ -1,3 +1,4 @@
+import type { ContextLocalStorage } from "./context.ts";
 import type { Filter } from "./filter.ts";
 import type { LogLevel } from "./level.ts";
 import type { LogRecord } from "./record.ts";
@@ -412,6 +413,7 @@ export class LoggerImpl implements Logger {
   readonly sinks: Sink[];
   parentSinks: "inherit" | "override" = "inherit";
   readonly filters: Filter[];
+  contextLocalStorage?: ContextLocalStorage<Record<string, unknown>>;
 
   static getLogger(category: string | readonly string[] = []): LoggerImpl {
     let rootLogger: LoggerImpl | null = globalRootLoggerSymbol in globalThis
@@ -526,6 +528,8 @@ export class LoggerImpl implements Logger {
     properties: Record<string, unknown> | (() => Record<string, unknown>),
     bypassSinks?: Set<Sink>,
   ): void {
+    const implicitContext =
+      LoggerImpl.getLogger().contextLocalStorage?.getStore() ?? {};
     let cachedProps: Record<string, unknown> | undefined = undefined;
     const record: LogRecord = typeof properties === "function"
       ? {
@@ -537,17 +541,25 @@ export class LoggerImpl implements Logger {
         },
         rawMessage,
         get properties() {
-          if (cachedProps == null) cachedProps = properties();
+          if (cachedProps == null) {
+            cachedProps = {
+              ...implicitContext,
+              ...properties(),
+            };
+          }
           return cachedProps;
         },
       }
       : {
         category: this.category,
         level,
         timestamp: Date.now(),
-        message: parseMessageTemplate(rawMessage, properties),
+        message: parseMessageTemplate(rawMessage, {
+          ...implicitContext,
+          ...properties,
+        }),
         rawMessage,
-        properties,
+        properties: { ...implicitContext, ...properties },
       };
     this.emit(record, bypassSinks);
   }
@@ -557,6 +569,8 @@ export class LoggerImpl implements Logger {
     callback: LogCallback,
     properties: Record<string, unknown> = {},
   ): void {
+    const implicitContext =
+      LoggerImpl.getLogger().contextLocalStorage?.getStore() ?? {};
     let rawMessage: TemplateStringsArray | undefined = undefined;
     let msg: unknown[] | undefined = undefined;
     function realizeMessage(): [unknown[], TemplateStringsArray] {
@@ -579,7 +593,7 @@ export class LoggerImpl implements Logger {
         return realizeMessage()[1];
       },
       timestamp: Date.now(),
-      properties,
+      properties: { ...implicitContext, ...properties },
     });
   }
 
@@ -589,13 +603,15 @@ export class LoggerImpl implements Logger {
     values: unknown[],
     properties: Record<string, unknown> = {},
   ): void {
+    const implicitContext =
+      LoggerImpl.getLogger().contextLocalStorage?.getStore() ?? {};
     this.emit({
       category: this.category,
       level,
       message: renderMessage(messageTemplate, values),
       rawMessage: messageTemplate,
       timestamp: Date.now(),
-      properties,
+      properties: { ...implicitContext, ...properties },
     });
   }
 

logtape/mod.ts

@@ -7,6 +7,7 @@ export {
   type LoggerConfig,
   reset,
 } from "./config.ts";
+export { type ContextLocalStorage, withContext } from "./context.ts";
 export { getFileSink, getRotatingFileSink } from "./filesink.jsr.ts";
 export {
   type Filter,