feat(core): Improved control over TypeORM query logging

Closes #368
vendure-ecommerce · Jun 11, 2020 · 3168e54 · 3168e54
1 parent 5ed6c24
commit 3168e54
Show file tree

Hide file tree

Showing 4 changed files with 76 additions and 9 deletions.
diff --git a/packages/core/src/config/default-config.ts b/packages/core/src/config/default-config.ts
@@ -80,7 +80,6 @@ export const defaultConfig: RuntimeVendureConfig = {
     dbConnectionOptions: {
         timezone: 'Z',
         type: 'mysql',
-        logger: new TypeOrmLogger(),
     },
     promotionOptions: {
         promotionConditions: defaultPromotionConditions,

diff --git a/packages/core/src/config/logger/typeorm-logger.ts b/packages/core/src/config/logger/typeorm-logger.ts
@@ -1,23 +1,36 @@
 import { Logger as TypeOrmLoggerInterface, QueryRunner } from 'typeorm';
+import { LoggerOptions } from 'typeorm/logger/LoggerOptions';
 
 import { Logger } from './vendure-logger';
 
 const context = 'TypeORM';
 
+type typeOrmLogLevel = Exclude<LoggerOptions, 'all' | boolean>[number];
+
+const defaultLoggerOptions: LoggerOptions = ['error', 'warn', 'schema', 'migration'];
+
 /**
  * A custom logger for TypeORM which delegates to the Vendure Logger service.
  */
 export class TypeOrmLogger implements TypeOrmLoggerInterface {
+    constructor(private options: LoggerOptions = defaultLoggerOptions) {}
+
     log(level: 'log' | 'info' | 'warn', message: any, queryRunner?: QueryRunner): any {
         switch (level) {
             case 'info':
-                Logger.info(message, context);
+                if (this.shouldDisplay('info')) {
+                    Logger.info(message, context);
+                }
                 break;
             case 'log':
-                Logger.verbose(message, context);
+                if (this.shouldDisplay('log')) {
+                    Logger.info(message, context);
+                }
                 break;
             case 'warn':
-                Logger.warn(message, context);
+                if (this.shouldDisplay('warn')) {
+                    Logger.warn(message, context);
+                }
                 break;
         }
     }
@@ -27,18 +40,53 @@ export class TypeOrmLogger implements TypeOrmLoggerInterface {
     }
 
     logQuery(query: string, parameters?: any[], queryRunner?: QueryRunner): any {
-        Logger.debug(`Query: "${query}" -- [${parameters}]`, context);
+        if (this.shouldDisplay('query')) {
+            const sql = this.formatQueryWithParams(query, parameters);
+            Logger.debug(`Query: ${sql}`, context);
+        }
     }
 
     logQueryError(error: string, query: string, parameters?: any[], queryRunner?: QueryRunner): any {
-        Logger.error(`Query error: ${error}, "${query}" -- [${parameters}]`, context);
+        if (this.shouldDisplay('error')) {
+            const sql = this.formatQueryWithParams(query, parameters);
+            Logger.error(`Query error: ${sql}`, context);
+        }
     }
 
     logQuerySlow(time: number, query: string, parameters?: any[], queryRunner?: QueryRunner): any {
-        Logger.warn(`Slow query (${time}): "${query}" -- [${parameters}]`, context);
+        const sql = this.formatQueryWithParams(query, parameters);
+        Logger.warn(`Query is slow: ` + sql);
+        Logger.warn(`Execution time: ` + time);
     }
 
     logSchemaBuild(message: string, queryRunner?: QueryRunner): any {
-        Logger.info(message, context);
+        if (this.shouldDisplay('schema')) {
+            Logger.info(message, context);
+        }
+    }
+
+    private shouldDisplay(logType: typeOrmLogLevel): boolean {
+        return (
+            this.options === 'all' ||
+            this.options === true ||
+            (Array.isArray(this.options) && this.options.includes(logType))
+        );
+    }
+
+    private formatQueryWithParams(query: string, parameters?: any[]) {
+        return query + (parameters?.length ? ' -- PARAMETERS: ' + this.stringifyParams(parameters) : '');
+    }
+
+    /**
+     * Converts parameters to a string.
+     * Sometimes parameters can have circular objects and therefor we are handle this case too.
+     */
+    private stringifyParams(parameters: any[]) {
+        try {
+            return JSON.stringify(parameters);
+        } catch (error) {
+            // most probably circular objects in parameters
+            return parameters;
+        }
     }
 }
diff --git a/packages/core/src/config/vendure-config.ts b/packages/core/src/config/vendure-config.ts
@@ -656,6 +656,8 @@ export interface VendureConfig {
     /**
      * @description
      * Provide a logging service which implements the {@link VendureLogger} interface.
+     * Note that the logging of SQL queries is controlled separately by the
+     * `dbConnectionOptions.logging` property.
      *
      * @default DefaultLogger
      */

diff --git a/packages/core/src/service/service.module.ts b/packages/core/src/service/service.module.ts
@@ -1,8 +1,10 @@
 import { DynamicModule, Module, OnModuleInit } from '@nestjs/common';
 import { TypeOrmModule } from '@nestjs/typeorm';
+import { ConnectionOptions } from 'typeorm';
 
 import { ConfigModule } from '../config/config.module';
 import { ConfigService } from '../config/config.service';
+import { TypeOrmLogger } from '../config/logger/typeorm-logger';
 import { EventBusModule } from '../event-bus/event-bus.module';
 import { JobQueueModule } from '../job-queue/job-queue.module';
 import { WorkerServiceModule } from '../worker/worker-service.module';
@@ -158,7 +160,12 @@ export class ServiceModule {
             defaultTypeOrmModule = TypeOrmModule.forRootAsync({
                 imports: [ConfigModule],
                 useFactory: (configService: ConfigService) => {
-                    return configService.dbConnectionOptions;
+                    const { dbConnectionOptions } = configService;
+                    const logger = ServiceModule.getTypeOrmLogger(dbConnectionOptions);
+                    return {
+                        ...dbConnectionOptions,
+                        logger,
+                    };
                 },
                 inject: [ConfigService],
             });
@@ -175,17 +182,20 @@ export class ServiceModule {
                 imports: [ConfigModule],
                 useFactory: (configService: ConfigService) => {
                     const { dbConnectionOptions, workerOptions } = configService;
+                    const logger = ServiceModule.getTypeOrmLogger(dbConnectionOptions);
                     if (workerOptions.runInMainProcess) {
                         // When running in the main process, we can re-use the existing
                         // default connection.
                         return {
                             ...dbConnectionOptions,
+                            logger,
                             name: 'default',
                             keepConnectionAlive: true,
                         };
                     } else {
                         return {
                             ...dbConnectionOptions,
+                            logger,
                         };
                     }
                 },
@@ -205,4 +215,12 @@ export class ServiceModule {
             imports: [TypeOrmModule.forFeature()],
         };
     }
+
+    static getTypeOrmLogger(dbConnectionOptions: ConnectionOptions) {
+        if (!dbConnectionOptions.logger) {
+            return new TypeOrmLogger(dbConnectionOptions.logging);
+        } else {
+            return dbConnectionOptions.logger;
+        }
+    }
 }