oshai/kotlin-logging

Problem using LogstashMarker

pandrez opened this issue · 15 comments

Hi @oshai!
First of all, thank you for your work in the library!

I'm having an issue migrating to v5 and I can't seem to find a good approach to solve this problem.

We are using LogstashMarkers which is basically an implementation of org.slf4j.Marker interface provided by the logstash-logback-encoder library.
Migrating to V5 from V3 is proving to be more difficult because the KLogger methods only accept a io.github.oshai.kotlinlogging.Marker interface.

In this case, how would you suggest to proceed? I tried looking into the documentation and other issues in the project but could not find any approach to this.

Thank you for time!

Thank you for reporting an issue. See the wiki for documentation and slack for questions.

oshai commented

Marker is basically a wrapper around a string key. So I think the easiest would be to replace it with

KMarkerFactory.getMarker(name)

Later the lib is converting it to a slf4j marker.

Let me know if that approach works for you.

madorb commented

I am using StructuredArguments from logstash encoder and it's unclear to me how to convert from:

        logger.info(
            "Sending event to foo {} {} {} {}",
            keyValue("id", event.id),
            keyValue("type", event.type),
            keyValue("sourceSystem", event.sourceSystem),
            keyValue("sourceSystemId", event.sourceSystemReferenceId),
        )

to the lazily evaluated version. any suggestions would be appreciated

oshai commented

How about:

logger.info {
            "Sending event to foo ${keyValue("id", event.id)} ${keyValue("type", event.type)} ${keyValue("sourceSystem", event.sourceSystem)} ${keyValue("sourceSystemId", event.sourceSystemReferenceId)}" 
}

How about:

logger.info {
            "Sending event to foo ${keyValue("id", event.id)} ${keyValue("type", event.type)} ${keyValue("sourceSystem", event.sourceSystem)} ${keyValue("sourceSystemId", event.sourceSystemReferenceId)}" 
}

Hi oshai,
I'm probably doing something wrong but I'm trying to have the LogstashEncoder's json output serialize a provided data class and have it appended to the json log. The deprecated logger.info with StructuredArguments generates what I'm looking for but I can't seem to get the equivalent to work with the example you suggested.

When using the deprecated form logger.info("ex {}", StructuredArguments.value("obj", ex) )
Output: {...,"message":"ex MinimalClass(createdAt=2023-12-18T22:49:19.228628500Z, name=hi)",...,"obj":{"createdAt":1702939759.228628500,"name":"hi"}}

I've tried about every combination i can think of even if it doesn't make sense

logger.info { StructuredArguments.value("obj", ex) }
logger.info { "${StructuredArguments.value("obj", ex)}" }
logger.info { "ex {} ${StructuredArguments.value("obj", ex)}" }
logger.info { "ex ${StructuredArguments.value("obj", ex)}" }
logger.info { "${"ex {}"} ${StructuredArguments.value("obj", ex)}" }
logger.info { "${"ex {} ${StructuredArguments.value("obj", ex)} "}"}
logger.info { StructuredArguments.fields(ex) }
logger.info { "${StructuredArguments.keyValue("obj", ex)}" }

but in all of them the output comes out as slight variations in the message to
{"timestamp":"2023-12-18T17:56:44.975-0500","message":"MinimalClass(createdAt=2023-12-18T22:56:44.920520500Z, name=hi)","logger_name":"config.AppConfigTest","thread_name":"Test worker","level":"INFO"} albeit none of them having the MinimalClass data class being serialized

Is this something that would be fixed through customizing the LogstashEncoder in the logback.xml? I'm admittedly lost amongst a sea of knobs and dials and not sure which ones to turn.

oshai commented

You can try the new atInfo(). In a way like that maybe:

logger.atInfo(marker)  {
payload = StructuredArguments.value("obj", ex)
message = "Sending event to foo"
}

The at methods are more rich and have various parameters, and allows sending structured arguments as payload.

You can see more examples (not exactly the same), at slf4j fluent logging: https://www.baeldung.com/slf4j-parameterized-logging#fluent-logging

Regardless, I suggest to see if writing log messages directly to logback is doing what's expected to make sure it's not a configuration issue.

mlewe commented

@oshai

The problem that it's not possible to use org.slf4j.Marker still stands.
As of now, the README states

  • Is all slf4j implementation supported (Markers, params, etc')? Yes.

Which simply doesn't seem to be true for Markers as of version 5.x anymore (without accessing the underlying logger).

The org.slf4j.Marker does not seem to be usable, however you could supply a io.github.oshai.kotlinlogging.Marker established by KMarkerFactory.getMarker("someMarkerName")

this way you can log the following way

logger.info(throwable = null, myMarker) { "some Message" }

Unfortunately you would have to supply the throwable attribute though if you do not want to use a deprecated method.
I think that could be improved.

I was thinking about providing a PR containing just a marker and a message which would be more readable like this:

logger.info(myMarker) { "some Message" }

However if the deprecated methods, having the same signature, this wont be possible.
Due to the fact that only one method per level remains undeprecated using markers will always require a throwable being supplied.

The api could be improved a bit by not requiring the throwable, which could result in the following:

logger.info(marker=myMarker) { "some Message" }

I will create a PR for that approach and see what @oshai thinks

PR is created under #408

@ewoelfel that is also useful to have, but it doesn't solve this issue at all.

@ewoelfel that is also useful to have, but it doesn't solve this issue at all.

That is true concerning the org.slf4j.Marker, but as suggested here you could use a io.github.oshai.kotlinlogging.Marker doing the same job.
Wouldn't that solve your issue? @mlewe
If you need to have a org.slf4j.Marker somewhere maybe the Slf4jExtension-Function Marker.toSlf4j() could help.

No, that wouldn't solve the issue either.

If you need to have a org.slf4j.Marker somewhere maybe the Slf4jExtension-Function Marker.toSlf4j() could help.

That's the opposite of what's needed.
I already have the org.slf4j.Marker and want to pass it to the logger, which only accepts a io.github.oshai.kotlinlogging.Marker .

The way this problem could potentially be solved is to have another implementation of io.github.oshai.kotlinlogging.Marker which wraps a org.slf4j.Marker and to change the implementation of Marker.toSlf4j() to check for this implementation and in that case to unwrap the marker so that it can be fed to the underlying logger.

That's the opposite of what's needed.
I already have the org.slf4j.Marker and want to pass it to the logger, which only accepts a io.github.oshai.kotlinlogging.Marker .

I see, maybe adding a new extenion-function similiar to this

public fun org.slf4j.Marker.toMarker(): Marker = KMarkerFactory.getMarker(this.name)

could mitigate the issue. Maybe just for you or even as a PR.
This way you couly supply your own marker by just adding toMarker()

public fun org.slf4j.Marker.toMarker(): Marker = KMarkerFactory.getMarker(this.name)

That would not solve the issues at all.
This would copy the name of the Marker and generate a new Marker from the Slf4j MarkerFactory to be sent to the underlying logger instead of giving the original Marker to the underlying logger.
Yes, every org.slf4j.Marker needs to implement getName(), but I'm free to add whatever other data to my own implementation.

Maybe actually take a look at net.logstash.logback.marker.LogStashMarker which this issue is about, to understand this.

The only way to do this, would be to wrap the org.slf4j.Marker in an implementation of io.github.oshai.kotlinlogging.Marker like I wrote in my previous comment.

I might create a PR for this, but I'm not sure when to find the time.