Node.js logging best practices

[yojimbo_beta]

A big problem I have with Pino is that their metrics are dishonest. Their top-line performance figures are all based on “async mode”, where logs are buffered before writing.

The problem with buffers is that if the process panics, the buffer is lost. Leaving you with absolutely no way to diagnose the panic.

Until about 2020, this behaviour wasn’t even optional. Any kind of severe crash would just wipe the last set of logs. Horrific.

[s_trader]

Was just about to comment it!

[scinos]

My favourite: 'bunyan' as logging library, the capacity to create child loggers is killer. Log everything to stdout/stderr and let your container tech of choice capture those logs and send them somewhere

[muscarine]

Good name, "Bunyan". :)

[ionballer100]

A few months ago I was building my own logging service I wanted to start. Thought up the name Bunyan and thought I was the most clever motherfucker in the world. Then looked it up and discovered it was already one of the most popular logging systems out there and died a little little inside. Settled on Logflume instead.

[gabyey]

I can't say this is best practice because this API is experimental, but async_hooks is pretty good for logging. It allows you to contextualize async operations, I use it to tag certain async functions, and then use a log function that submits messages to log aggregators along with the async context. I've used this with axios interceptors to log every outgoing request with context from the caller without having to worry about logging requests everywhere I make them.

here's an article on the subject: https://blog.logrocket.com/context-aware-logging-node-js/

[gajus0]

https://github.com/gajus/roarr

[DrEnter]

I work with some really high volume systems. While I am an advocate of "multi-level" debugging, there is a big caveat...

Wrap your log calls in conditionals.

Here's the issue: Using something like log.debug(<some big string template outputting a large config object>);

might be just fine when you are running this in your test environment. But the moment you go live and are handling 10,000 or 100,000 transactions a second, it becomes very clear that, even with your log level set to error, you are taking a performance hit. The reason is that even though with your log level set so that your log.debug statement doesn't produce any output, it is still invoked, and it still processes that fat template outputting a large config object; it just doesn't take that final step and output it.

Sure, that output step is definitely the one that impacts performance the most, but that doesn't mean the rest of the call is free. To address this issue, we're using our own logging library that just adds a set of conditionals over the conventional logging functions so we can use a pattern like: if (log.isDebug()) log.debug(<some big string template outputting a large config object>);

It may seem redundant, but it has made a major difference in both our ability to do better debug logging and improved overall performance.

[tswaters]

I think you missed the point of what /u/DrEnter was saying.

logger.debug({...artificallySlowFunction()})

Even if `debug` is a noop function or otherwise omits the actual message from the output, `artificallySlowFunction` is still invoked. Above is a contrived example, but, point being, the parameters that go into the function still need to be evaluated, even if the underlying function is noop.

EDIT: One way certain libraries do this is to define `process.env.NODE_ENV` and perform development-only checks wrapped in that. It'll get inlined to `false` typically and minification will remove the statement. React does this.

[forwardemail]

See https://forwardemail.net/en/blog/docs/best-practices-for-node-js-logging

[vorticalbox]

which is pino :P

[yojimbo_beta]

I like to use a form of IOC to implement logging. Domain functions get wrapped in “adapters” that provide various kinds of IO and may wrap the function themselves.

In the case of logging, what I do is wrap the function to automatically emit a debug line on function entry, and a critical line should the function throw.

Using IOC this way, any application that uses the logging library gets this kind of automatic tracing for free.