diff --git a/packages/example-log-extension/README.md b/packages/example-log-extension/README.md index 80422623e6ea..4381ebe9ac09 100644 --- a/packages/example-log-extension/README.md +++ b/packages/example-log-extension/README.md @@ -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,10 +115,14 @@ Define TypeScript type definitions / interfaces for complex types and functions ```ts import {ParsedRequest, OperationArgs} from '@loopback/rest'; +/** + * A function to perform REST req/res logging action + */ export interface LogFn { ( req: ParsedRequest, args: OperationArgs, + // tslint:disable-next-line:no-any result: any, startTime?: HighResTime, ): Promise; @@ -119,45 +130,78 @@ export interface LogFn { startTimer(): HighResTime; } +/** + * Log level metadata + */ export type LevelMetadata = {level: number}; + +/** + * High resolution time as [seconds, nanoseconds]. Used by process.hrtime(). + */ export type HighResTime = [number, number]; // [seconds, nanoseconds] + +/** + * Log writing function + */ +export type LogWriterFn = (msg: string, level: number) => void; + +/** + * Timer function for logging + */ 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( + 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( + EXAMPLE_LOG_BINDINGS.METADATA, + controllerClass.prototype, + methodName, + ) || {level: LOG_LEVEL.OFF} ); } ``` @@ -214,23 +258,6 @@ export class TimerProvider implements Provider { } ``` -### `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 { - 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,17 +272,28 @@ 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 { + // LogWriteFn is an optional dependency and it falls back to `logToConsole` + @inject(EXAMPLE_LOG_BINDINGS.LOGGER, {optional: true}) + private logWriter: LogWriterFn = logToConsole; + + @inject(EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL, {optional: true}) + private logLevel: number = LOG_LEVEL.WARN; + constructor( @inject.getter(CoreBindings.CONTROLLER_CLASS) private readonly getController: Getter>, @inject.getter(CoreBindings.CONTROLLER_METHOD_NAME) private readonly getMethod: Getter, - @inject(EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL) - private readonly logLevel: number, @inject(EXAMPLE_LOG_BINDINGS.TIMER) public timer: TimerFn, ) {} @@ -263,6 +301,7 @@ export class LogActionProvider implements Provider { const fn = (( req: ParsedRequest, args: OperationArgs, + // tslint:disable-next-line:no-any result: any, start?: HighResTime, ) => { @@ -279,11 +318,13 @@ export class LogActionProvider implements Provider { private async action( req: ParsedRequest, args: OperationArgs, + // tslint:disable-next-line:no-any result: any, start?: HighResTime, ): Promise { 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 +335,42 @@ export class LogActionProvider implements Provider { 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; - } + this.logWriter(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 +380,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 +393,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 index 0000f8fd22d0..146f5a75ab86 100644 --- 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 index 4e86d63a1250..3bdab2b034f8 100644 --- 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( + 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( + 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 index d57d2af4bf4d..7fd3d3b8e4c0 100644 --- 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 index b5b12d5ce9a1..48b6ebc3f62e 100644 --- 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'; } diff --git a/packages/example-log-extension/src/providers/log-action.provider.ts b/packages/example-log-extension/src/providers/log-action.provider.ts index 00a37e5059a5..712d047e9172 100644 --- a/packages/example-log-extension/src/providers/log-action.provider.ts +++ b/packages/example-log-extension/src/providers/log-action.provider.ts @@ -8,19 +8,28 @@ 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'; -import * as debugModule from 'debug'; -const debug = debugModule('loopback:example:extension:log'); export class LogActionProvider implements Provider { + // LogWriteFn is an optional dependency and it falls back to `logToConsole` + @inject(EXAMPLE_LOG_BINDINGS.LOGGER, {optional: true}) + writeLog: LogWriterFn = logToConsole; + + @inject(EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL, {optional: true}) + logLevel: number = LOG_LEVEL.WARN; + constructor( @inject.getter(CoreBindings.CONTROLLER_CLASS) private readonly getController: Getter>, @inject.getter(CoreBindings.CONTROLLER_METHOD_NAME) private readonly getMethod: Getter, - @inject(EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL) - private readonly logLevel: number, @inject(EXAMPLE_LOG_BINDINGS.TIMER) public timer: TimerFn, ) {} @@ -75,24 +84,26 @@ export class LogActionProvider implements Provider { msg = `${time}ms: ${msg}`; } - switch (level) { - case LOG_LEVEL.DEBUG: - this.log(chalk.white(`DEBUG: ${msg}`)); - break; - case LOG_LEVEL.INFO: - this.log(chalk.green(`INFO: ${msg}`)); - break; - case LOG_LEVEL.WARN: - this.log(chalk.yellow(`WARN: ${msg}`)); - break; - case LOG_LEVEL.ERROR: - this.log(chalk.red(`ERROR: ${msg}`)); - break; - } + this.writeLog(msg, level); } } +} - log(msg: string) { - debug(msg); +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); } diff --git a/packages/example-log-extension/src/providers/log-level.provider.ts b/packages/example-log-extension/src/providers/log-level.provider.ts deleted file mode 100644 index 619ad96b0dfd..000000000000 --- a/packages/example-log-extension/src/providers/log-level.provider.ts +++ /dev/null @@ -1,17 +0,0 @@ -// Copyright IBM Corp. 2018. All Rights Reserved. -// Node module: @loopback/example-log-extension -// This file is licensed under the MIT License. -// License text available at https://opensource.org/licenses/MIT - -import {Provider} from '@loopback/context'; -import {LOG_LEVEL} from '../keys'; - -export class LogLevelProvider implements Provider { - constructor() {} - - value(): number { - const level = Number(process.env.LOG_LEVEL); - if (!isNaN(level) && typeof level === 'number') return level; - return LOG_LEVEL.WARN; - } -} diff --git a/packages/example-log-extension/src/types.ts b/packages/example-log-extension/src/types.ts index edec0daeab9d..8e060d95e391 100644 --- a/packages/example-log-extension/src/types.ts +++ b/packages/example-log-extension/src/types.ts @@ -7,6 +7,9 @@ import {ParsedRequest, OperationArgs} from '@loopback/rest'; +/** + * A function to perform REST req/res logging action + */ export interface LogFn { ( req: ParsedRequest, @@ -19,8 +22,22 @@ export interface LogFn { startTimer(): HighResTime; } +/** + * Log level metadata + */ export type LevelMetadata = {level: number}; +/** + * High resolution time as [seconds, nanoseconds]. Used by process.hrtime(). + */ export type HighResTime = [number, number]; // [seconds, nanoseconds] +/** + * Log writing function + */ +export type LogWriterFn = (msg: string, level: number) => void; + +/** + * Timer function for logging + */ export type TimerFn = (start?: HighResTime) => HighResTime; diff --git a/packages/example-log-extension/test/acceptance/log.extension.acceptance.ts b/packages/example-log-extension/test/acceptance/log.extension.acceptance.ts index f243d8c892d6..5382fba8990e 100644 --- a/packages/example-log-extension/test/acceptance/log.extension.acceptance.ts +++ b/packages/example-log-extension/test/acceptance/log.extension.acceptance.ts @@ -20,7 +20,6 @@ import { } from '@loopback/rest'; import { LogComponent, - LogActionProvider, LogLevelMixin, LOG_LEVEL, log, @@ -40,6 +39,9 @@ import chalk from 'chalk'; const SequenceActions = RestBindings.SequenceActions; +import {createLogSpy, restoreLogSpy} from '../log-spy'; +import {logToMemory, resetLogs} from '../in-memory-logger'; + describe('log extension acceptance test', () => { let app: LogApp; let server: RestServer; @@ -66,9 +68,10 @@ describe('log extension acceptance test', () => { beforeEach(createApp); beforeEach(createController); beforeEach(createSequence); - beforeEach(createLogSpy); - afterEach(restoreLogSpy); + beforeEach(resetLogs); + beforeEach(() => (spy = createLogSpy())); + afterEach(() => restoreLogSpy(spy)); it('logs information at DEBUG or higher', async () => { setAppLogToDebug(); @@ -241,6 +244,7 @@ describe('log extension acceptance test', () => { app.component(LogComponent); app.bind(EXAMPLE_LOG_BINDINGS.TIMER).to(timer); + app.bind(EXAMPLE_LOG_BINDINGS.LOGGER).to(logToMemory); server = await app.getServer(RestServer); } @@ -315,12 +319,4 @@ describe('log extension acceptance test', () => { if (!startTime) return [3, 3]; return [2, 2]; } - - function createLogSpy() { - spy = sinon.spy(LogActionProvider.prototype, 'log'); - } - - function restoreLogSpy() { - spy.restore(); - } }); diff --git a/packages/example-log-extension/test/in-memory-logger.ts b/packages/example-log-extension/test/in-memory-logger.ts new file mode 100644 index 000000000000..a5b3f282b223 --- /dev/null +++ b/packages/example-log-extension/test/in-memory-logger.ts @@ -0,0 +1,44 @@ +// Copyright IBM Corp. 2018. All Rights Reserved. +// Node module: @loopback/example-log-extension +// This file is licensed under the MIT License. +// License text available at https://opensource.org/licenses/MIT + +import {LOG_LEVEL} from '../'; +import chalk from 'chalk'; + +export class InMemoryLog { + private entries: string[] = []; + + add(msg?: string) { + if (msg) this.entries.push(msg); + } + + reset() { + this.entries = []; + } +} + +export const inMemLog = new InMemoryLog(); + +export function logToMemory(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; + } + inMemLog.add(output); +} + +export function resetLogs() { + inMemLog.reset(); +} diff --git a/packages/example-log-extension/test/log-spy.ts b/packages/example-log-extension/test/log-spy.ts new file mode 100644 index 000000000000..4612813b3e10 --- /dev/null +++ b/packages/example-log-extension/test/log-spy.ts @@ -0,0 +1,19 @@ +// Copyright IBM Corp. 2018. All Rights Reserved. +// Node module: @loopback/example-log-extension +// This file is licensed under the MIT License. +// License text available at https://opensource.org/licenses/MIT + +import {sinon} from '@loopback/testlab'; +import {InMemoryLog} from './in-memory-logger'; + +export function createLogSpy() { + return sinon.spy(InMemoryLog.prototype, 'add'); +} + +export function restoreLogSpy(spy: sinon.SinonSpy) { + spy.restore(); +} + +export function createConsoleStub() { + return sinon.stub(console, 'log'); +} diff --git a/packages/example-log-extension/test/unit/providers/log-action.provider.unit.ts b/packages/example-log-extension/test/unit/providers/log-action.provider.unit.ts index ced97445bb5b..ac913bd195e9 100644 --- a/packages/example-log-extension/test/unit/providers/log-action.provider.unit.ts +++ b/packages/example-log-extension/test/unit/providers/log-action.provider.unit.ts @@ -5,27 +5,28 @@ import {sinon} from '@loopback/testlab'; import {ParsedRequest} from '@loopback/rest'; -import {Context} from '@loopback/context'; import { LogActionProvider, LogFn, + LogWriterFn, log, - EXAMPLE_LOG_BINDINGS, LOG_LEVEL, HighResTime, } from '../../..'; -import {CoreBindings} from '@loopback/core'; import chalk from 'chalk'; -describe('LogActionProvider (unit)', () => { +import {createLogSpy, restoreLogSpy, createConsoleStub} from '../../log-spy'; +import {logToMemory} from '../../in-memory-logger'; + +describe('LogActionProvider with in-memory logger', () => { let spy: sinon.SinonSpy; let logger: LogFn; const req = {url: '/test'}; - beforeEach(createLogSpy); - beforeEach(getLogger); + beforeEach(() => (spy = createLogSpy())); + beforeEach(async () => (logger = await getLogger(logToMemory))); - afterEach(restoreLogSpy); + afterEach(() => restoreLogSpy(spy)); it('logs a value without a start time', async () => { const match = chalk.red('ERROR: /test :: TestClass.test() => test message'); @@ -52,32 +53,63 @@ describe('LogActionProvider (unit)', () => { await logger(req, ['test', 'message'], 'test message'); sinon.assert.calledWith(spy, match); }); +}); - async function getLogger() { - class TestClass { - @log(LOG_LEVEL.ERROR) - test() {} - } - - const context: Context = new Context(); - context.bind(CoreBindings.CONTROLLER_CLASS).to(TestClass); - context.bind(CoreBindings.CONTROLLER_METHOD_NAME).to('test'); - context.bind(EXAMPLE_LOG_BINDINGS.APP_LOG_LEVEL).to(LOG_LEVEL.WARN); - context.bind(EXAMPLE_LOG_BINDINGS.TIMER).to(timer); - context.bind(EXAMPLE_LOG_BINDINGS.LOG_ACTION).toProvider(LogActionProvider); - logger = await context.get(EXAMPLE_LOG_BINDINGS.LOG_ACTION); - } +describe('LogActionProvider with default logger', () => { + let stub: sinon.SinonSpy; + let logger: LogFn; + const req = {url: '/test'}; - function createLogSpy() { - spy = sinon.spy(LogActionProvider.prototype, 'log'); - } + beforeEach(() => (stub = createConsoleStub())); + beforeEach(async () => (logger = await getLogger())); - function restoreLogSpy() { - spy.restore(); - } + afterEach(() => restoreLogSpy(stub)); - function timer(startTime?: HighResTime): HighResTime { - if (!startTime) return [3, 3]; - else return [0, 100000002]; - } + it('logs a value without a start time', async () => { + const match = chalk.red('ERROR: /test :: TestClass.test() => test message'); + + await logger(req, [], 'test message'); + sinon.assert.calledWith(stub, match); + }); + + it('logs a value with a start time', async () => { + const match = chalk.red( + 'ERROR: 100ms: /test :: TestClass.test() => test message', + ); + const startTime: HighResTime = logger.startTimer(); + + await logger(req, [], 'test message', startTime); + sinon.assert.calledWith(stub, match); + }); + + it('logs a value with args present', async () => { + const match = chalk.red( + 'ERROR: /test :: TestClass.test(test, message) => test message', + ); + + await logger(req, ['test', 'message'], 'test message'); + sinon.assert.calledWith(stub, match); + }); }); + +async function getLogger(logWriter?: LogWriterFn) { + class TestClass { + @log(LOG_LEVEL.ERROR) + test() {} + } + + const provider = new LogActionProvider( + () => Promise.resolve(TestClass), + () => Promise.resolve('test'), + timer, + ); + + if (logWriter) provider.writeLog = logWriter; + + return provider.value(); +} + +function timer(startTime?: HighResTime): HighResTime { + if (!startTime) return [3, 3]; + else return [0, 100000002]; +} diff --git a/packages/example-log-extension/test/unit/providers/log-level.provider.unit.ts b/packages/example-log-extension/test/unit/providers/log-level.provider.unit.ts deleted file mode 100644 index 259d7f010469..000000000000 --- a/packages/example-log-extension/test/unit/providers/log-level.provider.unit.ts +++ /dev/null @@ -1,14 +0,0 @@ -// Copyright IBM Corp. 2018. All Rights Reserved. -// Node module: @loopback/example-log-extension -// This file is licensed under the MIT License. -// License text available at https://opensource.org/licenses/MIT - -import {expect} from '@loopback/testlab'; -import {LogLevelProvider, LOG_LEVEL} from '../../..'; - -describe('LogLevelProvider (unit)', () => { - it('returns LOG_LEVEL.WARN as default level', () => { - const level = new LogLevelProvider().value(); - expect(level).to.be.eql(LOG_LEVEL.WARN); - }); -});