From bb0accf381797528581640be0f5d824e7e3cf683 Mon Sep 17 00:00:00 2001 From: Simon Brandhof Date: Mon, 10 Jun 2019 15:49:07 +0200 Subject: [PATCH] SC-702 support new property sonar.log.useJsonOutput --- .../org/sonar/application/AppLogging.java | 15 +- .../org/sonar/application/AppLoggingTest.java | 14 ++ server/sonar-process/build.gradle | 1 + .../sonar/process/logging/LogbackHelper.java | 17 ++ .../process/logging/LogbackJsonLayout.java | 130 +++++++++++++++ .../process/logging/RootLoggerConfig.java | 4 +- .../process/logging/LogbackHelperTest.java | 29 ++++ .../logging/LogbackJsonLayoutTest.java | 150 ++++++++++++++++++ .../server/log/ServerProcessLogging.java | 18 +-- .../app/WebServerProcessLoggingTest.java | 17 ++ 10 files changed, 374 insertions(+), 21 deletions(-) create mode 100644 server/sonar-process/src/main/java/org/sonar/process/logging/LogbackJsonLayout.java create mode 100644 server/sonar-process/src/test/java/org/sonar/process/logging/LogbackJsonLayoutTest.java diff --git a/server/sonar-main/src/main/java/org/sonar/application/AppLogging.java b/server/sonar-main/src/main/java/org/sonar/application/AppLogging.java index 24d1d4fea23..2203e351c63 100644 --- a/server/sonar-main/src/main/java/org/sonar/application/AppLogging.java +++ b/server/sonar-main/src/main/java/org/sonar/application/AppLogging.java @@ -154,7 +154,7 @@ public class AppLogging { * It creates a dedicated appender to the System.out which applies no formatting the logs it receives. */ private void configureConsole(LoggerContext loggerContext) { - Encoder encoder = newPatternLayoutEncoder(loggerContext, "%msg%n"); + Encoder encoder = createGobblerEncoder(loggerContext); ConsoleAppender consoleAppender = helper.newConsoleAppender(loggerContext, CONSOLE_PLAIN_APPENDER, encoder); Logger consoleLogger = loggerContext.getLogger(CONSOLE_LOGGER); @@ -195,7 +195,7 @@ public class AppLogging { // logs are written to the console because we want them to be in sonar.log and the wrapper will write any log // from APP's System.out and System.err to sonar.log Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME); - Encoder encoder = newPatternLayoutEncoder(ctx, helper.buildLogPattern(APP_ROOT_LOGGER_CONFIG)); + Encoder encoder = helper.createEncoder(appSettings.getProps(), APP_ROOT_LOGGER_CONFIG, ctx); rootLogger.addAppender(createAppConsoleAppender(ctx, encoder)); // in regular configuration, sub processes are not copying their logs to their System.out, so, the only logs to be @@ -209,7 +209,7 @@ public class AppLogging { private void configureRootWithLogbackWritingToFile(LoggerContext ctx) { Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME); - Encoder encoder = newPatternLayoutEncoder(ctx, helper.buildLogPattern(APP_ROOT_LOGGER_CONFIG)); + Encoder encoder = helper.createEncoder(appSettings.getProps(), APP_ROOT_LOGGER_CONFIG, ctx); FileAppender fileAppender = helper.newFileAppender(ctx, appSettings.getProps(), APP_ROOT_LOGGER_CONFIG, encoder); rootLogger.addAppender(fileAppender); rootLogger.addAppender(createAppConsoleAppender(ctx, encoder)); @@ -228,7 +228,7 @@ public class AppLogging { private void configureGobbler(LoggerContext ctx) { Logger gobblerLogger = ctx.getLogger(LOGGER_GOBBLER); gobblerLogger.setAdditive(false); - Encoder encoder = newPatternLayoutEncoder(ctx, "%msg%n"); + Encoder encoder = createGobblerEncoder(ctx); gobblerLogger.addAppender(helper.newConsoleAppender(ctx, GOBBLER_PLAIN_CONSOLE, encoder)); } @@ -236,10 +236,13 @@ public class AppLogging { return helper.newConsoleAppender(ctx, APP_CONSOLE_APPENDER, encoder); } - private static Encoder newPatternLayoutEncoder(LoggerContext context, String pattern) { + /** + * Simply displays the message received as input. + */ + private static Encoder createGobblerEncoder(LoggerContext context) { PatternLayoutEncoder encoder = new PatternLayoutEncoder(); encoder.setContext(context); - encoder.setPattern(pattern); + encoder.setPattern("%msg%n"); encoder.start(); return encoder; } diff --git a/server/sonar-main/src/test/java/org/sonar/application/AppLoggingTest.java b/server/sonar-main/src/test/java/org/sonar/application/AppLoggingTest.java index 03dd5be3b43..75a9519aa13 100644 --- a/server/sonar-main/src/test/java/org/sonar/application/AppLoggingTest.java +++ b/server/sonar-main/src/test/java/org/sonar/application/AppLoggingTest.java @@ -28,6 +28,7 @@ import ch.qos.logback.core.Appender; import ch.qos.logback.core.ConsoleAppender; import ch.qos.logback.core.FileAppender; import ch.qos.logback.core.encoder.Encoder; +import ch.qos.logback.core.encoder.LayoutWrappingEncoder; import ch.qos.logback.core.joran.spi.ConsoleTarget; import ch.qos.logback.core.rolling.RollingFileAppender; import java.io.File; @@ -42,6 +43,7 @@ import org.slf4j.LoggerFactory; import org.sonar.application.config.AppSettings; import org.sonar.application.config.TestAppSettings; import org.sonar.process.logging.LogbackHelper; +import org.sonar.process.logging.LogbackJsonLayout; import static org.assertj.core.api.Assertions.assertThat; import static org.slf4j.Logger.ROOT_LOGGER_NAME; @@ -255,6 +257,18 @@ public class AppLoggingTest { LoggerFactory.getLogger("com.hazelcast").isInfoEnabled()).isEqualTo(false); } + @Test + public void use_json_output() { + settings.getProps().set("sonar.log.useJsonOutput", "true"); + + LoggerContext ctx = underTest.configure(); + Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME); + ConsoleAppender appender = (ConsoleAppender)rootLogger.getAppender("APP_CONSOLE"); + Encoder encoder = appender.getEncoder(); + assertThat(encoder).isInstanceOf(LayoutWrappingEncoder.class); + assertThat(((LayoutWrappingEncoder)encoder).getLayout()).isInstanceOf(LogbackJsonLayout.class); + } + private void emulateRunFromSonarScript() { settings.getProps().set("sonar.wrapped", "true"); } diff --git a/server/sonar-process/build.gradle b/server/sonar-process/build.gradle index ee525939cb9..48e763545b2 100644 --- a/server/sonar-process/build.gradle +++ b/server/sonar-process/build.gradle @@ -11,6 +11,7 @@ dependencies { compile 'commons-codec:commons-codec' compile 'commons-io:commons-io' compile 'commons-lang:commons-lang' + compile 'com.google.code.gson:gson' compile 'com.google.guava:guava' compile 'com.hazelcast:hazelcast' compile 'org.slf4j:jul-to-slf4j' diff --git a/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackHelper.java b/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackHelper.java index 3af237048df..e1810fd3ffa 100644 --- a/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackHelper.java +++ b/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackHelper.java @@ -22,6 +22,7 @@ package org.sonar.process.logging; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.encoder.PatternLayoutEncoder; import ch.qos.logback.classic.joran.JoranConfigurator; import ch.qos.logback.classic.jul.LevelChangePropagator; import ch.qos.logback.classic.spi.ILoggingEvent; @@ -30,6 +31,7 @@ import ch.qos.logback.core.ConsoleAppender; import ch.qos.logback.core.Context; import ch.qos.logback.core.FileAppender; import ch.qos.logback.core.encoder.Encoder; +import ch.qos.logback.core.encoder.LayoutWrappingEncoder; import ch.qos.logback.core.joran.spi.JoranException; import ch.qos.logback.core.rolling.FixedWindowRollingPolicy; import ch.qos.logback.core.rolling.RollingFileAppender; @@ -223,6 +225,21 @@ public class LogbackHelper extends AbstractLogHelper { configurator.doConfigure(LogbackHelper.class.getResource(xmlResourcePath)); } + public Encoder createEncoder(Props props, RootLoggerConfig config, LoggerContext context) { + if (props.valueAsBoolean("sonar.log.useJsonOutput", false)) { + LayoutWrappingEncoder encoder = new LayoutWrappingEncoder<>(); + encoder.setLayout(new LogbackJsonLayout(config.getProcessId().getKey())); + encoder.setContext(context); + encoder.start(); + return encoder; + } + PatternLayoutEncoder encoder = new PatternLayoutEncoder(); + encoder.setContext(context); + encoder.setPattern(buildLogPattern(config)); + encoder.start(); + return encoder; + } + public RollingPolicy createRollingPolicy(Context ctx, Props props, String filenamePrefix) { String rollingPolicy = props.value(ROLLING_POLICY_PROPERTY, "time:yyyy-MM-dd"); int maxFiles = props.valueAsInt(MAX_FILES_PROPERTY, 7); diff --git a/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackJsonLayout.java b/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackJsonLayout.java new file mode 100644 index 00000000000..94459687d0c --- /dev/null +++ b/server/sonar-process/src/main/java/org/sonar/process/logging/LogbackJsonLayout.java @@ -0,0 +1,130 @@ +/* + * SonarQube + * Copyright (C) 2009-2019 SonarSource SA + * mailto:info AT sonarsource DOT com + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 3 of the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public License + * along with this program; if not, write to the Free Software Foundation, + * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. + */ +package org.sonar.process.logging; + +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.IThrowableProxy; +import ch.qos.logback.classic.spi.StackTraceElementProxy; +import ch.qos.logback.core.CoreConstants; +import ch.qos.logback.core.LayoutBase; +import com.google.gson.stream.JsonWriter; +import java.io.IOException; +import java.io.StringWriter; +import java.time.Instant; +import java.time.ZoneId; +import java.time.format.DateTimeFormatter; +import java.util.Locale; +import java.util.Map; +import java.util.regex.Pattern; +import org.apache.commons.lang.StringUtils; + +import static java.lang.String.format; +import static java.util.Objects.requireNonNull; + +/** + * Formats logs in JSON. + *

+ * Strongly inspired by https://github.com/qos-ch/logback/blob/master/logback-classic/src/main/java/ch/qos/logback/classic/html/DefaultThrowableRenderer.java + */ +public class LogbackJsonLayout extends LayoutBase { + + private static final DateTimeFormatter DATE_FORMATTER = DateTimeFormatter.ISO_OFFSET_DATE_TIME + .withLocale(Locale.US) + .withZone(ZoneId.systemDefault()); + private static final Pattern NEWLINE_REGEXP = Pattern.compile("\n"); + + private final String processKey; + + public LogbackJsonLayout(String processKey) { + this.processKey = requireNonNull(processKey); + } + + String getProcessKey() { + return processKey; + } + + @Override + public String doLayout(ILoggingEvent event) { + StringWriter output = new StringWriter(); + try (JsonWriter json = new JsonWriter(output)) { + json.beginObject(); + json.name("process").value(processKey); + for (Map.Entry entry : event.getMDCPropertyMap().entrySet()) { + if (entry.getValue() != null) { + json.name(entry.getKey()).value(entry.getValue()); + } + } + json + .name("instant").value(event.getTimeStamp()) + .name("date").value(DATE_FORMATTER.format(Instant.ofEpochMilli(event.getTimeStamp()))) + .name("severity").value(event.getLevel().toString()) + .name("logger").value(event.getLoggerName()) + .name("message").value(NEWLINE_REGEXP.matcher(event.getFormattedMessage()).replaceAll("\r")); + IThrowableProxy tp = event.getThrowableProxy(); + if (tp != null) { + json.name("stacktrace").beginArray(); + int nbOfTabs = 0; + while (tp != null) { + printFirstLine(json, tp, nbOfTabs); + render(json, tp, nbOfTabs); + tp = tp.getCause(); + nbOfTabs++; + } + json.endArray(); + + } + json.endObject(); + } catch (Exception e) { + e.printStackTrace(); + throw new IllegalStateException("BUG - fail to create JSON", e); + } + output.write(System.lineSeparator()); + return output.toString(); + } + + private static void render(JsonWriter output, IThrowableProxy tp, int nbOfTabs) throws IOException { + String tabs = StringUtils.repeat("\t", nbOfTabs); + int commonFrames = tp.getCommonFrames(); + StackTraceElementProxy[] stepArray = tp.getStackTraceElementProxyArray(); + + for (int i = 0; i < stepArray.length - commonFrames; i++) { + StackTraceElementProxy step = stepArray[i]; + output.value(tabs + step.toString()); + } + + if (commonFrames > 0) { + output.value(tabs + "... " + commonFrames + " common frames omitted"); + } + + for (IThrowableProxy suppressed : tp.getSuppressed()) { + output.value(format("%sSuppressed: %s: %s", tabs, suppressed.getClassName(), suppressed.getMessage())); + render(output, suppressed, nbOfTabs + 1); + } + } + + private static void printFirstLine(JsonWriter output, IThrowableProxy tp, int nbOfTabs) throws IOException { + String tabs = StringUtils.repeat("\t", nbOfTabs); + int commonFrames = tp.getCommonFrames(); + if (commonFrames > 0) { + output.value(tabs + CoreConstants.CAUSED_BY); + } + output.value(tabs + tp.getClassName() + ": " + tp.getMessage()); + } +} diff --git a/server/sonar-process/src/main/java/org/sonar/process/logging/RootLoggerConfig.java b/server/sonar-process/src/main/java/org/sonar/process/logging/RootLoggerConfig.java index d9960ce93cf..2c503252530 100644 --- a/server/sonar-process/src/main/java/org/sonar/process/logging/RootLoggerConfig.java +++ b/server/sonar-process/src/main/java/org/sonar/process/logging/RootLoggerConfig.java @@ -37,11 +37,11 @@ public final class RootLoggerConfig { return new Builder(); } - ProcessId getProcessId() { + public ProcessId getProcessId() { return processId; } - String getThreadIdFieldPattern() { + public String getThreadIdFieldPattern() { return threadIdFieldPattern; } diff --git a/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackHelperTest.java b/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackHelperTest.java index 4d07ae721ea..924e45bec0c 100644 --- a/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackHelperTest.java +++ b/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackHelperTest.java @@ -28,6 +28,9 @@ import ch.qos.logback.core.Appender; import ch.qos.logback.core.AppenderBase; import ch.qos.logback.core.ConsoleAppender; import ch.qos.logback.core.FileAppender; +import ch.qos.logback.core.Layout; +import ch.qos.logback.core.encoder.Encoder; +import ch.qos.logback.core.encoder.LayoutWrappingEncoder; import ch.qos.logback.core.rolling.FixedWindowRollingPolicy; import ch.qos.logback.core.rolling.RollingFileAppender; import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy; @@ -476,6 +479,32 @@ public class LogbackHelperTest { assertThat(context.getLogger("fii").getLevel()).isNull(); } + @Test + public void createEncoder_uses_pattern_by_default() { + RootLoggerConfig config = newRootLoggerConfigBuilder() + .setProcessId(ProcessId.WEB_SERVER) + .build(); + + Encoder encoder = underTest.createEncoder(props, config, underTest.getRootContext()); + + assertThat(encoder).isInstanceOf(PatternLayoutEncoder.class); + } + + @Test + public void createEncoder_uses_json_output() { + props.set("sonar.log.useJsonOutput", "true"); + RootLoggerConfig config = newRootLoggerConfigBuilder() + .setProcessId(ProcessId.WEB_SERVER) + .build(); + + Encoder encoder = underTest.createEncoder(props, config, underTest.getRootContext()); + + assertThat(encoder).isInstanceOf(LayoutWrappingEncoder.class); + Layout layout = ((LayoutWrappingEncoder) encoder).getLayout(); + assertThat(layout).isInstanceOf(LogbackJsonLayout.class); + assertThat(((LogbackJsonLayout)layout).getProcessKey()).isEqualTo("web"); + } + private LogLevelConfig.Builder newLogLevelConfig() { return LogLevelConfig.newBuilder(ROOT_LOGGER_NAME); } diff --git a/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackJsonLayoutTest.java b/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackJsonLayoutTest.java new file mode 100644 index 00000000000..9c7254e5c6c --- /dev/null +++ b/server/sonar-process/src/test/java/org/sonar/process/logging/LogbackJsonLayoutTest.java @@ -0,0 +1,150 @@ +/* + * SonarQube + * Copyright (C) 2009-2019 SonarSource SA + * mailto:info AT sonarsource DOT com + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 3 of the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public License + * along with this program; if not, write to the Free Software Foundation, + * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. + */ +package org.sonar.process.logging; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.LoggingEvent; +import com.google.gson.Gson; +import java.time.Instant; +import java.time.format.DateTimeFormatter; +import org.assertj.core.data.Offset; +import org.junit.Test; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; + +import static org.assertj.core.api.Assertions.assertThat; + +public class LogbackJsonLayoutTest { + + private LogbackJsonLayout underTest = new LogbackJsonLayout("web"); + + @Test + public void test_simple_log() { + LoggingEvent event = new LoggingEvent("org.foundation.Caller", (Logger) LoggerFactory.getLogger("the.logger"), Level.WARN, "the message", null, new Object[0]); + + String log = underTest.doLayout(event); + + JsonLog json = new Gson().fromJson(log, JsonLog.class); + assertThat(json.process).isEqualTo("web"); + assertThat(json.instant).isCloseTo(System.currentTimeMillis(), Offset.offset(10_000L)); + assertThat(Instant.from(DateTimeFormatter.ISO_OFFSET_DATE_TIME.parse(json.date)).toEpochMilli()).isEqualTo(json.instant); + assertThat(json.severity).isEqualTo("WARN"); + assertThat(json.logger).isEqualTo("the.logger"); + assertThat(json.message).isEqualTo("the message"); + assertThat(json.message).isEqualTo("the message"); + assertThat(json.stacktrace).isNull(); + assertThat(json.fromMdc).isNull(); + } + + @Test + public void test_log_with_throwable_and_no_cause() { + Throwable exception = new IllegalStateException("BOOM"); + LoggingEvent event = new LoggingEvent("org.foundation.Caller", (Logger) LoggerFactory.getLogger("the.logger"), Level.WARN, "the message", exception, new Object[0]); + + String log = underTest.doLayout(event); + + JsonLog json = new Gson().fromJson(log, JsonLog.class); + assertThat(json.process).isEqualTo("web"); + assertThat(json.instant).isCloseTo(System.currentTimeMillis(), Offset.offset(10_000L)); + assertThat(Instant.from(DateTimeFormatter.ISO_OFFSET_DATE_TIME.parse(json.date)).toEpochMilli()).isEqualTo(json.instant); + assertThat(json.severity).isEqualTo("WARN"); + assertThat(json.logger).isEqualTo("the.logger"); + assertThat(json.message).isEqualTo("the message"); + assertThat(json.stacktrace.length).isGreaterThan(5); + assertThat(json.stacktrace[0]).isEqualTo("java.lang.IllegalStateException: BOOM"); + assertThat(json.stacktrace[1]).startsWith("at ").contains("LogbackJsonLayoutTest.test_log_with_throwable"); + assertThat(json.fromMdc).isNull(); + } + + @Test + public void test_log_with_throwable_and_cause() { + Throwable rootCause = new IllegalArgumentException("Root cause"); + Throwable exception = new IllegalStateException("BOOM", rootCause); + LoggingEvent event = new LoggingEvent("org.foundation.Caller", (Logger) LoggerFactory.getLogger("the.logger"), Level.WARN, "the message", exception, new Object[0]); + + String log = underTest.doLayout(event); + + JsonLog json = new Gson().fromJson(log, JsonLog.class); + assertThat(json.stacktrace.length).isGreaterThan(5); + assertThat(json.stacktrace[0]).isEqualTo("java.lang.IllegalStateException: BOOM"); + assertThat(json.stacktrace[1]).startsWith("at org.sonar.process.logging.LogbackJsonLayoutTest.test_log_with_throwable_and_cause(LogbackJsonLayoutTest.java:"); + assertThat(json.stacktrace) + .contains("\tCaused by: ") + .contains("\tjava.lang.IllegalArgumentException: Root cause"); + } + + @Test + public void test_log_with_suppressed_throwable() { + Exception exception = new Exception("BOOM"); + exception.addSuppressed(new IllegalStateException("foo")); + LoggingEvent event = new LoggingEvent("org.foundation.Caller", (Logger) LoggerFactory.getLogger("the.logger"), Level.WARN, "the message", exception, new Object[0]); + + String log = underTest.doLayout(event); + + JsonLog json = new Gson().fromJson(log, JsonLog.class); + assertThat(json.stacktrace.length).isGreaterThan(5); + assertThat(json.stacktrace[0]).isEqualTo("java.lang.Exception: BOOM"); + assertThat(json.stacktrace).contains("Suppressed: java.lang.IllegalStateException: foo"); + } + + @Test + public void test_log_with_message_arguments() { + LoggingEvent event = new LoggingEvent("org.foundation.Caller", (Logger) LoggerFactory.getLogger("the.logger"), Level.WARN, "the {}", null, new Object[]{"message"}); + + String log = underTest.doLayout(event); + + JsonLog json = new Gson().fromJson(log, JsonLog.class); + assertThat(json.process).isEqualTo("web"); + assertThat(json.instant).isCloseTo(System.currentTimeMillis(), Offset.offset(10_000L)); + assertThat(Instant.from(DateTimeFormatter.ISO_OFFSET_DATE_TIME.parse(json.date)).toEpochMilli()).isEqualTo(json.instant); + assertThat(json.severity).isEqualTo("WARN"); + assertThat(json.logger).isEqualTo("the.logger"); + assertThat(json.message).isEqualTo("the message"); + assertThat(json.stacktrace).isNull(); + assertThat(json.fromMdc).isNull(); + } + + @Test + public void test_log_with_MDC() { + try { + LoggingEvent event = new LoggingEvent("org.foundation.Caller", (Logger) LoggerFactory.getLogger("the.logger"), Level.WARN, "the message", null, new Object[0]); + MDC.put("fromMdc", "foo"); + + String log = underTest.doLayout(event); + + JsonLog json = new Gson().fromJson(log, JsonLog.class); + assertThat(json.fromMdc).isEqualTo("foo"); + } finally { + MDC.clear(); + } + } + + private static class JsonLog { + private String process; + private long instant; + private String date; + private String severity; + private String logger; + private String message; + private String fromMdc; + private String[] stacktrace; + } +} diff --git a/server/sonar-server-common/src/main/java/org/sonar/server/log/ServerProcessLogging.java b/server/sonar-server-common/src/main/java/org/sonar/server/log/ServerProcessLogging.java index 5e453dfbbe3..3d1726ac42b 100644 --- a/server/sonar-server-common/src/main/java/org/sonar/server/log/ServerProcessLogging.java +++ b/server/sonar-server-common/src/main/java/org/sonar/server/log/ServerProcessLogging.java @@ -22,9 +22,9 @@ package org.sonar.server.log; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; -import ch.qos.logback.classic.encoder.PatternLayoutEncoder; import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.ConsoleAppender; +import ch.qos.logback.core.encoder.Encoder; import com.google.common.collect.ImmutableSet; import java.util.Set; import org.sonar.process.ProcessId; @@ -107,7 +107,7 @@ public abstract class ServerProcessLogging { configureRootLogger(props); helper.apply(logLevelConfig, props); - configureDirectToConsoleLoggers(ctx, STARTUP_LOGGER_NAME); + configureDirectToConsoleLoggers(props, ctx, STARTUP_LOGGER_NAME); extendConfigure(); helper.enableJulChangePropagation(ctx); @@ -128,11 +128,7 @@ public abstract class ServerProcessLogging { .setProcessId(processId) .setThreadIdFieldPattern(threadIdFieldPattern) .build(); - PatternLayoutEncoder encoder = new PatternLayoutEncoder(); - encoder.setContext(helper.getRootContext()); - encoder.setPattern(helper.buildLogPattern(config)); - encoder.start(); - + Encoder encoder = helper.createEncoder(props, config, helper.getRootContext()); helper.configureGlobalFileLog(props, config, encoder); helper.configureForSubprocessGobbler(props, encoder); } @@ -141,15 +137,12 @@ public abstract class ServerProcessLogging { * Setup one or more specified loggers to be non additive and to print to System.out which will be caught by the Main * Process and written to sonar.log. */ - private void configureDirectToConsoleLoggers(LoggerContext context, String... loggerNames) { + private void configureDirectToConsoleLoggers(Props props, LoggerContext context, String... loggerNames) { RootLoggerConfig config = newRootLoggerConfigBuilder() .setProcessId(ProcessId.APP) .setThreadIdFieldPattern("") .build(); - PatternLayoutEncoder encoder = new PatternLayoutEncoder(); - encoder.setContext(context); - encoder.setPattern(helper.buildLogPattern(config)); - encoder.start(); + Encoder encoder = helper.createEncoder(props, config, context); ConsoleAppender consoleAppender = helper.newConsoleAppender(context, "CONSOLE", encoder); for (String loggerName : loggerNames) { @@ -158,5 +151,4 @@ public abstract class ServerProcessLogging { consoleLogger.addAppender(consoleAppender); } } - } diff --git a/server/sonar-server/src/test/java/org/sonar/server/app/WebServerProcessLoggingTest.java b/server/sonar-server/src/test/java/org/sonar/server/app/WebServerProcessLoggingTest.java index 87056ecf5b9..b5612766341 100644 --- a/server/sonar-server/src/test/java/org/sonar/server/app/WebServerProcessLoggingTest.java +++ b/server/sonar-server/src/test/java/org/sonar/server/app/WebServerProcessLoggingTest.java @@ -28,6 +28,9 @@ import ch.qos.logback.core.Appender; import ch.qos.logback.core.AppenderBase; import ch.qos.logback.core.ConsoleAppender; import ch.qos.logback.core.FileAppender; +import ch.qos.logback.core.OutputStreamAppender; +import ch.qos.logback.core.encoder.Encoder; +import ch.qos.logback.core.encoder.LayoutWrappingEncoder; import ch.qos.logback.core.joran.spi.JoranException; import com.google.common.collect.ImmutableList; import java.io.File; @@ -44,6 +47,7 @@ import org.junit.rules.ExpectedException; import org.junit.rules.TemporaryFolder; import org.sonar.process.Props; import org.sonar.process.logging.LogbackHelper; +import org.sonar.process.logging.LogbackJsonLayout; import static org.assertj.core.api.Assertions.assertThat; import static org.slf4j.Logger.ROOT_LOGGER_NAME; @@ -497,6 +501,19 @@ public class WebServerProcessLoggingTest { .forEach(loggerName -> assertThat(context.getLogger(loggerName).getLevel()).isEqualTo(Level.OFF)); } + @Test + public void use_json_output() { + props.set("sonar.log.useJsonOutput", "true"); + + LoggerContext context = underTest.configure(props); + + Logger rootLogger = context.getLogger(ROOT_LOGGER_NAME); + OutputStreamAppender appender = (OutputStreamAppender)rootLogger.getAppender("file_web"); + Encoder encoder = appender.getEncoder(); + assertThat(encoder).isInstanceOf(LayoutWrappingEncoder.class); + assertThat(((LayoutWrappingEncoder)encoder).getLayout()).isInstanceOf(LogbackJsonLayout.class); + } + private void verifyRootLogLevel(LoggerContext ctx, Level expected) { Logger rootLogger = ctx.getLogger(ROOT_LOGGER_NAME); assertThat(rootLogger.getLevel()).isEqualTo(expected); -- 2.39.5