Integrating Pino with `async_hooks.AsyncLocalStorage`, `zone.js`, adding Python/Java style logger names, and more

[segevfiner]

I'm looking into how to integrate pino with AsyncLocalStorage and zone.js to be able to propagate context down into logs in deep async call stacks. But the existing code base I have might not be using pino in the best way, and I'm not sure what's the best approach to achieve this.

The current code base I have defines a global pino logger, and calls child in each module globally at import time to add a module name, but it also has a fastify app which doesn't integrate well with that as it uses it's own logger ATM, It also uses mixin to inject some global context that is only available later, although it might also be using it for some fixed fields that if the logger was not used globally at import time I could just set with a child logger. Also due to having to initialize the logger streams a bit later than import time, I had to add a hack of a stream that buffers messages until you pass it the actual streams during init later on. All in all, I'm not sure we are using Pino optimally, yet I'm not sure how to use it and achieve what we want as well. Oh and it is code that needs to work in both Node and the browser, FUN!

For the async context, one approach would be to just stuff a child logger in AsyncLoggerStorage/zone.js (Async context henceforth), but that doesn't integrate well with the fact that the current code uses global child loggers per file, and I'm unsure what's a better way to add such per file context so that I can still use a child logger inside an async context like that.

Another approach is to just store the context vars in the async storage and add them to pino via mixin (Manually in the browser), but that doesn't interact well with fastify which just creates child loggers to attach request context, nor am I sure how well it perform in terms of Pino's JSON serialization optimizations?

Basically, I want two things, have a per file/module logger name set in the style of Java/Python logging, and be able to attach context that will travel along the async call stack so that even logs deep down in the async call stack can be associated with the request without having to manually pass a logger/context to every single function/class in the code base (Golang context.Context style... quite painful...).

Any ideas/tips? What's the best way to use pino, and achieve those things? Also integrating it well with Fastify's logging?

[trevoro]

We do this; I would suggest avoiding storing any methods in your async local storage and instead store the request specific variables as variables instead. So in whatever part of your application is setting these values (like a user ID, X-Request-ID, etc) you store those in your asyncLocalStorage weakMap. Then write a mixin in some master logger instance that reads these values and includes them when returning a log message.

If your master logger instance has this mixin, then the 'child' modules will just inherit that same mixin w/o any issue.

[mcollina]

What @trevoro said.

[segevfiner]

So I guess in addition, I should go with a Fastify plugin that will push the relevant context that Fastify adds to it's logger for each request to the async context, so whether I use the Fastify request logger, or not, they will be available.

I wonder if there was something better builtin for the lazy init trick, as in, being able to initialize the global logger late at CLI parsing time, but still have a global logger available at import time for import time logging, or is that lazy init buffering stream the way to go, and perhaps even useful as a library for others?

Would perhaps be interesting to have an official library that implements this concept, as in, integrates AsyncLocalStorage and zone.js with Pino in a clean way that is considered best practice so that others that want this can benefit and there will be a standard interface around it.

[mcollina]

Here is it: https://github.com/fastify/fastify-request-context

[segevfiner]

Neat. But I need a solution that works in other Node.JS contexts as well (e.g. Google Cloud Functions), and browser in the browser, but it would be useful to look at how this was implemented.

[github-actions[bot]]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.