Skip to content

Commit

Permalink
Serialize stack traces in error.stack_trace
Browse files Browse the repository at this point in the history
depends on elastic/ecs#562
  • Loading branch information
felixbarny committed Sep 18, 2019
1 parent 7e441fb commit 3bce698
Show file tree
Hide file tree
Showing 14 changed files with 328 additions and 78 deletions.
8 changes: 5 additions & 3 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -69,10 +69,12 @@ We recommend using this library to log into a JSON log file and let Filebeat sen
|ECS field | Log4j2 API |
|----------|-------------|
|[`@timestamp`](https://www.elastic.co/guide/en/ecs/current/ecs-base.html) | [`LogEvent#getTimeMillis()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getTimeMillis()) |
| [`log.level`](https://www.elastic.co/guide/en/ecs/current/ecs-log.html) | [`LogEvent#getLevel()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getLevel()) |
|[`log.logger`](https://www.elastic.co/guide/en/ecs/current/ecs-log.html)|[`LogEvent#getLoggerName(`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getLoggerName())|
|[`log.level`](https://www.elastic.co/guide/en/ecs/current/ecs-log.html) | [`LogEvent#getLevel()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getLevel()) |
|[`log.logger`](https://www.elastic.co/guide/en/ecs/current/ecs-log.html)|[`LogEvent#getLoggerName()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getLoggerName())|
|[`message`](https://www.elastic.co/guide/en/ecs/current/ecs-base.html)|[`LogEvent#getMessage()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getMessage())|
|[`message`](https://www.elastic.co/guide/en/ecs/current/ecs-base.html)|[`LogEvent#getThrown()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getThrown())|
|[`error.code`](https://www.elastic.co/guide/en/ecs/current/ecs-error.html)|[`Throwable#getClass()`](https://docs.oracle.com/javase/7/docs/api/java/lang/Object.html#getClass())|
|[`error.message`](https://www.elastic.co/guide/en/ecs/current/ecs-error.html)|[`Throwable#getStackTrace()`](https://docs.oracle.com/javase/7/docs/api/java/lang/Throwable.html#getMessage())|
|[`error.stack_trace`](https://www.elastic.co/guide/en/ecs/current/ecs-error.html)|[`Throwable#getStackTrace()`](https://docs.oracle.com/javase/7/docs/api/java/lang/Throwable.html#getStackTrace())|
|[`process.thread.name`](https://www.elastic.co/guide/en/ecs/current/ecs-process.html)|[`LogEvent#getThreadName()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getThreadName()) |
|[`labels`](https://www.elastic.co/guide/en/ecs/current/ecs-base.html)|[`LogEvent#getContextMap()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getContextMap())|
|[`tags`](https://www.elastic.co/guide/en/ecs/current/ecs-base.html)|[`LogEvent#getContextStack()`](https://logging.apache.org/log4j/log4j-2.3/log4j-core/apidocs/org/apache/logging/log4j/core/LogEvent.html#getContextStack())|
Expand Down
163 changes: 150 additions & 13 deletions ecs-logging-core/src/main/java/co/elastic/logging/EcsJsonSerializer.java
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@
package co.elastic.logging;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.io.Writer;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
Expand All @@ -35,6 +35,8 @@ public class EcsJsonSerializer {

public static final List<String> DEFAULT_TOP_LEVEL_LABELS = Arrays.asList("trace.id", "transaction.id", "span.id", "error.id", "service.name");
private static final TimestampSerializer TIMESTAMP_SERIALIZER = new TimestampSerializer();
private static final ThreadLocal<StringBuilder> messageStringBuilder = new ThreadLocal<StringBuilder>();
private static final String NEW_LINE = System.getProperty("line.separator");

public static CharSequence toNullSafeString(final CharSequence s) {
return s == null ? "" : s;
Expand All @@ -48,8 +50,7 @@ public static void serializeObjectStart(StringBuilder builder, long timeMillis)
}

public static void serializeObjectEnd(StringBuilder builder) {
// last char is always a comma (,)
builder.setLength(builder.length() - 1);
removeIfEndsWith(builder, ",");
builder.append('}');
builder.append('\n');
}
Expand All @@ -68,13 +69,9 @@ public static void serializeThreadName(StringBuilder builder, String threadName)
}
}

public static void serializeFormattedMessage(StringBuilder builder, String message, Throwable t) {
public static void serializeFormattedMessage(StringBuilder builder, String message) {
builder.append("\"message\":\"");
JsonUtils.quoteAsString(message, builder);
if (t != null) {
builder.append("\\n");
JsonUtils.quoteAsString(formatThrowable(t), builder);
}
builder.append("\", ");
}

Expand Down Expand Up @@ -138,22 +135,162 @@ public static void serializeLabels(StringBuilder builder, Map<String, ?> labels,
}
}

public static void serializeException(StringBuilder builder, Throwable thrown) {
public static void serializeException(StringBuilder builder, Throwable thrown, boolean stackTraceAsArray) {
if (thrown != null) {
builder.append("\"error.code\":\"");
JsonUtils.quoteAsString(thrown.getClass().getName(), builder);
builder.append("\",");
builder.append("\"error.message\":\"");
JsonUtils.quoteAsString(formatThrowable(thrown), builder);
JsonUtils.quoteAsString(thrown.getMessage(), builder);
builder.append("\",");
if (stackTraceAsArray) {
builder.append("\"error.stack_trace\":[").append(NEW_LINE);
formatThrowableAsArray(builder, thrown);
builder.append(NEW_LINE).append("]");
} else {
builder.append("\"error.stack_trace\":\"");
JsonUtils.quoteAsString(formatThrowable(thrown), builder);
builder.append("\"");
}
}
}

public static void serializeException(StringBuilder builder, String exceptionClassName, String exceptionMessage, String stackTrace, boolean stackTraceAsArray) {
builder.append("\"error.code\":\"");
JsonUtils.quoteAsString(exceptionClassName, builder);
builder.append("\",");
builder.append("\"error.message\":\"");
JsonUtils.quoteAsString(exceptionMessage, builder);
builder.append("\",");
if (stackTraceAsArray) {
builder.append("\"error.stack_trace\":[").append(NEW_LINE);
for (String line : stackTrace.split("\\n")) {
appendQuoted(builder, line);
}
builder.append(NEW_LINE).append("]");
} else {
builder.append("\"error.stack_trace\":\"");
JsonUtils.quoteAsString(stackTrace, builder);
builder.append("\"");
}
}

private static void appendQuoted(StringBuilder builder, CharSequence content) {
builder.append('"');
JsonUtils.quoteAsString(content, builder);
builder.append('"');
}

private static CharSequence formatThrowable(final Throwable throwable) {
StringWriter sw = new StringWriter(2048);
final PrintWriter pw = new PrintWriter(sw);
StringBuilder buffer = getMessageStringBuilder();
final PrintWriter pw = new PrintWriter(new StringBuilderWriter(buffer));
throwable.printStackTrace(pw);
pw.flush();
return sw.toString();
return buffer;
}

private static void formatThrowableAsArray(final StringBuilder jsonBuilder, final Throwable throwable) {
final StringBuilder buffer = getMessageStringBuilder();
final PrintWriter pw = new PrintWriter(new StringBuilderWriter(buffer), true) {
@Override
public void println() {
flush();
jsonBuilder.append("\t\"");
JsonUtils.quoteAsString(buffer, jsonBuilder);
jsonBuilder.append("\",");
jsonBuilder.append(NEW_LINE);
buffer.setLength(0);
}
};
throwable.printStackTrace(pw);
removeIfEndsWith(jsonBuilder, NEW_LINE);
removeIfEndsWith(jsonBuilder, ",");
}

public static void removeIfEndsWith(StringBuilder sb, String ending) {
if (endsWith(sb, ending)) {
sb.setLength(sb.length() - ending.length());
}
}

public static boolean endsWith(StringBuilder sb, String ending) {
int endingLength = ending.length();
int startIndex = sb.length() - endingLength;
if (startIndex < 0) {
return false;
}
for (int i = 0; i < endingLength; i++) {
if (sb.charAt(startIndex + i) != ending.charAt(i)) {
return false;
}
}
return true;
}

public static StringBuilder getMessageStringBuilder() {
StringBuilder result = messageStringBuilder.get();
if (result == null) {
result = new StringBuilder(1024);
messageStringBuilder.set(result);
}
result.setLength(0);
return result;
}

private static class StringBuilderWriter extends Writer {

private final StringBuilder buffer;

StringBuilderWriter(StringBuilder buffer) {
this.buffer = buffer;
}

@Override
public Writer append(CharSequence csq) {
buffer.append(csq);
return this;
}

@Override
public void write(String str) {
buffer.append(str);
}

@Override
public void write(String str, int off, int len) {
buffer.append(str, off, len);
}

@Override
public Writer append(CharSequence csq, int start, int end) {
buffer.append(csq, start, end);
return this;
}

@Override
public Writer append(char c) {
buffer.append(c);
return this;
}

@Override
public void write(int c) {
buffer.append((char) c);
}

@Override
public void write(char[] cbuf, int off, int len) {
buffer.append(cbuf, off, len);
}

@Override
public void flush() {

}

@Override
public void close() {

}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -27,16 +27,13 @@

import com.fasterxml.jackson.databind.JsonNode;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.assertj.core.data.TemporalOffset;
import org.junit.jupiter.api.Disabled;
import org.junit.jupiter.api.Test;

import java.io.IOException;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.time.Duration;
import java.time.Instant;
import java.time.temporal.ChronoUnit;
import java.util.stream.Collectors;
import java.util.stream.StreamSupport;

import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.within;
Expand Down Expand Up @@ -88,7 +85,12 @@ void testTopLevelLabels() throws Exception {
void testLogException() throws Exception {
error("test", new RuntimeException("test"));
assertThat(getLastLogLine().get("log.level").textValue()).isEqualTo("ERROR");
assertThat(getLastLogLine().get("message").textValue()).contains("at co.elastic.logging.AbstractEcsLoggingTest.testLogException");
assertThat(getLastLogLine().get("error.message").textValue()).isEqualTo("test");
assertThat(getLastLogLine().get("error.code").textValue()).isEqualTo(RuntimeException.class.getName());
String stackTrace = StreamSupport.stream(getLastLogLine().get("error.stack_trace").spliterator(), false)
.map(JsonNode::textValue)
.collect(Collectors.joining("\n", "", "\n"));
assertThat(stackTrace).contains("at co.elastic.logging.AbstractEcsLoggingTest.testLogException");
}

public abstract void putMdc(String key, String value);
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,89 @@
/*-
* #%L
* Java ECS logging
* %%
* Copyright (C) 2019 Elastic and contributors
* %%
* Licensed to Elasticsearch B.V. under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch B.V. 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.
* #L%
*/
package co.elastic.logging;

import com.fasterxml.jackson.databind.JsonNode;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.junit.jupiter.api.Test;

import java.io.IOException;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.stream.Collectors;
import java.util.stream.StreamSupport;

import static org.assertj.core.api.Assertions.assertThat;

class EcsJsonSerializerTest {

@Test
void serializeExceptionAsString() throws IOException {
Exception exception = new Exception("foo");
StringBuilder jsonBuilder = new StringBuilder();
jsonBuilder.append('{');
EcsJsonSerializer.serializeException(jsonBuilder, exception, false);
jsonBuilder.append('}');
JsonNode jsonNode = new ObjectMapper().readTree(jsonBuilder.toString());

assertThat(jsonNode.get("error.code").textValue()).isEqualTo(exception.getClass().getName());
assertThat(jsonNode.get("error.message").textValue()).isEqualTo("foo");
StringWriter stringWriter = new StringWriter();
exception.printStackTrace(new PrintWriter(stringWriter));
assertThat(jsonNode.get("error.stack_trace").textValue()).isEqualTo(stringWriter.toString());
}

@Test
void serializeExceptionAsArray() throws IOException {
Exception exception = new Exception("foo");
StringBuilder jsonBuilder = new StringBuilder();
jsonBuilder.append('{');
EcsJsonSerializer.serializeException(jsonBuilder, exception, true);
jsonBuilder.append('}');
System.out.println(jsonBuilder);
JsonNode jsonNode = new ObjectMapper().readTree(jsonBuilder.toString());

assertThat(jsonNode.get("error.code").textValue()).isEqualTo(exception.getClass().getName());
assertThat(jsonNode.get("error.message").textValue()).isEqualTo("foo");
StringWriter stringWriter = new StringWriter();
exception.printStackTrace(new PrintWriter(stringWriter));
assertThat(StreamSupport.stream(jsonNode.get("error.stack_trace").spliterator(), false)
.map(JsonNode::textValue)
.collect(Collectors.joining("\n", "", "\n")))
.isEqualTo(stringWriter.toString());
}

@Test
void testRemoveIfEndsWith() {
assertRemoveIfEndsWith("", "foo", "");
assertRemoveIfEndsWith("foobar", "foo", "foobar");
assertRemoveIfEndsWith("barfoo", "foo", "bar");
}

private void assertRemoveIfEndsWith(String builder, String ending, String expected) {
StringBuilder sb = new StringBuilder(builder);
EcsJsonSerializer.removeIfEndsWith(sb, ending);
assertThat(sb.toString()).isEqualTo(expected);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -27,12 +27,14 @@
import co.elastic.logging.EcsJsonSerializer;
import org.apache.log4j.Layout;
import org.apache.log4j.spi.LoggingEvent;
import org.apache.log4j.spi.ThrowableInformation;

import java.util.HashSet;
import java.util.Set;

public class EcsLayout extends Layout {

private boolean stackTraceAsArray = false;
private String serviceName;
private Set<String> topLevelLabels = new HashSet<String>(EcsJsonSerializer.DEFAULT_TOP_LEVEL_LABELS);

Expand All @@ -41,13 +43,16 @@ public String format(LoggingEvent event) {
StringBuilder builder = new StringBuilder();
EcsJsonSerializer.serializeObjectStart(builder, event.getTimeStamp());
EcsJsonSerializer.serializeLogLevel(builder, event.getLevel().toString());
Throwable thrown = event.getThrowableInformation() != null ? event.getThrowableInformation().getThrowable() : null;
EcsJsonSerializer.serializeFormattedMessage(builder, event.getRenderedMessage(), thrown);
EcsJsonSerializer.serializeFormattedMessage(builder, event.getRenderedMessage());
EcsJsonSerializer.serializeServiceName(builder, serviceName);
EcsJsonSerializer.serializeThreadName(builder, event.getThreadName());
EcsJsonSerializer.serializeLoggerName(builder, event.getLoggerName());
EcsJsonSerializer.serializeLabels(builder, event.getProperties(), topLevelLabels);
EcsJsonSerializer.serializeTag(builder, event.getNDC());
ThrowableInformation throwableInformation = event.getThrowableInformation();
if (throwableInformation != null) {
EcsJsonSerializer.serializeException(builder, throwableInformation.getThrowable(), stackTraceAsArray);
}
EcsJsonSerializer.serializeObjectEnd(builder);
return builder.toString();
}
Expand All @@ -65,4 +70,8 @@ public void activateOptions() {
public void setServiceName(String serviceName) {
this.serviceName = serviceName;
}

public void setStackTraceAsArray(boolean stackTraceAsArray) {
this.stackTraceAsArray = stackTraceAsArray;
}
}
Loading

0 comments on commit 3bce698

Please sign in to comment.