AboutWritings
CTRL K

Logging in Node.js! Why, How and What?

•4 min read
nodejsfastify

Ever heard of “Production is down!”. The moment you heard that, the only thought that would’ve come to your mind is - My day is now ruined We need to fix it and quickly.

In this post, I’ll explain What is logging? How to setup logging? and What data to log? through fastify , express  as the server framework and pino  as the logging framework for Node.js.

Logging

Logging is a technique that allows anyone to see and observe what’s going on inside a service or application whether it’s a server, database or a process running in the background.

It also enables reporting of crashes or failures like server outage, so that we can quickly fix those issue by looking into those logs and finding the root cause.

How to log?

With fastify, logging comes out-of-the-box  and it uses pino under the hood. Here’s how you can use it:

npm install fastify
server.js
const fastify = require("fastify")({
    // this will enable the request logging
    logger: true,
});
 
fastify.get("/", async () => "Ok");
 
fastify.get("/log", async (req, reply) => {
    // custom log
    req.log.info("this is a custom log message");
 
    return "Ok";
});
 
fastify.listen({ port: 8080 });

Now run the server from the terminal

node server.js

And, visit http://localhost:8080  in the browser and see the logs printing, or http://localhost:8080/log  to see the custom log message.

{"level":30,"time":1654844524714,"pid":17118,"hostname":"DESKTOP","msg":"Server listening at http://127.0.0.1:8080"}
{"level":30,"time":1654844542572,"pid":17118,"hostname":"DESKTOP","reqId":"req-1","req":{"method":"GET","url":"/","hostname":"localhost:8080","remoteAddress":"127.0.0.1","remotePort":45384},"msg":"incoming request"}
{"level":30,"time":1654844542577,"pid":17118,"hostname":"DESKTOP","reqId":"req-1","res":{"statusCode":200},"responseTime":4.297284999862313,"msg":"request completed"}
{"level":30,"time":1654844632191,"pid":17118,"hostname":"DESKTOP","reqId":"req-2","req":{"method":"GET","url":"/log","hostname":"localhost:8080","remoteAddress":"127.0.0.1","remotePort":45414},"msg":"incoming request"}
{"level":30,"time":1654844632192,"pid":17118,"hostname":"DESKTOP","reqId":"req-2","msg":"this is a custom log message"}
{"level":30,"time":1654844632192,"pid":17118,"hostname":"DESKTOP","reqId":"req-2","res":{"statusCode":200},"responseTime":0.5779439993202686,"msg":"request completed"}

However, If you are using express you need to install express-pino-logger

npm install express express-pino-logger
server.js
const app = require("express")();
const pino = require("express-pino-logger")();
 
// Enables logging by registering it as a middleware
app.use(pino);
 
app.get("/", (req, res) => {
    res.send("Ok");
});
 
app.get("/log", (req, res) => {
    // custom log
    req.log.info("this is a custom log message");
 
    req.send("Ok");
});
 
app.listen(3000);

By default fastify logs request and response separately unlike the express which logs both at the same time

What to log?

For a server environment, having observability on the request <-> response life cycle is very crucial. Everything depends on this life cycle working flawlessly, if something happens in-between then we need to make sure that we can get an idea when things went wrong. Things that we could/should log are:

server.js
process.on("unhandledRejection", (err) => {
    // Here we can just use `console` instead of `pino`
    console.error(err);
 
    process.exit(1);
});

What not to log?

But, don’t go and start logging everything you find. There are certain precautions we have to take to do logging in an ethical manner and protect your user’s data.

server.js
const fastify = require("fastify")({
    // We can also use the pino's configuration
    // https://github.com/pinojs/pino/blob/master/docs/api.md#pinooptions-stream
    logger: {
        redact: [
            "req.headers.authorization",
            "req.headers.token",
            "req.headers.cookie",
        ],
    },
});
 
fastify.get("/", async () => "Ok");
 
fastify.listen({ port: 8080 });

With express

server.js
const app = require("express")();
const pino = require("express-pino-logger")({
    redact: [
        "req.headers.authorization",
        "req.headers.token",
        "req.headers.cookie",
    ],
});
 
app.use(pino);

Now, those header will be removed before everything gets logged.

Best Practices

npm install -D pino-pretty
package.json
{
    // ...
    "scripts": {
        "start": "node server.js",
        "dev": "node server.js | pino-pretty",
    },
}