Hacker News new | ask | show | jobs
by tjelen 2667 days ago
In my experience, it's better to create a "request context" at the beginning of handling a request and pass it down explicitly to subsequent async calls that handle the request. I think that this approach is similar to Golang's "context" package, for example.

As other commenters note, using CLS (via async hooks or domains) is often too much magic and can possibly cause leaks or at least it results in program logic that's hard to reason about and hard to test.

6 comments

I disagree. Logging is a cross-cutting concern. It is basically the example used to define what a cross-cutting concern is.

I want my cross-cutting concerns to be as invisible as possible, I definitely do not want them to proliferate through all function calls I make in the app.

I do not believe domains or async hooks is too much magic, and they are pretty sound when used properly. As long as they are used responsibly and in a limited setting it is just the right amount of magic.

Cross-cutting concerns are an antipattern.

Logging should not happen inside libraries or submodules. Libraries should expose errors and exceptions either via throwing or message passing (e.g. dispatching error events). Logging should happen at the top-level of the application from a central place (logging logic should not be scattered all over the source code). The top level application logic should aggregate errors from children components/libraries and decide how to log them. This makes it easy to change the default logger and to customize various aspects of the logging.

When you scatter logging logic everywhere throughout your source code, you break the principle of separation of concerns which is probably the most important principle of software development. Even the term 'cross-cutting concern' implies a violation of separation of concerns (a violation of the cross-cutting kind to be exact). A concern cannot be both separate and cross-cutting.

>When you scatter logging logic everywhere throughout your source code, you break the principle of separation of concerns which is probably the most important principle of software development. Even the term 'cross-cutting concern' implies a violation of separation of concerns (a violation of the cross-cutting kind to be exact). A concern cannot be both separate and cross-cutting.

That's because logging is not a concern of your app -- it's a secondary need that's orthogonal (hence cross-cutting) to its actual concerns, and which is there regardless of the app.

Changing your whole app's structure just so that you collect things to log in a central place (as you propose), would be the real violation of concerns.

Not to mention this way you pass around information that might be useless for the purposes of the app (and is just needed for debugging), that it's enough that separate components know themselves internally.

>> Changing your whole app's structure just so that you collect things to log in a central place (as you propose), would be the real violation of concerns.

Maybe it depends on what kind of language/platform you use but if each component is able to dispatch events on itself instead of logging, then that does not require changing the whole app's structure.

The only concern of the top level application logic would be monitoring/reporting so logging fits naturally under that label.

When I write code, I don't want anything to be invisible. I should be able to look at a single file, and understand how it works without reading any others. Sure, there may be some imports at the top of the file, but clearly named external API's will infer what they do.
Yes, and when `const cls = require('cls-hooked')` is written at the top of the file it's pretty clear that the file is using CLS. Nothing invisible about it.
Yes. This is correct way to do logging. Pass an object with request, user, logger and other attributes around as you process it. This is basically "session"
This is the exact problem I solved with CabinJS; making this simple on both client and server. I've tried nearly every logging service and they continually get one thing or the other wrong (even after my attempts to fix them).

https://cabinjs.com

Hapi.js does this natively.
No, it does not do it to best standards and simplicity. Hapi itself is also incredibly convoluted and bloated.
I believe just the opposite.

Explicitly passing the context is robust but in my experience becomes neglected because of the extra work involved everywhere and so just doesn't happen. (The tracing equivalent of requiring a password so strong that people write it on sticky notes.)

My C++, Python, Ruby, C#, and Java runtimes provides thread local storage without cooperation from every function; I don't see why it's improper for my JS runtime to do the same.

It's single threaded. You can usually stick the context in the request object itself.
The issue becomes when you're calling some generic library that's unaware that it is running in a request handler. If you want to log from deeper in some logic, maybe you've passed some data or domain objects but not a request/context/session object. Do you pollute that logic with additional data passed in or does your library just create its own logger and call `log.info('intermediate result of some thing: XXX')` and let the CLS magic associate that with the request that generated the call?
And generally speaking, you want to exit the domain of request/response as early as you can, because it's your interface with the outside world, rather than something that should be pervasive throughout your system.
You still have to rely on async hooks since you won’t be able to pass the context through to a library that doesn’t account for such API.
Along the way you might have some generic data transformation functions that require no notion of a request. They're just pure functions that transform data and can be easily unit tested. Seems nuts to mock a request just to test something like that.
If they don't require a notion of a request then don't pass it to them?
Or you could just pass the function an optional tracing ID as an argument.
Or just keep logging / requests out of the pure functions, and leave it to the context around them. You can always have the pure functions return a `Result` or `Either` type, if you need information about a failure to be logged.
This golang pattern is the worst. Why not just built in thread resolution when the parent cancels?

The context pattern exists because go routines don't have parent child relationships.