Building a logger with Undercut
Tags: javascript, webdev, tutorial, undercutjs
Published: 2020-07-24 14:00:59

---
title: Building a logger with Undercut
published: true
description: 
tags: javascript, webdev, tutorial, undercutjs
cover_image: https://dev-to-uploads.s3.amazonaws.com/i/xu0e9gu5o4p5mw2g93dq.jpg
---

In this tutorial we will use [Undercut](https://undercut.js.org/) to build a non-complicated logger. The simplest one you can think of is just a `console.log()`, but we need more:

* Ability to disable logging where not needed without commenting out lines.
* Severity levels support with logger outputting only severe enough entries.
* Log entries processing and transformation (like middlewares).
* Support for custom destinations and outputting into other loggers.
* Less code.

[![Edit Undercut Logger](https://codesandbox.io/static/img/play-codesandbox.svg)](https://codesandbox.io/s/undercut-logger-nx6dl?fontsize=14&hidenavigation=1&theme=dark)

Let's start with use case example:

```js
function myAction(userId, postId) {
  // code
  log.info(() => `User ${userId} requesting post ${postId}`);
  // code
  log.debug(() => [`Current DB context is`, { dbContext }]);
  // code
}
```

Severity levels are embedded into method names, and we use Arrow Functions for building messages (and template literals instead of formatted strings for simplicity). If we need to pass some context among the message, we could do this as a Tuple (an array).

Of course, we want to have more data than just a message. A log entry should be more robust and could be an object with various meaningful properties:

```js
{
  severity: 3,
  level: 'debug',
  timestamp: '2020-07-23T13:56:19.325Z',
  message: 'Current DB context is',
  context: { },
}
```

Such object could be processed by middlewares, which may add more information to it, format some values, filter excess entries, etc. Basic process may look like this:

```text
[log_entry] => [middleware_1] => [middleware_2] => ... => [done]
```

A `middleware` could also output an entry somewhere as Browser's console or a remote web server. It should be configurable too.

As we're going to utilize Undercut for this task, let's think what would be the best choice for our requirements. Log entries come with time. If we can't iterate synchronously, the best option would be to use Observers (Push Lines).

After slight modifications the diagram from above may look like this:

```text
[log_entry] => [------------- push_line--------------]
               [operation_1] => [operation_2] => ... ]
```

Before codding the Logger itself, we need to define severity levels:

```js
// level.js

export const ERROR = 0;
export const WARNING = 1;
export const INFO = 2;
export const DEBUG = 3;
```

We will use a factory function approach for the Logger. Start with options:

```js
// logger.js_1

import { filter, pushLine, toNull } from "@undercut/push";
import { isString } from "@undercut/utils";

import * as Level from "./level.js";

export function createLogger(pipeline, options = {}) {
  const isEnabled = options.isEnabled ?? true;
  const lowestSeverity = options.severity ?? Level.INFO;
```

The function requires a `pipeline` (a list of operations-middlewares) and an `options` object. `isEnabled` allows disabling logger entirely, `level` defines lowest allowed severity level (all levels lower will be skipped).

```js
  const isAllowed = severity => severity <= lowestSeverity && isEnabled;
  const observer = pushLine(pipeline, toNull());
```

The `observer` will represent a chain of middlewares. We're using `toNull` target because there can be more than 1 destination to write logs and users will specify destinations within the `pipeline`, so `toNull` is just a placeholder.

```js
  function log(severity, messageFactory) {
    if (!isAllowed(severity)) return;

    const timestamp = Date.now();
    const message = messageFactory();
    const entry = isString(message)
      ? { severity, timestamp, message }
      : { severity, timestamp, message: message[0], context: message[1] };

    observer.next(entry);
  }
```

The `log` function represents the whole logic of the Logger. Firstly we need to check severity level as soon as possible to lower performance penalty. Then we call the `messageFactory` (an arrow function where you specify the message) and look if it returns a tuple of `[message, context]` or just a message string. These values represent initial log entry, which we pass to the `observer`.

```js
  return {
    error: m => log(Level.ERROR, m),
    warning: m => log(Level.WARNING, m),
    info: m => log(Level.INFO, m),
    debug: m => log(Level.DEBUG, m),
    observer: filter(e => isAllowed(e.severity))(observer)
  };
}
```

The logger object has methods for each severity level. This could be done automatically with a helper like `collectProps` and going through the `Level` enumeration, but manual way is the simplest one to get type ahead in IDEs.

Notice the `observer` property. It could be used by a middleware to pass entries from one logger to another. The `observer` is wrapped into a filter with severity level check. This check is done only in the `log` function for performance, so we need to add it here too.

The Logger is finished, but we need to provide a built-in middleware for connecting loggers together.

Every middleware is just a Push Operation. Knowing this and we could reuse operations from Undercut instead of writing our own from scratch.

```js
import { filter, forEach, map } from "@undercut/push";

export function toLogger({ observer }) {
  return forEach(entry => observer.next(entry));
}
```

All `toLogger` does is getting that `observer` from a logger  logger and passing all incoming log entries to it.

Let's add more middlewares.

```js
export const convertTimestampToISO = map(entry => ({
  ...entry,
  timestamp: new Date(entry.timestamp).toISOString()
}));
```

`convertTimestampToISO` maps incoming log entry to a new object (a clone) with `timestamp` set to an ISO string instead of original Unix Time number.

```js
export const filterNoContext = filter(entry => entry.context);
```

`filterNoContext` is even more simple and filters log entries with no `context` property.

```js
export const toConsole = prefix =>
  forEach(entry => console.log(prefix + JSON.stringify(entry)));
```

`toConsole` outputs every log entry as a JSON string to browser's console adding text prefix at the beginning.

Testing time:

```js
import * as Level from "./level.js";
import { createLogger, toLogger } from "./logger.js";
import {
  addLevelName,
  addProps,
  convertTimestampToISO,
  filterNoContext,
  toConsole,
  uppercaseMessage
} from "./middlewares.js";

const logger1 = createLogger(
  [
    convertTimestampToISO,
    addLevelName,
    addProps({ test: true }),
    toConsole("logger1: ")
  ],
  { severity: Level.WARNING }
);
```

`logger1` processes only log entries with levels `WARNING` and `ERROR`. Processing of entries looks like this:

1. Create base entry `{ severity, timestamp, message, context }`.
2. Convert `timestamp` to ISO string.
3. Add `level` prop.
4. Add `test` prop with value `true`.
5. Output entry to the console prefixed by "logger1: ".

We could create another logger and connect it to the prevoius:

```js
const logger2 = createLogger(
  [
    filterNoContext,
    toLogger(logger1),
    uppercaseMessage,
    toConsole("logger2: ")
  ],
  { severity: Level.INFO }
);
```

`logger2` processes severity levels `INFO`, `WARN`, `ERROR`, only `DEBUG` will be skipped.

1. Create base entry `{ severity, timestamp, message, context }`.
2. Filter out entry without contexxt.
3. Pass entry to `logger1`.
4. Make message prop uppercase.
5. Output entry to the console prefixed by "logger2: ".

Now we can log some stuff:

```js
const context = { username: "root" };
let counter = 100;

logger1.debug(() => `Debug message: ${counter++}`);
// No output from logger1 because of low severity.

logger1.info(() => `Info message: ${counter++}`);
// No output from logger1 because of low severity.

logger1.warning(() => `Warning message: ${counter++}`);
// logger1: {"severity":1,"timestamp":"2020-07-24T12:34:58.894Z","message":"Warning message: 100","level":"warning","test":true}

logger1.error(() => `Error message: ${counter++}`);
// logger1: {"severity":0,"timestamp":"2020-07-24T12:34:58.895Z","message":"Error message: 101","level":"error","test":true}

logger2.info(() => [`Info message: ${counter++}`, context]);
// No output from logger1 because of low severity.
// logger2: {"severity":2,"timestamp":1595594098895,"message":"INFO MESSAGE: 102","context":{"username":"root"}}

logger2.error(() => `Error message: ${counter++}`);
// No output from logger1 because was filtered by logger2.
// No output from logger2 because of missing context.

logger2.error(() => [`Error message: ${counter++}`, context]);
// logger1: {"severity":0,"timestamp":"2020-07-24T12:34:58.895Z","message":"Error message: 104","context":{"username":"root"},"level":"error","test":true}
// logger2: {"severity":0,"timestamp":1595594098895,"message":"ERROR MESSAGE: 104","context":{"username":"root"}}
```

[![Edit Undercut Logger](https://codesandbox.io/static/img/play-codesandbox.svg)](https://codesandbox.io/s/undercut-logger-nx6dl?fontsize=14&hidenavigation=1&theme=dark)

That's it. Try yourself to make some cool middlewares or use the knowledge in other projects. Feel free to ask your questions in comments.

Visit [GitHub](https://github.com/the-spyke/undercut) Undercut repository for code and [undercut.js.org](https://undercut.js.org/) website for documentation.

Photo by [NeONBRAND](https://unsplash.com/@neonbrand?utm_source=unsplash&amp;utm_medium=referral&amp;utm_content=creditCopyText) on [Unsplash](https://unsplash.com/s/photos/mechanic?utm_source=unsplash&amp;utm_medium=referral&amp;utm_content=creditCopyText)