From cdfa6621e818729230b6ad8e1c4df6331d95ffb2 Mon Sep 17 00:00:00 2001 From: Ceki Gulcu Date: Fri, 7 Jul 2023 23:46:19 +0200 Subject: [PATCH] add support for throwable cause and suppressed[] in JsonEncoder, this fixes LOGBACK-1749 Signed-off-by: Ceki Gulcu --- .../logback/classic/encoder/JsonEncoder.java | 78 ++++++++++--- .../classic/encoder/JsonEncoderTest.java | 45 +++++-- .../JsonStringToLoggingEventMapper.java | 2 + .../PubThrowableProxyDeserializer.java | 110 ++++++++++++++++++ .../classic/jsonTest/STEPDeserializer.java | 4 + .../jsonTest/ThrowableProxyComparator.java | 56 +++++++-- .../classic/spi/PubThrowableProxy.java | 22 +++- 7 files changed, 279 insertions(+), 38 deletions(-) create mode 100644 logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/PubThrowableProxyDeserializer.java diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/encoder/JsonEncoder.java b/logback-classic/src/main/java/ch/qos/logback/classic/encoder/JsonEncoder.java index 7b60b070a9..dd110ba4db 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/encoder/JsonEncoder.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/encoder/JsonEncoder.java @@ -18,6 +18,7 @@ import ch.qos.logback.classic.spi.IThrowableProxy; import ch.qos.logback.classic.spi.LoggerContextVO; import ch.qos.logback.classic.spi.StackTraceElementProxy; +import ch.qos.logback.classic.spi.ThrowableProxy; import ch.qos.logback.core.CoreConstants; import ch.qos.logback.core.encoder.EncoderBase; import org.slf4j.Marker; @@ -30,6 +31,7 @@ import static ch.qos.logback.core.CoreConstants.COLON_CHAR; import static ch.qos.logback.core.CoreConstants.COMMA_CHAR; import static ch.qos.logback.core.CoreConstants.DOUBLE_QUOTE_CHAR; +import static ch.qos.logback.core.CoreConstants.SUPPRESSED; import static ch.qos.logback.core.CoreConstants.UTF_8_CHARSET; import static ch.qos.logback.core.encoder.JsonEscapeUtil.jsonEscapeString; import static ch.qos.logback.core.model.ModelConstants.NULL_STR; @@ -71,12 +73,19 @@ public class JsonEncoder extends EncoderBase { public static final String THROWABLE_ATTR_NAME = "throwable"; - private static final String CLASS_NAME_ATTR_NAME = "className"; - private static final String METHOD_NAME_ATTR_NAME = "methodName"; + public static final String CAUSE_ATTR_NAME = "cause"; + + public static final String SUPPRESSED_ATTR_NAME = "suppressed"; + + + public static final String COMMON_FRAMES_COUNT_ATTR_NAME = "commonFramesCount"; + + public static final String CLASS_NAME_ATTR_NAME = "className"; + public static final String METHOD_NAME_ATTR_NAME = "methodName"; private static final String FILE_NAME_ATTR_NAME = "fileName"; private static final String LINE_NUMBER_ATTR_NAME = "lineNumber"; - private static final String STEP_ARRAY_NAME_ATTRIBUTE = "stepArray"; + public static final String STEP_ARRAY_NAME_ATTRIBUTE = "stepArray"; private static final char OPEN_OBJ = '{'; private static final char CLOSE_OBJ = '}'; @@ -139,7 +148,7 @@ public byte[] encode(ILoggingEvent event) { appendArgumentArray(sb, event); - appendThrowableProxy(sb, event); + appendThrowableProxy(sb, THROWABLE_ATTR_NAME, event.getThrowableProxy()); sb.append(CLOSE_OBJ); sb.append(CoreConstants.JSON_LINE_SEPARATOR); return sb.toString().getBytes(UTF_8_CHARSET); @@ -174,7 +183,6 @@ private void appendMap(StringBuilder sb, String attrName, Map ma sb.append(OPEN_OBJ); - boolean addComma = false; Set> entries = map.entrySet(); for(Map.Entry entry: entries) { @@ -186,18 +194,17 @@ private void appendMap(StringBuilder sb, String attrName, Map ma } sb.append(CLOSE_OBJ); - - - } - private void appendThrowableProxy(StringBuilder sb, ILoggingEvent event) { - IThrowableProxy itp = event.getThrowableProxy(); - sb.append(QUOTE).append(THROWABLE_ATTR_NAME).append(QUOTE_COL); - if (itp == null) { - sb.append(NULL_STR); - return; + private void appendThrowableProxy(StringBuilder sb, String attributeName, IThrowableProxy itp) { + + if(attributeName != null) { + sb.append(QUOTE).append(attributeName).append(QUOTE_COL); + if (itp == null) { + sb.append(NULL_STR); + return; + } } sb.append(OPEN_OBJ); @@ -206,13 +213,50 @@ private void appendThrowableProxy(StringBuilder sb, ILoggingEvent event) { sb.append(VALUE_SEPARATOR); appenderMember(sb, MESSAGE_ATTR_NAME, jsonEscape(itp.getMessage())); 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) { + sb.append(VALUE_SEPARATOR); + 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) { + if(first) { + first = false; + } else { + sb.append(VALUE_SEPARATOR); + } + appendThrowableProxy(sb, null, suppressedITP); + } + sb.append(CLOSE_ARRAY); + } + + + sb.append(CLOSE_OBJ); - StackTraceElementProxy[] stepArray = itp.getStackTraceElementProxyArray(); + } + 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; - for (int i = 0; i < len; i++) { + + if(commonFrames >= len) { + commonFrames = 0; + } + + for (int i = 0; i < len - commonFrames; i++) { if (i != 0) sb.append(VALUE_SEPARATOR); @@ -236,8 +280,6 @@ private void appendThrowableProxy(StringBuilder sb, ILoggingEvent event) { } sb.append(CLOSE_ARRAY); - sb.append(CLOSE_OBJ); - } private void appenderMember(StringBuilder sb, String key, String value) { diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/encoder/JsonEncoderTest.java b/logback-classic/src/test/java/ch/qos/logback/classic/encoder/JsonEncoderTest.java index edb9b78145..932cb5f166 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/encoder/JsonEncoderTest.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/encoder/JsonEncoderTest.java @@ -97,7 +97,7 @@ void smoke() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + //System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); @@ -113,7 +113,7 @@ void contextWithProperties() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + // System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); @@ -200,7 +200,7 @@ void withMarkers() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + //System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); @@ -212,7 +212,7 @@ void withArguments() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + //System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); @@ -227,7 +227,7 @@ void withKeyValuePairs() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + //System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); } @@ -248,7 +248,7 @@ void withMDC() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + //System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); } @@ -260,7 +260,38 @@ void withThrowable() throws JsonProcessingException { byte[] resultBytes = jsonEncoder.encode(event); String resultString = new String(resultBytes, StandardCharsets.UTF_8); - System.out.println(resultString); + JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); + compareEvents(event, resultEvent); + } + + @Test + void withThrowableHavingCause() throws JsonProcessingException { + Throwable cause = new IllegalStateException("test cause"); + + Throwable t = new RuntimeException("test", cause); + + + LoggingEvent event = new LoggingEvent("in withThrowableHavingCause test", logger, Level.WARN, "hello kvp", t, null); + + byte[] resultBytes = jsonEncoder.encode(event); + String resultString = new String(resultBytes, StandardCharsets.UTF_8); + //System.out.println(resultString); + JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); + compareEvents(event, resultEvent); + } + + @Test + void withThrowableHavingSuppressed() throws JsonProcessingException { + Throwable suppressed = new IllegalStateException("test suppressed"); + + Throwable t = new RuntimeException("test"); + t.addSuppressed(suppressed); + + LoggingEvent event = new LoggingEvent("in withThrowableHavingCause test", logger, Level.WARN, "hello kvp", t, null); + + byte[] resultBytes = jsonEncoder.encode(event); + String resultString = new String(resultBytes, StandardCharsets.UTF_8); + //System.out.println(resultString); JsonLoggingEvent resultEvent = stringToLoggingEventMapper.mapStringToLoggingEvent(resultString); compareEvents(event, resultEvent); } diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/JsonStringToLoggingEventMapper.java b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/JsonStringToLoggingEventMapper.java index ce2370ab21..d6b5cac3d2 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/JsonStringToLoggingEventMapper.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/JsonStringToLoggingEventMapper.java @@ -17,6 +17,7 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.encoder.JsonEncoder; import ch.qos.logback.classic.spi.LoggerContextVO; +import ch.qos.logback.classic.spi.PubThrowableProxy; import ch.qos.logback.classic.spi.StackTraceElementProxy; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.databind.JsonNode; @@ -47,6 +48,7 @@ public JsonLoggingEvent mapStringToLoggingEvent(String resultString) throws Json module.addDeserializer(Marker.class, new MarkerDeserializer(markerFactory)); module.addDeserializer(KeyValuePair.class, new KeyValuePairDeserializer()); module.addDeserializer(LoggerContextVO.class, new LoggerContextVODeserializer()); + module.addDeserializer(PubThrowableProxy.class, new PubThrowableProxyDeserializer()); objectMapper.registerModule(module); diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/PubThrowableProxyDeserializer.java b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/PubThrowableProxyDeserializer.java new file mode 100644 index 0000000000..71fd0ce84a --- /dev/null +++ b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/PubThrowableProxyDeserializer.java @@ -0,0 +1,110 @@ +/* + * Logback: the reliable, generic, fast and flexible logging framework. + * Copyright (C) 1999-2023, QOS.ch. All rights reserved. + * + * This program and the accompanying materials are dual-licensed under + * either the terms of the Eclipse Public License v1.0 as published by + * the Eclipse Foundation + * + * or (per the licensee's choosing) + * + * under the terms of the GNU Lesser General Public License version 2.1 + * as published by the Free Software Foundation. + */ + +package ch.qos.logback.classic.jsonTest; + +import ch.qos.logback.classic.encoder.JsonEncoder; +import ch.qos.logback.classic.spi.PubThrowableProxy; +import ch.qos.logback.classic.spi.StackTraceElementProxy; +import com.fasterxml.jackson.core.JacksonException; +import com.fasterxml.jackson.core.JsonParser; +import com.fasterxml.jackson.databind.DeserializationContext; +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.deser.std.StdDeserializer; + +import java.io.IOException; +import java.util.ArrayList; +import java.util.List; + +public class PubThrowableProxyDeserializer extends StdDeserializer { + + protected PubThrowableProxyDeserializer() { + this(null); + } + protected PubThrowableProxyDeserializer(Class vc) { + super(vc); + } + + @Override + public PubThrowableProxy deserialize(JsonParser jsonParser, DeserializationContext deserializationContext) + throws IOException, JacksonException { + JsonNode node = jsonParser.getCodec().readTree(jsonParser); + + return jsonNodeThrowableProxy(node); + } + + static StackTraceElementProxy[] EMPTY_STEP_ARRAY = new StackTraceElementProxy[0]; + static PubThrowableProxy[] EMPTY_PTP_ARRAY = new PubThrowableProxy[0]; + + private static PubThrowableProxy jsonNodeThrowableProxy(JsonNode node) { + JsonNode classNameJN = node.get(JsonEncoder.CLASS_NAME_ATTR_NAME); + JsonNode messageJN = node.get(JsonEncoder.MESSAGE_ATTR_NAME); + JsonNode stepArrayJN = node.get(JsonEncoder.STEP_ARRAY_NAME_ATTRIBUTE); + JsonNode causeJN = node.get(JsonEncoder.CAUSE_ATTR_NAME); + JsonNode commonFramesCountJN = node.get(JsonEncoder.COMMON_FRAMES_COUNT_ATTR_NAME); + + JsonNode suppressedJN = node.get(JsonEncoder.SUPPRESSED_ATTR_NAME); + + PubThrowableProxy ptp = new PubThrowableProxy(); + ptp.setClassName(classNameJN.textValue()); + ptp.setMessage(messageJN.textValue()); + + List stepList = stepNodeToList(stepArrayJN); + ptp.setStackTraceElementProxyArray(stepList.toArray(EMPTY_STEP_ARRAY)); + + if(commonFramesCountJN != null) { + int commonFramesCount = commonFramesCountJN.asInt(); + ptp.setCommonFramesCount(commonFramesCount); + } + + if(causeJN != null) { + PubThrowableProxy cause = jsonNodeThrowableProxy(causeJN); + ptp.setCause(cause); + } + + if(suppressedJN != null) { + //System.out.println("suppressedJN "+suppressedJN); + List ptpList = suppressedNodeToList(suppressedJN); + System.out.println("iiiiiiiiiiii"); + System.out.println("ptpList="+ptpList); + + ptp.setSuppressed(ptpList.toArray(EMPTY_PTP_ARRAY)); + } + + System.out.println("xxxxxxxxxxxxx"); + System.out.println(ptp.getSuppressed()); + + return ptp; + } + + private static List stepNodeToList(JsonNode stepArrayJN) { + List stepList = new ArrayList<>(); + for(JsonNode jsonNode: stepArrayJN) { + StackTraceElementProxy step = STEPDeserializer.jsonNodeToSTEP(jsonNode); + stepList.add(step); + } + return stepList; + } + + private static List suppressedNodeToList(JsonNode ptpArrayJN) { + List ptpList = new ArrayList<>(); + for(JsonNode jsonNode: ptpArrayJN) { + //System.out.println("---in suppressedNodeToList seeing "+jsonNode); + PubThrowableProxy ptp = jsonNodeThrowableProxy(jsonNode); + //System.out.println("--in suppressedNodeToList ptp="+ptp); + ptpList.add(ptp); + } + return ptpList; + } +} diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/STEPDeserializer.java b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/STEPDeserializer.java index 788d75ca82..a6056dc3d2 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/STEPDeserializer.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/STEPDeserializer.java @@ -38,6 +38,10 @@ public STEPDeserializer(Class vc) { public StackTraceElementProxy deserialize(JsonParser jp, DeserializationContext ctxt) throws IOException, JsonProcessingException { JsonNode node = jp.getCodec().readTree(jp); + return jsonNodeToSTEP(node); + } + + public static StackTraceElementProxy jsonNodeToSTEP(JsonNode node) { String className = node.get("className").asText(); String methodName = node.get("methodName").asText(); String fileName = node.get("fileName").asText(); diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/ThrowableProxyComparator.java b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/ThrowableProxyComparator.java index 3e951985da..14f0e57d4c 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/ThrowableProxyComparator.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/jsonTest/ThrowableProxyComparator.java @@ -39,41 +39,83 @@ static public boolean areEqual(IThrowableProxy left, IThrowableProxy right) { if(!left.getMessage().equals(right.getMessage())) return false; + System.out.println("before equalsSTEPArray left.message="+left.getMessage()+", right.message="+right.getMessage()); + StackTraceElementProxy[] leftStepArray = left.getStackTraceElementProxyArray(); StackTraceElementProxy[] rightStepArray = right.getStackTraceElementProxyArray(); - System.out.println("before equalsSTEPArray"); + if(left.getCommonFrames() != right.getCommonFrames()) { + return false; + } + + if(!equalsSTEPArray(leftStepArray, rightStepArray, left.getCommonFrames())) + return false; + + boolean causeComparaison = areEqual(left.getCause(), right.getCause()); + if(!causeComparaison) + return causeComparaison; + + if (!compareSuppressedThrowables(left, right)) + return false; + + return true; + } + + private static boolean compareSuppressedThrowables(IThrowableProxy left, IThrowableProxy right) { + IThrowableProxy[] leftSuppressedThrowableArray = left.getSuppressed(); + IThrowableProxy[] rightSuppressedThrowableArray = right.getSuppressed(); - if(!equalsSTEPArray(leftStepArray, rightStepArray)) + + //System.out.println("leftSuppressedThrowableArray="+leftSuppressedThrowableArray); + //System.out.println("rightSuppressedThrowableArray="+rightSuppressedThrowableArray); + + if(leftSuppressedThrowableArray == null && rightSuppressedThrowableArray == null) { + return true; + } + if(leftSuppressedThrowableArray.length == 0 && rightSuppressedThrowableArray == null) { + return true; + } + + if(leftSuppressedThrowableArray.length != rightSuppressedThrowableArray.length) { + System.out.println("suppressed array length discrepancy"); return false; + } + for(int i = 0; i < leftSuppressedThrowableArray.length; i++) { + IThrowableProxy leftSuppressed = leftSuppressedThrowableArray[i]; + IThrowableProxy rightSuppressed = rightSuppressedThrowableArray[i]; + boolean suppressedComparison = areEqual(leftSuppressed, rightSuppressed); + if(!suppressedComparison) { + System.out.println("suppressed ITP comparison failed at position "+i); + return false; + } + } return true; } - static public boolean equalsSTEPArray( StackTraceElementProxy[] leftStepArray, StackTraceElementProxy[] rightStepArray) { + static public boolean equalsSTEPArray( StackTraceElementProxy[] leftStepArray, StackTraceElementProxy[] rightStepArray, int commonFrames) { if (leftStepArray==rightStepArray) return true; if (leftStepArray==null || rightStepArray==null) return false; - int length = leftStepArray.length; + int length = leftStepArray.length - commonFrames; if (rightStepArray.length != length) { System.out.println("length discrepancy"); return false; } - System.out.println("checking ste array elements"); + System.out.println("checking ste array elements "); - for (int i=0; i