lib: added logger api to node core#60468
Conversation
|
Review requested:
|
|
thats my first performance results: I think need improvement for child logger area, but ı'm so happy because other results it looks nice. node:logger vs pino ➜ node git:(mert/create-logger-api/node-core) ✗ ./node benchmark/logger/vs-pino.js n=100000
logger/vs-pino.js scenario="simple" logger="node-logger" n=100000: 5,240,540.823813018
logger/vs-pino.js scenario="child" logger="node-logger" n=100000: 2,635,847.7027229806
logger/vs-pino.js scenario="disabled" logger="node-logger" n=100000: 159,436,487.67795104
logger/vs-pino.js scenario="fields" logger="node-logger" n=100000: 3,619,336.304205216
logger/vs-pino.js scenario="simple" logger="pino" n=100000: 3,398,489.9761368227
logger/vs-pino.js scenario="child" logger="pino" n=100000: 4,489,799.803418606
logger/vs-pino.js scenario="disabled" logger="pino" n=100000: 119,772,384.56038144
logger/vs-pino.js scenario="fields" logger="pino" n=100000: 1,257,930.8609750536 |
|
I now learn this feat in Pino I will try add in node:logger |
|
This will require support for serializers |
I wonder, should we name them like Pino does (built-in serializers), or go with something like standardSerializers ? |
Follow pino and we’ll change it |
I tryed serializer implement for logger, and some bench result repaired and fields and simple are experiencing a decline; I will try to resolve these fields: 3.62M → 2.16M (-40%) previously, the results for the child logger were quite slow at around 70%, but the new results have dropped to 18% and have actually improved significantly. I continue to try new methods. |
I inspected pino and I learn some patterns, than I applied this commit and new results! 1ededc7 I used this patterns removed the cost of serializing bindings in each log for the child logger, simple: 6.06M vs 3.48M ops/s (+74% faster) |
|
hello @mcollina do you any comments or suggestions for this end commits, I'm curious 🙏 . |
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #60468 +/- ##
==========================================
+ Coverage 90.32% 90.33% +0.01%
==========================================
Files 730 732 +2
Lines 234653 235341 +688
Branches 43933 44051 +118
==========================================
+ Hits 211949 212607 +658
- Misses 14416 14450 +34
+ Partials 8288 8284 -4
🚀 New features to boost your workflow:
|
f5b0108 to
429359b
Compare
Signed-off-by: Mert Can Altin <mertgold60@gmail.com>
Signed-off-by: Mert Can Altin <mertgold60@gmail.com>
|
@anonrig what is the question for the TSC? |
|
No question for the TSC, removing. |
|
@mcollina the question was not related to the module this logger API would be released?
|
|
@H4ad I don't understand. |
|
@mcollina If the new logger will be released as Ref: |
Signed-off-by: Mert Can Altin <mertgold60@gmail.com>
f2faa6d to
d4f75da
Compare
mcollina
left a comment
There was a problem hiding this comment.
I have a few issues with this implementation, which probably would need a bit more design and community discussion before landing.
the diagnostics channels are global
The main problem with this is that the diagnostic channels are global. This match reality for most applications I've seen where logging is a "global" concern, however it makes it harder for testing. We create a logger with new, which implies a local scope, even though the logs go to a global stream.
Let's say that I what to create two or more instances of the logger with two different transports, how can I achieve that?
(I still think that diagnostics_channel are the best primitive here, but we need to have answers to these questions?
levels are strings, not numbers, in the diagnostics channels.
In most implementations, log levels are actually mapped to integers. This has an advantage when further processing them down. We can see this in action with the n number of diagnostic channel listeners. This is present here, but not moved down the diagnostics channels. Why do we have one channel per level instead of just a single channel with integer values?
The concept of "ERROR is more important than INFO" is pushed down to consumers, and not built into the lib.
As an additional question: many companies want to create their own custom levels (unfortunately), how can this be implemented here?
Note this is about tradeoffs.
the basic logger has a pre-serialized binding string
Part of the goal of this library is to be protocol agnostic, however there is a #bindingStr, which is some inheritance from Pino. I don't think we can afford to do this here in a generic way.
Child logger properties should be LRUd/cached down in the consumer.
| * @returns {object} Serialized error object | ||
| * @private | ||
| */ | ||
| #serializeError(err, seen = new SafeSet()) { |
There was a problem hiding this comment.
I think this should be in a serializer
There was a problem hiding this comment.
Yes, I was added in a serialize, https://github.com/nodejs/node/pull/60468/changes#diff-2d1249526faad148f37dc1ea3bfd8d56b77ceb4bf1e27299de1ed8e1d6ffc12cR9
| logs independently. | ||
|
|
||
| ```mjs | ||
| import { Logger, JSONConsumer } from 'node:logger'; |
There was a problem hiding this comment.
Adding a new module should be a minor change
IMHO this was due to the "shadowing" of the ecosystem. I think this is relaxable/not needed for node: prefixed modules.
My understanding is there are quite a few plus in doing |
Description
Adds an experimental
node:loggermodule that provides a structured, high-performance logging API for Node.js. Available behind the--experimental-loggerflag.Refs: #49296
Architecture
diagnostics_channelas the dispatch mechanism, loggers publish log records to level-specific channels, consumers subscribe to receive themnoopfunctions, eliminating runtime level checksUtf8Stream(SonicBoom port) for high-throughput writesAPI Surface
Logger, Producer class withtrace,debug,info,warn,error,fatalmethodsLogConsumer, Base consumer class for custom log handlingJSONConsumer, Built-in consumer that outputs structured JSON viaUtf8Streamchild(bindings, options), Child loggers with inherited context and serializerslogger.<level>.enabled, Getter for conditional logging (typo-safe)stdSerializers, Built-in serializers forerr,req,resserializesymbol,Symbol.for('nodejs.logger.serialize'), custom object serialization hook (stacked with field serializers)Log levels follow RFC 5424 numerical ordering internally (
trace: 10, debug: 20, info: 30, warn: 40, error: 50, fatal: 60). The API accepts string level names.diagnostics_channelchannel names (log:trace,log:debug,log:info,log:warn,log:error,log:fatal) are used internally and can be subscribed to directly viadiagnostics_channelif needed.Performance
Benchmarked against Pino (output to
/dev/null, n=100000):New files
lib/logger.js, Main module (Logger,LogConsumer,JSONConsumer)lib/internal/logger/serializers.js, Standarderr/req/resserializersdoc/api/logger.md, Full API documentationbenchmark/logger/basic-json.js, Benchmarkstest/parallel/test-log-basic.js, Core logger teststest/parallel/test-logger-serializers.js, Serializer testsModified files
src/node_options.h/src/node_options.cc,--experimental-loggerflaglib/internal/process/pre_execution.js,setupLogger()to allow module loading when flag is setlib/internal/bootstrap/realm.js, Module registrationdoc/api/cli.md, Flag documentationdoc/api/index.md/doc/node.1, Index updatestest/parallel/test-code-cache.js/test-process-get-builtin.mjs/test-require-resolve.js, Test adjustments for new module