Skip to content

LOG4J2-3116 Google Cloud structured logging via JsonTemplate #543

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 7 commits into from
Jul 20, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 65 additions & 0 deletions log4j-layout-template-json/src/main/resources/GcpLayout.json
Original file line number Diff line number Diff line change
@@ -0,0 +1,65 @@
{
"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}",
"stackTraceEnabled": false
},
"message": {
"$resolver": "pattern",
"pattern": "%m",
"stackTraceEnabled": true
},
"logging.googleapis.com/labels": {
"$resolver": "mdc",
"stringified": true
},
"logging.googleapis.com/sourceLocation": {
"file": {
"$resolver": "source",
"field": "fileName"
},
"line": {
"$resolver": "source",
"field": "lineNumber"
},
"function": {
"$resolver": "pattern",
"pattern": "%replace{%C.%M}{^\\?\\.$}{}",
"stackTraceEnabled": false
}
},
"logging.googleapis.com/insertId": {
"$resolver": "counter",
"stringified": true
},
"_exception": {
"class": {
"$resolver": "exception",
"field": "className"
},
"message": {
"$resolver": "exception",
"field": "message"
},
"stackTrace": {
"$resolver": "pattern",
"pattern": "%xEx"
}
},
"_thread": {
"$resolver": "thread",
"field": "name"
},
"_logger": {
"$resolver": "logger",
"field": "name"
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,195 @@
/*
* 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.Level;
import org.apache.logging.log4j.core.LogEvent;
import org.junit.jupiter.api.Test;

import java.time.Instant;
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.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 JsonTemplateLayout LAYOUT = JsonTemplateLayout
.newBuilder()
.setConfiguration(CONFIGURATION)
.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() {
LogEventFixture
.createLiteLogEvents(LOG_EVENT_COUNT)
.forEach(GcpLayoutTest::verifySerialization);
}

@Test
void test_full_log_events() {
LogEventFixture
.createFullLogEvents(LOG_EVENT_COUNT)
.forEach(GcpLayoutTest::verifySerialization);
}

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");
}

// 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);
});

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 {
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();
}

// 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 {
assertThat(accessor.getObject(
new String[]{"_exception", "class"}))
.isNull();
assertThat(accessor.getObject(
new String[]{"_exception", "message"}))
.isNull();
assertThat(accessor.getString(
new String[]{"_exception", "stackTrace"}))
.isEmpty();
}

// Verify thread name.
assertThat(accessor.getString("_thread"))
.isEqualTo(logEvent.getThreadName());

// Verify logger name.
assertThat(accessor.getString("_logger"))
.isEqualTo(logEvent.getLoggerName());

});
}

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);
}

}
3 changes: 3 additions & 0 deletions src/changes/changes.xml
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,9 @@
-->
<release version="2.15.0" date="2021-MM-DD" description="GA Release 2.15.0">
<!-- ADDS -->
<action issue="LOG4J2-3116" dev="rgupta" type="add">
Add JsonTemplateLayout for Google Cloud Platform structured logging layout.
</action>
<action issue="LOG4J2-3067" dev="vy" type="add">
Add CounterResolver to JsonTemplateLayout.
</action>
Expand Down
9 changes: 9 additions & 0 deletions src/site/asciidoc/manual/json-template-layout.adoc.vm
Original file line number Diff line number Diff line change
Expand Up @@ -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 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`]
with the exception of `thrown` field. (`JsonLayout` serializes the `Throwable`
Expand Down