feat(core): Create Logger service

Relates to #86

packages/admin-ui-plugin/src/plugin.ts

@@ -80,7 +80,7 @@ export class AdminUiPlugin implements VendurePlugin {
     async configure(config: Required<VendureConfig>): Promise<Required<VendureConfig>> {
         const route = 'admin';
         config.middleware.push({
-            handler: createProxyHandler({ ...this.options, route }, !config.silent),
+            handler: createProxyHandler({ ...this.options, route, label: 'Admin UI' }),
             route,
         });
         const { adminApiPath } = config;

packages/asset-server-plugin/src/plugin.ts

@@ -200,7 +200,7 @@ export class AssetServerPlugin implements VendurePlugin {
         });
         config.assetOptions.assetStorageStrategy = this.assetStorage;
         config.middleware.push({
-            handler: createProxyHandler(this.options, !config.silent),
+            handler: createProxyHandler({ ...this.options, label: 'Asset Server' }),
             route: this.options.route,
         });
         return config;

packages/core/cli/populate.ts

@@ -100,7 +100,6 @@ async function getApplicationRef(): Promise<INestApplication | undefined> {
     }
 
     const config = index.config;
-    config.silent = true;
 
     // Force the sync mode on, so that all the tables are created
     // on this initial run.

packages/core/package.json

@@ -44,6 +44,7 @@
     "apollo-server-express": "^2.4.0",
     "bcrypt": "^3.0.3",
     "body-parser": "^1.18.3",
+    "chalk": "^2.4.2",
     "commander": "^2.19.0",
     "cookie-session": "^2.0.0-beta.3",
     "csv-parse": "^4.3.0",

packages/core/src/bootstrap.ts

@@ -6,8 +6,11 @@ import { EntitySubscriberInterface } from 'typeorm';
 import { InternalServerError } from './common/error/errors';
 import { ReadOnlyRequired } from './common/types/common-types';
 import { getConfig, setConfig } from './config/config-helpers';
+import { DefaultLogger } from './config/logger/default-logger';
+import { Logger, LogLevel } from './config/logger/vendure-logger';
 import { VendureConfig } from './config/vendure-config';
 import { registerCustomEntityFields } from './entity/custom-entity-fields';
+import { logProxyMiddlewares } from './plugin/plugin-utils';
 
 export type VendureBootstrapFunction = (config: VendureConfig) => Promise<INestApplication>;
 
@@ -16,24 +19,27 @@ export type VendureBootstrapFunction = (config: VendureConfig) => Promise<INestA
  */
 export async function bootstrap(userConfig: Partial<VendureConfig>): Promise<INestApplication> {
     const config = await preBootstrapConfig(userConfig);
+    Logger.info(`Bootstrapping Vendure Server...`);
 
     // The AppModule *must* be loaded only after the entities have been set in the
     // config, so that they are available when the AppModule decorator is evaluated.
     // tslint:disable-next-line:whitespace
     const appModule = await import('./app.module');
-    const app = await NestFactory.create(appModule.AppModule, {
+    DefaultLogger.hideNestBoostrapLogs();
+    let app: INestApplication;
+    app = await NestFactory.create(appModule.AppModule, {
         cors: config.cors,
-        logger: config.silent ? false : undefined,
+        logger: new Logger(),
     });
-
+    DefaultLogger.restoreOriginalLogLevel();
+    app.useLogger(new Logger());
     await runPluginOnBootstrapMethods(config, app);
     await app.listen(config.port, config.hostname);
-    if (!config.silent) {
-        // tslint:disable:no-console
-        console.log(`\n\nVendure server now running on port ${config.port}`);
-        console.log(`Shop API: http://localhost:${config.port}/${config.shopApiPath}`);
-        console.log(`Admin API: http://localhost:${config.port}/${config.adminApiPath}`);
-    }
+
+    Logger.info(`Vendure server now running on port ${config.port}`);
+    Logger.info(`Shop API: http://localhost:${config.port}/${config.shopApiPath}`);
+    Logger.info(`Admin API: http://localhost:${config.port}/${config.adminApiPath}`);
+    logProxyMiddlewares(config);
     return app;
 }
 
@@ -62,6 +68,7 @@ export async function preBootstrapConfig(
     });
 
     let config = getConfig();
+    Logger.useLogger(config.logger);
     config = await runPluginConfigurations(config);
     registerCustomEntityFields(config);
     return config;

packages/core/src/config/config.service.ts

@@ -9,6 +9,7 @@ import { ReadOnlyRequired } from '../common/types/common-types';
 
 import { getConfig } from './config-helpers';
 import { EntityIdStrategy } from './entity-id-strategy/entity-id-strategy';
+import { VendureLogger } from './logger/vendure-logger';
 import {
     AssetOptions,
     AuthOptions,
@@ -115,4 +116,8 @@ export class ConfigService implements VendureConfig {
     get plugins(): VendurePlugin[] {
         return this.activeConfig.plugins;
     }
+
+    get logger(): VendureLogger {
+        return this.activeConfig.logger;
+    }
 }

packages/core/src/config/default-config.ts

@@ -8,6 +8,7 @@ import { DefaultAssetNamingStrategy } from './asset-naming-strategy/default-asse
 import { NoAssetPreviewStrategy } from './asset-preview-strategy/no-asset-preview-strategy';
 import { NoAssetStorageStrategy } from './asset-storage-strategy/no-asset-storage-strategy';
 import { AutoIncrementIdStrategy } from './entity-id-strategy/auto-increment-id-strategy';
+import { DefaultLogger } from './logger/default-logger';
 import { MergeOrdersStrategy } from './order-merge-strategy/merge-orders-strategy';
 import { UseGuestStrategy } from './order-merge-strategy/use-guest-strategy';
 import { defaultPromotionActions } from './promotion/default-promotion-actions';
@@ -31,7 +32,7 @@ export const defaultConfig: ReadOnlyRequired<VendureConfig> = {
         origin: true,
         credentials: true,
     },
-    silent: false,
+    logger: new DefaultLogger(),
     authOptions: {
         disableAuth: false,
         tokenMethod: 'cookie',

packages/core/src/config/index.ts

@@ -8,6 +8,8 @@ export * from './config.service';
 export * from './entity-id-strategy/entity-id-strategy';
 export * from './entity-id-strategy/uuid-id-strategy';
 export * from './order-merge-strategy/order-merge-strategy';
+export * from './logger/vendure-logger';
+export * from './logger/default-logger';
 export * from './payment-method/example-payment-method-config';
 export * from './payment-method/payment-method-handler';
 export * from './promotion/default-promotion-actions';

packages/core/src/config/logger/default-logger.ts

@@ -0,0 +1,145 @@
+import chalk from 'chalk';
+
+import { Logger, LogLevel, VendureLogger } from './vendure-logger';
+
+const DEFAULT_CONTEXT = 'Vendure Server';
+
+/**
+ * @description
+ * The default logger, which logs to the console (stdout) with optional timestamps. Since this logger is part of the
+ * default Vendure configuration, you do not need to specify it explicitly in your server config. You would only need
+ * to specify it if you wish to change the log level (which defaults to `LogLevel.Info`) or remove the timestamp.
+ *
+ * @example
+ * ```ts
+ * import { DefaultLogger, LogLevel, VendureConfig } from '@vendure/core';
+ *
+ * export config: VendureConfig = {
+ *     // ...
+ *     logger: new DefaultLogger({ level: LogLevel.Debug, timestamp: false }),
+ * }
+ * ```
+ *
+ * @docsCategory Logger
+ */
+export class DefaultLogger implements VendureLogger {
+    level: LogLevel = LogLevel.Info;
+    private readonly timestamp: boolean;
+    private readonly localeStringOptions = {
+        year: '2-digit',
+        hour: 'numeric',
+        minute: 'numeric',
+        day: 'numeric',
+        month: 'numeric',
+    };
+    private static originalLogLevel: LogLevel;
+
+    constructor(options?: { level?: LogLevel; timestamp?: boolean; }) {
+        this.level = options && options.level || LogLevel.Info;
+        this.timestamp = options && options.timestamp !== undefined ? options.timestamp : true;
+    }
+
+    /**
+     * @description
+     * A work-around to hide the info-level logs generated by Nest when bootstrapping the AppModule.
+     * To be run directly before the `NestFactory.create()` call in the `bootstrap()` function.
+     *
+     * See https://github.com/nestjs/nest/issues/1838
+     */
+    static hideNestBoostrapLogs(): void {
+        const { logger } = Logger;
+        if (logger instanceof DefaultLogger) {
+            if (logger.level === LogLevel.Info) {
+                this.originalLogLevel = LogLevel.Info;
+                logger.level = LogLevel.Warn;
+            }
+        }
+    }
+
+    /**
+     * @description
+     * If the log level was changed by `hideNestBoostrapLogs()`, this method will restore the
+     * original log level. To be run directly after the `NestFactory.create()` call in the
+     * `bootstrap()` function.
+     *
+     * See https://github.com/nestjs/nest/issues/1838
+     */
+    static restoreOriginalLogLevel(): void {
+        const { logger } = Logger;
+        if (logger instanceof DefaultLogger && DefaultLogger.originalLogLevel !== undefined) {
+            logger.level = DefaultLogger.originalLogLevel;
+        }
+    }
+
+    error(message: string, context: string | undefined = DEFAULT_CONTEXT, trace?: string | undefined): void {
+        if (this.level >= LogLevel.Error) {
+            this.logMessage(
+                chalk.red(`error`),
+                chalk.red(message + trace ? ` trace: \n${trace}` : ''),
+                context,
+            );
+        }
+    }
+    warn(message: string, context: string | undefined = DEFAULT_CONTEXT): void {
+        if (this.level >= LogLevel.Warn) {
+            this.logMessage(
+                chalk.yellow(`warn`),
+                chalk.yellow(message),
+                context,
+            );
+        }
+    }
+    info(message: string, context: string | undefined = DEFAULT_CONTEXT): void {
+        if (this.level >= LogLevel.Info) {
+            this.logMessage(
+                chalk.blue(`info`),
+                message,
+                context,
+            );
+        }
+    }
+    verbose(message: string, context: string | undefined = DEFAULT_CONTEXT): void {
+        if (this.level >= LogLevel.Verbose) {
+            this.logMessage(
+                chalk.magenta(`verbose`),
+                message,
+                context,
+            );
+        }
+    }
+    debug(message: string, context: string | undefined = DEFAULT_CONTEXT): void {
+        if (this.level >= LogLevel.Debug) {
+            this.logMessage(
+                chalk.magenta(`debug`),
+                message,
+                context,
+            );
+        }
+    }
+
+    private logMessage(prefix: string, message: string, context?: string) {
+        process.stdout.write([
+            prefix,
+            this.logTimestamp(),
+            this.logContext(context),
+            message,
+            '\n',
+        ].join(' '));
+    }
+
+    private logContext(context?: string) {
+        return chalk.cyan(`[${context || DEFAULT_CONTEXT}]`);
+    }
+
+    private logTimestamp() {
+        if (this.timestamp) {
+            const timestamp = new Date(Date.now()).toLocaleString(
+                undefined,
+                this.localeStringOptions,
+            );
+            return chalk.gray(timestamp + ' -');
+        } else {
+            return '';
+        }
+    }
+}

packages/core/src/config/logger/vendure-logger.ts

@@ -0,0 +1,115 @@
+import { LoggerService } from '@nestjs/common';
+
+/**
+ * @description
+ * An enum of valid logging levels.
+ *
+ * @docsCategory Logger
+ */
+export enum LogLevel {
+    Error = 0,
+    Warn = 1,
+    Info = 2,
+    Verbose = 3,
+    Debug = 4,
+}
+
+/**
+ * @description
+ * The VendureLogger interface defines the shape of a logger service which may be provided in
+ * the config.
+ *
+ * @docsCategory Logger
+ */
+export interface VendureLogger {
+    error(message: string, context?: string, trace?: string): void;
+    warn(message: string, context?: string): void;
+    info(message: string, context?: string): void;
+    verbose(message: string, context?: string): void;
+    debug(message: string, context?: string): void;
+}
+
+const noopLogger: VendureLogger = {
+    error() { /* */ },
+    warn() { /* */ },
+    info() { /* */ },
+    verbose() { /* */ },
+    debug() { /* */ },
+};
+
+/**
+ * @description
+ * The Logger is responsible for all logging in a Vendure application.
+ *
+ * It is intended to be used as a static class:
+ *
+ * @example
+ * ```ts
+ * import { Logger } from '@vendure/core';
+ *
+ * Logger.info(`Some log message`, 'My Vendure Plugin');
+ * ```
+ *
+ * The actual implementation - where the logs are written to - is defined by the {@link VendureLogger}
+ * instance configured in the {@link VendureConfig}. By default, the {@link DefaultLogger} is used, which
+ * logs to the console.
+ *
+ * @docsCategory Logger
+ */
+export class Logger implements LoggerService {
+    private static _instance: typeof Logger = Logger;
+    private static _logger: VendureLogger;
+
+    static get logger(): VendureLogger {
+        return this._logger || noopLogger;
+    }
+
+    private get instance(): typeof Logger {
+        const { _instance } = Logger;
+        return _instance;
+    }
+
+    static useLogger(logger: VendureLogger) {
+        Logger._logger = logger;
+    }
+
+    error(message: any, trace?: string, context?: string): any {
+        this.instance.error(message, context, trace);
+    }
+
+    warn(message: any, context?: string): any {
+        this.instance.warn(message, context);
+    }
+
+    log(message: any, context?: string): any {
+        this.instance.info(message, context);
+    }
+
+    verbose(message: any, context?: string): any {
+        this.instance.verbose(message, context);
+    }
+
+    debug(message: any, context?: string): any {
+        this.instance.debug(message, context);
+    }
+
+    static error(message: string, context?: string, trace?: string) {
+        Logger.logger.error(message, context, trace);
+    }
+
+    static warn(message: string, context?: string) {
+        Logger.logger.warn(message, context);
+    }
+
+    static info(message: string, context?: string) {
+        Logger.logger.info(message, context);
+    }
+
+    static verbose(message: string, context?: string) {
+        Logger.logger.verbose(message, context);
+    }
+
+    static debug(message: string, context?: string) {
+        Logger.logger.debug(message, context);
+    }
+}

packages/core/src/config/vendure-config.ts

@@ -13,6 +13,7 @@ import { AssetNamingStrategy } from './asset-naming-strategy/asset-naming-strate
 import { AssetPreviewStrategy } from './asset-preview-strategy/asset-preview-strategy';
 import { AssetStorageStrategy } from './asset-storage-strategy/asset-storage-strategy';
 import { EntityIdStrategy } from './entity-id-strategy/entity-id-strategy';
+import { VendureLogger } from './logger/vendure-logger';
 import { OrderMergeStrategy } from './order-merge-strategy/order-merge-strategy';
 import { PaymentMethodHandler } from './payment-method/payment-method-handler';
 import { PromotionAction } from './promotion/promotion-action';
@@ -453,11 +454,11 @@ export interface VendureConfig {
     shippingOptions?: ShippingOptions;
     /**
      * @description
-     * When set to true, no application logging will be output to the console.
+     * Provide a logging service which implements the {@link VendureLogger} interface.
      *
-     * @default false
+     * @default DefaultLogger
      */
-    silent?: boolean;
+    logger: VendureLogger;
     /**
      * @description
      * Configures how taxes are calculated on products.

packages/core/src/plugin/plugin-utils.ts

@@ -1,30 +1,93 @@
 import { notNullOrUndefined } from '@vendure/common/lib/shared-utils';
 import proxy from 'http-proxy-middleware';
 
-import { APIExtensionDefinition, VendurePlugin } from '../config';
+import { APIExtensionDefinition, Logger, VendureConfig, VendurePlugin } from '../config';
 
+/**
+ * @description
+ * Options to configure the proxy middleware.
+ *
+ * @docsCategory Plugin
+ */
 export interface ProxyOptions {
+    /**
+     * @description
+     * A human-readable label for the service which is being proxied. Used to
+     * generate more informative logs.
+     */
+    label: string;
+    /**
+     * @description
+     * The route of the Vendure server which will act as the proxy url.
+     */
     route: string;
+    /**
+     * @description
+     * The port on which the service being proxied is running.
+     */
     port: number;
+    /**
+     * @description
+     * The hostname of the server on which the service being proxied is running.
+     *
+     * @default 'localhost'
+     */
     hostname?: string;
 }
 
 /**
+ * @description
  * Creates a proxy middleware which proxies the given route to the given port.
  * Useful for plugins which start their own servers but should be accessible
  * via the main Vendure url.
+ *
+ * @docsCategory Plugin
  */
-export function createProxyHandler(options: ProxyOptions, logging: boolean) {
+export function createProxyHandler(options: ProxyOptions) {
     const route = options.route.charAt(0) === '/' ? options.route : '/' + options.route;
     const proxyHostname = options.hostname || 'localhost';
-    return proxy({
+    const middleware = proxy({
         // TODO: how do we detect https?
         target: `http://${proxyHostname}:${options.port}`,
         pathRewrite: {
             [`^${route}`]: `/`,
         },
-        logLevel: logging ? 'info' : 'silent',
+        logProvider(provider: proxy.LogProvider): proxy.LogProvider {
+            return {
+                log(message: string) {
+                    Logger.debug(message, options.label);
+                },
+                debug(message: string) {
+                    Logger.debug(message, options.label);
+                },
+                info(message: string) {
+                    Logger.debug(message, options.label);
+                },
+                warn(message: string) {
+                    Logger.warn(message, options.label);
+                },
+                error(message: string) {
+                    Logger.error(message, options.label);
+                },
+            };
+        },
     });
+    // Attach the options to the middleware function to allow
+    // the info to be logged after bootstrap.
+    (middleware as any).proxyMiddleware = options;
+    return middleware;
+}
+
+/**
+ * If any proxy middleware has been set up using the createProxyHandler function, log this information.
+ */
+export function logProxyMiddlewares(config: VendureConfig) {
+    for (const middleware of config.middleware || []) {
+        if ((middleware.handler as any).proxyMiddleware) {
+            const { port, hostname, label, route } = (middleware.handler as any).proxyMiddleware as ProxyOptions;
+            Logger.info(`${label}: http://${config.hostname || 'localhost'}:${config.port}/${route}/ -> http://${hostname || 'localhost'}:${port}`);
+        }
+    }
 }
 
 /**

packages/dev-server/dev-config.ts

@@ -1,11 +1,7 @@
 import { AdminUiPlugin } from '@vendure/admin-ui-plugin';
 import { AssetServerPlugin } from '@vendure/asset-server-plugin';
 import { ADMIN_API_PATH, API_PORT, SHOP_API_PATH } from '@vendure/common/lib/shared-constants';
-import {
-    DefaultSearchPlugin,
-    examplePaymentHandler,
-    VendureConfig,
-} from '@vendure/core';
+import { DefaultLogger, DefaultSearchPlugin, examplePaymentHandler, LogLevel, VendureConfig } from '@vendure/core';
 import { defaultEmailHandlers, EmailPlugin } from '@vendure/email-plugin';
 import path from 'path';
 
@@ -46,6 +42,7 @@ export const devConfig: VendureConfig = {
         paymentMethodHandlers: [examplePaymentHandler],
     },
     customFields: {},
+    logger: new DefaultLogger({ level: LogLevel.Debug }),
     importExportOptions: {
         importAssetsDir: path.join(__dirname, 'import-assets'),
     },

packages/email-plugin/src/plugin.ts

@@ -1,4 +1,4 @@
-import { createProxyHandler, EventBus, InternalServerError, Type, VendureConfig, VendurePlugin } from '@vendure/core';
+import { createProxyHandler, EventBus, InternalServerError, Logger, Type, VendureConfig, VendurePlugin } from '@vendure/core';
 import fs from 'fs-extra';
 
 import { DevMailbox } from './dev-mailbox';
@@ -150,7 +150,7 @@ export class EmailPlugin implements VendurePlugin {
             this.devMailbox.handleMockEvent((handler, event) => this.handleEvent(handler, event));
             const route = 'mailbox';
             config.middleware.push({
-                handler: createProxyHandler({ port: this.options.mailboxPort, route }, !config.silent),
+                handler: createProxyHandler({ port: this.options.mailboxPort, route, label: 'Dev Mailbox' }),
                 route,
             });
         }
@@ -190,6 +190,7 @@ export class EmailPlugin implements VendurePlugin {
     }
 
     private async handleEvent(handler: EmailEventHandler, event: EventWithContext) {
+        Logger.debug(`Handling event "${handler.type}"`, 'EmailPlugin');
         const { type } = handler;
         const result = handler.handle(event, this.options.globalTemplateVars);
         if (!result) {

yarn.lock

@@ -8343,13 +8343,6 @@ onetime@^2.0.0:
   dependencies:
     mimic-fn "^1.0.0"
 
-opn@^5.4.0:
-  version "5.5.0"
-  resolved "https://registry.yarnpkg.com/opn/-/opn-5.5.0.tgz#fc7164fab56d235904c51c3b27da6758ca3b9bfc"
-  integrity sha512-PqHpggC9bLV0VeWcdKhkpxY+3JTzetLSqTCWL/z/tFIbI6G8JCjondXklT1JinczLz2Xib62sSp0T/gKT4KksA==
-  dependencies:
-    is-wsl "^1.1.0"
-
 optimist@^0.6.1:
   version "0.6.1"
   resolved "https://registry.yarnpkg.com/optimist/-/optimist-0.6.1.tgz#da3ea74686fa21a19a111c326e90eb15a0196686"