feat(core): add customizable LoggerContext with labeling support (#…

…4233)

Closes #4230

docs/docs/logging.md

@@ -30,9 +30,52 @@ It is also useful for debugging problems with entity discovery, as you will see
 [discovery] - entity discovery finished after 13 ms
 ```
 
-## Custom Logger
+## Disabling colored output
+
+To disable colored output, you can use multiple environment variables:
 
-We can also provide our own logger function via `logger` option.
+- `NO_COLOR`
+- `MIKRO_ORM_NO_COLOR`
+- `FORCE_COLOR`
+
+## Logger Namespaces
+
+There are multiple Logger Namespaces that you can specifically request, while omitting the rest. Just specify array of them via the `debug` option:
+
+```ts
+return MikroORM.init({
+  debug: ['query'], // now only queries will be logged
+});
+```
+
+Currently, there are 5 namespaces – `query`, `query-params`, `schema`, `discovery` and `info`.
+
+If you provide `query-params` then you must also provide `query` in order for it to take effect.
+
+## Highlighters
+
+Previously Highlight.js was used to highlight various things in the CLI, like SQL and mongo queries, or migrations or entities generated via CLI. While the library worked fine, it was causing performance issues mainly for those bundling via webpack and using lambdas, as the library was huge.
+
+Since v4, highlighting is disabled by default, and there are 2 highlighters you can optionally use (you need to install them first).
+
+```ts
+import { SqlHighlighter } from '@mikro-orm/sql-highlighter';
+
+MikroORM.init({
+  highlighter: new SqlHighlighter(),
+  // ...
+});
+```
+
+For MongoDB you can use `MongoHighlighter` from `@mikro-orm/mongo-highlighter` package.
+
+## Logger Customization
+
+Several customization options exist to allow for style changes or custom logic.
+
+### Using a custom logger
+
+You can provide your own logger function via the `logger` option:
 
 ```ts
 return MikroORM.init({
@@ -41,7 +84,41 @@ return MikroORM.init({
 });
 ```
 
-If we want to have more control over logging, we can use `loggerFactory` and use our own implementation of the `Logger` interface:
+### Using a custom `LoggerFactory`
+
+If you want more control over what is logged and how, use the `loggerFactory` option in your config and extend the `SimpleLogger` class, extend the `DefaultLogger` class, or make your `Logger` from scratch:
+
+#### Extending `DefaultLogger` or `SimpleLogger`
+
+You can extend the `DefaultLogger` or `SimpleLogger` instead of implementing everything from scratch. `DefaultLogger` and `SimpleLogger` are both exported from the `@mikro-orm/core` package with `SimpleLogger` being colorless.
+
+```ts
+class CustomLogger extends DefaultLogger {
+  log(namespace: LoggerNamespace, message: string, context?: LogContext) {
+    // Create your own implementation for output:
+    console.log(`[${namespace}] (${context.label}) ${message}`);
+
+    // OR Utilize DefaultLogger's implementation:
+    super.log(namespace, message, context)
+  }
+}
+
+return MikroORM.init({
+  debug: true,
+  loggerFactory: (options) => new CustomLogger(options),
+});
+```
+
+To use `SimpleLogger` instead, simply replace `DefaultLogger` in the example above: 
+```ts
+class CustomLogger extends SimpleLogger {
+  // ...
+}
+```
+
+#### Creating a custom logger from scratch
+
+You can use `loggerFactory` and use your own implementation of the `Logger` interface:
 
 ```ts
 import { Logger, LoggerOptions, MikroORM, Configuration } from '@mikro-orm/core';
@@ -52,12 +129,10 @@ class MyLogger implements Logger {
 
 const orm = await MikroORM.init({
   debug: true,
-  loggerFactory: (options: LoggerOptions) => new MyLogger(config),
+  loggerFactory: (options) => new MyLogger(options),
 });
 ```
 
-We can also extend the `DefaultLogger` instead of implementing everything from scratch. It is also exported from the `@mikro-orm/core` package.
-
 The `Logger` interface is defined as follows:
 
 ```ts
@@ -70,10 +145,11 @@ interface Logger {
   isEnabled(namespace: LoggerNamespace): boolean;
 }
 
-type LoggerNamespace = 'query' | 'query-params' | 'discovery' | 'info';
+type LoggerNamespace = 'query' | 'query-params' | 'schema' | 'discovery' | 'info';
 
-interface LogContext {
+interface LogContext extends Dictionary {
   query?: string;
+  label?: string;
   params?: unknown[];
   took?: number;
   level?: 'info' | 'warning' | 'error';
@@ -84,41 +160,29 @@ interface LogContext {
 }
 ```
 
-## Disabling colored output
-
-To disable colored output, we can use multiple environment variables:
-
-- `NO_COLOR`
-- `MIKRO_ORM_NO_COLOR`
-- `FORCE_COLOR`
+### Query Labels
 
-## Logger Namespaces
+It may often be beneficial to log the origin of a query when using [`EntityManager.find`](entity-manager.md#fetching-entities-with-entitymanager) or [`EntityManager.findOne`](entity-manager.md#fetching-entities-with-entitymanager) for debugging and redundancy elimination purposes. 
 
-There are multiple Logger Namespaces that you can specifically request, while omitting the rest. Just specify array of them via the `debug` option:
+An optional `loggerContext` option can be included within the `FindOptions` parameter of either call which will add a label to the output when debug mode is enabled.
 
 ```ts
-return MikroORM.init({
-  debug: ['query'], // now only queries will be logged
-});
+const author = await em.findOne(Author, { id: 1 }, { loggerContext: { label: 'Author Retrieval - /authors/me' } });
+// [query] (Author Retrieval - /authors/me) select "a0".* from "Author" as "a0" where "a0"."id" = 1 limit 1 [took 21 ms]
 ```
 
-Currently, there are 4 namespaces – `query`, `query-params`, `discovery` and `info`.
-
-If you provide `query-params` then you must also provide `query` in order for it to take effect.
-
-## Highlighters
-
-Previously Highlight.js was used to highlight various things in the CLI, like SQL and mongo queries, or migrations or entities generated via CLI. While the library worked fine, it was causing performance issues mainly for those bundling via webpack and using lambdas, as the library was huge.
-
-Since v4, highlighting is disabled by default, and there are 2 highlighters you can optionally use (you need to install them first).
+### Providing additional context to a custom logger
+If you have implemented your own `LoggerFactory` and need to access additional contextual values inside your customer logger implementation, utilize the `LoggerContext` property of `FindOptions`. Adding additional key/value pairs to that object will make them available inside your custom logger:
 
 ```ts
-import { SqlHighlighter } from '@mikro-orm/sql-highlighter';
+const author = await em.findOne(Author, { id: 1 }, { loggerContext: { meaningOfLife: 42 } });
 
-MikroORM.init({
-  highlighter: new SqlHighlighter(),
-  // ...
-});
-```
+// ...
 
-For MongoDB you can use `MongoHighlighter` from `@mikro-orm/mongo-highlighter` package.
+class CustomLogger extends DefaultLogger {
+  log(namespace: LoggerNamespace, message: string, context?: LogContext) {
+    console.log(context?.meaningOfLife);
+    // 42
+  }
+}
+```

packages/core/src/drivers/IDatabaseDriver.ts

@@ -10,6 +10,7 @@ import type { Collection } from '../entity/Collection';
 import type { EntityManager } from '../EntityManager';
 import type { DriverException } from '../exceptions';
 import type { Configuration } from '../utils/Configuration';
+import type { LoggerContext } from '../logging';
 
 export const EntityManagerType = Symbol('EntityManagerType');
 
@@ -138,6 +139,7 @@ export interface FindOptions<T, P extends string = never, F extends string = nev
   comments?: string | string[];
   /** sql only */
   hintComments?: string | string[];
+  loggerContext?: LoggerContext;
 }
 
 export interface FindByCursorOptions<T extends object, P extends string = never, F extends string = never> extends Omit<FindOptions<T, P, F>, 'limit' | 'offset'> {

packages/core/src/logging/DefaultLogger.ts

@@ -31,7 +31,11 @@ export class DefaultLogger implements Logger {
       message = colors.yellow(message);
     }
 
-    this.writer(colors.grey(`[${namespace}] `) + message);
+    const label = context?.label
+      ? colors.cyan(`(${context.label}) `)
+      : '';
+
+    this.writer(colors.grey(`[${namespace}] `) + label + message);
   }
 
   /**

packages/core/src/logging/Logger.ts

@@ -1,4 +1,4 @@
-import type { Highlighter } from '../typings';
+import type { Dictionary, Highlighter } from '../typings';
 
 export interface Logger {
 
@@ -33,8 +33,9 @@ export interface Logger {
 
 export type LoggerNamespace = 'query' | 'query-params' | 'schema' | 'discovery' | 'info';
 
-export interface LogContext {
+export interface LogContext extends Dictionary {
   query?: string;
+  label?: string;
   params?: unknown[];
   took?: number;
   results?: number;
@@ -51,3 +52,12 @@ export interface LoggerOptions {
   highlighter?: Highlighter;
   usesReplicas?: boolean;
 }
+
+/**
+ * Context for a logger to utilize to format output, including a label and additional properties that can be accessed by custom loggers
+ *
+ * @example
+ * await em.findOne(User, 1, { loggerContext: { label: 'user middleware' } };
+ * // [query] (user middleware) select * from user where id = 1;
+ */
+export type LoggerContext = Pick<LogContext, 'label'> & Dictionary;

packages/core/src/logging/SimpleLogger.ts

@@ -1,6 +1,9 @@
 import type { LogContext, LoggerNamespace } from './Logger';
 import { DefaultLogger } from './DefaultLogger';
 
+/**
+ * A basic logger that provides fully formatted output without color
+ */
 export class SimpleLogger extends DefaultLogger {
 
   /**
@@ -13,8 +16,9 @@ export class SimpleLogger extends DefaultLogger {
 
     // clean up the whitespace
     message = message.replace(/\n/g, '').replace(/ +/g, ' ').trim();
+    const label = context?.label ? `(${context.label}) ` : '';
 
-    this.writer(`[${namespace}] ${message}`);
+    this.writer(`[${namespace}] ${label}${message}`);
   }
 
   /**

packages/knex/src/AbstractSqlConnection.ts

@@ -1,8 +1,18 @@
 import { knex, type Knex } from 'knex';
 import { readFile } from 'fs-extra';
-import { Connection, EventType, Utils, type
-  AnyEntity, type Configuration, type ConnectionOptions, type EntityData, type IsolationLevel, type QueryResult, type
-  Transaction, type TransactionEventBroadcaster,
+import {
+  Connection,
+  EventType,
+  Utils,
+  type AnyEntity,
+  type Configuration,
+  type ConnectionOptions,
+  type EntityData,
+  type IsolationLevel,
+  type QueryResult,
+  type Transaction,
+  type TransactionEventBroadcaster,
+  type LoggerContext,
 } from '@mikro-orm/core';
 import type { AbstractSqlPlatform } from './AbstractSqlPlatform';
 import { MonkeyPatchable } from './MonkeyPatchable';
@@ -115,7 +125,7 @@ export abstract class AbstractSqlConnection extends Connection {
     }
   }
 
-  async execute<T extends QueryResult | EntityData<AnyEntity> | EntityData<AnyEntity>[] = EntityData<AnyEntity>[]>(queryOrKnex: string | Knex.QueryBuilder | Knex.Raw, params: unknown[] = [], method: 'all' | 'get' | 'run' = 'all', ctx?: Transaction): Promise<T> {
+  async execute<T extends QueryResult | EntityData<AnyEntity> | EntityData<AnyEntity>[] = EntityData<AnyEntity>[]>(queryOrKnex: string | Knex.QueryBuilder | Knex.Raw, params: unknown[] = [], method: 'all' | 'get' | 'run' = 'all', ctx?: Transaction, loggerContext?: LoggerContext): Promise<T> {
     await this.ensureConnection();
 
     if (Utils.isObject<Knex.QueryBuilder | Knex.Raw>(queryOrKnex)) {
@@ -136,7 +146,7 @@ export abstract class AbstractSqlConnection extends Connection {
 
       const res = await query;
       return this.transformRawResult<T>(res, method);
-    }, { query: queryOrKnex, params });
+    }, { query: queryOrKnex, params, ...loggerContext });
   }
 
   /**

packages/knex/src/AbstractSqlDriver.ts

@@ -31,6 +31,7 @@ import {
   type IDatabaseDriver,
   LoadStrategy,
   type LockOptions,
+  type LoggerContext,
   type NativeInsertUpdateManyOptions,
   type NativeInsertUpdateOptions,
   type PopulateOptions,
@@ -87,7 +88,7 @@ export abstract class AbstractSqlDriver<Connection extends AbstractSqlConnection
 
     const populate = this.autoJoinOneToOneOwner(meta, options.populate as unknown as PopulateOptions<T>[], options.fields);
     const joinedProps = this.joinedProps(meta, populate);
-    const qb = this.createQueryBuilder<T>(entityName, options.ctx, options.connectionType, false);
+    const qb = this.createQueryBuilder<T>(entityName, options.ctx, options.connectionType, false, options.loggerContext);
     const fields = this.buildFields(meta, populate, joinedProps, qb, options.fields as unknown as Field<T>[]);
     const joinedPropsOrderBy = this.buildJoinedPropsOrderBy(entityName, qb, meta, joinedProps);
     const orderBy = [...Utils.asArray(options.orderBy), ...joinedPropsOrderBy];
@@ -904,9 +905,18 @@ export abstract class AbstractSqlDriver<Connection extends AbstractSqlConnection
   }
 
   /** @internal */
-  createQueryBuilder<T extends object>(entityName: EntityName<T> | QueryBuilder<T>, ctx?: Transaction<Knex.Transaction>, preferredConnectionType?: ConnectionType, convertCustomTypes?: boolean): QueryBuilder<T> {
+  createQueryBuilder<T extends object>(entityName: EntityName<T> | QueryBuilder<T>, ctx?: Transaction<Knex.Transaction>, preferredConnectionType?: ConnectionType, convertCustomTypes?: boolean, loggerContext?: LoggerContext): QueryBuilder<T> {
     const connectionType = this.resolveConnectionType({ ctx, connectionType: preferredConnectionType });
-    const qb = new QueryBuilder<T>(entityName, this.metadata, this, ctx, undefined, connectionType);
+    const qb = new QueryBuilder<T>(
+      entityName,
+      this.metadata,
+      this,
+      ctx,
+      undefined,
+      connectionType,
+      undefined,
+      loggerContext,
+    );
 
     if (!convertCustomTypes) {
       qb.unsetFlag(QueryFlag.CONVERT_CUSTOM_TYPES);

packages/knex/src/query/QueryBuilder.ts

@@ -32,13 +32,15 @@ import {
   type QBQueryOrderMap,
   type QueryOrderMap,
   type QueryResult,
-  type RequiredEntityData } from '@mikro-orm/core';
+  type RequiredEntityData,
+  type LoggerContext,
+} from '@mikro-orm/core';
 import { QueryType } from './enums';
 import type { AbstractSqlDriver } from '../AbstractSqlDriver';
 import { QueryBuilderHelper, type Alias } from './QueryBuilderHelper';
 import type { SqlEntityManager } from '../SqlEntityManager';
 import { CriteriaNodeFactory } from './CriteriaNodeFactory';
-import type { Field, IQueryBuilder, JoinOptions } from '../typings';
+import type { Field, JoinOptions } from '../typings';
 
 /**
  * SQL query builder with fluent interface.
@@ -126,7 +128,8 @@ export class QueryBuilder<T extends object = AnyEntity> {
               private readonly context?: Knex.Transaction,
               alias?: string,
               private connectionType?: ConnectionType,
-              private readonly em?: SqlEntityManager) {
+              private readonly em?: SqlEntityManager,
+              private readonly loggerContext?: LoggerContext) {
     if (alias) {
       this.aliasCounter++;
       this._explicitAlias = true;
@@ -646,7 +649,7 @@ export class QueryBuilder<T extends object = AnyEntity> {
     }
 
     const type = this.connectionType || (method === 'run' ? 'write' : 'read');
-    const res = await this.driver.getConnection(type).execute(query.sql, query.bindings as any[], method, this.context);
+    const res = await this.driver.getConnection(type).execute(query.sql, query.bindings as any[], method, this.context, this.loggerContext);
     const meta = this.mainAlias.metadata;
 
     if (!mapResults || !meta) {