Slf4j v2 addKeyValue fluent API silently ignores all logs where Protobuf objects are given

[Proximyst]

Describe the bug

If a protobuf object is given to the addKeyValue fluent methods, no log is output, regardless of severity level.

To Reproduce

Here is a minimal reproduction repository: https://github.com/Proximyst/logstash-encoder-addkeyvalue-ignoring-objects-bug

Steps:

1. Have a Protobuf object
2. Call LOGGER.atError().withKeyValue("obj", protobufObject).log("test")
3. See the ERROR severity log be silently swallowed with no output whatsoever

Expected behavior

At the very least output what goes wrong in logging. Preferably, of course, it should just log it properly (be it as a string, as a proper object, or some other way). Even ignoring the specific field would be miles better than how it works today.

Additional context
Add any other context about the problem here.

• logstash-logback-encoder version: 7.4
• logback version: 1.4.14
• jackson version: 2.16.1
• java version: 17 & 21

[philsttr]

Hi @Proximyst

Thanks for an excellent bug report. The reproducer is great. I wish every bug report was as good as this one.

Errors that occur within logback during encoding/appending can be seen by enabling a logback status listener. This is a logback feature, and not specific to logstash-logback-encoder.

When doing so in your example project, I see the following error:

2:39:34,929 |-WARN in net.logstash.logback.encoder.LogstashEncoder@4686afc2 - Error encountered while encoding log event. Event: [ERROR] Super mega important log message with large business value com.fasterxml.jackson.databind.exc.InvalidDefinitionException: Direct self-reference leading to cycle (through reference chain: com.spotify.logstashbug.proto.TestMessage["unknownFields"]->com.google.protobuf.UnknownFieldSet["defaultInstanceForType"])
	at com.fasterxml.jackson.databind.exc.InvalidDefinitionException: Direct self-reference leading to cycle (through reference chain: com.spotify.logstashbug.proto.TestMessage["unknownFields"]->com.google.protobuf.UnknownFieldSet["defaultInstanceForType"])
	at 	at com.fasterxml.jackson.databind.exc.InvalidDefinitionException.from(InvalidDefinitionException.java:77)
	at 	at com.fasterxml.jackson.databind.SerializerProvider.reportBadDefinition(SerializerProvider.java:1330)
	at 	at com.fasterxml.jackson.databind.ser.BeanPropertyWriter._handleSelfReference(BeanPropertyWriter.java:948)
	at 	at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:726)
	at 	at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:770)
	at 	at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:183)
	at 	at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:732)
	at 	at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:770)
	at 	at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:183)
	at 	at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:502)
	at 	at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:341)
	at 	at com.fasterxml.jackson.databind.ObjectMapper.writeValue(ObjectMapper.java:3362)
	at 	at com.fasterxml.jackson.core.base.GeneratorBase.writeObject(GeneratorBase.java:407)
	at 	at net.logstash.logback.util.SimpleObjectJsonGeneratorDelegate.writeObject(SimpleObjectJsonGeneratorDelegate.java:186)
	at 	at net.logstash.logback.composite.loggingevent.KeyValuePairsJsonProvider.writeTo(KeyValuePairsJsonProvider.java:106)
	at 	at net.logstash.logback.composite.loggingevent.KeyValuePairsJsonProvider.writeTo(KeyValuePairsJsonProvider.java:62)
	at 	at net.logstash.logback.composite.JsonProviders.writeTo(JsonProviders.java:78)
	at 	at net.logstash.logback.composite.AbstractCompositeJsonFormatter.writeEventToGenerator(AbstractCompositeJsonFormatter.java:290)
	at 	at net.logstash.logback.composite.AbstractCompositeJsonFormatter$JsonFormatter.writeEvent(AbstractCompositeJsonFormatter.java:190)
	at 	at net.logstash.logback.composite.AbstractCompositeJsonFormatter.writeEvent(AbstractCompositeJsonFormatter.java:156)
	at 	at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:106)
	at 	at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:92)
	at 	at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:36)
	at 	at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:192)
	at 	at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:237)
	at 	at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
	at 	at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:85)
	at 	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
	at 	at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272)
	at 	at ch.qos.logback.classic.Logger.callAppenders(Logger.java:259)
	at 	at ch.qos.logback.classic.Logger.log(Logger.java:817)
	at 	at org.slf4j.spi.DefaultLoggingEventBuilder.log(DefaultLoggingEventBuilder.java:147)
	at 	at org.slf4j.spi.DefaultLoggingEventBuilder.log(DefaultLoggingEventBuilder.java:109)
	at 	at com.spotify.logstashbug.Main.main(Main.java:16)

The error indicates that jackson is not able to serialize the value.

When using logstash-logback-encoder, it's up to the user to ensure that values passed to withKeyValue are serializable by jackson.

Doing some googling, I found https://github.com/HubSpot/jackson-datatype-protobuf, which seems to enable Jackson to serialize protobuf objects as json. I've never used it, but you could give it a shot. See instructions for customizing jackson in the readme.

You could also pass other representations of the object to withKeyValue. For example pass the .toString() representation of the object.