feat(core): add label to logger

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');
 
@@ -128,6 +129,7 @@ export interface FindOptions<T, P extends string = never, F extends string = nev
   lockTableAliases?: string[];
   ctx?: Transaction;
   connectionType?: ConnectionType;
+  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

@@ -32,7 +32,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

@@ -35,6 +35,7 @@ export type LoggerNamespace = 'query' | 'query-params' | 'schema' | 'discovery'
 
 export interface LogContext {
   query?: string;
+  label?: string;
   params?: unknown[];
   took?: number;
   level?: 'info' | 'warning' | 'error';
@@ -50,3 +51,5 @@ export interface LoggerOptions {
   highlighter?: Highlighter;
   usesReplicas?: boolean;
 }
+
+export type LoggerContext = { queryLabel?: string };

packages/core/src/logging/SimpleLogger.ts

@@ -13,8 +13,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/AbstractSqlDriver.ts

@@ -34,6 +34,7 @@ import type {
   EntityKey,
   EntityValue,
   OrderDefinition,
+  LoggerContext,
 } from '@mikro-orm/core';
 import {
   DatabaseDriver,
@@ -843,9 +844,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

@@ -13,6 +13,7 @@ import type {
   FlatQueryOrderMap,
   FlushMode,
   GroupOperator,
+  LoggerContext,
   MetadataStorage,
   ObjectQuery,
   PopulateOptions,
@@ -127,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;
@@ -608,7 +610,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) {

tests/Logger.test.ts

@@ -1,43 +1,111 @@
-import { Configuration, DefaultLogger } from '@mikro-orm/core';
+import { Configuration, DefaultLogger, SimpleLogger, colors } from '@mikro-orm/core';
 
-describe('Logger', () => {
+// Remove colors to allow for text matching in response
+const redColorFormatterSpy = jest.spyOn(colors, 'red').mockImplementation(text => text);
+const greyColorFormatterSpy = jest.spyOn(colors, 'grey').mockImplementation(text => text);
+const cyanColorFormatterSpy = jest.spyOn(colors, 'cyan').mockImplementation(text => text);
+const yellowColorFormatterSpy = jest.spyOn(colors, 'yellow').mockImplementation(text => text);
+
+const mockWriter = jest.fn();
 
-  test('should have debug mode disabled by default', async () => {
-    const mock = jest.fn();
-    const logger = new DefaultLogger({ writer: mock });
-    expect(logger.debugMode).toBe(false);
-    logger.log('discovery', 'test debug msg');
-    expect(mock.mock.calls.length).toBe(0);
-    logger.log('info', 'test info msg');
-    expect(mock.mock.calls.length).toBe(0);
+describe('Logger', () => {
+  beforeEach(() => {
+    jest.clearAllMocks();
   });
 
-  test('should print debug messages when debug mode enabled', async () => {
-    const mock = jest.fn();
-    const logger = new DefaultLogger({ writer: mock, debugMode: true });
-    expect(logger.debugMode).toBe(true);
-    logger.log('discovery', 'test debug msg');
-    expect(mock.mock.calls.length).toBe(1);
-    logger.log('info', 'test info msg');
-    expect(mock.mock.calls.length).toBe(2);
-    logger.log('query', 'test query msg');
-    expect(mock.mock.calls.length).toBe(3);
+  describe('DefaultLogger', () => {
+
+    test('should have debug mode disabled by default', async () => {
+      const logger = new DefaultLogger({ writer: mockWriter });
+      expect(logger.debugMode).toBe(false);
+      logger.log('discovery', 'test debug msg');
+      logger.log('info', 'test info msg');
+      expect(mockWriter).toBeCalledTimes(0);
+    });
+
+    test('should print debug messages when debug mode enabled', async () => {
+      const logger = new DefaultLogger({ writer: mockWriter, debugMode: true });
+      expect(logger.debugMode).toBe(true);
+      logger.log('discovery', 'test debug msg');
+      expect(mockWriter).toBeCalledTimes(1);
+      logger.log('info', 'test info msg');
+      expect(mockWriter).toBeCalledTimes(2);
+      logger.log('query', 'test query msg');
+      expect(mockWriter).toBeCalledTimes(3);
+    });
+
+    test('should not print debug messages when given namespace not enabled', async () => {
+      const logger = new DefaultLogger({ writer: mockWriter, debugMode: ['query'] });
+      expect(logger.debugMode).toEqual(['query']);
+      logger.log('discovery', 'test debug msg');
+      expect(mockWriter).toBeCalledTimes(0);
+      logger.log('info', 'test info msg');
+      expect(mockWriter).toBeCalledTimes(0);
+      logger.log('query', 'test query msg');
+      expect(mockWriter).toBeCalledTimes(1);
+      logger.error('query', 'test error msg');
+      expect(mockWriter).toBeCalledTimes(2);
+      logger.warn('query', 'test warning msg');
+      expect(mockWriter).toBeCalledTimes(3);
+    });
+
+    test('should print labels correctly', () => {
+      const logger = new DefaultLogger({ writer: mockWriter, debugMode: ['query'] });
+      const namespace = 'query';
+      const message = 'test label msg';
+      const label = 'hello world handler';
+      logger.log(namespace, message, { label });
+      expect(mockWriter).toBeCalledWith(`[${namespace}] (${label}) ${message}`);
+    });
+
+    test('should print values with the appropriate colors', () => {
+      const logger = new DefaultLogger({ writer: mockWriter, debugMode: ['query'] });
+      const namespace = 'query';
+      const label = 'handler';
+      const message = 'test label msg';
+
+      logger.log(namespace, message, { level: 'error', label });
+      expect(greyColorFormatterSpy).toBeCalledWith(`[${namespace}] `);
+      expect(redColorFormatterSpy).toBeCalledWith(message);
+      expect(cyanColorFormatterSpy).toBeCalledWith(`(${label}) `);
+      expect(yellowColorFormatterSpy).not.toBeCalled();
+
+      jest.clearAllMocks();
+
+      logger.log(namespace, message, { level: 'warning', label });
+      expect(greyColorFormatterSpy).toBeCalledWith(`[${namespace}] `);
+      expect(yellowColorFormatterSpy).toBeCalledWith(message);
+      expect(cyanColorFormatterSpy).toBeCalledWith(`(${label}) `);
+      expect(redColorFormatterSpy).not.toBeCalled();
+
+      jest.clearAllMocks();
+
+      logger.log(namespace, message, { level: 'info', label });
+      expect(greyColorFormatterSpy).toBeCalledWith(`[${namespace}] `);
+      expect(cyanColorFormatterSpy).toBeCalledWith(`(${label}) `);
+      expect(yellowColorFormatterSpy).not.toBeCalled();
+      expect(redColorFormatterSpy).not.toBeCalled();
+    });
   });
 
-  test('should not print debug messages when given namespace not enabled', async () => {
-    const mock = jest.fn();
-    const logger = new DefaultLogger({ writer: mock, debugMode: ['query'] });
-    expect(logger.debugMode).toEqual(['query']);
-    logger.log('discovery', 'test debug msg');
-    expect(mock.mock.calls.length).toBe(0);
-    logger.log('info', 'test info msg');
-    expect(mock.mock.calls.length).toBe(0);
-    logger.log('query', 'test query msg');
-    expect(mock.mock.calls.length).toBe(1);
-    logger.error('query', 'test error msg');
-    expect(mock.mock.calls.length).toBe(2);
-    logger.warn('query', 'test warning msg');
-    expect(mock.mock.calls.length).toBe(3);
+  describe('SimpleLogger', () => {
+
+        test('should print correctly without a label', () => {
+      const logger = new SimpleLogger({ writer: mockWriter, debugMode: ['query'] });
+      const namespace = 'query';
+      const message = 'test label msg';
+      logger.log(namespace, message);
+      expect(mockWriter).toBeCalledWith(`[${namespace}] ${message}`);
+    });
+
+        test('should print labels correctly', () => {
+      const logger = new SimpleLogger({ writer: mockWriter, debugMode: ['query'] });
+      const namespace = 'query';
+      const message = 'test label msg';
+      const label = 'hello world handler';
+      logger.log(namespace, message, { label });
+      expect(mockWriter).toBeCalledWith(`[${namespace}] (${label}) ${message}`);
+    });
   });
 
 });