Creating a logger in Node.js from scratch

Logging is undoubtedly one of the most important parts of our application. Now, console is a very powerful tool, yes, but what if we wanted to log not only to console, but also to a file?

We could try to write a function logToFile and call it right after console.log. This, however, is not the most DRY (don’t repeat yourself) way to go about it.

What we actually want is a single logger with which we can call, for example, logger.info that automatically logs the message into our console, saves it into two files, and whatever else we might need at the time.

Libraries like Winston, which provide logging in our applications, are very good at what they do, so we don’t really need to reinvent the wheel. Still, I believe that implementing such a library ourselves often provides a lot of insight into how they work. Also, we may want to do a few things differently and add a feature or two.

Go ahead and clone the repository and let’s get started by having a look at what we want to achieve:

const logger = createLogger({
  level: 'info',
  transports: [
    new transports.console({
      level: 'debug',
      colorize: true,
      template: createTemplate(
        format.level(),
        format.text(' :gift:'),
        format.newLine(),
        format.message(),
        format.newLine(),
        format.text('Logged from '),
        format.location(),
        format.text(' :tada:'),
      ),
    }),
    new transports.file({
      level: 'info',
      path: path.join(__dirname, '../important.log'),
      template: createTemplate(
        format.level(),
        format.text(' :gift:'),
        format.newLine(),
        format.message(),
        format.newLine(),
        format.text('Logged from '),
        format.location(),
        format.text(' :tada:'),
      ),
    }),
    new transports.file({
      level: 'info',
      path: path.join(__dirname, '../not-so-important.log'),
      template: createTemplate(
        format.level(),
        format.text(' :tada:'),
        format.newLine(),
        format.message(),
        format.newLine(),
        format.text('Logged from '),
        format.location(),
        format.text(' :tada:'),
      ),
    }),
  ],
});

createLogger

Here is the interface for the createLogger config:

interface Config {
  transports?: Transport[];
  level?: Level;
}

Let’s break it down.

Level

A level is a string with a numeric value assigned to it.

Here are our levels and their numeric values:

const levels = {
  emerg: 'emerg',
  alert: 'alert',
  crit: 'crit',
  error: 'error',
  warning: 'warning',
  notice: 'notice',
  info: 'info',
  debug: 'debug',
};

const levelsNumbers = {
  [levels.emerg]: 0,
  [levels.alert]: 1,
  [levels.crit]: 2,
  [levels.error]: 3,
  [levels.warning]: 4,
  [levels.notice]: 5,
  [levels.info]: 6,
  [levels.debug]: 7,
};

As you can see, the lower the level, the more important the message.

No logs with a level lower than the one provided to the config will be accepted.

Transports

We provide an array of transports, which are different ways of displaying the message. transports.console is going to log the message into our console, and transports.file into a file. We could even create our own transport and use it to save each message inside a database.

Transport

A transport has to be an instance of a class called Transport so that it can inherit all the necessary methods.

---

Over 200k developers use LogRocket to create better digital experiences

Learn more →

---

Let’s take a look at a config passed to each transport:

interface TransportConfig {
  format?: (value: any) => string;
  level?: Level;
  template?: (info: Info) => string;
}

Changing an expression to a string with the built-in function .toString() may sometimes return results such as [object Object]. It tells us literally nothing and we would like to avoid that, thus we are using our custom-build function to handle changing the expression into a string-based representation.

The message is going to be passed like this:

logger.info`This is a collection ${collection} and it is very nice. This is a number ${numb} and it is also very nice.`;

Here, our function would be called twice: first with collection passed in as the value, and the second time with numb.

Note that I did not include parentheses () after calling the info method. This is an example of what we call a tag function; you can read more about this here. I chose to use tag functions to try something different, and also, it is actually the easiest way to pass variables inside our message.

Here is what the call would look like if we did not use a tag function:

console.info('This is a collection', collection, ' and it is very nice. This is a number ', numb, ' and it is also very nice');

Our format function can be, for example, JSON.stringify.

Level

This level, aside from it being transport-specific, works exactly the same as the one inside the logger config.

Template

A template is a function that takes, as arguments, functions called Formatters. Each Formatter returns a function that creates a chunk of our message by taking the Info object as an argument and returning a string.

Inside the Info object, we can find a lot of useful information. For example, for logger.info'This is message' that would be:

• Level: info
• The message: This is a message
• Date of calling log: new Date()
• Place in the code where logger.info was called: log (/Users/primq/Repositories/loqqer/build/index.js:115:17).

interface Info {
  date: Date;
  level: string;
  message: string;
  location: string;
}

type Formatter = (info: Info) => string;

const format = {
  date: (format: string): Formatter => ({ date }) =>
    moment(date).format(format),
  location: (): Formatter => ({ location }) => location,
  message: (): Formatter => ({ message }) => message,
  text: (message: string): Formatter => () => emoji.emojify(message),
  level: (): Formatter => ({ level }) => level.toUpperCase(),
  newLine: (): Formatter => () => '\n',
};

const createTemplate = (...fns: Formatter[]) => {
  return (info) => {
    return fns.reduce((prev, curr) => {
      return `${prev}${curr(info)}`;
    }, '');
  };
};

Inside format.text, we use the node-emoji library, which lets us get the Unicode of emojis. They then can be rendered correctly in our terminal, our file, or anywhere else.

So, Here is a message :heart:, becomes Here is a message ❤️.

It adds a little flavor to our logs and, for me, simply looks good.

Place in the code where logger.info was called…

Whenever we log something we may forget where the log was located — I know it is not a problem to find it, but still, it is interesting how one would go about finding it without searching manually.

If you think about it, we have this one way of revealing all the called functions just before the one we are in right now; it’s what we call a stack. We can gain access to the stack by throwing an error.

Error: Log stack
    at Object.getLocation (/Users/primq/Repositories/loqqer/build/loqqer/location.js:5:15)
    at config.transports.forEach (/Users/primq/Repositories/loqqer/build/loqqer/index.js:41:42)
    at Array.forEach (<anonymous>)
    ...

Here is how this is going to work:

1. We throw an error inside our function
2. We catch the error immediately and check its stack
3. We split the stack by new line and have as a result an array with each line of the stack being a separate element. Now we filter the array to get only those lines starting with “at” since we are only interested in locations
4. We either get the location at the index provided to the function or at the first one (default), which means any function that was called before getLocation(). You can look at the locations like: [getLocation, functionThatCalledGetLocation (the default one), functionThatCalledFunctionThatCalledGetLocation, ...].

const getLocation = (stepInStack: number = 1) => {
  try {
    throw new Error('Log stack');
  } catch (e) {
    try {
      const err: Error = e;
      const stackLocations = err.stack
        .split('\n')
        .map((m) => m.trim())
        .filter((m) => m.startsWith('at'));

      return String(stackLocations[stepInStack]).slice(3);
    } catch (e) {
      return '';
    }
  }
};

Now that we have talked about the config, let’s implement the Transport class.

const defaultConfig: Partial<TransportConfig> = {
  template: ({ message }) => message,
  format: JSON.stringify,
  level: 'info',
};

class Transport<T extends TransportConfig = TransportConfig> {
  protected config: T;

  public constructor(config: T) {
    this.config = { ...defaultConfig, ...(config as any) };
  }

  public isAllowed(level: Level): boolean {
    return isAllowed(this.config.level, level);
  }

  public log({ message, level }: { message: string; level: string }): string {
    return message;
  }

  public format(value: any): string {
    return this.config.format(value);
  }

  public getMessage(info: Info): string {
    return this.config.template(info);
  }
}

The format and getMessage methods are using the config’s methods. The log method acts here as a fallback in case a subclass does not define one of their own. The isAllowed method simply checks whether the provided level of a given message is sufficient enough to be logged in our transport.

Built-in transports

Before we can create our logger, we have to create some transports. I think it would be nice to provide one or two as built-ins. We are going to create two transports that are going to be used in literally every application: a console and a file transport.

transports.console

colors.setTheme({
  emerg: 'red',
  alert: 'orange',
  crit: 'red',
  error: 'cyan',
  warning: 'yellow',
  notice: 'blue',
  info: 'green',
  debug: 'rainbow',
});

interface Config extends TransportConfig {
  colorize?: boolean;
}

const defaultConfig: Partial<Config> = {
  level: 'info',
  colorize: true,
  template: createTemplate(
    format.level(),
    format.text(' - '),
    format.date('DD/MM/YYYY'),
    format.newLine(),
    format.location(),
    format.newLine(),
    format.message(),
  ),
};

class ConsoleTransport extends Transport<Config> {
  public static colors = colors;

  public constructor(unsafeConfig: Config) {
    const config = { ...defaultConfig, ...unsafeConfig };

    super(config);
  }

  public format(value: any): string {
    if (_.isObject(value)) {
      return `\n${inspect(value, false, 2, true)}\n`;
    }

    return String(value);
  }

  private getConsoleMethod(level: string) {
    const method = console[level];

    if (method) {
      return method.bind(console);
    }

    return console.log.bind(console);
  }

  public log({ message, level }: { message: string; level: string }) {
    let msg = message;

    const logToConsole = this.getConsoleMethod(level);

    if (this.config.colorize) {
      msg = colors[level](message);
    }

    logToConsole(`${msg}\n`);

    return msg;
  }
}

format

The util module provides us with a function called inspect, which creates a string-based representation of an object. As the third argument, we can pass the number of how many objects deep we would like to go.

log

We try to use a method from console if there is one for our level. So, if the level is info, the console‘s info method will be used. We also want to check whether the output should be colorized. If it should, we are going to use the colors package to do so. We may also want to include colors as a static property in our class so that it can be changed manually if needed.

transports.file

interface Config extends TransportConfig {
  path: string;
}

const defaultConfig: Partial<Config> = {
  level: 'info',
  template: createTemplate(
    format.level(),
    format.text(' - '),
    format.date('DD/MM/YYYY'),
    format.newLine(),
    format.location(),
    format.newLine(),
    format.message(),
  ),
};

class FileTransport extends Transport<Config> {
  private fileStream: fs.WriteStream;

  public constructor(unsafeConfig: Config) {
    const config = { ...defaultConfig, ...unsafeConfig };
    super(config);

    this.fileStream = fs.createWriteStream(config.path);
  }

  public format(value: any): string {
    if (_.isObject(value)) {
      return `\n${inspect(value, false, null, false)}\n`;
    }

    return String(value);
  }

  public log({ message, level }: { message: string; level: string }) {
    this.fileStream.write(`${message}\n`);

    return message;
  }
}

Inside the FileTransport constructor, we create a writeStream property, which we then use to store each message into a file.

Here, we are also using the inspect function, but now we do not need to limit ourselves;  we can show all the properties.

Summary

Let’s just add the code for createLogger based on the previously defined transport API.

interface Config {
  transports?: Transport[];
  level?: Level;
}

const defaultConfig: Config = {
  transports: [new transports.console({ level: 'info' })],
  level: 'info',
};

const createLogger = (unsafeConfig?: Config) => {
  const config = { ...defaultConfig, ...unsafeConfig };

  const log = (level: Level) => {
    if (!isAllowed(config.level, level)) {
      return (strings: TemplateStringsArray, ...expressions): void => {};
    }

    return (strings: TemplateStringsArray, ...expressions): void => {
      return config.transports.forEach((transport) => {
        if (!transport.isAllowed(level)) {
          return null;
        }

        const content = strings.reduce((prev, curr, index) => {
          const formatted = transport.format(expressions[index] || '');

          return `${prev}${curr}${formatted}`;
        }, '');

        const message = transport.getMessage({
          level,
          message: content,
          date: new Date(),
          location: getLocation(4),
        });

        return transport.log({ level, message });
      });
    };
  };

  return {
    log,
    emerg: log('emerg'),
    alert: log('alert'),
    crit: log('crit'),
    error: log('error'),
    warning: log('warning'),
    notice: log('notice'),
    info: log('info'),
    debug: log('debug'),
  };
};

Now, finally, we can create an instance of our logger.

import { createLogger, transports, createTemplate, format } from 'src/loqqer';

const logger = createLogger({
  level: 'info',
  transports: [
    new transports.console({
      level: 'debug',
      colorize: true,
      template: createTemplate(
        format.level(),
        format.text(' :gift:'),
        format.newLine(),
        format.message(),
        format.newLine(),
        format.text('Logged from '),
        format.location(),
        format.text(' :tada:'),
      ),
    }),
    new transports.file({
      level: 'info',
      path: path.join(__dirname, '../important.log'),
      template: createTemplate(
        format.level(),
        format.text(' :gift:'),
        format.newLine(),
        format.message(),
        format.newLine(),
        format.text('Logged from '),
        format.location(),
        format.text(' :tada:'),
      ),
    }),
    new transports.file({
      level: 'info',
      path: path.join(__dirname, '../not-so-important.log'),
      template: createTemplate(
        format.level(),
        format.text(' :tada:'),
        format.newLine(),
        format.message(),
        format.newLine(),
        format.text('Logged from '),
        format.location(),
        format.text(' :tada:'),
      ),
    }),
  ],
});

const collection = [
  {
    _id: '5ba7840f298023585dfd4b7c',
    index: 0,
    guid: '95f14d33-0dd2-43ef-bc1c-1d8de4e72c7d',
    isActive: false,
    balance: '$1,938.64',
    picture: 'http://placehold.it/32x32',
    age: 26,
    eyeColor: 'green',
    name: {
      first: 'Rhea',
      last: 'Clark',
    },
    company: 'AVENETRO',
    email: '[email protected]',
    phone: '+1 (837) 471-3366',
    address: '531 Debevoise Street, Abiquiu, Oregon, 7728',
    about: 'Veniam aliqua eu qui culpa nisi anim qui veniam ex enim.',
    registered: 'Wednesday, September 5, 2018 5:49 AM',
    latitude: '-27.154951',
    longitude: '-125.263789',
    tags: ['consequat', 'ad', 'id', 'sunt', 'occaecat'],
    range: [0, 1, 2, 3, 4, 5, 6, 7, 8, 9],
    friends: [
      {
        id: 0,
        name: 'Sampson Hughes',
      },
      {
        id: 1,
        name: 'Mathis Branch',
      },
      {
        id: 2,
        name: 'Sabrina Richmond',
      },
    ],
    greeting: 'Hello, Rhea! You have 7 unread messages.',
    favoriteFruit: 'apple',
  },
  {
    _id: '5ba7840f2b0a77562ca911e9',
    index: 1,
    guid: '6af39bb3-932b-4cea-8a66-3114f33e40cd',
    isActive: false,
    balance: '$3,423.66',
    picture: 'http://placehold.it/32x32',
    age: 29,
    eyeColor: 'blue',
    name: {
      first: 'Robbie',
      last: 'Rollins',
    },
    company: 'MUSANPOLY',
    email: '[email protected]',
    phone: '+1 (889) 429-2292',
    address: '737 Village Court, Riceville, Wisconsin, 1234',
    about: 'Veniam aliqua eu qui culpa nisi anim qui veniam ex enim.',
    registered: 'Friday, December 12, 2014 12:04 PM',
    latitude: '-48.466841',
    longitude: '109.167268',
    tags: ['amet', 'laborum', 'excepteur', 'consectetur', 'reprehenderit'],
    range: [0, 1, 2, 3, 4, 5, 6, 7, 8, 9],
    friends: [
      {
        id: 0,
        name: 'Lillie Mcmahon',
      },
      {
        id: 1,
        name: 'Briana Sims',
      },
      {
        id: 2,
        name: 'Caldwell Norman',
      },
    ],
    greeting: 'Hello, Robbie! You have 8 unread messages.',
    favoriteFruit: 'apple',
  },
];

function log() {
  logger.info`heeey, this is my collection: ${collection}`;
  logger.debug`nope, not going to happen ${collection}`;
}

log();

Let’s run it and check the results.

In important.log file:

INFO 🎁
heeey, this is my collection: 
[ { _id: '5ba7840f298023585dfd4b7c',
    index: 0,
    guid: '95f14d33-0dd2-43ef-bc1c-1d8de4e72c7d',
    isActive: false,
    balance: '$1,938.64',
    picture: 'http://placehold.it/32x32',
    age: 26,
    eyeColor: 'green',
    name: { first: 'Rhea', last: 'Clark' },
    company: 'AVENETRO',
    email: '[email protected]',
    phone: '+1 (837) 471-3366',
    address: '531 Debevoise Street, Abiquiu, Oregon, 7728',
    about: 'Veniam aliqua eu qui culpa nisi anim qui veniam ex enim.',
    registered: 'Wednesday, September 5, 2018 5:49 AM',
    latitude: '-27.154951',
    longitude: '-125.263789',
    tags: [ 'consequat', 'ad', 'id', 'sunt', 'occaecat' ],
    range: [ 0, 1, 2, 3, 4, 5, 6, 7, 8, 9 ],
    friends:
     [ { id: 0, name: 'Sampson Hughes' },
       { id: 1, name: 'Mathis Branch' },
       { id: 2, name: 'Sabrina Richmond' } ],
    greeting: 'Hello, Rhea! You have 7 unread messages.',
    favoriteFruit: 'apple' },
  { _id: '5ba7840f2b0a77562ca911e9',
    index: 1,
    guid: '6af39bb3-932b-4cea-8a66-3114f33e40cd',
    isActive: false,
    balance: '$3,423.66',
    picture: 'http://placehold.it/32x32',
    age: 29,
    eyeColor: 'blue',
    name: { first: 'Robbie', last: 'Rollins' },
    company: 'MUSANPOLY',
    email: '[email protected]',
    phone: '+1 (889) 429-2292',
    address: '737 Village Court, Riceville, Wisconsin, 1234',
    about: 'Veniam aliqua eu qui culpa nisi anim qui veniam ex enim.',
    registered: 'Friday, December 12, 2014 12:04 PM',
    latitude: '-48.466841',
    longitude: '109.167268',
    tags:
     [ 'amet', 'laborum', 'excepteur', 'consectetur', 'reprehenderit' ],
    range: [ 0, 1, 2, 3, 4, 5, 6, 7, 8, 9 ],
    friends:
     [ { id: 0, name: 'Lillie Mcmahon' },
       { id: 1, name: 'Briana Sims' },
       { id: 2, name: 'Caldwell Norman' } ],
    greeting: 'Hello, Robbie! You have 8 unread messages.',
    favoriteFruit: 'apple' } ]

Logged from log (/Users/primq/Repositories/loqqer/build/index.js:115:17) 🎉

In not-so-important.log file:

INFO 🎉
heeey, this is my collection: 
[ { _id: '5ba7840f298023585dfd4b7c',
    index: 0,
    guid: '95f14d33-0dd2-43ef-bc1c-1d8de4e72c7d',
    isActive: false,
    balance: '$1,938.64',
    picture: 'http://placehold.it/32x32',
    age: 26,
    eyeColor: 'green',
    name: { first: 'Rhea', last: 'Clark' },
    company: 'AVENETRO',
    email: '[email protected]',
    phone: '+1 (837) 471-3366',
    address: '531 Debevoise Street, Abiquiu, Oregon, 7728',
    about: 'Veniam aliqua eu qui culpa nisi anim qui veniam ex enim.',
    registered: 'Wednesday, September 5, 2018 5:49 AM',
    latitude: '-27.154951',
    longitude: '-125.263789',
    tags: [ 'consequat', 'ad', 'id', 'sunt', 'occaecat' ],
    range: [ 0, 1, 2, 3, 4, 5, 6, 7, 8, 9 ],
    friends:
     [ { id: 0, name: 'Sampson Hughes' },
       { id: 1, name: 'Mathis Branch' },
       { id: 2, name: 'Sabrina Richmond' } ],
    greeting: 'Hello, Rhea! You have 7 unread messages.',
    favoriteFruit: 'apple' },
  { _id: '5ba7840f2b0a77562ca911e9',
    index: 1,
    guid: '6af39bb3-932b-4cea-8a66-3114f33e40cd',
    isActive: false,
    balance: '$3,423.66',
    picture: 'http://placehold.it/32x32',
    age: 29,
    eyeColor: 'blue',
    name: { first: 'Robbie', last: 'Rollins' },
    company: 'MUSANPOLY',
    email: '[email protected]',
    phone: '+1 (889) 429-2292',
    address: '737 Village Court, Riceville, Wisconsin, 1234',
    about: 'Veniam aliqua eu qui culpa nisi anim qui veniam ex enim.',
    registered: 'Friday, December 12, 2014 12:04 PM',
    latitude: '-48.466841',
    longitude: '109.167268',
    tags:
     [ 'amet', 'laborum', 'excepteur', 'consectetur', 'reprehenderit' ],
    range: [ 0, 1, 2, 3, 4, 5, 6, 7, 8, 9 ],
    friends:
     [ { id: 0, name: 'Lillie Mcmahon' },
       { id: 1, name: 'Briana Sims' },
       { id: 2, name: 'Caldwell Norman' } ],
    greeting: 'Hello, Robbie! You have 8 unread messages.',
    favoriteFruit: 'apple' } ]

Logged from log (/Users/primq/Repositories/loqqer/build/index.js:115:17) 🎉

plug

200s only Monitor failed and slow network requests in production

Deploying a Node-based web app or website is the easy part. Making sure your Node instance continues to serve resources to your app is where things get tougher. If you’re interested in ensuring requests to the backend or third-party services are successful, try LogRocket.

LogRocket is like a DVR for web and mobile apps, recording literally everything that happens while a user interacts with your app. Instead of guessing why problems happen, you can aggregate and report on problematic network requests to quickly understand the root cause.

LogRocket instruments your app to record baseline performance timings such as page load time, time to first byte, slow network requests, and also logs Redux, NgRx, and Vuex actions/state. Start monitoring for free.