Lazy evaluated structured arguments

[kschlesselmann]

Is there a way to lazy evaluate log statements that use net.logstash.logback.argument.StructuredArgument?

Currently I can only use logger.trace("msg", kv("foo", bar())) and if bar takes some time to compute I have to wrap everything with logger.isTraceEnabled. It would be nice if I could somehow fall back to some variant of logger.trace { ??? } for this case.

[oshai]

Is it used with the slf4j api? If it is, we can add that. Otherwise you can write such an extension method yourself pretty easily I guess.

[kschlesselmann]

@oshai Yeah, I'm using http://www.slf4j.org/apidocs/org/slf4j/Logger.html#debug(java.lang.String,java.lang.Object...) for this.

[oshai]

@kschlesselmann if I get you correct you're trying to do something like:

logger.trace("my msg with placeholder: {}", kv("foo", bar()))

If so, you can simply replace it with:

logger.trace { "my msg without placeholder: ${kv("foo", bar())}" }

And it will work as you expect (no resolution of kv if level is disabled)

[kschlesselmann]

@oshai This would work, yes. If you don't provide the kv in the message itself though it keeps the message clean (just my msg without placeholder) and appends the structured values to generated JSON (which is then displayable by kibana/cloudwatch logs insights etc).

So it would be great to have a variant where I do not have to put the additional information in the log string.

[oshai]

oh, I got that. How do you think such method signature should be?

[kschlesselmann]

Good question. I too thought about that (tried to design my own extension) but I could not come up with a nice API. Do you have any suggestions?

[kschlesselmann]

@kschlesselmann if I get you correct you're trying to do something like:

logger.trace("my msg with placeholder: {}", kv("foo", bar()))

If so, you can simply replace it with:

logger.trace { "my msg without placeholder: ${kv("foo", bar())}" }

And it will work as you expect (no resolution of kv if level is disabled)

Hi @oshai . I tried your suggestion today and sadly the kv isn't added to the generated JSON this way. So this does not work :-(

[kschlesselmann]

@oshai I thought a little bit about that and I've come up with something like that

internal fun KLogger.trace(vararg objs: () -> Pair<String, Any>, msg: () -> String) {
    if (this.isTraceEnabled) {
        val args = objs
                .map { it.invoke() }
                .map { kv(it.first, it.second.toString()) }
                .toTypedArray()

        this.trace(msg.invoke(), *args)
    }
}

fun foo() {
    logger.trace({ "foo" to "bar" }) { "lala" }
}

This impl is tied to the logstash encoder though to be a bit more "ideomatic". It's easy to use the SLF4J API though if you'd just use vararg objs: () -> Any and provide the kv yourself.

What do you think?

[oshai]

Yes, I think it is better to stick with the slf4j api.
I am not sure how "pretty" is that format, but it sounds like it will be helpful for your case.
Do you want to create a PR for that?

[kschlesselmann]

Yep sure, I'll see what I can do 👍

[newzubakhin]

Hi Gents. Is there any update on this feature? I'd like to see this in kotlin-logging.
Structured logging is a common and useful thing in a distributed environment.

[oshai]

@kschlesselmann - is there any update on that?

[kschlesselmann]

Sorry … nothing yet. I wasn't sure if using so many lambdas would lead to negative performance somewhere and had no time yet to investigate this any further :-(

We currently wrap our statements with

if (logger.isDebugEnabled) { … }

but I'd like to see this feature too ;-)

I'm happy to help but as it looks right now I won't have the time to drive this feature forward as main developer. Sorry guys.

[oshai]

Thanks @kschlesselmann I am closing it for now, until someone decide to pick it up.