Pino: Question: multiple levels of hierarchy

[DonutEspresso]

We have some use cases with deep dependency graphs. In these scenarios multiple levels of child loggers are created (app -> module -> submodule -> subsub etc). Between name and component we are stuck with only two levels of descriptive hierarchy. If child properties were kept around we could build up that hierarchy internally for grandchild+ loggers:

const log = pino({
    name: 'foo'
});
const child = log.child({
    component: 'bar'
});  // => component=bar
const grandchild = child.child({
    component: 'baz'
});  // => component=bar+baz

The deeper the dependency tree, the more useful this becomes. Has the pino team had any thoughts around this area? Two levels seems like a somewhat arbitrary limitation, though I realize the current approach is likely mimicking bunyan. Interestingly, bunyan doesn't even allow renaming of the name field in child loggers (which pino does since its just string concatenation under the hood), so options there are even more limited.

cc @yunong @misterdjules

[jsumners]

https://github.com/pinojs/pino#duplicate-keys

[marcbachmann]

This looks more like a feature request in which I'm also a bit interested.
We could introduce a new namespace api:

const log = pino({}).namespace({ns: 'app'})
log.info('test')
// {"ns":"app","pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"test","time":1459534114473,"v":1}

const sublogger = log.namespace({ns: 'submodule'})
log.info('log from submodule')
// {"ns":"app > submodule","pid":95469,"hostname":"MacBook-Pro-3.home","level":30,"msg":"log from submodule","time":1459534114473,"v":1}

[jsumners]

PRs are welcome. But creating child loggers is already a bottleneck. It could be tricky to implement such a feature efficiently.

[mcollina]

Currently we are using child loggers to create a single logger for every request in all our framework integrations. This is the bottleneck that @jsumners was talking about. I'm 👍 for @marcbachmann suggestion.

You can find an example of interpreting the child logger current properties in https://github.com/pinojs/pino/blob/next-major/lib/tools.js#L46-L51. As you see, it's not pretty. We could in theory keep those around in the form of a prototype chain, and provide them as property (I'm definitely +1 to that approach if you want to try).

Would you mind to send a PR for this feature?

Notes aside, that code is from pino@5. We are shipping some new features there to write faster to files, among other things. It would be good to have some feedback.

[DonutEspresso]

Awesome! Glad to hear I'm not the only one thinking about this. Just so I'm clear on the suggested approach:

1) create some namespace/hierarchy property on the log prototype
2) reuse said property when creating additional child loggers, which would use the parent property appended with its own (potentially passed in) value
3) continue ad-infinitum

Keeping the value around could avoid the re-parse tax. As implied, I think you then pay the tax at the time of _creation_ of each child logger in the hierarchy.

Any thoughts as to how this would work in conjunction with the existing name and component properties? IMHO the semantics of those properties seem somewhat arbitrary at the moment - would we collapse this into a single new property, or would you prefer to create a new property separate from those two?

[mcollina]

Keeping the value around could avoid the re-parse tax. As implied, I think you then pay the tax at the time of creation of each child logger in the hierarchy.

@DonutEspresso I'm against adding this behavior to .child(), mainly because it will be slow and child creation is an hot path for web frameworks (it has been optimized heavily), as we recommend to create a child logger for every request. I guess (but please confirm) that you need this feature _outside_ of a web framework.

I think we could:

• [ ] add logger.baseValues, which will return an object with all the properties currently set on a logger
• [ ] add logger.namespace('foo') which will create a new logger via the slow path of JSON.stringify the baseValues, concatenating the namespaces logger.namespace('foo').namespace('bar') will create { ns: 'foo > bar' }.

Would this work?

[DonutEspresso]

@mcollina For background we create child loggers for every request too, though the use case for the feature being asked for here is intended primarily for long lived components.

Thanks for the clarification, that helps a lot! So if I want both a new namespace as well as new properties, would the preferred method be to chain them like so:

const childLogger = logger.namespace('foo').child({ a: 1, b: 2 }); 

This should work for us! Given that namespace() feels like a JSON.stringify version of .child(), I assume there is no technical reason for allowing arbitrary properties to passed in, but rather a philosophical approach in that we want users to continue using .child() for additional properties given the more performant string building approach?

@yunong anything I might have missed? I think there are a few minor details to work out like the format of concatenated ns values (given we'd be filtering a lot on that value) and how to make sense of it against name and component when pretty formatting the logs. But we should be able to iterate on that pretty easily.

[mcollina]

@DonutEspresso exactly.

[jsumners]

Please target the next-major branch with any PR. Technically, this could be a minor worthy feature, but it is going to cause significant merge conflicts between master and next-major if it were merged into major.

[davidmarkclements]

I'm going to close this as stale for now, @DonutEspresso please feel free to re-open if you're planning on proceeding