diff --git a/src/main/java/app/quickcase/sdk/spring/logging/logback/JsonEncoder.java b/src/main/java/app/quickcase/sdk/spring/logging/logback/JsonEncoder.java new file mode 100644 index 0000000..38fe323 --- /dev/null +++ b/src/main/java/app/quickcase/sdk/spring/logging/logback/JsonEncoder.java @@ -0,0 +1,323 @@ +package app.quickcase.sdk.spring.logging.logback; + +import java.util.Collection; +import java.util.Map; + +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.encoder.EncoderBase; + +import static ch.qos.logback.core.CoreConstants.NULL_STR; +import static ch.qos.logback.core.encoder.JsonEscapeUtil.jsonEscapeString; +import static java.util.stream.Collectors.toMap; + +/** + * A take on {@link ch.qos.logback.classic.encoder.JsonEncoder} simplified and with different opinions: + * + */ +public class JsonEncoder extends EncoderBase { + static int DEFAULT_SIZE = 1024; + static int DEFAULT_SIZE_WITH_THROWABLE = DEFAULT_SIZE * 8; + + static byte[] EMPTY_BYTES = new byte[0]; + + protected static final String TIMESTAMP_ATTR_NAME = "timestamp"; + protected static final String LEVEL_ATTR_NAME = "level"; + protected static final String LOGGER_ATTR_NAME = "loggerName"; + protected static final String THREAD_NAME_ATTR_NAME = "threadName"; + protected static final String MARKERS_ATTR_NAME = "markers"; + protected static final String MDC_ATTR_NAME = "mdc"; + protected static final String MESSAGE_ATTR_NAME = "message"; + protected static final String KEY_VALUE_PAIRS_ATTR_NAME = "kvp"; + protected static final String THROWABLE_ATTR_NAME = "exception"; + + protected static final String CYCLIC_THROWABLE_ATTR_NAME = "cyclic"; + protected static final String CAUSE_ATTR_NAME = "cause"; + protected static final String SUPPRESSED_ATTR_NAME = "suppressed"; + protected static final String COMMON_FRAMES_COUNT_ATTR_NAME = "commonFramesCount"; + + protected static final String CLASS_NAME_ATTR_NAME = "className"; + protected static final String METHOD_NAME_ATTR_NAME = "methodName"; + protected static final String FILE_NAME_ATTR_NAME = "fileName"; + protected static final String LINE_NUMBER_ATTR_NAME = "lineNumber"; + + protected static final String STEP_ARRAY_NAME_ATTRIBUTE = "stepArray"; + + protected static final char OPEN_OBJ = '{'; + protected static final char CLOSE_OBJ = '}'; + protected static final char OPEN_ARRAY = '['; + protected static final char CLOSE_ARRAY = ']'; + + protected static final char QUOTE = '"'; + protected static final char SP = ' '; + protected static final String QUOTE_COL = "\":"; + protected static final char VALUE_SEPARATOR = ','; + + @Override + public byte[] headerBytes() { + return EMPTY_BYTES; + } + + @Override + public byte[] encode(ILoggingEvent event) { + final int initialCapacity = event.getThrowableProxy() == null ? DEFAULT_SIZE : DEFAULT_SIZE_WITH_THROWABLE; + StringBuilder sb = new StringBuilder(initialCapacity); + + sb.append(OPEN_OBJ); + + // Timestamp + appenderMemberWithLongValue(sb, TIMESTAMP_ATTR_NAME, event.getTimeStamp()); + + // Level + sb.append(VALUE_SEPARATOR); + String levelStr = event.getLevel() != null ? event.getLevel().levelStr : NULL_STR; + appenderMember(sb, LEVEL_ATTR_NAME, levelStr); + + // Thread + sb.append(VALUE_SEPARATOR); + appenderMember(sb, THREAD_NAME_ATTR_NAME, jsonEscape(event.getThreadName())); + + // Logger + sb.append(VALUE_SEPARATOR); + appenderMember(sb, LOGGER_ATTR_NAME, event.getLoggerName()); + + // Markers + appendMarkers(sb, event); + + // MDC + appendMDC(sb, event); + + // Message + sb.append(VALUE_SEPARATOR); + appenderMember(sb, MESSAGE_ATTR_NAME, jsonEscape(event.getFormattedMessage())); + + // Key/value pairs + appendKeyValuePairs(sb, event); + + // Throwable + appendException(sb, event); + + sb.append(CLOSE_OBJ); + sb.append(CoreConstants.JSON_LINE_SEPARATOR); + + return sb.toString().getBytes(CoreConstants.UTF_8_CHARSET); + } + + @Override + public byte[] footerBytes() { + return EMPTY_BYTES; + } + + private void appenderMember(StringBuilder sb, String key, String value) { + sb.append(QUOTE).append(key).append(QUOTE_COL).append(QUOTE).append(value).append(QUOTE); + } + + private void appenderMemberWithIntValue(StringBuilder sb, String key, int value) { + sb.append(QUOTE).append(key).append(QUOTE_COL).append(value); + } + + private void appenderMemberWithLongValue(StringBuilder sb, String key, long value) { + sb.append(QUOTE).append(key).append(QUOTE_COL).append(value); + } + + private void appendMarkers(StringBuilder sb, ILoggingEvent event) { + var markerList = event.getMarkerList(); + + if (isEmptyCollection(markerList)) + return; + + sb.append(VALUE_SEPARATOR); + sb.append(QUOTE).append(MARKERS_ATTR_NAME).append(QUOTE_COL).append(SP).append(OPEN_ARRAY); + final int len = markerList.size(); + for (int i = 0; i < len; i++) { + if (i != 0) + sb.append(VALUE_SEPARATOR); + sb.append(QUOTE).append(jsonEscapedToString(markerList.get(i))).append(QUOTE); + + } + sb.append(CLOSE_ARRAY); + } + + private void appendMDC(StringBuilder sb, ILoggingEvent event) { + var mdc = event.getMDCPropertyMap(); + + if (isEmptyMap(mdc)) + return; + + sb.append(VALUE_SEPARATOR); + appendMap(sb, MDC_ATTR_NAME, mdc); + } + + private void appendKeyValuePairs(StringBuilder sb, ILoggingEvent event) { + var kvpList = event.getKeyValuePairs(); + + if (isEmptyCollection(kvpList)) + return; + + sb.append(VALUE_SEPARATOR); + appendMap(sb, KEY_VALUE_PAIRS_ATTR_NAME, kvpList.stream().collect(toMap(kvp -> kvp.key, kvp -> kvp.value))); + } + + private void appendException(StringBuilder sb, ILoggingEvent event) { + var itp = event.getThrowableProxy(); + + if (itp == null) + return; + + appendThrowableProxy(sb, THROWABLE_ATTR_NAME, itp, true); + } + + private void appendThrowableProxy(StringBuilder sb, String attributeName, IThrowableProxy itp) { + appendThrowableProxy(sb, attributeName, itp, true); + } + + private void appendThrowableProxy(StringBuilder sb, String attributeName, IThrowableProxy itp, boolean appendValueSeparator) { + + if (appendValueSeparator) + sb.append(VALUE_SEPARATOR); + + // in the nominal case, attributeName != null. However, attributeName will be null for suppressed + // IThrowableProxy array, in which case no attribute name is needed + if (attributeName != null) { + sb.append(QUOTE).append(attributeName).append(QUOTE_COL); + if (itp == null) { + sb.append(NULL_STR); + return; + } + } + + sb.append(OPEN_OBJ); + + appenderMember(sb, CLASS_NAME_ATTR_NAME, nullSafeStr(itp.getClassName())); + + sb.append(VALUE_SEPARATOR); + appenderMember(sb, MESSAGE_ATTR_NAME, jsonEscape(itp.getMessage())); + + if (itp.isCyclic()) { + sb.append(VALUE_SEPARATOR); + appenderMember(sb, CYCLIC_THROWABLE_ATTR_NAME, jsonEscape("true")); + } + + sb.append(VALUE_SEPARATOR); + appendSTEPArray(sb, itp.getStackTraceElementProxyArray(), itp.getCommonFrames()); + + if (itp.getCommonFrames() != 0) { + sb.append(VALUE_SEPARATOR); + appenderMemberWithIntValue(sb, COMMON_FRAMES_COUNT_ATTR_NAME, itp.getCommonFrames()); + } + + IThrowableProxy cause = itp.getCause(); + if (cause != null) { + appendThrowableProxy(sb, CAUSE_ATTR_NAME, cause); + } + + IThrowableProxy[] suppressedArray = itp.getSuppressed(); + if (suppressedArray != null && suppressedArray.length != 0) { + sb.append(VALUE_SEPARATOR); + sb.append(QUOTE).append(SUPPRESSED_ATTR_NAME).append(QUOTE_COL); + sb.append(OPEN_ARRAY); + + boolean first = true; + for (IThrowableProxy suppressedITP : suppressedArray) { + appendThrowableProxy(sb, null, suppressedITP, !first); + if (first) + first = false; + } + sb.append(CLOSE_ARRAY); + } + + sb.append(CLOSE_OBJ); + + } + + private void appendSTEPArray(StringBuilder sb, StackTraceElementProxy[] stepArray, int commonFrames) { + sb.append(QUOTE).append(STEP_ARRAY_NAME_ATTRIBUTE).append(QUOTE_COL).append(OPEN_ARRAY); + + int len = stepArray != null ? stepArray.length : 0; + + if (commonFrames >= len) { + commonFrames = 0; + } + + for (int i = 0; i < len - commonFrames; i++) { + if (i != 0) + sb.append(VALUE_SEPARATOR); + + StackTraceElementProxy step = stepArray[i]; + + sb.append(OPEN_OBJ); + StackTraceElement ste = step.getStackTraceElement(); + + appenderMember(sb, CLASS_NAME_ATTR_NAME, nullSafeStr(ste.getClassName())); + sb.append(VALUE_SEPARATOR); + + appenderMember(sb, METHOD_NAME_ATTR_NAME, nullSafeStr(ste.getMethodName())); + sb.append(VALUE_SEPARATOR); + + appenderMember(sb, FILE_NAME_ATTR_NAME, nullSafeStr(ste.getFileName())); + sb.append(VALUE_SEPARATOR); + + appenderMemberWithIntValue(sb, LINE_NUMBER_ATTR_NAME, ste.getLineNumber()); + sb.append(CLOSE_OBJ); + + } + + sb.append(CLOSE_ARRAY); + } + + private void appendMap(StringBuilder sb, String attrName, Map map) { + sb.append(QUOTE).append(attrName).append(QUOTE_COL).append(SP); + + if (map == null) { + sb.append(NULL_STR); + return; + } + + sb.append(OPEN_OBJ); + + boolean addComma = false; + var entries = map.entrySet(); + for (var entry : entries) { + if (addComma) { + sb.append(VALUE_SEPARATOR); + } + addComma = true; + appenderMember(sb, jsonEscapedToString(entry.getKey()), jsonEscapedToString(entry.getValue())); + } + + sb.append(CLOSE_OBJ); + } + + private String jsonEscapedToString(Object o) { + if (o == null) + return NULL_STR; + return jsonEscapeString(o.toString()); + } + + private String nullSafeStr(String s) { + if (s == null) + return NULL_STR; + return s; + } + + private String jsonEscape(String s) { + if (s == null) + return NULL_STR; + return jsonEscapeString(s); + } + + private boolean isEmptyMap(Map map) { + return map == null || map.isEmpty(); + } + + private boolean isEmptyCollection(Collection collection) { + return collection == null || collection.isEmpty(); + } +} diff --git a/src/main/resources/console-json-appender.xml b/src/main/resources/console-json-appender.xml index e1af9bb..49f11cf 100644 --- a/src/main/resources/console-json-appender.xml +++ b/src/main/resources/console-json-appender.xml @@ -10,13 +10,6 @@ initialization performed by Boot ${CONSOLE_LOG_THRESHOLD} - - false - false - false - false - false - true - + \ No newline at end of file diff --git a/src/test/java/app/quickcase/sdk/spring/logging/logback/JsonEncoderTest.java b/src/test/java/app/quickcase/sdk/spring/logging/logback/JsonEncoderTest.java new file mode 100644 index 0000000..97c2817 --- /dev/null +++ b/src/test/java/app/quickcase/sdk/spring/logging/logback/JsonEncoderTest.java @@ -0,0 +1,207 @@ +package app.quickcase.sdk.spring.logging.logback; + +import java.io.IOException; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.classic.spi.ThrowableProxy; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.node.JsonNodeFactory; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; +import org.slf4j.Marker; +import org.slf4j.MarkerFactory; +import org.slf4j.event.KeyValuePair; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.equalTo; +import static org.hamcrest.Matchers.is; +import static org.junit.jupiter.api.Assertions.assertAll; + +class JsonEncoderTest { + private static final JsonNodeFactory JSON = new JsonNodeFactory(false); + private static final ObjectMapper MAPPER = new ObjectMapper(); + + final JsonEncoder encoder = new JsonEncoder(); + + @Test + @DisplayName("should serialise simple log event") + void shouldSerialiseSimpleLogEvent() throws IOException { + var event = loggingEvent().withLevel(Level.WARN).build(); + + var log = MAPPER.readTree(encoder.encode(event)); + + assertAll( + () -> assertThat(log.get("loggerName").asText(), is("a.b.c.TestLogger")), + () -> assertThat(log.get("level").asText(), is("WARN")), + () -> assertThat(log.get("message").asText(), is("Simple log event")) + ); + } + + @Test + @DisplayName("should serialise formatted message") + void withFormattedMessage() throws IOException { + var event = loggingEvent().withMessage("Formatted message {}: {}") + .withArguments("hello", "world") + .build(); + + var log = MAPPER.readTree(encoder.encode(event)); + + assertThat(log.get("message").asText(), is("Formatted message hello: world")); + } + + @Test + @DisplayName("should serialise markers") + void withMarkers() throws IOException { + var event = loggingEvent().withMarker("MARKER_1") + .withMarker("MARKER_2") + .build(); + + var log = MAPPER.readTree(encoder.encode(event)); + var logMarkers = log.get("markers"); + + assertAll( + () -> assertThat(logMarkers.size(), equalTo(2)), + () -> assertThat(logMarkers.get(0).asText(), is("MARKER_1")), + () -> assertThat(logMarkers.get(1).asText(), is("MARKER_2")) + ); + } + + @Test + @DisplayName("should serialise MDC") + void withMdc() throws IOException { + var event = loggingEvent().withMdcEntry("mdcKey1", "value1") + .withMdcEntry("mdcKey2", "value2") + .build(); + + var log = MAPPER.readTree(encoder.encode(event)); + var logMdc = log.get("mdc"); + + assertAll( + () -> assertThat(logMdc.size(), equalTo(2)), + () -> assertThat(logMdc.get("mdcKey1").asText(), is("value1")), + () -> assertThat(logMdc.get("mdcKey2").asText(), is("value2")) + ); + } + + @Test + @DisplayName("should serialise key/value pairs") + void withKvp() throws IOException { + var event = loggingEvent().withKvp("key1", "value1") + .withKvp("key2", "value2") + .build(); + + var log = MAPPER.readTree(encoder.encode(event)); + var logKvp = log.get("kvp"); + + assertAll( + () -> assertThat(logKvp.size(), equalTo(2)), + () -> assertThat(logKvp.get("key1").asText(), is("value1")), + () -> assertThat(logKvp.get("key2").asText(), is("value2")) + ); + } + + @Test + @DisplayName("should serialise exception") + void withException() throws IOException { + var event = loggingEvent().withException(new Throwable("Some exception")) + .build(); + + var log = MAPPER.readTree(encoder.encode(event)); + var logException = log.get("exception"); + + assertThat(logException.get("message"), equalTo(JSON.textNode("Some exception"))); + } + + LoggingEventBuilder loggingEvent() { + return new LoggingEventBuilder(); + } + + static class LoggingEventBuilder { + private Level level = Level.INFO; + private String loggerName = "a.b.c.TestLogger"; + private List markers = null; + private Map mdc = null; + private String message = "Simple log event"; + private Object[] arguments = null; + private List kvp = null; + private Throwable exception = null; + + public LoggingEventBuilder withLevel(Level level) { + this.level = level; + return this; + } + + public LoggingEventBuilder withLoggerName(String loggerName) { + this.loggerName = loggerName; + return this; + } + + public LoggingEventBuilder withMarker(String marker) { + if (markers == null) { + markers = new ArrayList<>(); + } + + markers.add(MarkerFactory.getMarker(marker)); + + return this; + } + + public LoggingEventBuilder withMdcEntry(String key, String value) { + if (mdc == null) { + mdc = new HashMap<>(); + } + + mdc.put(key, value); + + return this; + } + + public LoggingEventBuilder withMessage(String message) { + this.message = message; + return this; + } + + public LoggingEventBuilder withArguments(Object... args) { + this.arguments = args; + return this; + } + + public LoggingEventBuilder withKvp(String key, String value) { + if (kvp == null) { + kvp = new ArrayList<>(); + } + + kvp.add(new KeyValuePair(key, value)); + + return this; + } + + public LoggingEventBuilder withException(Throwable exception) { + this.exception = exception; + return this; + } + + public LoggingEvent build() { + var event = new LoggingEvent(); + event.setLevel(level); + event.setLoggerName(loggerName); + if (markers != null) { + markers.forEach(event::addMarker); + } + event.setMDCPropertyMap(mdc != null ? mdc : Map.of()); + event.setMessage(message); + event.setArgumentArray(arguments); + event.setKeyValuePairs(kvp); + if (exception != null) { + event.setThrowableProxy(new ThrowableProxy(exception)); + } + return event; + } + } + +} \ No newline at end of file