5

In a JVM project, we're using logstash to log messages with additional JSON data on production servers.

The problem is that the JSON is hard to read in console. So, I tried to changed to the local (dev) configuration to use PatternLayoutEncoder and have nice, clean logs locally.

I found this issue: https://github.com/logstash/logstash-logback-encoder/issues/136

The conclusion was that with logstash logback encoder 5.0, we can now unify the key/value pairs with Structured Parameters.

I did that, and it works great, but they problem I have is that now on logstash the pairs are repeated both in the message and the JSON.

  • For the console I'm using ch.qos.logback.classic.encoder.PatternLayoutEncoder
  • For JSON I'm using net.logstash.logback.encoder.LogstashEncoder

Either I do this:

LOGGER.info("Some message", kv("user_id", 1));

The logstash json is this:

{  message: "Some message", user_id: 1 }

But the console log is doesn't have the parameter:

2018-04-10 08:38:38,042 INFO - Some message

Or I do this:

LOGGER.info("Some message {}", kv("user_id", 1));

The logstash json has duplicated info (not good):

{  message: "Some message user_id=1", user_id: 1 }

And the console log is what I want:

2018-04-10 08:38:38,042 INFO - Some message user_id=1

So my question is:

How can I configure my logs so I get the additional infos in the console, in a clean way, but not have them duplicated in the JSON?

erwan
  • 1,285
  • 5
  • 14
  • 28
  • I'd love to help but I don't know what kind og logger class you are using and how it handles key-value parameters. Or how you can consider key-value information in configuring the default console logger output. If there is no solution you can still setup the message in a form that you can process it easily and get the information and you won't need the additional kv function. – MrSimple Apr 10 '18 at 13:47
  • I've updated my question with the appender classes – erwan Apr 10 '18 at 18:51
  • the "kv" function is actually a helper from `logstash-logback-encoder` – erwan Apr 10 '18 at 18:52
  • In this configuration I'm not sure you can achive your goal. You wish to see detailed data in the message of the event which is your second scenario. But if it's in the message then you will have it as extra info in the logstash message next to the key-value data. So you would need to remove it from the message in the logstash. I don't see how else this could work. – MrSimple Apr 11 '18 at 08:12
  • I'm completely open on how to achieve it actually, I soon as I have the date where I want it to be (displayed in console + in the json for servers) – erwan Apr 11 '18 at 12:00
  • I guess the logstash json is the result of the output. Why not add the date there? If because you need the exact date in both, why not append the date in the message and format the console output not to add it? Which solution do you prefer? – MrSimple Apr 11 '18 at 12:09
  • it's not about the date, it's about additional data I add like the `user_id` – erwan Apr 11 '18 at 16:20
  • Sry, you said "I have the date where I want it", but if thats not relevant then its easier. Leave the kv function and put all the data in the message. Then you need to write a grok filter in logstash. This way you will be able to read it on console and have it as a JSON as logstash output. Can you edit your logstash config into the question? – MrSimple Apr 11 '18 at 18:19

1 Answers1

1
ArrayList<Object> argumentList = new ArrayList<>();
argumentList.add(StructuredArguments.kv("system", "MySystem"));
argumentList.add(StructuredArguments.kv("id", 1234L));
argumentList.add(StructuredArguments.kv("method", "MyMethod"));
log.info("some message", argumentList.toArray());

ArgumentArrayConverter:

import ch.qos.logback.classic.pattern.ClassicConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import static java.util.Arrays.stream;
import static java.util.Optional.ofNullable;

public class ArgumentArrayConverter extends ClassicConverter {
    @Override
    public String convert(ILoggingEvent iLoggingEvent) {
        List<String> allArgs = new ArrayList<>();
        ofNullable(iLoggingEvent.getArgumentArray()).ifPresent(a -> 
            stream(a)
            .forEach(o -> allArgs.add(o.toString())));
        stream(iLoggingEvent.getMDCPropertyMap()
             .entrySet()
             .toArray())
             .forEach(o -> allArgs.add(o.toString()));
        Collections.sort(allArgs);
        return !allArgs.isEmpty() ? allArgs.toString() : "";
}

}

logback config local:

<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
        <conversionRule conversionWord="argumentArray" converterClass="com.nordea.swo.digi.ncr.config.logging.ArgumentArrayConverter" />
        <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
            <withJansi>true</withJansi>
            <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
                <layout class="ch.qos.logback.classic.PatternLayout">
                    <Pattern> %date{"yyyy-MM-dd'T'HH:mm:ss,SSSZ", CET} %clr(%-5level) --- [%15.-15t] %cyan(%-40.40logger{39}) : %msg%argumentArray\r\n</Pattern>
                </layout>
            </encoder>
        </appender>
        <root level="info">
            <appender-ref ref="console"/>
        </root>
    </configuration>

logback config other env:

<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
                <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSX</timestampFormat>
                <timestampFormatTimezoneId>Etc/UTC</timestampFormatTimezoneId>
                <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">
                    <prettyPrint>false</prettyPrint>
                </jsonFormatter>
                <appendLineSeparator>true</appendLineSeparator>
            </layout>
        </encoder>
    </appender>
    <root level="info">
        <appender-ref ref="console"/>
    </root>
</configuration>

Output local:

some message[id=1234, method=MyMethod, system=MySystem]

Output other env:

{with timestamp and other thingies as well. . ." id":"1234", "method":"MyMethod", "system":"MySystem"}

To switch between configs you can ether have different files for the different env's or have both configs in one file but wrapped with spring boot profile tags.

PlickPlick
  • 197
  • 15