From 7e5610400ba30623f31c56ffd480de1bbe37b9c6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Martin=20Ad=C3=A1mek?= Date: Fri, 15 Dec 2023 23:23:19 +0100 Subject: [PATCH] feat(core): allow setting logger context on EM level (#5023) The logger context can now be also set on `EntityManager` level, e.g. via `em.fork()`: ```ts const fork = em.fork({ loggerContext: { meaningOfLife: 42 }, }); const res = await fork.findAll(Author); ``` Closes #5022 --- docs/docs/logging.md | 15 +++- packages/core/src/EntityManager.ts | 80 ++++++++++++++------ packages/core/src/drivers/IDatabaseDriver.ts | 13 ++-- packages/core/src/enums.ts | 2 + packages/core/src/logging/Logger.ts | 8 +- packages/core/src/utils/RequestContext.ts | 8 +- packages/knex/src/AbstractSqlConnection.ts | 6 +- packages/knex/src/AbstractSqlDriver.ts | 6 +- packages/knex/src/SqlEntityManager.ts | 10 +-- packages/knex/src/query/QueryBuilder.ts | 4 +- packages/mongodb/src/MongoConnection.ts | 13 ++-- tests/EntityManager.postgre.test.ts | 24 ++++-- tests/features/logging/logging.test.ts | 33 +++++++- 13 files changed, 155 insertions(+), 67 deletions(-) diff --git a/docs/docs/logging.md b/docs/docs/logging.md index 806dd9a7e18b..917e360227dc 100644 --- a/docs/docs/logging.md +++ b/docs/docs/logging.md @@ -197,10 +197,10 @@ interface LogContext extends Dictionary { ### 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: +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 -const author = await em.findOne(Author, { id: 1 }, { loggerContext: { meaningOfLife: 42 } }); +const res = await em.findAll(Author, { loggerContext: { meaningOfLife: 42 } }); // ... @@ -210,4 +210,13 @@ class CustomLogger extends DefaultLogger { // 42 } } -``` \ No newline at end of file +``` + +The logger context can be also set on `EntityManager` level, e.g. via `em.fork()`: + +```ts +const fork = em.fork({ + loggerContext: { meaningOfLife: 42 }, +}); +const res = await fork.findAll(Author); // same as previous example +``` diff --git a/packages/core/src/EntityManager.ts b/packages/core/src/EntityManager.ts index e89ad451988d..c72e79771a1c 100644 --- a/packages/core/src/EntityManager.ts +++ b/packages/core/src/EntityManager.ts @@ -86,10 +86,11 @@ import { EventManager, type FlushEventArgs, TransactionEventBroadcaster } from ' import type { EntityComparator } from './utils/EntityComparator'; import { OptimisticLockError, ValidationError } from './errors'; import type { CacheAdapter } from './cache/CacheAdapter'; +import type { LogContext, LoggingOptions } from './logging'; /** * The EntityManager is the central access point to ORM functionality. It is a facade to all different ORM subsystems - * such as UnitOfWork, Query Language and Repository API. + * such as UnitOfWork, Query Language, and Repository API. * @template {D} current driver type */ export class EntityManager { @@ -109,6 +110,7 @@ export class EntityManager { private readonly resultCache: CacheAdapter; private filters: Dictionary = {}; private filterParams: Dictionary = {}; + protected loggerContext?: LoggingOptions; private transactionContext?: Transaction; private disableTransactions: boolean; private flushMode?: FlushMode; @@ -207,7 +209,7 @@ export class EntityManager { } const em = this.getContext(); - options.schema ??= em._schema; + this.prepareOptions(options, em); await em.tryFlush(entityName, options); entityName = Utils.className(entityName); where = await em.processWhere(entityName, where, options, 'read') as FilterQuery; @@ -215,7 +217,8 @@ export class EntityManager { options.orderBy = options.orderBy || {}; options.populate = em.preparePopulate(entityName, options) as any; const populate = options.populate as unknown as PopulateOptions[]; - const cached = await em.tryCache[]>(entityName, options.cache, [entityName, 'em.find', options, where], options.refresh, true); + const cacheKey = em.cacheKey(entityName, options, 'em.find', where); + const cached = await em.tryCache[]>(entityName, options.cache, cacheKey, options.refresh, true); if (cached?.data) { await em.entityLoader.populate(entityName, cached.data as Entity[], populate, { @@ -632,7 +635,7 @@ export class EntityManager { const em = this.getContext(); entityName = Utils.className(entityName); - options.schema ??= em._schema; + this.prepareOptions(options, em); let entity = em.unitOfWork.tryGetById(entityName, where, options.schema); // query for a not managed entity which is already in the identity map as it @@ -656,7 +659,8 @@ export class EntityManager { em.validator.validateParams(where); options.populate = em.preparePopulate(entityName, options) as any; - const cached = await em.tryCache>(entityName, options.cache, [entityName, 'em.findOne', options, where], options.refresh, true); + const cacheKey = em.cacheKey(entityName, options, 'em.findOne', where); + const cached = await em.tryCache>(entityName, options.cache, cacheKey, options.refresh, true); if (cached?.data) { await em.entityLoader.populate(entityName, [cached.data as Entity], options.populate as unknown as PopulateOptions[], { @@ -755,7 +759,7 @@ export class EntityManager { */ async upsert(entityNameOrEntity: EntityName | Entity, data?: EntityData | Entity, options: UpsertOptions = {}): Promise { const em = this.getContext(false); - options.schema ??= em._schema; + this.prepareOptions(options, em); let entityName: EntityName; let where: FilterQuery; @@ -893,7 +897,7 @@ export class EntityManager { */ async upsertMany(entityNameOrEntity: EntityName | Entity[], data?: (EntityData | Entity)[], options: UpsertManyOptions = {}): Promise { const em = this.getContext(false); - options.schema ??= em._schema; + this.prepareOptions(options, em); let entityName: string; let propIndex: number; @@ -1137,6 +1141,7 @@ export class EntityManager { flushMode: options.flushMode, cloneEventManager: true, disableTransactions: options.ignoreNestedTransactions, + loggerContext: options.loggerContext, }); options.ctx ??= em.transactionContext; @@ -1231,7 +1236,7 @@ export class EntityManager { */ async insert(entityNameOrEntity: EntityName | Entity, data?: RequiredEntityData | Entity, options: NativeInsertUpdateOptions = {}): Promise> { const em = this.getContext(false); - options.schema ??= em._schema; + this.prepareOptions(options, em); let entityName; @@ -1274,7 +1279,7 @@ export class EntityManager { */ async insertMany(entityNameOrEntities: EntityName | Entity[], data?: RequiredEntityData[] | Entity[], options: NativeInsertUpdateOptions = {}): Promise[]> { const em = this.getContext(false); - options.schema ??= em._schema; + this.prepareOptions(options, em); let entityName; @@ -1324,7 +1329,7 @@ export class EntityManager { */ async nativeUpdate(entityName: EntityName, where: FilterQuery, data: EntityData, options: UpdateOptions = {}): Promise { const em = this.getContext(false); - options.schema ??= em._schema; + this.prepareOptions(options, em); entityName = Utils.className(entityName); data = QueryHelper.processObjectParams(data); @@ -1341,7 +1346,7 @@ export class EntityManager { */ async nativeDelete(entityName: EntityName, where: FilterQuery, options: DeleteOptions = {}): Promise { const em = this.getContext(false); - options.schema ??= em._schema; + this.prepareOptions(options, em); entityName = Utils.className(entityName); where = await em.processWhere(entityName, where, options, 'delete'); @@ -1548,7 +1553,8 @@ export class EntityManager { em.validator.validateParams(where); delete (options as FindOptions).orderBy; - const cached = await em.tryCache(entityName, options.cache, [entityName, 'em.count', options, where]); + const cacheKey = em.cacheKey(entityName, options, 'em.count', where); + const cached = await em.tryCache(entityName, options.cache, cacheKey); if (cached?.data) { return cached.data as number; @@ -1713,9 +1719,9 @@ export class EntityManager { } const em = this.getContext(); - options.schema ??= em._schema; + this.prepareOptions(options, em); const entityName = (arr[0] as Dictionary).constructor.name; - const preparedPopulate = em.preparePopulate(entityName, { populate: populate as any }); + const preparedPopulate = em.preparePopulate(entityName, { populate: populate as any }); await em.entityLoader.populate(entityName, arr, preparedPopulate, options as EntityLoaderOptions); return entities as any; @@ -1747,6 +1753,7 @@ export class EntityManager { fork.filters = { ...em.filters }; fork.filterParams = Utils.copy(em.filterParams); + fork.loggerContext = Utils.merge({}, em.loggerContext, options.loggerContext); fork._schema = options.schema ?? em._schema; if (!options.clear) { @@ -1895,7 +1902,7 @@ export class EntityManager { }); } - const preparedPopulate = this.preparePopulate(meta.className, options); + const preparedPopulate = this.preparePopulate(meta.className, options); await this.entityLoader.populate(meta.className, [entity], preparedPopulate, { ...options as Dictionary, ...this.getPopulateWhere(where as ObjectQuery, options), @@ -1919,11 +1926,7 @@ export class EntityManager { }, [] as string[]); } - private preparePopulate< - Entity extends object, - Hint extends string = never, - Fields extends string = '*', - >(entityName: string, options: Pick, 'populate' | 'strategy' | 'fields' | 'flags'>): PopulateOptions[] { + private preparePopulate(entityName: string, options: Pick, 'populate' | 'strategy' | 'fields' | 'flags'>): PopulateOptions[] { if (options.populate === false) { return []; } @@ -2035,6 +2038,35 @@ export class EntityManager { return !!options.populate; } + protected prepareOptions(options: FindOptions | FindOneOptions, em: this): void { + options.schema ??= em._schema; + options.logging = Utils.merge( + { id: this.id }, + em.loggerContext, + options.loggerContext, + options.logging, + ); + } + + /** + * @internal + */ + cacheKey( + entityName: string, + options: FindOptions | FindOneOptions | CountOptions, + method: string, + where: FilterQuery, + ): unknown[] { + const { ...opts } = options; + + // ignore some irrelevant options, e.g. logger context can contain dynamic data for the same query + for (const k of ['ctx', 'strategy', 'flushMode', 'logging', 'loggerContext']) { + delete opts[k as keyof typeof opts]; + } + + return [entityName, method, opts, where]; + } + /** * @internal */ @@ -2154,7 +2186,7 @@ export interface MergeOptions { } export interface ForkOptions { - /** do we want clear identity map? defaults to true */ + /** do we want a clear identity map? defaults to true */ clear?: boolean; /** use request context? should be used only for top level request scope EM, defaults to false */ useContext?: boolean; @@ -2162,12 +2194,14 @@ export interface ForkOptions { freshEventManager?: boolean; /** do we want to clone current EventManager instance? defaults to false (global instance) */ cloneEventManager?: boolean; - /** use this flag to ignore current async context - this is required if we want to call `em.fork()` inside the `getContext` handler */ + /** use this flag to ignore the current async context - this is required if we want to call `em.fork()` inside the `getContext` handler */ disableContextResolution?: boolean; - /** set flush mode for this fork, overrides the global option, can be overridden locally via FindOptions */ + /** set flush mode for this fork, overrides the global option can be overridden locally via FindOptions */ flushMode?: FlushMode; /** disable transactions for this fork */ disableTransactions?: boolean; /** default schema to use for this fork */ schema?: string; + /** default logger context, can be overridden via {@apilink FindOptions} */ + loggerContext?: LogContext; } diff --git a/packages/core/src/drivers/IDatabaseDriver.ts b/packages/core/src/drivers/IDatabaseDriver.ts index f6c56b6f91ca..5353401d35ac 100644 --- a/packages/core/src/drivers/IDatabaseDriver.ts +++ b/packages/core/src/drivers/IDatabaseDriver.ts @@ -94,14 +94,13 @@ export type EntityField = keyof T | '*' | AutoPath = (QueryOrderMap & { 0?: never }) | QueryOrderMap[]; -export interface FindAllOptions extends FindOptions { +export interface FindAllOptions extends FindOptions { where?: FilterQuery; } export type FilterOptions = Dictionary | string[] | boolean; -export interface FindOptions { - where?: FilterQuery; +export interface FindOptions { populate?: Populate; populateWhere?: ObjectQuery | PopulateHint | `${PopulateHint}`; populateOrderBy?: OrderDefinition; @@ -148,15 +147,15 @@ export interface FindOptions extends Omit, 'limit' | 'offset'> { +export interface FindByCursorOptions extends Omit, 'limit' | 'offset'> { } -export interface FindOneOptions extends Omit, 'limit' | 'lockMode'> { +export interface FindOneOptions extends Omit, 'limit' | 'lockMode'> { lockMode?: LockMode; lockVersion?: number | Date; } -export interface FindOneOrFailOptions extends FindOneOptions { +export interface FindOneOrFailOptions extends FindOneOptions { failHandler?: (entityName: string, where: Dictionary | IPrimaryKey | any) => Error; strict?: boolean; } @@ -199,6 +198,8 @@ export interface CountOptions { comments?: string | string[]; /** sql only */ hintComments?: string | string[]; + loggerContext?: LogContext; + logging?: LoggingOptions; } export interface UpdateOptions { diff --git a/packages/core/src/enums.ts b/packages/core/src/enums.ts index 0012077b4495..706225dd32a5 100644 --- a/packages/core/src/enums.ts +++ b/packages/core/src/enums.ts @@ -1,5 +1,6 @@ import type { Dictionary, EntityKey, ExpandProperty } from './typings'; import type { Transaction } from './connections'; +import type { LogContext } from './logging'; export enum FlushMode { /** The `EntityManager` delays the flush until the current Transaction is committed. */ @@ -190,6 +191,7 @@ export interface TransactionOptions { clear?: boolean; flushMode?: FlushMode; ignoreNestedTransactions?: boolean; + loggerContext?: LogContext; } export abstract class PlainObject { diff --git a/packages/core/src/logging/Logger.ts b/packages/core/src/logging/Logger.ts index ac01e95d70a7..ba4befe4dbb2 100644 --- a/packages/core/src/logging/Logger.ts +++ b/packages/core/src/logging/Logger.ts @@ -57,12 +57,12 @@ export interface LoggerOptions { } /** - * Logger options to modify format output and overrides, including a label and additional properties that can be accessed by custom loggers + * Logger options to modify format output and overrides, including a label and additional properties that can be accessed by custom loggers. * - * Differs from {@link LoggerOptions} in terms of how they are used; this type is primarily a public type meant to be used within methods like `EntityManager.Find` + * Differs from {@apilink LoggerOptions} in terms of how they are used; this type is primarily a public type meant to be used within methods like `em.find()`. * * @example - * await em.findOne(User, 1, { loggerContext: { label: 'user middleware' } }; + * await em.findOne(User, 1, { logger: { label: 'user middleware' } }; * // [query] (user middleware) select * from user where id = 1; */ -export type LoggingOptions = Pick & Dictionary; +export type LoggingOptions = Pick; diff --git a/packages/core/src/utils/RequestContext.ts b/packages/core/src/utils/RequestContext.ts index 194edb8dfec5..be5511a56b0c 100644 --- a/packages/core/src/utils/RequestContext.ts +++ b/packages/core/src/utils/RequestContext.ts @@ -1,8 +1,9 @@ import { AsyncLocalStorage } from 'async_hooks'; import type { EntityManager } from '../EntityManager'; +import { type LoggingOptions } from '../logging/Logger'; /** - * Uses `AsyncLocalStorage` to create async context that holds current EM fork. + * Uses `AsyncLocalStorage` to create async context that holds the current EM fork. */ export class RequestContext { @@ -47,9 +48,9 @@ export class RequestContext { const forks = new Map(); if (Array.isArray(em)) { - em.forEach(em => forks.set(em.name, em.fork({ useContext: true, schema: options.schema }))); + em.forEach(em => forks.set(em.name, em.fork({ useContext: true, ...options }))); } else { - forks.set(em.name, em.fork({ useContext: true, schema: options.schema })); + forks.set(em.name, em.fork({ useContext: true, ...options })); } return new RequestContext(forks); @@ -59,4 +60,5 @@ export class RequestContext { export interface CreateContextOptions { schema?: string; + loggerContext?: LoggingOptions; } diff --git a/packages/knex/src/AbstractSqlConnection.ts b/packages/knex/src/AbstractSqlConnection.ts index 406a007353a1..4b21fafd8fd8 100644 --- a/packages/knex/src/AbstractSqlConnection.ts +++ b/packages/knex/src/AbstractSqlConnection.ts @@ -144,7 +144,7 @@ export abstract class AbstractSqlConnection extends Connection { } } - async execute | EntityData[] = EntityData[]>(queryOrKnex: string | Knex.QueryBuilder | Knex.Raw, params: unknown[] = [], method: 'all' | 'get' | 'run' = 'all', ctx?: Transaction, logging?: LoggingOptions): Promise { + async execute | EntityData[] = EntityData[]>(queryOrKnex: string | Knex.QueryBuilder | Knex.Raw, params: unknown[] = [], method: 'all' | 'get' | 'run' = 'all', ctx?: Transaction, loggerContext?: LoggingOptions): Promise { await this.ensureConnection(); if (Utils.isObject(queryOrKnex)) { @@ -155,7 +155,7 @@ export abstract class AbstractSqlConnection extends Connection { } const formatted = this.platform.formatQuery(queryOrKnex, params); - const sql = this.getSql(queryOrKnex, formatted, logging); + const sql = this.getSql(queryOrKnex, formatted, loggerContext); return this.executeQuery(sql, async () => { const query = this.getKnex().raw(formatted); @@ -165,7 +165,7 @@ export abstract class AbstractSqlConnection extends Connection { const res = await query; return this.transformRawResult(res, method); - }, { query: queryOrKnex, params, ...logging }); + }, { query: queryOrKnex, params, ...loggerContext }); } /** diff --git a/packages/knex/src/AbstractSqlDriver.ts b/packages/knex/src/AbstractSqlDriver.ts index f1c205cab6f2..5d86c73cbb92 100644 --- a/packages/knex/src/AbstractSqlDriver.ts +++ b/packages/knex/src/AbstractSqlDriver.ts @@ -950,7 +950,7 @@ export abstract class AbstractSqlDriver(meta: EntityMetadata, populate: PopulateOptions[], fields: readonly EntityField[] = []): PopulateOptions[] { + protected autoJoinOneToOneOwner(meta: EntityMetadata, populate: PopulateOptions[], fields: readonly EntityField[] = []): PopulateOptions[] { if (!this.config.get('autoJoinOneToOneOwner')) { return populate; } @@ -1136,7 +1136,7 @@ export abstract class AbstractSqlDriver(entityName: EntityName | QueryBuilder, ctx?: Transaction, preferredConnectionType?: ConnectionType, convertCustomTypes?: boolean, logging?: LoggingOptions): QueryBuilder { + createQueryBuilder(entityName: EntityName | QueryBuilder, ctx?: Transaction, preferredConnectionType?: ConnectionType, convertCustomTypes?: boolean, loggerContext?: LoggingOptions): QueryBuilder { const connectionType = this.resolveConnectionType({ ctx, connectionType: preferredConnectionType }); const qb = new QueryBuilder( entityName, @@ -1146,7 +1146,7 @@ export abstract class AbstractSqlDriver e /** * Creates a QueryBuilder instance */ - createQueryBuilder(entityName: EntityName | QueryBuilder, alias?: string, type?: ConnectionType): QueryBuilder { + createQueryBuilder(entityName: EntityName | QueryBuilder, alias?: string, type?: ConnectionType, loggerContext?: LoggingOptions): QueryBuilder { const context = this.getContext(); - - return new QueryBuilder(entityName, this.getMetadata(), this.getDriver(), context.getTransactionContext(), alias, type, context); + return new QueryBuilder(entityName, this.getMetadata(), this.getDriver(), context.getTransactionContext(), alias, type, context, loggerContext ?? context.loggerContext); } /** * Shortcut for `createQueryBuilder()` */ - qb(entityName: EntityName, alias?: string, type?: ConnectionType) { - return this.createQueryBuilder(entityName, alias, type); + qb(entityName: EntityName, alias?: string, type?: ConnectionType, loggerContext?: LoggingOptions) { + return this.createQueryBuilder(entityName, alias, type, loggerContext); } /** diff --git a/packages/knex/src/query/QueryBuilder.ts b/packages/knex/src/query/QueryBuilder.ts index 5776c9c52379..832c0e8a4d55 100644 --- a/packages/knex/src/query/QueryBuilder.ts +++ b/packages/knex/src/query/QueryBuilder.ts @@ -137,7 +137,7 @@ export class QueryBuilder { alias?: string, private connectionType?: ConnectionType, private readonly em?: SqlEntityManager, - private readonly logging?: LoggingOptions) { + private readonly loggerContext?: LoggingOptions) { this.platform = this.driver.getPlatform(); this.knex = this.driver.getConnection(this.connectionType).getKnex(); @@ -757,7 +757,7 @@ export class QueryBuilder { const write = method === 'run' || !this.platform.getConfig().get('preferReadReplicas'); const type = this.connectionType || (write ? 'write' : 'read'); - const res = await this.driver.getConnection(type).execute(query.sql, query.bindings as any[], method, this.context, this.logging); + 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 (!options.mapResults || !meta) { diff --git a/packages/mongodb/src/MongoConnection.ts b/packages/mongodb/src/MongoConnection.ts index c1710214f045..12dafd749573 100644 --- a/packages/mongodb/src/MongoConnection.ts +++ b/packages/mongodb/src/MongoConnection.ts @@ -39,7 +39,6 @@ import { type UpsertOptions, type UpsertManyOptions, type LoggingOptions, - type LogContext, } from '@mikro-orm/core'; export class MongoConnection extends Connection { @@ -165,7 +164,7 @@ export class MongoConnection extends Connection { throw new Error(`${this.constructor.name} does not support generic execute method`); } - async find(collection: string, where: FilterQuery, orderBy?: QueryOrderMap | QueryOrderMap[], limit?: number, offset?: number, fields?: string[], ctx?: Transaction, logging?: LoggingOptions): Promise[]> { + async find(collection: string, where: FilterQuery, orderBy?: QueryOrderMap | QueryOrderMap[], limit?: number, offset?: number, fields?: string[], ctx?: Transaction, loggerContext?: LoggingOptions): Promise[]> { await this.ensureConnection(); collection = this.getCollectionName(collection); const options: Dictionary = ctx ? { session: ctx } : {}; @@ -205,7 +204,7 @@ export class MongoConnection extends Connection { const now = Date.now(); const res = await resultSet.toArray(); - this.logQuery(`${query}.toArray();`, { took: Date.now() - now, results: res.length, ...logging }); + this.logQuery(`${query}.toArray();`, { took: Date.now() - now, results: res.length, ...loggerContext }); return res as EntityData[]; } @@ -230,7 +229,7 @@ export class MongoConnection extends Connection { return this.runQuery('deleteMany', collection, undefined, where, ctx); } - async aggregate(collection: string, pipeline: any[], ctx?: Transaction, logging?: LoggingOptions): Promise { + async aggregate(collection: string, pipeline: any[], ctx?: Transaction, loggerContext?: LoggingOptions): Promise { await this.ensureConnection(); collection = this.getCollectionName(collection); /* istanbul ignore next */ @@ -238,7 +237,7 @@ export class MongoConnection extends Connection { const query = `db.getCollection('${collection}').aggregate(${this.logObject(pipeline)}, ${this.logObject(options)}).toArray();`; const now = Date.now(); const res = await this.getCollection(collection).aggregate(pipeline, options).toArray(); - this.logQuery(query, { took: Date.now() - now, results: res.length, ...logging }); + this.logQuery(query, { took: Date.now() - now, results: res.length, ...loggerContext }); return res; } @@ -295,7 +294,7 @@ export class MongoConnection extends Connection { await eventBroadcaster?.dispatchEvent(EventType.afterTransactionRollback, ctx); } - private async runQuery | number = QueryResult>(method: 'insertOne' | 'insertMany' | 'updateMany' | 'bulkUpdateMany' | 'deleteMany' | 'countDocuments', collection: string, data?: Partial | Partial[], where?: FilterQuery | FilterQuery[], ctx?: Transaction, upsert?: boolean, upsertOptions?: UpsertOptions, logging?: LoggingOptions): Promise { + private async runQuery | number = QueryResult>(method: 'insertOne' | 'insertMany' | 'updateMany' | 'bulkUpdateMany' | 'deleteMany' | 'countDocuments', collection: string, data?: Partial | Partial[], where?: FilterQuery | FilterQuery[], ctx?: Transaction, upsert?: boolean, upsertOptions?: UpsertOptions, loggerContext?: LoggingOptions): Promise { await this.ensureConnection(); collection = this.getCollectionName(collection); const logger = this.config.getLogger(); @@ -357,7 +356,7 @@ export class MongoConnection extends Connection { break; } - this.logQuery(query!, { took: Date.now() - now, ...logging }); + this.logQuery(query!, { took: Date.now() - now, ...loggerContext }); if (method === 'countDocuments') { return res! as unknown as U; diff --git a/tests/EntityManager.postgre.test.ts b/tests/EntityManager.postgre.test.ts index 0bcf1426174a..053199518633 100644 --- a/tests/EntityManager.postgre.test.ts +++ b/tests/EntityManager.postgre.test.ts @@ -1,5 +1,5 @@ import { v4 } from 'uuid'; -import type { AnyEntity, ChangeSet, EventSubscriber, FilterQuery, FlushEventArgs } from '@mikro-orm/core'; +import { AnyEntity, ChangeSet, DefaultLogger, EventSubscriber, FilterQuery, FlushEventArgs } from '@mikro-orm/core'; import { ChangeSetType, Collection, @@ -651,21 +651,35 @@ describe('EntityManagerPostgre', () => { const mock = mockLogger(orm, ['query', 'query-params']); - const b0 = await orm.em.findOneOrFail(FooBar2, bar); + const em = orm.em.fork({ loggerContext: { label: 'foo', bar: 123 } }); + const logSpy = jest.spyOn(DefaultLogger.prototype, 'log'); + const b0 = await em.findOneOrFail(FooBar2, bar, { + logging: { label: 'foo 123' }, + loggerContext: { bar: 456, new: true }, + }); expect(b0.objectProperty).toEqual({ myPropName: { nestedProperty: 123, somethingElse: null } }); - const b1 = await orm.em.findOneOrFail(FooBar2, { objectProperty: { myPropName: { nestedProperty: 123 } } }); - const b2 = await orm.em.findOneOrFail(FooBar2, { objectProperty: { myPropName: { somethingElse: null } } }); - const b3 = await orm.em.findOneOrFail(FooBar2, { objectProperty: { myPropName: { nestedProperty: 123, somethingElse: null } } }); + const b1 = await em.findOneOrFail(FooBar2, { objectProperty: { myPropName: { nestedProperty: 123 } } }); + const b2 = await em.findOneOrFail(FooBar2, { objectProperty: { myPropName: { somethingElse: null } } }); + const b3 = await em.findOneOrFail(FooBar2, { objectProperty: { myPropName: { nestedProperty: 123, somethingElse: null } } }); expect(b0).toBe(b1); expect(b0).toBe(b2); expect(b0).toBe(b3); expect(mock.mock.calls).toHaveLength(4); + expect(logSpy.mock.calls).toHaveLength(4); expect(mock.mock.calls[0][0]).toMatch(`select "f0".*, (select 123) as "random" from "foo_bar2" as "f0" where "f0"."id" = 1 limit 1`); + expect(mock.mock.calls[0][0]).toMatch('(foo 123)'); + expect(logSpy.mock.calls[0][2]).toMatchObject({ id: em.id, label: 'foo 123', bar: 456, new: true }); expect(mock.mock.calls[1][0]).toMatch(`select "f0".*, (select 123) as "random" from "foo_bar2" as "f0" where ("f0"."object_property"->'myPropName'->>'nestedProperty')::float8 = 123 limit 1`); + expect(mock.mock.calls[1][0]).toMatch('(foo)'); + expect(logSpy.mock.calls[1][2]).toMatchObject({ id: em.id, label: 'foo', bar: 123 }); expect(mock.mock.calls[2][0]).toMatch(`select "f0".*, (select 123) as "random" from "foo_bar2" as "f0" where "f0"."object_property"->'myPropName'->>'somethingElse' is null limit 1`); + expect(mock.mock.calls[2][0]).toMatch('(foo)'); + expect(logSpy.mock.calls[2][2]).toMatchObject({ id: em.id, label: 'foo', bar: 123 }); expect(mock.mock.calls[3][0]).toMatch(`select "f0".*, (select 123) as "random" from "foo_bar2" as "f0" where ("f0"."object_property"->'myPropName'->>'nestedProperty')::float8 = 123 and "f0"."object_property"->'myPropName'->>'somethingElse' is null limit 1`); + expect(mock.mock.calls[3][0]).toMatch('(foo)'); + expect(logSpy.mock.calls[3][2]).toMatchObject({ id: em.id, label: 'foo', bar: 123 }); }); test('findOne should initialize entity that is already in IM', async () => { diff --git a/tests/features/logging/logging.test.ts b/tests/features/logging/logging.test.ts index 4ddcbc5df4f4..d0139b94c6aa 100644 --- a/tests/features/logging/logging.test.ts +++ b/tests/features/logging/logging.test.ts @@ -1,4 +1,4 @@ -import { Entity, LoggerNamespace, MikroORM, PrimaryKey, Property } from '@mikro-orm/core'; +import { DefaultLogger, Entity, LoggerNamespace, MikroORM, PrimaryKey, Property } from '@mikro-orm/core'; import { SqliteDriver } from '@mikro-orm/sqlite'; import { mockLogger } from '../../helpers'; @@ -52,9 +52,14 @@ describe('logging', () => { it(`overrides the default namespace`, async () => { setDebug(['discovery']); - const em = orm.em.fork(); + const em = orm.em.fork({ + loggerContext: { foo: 0, bar: true, label: 'fork' }, + }); - const example = await em.findOneOrFail(Example, { id: 1 }, { logging: { debugMode: ['query'] } }); + const example = await em.findOneOrFail(Example, { id: 1 }, { + logging: { debugMode: ['query'] }, + loggerContext: { foo: 123 }, + }); example.title = 'An update'; await em.persistAndFlush(example); @@ -70,4 +75,26 @@ describe('logging', () => { expect(mockedLogger).toHaveBeenCalledTimes(1); }); + test('json properties respect field names', async () => { + const mock = mockLogger(orm, ['query', 'query-params']); + + const em = orm.em.fork({ loggerContext: { label: 'foo', bar: 123 } }); + const logSpy = jest.spyOn(DefaultLogger.prototype, 'log'); + await em.findOne(Example, { id: 1 }, { + logging: { label: 'foo 123' }, + loggerContext: { bar: 456, new: true }, + }); + + await em.findOne(Example, { id: 1 }, { refresh: true }); + + expect(mock.mock.calls).toHaveLength(2); + expect(logSpy.mock.calls).toHaveLength(2); + expect(mock.mock.calls[0][0]).toMatch('select `e0`.* from `example` as `e0` where `e0`.`id` = 1 limit 1'); + expect(mock.mock.calls[0][0]).toMatch('(foo 123)'); + expect(logSpy.mock.calls[0][2]).toMatchObject({ id: em.id, label: 'foo 123', bar: 456, new: true }); + expect(mock.mock.calls[1][0]).toMatch('select `e0`.* from `example` as `e0` where `e0`.`id` = 1 limit 1'); + expect(mock.mock.calls[1][0]).toMatch('(foo)'); + expect(logSpy.mock.calls[1][2]).toMatchObject({ id: em.id, label: 'foo', bar: 123 }); + }); + });