fix: clean up example-log-extension

This PR is a follow-up to the following issue based on review comments: #939 - Demonstrate how to plug in a different log (console vs memory) - Switch to @loopback/metadata for decorator implementation - Remove log level provider as it's supposed to be contributed by the app The exercise also exposes a few needs: 1. Support for optional dependency so that we can fall back a default implementation (or a better way) 2. Allow a component to bind artifacts beyond providers
loopbackio · Feb 1, 2018 · b89dd96 · b89dd96
1 parent 25b8ee1
commit b89dd96
Show file tree

Hide file tree

Showing 13 changed files with 219 additions and 158 deletions.
diff --git a/packages/example-log-extension/README.md b/packages/example-log-extension/README.md
@@ -8,7 +8,7 @@ This repository shows you how to use [@loopback/cli](https://github.com/stronglo
 to write a complex logging extension that requires a [Component](http://loopback.io/doc/en/lb4/Using-components.html),
 [Decorator](http://loopback.io/doc/en/lb4/Decorators.html), and a [Mixin](http://loopback.io/doc/en/lb4/Mixin.html).
 
-To use the extension, load the component to get access to a `LogFn` that can be
+To use the extension, load the component to get access to a `LogAction` that can be
 used in a sequence to log information. A Mixin allows you to set the
 application wide logLevel. Only Controller methods configured at or above the
 logLevel will be logged.
@@ -86,13 +86,20 @@ Define `Binding` keys here for the component as well as any constants for the
 user (for this extension that'll be the logLevel `enum`).
 
 ```ts
+/**
+ * Binding keys used by this component.
+ */
 export namespace EXAMPLE_LOG_BINDINGS {
   export const METADATA = 'example.log.metadata';
   export const APP_LOG_LEVEL = 'example.log.level';
   export const TIMER = 'example.log.timer';
+  export const LOGGER = 'example.log.logger';
   export const LOG_ACTION = 'example.log.action';
 }
 
+/**
+ * Enum to define the supported log levels
+ */
 export enum LOG_LEVEL {
   DEBUG,
   INFO,
@@ -108,7 +115,7 @@ Define TypeScript type definitions / interfaces for complex types and functions
 ```ts
 import {ParsedRequest, OperationArgs} from '@loopback/rest';
 
-export interface LogFn {
+export interface LogAction {
   (
     req: ParsedRequest,
     args: OperationArgs,
@@ -125,39 +132,56 @@ export type TimerFn = (start?: HighResTime) => HighResTime;
 ```
 
 ### `src/decorators/log.decorator.ts`
-Extension users can use decorators to provide "hints" (or metadata) for our
-component. These "hints" allow the extension to modify behaviour accordingly.
+Extension developers can create decorators to provide "hints" (or metadata) to
+user artifacts such as controllers and their methods. These "hints" allow the
+extension to add extra processing accordingly.
 
 For this extension, the decorator marks which controller methods should be
-logged (and optionally at which level they should be logged).
-`Reflector` from `@loopback/context` is used to store and retrieve the metadata
-by the extension.
+logged (and optionally at which level they should be logged). We leverage
+`@loopback/metadata` module to implement the decorator and inspection function.
 
 ```ts
 import {LOG_LEVEL, EXAMPLE_LOG_BINDINGS} from '../keys';
-import {Constructor, Reflector} from '@loopback/context';
+import {
+  Constructor,
+  MethodDecoratorFactory,
+  MetadataInspector,
+} from '@loopback/context';
 import {LevelMetadata} from '../types';
 
+/**
+ * Mark a controller method as requiring logging (input, output & timing)
+ * if it is set at or greater than Application LogLevel.
+ * LOG_LEVEL.DEBUG < LOG_LEVEL.INFO < LOG_LEVEL.WARN < LOG_LEVEL.ERROR < LOG_LEVEL.OFF
+ *
+ * @param level The Log Level at or above it should log
+ */
 export function log(level?: number) {
-  return function(target: Object, methodName: string): void {
-    if (level === undefined) level = LOG_LEVEL.WARN;
-    Reflector.defineMetadata(
-      EXAMPLE_LOG_BINDINGS.METADATA,
-      {level},
-      target,
-      methodName,
-    );
-  };
+  if (level === undefined) level = LOG_LEVEL.WARN;
+  return MethodDecoratorFactory.createDecorator<LevelMetadata>(
+    EXAMPLE_LOG_BINDINGS.METADATA,
+    {
+      level,
+    },
+  );
 }
 
+/**
+ * Fetch log level stored by `@log` decorator.
+ *
+ * @param controllerClass Target controller
+ * @param methodName Target method
+ */
 export function getLogMetadata(
   controllerClass: Constructor<{}>,
   methodName: string,
 ): LevelMetadata {
-  return Reflector.getMetadata(
-    EXAMPLE_LOG_BINDINGS.METADATA,
-    controllerClass.prototype,
-    methodName,
+  return (
+    MetadataInspector.getMethodMetadata<LevelMetadata>(
+      EXAMPLE_LOG_BINDINGS.METADATA,
+      controllerClass.prototype,
+      methodName,
+    ) || {level: LOG_LEVEL.OFF}
   );
 }
 ```
@@ -214,23 +238,6 @@ export class TimerProvider implements Provider<TimerFn> {
 }
 ```
 
-### `src/providers/log-level.provider.ts`
-A provider can set the default binding value for `example.log.level` so it's
-easier to get started with the extension. User's can override the value by
-binding a new value or using the mixin.
-
-```ts
-import {Provider} from '@loopback/context';
-import {LOG_LEVEL} from '../keys';
-
-export class LogLevelProvider implements Provider<number> {
-  constructor() {}
-  value(): number {
-    return LOG_LEVEL.WARN;
-  }
-}
-```
-
 ### `src/providers/log-action.provider.ts`
 This will be the most important provider for the extension as it is responsible
 for actually logging the request. The extension will retrieve the metadata
@@ -245,24 +252,27 @@ import {CoreBindings} from '@loopback/core';
 import {OperationArgs, ParsedRequest} from '@loopback/rest';
 import {getLogMetadata} from '../decorators/log.decorator';
 import {EXAMPLE_LOG_BINDINGS, LOG_LEVEL} from '../keys';
-import {LogFn, TimerFn, HighResTime, LevelMetadata} from '../types';
+import {LogAction, TimerFn, HighResTime, LevelMetadata, LogFn} from '../types';
 import chalk from 'chalk';
 
-export class LogActionProvider implements Provider<LogFn> {
+export class LogActionProvider implements Provider<LogAction> {
   constructor(
     @inject.getter(CoreBindings.CONTROLLER_CLASS)
     private readonly getController: Getter<Constructor<{}>>,
     @inject.getter(CoreBindings.CONTROLLER_METHOD_NAME)
     private readonly getMethod: Getter<string>,
     @inject(EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL)
     private readonly logLevel: number,
+    // Use a getter to defer to resolution of Logger
+    @inject.getter(EXAMPLE_LOG_BINDINGS.LOGGER) public getLogger: Getter<LogFn>,
     @inject(EXAMPLE_LOG_BINDINGS.TIMER) public timer: TimerFn,
   ) {}
 
-  value(): LogFn {
-    const fn = <LogFn>((
+  value(): LogAction {
+    const fn = <LogAction>((
       req: ParsedRequest,
       args: OperationArgs,
+      // tslint:disable-next-line:no-any
       result: any,
       start?: HighResTime,
     ) => {
@@ -279,11 +289,13 @@ export class LogActionProvider implements Provider<LogFn> {
   private async action(
     req: ParsedRequest,
     args: OperationArgs,
+    // tslint:disable-next-line:no-any
     result: any,
     start?: HighResTime,
   ): Promise<void> {
     const controllerClass = await this.getController();
     const methodName: string = await this.getMethod();
+
     const metadata: LevelMetadata = getLogMetadata(controllerClass, methodName);
     const level: number | undefined = metadata ? metadata.level : undefined;
 
@@ -294,36 +306,51 @@ export class LogActionProvider implements Provider<LogFn> {
       level !== LOG_LEVEL.OFF
     ) {
       if (!args) args = [];
-      let log = `${req.url} :: ${controllerClass.name}.`;
-      log += `${methodName}(${args.join(', ')}) => `;
+      let msg = `${req.url} :: ${controllerClass.name}.`;
+      msg += `${methodName}(${args.join(', ')}) => `;
 
-      if (typeof result === 'object') log += JSON.stringify(result);
-      else log += result;
+      if (typeof result === 'object') msg += JSON.stringify(result);
+      else msg += result;
 
       if (start) {
         const timeDiff: HighResTime = this.timer(start);
         const time: number =
           timeDiff[0] * 1000 + Math.round(timeDiff[1] * 1e-4) / 100;
-        log = `${time}ms: ${log}`;
+        msg = `${time}ms: ${msg}`;
       }
 
-      switch (level) {
-        case LOG_LEVEL.DEBUG:
-          console.log(chalk.white(`DEBUG: ${log}`));
-          break;
-        case LOG_LEVEL.INFO:
-          console.log(chalk.green(`INFO: ${log}`));
-          break;
-        case LOG_LEVEL.WARN:
-          console.log(chalk.yellow(`WARN: ${log}`));
-          break;
-        case LOG_LEVEL.ERROR:
-          console.log(chalk.red(`ERROR: ${log}`));
-          break;
+      let logger: LogFn;
+      try {
+        // Try to see if an external logger is bound
+        // This is a workaround before optional injection is supported
+        logger = await this.getLogger();
+      } catch (e) {
+        // Fall back to logToConsole
+        logger = logToConsole;
       }
+      logger(msg, level);
     }
   }
 }
+
+function logToConsole(msg: string, level: number) {
+  let output;
+  switch (level) {
+    case LOG_LEVEL.DEBUG:
+      output = chalk.white(`DEBUG: ${msg}`);
+      break;
+    case LOG_LEVEL.INFO:
+      output = chalk.green(`INFO: ${msg}`);
+      break;
+    case LOG_LEVEL.WARN:
+      output = chalk.yellow(`WARN: ${msg}`);
+      break;
+    case LOG_LEVEL.ERROR:
+      output = chalk.red(`ERROR: ${msg}`);
+      break;
+  }
+  if (output) console.log(output);
+}
 ```
 
 ### `src/index.ts`
@@ -333,7 +360,6 @@ Export all the files to ensure a user can import the necessary components.
 export * from './decorators/log.decorator';
 export * from './mixins/log-level.mixin';
 export * from './providers/log-action.provider';
-export * from './providers/log-level.provider';
 export * from './providers/timer.provider';
 export * from './component';
 export * from './types';
@@ -347,13 +373,12 @@ they are automatically bound when a user adds the component to their application
 ```ts
 import {EXAMPLE_LOG_BINDINGS} from './keys';
 import {Component, ProviderMap} from '@loopback/core';
-import {TimerProvider, LogActionProvider, LogLevelProvider} from './';
+import {TimerProvider, LogActionProvider} from './';
 
 export class LogComponent implements Component {
   providers?: ProviderMap = {
     [EXAMPLE_LOG_BINDINGS.TIMER]: TimerProvider,
     [EXAMPLE_LOG_BINDINGS.LOG_ACTION]: LogActionProvider,
-    [EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL]: LogLevelProvider,
   };
 }
 ```

diff --git a/packages/example-log-extension/src/component.ts b/packages/example-log-extension/src/component.ts
@@ -5,12 +5,11 @@
 
 import {EXAMPLE_LOG_BINDINGS} from './keys';
 import {Component, ProviderMap} from '@loopback/core';
-import {TimerProvider, LogActionProvider, LogLevelProvider} from './';
+import {TimerProvider, LogActionProvider} from './';
 
 export class LogComponent implements Component {
   providers?: ProviderMap = {
     [EXAMPLE_LOG_BINDINGS.TIMER]: TimerProvider,
     [EXAMPLE_LOG_BINDINGS.LOG_ACTION]: LogActionProvider,
-    [EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL]: LogLevelProvider,
   };
 }
diff --git a/packages/example-log-extension/src/decorators/log.decorator.ts b/packages/example-log-extension/src/decorators/log.decorator.ts
@@ -4,7 +4,11 @@
 // License text available at https://opensource.org/licenses/MIT
 
 import {LOG_LEVEL, EXAMPLE_LOG_BINDINGS} from '../keys';
-import {Constructor, Reflector} from '@loopback/context';
+import {
+  Constructor,
+  MethodDecoratorFactory,
+  MetadataInspector,
+} from '@loopback/context';
 import {LevelMetadata} from '../types';
 
 /**
@@ -15,15 +19,13 @@ import {LevelMetadata} from '../types';
  * @param level The Log Level at or above it should log
  */
 export function log(level?: number) {
-  return function(target: Object, methodName: string): void {
-    if (level === undefined) level = LOG_LEVEL.WARN;
-    Reflector.defineMetadata(
-      EXAMPLE_LOG_BINDINGS.METADATA,
-      {level},
-      target,
-      methodName,
-    );
-  };
+  if (level === undefined) level = LOG_LEVEL.WARN;
+  return MethodDecoratorFactory.createDecorator<LevelMetadata>(
+    EXAMPLE_LOG_BINDINGS.METADATA,
+    {
+      level,
+    },
+  );
 }
 
 /**
@@ -36,9 +38,11 @@ export function getLogMetadata(
   controllerClass: Constructor<{}>,
   methodName: string,
 ): LevelMetadata {
-  return Reflector.getMetadata(
-    EXAMPLE_LOG_BINDINGS.METADATA,
-    controllerClass.prototype,
-    methodName,
+  return (
+    MetadataInspector.getMethodMetadata<LevelMetadata>(
+      EXAMPLE_LOG_BINDINGS.METADATA,
+      controllerClass.prototype,
+      methodName,
+    ) || {level: LOG_LEVEL.OFF}
   );
 }
diff --git a/packages/example-log-extension/src/index.ts b/packages/example-log-extension/src/index.ts
@@ -6,7 +6,6 @@
 export * from './decorators/log.decorator';
 export * from './mixins/log-level.mixin';
 export * from './providers/log-action.provider';
-export * from './providers/log-level.provider';
 export * from './providers/timer.provider';
 export * from './component';
 export * from './types';

diff --git a/packages/example-log-extension/src/keys.ts b/packages/example-log-extension/src/keys.ts
@@ -10,6 +10,7 @@ export namespace EXAMPLE_LOG_BINDINGS {
   export const METADATA = 'example.log.metadata';
   export const APP_LOG_LEVEL = 'example.log.level';
   export const TIMER = 'example.log.timer';
+  export const LOGGER = 'example.log.logger';
   export const LOG_ACTION = 'example.log.action';
 }