Skip to content

Home

Jump to bottom
Fabricio Campos edited this page Feb 16, 2019 · 6 revisions

General concepts

A good log is fundamental for troubleshooting and clio-nodejs-logger exists to solve commons needs that we had.

One good practice is have a standard schema. So we defined some basic attributes that exist in the logger context, so we don't need to pass in each .log call:

  • name: it's value comes from the environment variable APP_NAME
  • timestamp: it's generate but the logger itself
  • message: defined by the developer during the logger invocation, eg: Logger.current().info('my message')
  • level: also it's defined by the developer during the logger invocation
  • namespace: it's based on the namespace you defined in the constructor
  • uptime: the current app uptime in seconds (comes from os.uptime)

Those are the basic attributes that Clio is aware by default, but you can also add custom attributes as shown in the example below:

const Logger = require('../index');

const correlationId = '39c74d4d-50a9-4ccb-8c7d-ac413564f4a1';

const logger = new Logger({ context: { correlationId }, logPatterns: '*', namespace: 'app' });

const customAttributes = {
  currentUser: 'User X',
  orderNumber: '1234',
  orderStatus: 'PENDING',
};

logger.log('hello from Clio', customAttributes);

In the example above it's important to notice two lifecycle momments:

  • Logger creation: during the creation we can setup your custom attributes like (correlationId, sessionId, etc), those values are outputted every time a log event occurs
  • Logger event: this is when you call a log event, where you can pass the message and also as a second parameter custom attributes that will be outputted only in this log event

Giving an execution context to your logger

The main motivation for us to build Clio library was solve the following problem: we don't have an execution Context

But what we mean by "execution Context" you could be asking... We needed to have attributes like correlation id, but we didn't to spread it across our application layers. That's why Clio was created.

Execution Context is not something well solved in JavaScript, and during our research process we found to solutions:

Even Domain is being a pending deprecation module, we choose it over Zone.js because it comes with Node.js.

So after a little of history let's see how we can create an execution context:

const domain = require('domain');
const Logger = require('../index');

const currentDomain = domain.create();
const context = { correlationId: '39c74d4d-50a9-4ccb-8c7d-ac413564f4a1' };

currentDomain.logger = new Logger({ context, logPatterns: '*' });

function myAwesomeAppEntryPoint() {
  Logger.current().log('Awesome app running with execution context!');

  new Logger({ logPatterns: '*' }).log('Awesome app running without execution context!');
}

currentDomain.run(myAwesomeAppEntryPoint);

Enabling log

But default log is not outputted, we need to configure the logPatterns attribute to enable output. The configuration is based on debug and it's by namespace and level.

You need to configure the logPatterns and logLevel in the Logger constructor but it's also possible via the environment variables LOG_NAMESPACES and LOG_LEVEL.

const Logger = require('@naturacosmeticos/clio-nodejs-logger');

const logger = new Logger({ logLevel: 'debug', logPatterns: '*' });

A Logger instance accepts a configuration with the following parameters:

Name Default Description
context undefined An object where it attributes will be logged in every log event
namespace undefined Astring with the name your logger namespace (ex: app)
logFormat undefined We have only one graylog format besides the default
logLimit 7000 (7kb) The limit size in kb of a log event
logPatterns undefined A string with a pattern following debug to enable log ouput (ex: '*')
logLevel error A string that can be one of the following options: debug, error, warn and log

For development

We recommend you to enable all log namespaces (LOG_NAMESPACES: '*'), levels (LOG_LEVEL: 'debug') and enable also pretty print (LOGS_PRETTY_PRINT: '1').

For production

In production we the recommendation is disable the pretty print (by default is disabled) and configure LOG_NAMESPACES based on you need. We added some examples of valid configurations:

  • LOG_NAMESPACES: '*' - it's going to log everything
  • LOG_NAMESPACES: '' - it's going to disable the log
  • LOG_NAMESPACES: 'http' - it's going to print only log events with namespace equals http
  • LOG_NAMESPACES: 'db, integration' - db and integration namespaces will be outputted
  • LOG_NAMESPACES: '*,-db' - it's going to log everthing, except log events with db namespace
  • LOG_NAMESPACES: 'http:*,-http:routes' - it's to print every log with http namespace, except with the namespace http:routes

If you need to enable debug log level, then configure LOG_LEVEL equal debug (by default debug levels are suppressed).

Graylog format

Graylog has some default attributes (level, message, timestamp) that conflicts with the Clio attributes, so you need to use the graylog format to prepend log_ to those attributes:

const Logger = require('@naturacosmeticos/clio-nodejs-logger');

const logger = new Logger({ logFormat: 'graylog', logPatterns: '*' });

Recipes

API log

In this recipe we are going to showcase an Express app using Clio.

Source code: https://github.com/natura-cosmeticos/clio-nodejs-logger/tree/master/samples/express-api

To add Clio do an Express app you will need:

  1. Create a middleware to setup Clio, in our example we created clio-middleware.js

    • in requestContext we are getting some context attributes which origin is header from request
    • in createLogger is possible to enable a "debug mode", where our application will log everything
    • finally in contextMiddleware we are using domain to create an execution context and also we setup res.locals.logger that is a new Logger instance with the http namespace

  2. Create a middleware (logging-middleware) to log all input and output from our API

Database log

In this recipe we are going to showcase an integration with sqlite using TypeORM and Clio.

Source code: https://github.com/natura-cosmeticos/clio-nodejs-logger/tree/master/samples/typeorm

For this example to work, we needed to create the following files:

  • clio-logger.js - here we created a custom logger that implements TypeORM logger interface
  • config.js - this the configuration that TypeORM depends on, here we are using sqlite to reduce the recipe scope
  • index.js - here is where the fun stuff happens:
    • first we have to create our posts table
    • then we a new post and if an error occurs we use Clio to log it. All the queries executed also will be printed out, because we enabled TypeORM log mode (logging: true in config.js)
  • post-entity - this is an entity for TypeORM mapping

Creating a child logger

In this recipe we are going to show how to create a child logger.

Source code: https://github.com/natura-cosmeticos/clio-nodejs-logger/blob/master/samples/child-logger.js

Child logger can be used when we need to create another namespace, normally when we want to control the ouput of your application. For example, if you have an integration with a legacy system, you can create a child logger with legacy namespace, so you can control with LOG_NAMESPACES env variable if this namespace should or not should be logged.

This example is short so here is the complete code:

const Logger = require('@naturacosmeticos/clio-nodejs-logger');

class ChildLoggerSample {
  constructor() {
    this.logger = Logger.current().createChildLogger('child-logger');
  }

  execute() {
    try {
      this.logger.debug('Child logger example');

      throw new Error('Sorry...');
    } catch (error) {
      this.logger.error(error.message, { errorCode: '5000', stack: error.stack });
    }
  }
}

const childLoggerSample = new ChildLoggerSample();

childLoggerSample.execute();
Clone this wiki locally