NodeJS Logging: What should you know about logging? - Logging is undoubtedly one of the most important parts of our application. There are many ways to log in Node.js. We can use what’s built-in, or we can depend on one of the many popular packages to improve NodeJs logging.
For the time being, the ideal way to accomplish nodejs logging is to pipe the stdout and stderr to your preferred log destination. This is because the main logger-debug-writes directly to process.stdout and process.stderr. If we would take those writable streams and fork them to another stream, we would be in business!
There’s a feature request out to the folks at Node.js to allow us to observe these writable streams. With that in place, things will change for the better. Here’s what we have now:
NodeJS Logging
console.log():
The original method of logging is console.log(). It has variants like console.error(), console.info(), and console.warn(). All these are just convenience methods over the base function which is:
console.log(level, message)
Debug module:
With so many packages using “debug”, it is tempting to think we should hook directly into its power. Sure, we can enable it and get output to the console. The trouble is, this is most we can do with it. We can redirect stdout and stderr to a file.
The benefit of using debug is that many packages use it. You can turn it on to get additional info on what’s going on in web middleware like Express and Koa when your back-end gets a web request. The good frameworks will give you a way to hook up nodejs logging middleware, but you might not get all the details sent to it.
Middleware:
Anyway, what is this middleware about? Middleware is just something you can put into the request on the pipeline. The requests from the client side and response from the server side will pass through the middleware only.
For example, Express is one of the most popular API frameworks. You can set up middleware in just about any framework you will use.
Application
const app = express();
const loggingMiddleware = require(‘my-logging-middleware’);
app.use(loggingMiddleware);
Router
const router = express.Router();
const routeLoggingMiddleware = require(‘my-route-logging-middleware’);
router.use(routeLoggingMiddleware);
Errors
const app = express();
const errorLoggingMiddleware = require(‘my-error-logging-middleware’);
app.use(errorLoggingMiddleware);
There is a definite pattern in the way we set middleware in Express. You can set middleware for individual route and templates also.
Each type of middleware function takes specific arguments. It may be interesting to write the middleware or to use a nodejs logging package directly in your app code like this.
// Don’t do like this.
app.use(function(req, res, next) {
console.log(req.url)
next()
}
NodeJs Logging packages:
Next, we are looking at logging packages for Node.js. In one of the most popular utilities, Winston is one. The good thing is, it can take more than one output transport.
The bad thing is Node.js works as it does, you still can’t pipe the output of “debug” into a different transport. Otherwise, it would be great to do that, and send all the debug logs to whatever you want!
Here’s how you set Winston up in Express:
const app = express()
const winston = require(‘winston’)
const consoleTransport = new winston.transports.Console()
const myWinstonOptions = {
transports: [consoleTransport]
}
const logger = new winston.createLogger(myWinstonOptions)
function logRequest(req, res, next) {
logger.info(req.url)
next()
}
app.use(logRequest)
function logError(err, req, res, next) {
logger.error(err)
next()
}
app.use(logError);
The best advantage in Winston is that it’s highly configurable. With filtering, you can set up multiple transports, set custom formatters, and use more than one logger instance. In the code above, I am only logging the requested URL.
You can set a formatter on your request logger that prepares the request and response for logging. Here are the snippets.
‘use strict’
const winston = require(‘winston’)
const remoteLog = new winston.transports.Http({
host: “127.0.0.1”,
port: 3000,
path: “/errors”
})
const consoleLog = new winston.transports.Console()
module.exports = {
requestLogger: createRequestLogger([consoleLog]),
errorLogger: createErrorLogger([remoteLog, consoleLog])
}
function createRequestLogger(transports) {
const requestLogger = winston.createLogger({
format: getRequestLogFormatter(),
transports: transports
})
return function logRequest(req, res, next) {
requestLogger.info({req, res})
next()
}
}
function createErrorLogger(transports) {
const errLogger = winston.createLogger({
level: ‘error’,
transports: transports
})
return function logError(err, req, res, next) {
errLogger.error({err, req, res})
next()
}
}
function getRequestLogFormatter() {
const {combine, timestamp, printf} = winston.format;
return combine(
timestamp(),
printf(info => {
const {req, res} = info.message;
return ${info.timestamp} ${info.level}: ${req.hostname}${req.port || ”}${req.originalUrl};
})
);
}
This setup will create logging middleware using Winston. The middleware plugs into the Express request pipeline. But keep in mind the patterns you are seeing here.
The middleware is reusable. You can apply this pattern to just about any framework you are using. And if you want to hook in the debug module, you just change this file to include it.
If you are using Retrace, there is a package that plugs right into this model via Stackify transport. And for Express, there is a middleware handler built into the Stackify logger. That makes it even easier, it combined with the global handler, it logs global and route exceptions.
var stackify = require(‘stackify-logger’)
// logs global exceptions to Retrace
stackify.start({apiKey: ‘***’, env: ‘dev’})
// logs Express route exceptions to Retrace
app.use(stackify.expressExceptionHandler)
// or add the Stackify transport
require(‘winston-stackify’).Stackify
winstonLogger.add(winston.transports.Stackify, {storage: stackify})
require(‘winston-stackify’).Stackify
const stackifyTransport = new winston.transports.Stackify({storage: stackify})
This is great for nodejs logging within the application code, but it doesn’t stop there. Something can go wrong outside your web host, and you need to pay attention to that as well.
Server logs:
It is worth mentioning, while we are on the subject, that server logs are an important piece of the big picture-application monitoring.
No matter what on which hosting environment you are using, you need to keep an eye on this. The ideal solution is to send all the information to a single place.
Server logs, database logs and application logs should be taken as a whole since these things in aggregate impact your users. You can also capture server logs using Retrace agent.
And let’s not forget the network. Most of us don’t control the network, but it might be worth considering how you might log network issues. Sometimes errors are rooted in the network.
If we don’t have insight into network issues, we can chase our tails looking for a cause after an incident. We inevitably end up shrugging and blaming ghosts. Wouldn’t it be better to have a definitive answer right away?
What should we log in node.js logging?
Nodejs Logging has to be done purposefully. There are a few key categories of logging as followed, and each has its own purpose.
- Error
- Warn
- Info
- Verbose
- Debug
Why should we Log?
- Performance: You and your users care about performance. To measure it, track it somehow.
- **Debugging: **We need to track our mistakes because we need to see where the error occurred and under which conditions. Because we are only human and will make mistakes.
- **Error Tracking: **When Errors came, it helps to know when they started, how often they occurred, for whom they occurred. If they have been resolved, and if they have resurfaced. Those are just a few reasons to keep track of errors.
- Analyzing Logs: Logs are rich resources of information. You can analyze logs to discover usage patterns to guide decisions.
#node-js #web-development
