From c507b9bd26d73deb51f01e652f4b9ccdb73dae99 Mon Sep 17 00:00:00 2001 From: Raman Gupta Date: Thu, 1 Jul 2021 17:37:19 -0400 Subject: [PATCH 1/6] Google Cloud structured logging via JsonTemplate --- .../src/main/resources/GcpLayout.json | 64 ++++++++++++++++ .../layout/template/json/GcpLayoutTest.java | 76 +++++++++++++++++++ src/changes/changes.xml | 3 + .../manual/json-template-layout.adoc.vm | 9 +++ 4 files changed, 152 insertions(+) create mode 100644 log4j-layout-template-json/src/main/resources/GcpLayout.json create mode 100644 log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java diff --git a/log4j-layout-template-json/src/main/resources/GcpLayout.json b/log4j-layout-template-json/src/main/resources/GcpLayout.json new file mode 100644 index 00000000000..0bfb49bdce6 --- /dev/null +++ b/log4j-layout-template-json/src/main/resources/GcpLayout.json @@ -0,0 +1,64 @@ +{ + "timestamp": { + "$resolver": "timestamp", + "pattern": { + "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'", + "timeZone": "UTC", + "locale": "en_US" + } + }, + "severity": { + "$resolver": "pattern", + "pattern": "%level{WARN=WARNING, TRACE=DEBUG, FATAL=EMERGENCY}" + }, + "message": { + "$resolver": "pattern", + "pattern": "%m%xEx" + }, + "logging.googleapis.com/labels": { + "$resolver": "mdc" + }, + "logging.googleapis.com/sourceLocation": { + "file": { + "$resolver": "source", + "field": "fileName" + }, + "line": { + "$resolver": "source", + "field": "lineNumber" + }, + "function": { + "$resolver": "pattern", + "pattern": "%C.%M" + } + }, + "logging.googleapis.com/insertId": { + "$resolver": "pattern", + "pattern": "%sn" + }, + "_exception": { + "exception_class": { + "$resolver": "exception", + "field": "className" + }, + "exception_message": { + "$resolver": "exception", + "field": "message" + }, + "stacktrace": { + "$resolver": "exception", + "field": "stackTrace", + "stackTrace": { + "stringified": true + } + } + }, + "_thread": { + "$resolver": "thread", + "field": "name" + }, + "_logger": { + "$resolver": "logger", + "field": "name" + } +} diff --git a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java new file mode 100644 index 00000000000..1c0988c16bc --- /dev/null +++ b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java @@ -0,0 +1,76 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.layout.template.json; + +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.DefaultConfiguration; +import org.assertj.core.api.Assertions; +import org.junit.jupiter.api.Test; + +import java.nio.charset.Charset; +import java.nio.charset.StandardCharsets; +import java.util.Collection; +import java.util.List; +import java.util.Map; + +import static org.apache.logging.log4j.layout.template.json.TestHelpers.serializeUsingLayout; + +class GcpLayoutTest { + + private static final Configuration CONFIGURATION = new DefaultConfiguration(); + + private static final Charset CHARSET = StandardCharsets.UTF_8; + + private static final String SERVICE_NAME = "test"; + + private static final JsonTemplateLayout JSON_TEMPLATE_LAYOUT = JsonTemplateLayout + .newBuilder() + .setConfiguration(CONFIGURATION) + .setCharset(CHARSET) + .setEventTemplateUri("classpath:GcpLayout.json") + .build(); + + @Test + void test_lite_log_events() { + final List logEvents = LogEventFixture.createLiteLogEvents(1_000); + test(logEvents); + } + + @Test + void test_full_log_events() { + final List logEvents = LogEventFixture.createFullLogEvents(1_000); + test(logEvents); + } + + private static void test(final Collection logEvents) { + for (final LogEvent logEvent : logEvents) { + test(logEvent); + } + } + + private static void test(final LogEvent logEvent) { + final Map jsonTemplateLayoutMap = renderUsingJsonTemplateLayout(logEvent); + // for now, we just validate there are no errors + } + + private static Map renderUsingJsonTemplateLayout( + final LogEvent logEvent) { + return serializeUsingLayout(logEvent, JSON_TEMPLATE_LAYOUT); + } + +} diff --git a/src/changes/changes.xml b/src/changes/changes.xml index 6b35a21385c..f6ab2dc9d7a 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -31,6 +31,9 @@ --> + + Add JsonTemplateLayout for Google Cloud Platform structured logging layout. + Add CaseConverterResolver to JsonTemplateLayout. diff --git a/src/site/asciidoc/manual/json-template-layout.adoc.vm b/src/site/asciidoc/manual/json-template-layout.adoc.vm index 97e9a054aeb..d7279961f46 100644 --- a/src/site/asciidoc/manual/json-template-layout.adoc.vm +++ b/src/site/asciidoc/manual/json-template-layout.adoc.vm @@ -410,6 +410,15 @@ artifact, which contains the following predefined event templates: xref:additional-event-template-fields[additional event template fields] to avoid `hostName` property lookup at runtime, which incurs an extra cost.) +- https://github.com/apache/logging-log4j2/tree/master/log4j-layout-template-json/src/main/resources/GcpLayout.json[`GcpLayout.json`] + described by https://cloud.google.com/logging/docs/structured-logging[Google + Cloud Platform Structured logging] with additional + `_thread`, `_logger` and `_exception` fields. The exception trace, if any, + is written to the `_exception` field as well as the `message` field -- + the former is useful for explicitly searching/analyzing structured exception + information, while the latter is Google's expected place for the exception, + and integrates with Google Error Reporting. + - https://github.com/apache/logging-log4j2/tree/master/log4j-layout-template-json/src/main/resources/JsonLayout.json[`JsonLayout.json`] providing the exact JSON structure generated by link:layouts.html#JSONLayout[`JsonLayout`] with the exception of `thrown` field. (`JsonLayout` serializes the `Throwable` From 64e30255e42fe72fca7d311a807637d4548032a5 Mon Sep 17 00:00:00 2001 From: Raman Gupta Date: Mon, 5 Jul 2021 09:27:09 -0400 Subject: [PATCH 2/6] Minor code review updates MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Volkan Yazıcı --- src/changes/changes.xml | 2 +- src/site/asciidoc/manual/json-template-layout.adoc.vm | 6 +++--- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/changes/changes.xml b/src/changes/changes.xml index f6ab2dc9d7a..4f9133731a8 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -31,7 +31,7 @@ --> - + Add JsonTemplateLayout for Google Cloud Platform structured logging layout. diff --git a/src/site/asciidoc/manual/json-template-layout.adoc.vm b/src/site/asciidoc/manual/json-template-layout.adoc.vm index d7279961f46..d3d8f34e915 100644 --- a/src/site/asciidoc/manual/json-template-layout.adoc.vm +++ b/src/site/asciidoc/manual/json-template-layout.adoc.vm @@ -412,12 +412,12 @@ artifact, which contains the following predefined event templates: - https://github.com/apache/logging-log4j2/tree/master/log4j-layout-template-json/src/main/resources/GcpLayout.json[`GcpLayout.json`] described by https://cloud.google.com/logging/docs/structured-logging[Google - Cloud Platform Structured logging] with additional + Cloud Platform structured logging] with additional `_thread`, `_logger` and `_exception` fields. The exception trace, if any, - is written to the `_exception` field as well as the `message` field -- + is written to the `_exception` field as well as the `message` field – the former is useful for explicitly searching/analyzing structured exception information, while the latter is Google's expected place for the exception, - and integrates with Google Error Reporting. + and integrates with https://cloud.google.com/error-reporting[Google Error Reporting]. - https://github.com/apache/logging-log4j2/tree/master/log4j-layout-template-json/src/main/resources/JsonLayout.json[`JsonLayout.json`] providing the exact JSON structure generated by link:layouts.html#JSONLayout[`JsonLayout`] From 81aa8dbcef3b3999496dffd6ae605c6624e46fd1 Mon Sep 17 00:00:00 2001 From: Raman Gupta Date: Wed, 7 Jul 2021 10:27:50 -0400 Subject: [PATCH 3/6] GCP layout test enhancement and stack trace fixes --- .../src/main/resources/GcpLayout.json | 12 ++- .../layout/template/json/GcpLayoutTest.java | 95 ++++++++++++++++++- 2 files changed, 99 insertions(+), 8 deletions(-) diff --git a/log4j-layout-template-json/src/main/resources/GcpLayout.json b/log4j-layout-template-json/src/main/resources/GcpLayout.json index 0bfb49bdce6..a452f558a11 100644 --- a/log4j-layout-template-json/src/main/resources/GcpLayout.json +++ b/log4j-layout-template-json/src/main/resources/GcpLayout.json @@ -9,11 +9,13 @@ }, "severity": { "$resolver": "pattern", - "pattern": "%level{WARN=WARNING, TRACE=DEBUG, FATAL=EMERGENCY}" + "pattern": "%level{WARN=WARNING, TRACE=DEBUG, FATAL=EMERGENCY}", + "stackTraceEnabled": false }, "message": { "$resolver": "pattern", - "pattern": "%m%xEx" + "pattern": "%m", + "stackTraceEnabled": true }, "logging.googleapis.com/labels": { "$resolver": "mdc" @@ -29,12 +31,14 @@ }, "function": { "$resolver": "pattern", - "pattern": "%C.%M" + "pattern": "%C.%M", + "stackTraceEnabled": false } }, "logging.googleapis.com/insertId": { "$resolver": "pattern", - "pattern": "%sn" + "pattern": "%sn", + "stackTraceEnabled": false }, "_exception": { "exception_class": { diff --git a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java index 1c0988c16bc..f36263ac491 100644 --- a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java +++ b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java @@ -16,17 +16,22 @@ */ package org.apache.logging.log4j.layout.template.json; +import com.google.common.base.Charsets; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.DefaultConfiguration; +import org.apache.logging.log4j.core.impl.ThrowableProxy; +import org.apache.logging.log4j.util.SortedArrayStringMap; import org.assertj.core.api.Assertions; import org.junit.jupiter.api.Test; +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.io.UnsupportedEncodingException; import java.nio.charset.Charset; import java.nio.charset.StandardCharsets; -import java.util.Collection; -import java.util.List; -import java.util.Map; +import java.time.Instant; +import java.util.*; import static org.apache.logging.log4j.layout.template.json.TestHelpers.serializeUsingLayout; @@ -63,9 +68,78 @@ private static void test(final Collection logEvents) { } } + @SuppressWarnings("rawtypes") private static void test(final LogEvent logEvent) { final Map jsonTemplateLayoutMap = renderUsingJsonTemplateLayout(logEvent); - // for now, we just validate there are no errors + Assertions.assertThat(Instant.parse(jsonTemplateLayoutMap.get("timestamp").toString()).toEpochMilli()) + .isEqualTo(logEvent.getTimeMillis()); + Assertions.assertThat(jsonTemplateLayoutMap.get("severity")).isEqualTo(logEvent.getLevel().toString()); + Assertions.assertThat(jsonTemplateLayoutMap.get("_logger")).isEqualTo(logEvent.getLoggerName()); + Assertions.assertThat(jsonTemplateLayoutMap.get("_thread").toString()) + .isEqualTo(logEvent.getThreadName()); + + if (logEvent.getContextData().size() == 0) { + Assertions.assertThat(jsonTemplateLayoutMap.get("logging.googleapis.com/labels")) + .isNull(); + } else { + Assertions.assertThat(logEvent.getContextData().toMap().keySet()) + .isEqualTo(((Map)jsonTemplateLayoutMap.get("logging.googleapis.com/labels")).keySet()); + logEvent.getContextData().toMap().keySet().forEach(k -> { + Assertions.assertThat((Object) logEvent.getContextData().getValue(k)) + .isEqualTo(((Map)jsonTemplateLayoutMap.get("logging.googleapis.com/labels")).get(k)); + }); + } + + if (logEvent.getSource() == null) { + // not quite sure why the output has "?." in sourceLocation.function + //Assertions.assertThat(jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")) + // .isNull(); + } else { + if (logEvent.getSource().getFileName() == null || !logEvent.isIncludeLocation()) { + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("file")) + .isNull(); + } else { + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("file")) + .isEqualTo(logEvent.getSource().getFileName()); + } + if (logEvent.getSource().getLineNumber() < 0 || !logEvent.isIncludeLocation()) { + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("line")) + .isNull(); + } else { + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("line")) + .isEqualTo(logEvent.getSource().getLineNumber()); + } + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("function")) + .isEqualTo(logEvent.getSource().getClassName() + "." + logEvent.getSource().getMethodName()); + } + + // NOTE: no access to serial number in logEvent + if (logEvent.getThrown() == null) { + Assertions.assertThat(jsonTemplateLayoutMap.get("_exception")) + .isNull(); + Assertions.assertThat(jsonTemplateLayoutMap.get("message")) + .isEqualTo(logEvent.getMessage().toString()); + } else { + // the message field includes class packaging information as it uses the %xEx pattern, + // this fails as extendedStackTrace is truncated for some reason + //String extendedStackTrace = logEvent.getThrownProxy().getExtendedStackTraceAsString(); + //Assertions.assertThat(jsonTemplateLayoutMap.get("message")) + // .isEqualTo(logEvent.getMessage().toString() + " " + extendedStackTrace); + + // for now, just compare the first line and that we have multiple stack trace lines + String[] messageLines = jsonTemplateLayoutMap.get("message").toString().split(System.lineSeparator()); + Assertions.assertThat(messageLines[0]) + .isEqualTo(logEvent.getMessage().toString() + " " + logEvent.getThrown().getClass().getName() + ": " + logEvent.getThrown().getMessage()); + Assertions.assertThat(messageLines.length) + .isGreaterThan(1); + + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("_exception")).get("exception_class")) + .isEqualTo(logEvent.getThrown().getClass().getName()); + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("_exception")).get("exception_message")) + .isEqualTo(logEvent.getThrown().getMessage()); + Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("_exception")).get("stacktrace")) + .isEqualTo(serializeStackTrace(Charsets.UTF_8, logEvent.getThrown())); + } } private static Map renderUsingJsonTemplateLayout( @@ -73,4 +147,17 @@ private static Map renderUsingJsonTemplateLayout( return serializeUsingLayout(logEvent, JSON_TEMPLATE_LAYOUT); } + private static String serializeStackTrace( + final Charset charset, + final Throwable exception) { + final ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); + final String charsetName = charset.name(); + try (final PrintStream printStream = + new PrintStream(outputStream, false, charsetName)) { + exception.printStackTrace(printStream); + return outputStream.toString(charsetName); + } catch (final UnsupportedEncodingException error) { + throw new RuntimeException("failed converting the stack trace to string", error); + } + } } From cc95baa24e03e56b68a70e8ea6119befc3d37206 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Tue, 20 Jul 2021 09:19:25 +0200 Subject: [PATCH 4/6] LOG4J2-3116 Fix changes.xml typo. --- src/changes/changes.xml | 1 + 1 file changed, 1 insertion(+) diff --git a/src/changes/changes.xml b/src/changes/changes.xml index 1ba6b37848d..d485598496a 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -33,6 +33,7 @@ Add JsonTemplateLayout for Google Cloud Platform structured logging layout. + Add CounterResolver to JsonTemplateLayout. From 3efc5dacddda237a0cb36672d8a48514305a2ab0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Tue, 20 Jul 2021 09:20:35 +0200 Subject: [PATCH 5/6] LOG4J2-3116 Massage GcpLayout more. --- .../src/main/resources/GcpLayout.json | 23 ++++++++----------- 1 file changed, 10 insertions(+), 13 deletions(-) diff --git a/log4j-layout-template-json/src/main/resources/GcpLayout.json b/log4j-layout-template-json/src/main/resources/GcpLayout.json index a452f558a11..563e5a2fc3c 100644 --- a/log4j-layout-template-json/src/main/resources/GcpLayout.json +++ b/log4j-layout-template-json/src/main/resources/GcpLayout.json @@ -18,7 +18,8 @@ "stackTraceEnabled": true }, "logging.googleapis.com/labels": { - "$resolver": "mdc" + "$resolver": "mdc", + "stringified": true }, "logging.googleapis.com/sourceLocation": { "file": { @@ -31,30 +32,26 @@ }, "function": { "$resolver": "pattern", - "pattern": "%C.%M", + "pattern": "%replace{%C.%M}{^\\?\\.$}{}", "stackTraceEnabled": false } }, "logging.googleapis.com/insertId": { - "$resolver": "pattern", - "pattern": "%sn", - "stackTraceEnabled": false + "$resolver": "counter", + "stringified": true }, "_exception": { - "exception_class": { + "class": { "$resolver": "exception", "field": "className" }, - "exception_message": { + "message": { "$resolver": "exception", "field": "message" }, - "stacktrace": { - "$resolver": "exception", - "field": "stackTrace", - "stackTrace": { - "stringified": true - } + "stackTrace": { + "$resolver": "pattern", + "pattern": "%xEx" } }, "_thread": { From 5ea3d851090c9b83623a59ec909da51ed8131274 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Volkan=20Yaz=C4=B1c=C4=B1?= Date: Tue, 20 Jul 2021 09:27:57 +0200 Subject: [PATCH 6/6] LOG4J2-3116 Overhaul GcpLayoutTest. --- .../layout/template/json/GcpLayoutTest.java | 258 ++++++++++-------- 1 file changed, 145 insertions(+), 113 deletions(-) diff --git a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java index f36263ac491..b7c149777cd 100644 --- a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java +++ b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/GcpLayoutTest.java @@ -16,148 +16,180 @@ */ package org.apache.logging.log4j.layout.template.json; -import com.google.common.base.Charsets; +import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.LogEvent; -import org.apache.logging.log4j.core.config.Configuration; -import org.apache.logging.log4j.core.config.DefaultConfiguration; -import org.apache.logging.log4j.core.impl.ThrowableProxy; -import org.apache.logging.log4j.util.SortedArrayStringMap; -import org.assertj.core.api.Assertions; import org.junit.jupiter.api.Test; -import java.io.ByteArrayOutputStream; -import java.io.PrintStream; -import java.io.UnsupportedEncodingException; -import java.nio.charset.Charset; -import java.nio.charset.StandardCharsets; import java.time.Instant; -import java.util.*; +import java.time.ZoneId; +import java.time.ZonedDateTime; +import java.time.format.DateTimeFormatter; +import java.util.Locale; -import static org.apache.logging.log4j.layout.template.json.TestHelpers.serializeUsingLayout; +import static org.apache.logging.log4j.layout.template.json.TestHelpers.CONFIGURATION; +import static org.apache.logging.log4j.layout.template.json.TestHelpers.usingSerializedLogEventAccessor; +import static org.assertj.core.api.Assertions.assertThat; class GcpLayoutTest { - private static final Configuration CONFIGURATION = new DefaultConfiguration(); - - private static final Charset CHARSET = StandardCharsets.UTF_8; - - private static final String SERVICE_NAME = "test"; - - private static final JsonTemplateLayout JSON_TEMPLATE_LAYOUT = JsonTemplateLayout + private static final JsonTemplateLayout LAYOUT = JsonTemplateLayout .newBuilder() .setConfiguration(CONFIGURATION) - .setCharset(CHARSET) + .setStackTraceEnabled(true) + .setLocationInfoEnabled(true) .setEventTemplateUri("classpath:GcpLayout.json") .build(); + private static final int LOG_EVENT_COUNT = 1_000; + + private static final DateTimeFormatter DATE_TIME_FORMATTER = + DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'", Locale.US); + @Test void test_lite_log_events() { - final List logEvents = LogEventFixture.createLiteLogEvents(1_000); - test(logEvents); + LogEventFixture + .createLiteLogEvents(LOG_EVENT_COUNT) + .forEach(GcpLayoutTest::verifySerialization); } @Test void test_full_log_events() { - final List logEvents = LogEventFixture.createFullLogEvents(1_000); - test(logEvents); + LogEventFixture + .createFullLogEvents(LOG_EVENT_COUNT) + .forEach(GcpLayoutTest::verifySerialization); } - private static void test(final Collection logEvents) { - for (final LogEvent logEvent : logEvents) { - test(logEvent); - } - } + private static void verifySerialization(final LogEvent logEvent) { + usingSerializedLogEventAccessor(LAYOUT, logEvent, accessor -> { + + // Verify timestamp. + final String expectedTimestamp = formatLogEventInstant(logEvent); + assertThat(accessor.getString("timestamp")).isEqualTo(expectedTimestamp); + + // Verify severity. + final Level level = logEvent.getLevel(); + final String expectedSeverity; + if (Level.WARN.equals(level)) { + expectedSeverity = "WARNING"; + } else if (Level.TRACE.equals(level)) { + expectedSeverity = "TRACE"; + } else if (Level.FATAL.equals(level)) { + expectedSeverity = "EMERGENCY"; + } else { + expectedSeverity = level.name(); + } + assertThat(accessor.getString("severity")).isEqualTo(expectedSeverity); + + // Verify message. + final Throwable exception = logEvent.getThrown(); + if (exception != null) { + final String actualMessage = accessor.getString("message"); + assertThat(actualMessage) + .contains(logEvent.getMessage().getFormattedMessage()) + .contains(exception.getLocalizedMessage()) + .contains("at org.apache.logging.log4j.layout.template.json") + .contains("at java.lang.reflect.Method") + .contains("at org.junit.platform.engine"); + } - @SuppressWarnings("rawtypes") - private static void test(final LogEvent logEvent) { - final Map jsonTemplateLayoutMap = renderUsingJsonTemplateLayout(logEvent); - Assertions.assertThat(Instant.parse(jsonTemplateLayoutMap.get("timestamp").toString()).toEpochMilli()) - .isEqualTo(logEvent.getTimeMillis()); - Assertions.assertThat(jsonTemplateLayoutMap.get("severity")).isEqualTo(logEvent.getLevel().toString()); - Assertions.assertThat(jsonTemplateLayoutMap.get("_logger")).isEqualTo(logEvent.getLoggerName()); - Assertions.assertThat(jsonTemplateLayoutMap.get("_thread").toString()) - .isEqualTo(logEvent.getThreadName()); - - if (logEvent.getContextData().size() == 0) { - Assertions.assertThat(jsonTemplateLayoutMap.get("logging.googleapis.com/labels")) - .isNull(); - } else { - Assertions.assertThat(logEvent.getContextData().toMap().keySet()) - .isEqualTo(((Map)jsonTemplateLayoutMap.get("logging.googleapis.com/labels")).keySet()); - logEvent.getContextData().toMap().keySet().forEach(k -> { - Assertions.assertThat((Object) logEvent.getContextData().getValue(k)) - .isEqualTo(((Map)jsonTemplateLayoutMap.get("logging.googleapis.com/labels")).get(k)); + // Verify labels. + logEvent.getContextData().forEach((key, value) -> { + final String expectedValue = String.valueOf(value); + final String actualValue = + accessor.getString(new String[]{ + "logging.googleapis.com/labels", key}); + assertThat(actualValue).isEqualTo(expectedValue); }); - } - - if (logEvent.getSource() == null) { - // not quite sure why the output has "?." in sourceLocation.function - //Assertions.assertThat(jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")) - // .isNull(); - } else { - if (logEvent.getSource().getFileName() == null || !logEvent.isIncludeLocation()) { - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("file")) - .isNull(); + + final StackTraceElement source = logEvent.getSource(); + if (source != null) { + + // Verify file name. + final String actualFileName = + accessor.getString(new String[]{ + "logging.googleapis.com/sourceLocation", "file"}); + assertThat(actualFileName).isEqualTo(source.getFileName()); + + // Verify line number. + final int actualLineNumber = + accessor.getInteger(new String[]{ + "logging.googleapis.com/sourceLocation", "line"}); + assertThat(actualLineNumber).isEqualTo(source.getLineNumber()); + + // Verify function. + final String expectedFunction = + source.getClassName() + "." + source.getMethodName(); + final String actualFunction = + accessor.getString(new String[]{ + "logging.googleapis.com/sourceLocation", "function"}); + assertThat(actualFunction).isEqualTo(expectedFunction); + } else { - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("file")) - .isEqualTo(logEvent.getSource().getFileName()); + assertThat(accessor.exists( + new String[]{"logging.googleapis.com/sourceLocation", "file"})) + .isFalse(); + assertThat(accessor.exists( + new String[]{"logging.googleapis.com/sourceLocation", "line"})) + .isFalse(); + assertThat(accessor.getString( + new String[]{"logging.googleapis.com/sourceLocation", "function"})) + .isEmpty(); } - if (logEvent.getSource().getLineNumber() < 0 || !logEvent.isIncludeLocation()) { - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("line")) - .isNull(); + + // Verify insert id. + assertThat(accessor.getString("logging.googleapis.com/insertId")) + .matches("[-]?[0-9]+"); + + // Verify exception. + if (exception != null) { + + // Verify exception class. + assertThat(accessor.getString( + new String[]{"_exception", "class"})) + .isEqualTo(exception.getClass().getCanonicalName()); + + // Verify exception message. + assertThat(accessor.getString( + new String[]{"_exception", "message"})) + .isEqualTo(exception.getMessage()); + + // Verify exception stack trace. + assertThat(accessor.getString( + new String[]{"_exception", "stackTrace"})) + .contains(exception.getLocalizedMessage()) + .contains("at org.apache.logging.log4j.layout.template.json") + .contains("at java.lang.reflect.Method") + .contains("at org.junit.platform.engine"); + } else { - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("line")) - .isEqualTo(logEvent.getSource().getLineNumber()); + assertThat(accessor.getObject( + new String[]{"_exception", "class"})) + .isNull(); + assertThat(accessor.getObject( + new String[]{"_exception", "message"})) + .isNull(); + assertThat(accessor.getString( + new String[]{"_exception", "stackTrace"})) + .isEmpty(); } - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("logging.googleapis.com/sourceLocation")).get("function")) - .isEqualTo(logEvent.getSource().getClassName() + "." + logEvent.getSource().getMethodName()); - } - - // NOTE: no access to serial number in logEvent - if (logEvent.getThrown() == null) { - Assertions.assertThat(jsonTemplateLayoutMap.get("_exception")) - .isNull(); - Assertions.assertThat(jsonTemplateLayoutMap.get("message")) - .isEqualTo(logEvent.getMessage().toString()); - } else { - // the message field includes class packaging information as it uses the %xEx pattern, - // this fails as extendedStackTrace is truncated for some reason - //String extendedStackTrace = logEvent.getThrownProxy().getExtendedStackTraceAsString(); - //Assertions.assertThat(jsonTemplateLayoutMap.get("message")) - // .isEqualTo(logEvent.getMessage().toString() + " " + extendedStackTrace); - - // for now, just compare the first line and that we have multiple stack trace lines - String[] messageLines = jsonTemplateLayoutMap.get("message").toString().split(System.lineSeparator()); - Assertions.assertThat(messageLines[0]) - .isEqualTo(logEvent.getMessage().toString() + " " + logEvent.getThrown().getClass().getName() + ": " + logEvent.getThrown().getMessage()); - Assertions.assertThat(messageLines.length) - .isGreaterThan(1); - - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("_exception")).get("exception_class")) - .isEqualTo(logEvent.getThrown().getClass().getName()); - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("_exception")).get("exception_message")) - .isEqualTo(logEvent.getThrown().getMessage()); - Assertions.assertThat(((Map) jsonTemplateLayoutMap.get("_exception")).get("stacktrace")) - .isEqualTo(serializeStackTrace(Charsets.UTF_8, logEvent.getThrown())); - } - } - private static Map renderUsingJsonTemplateLayout( - final LogEvent logEvent) { - return serializeUsingLayout(logEvent, JSON_TEMPLATE_LAYOUT); + // Verify thread name. + assertThat(accessor.getString("_thread")) + .isEqualTo(logEvent.getThreadName()); + + // Verify logger name. + assertThat(accessor.getString("_logger")) + .isEqualTo(logEvent.getLoggerName()); + + }); } - private static String serializeStackTrace( - final Charset charset, - final Throwable exception) { - final ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); - final String charsetName = charset.name(); - try (final PrintStream printStream = - new PrintStream(outputStream, false, charsetName)) { - exception.printStackTrace(printStream); - return outputStream.toString(charsetName); - } catch (final UnsupportedEncodingException error) { - throw new RuntimeException("failed converting the stack trace to string", error); - } + private static String formatLogEventInstant(final LogEvent logEvent) { + org.apache.logging.log4j.core.time.Instant instant = logEvent.getInstant(); + ZonedDateTime dateTime = Instant.ofEpochSecond( + instant.getEpochSecond(), + instant.getNanoOfSecond()).atZone(ZoneId.of("UTC")); + return DATE_TIME_FORMATTER.format(dateTime); } + }