Implement custom logging in Loopback 4

Question

Can Winston, Pino or Bunyan be used for logging in Loopback4? If so, what would be the basic steps to implement them in Loopback4?

I was able to make Winston work using Express while viewing this tutorial: https://www.digitalocean.com/community/tutorials/how-to-use-winston-to-log-node-js-applications

There are Loopback modules for Winston and Brunyan. However, I get the impression (since last updates are greater than 10 months old) they must be for older versions of Loopback (since v4 came out in Oct 18')?

Winston - https://www.npmjs.com/package/loopback-component-winston

Brunyan - https://www.npmjs.com/package/loopback-component-bunyan

Answer 1

It bothered me a bit that, if one of my routes threw an exception, the output could only be logged to stderr. So I did the following to fix this and use Winston for logging instead, while still being fully agnostic to the underlying logging system that is actually used.

Assume that in one of my controllers I have the following REST endpoint:

@post('/myendpoint')
async handleEndpoint(): Promise<void> {
  throw new Error('I am an error!');
}

To now add the custom logger, I created a new service for it and bound the Winston variant of it to my application.

src/services/logger.service.ts (the abstract logger service and a concrete implementation of it that uses Winston)

import winston from 'winston';

export interface LoggerService {
  logger: object;
}

export class WinstonLoggerService implements LoggerService {
  logger: winston.Logger = winston.createLogger({
    level: 'info',
    format: winston.format.combine(
      winston.format.timestamp(),
      winston.format.json(),
    ),
    transports: [
      new winston.transports.Console({
        format: winston.format.combine(
          winston.format.colorize(),
          winston.format.printf(info => {
            return `[${info.timestamp}]  ${info.level}: ${info.message}`;
          }),
        ),
      }),
    ],
  });
}

src/keys.ts

export namespace LoggerBindings {
  export const LOGGER = BindingKey.create<LoggerService>('services.logger');
}

src/providers/log-error.provider.ts (a Loopback 4 provider class where the logger class bound by the application is injected into and which can then use it)

import {Provider} from '@loopback/context';
import {LogError, Request} from '@loopback/rest';
import {inject} from '@loopback/core';
import {LoggerBindings} from '../keys';
import {LoggerService} from '../services/logger.service';

export class LogErrorProvider implements Provider<LogError> {
  constructor(@inject(LoggerBindings.LOGGER) protected logger: LoggerService) {}

  value(): LogError {
    return (err, statusCode, req) => this.action(err, statusCode, req);
  }

  action(err: Error, statusCode: number, req: Request) {
    if (statusCode < 500) {
      return;
    }

    this.logger.logger.error(
      `HTTP ${statusCode} on ${req.method} ${req.url}: ${err.stack ?? err}`,
    );
  }
}

src/application.ts (bind statements go into the constructor)

import {WinstonLoggerService} from './services/logger.service';
import {LogErrorProvider} from './providers/log-error.provider';

this.bind(LoggerBindings.LOGGER).toClass(WinstonLoggerService);
this.bind(RestBindings.SequenceActions.LOG_ERROR).toProvider(LogErrorProvider);

The last line in the previous code block is the key here, because it makes sure to bind our custom provider for LOG_ERROR. Internally, Loopback 4 uses the RejectProvider defined in @loopback/rest/src/providers/reject.provider.ts to handle errors thrown in REST endpoints. Into this provider, RestBindings.SequenceActions.LOG_ERROR is injected, which is taken from @loopback/rest/src/providers/log-error.provider.ts by default and which we redefine here. This way, we don't need to rewrite the entire reject provider but just the tiny part of it that handles logging REST errors.

When the example route is now invoked, the following is shown on the console:

[2020-01-05T23:41:28.604Z]  error: HTTP 500 on POST /myendpoint: Error: I am an error!
    at [...long stacktrace...]

Answer 2

It's possible to implement custom logging in Loopback 4 and doing so should not be much different than Express. I have experimented with winston and hence, would detail out the same but this should be achievable using bunyan as well.

To begin with, you can create a utils folder at the root of your project to keep your custom logger. An app scaffolded using LB4 CLI takes a typical structure and with utils folder, it would look like the following:

.
|
|-- public
|-- src  
|-- utils
|   |-- logger
|       |-- index.js  <-- custom logger can be defined here.
|-- node_modules
|-- index.js
|--
.

I am using the example as outlined in the winston's github repo for defining the logger:

// utils/logger/index.js

const winston = require('winston');

const logger = winston.createLogger({
    level: 'info',
    format: winston.format.json(),
    defaultMeta: { service: 'user-service' },
    transports: [
        //
        // - Write to all logs with level `info` and below to `combined.log` 
        // - Write all logs error (and below) to `error.log`.
        //
        new winston.transports.File({ filename: 'error.log', level: 'error' }),
        new winston.transports.File({ filename: 'combined.log' })
    ]
});

module.exports = logger;

You can now start using the logger by 'importing' it across your application. For index.js in the root folder, the import would look like:

// index.js

const logger = require('./utils/logger');

For the logger defined earlier, the following statement will log I am logged. to a file called combined.log:

logger.info('I am logged.');

This should get you started.

P.S. I am sure the answer(and the approach) can be improved and hence, very much open to any helpful suggestions.