Skip to content

Commit

Permalink
fix: clean up example-log-extension
Browse files Browse the repository at this point in the history 
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
  • Loading branch information
@raymondfeng
raymondfeng committed Feb 6, 2018
1 parent e9ceba9 commit 8a54686
Show file tree
Hide file tree
Showing 13 changed files with 284 additions and 165 deletions.
141 changes: 83 additions & 58 deletions packages/example-log-extension/README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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}
);
}
```
Expand Down Expand Up @@ -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
Expand All @@ -245,7 +252,7 @@ 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 {LogFn, TimerFn, HighResTime, LevelMetadata, LogWriterFn} from '../types';
import chalk from 'chalk';

export class LogActionProvider implements Provider<LogFn> {
Expand All @@ -256,13 +263,16 @@ export class LogActionProvider implements Provider<LogFn> {
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<LogWriterFn>,
@inject(EXAMPLE_LOG_BINDINGS.TIMER) public timer: TimerFn,
) {}

value(): LogFn {
const fn = <LogFn>((
req: ParsedRequest,
args: OperationArgs,
// tslint:disable-next-line:no-any
result: any,
start?: HighResTime,
) => {
Expand All @@ -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;

Expand All @@ -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: LogWriterFn;
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`
Expand All @@ -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';
Expand All @@ -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,
};
}
```
Expand Down
3 changes: 1 addition & 2 deletions packages/example-log-extension/src/component.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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,
};
}
32 changes: 18 additions & 14 deletions packages/example-log-extension/src/decorators/log.decorator.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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';

/**
Expand All @@ -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,
},
);
}

/**
Expand All @@ -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}
);
}
1 change: 0 additions & 1 deletion packages/example-log-extension/src/index.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand Down
1 change: 1 addition & 0 deletions packages/example-log-extension/src/keys.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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';
}

Expand Down
Loading

0 comments on commit 8a54686

Please sign in to comment.