perf(core): do not generate sql when logging disabled

Related: #732
mikro-orm · Aug 13, 2020 · f232bb3 · f232bb3
1 parent 9abbe03
commit f232bb3
Show file tree

Hide file tree

Showing 15 changed files with 59 additions and 58 deletions.
diff --git a/packages/core/src/connections/Connection.ts b/packages/core/src/connections/Connection.ts
@@ -100,7 +100,7 @@ export abstract class Connection {
     // We only actually log something when debugMode is enabled. If it's not enabled,
     // we can jump out here as a performance optimization and save ourselves some cycles
     // preparing a message that won't get used.
-    if (!logger.debugMode || (Array.isArray(logger.debugMode) && !logger.debugMode.includes('query'))) {
+    if (!logger.isEnabled('query')) {
       return;
     }
 

diff --git a/packages/core/src/utils/Logger.ts b/packages/core/src/utils/Logger.ts
@@ -9,11 +9,7 @@ export class Logger {
    * Logs a message inside given namespace.
    */
   log(namespace: LoggerNamespace, message: string): void {
-    if (!this.debugMode) {
-      return;
-    }
-
-    if (Array.isArray(this.debugMode) && !this.debugMode.includes(namespace)) {
+    if (!this.isEnabled(namespace)) {
       return;
     }
 
@@ -29,6 +25,10 @@ export class Logger {
     this.debugMode = debugMode;
   }
 
+  isEnabled(namespace: LoggerNamespace): boolean {
+    return this.debugMode && (!Array.isArray(this.debugMode) || this.debugMode.includes(namespace));
+  }
+
 }
 
 export type LoggerNamespace = 'query' | 'query-params' | 'discovery' | 'info';
diff --git a/packages/knex/src/AbstractSqlConnection.ts b/packages/knex/src/AbstractSqlConnection.ts
@@ -1,7 +1,7 @@
 import Knex, { Config, QueryBuilder, Raw, Transaction as KnexTransaction } from 'knex';
 import { readFile } from 'fs-extra';
 
-import { Connection, EntityData, AnyEntity, QueryResult, Transaction, Utils } from '@mikro-orm/core';
+import { AnyEntity, Connection, EntityData, QueryResult, Transaction, Utils } from '@mikro-orm/core';
 
 export abstract class AbstractSqlConnection extends Connection {
 
@@ -100,10 +100,13 @@ export abstract class AbstractSqlConnection extends Connection {
   }
 
   private getSql(qb: QueryBuilder | Raw): string {
-    const debug = this.config.get('debug');
-    const dumpParams = Array.isArray(debug) ? debug.includes('query-params') : debug;
+    const logger = this.config.getLogger();
 
-    if (dumpParams) {
+    if (!logger.isEnabled('query')) {
+      return '';
+    }
+
+    if (logger.isEnabled('query-params')) {
       return qb.toString();
     }
 

diff --git a/tests/EntityManager.mysql.test.ts b/tests/EntityManager.mysql.test.ts
@@ -322,7 +322,7 @@ describe('EntityManagerMySql', () => {
 
   test('nested transaction rollback with save-points will commit the outer one', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // start outer transaction
@@ -646,7 +646,7 @@ describe('EntityManagerMySql', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {
@@ -664,7 +664,7 @@ describe('EntityManagerMySql', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {
@@ -831,7 +831,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const b0 = (await orm.em.findOne(FooBaz2, { id: baz.id }))!;
@@ -1419,7 +1419,7 @@ describe('EntityManagerMySql', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     orm.em.clear();
@@ -1466,7 +1466,6 @@ describe('EntityManagerMySql', () => {
     const mock = jest.fn();
     const logger = new Logger(mock, true);
     Object.assign(orm.config, { logger });
-    orm.config.set('debug', true);
 
     orm.em.clear();
     const books1 = await orm.em.find(Book2, { title: '123' }, {
@@ -1561,7 +1560,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const jon = await orm.em.findOneOrFail(Author2, author.id, ['friends'], { friends: { name: QueryOrder.ASC } });
@@ -1731,7 +1730,7 @@ describe('EntityManagerMySql', () => {
 
   test('self referencing (1 step)', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const author = new Author2('name', 'email');
@@ -1853,7 +1852,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     const res1 = await orm.em.find(Book2, { author: { name: 'Jon Snow' } }, ['perex']);
     expect(res1).toHaveLength(3);
@@ -1965,7 +1964,7 @@ describe('EntityManagerMySql', () => {
 
   test('query highlighting', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     orm.config.set('highlighter', new SqlHighlighter());
     c.enabled = true;
@@ -1985,7 +1984,7 @@ describe('EntityManagerMySql', () => {
 
   test('read replicas', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     let author = new Author2('Jon Snow', 'snow@wall.st');
@@ -2080,7 +2079,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const res1 = await orm.em.find(Book2, { publisher: { $ne: null } }, { schema: 'mikro_orm_test_schema_2', populate: ['perex'] });
@@ -2116,7 +2115,7 @@ describe('EntityManagerMySql', () => {
     orm.em.remove(a.baz!);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     await orm.em.flush();
     expect(mock.mock.calls[0][0]).toMatch('begin');
@@ -2245,7 +2244,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // without paginate flag it fails to get 5 records
@@ -2310,7 +2309,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const b = await orm.em.findOneOrFail(Book2, { author: { name: 'God' } });
@@ -2398,7 +2397,7 @@ describe('EntityManagerMySql', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const r1 = await orm.em.find(Author2, {}, { populate: { books: true } });

diff --git a/tests/EntityManager.postgre.test.ts b/tests/EntityManager.postgre.test.ts
@@ -84,7 +84,7 @@ describe('EntityManagerPostgre', () => {
     await driver.nativeInsert(Test2.name, { id: 5, name: 't5' });
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const res = await driver.nativeInsertMany(Publisher2.name, [
@@ -205,7 +205,7 @@ describe('EntityManagerPostgre', () => {
 
   test('nested transaction rollback with save-points will commit the outer one', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // start outer transaction
@@ -515,7 +515,7 @@ describe('EntityManagerPostgre', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {
@@ -533,7 +533,7 @@ describe('EntityManagerPostgre', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {
@@ -662,7 +662,7 @@ describe('EntityManagerPostgre', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // autoJoinOneToOneOwner: false
@@ -968,7 +968,7 @@ describe('EntityManagerPostgre', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     const res = await orm.em.find(Author2, { books: { title: { $in: ['b1', 'b2'] } } }, ['books.perex']);
     expect(res).toHaveLength(1);
@@ -1054,9 +1054,8 @@ describe('EntityManagerPostgre', () => {
     expect(b.createdAt).toBeInstanceOf(Date);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query', 'query-params']);
     Object.assign(orm.config, { logger });
-    orm.config.set('debug', true);
     await orm.em.nativeInsert(Author2, { name: 'native name 1', email: 'native1@email.com' });
     expect(mock.mock.calls[0][0]).toMatch('insert into "author2" ("email", "name") values (\'native1@email.com\', \'native name 1\') returning "id", "created_at", "updated_at"');
     orm.config.set('debug', ['query']);
@@ -1093,7 +1092,7 @@ describe('EntityManagerPostgre', () => {
 
   test('self referencing (1 step)', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const author = new Author2('name', 'email');
@@ -1169,7 +1168,7 @@ describe('EntityManagerPostgre', () => {
     orm.em.clear();
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     const res1 = await orm.em.find(Book2, { author: { name: 'Jon Snow' } }, ['perex']);
     expect(res1).toHaveLength(3);
@@ -1281,7 +1280,7 @@ describe('EntityManagerPostgre', () => {
     expect(res1.map(a => a.name)).toEqual(['God 02', 'God 03']);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // with paginate flag (and a bit of dark sql magic) we get what we want

diff --git a/tests/EntityManager.sqlite.test.ts b/tests/EntityManager.sqlite.test.ts
@@ -162,7 +162,7 @@ describe('EntityManagerSqlite', () => {
 
   test('nested transaction rollback with save-points will commit the outer one', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // start outer transaction
@@ -447,7 +447,7 @@ describe('EntityManagerSqlite', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {
@@ -465,7 +465,7 @@ describe('EntityManagerSqlite', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {

diff --git a/tests/EntityManager.sqlite2.test.ts b/tests/EntityManager.sqlite2.test.ts
@@ -96,7 +96,7 @@ describe('EntityManagerSqlite2', () => {
 
   test('nested transaction rollback with save-points will commit the outer one', async () => {
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     // start outer transaction
@@ -385,7 +385,7 @@ describe('EntityManagerSqlite2', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {
@@ -403,7 +403,7 @@ describe('EntityManagerSqlite2', () => {
     await orm.em.persistAndFlush(author);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await orm.em.transactional(async em => {

diff --git a/tests/Migrator.test.ts b/tests/Migrator.test.ts
@@ -121,7 +121,7 @@ describe('Migrator', () => {
     const runner = migrator.runner;
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     const migration1 = new MigrationTest1(orm.em.getDriver(), orm.config);
@@ -164,7 +164,7 @@ describe('Migrator', () => {
     migratorMock.mockImplementation(async () => void 0);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await migrator.up(migration.fileName);
@@ -200,7 +200,7 @@ describe('Migrator', () => {
     migratorMock.mockImplementation(async () => void 0);
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
 
     await migrator.up(migration.fileName);

diff --git a/tests/composite-keys.mysql.test.ts b/tests/composite-keys.mysql.test.ts
@@ -275,7 +275,7 @@ describe('composite keys in mysql', () => {
     expect(wrap(u1.cars[2], true).__em).not.toBeUndefined(); // PK only, so will be merged automatically
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     await orm.em.persistAndFlush(u1);
     expect(mock.mock.calls[0][0]).toMatch('begin');

diff --git a/tests/embedded-entities.mysql.test.ts b/tests/embedded-entities.mysql.test.ts
@@ -140,7 +140,7 @@ describe('embedded entities in mysql', () => {
     user.address3 = new Address1('Downing street 12', '789', 'London 3', 'UK 3');
 
     const mock = jest.fn();
-    const logger = new Logger(mock, true);
+    const logger = new Logger(mock, ['query']);
     Object.assign(orm.config, { logger });
     orm.config.reset('highlighter');
     await orm.em.persistAndFlush(user);