dd-trace-js
dd-trace-js copied to clipboard
Re-implement the logger with diagnostics channel
What does this PR do?
Re-implement the logger with diagnostics channel.
Motivation
This will enable us to send logs as events to diagnostics channels instead of calling the logger directly. This has several benefits for our use case:
- Diagnostics channel has built-in support for checking for subscribers in order to avoid running whatever code is needed to build the log message. This is more efficient than the current callback approach. I haven't changed the usage in this PR as it can be done later in separate PR.
- We can do other things with the events, for example collect telemetry for the number of errors, etc.
- It could potentially allow using multiple loggers more easily, especially ones with different log levels.
- Allow us to eventually publish asynchronously to fix using log injection on a logger that is also set on the tracer.
Codecov Report
Merging #1560 (908611b) into master (cc3952d) will increase coverage by
0.00%. The diff coverage is97.43%.
@@ Coverage Diff @@
## master #1560 +/- ##
=======================================
Coverage 94.03% 94.03%
=======================================
Files 157 157
Lines 6455 6473 +18
=======================================
+ Hits 6070 6087 +17
- Misses 385 386 +1
| Impacted Files | Coverage Δ | |
|---|---|---|
| packages/dd-trace/src/log.js | 98.85% <97.43%> (-1.15%) |
:arrow_down: |
Continue to review full report at Codecov.
Legend - Click here to learn more
Δ = absolute <relative> (impact),ø = not affected,? = missing dataPowered by Codecov. Last update cc3952d...908611b. Read the comment docs.
wild idea: what about doing this instead
startupFailureLogChannel.subscribe((data) => {
console.log(`The tracer could not start: ${data.error}`)
})
startupFailureLogChannel.publish({ error })
instead of having log level channels, we'd have specific log message/event channels. any thoughts ?
instead of having log level channels, we'd have specific log message/event channels.
@simon-id That could potentially mean a lot of channels. An alternative to this would be to keep less channels and add some error type or error code or something like that. Originally that's how it was implemented but it was unclear if this would be useful, and made it more complicated to emit logs. Generally speaking, I think sending logs to just a few streams is enough. A good example of this is stdout and stderr.
In any case, I'm not against the idea, but if we're gonna go in that direction we should definitely define these really well to avoid having to add channels to core every time we add logging. Did you have a use case in mind where it would be helpful to have more granular log channels?
@bengl Thoughts?
Did you have a use case in mind where it would be helpful to have more granular log channels?
Nothing specific in mind, just a thought.
It's probably a good idea to at least split up by feature. For example, a user could decide to listen to only profiler messages. What I think would actually be best is to create a module similar to https://www.npmjs.com/package/debug that would export a function which receives a namespace fragment and uses that with some datadog-specific prefix to create a diagnostics_channel and register it with a centralized logger. Whenever a new namespace is given, the created channel would be stored in a list that could separately be subscribed to any time logging is enabled globally.
This way users could use diagnostics_channel directly for logging and listen for very specific events. It'd be super helpful for debug logging too if we could tell a user specific sets of channels to listen to. Currently turning on certain levels of logging can be very noisy. 😅
We could also have a similar comma-separated env var to turn logging of specific channels on.
@Qard What API would you propose? I agree that it would make sense to be able to turn on or off more granular logging, but I have a few concerns with this right now:
- The matrix might become complicated since users could want for example all profiling logs, or all debug logs regardless of the component, or all exporter logs regardless of level or component. I think this is less trivial than it seems at a glance.
- Being too granular could confuse users that don't know dd-trace extremely well. Standard log levels are universally understood, and while verbose, they are easy to use.
- Right now dd-trace internals are very coupled with little separation of concerns. This makes it difficult to clearly identify the namespace that a log record should belong to.
An alternative would also be to publish objects instead of strings and keep the current channels. Then you could for example subscribe to the debug channel and filter in your subscriber what is interesting to you. This would have the disadvantage of being more costly since it would generate the messages even if not needed (at least on the subscribed to channel), but it might be simpler to interact with, more flexible, and wouldn't require constantly adding new channels to core.
Here's a quick prototype for what I had in mind: https://gist.github.com/Qard/6ae4b84b1073908f84b0fab79c6b42f4
Thanks! Now I understand better the API you're looking for. I have a few concerns with the prototype that you shared:
- Numerical log levels and log level comparison should be left to any logger that subscribes to the channels. This keeps the channels pure as this is logger-specific and different loggers might have different ways to handle, remap to other levels, etc.
- The functionality to subscribe to multiple channels using a regular expression or a string with wildcards should probably be directly in
diagnostics_channelsince I expect this to be a very common use case. - Having more complex channel names means that it will become impossible to expose every channel instances, and every subscriber will need to know the exact name of the channel it subscribes too. This is not necessarily a bad thing as it would decouple things even further, but something to keep in mind since it will make usage a bit more difficult and we'll have to document the channel names when they are ready to be used externally. We'll also have to be careful to not explode the number of channels, or end up with inconsistent naming across dd-trace which would defeat the purpose of pattern matching.
- Not the end of the world, but it means we cannot update the implementation without also updating all usage of the logger in the same PR.
@Qard If you think the above makes sense, I can open a PR in Node to add pattern subscriptions in diagnostics_channel and then I'll update this PR to mostly remove the logger and use more specific names.
RegExp matching support was rejected in core when I originally built diagnostics_channel due to it being a lot more costly than string matching. It'd happen only at channel creation time so to me it's not a big deal but just be warned it could get rejected again.
Also, I would not worry about exploding quantity of channels. It's supposed to have many channels, it gains its performance advantage over a plain event emitter by reducing individual event types to separate channel objects which manage their own subscriber set independently. This is what enables zero-cost publishes when there are not listeners.
I do agree that we should figure out a standard for channel names though. Something like $module:$subsystem:$purpose makes sense to me.
Closing this one out as it's pretty old and has a lot of conflicts.