Configurable policies for formatting Markers/StructuredArguments as strings to substitute into PatternLayout

[Mumeii]

Describe the bug

Whenever I use Markers.appendFields() :

• 🟢 the fields of the given POJO are well sent to the logstash backend as new entries in the JSON root payload
• 🔴 but what is displayed in the console thru a net.logstash.logback.appender.LogstashAccessTcpSocketAppender is simply the POJO instance reference ... not even it's toString version 😋

Is it a Markers.appendFields related trouble, or a ch.qos.logback.classic.PatternLayout related trouble ?

From my point of view I would expect Markers.appendFields building a data structure that would be compatible with both appenders.

To Reproduce

Steps to reproduce the behavior:

1. Use this logback.xml configuration :

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <appender name="Console" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%marker</Pattern>
        </layout>
    </appender>

    <springProperty name="logstash-url" source="custom.logstash.url"/>

    <appender name="LOGSTASH" class="net.logstash.logback.appender.LogstashAccessTcpSocketAppender">
        <destination>${logstash-url}</destination>
        <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
    </appender>

    <root level="DEBUG">
        <appender-ref ref="Console"/>
        <appender-ref ref="LOGSTASH"/>
    </root>

</configuration>

2. Execute this code :

    public class MyPojo {

        public static void main(String[] args) {

            MyPojo pojoInstance = new MyPojo();

            log.debug( 
                Markers.appendFields( pojoInstance ), 
                "who cares, only markers are displayed on the console appender :)" 
            );
        }

        final String innerField = "test";

        public String getInnerField() {
            return innerField;
        }

        @Override
        public String toString() {
            return "MyPojo{" +
                "innerField='" + innerField + '\'' +
                '}';
        }
    }

3. The output on the console is something like that :

MyPojo@91ca23d

Expected behavior
I'm expecting the object fields been displayed in the console instead of there parent object reference, so at best, something like that :

innerField: "test"

Or at least, it's toString representation, but in that case it wouldn't fit well if something got appended to the marker instance returned from Markers.appendFields(), either by using .and(), .add() or Markers.aggregate()

• what output did you expect

innerField: "test"

Additional context

• java version : openjdk-11.0.2.jdk

• logstash-logback-encoder version :
  ~/.m2/repository/net/logstash/logback/logstash-logback-encoder/6.6/logstash-logback-encoder-6.6.jar

• logback version :
  ~/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar
  ~/.m2/repository/ch/qos/logback/logback-core/1.2.3/logback-core-1.2.3.jar

• jackson version :
  ~/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jdk8/2.11.4/jackson-datatype-jdk8-2.11.4.jar
  ~/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jsr310/2.11.4/jackson-datatype-jsr310-2.11.4.jar
  ~/.m2/repository/com/fasterxml/jackson/module/jackson-module-parameter-names/2.11.4/jackson-module-parameter-names-2.11.4.jar
  ~/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.11.4/jackson-databind-2.11.4.jar
  ~/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.11.4/jackson-annotations-2.11.4.jar
  ~/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.11.4/jackson-core-2.11.4.jar

• extra log related dependencies :
  ~/.m2/repository/org/springframework/boot/spring-boot-starter-logging/2.4.2/spring-boot-starter-logging-2.4.2.jar
  ~/.m2/repository/org/apache/logging/log4j/log4j-to-slf4j/2.13.3/log4j-to-slf4j-2.13.3.jar
  ~/.m2/repository/org/apache/logging/log4j/log4j-api/2.13.3/log4j-api-2.13.3.jar
  ~/.m2/repository/org/slf4j/jul-to-slf4j/1.7.30/jul-to-slf4j-1.7.30.jar
  ~/.m2/repository/org/slf4j/slf4j-api/1.7.30/slf4j-api-1.7.30.jar

[philsttr]

Hi @Mumeii,

The current behavior is as designed. Any change would be an enhancement.

There is not really a "great" way to consistently convert a logstash-logback-encoder marker to a string that works well in all situations. The markers are primarily designed to output JSON, which doesn't necessarily make sense when using PatternLayout.

For example, say we propose to print a name/value pair for each field in the POJO passed to Markers.appendFields... This works well for POJOs with only primitive/String fields. However, if that POJO contains nested POJO fields, it's not as easy as printing name/value pairs. Some other custom serialization logic is needed to handle the recursion. e.g. keep recursively printing name/value pairs somehow? or only print name/value.toString() for each field of the top level object?

Each type of StructuredArgument or Marker makes an attempt at providing a string value, which is used as a log message substitution argument or the marker value, respectively. The documentation on each method of StructuredArguments provides a better idea of what string value will be included in the substitution args for the log event message. For example, StructuredArguments.fields(..) will include object.toString() as a substitution arg for the log event message. The equivalent marker (Markers.appendFields) uses the same logic to determine the marker value. In this case.. object.toString() is used as well, which is what you are seeing in your output. This is a conservative approach, and is the same approach used by logback if you were to pass an object as a message argument.

Additionally, logstash-logback-encoder does not currently have any object reflection/traversal logic. Instead, it relies on Jackson to inspect and traverse fields, which works for JSON, but not for plain string values. This allows things like adding @JsonIgnore (and other jackson annotations) to fields to customize the JSON output. All of those Jackson annotations would not apply when just creating a plain string value, which might be surprising. For example, if a field is annotated with @JsonIgnore, it would not be output in JSON, but would it be output in the plain text version?

This is somewhat related to #397 which also requests markers to support a non-JSON string value, which is not what they are designed to do.

[Mumeii]

Hi @philsttr

Thanks for your feedback !

Well, I don't have as much experience than you certainly must have regarding the fact you're managing this library, but from what I understand from your previous message, it seems to be more an opinionated point of view.

Certain users will be fine with a call to the Object.toString() basic implementation
Other will favor their own toString implementation, to selectively choose what is displayed, and not simply leave it to the Jackson annotation directives (especially if it's a DTO they want to log)
Other will only go for the Jackson serialisation.

So, I think there would be some room in the interface to leave users the possibility to choose some kind of policy

But what really missled me in the first place is the method name Markers.appendFields.

I really expected that the behavior for the PatternAppender would have been the same same way as with Jackson when sending JSON : working fields by fields to display them in the console

At least one possible policy, would be to use the same mechanism that enable to merge several json element into one, and then revert the final JSON object structure back to a string (inline, I.E. non pretty printed) representation. Would be perfect for a console case (stil, in my opinion of course ;) )

[philsttr]

For some background... The primary purpose of logstash-logback-encoder is to produce JSON payloads (or other data types producible by jackson). The primary purpose for Markers and StructuredArguments is to add information to the payloads written by the encoders/layouts provided by logstash-logback-encoder.

PatternLayout is not the primary focus of logstash-logback-encoder. Support is pretty basic right now since it is not the primary focus.

Having said that, I'll leave this open as an enhancement for future consideration.

If you'd like to take a shot at providing multiple configurable policies for how to handle the string values displayed via the %marker conversion word in a PatternLayout while remaining backwards compatible, I'd be happy to discuss requirements and a design or review a PR.