Skip to content

Commit

Permalink
Refine structured logging
Browse files Browse the repository at this point in the history
Refine structured logging to support `Environment`, `ApplicationPid` and
`ElasticCommonSchemaService` injection. With these updates we are able
to remove the `ApplicationMetadata` class and simplify the parameters
passed to the layout/encoder classes.

Closes gh-41491
  • Loading branch information
philwebb committed Jul 24, 2024
1 parent 50dbaec commit de3b14f
Show file tree
Hide file tree
Showing 30 changed files with 539 additions and 290 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -440,7 +440,7 @@ Handling authenticated request
== Structured Logging

Structured logging is a technique where the log output is written in a well-defined, often machine-readable format.
Spring Boot supports structured logging and has support for the following formats out of the box:
Spring Boot supports structured logging and has support for the following JSON formats out of the box:

* xref:#features.logging.structured.ecs[Elastic Common Schema (ECS)]
* xref:#features.logging.structured.logstash[Logstash]
Expand Down Expand Up @@ -474,6 +474,22 @@ A log line looks like this:
This format also adds every key value pair contained in the MDC to the JSON object.
You can also use the https://www.slf4j.org/manual.html#fluent[SLF4J fluent logging API] to add key value pairs to the logged JSON object with the https://www.slf4j.org/apidocs/org/slf4j/spi/LoggingEventBuilder.html#addKeyValue(java.lang.String,java.lang.Object)[addKeyValue] method.

The `service` values can be customized using `logging.structured.ecs.service` properties:

[configprops,yaml]
----
logging:
structured:
ecs:
service:
name: MyService
version: 1.0
environment: Production
node-name: Primary
----

NOTE: configprop:logging.structured.ecs.service.name[] will default to configprop:spring.application.name[] if not specified.



[[features.logging.structured.logstash]]
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -24,9 +24,11 @@
import org.apache.logging.log4j.util.ReadOnlyStringMap;

import org.springframework.boot.json.JsonWriter;
import org.springframework.boot.logging.structured.ApplicationMetadata;
import org.springframework.boot.logging.structured.CommonStructuredLogFormat;
import org.springframework.boot.logging.structured.ElasticCommonSchemaService;
import org.springframework.boot.logging.structured.JsonWriterStructuredLogFormatter;
import org.springframework.boot.logging.structured.StructuredLogFormatter;
import org.springframework.boot.system.ApplicationPid;
import org.springframework.util.ObjectUtils;

/**
Expand All @@ -36,23 +38,19 @@
* @author Moritz Halbritter
* @author Phillip Webb
*/
class ElasticCommonSchemaStructuredLogFormatter implements StructuredLogFormatter<LogEvent> {
class ElasticCommonSchemaStructuredLogFormatter extends JsonWriterStructuredLogFormatter<LogEvent> {

private final JsonWriter<LogEvent> writer;

ElasticCommonSchemaStructuredLogFormatter(ApplicationMetadata metadata) {
this.writer = JsonWriter.<LogEvent>of((members) -> logEventJson(metadata, members)).withNewLineAtEnd();
ElasticCommonSchemaStructuredLogFormatter(ApplicationPid pid, ElasticCommonSchemaService service) {
super((members) -> jsonMembers(pid, service, members));
}

private void logEventJson(ApplicationMetadata metadata, JsonWriter.Members<LogEvent> members) {
members.add("@timestamp", LogEvent::getInstant).as(this::asTimestamp);
private static void jsonMembers(ApplicationPid pid, ElasticCommonSchemaService service,
JsonWriter.Members<LogEvent> members) {
members.add("@timestamp", LogEvent::getInstant).as(ElasticCommonSchemaStructuredLogFormatter::asTimestamp);
members.add("log.level", LogEvent::getLevel).as(Level::name);
members.add("process.pid", metadata::pid).whenNotNull();
members.add("process.pid", pid).when(ApplicationPid::isAvailable).as(ApplicationPid::toLong);
members.add("process.thread.name", LogEvent::getThreadName);
members.add("service.name", metadata::name).whenHasLength();
members.add("service.version", metadata::version).whenHasLength();
members.add("service.environment", metadata::environment).whenHasLength();
members.add("service.node.name", metadata::nodeName).whenHasLength();
service.jsonMembers(members);
members.add("log.logger", LogEvent::getLoggerName);
members.add("message", LogEvent::getMessage).as(Message::getFormattedMessage);
members.add(LogEvent::getContextData)
Expand All @@ -68,13 +66,8 @@ private void logEventJson(ApplicationMetadata metadata, JsonWriter.Members<LogEv
members.add("ecs.version", "8.11");
}

private java.time.Instant asTimestamp(Instant instant) {
private static java.time.Instant asTimestamp(Instant instant) {
return java.time.Instant.ofEpochMilli(instant.getEpochMillisecond()).plusNanos(instant.getNanoOfMillisecond());
}

@Override
public String format(LogEvent event) {
return this.writer.writeToString(event);
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@

import org.springframework.boot.json.JsonWriter;
import org.springframework.boot.logging.structured.CommonStructuredLogFormat;
import org.springframework.boot.logging.structured.JsonWriterStructuredLogFormatter;
import org.springframework.boot.logging.structured.StructuredLogFormatter;
import org.springframework.util.CollectionUtils;

Expand All @@ -41,16 +42,14 @@
* @author Moritz Halbritter
* @author Phillip Webb
*/
class LogstashStructuredLogFormatter implements StructuredLogFormatter<LogEvent> {

private JsonWriter<LogEvent> writer;
class LogstashStructuredLogFormatter extends JsonWriterStructuredLogFormatter<LogEvent> {

LogstashStructuredLogFormatter() {
this.writer = JsonWriter.<LogEvent>of(this::logEventJson).withNewLineAtEnd();
super(LogstashStructuredLogFormatter::jsonMembers);
}

private void logEventJson(JsonWriter.Members<LogEvent> members) {
members.add("@timestamp", LogEvent::getInstant).as(this::asTimestamp);
private static void jsonMembers(JsonWriter.Members<LogEvent> members) {
members.add("@timestamp", LogEvent::getInstant).as(LogstashStructuredLogFormatter::asTimestamp);
members.add("@version", "1");
members.add("message", LogEvent::getMessage).as(Message::getFormattedMessage);
members.add("logger_name", LogEvent::getLoggerName);
Expand All @@ -60,26 +59,29 @@ private void logEventJson(JsonWriter.Members<LogEvent> members) {
members.add(LogEvent::getContextData)
.whenNot(ReadOnlyStringMap::isEmpty)
.usingPairs((contextData, pairs) -> contextData.forEach(pairs::accept));
members.add("tags", LogEvent::getMarker).whenNotNull().as(this::getMarkers).whenNot(CollectionUtils::isEmpty);
members.add("tags", LogEvent::getMarker)
.whenNotNull()
.as(LogstashStructuredLogFormatter::getMarkers)
.whenNot(CollectionUtils::isEmpty);
members.add("stack_trace", LogEvent::getThrownProxy)
.whenNotNull()
.as(ThrowableProxy::getExtendedStackTraceAsString);
}

private String asTimestamp(Instant instant) {
private static String asTimestamp(Instant instant) {
java.time.Instant javaInstant = java.time.Instant.ofEpochMilli(instant.getEpochMillisecond())
.plusNanos(instant.getNanoOfMillisecond());
OffsetDateTime offsetDateTime = OffsetDateTime.ofInstant(javaInstant, ZoneId.systemDefault());
return DateTimeFormatter.ISO_OFFSET_DATE_TIME.format(offsetDateTime);
}

private Set<String> getMarkers(Marker marker) {
private static Set<String> getMarkers(Marker marker) {
Set<String> result = new TreeSet<>();
addMarkers(result, marker);
return result;
}

private void addMarkers(Set<String> result, Marker marker) {
private static void addMarkers(Set<String> result, Marker marker) {
result.add(marker.getName());
if (marker.hasParents()) {
for (Marker parent : marker.getParents()) {
Expand All @@ -88,9 +90,4 @@ private void addMarkers(Set<String> result, Marker marker) {
}
}

@Override
public String format(LogEvent event) {
return this.writer.writeToString(event);
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -21,17 +21,21 @@

import org.apache.logging.log4j.core.Layout;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.config.Node;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderFactory;
import org.apache.logging.log4j.core.config.plugins.PluginLoggerContext;
import org.apache.logging.log4j.core.layout.AbstractStringLayout;

import org.springframework.boot.logging.structured.ApplicationMetadata;
import org.springframework.boot.logging.structured.CommonStructuredLogFormat;
import org.springframework.boot.logging.structured.ElasticCommonSchemaService;
import org.springframework.boot.logging.structured.StructuredLogFormatter;
import org.springframework.boot.logging.structured.StructuredLogFormatterFactory;
import org.springframework.boot.logging.structured.StructuredLogFormatterFactory.CommonFormatters;
import org.springframework.boot.system.ApplicationPid;
import org.springframework.core.env.Environment;
import org.springframework.util.Assert;

/**
Expand All @@ -57,34 +61,27 @@ public String toSerializable(LogEvent event) {
return this.formatter.format(event);
}

@Override
public byte[] toByteArray(LogEvent event) {
return this.formatter.formatAsBytes(event, (getCharset() != null) ? getCharset() : StandardCharsets.UTF_8);
}

@PluginBuilderFactory
static StructuredLogLayout.Builder newBuilder() {
return new StructuredLogLayout.Builder();
}

static final class Builder implements org.apache.logging.log4j.core.util.Builder<StructuredLogLayout> {

@PluginLoggerContext
private LoggerContext loggerContext;

@PluginBuilderAttribute
private String format;

@PluginBuilderAttribute
private String charset = StandardCharsets.UTF_8.name();

@PluginBuilderAttribute
private Long pid;

@PluginBuilderAttribute
private String serviceName;

@PluginBuilderAttribute
private String serviceVersion;

@PluginBuilderAttribute
private String serviceNodeName;

@PluginBuilderAttribute
private String serviceEnvironment;

Builder setFormat(String format) {
this.format = format;
return this;
Expand All @@ -95,46 +92,22 @@ Builder setCharset(String charset) {
return this;
}

Builder setPid(Long pid) {
this.pid = pid;
return this;
}

Builder setServiceName(String serviceName) {
this.serviceName = serviceName;
return this;
}

Builder setServiceVersion(String serviceVersion) {
this.serviceVersion = serviceVersion;
return this;
}

Builder setServiceNodeName(String serviceNodeName) {
this.serviceNodeName = serviceNodeName;
return this;
}

Builder setServiceEnvironment(String serviceEnvironment) {
this.serviceEnvironment = serviceEnvironment;
return this;
}

@Override
public StructuredLogLayout build() {
ApplicationMetadata applicationMetadata = new ApplicationMetadata(this.pid, this.serviceName,
this.serviceVersion, this.serviceEnvironment, this.serviceNodeName);
Charset charset = Charset.forName(this.charset);
Environment environment = Log4J2LoggingSystem.getEnvironment(this.loggerContext);
Assert.state(environment != null, "Unable to find Spring Environment in logger context");
StructuredLogFormatter<LogEvent> formatter = new StructuredLogFormatterFactory<>(LogEvent.class,
applicationMetadata, null, this::addCommonFormatters)
environment, null, this::addCommonFormatters)
.get(this.format);
return new StructuredLogLayout(charset, formatter);
}

private void addCommonFormatters(CommonFormatters<LogEvent> commonFormatters) {
commonFormatters.add(CommonStructuredLogFormat.ELASTIC_COMMON_SCHEMA,
(instantiator) -> new ElasticCommonSchemaStructuredLogFormatter(
instantiator.getArg(ApplicationMetadata.class)));
instantiator.getArg(ApplicationPid.class),
instantiator.getArg(ElasticCommonSchemaService.class)));
commonFormatters.add(CommonStructuredLogFormat.LOGSTASH,
(instantiator) -> new LogstashStructuredLogFormatter());
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -174,11 +174,6 @@ private Encoder<ILoggingEvent> createEncoder(LogbackConfigurator config, String
private StructuredLogEncoder createStructuredLoggingEncoder(LogbackConfigurator config, String format) {
StructuredLogEncoder encoder = new StructuredLogEncoder();
encoder.setFormat(format);
encoder.setPid(resolveLong(config, "${PID:--1}"));
String applicationName = resolve(config, "${APPLICATION_NAME:-}");
if (StringUtils.hasLength(applicationName)) {
encoder.setServiceName(applicationName);
}
return encoder;
}

Expand All @@ -205,10 +200,6 @@ private int resolveInt(LogbackConfigurator config, String val) {
return Integer.parseInt(resolve(config, val));
}

private long resolveLong(LogbackConfigurator config, String val) {
return Long.parseLong(resolve(config, val));
}

private FileSize resolveFileSize(LogbackConfigurator config, String val) {
return FileSize.valueOf(resolve(config, val));
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,9 +23,11 @@

import org.springframework.boot.json.JsonWriter;
import org.springframework.boot.json.JsonWriter.PairExtractor;
import org.springframework.boot.logging.structured.ApplicationMetadata;
import org.springframework.boot.logging.structured.CommonStructuredLogFormat;
import org.springframework.boot.logging.structured.ElasticCommonSchemaService;
import org.springframework.boot.logging.structured.JsonWriterStructuredLogFormatter;
import org.springframework.boot.logging.structured.StructuredLogFormatter;
import org.springframework.boot.system.ApplicationPid;

/**
* Logback {@link StructuredLogFormatter} for
Expand All @@ -34,30 +36,23 @@
* @author Moritz Halbritter
* @author Phillip Webb
*/
class ElasticCommonSchemaStructuredLogFormatter implements StructuredLogFormatter<ILoggingEvent> {
class ElasticCommonSchemaStructuredLogFormatter extends JsonWriterStructuredLogFormatter<ILoggingEvent> {

private static final PairExtractor<KeyValuePair> keyValuePairExtractor = PairExtractor.of((pair) -> pair.key,
(pair) -> pair.value);

private JsonWriter<ILoggingEvent> writer;

ElasticCommonSchemaStructuredLogFormatter(ApplicationMetadata metadata,
ElasticCommonSchemaStructuredLogFormatter(ApplicationPid pid, ElasticCommonSchemaService service,
ThrowableProxyConverter throwableProxyConverter) {
this.writer = JsonWriter
.<ILoggingEvent>of((members) -> loggingEventJson(metadata, throwableProxyConverter, members))
.withNewLineAtEnd();
super((members) -> jsonMembers(pid, service, throwableProxyConverter, members));
}

private void loggingEventJson(ApplicationMetadata metadata, ThrowableProxyConverter throwableProxyConverter,
JsonWriter.Members<ILoggingEvent> members) {
private static void jsonMembers(ApplicationPid pid, ElasticCommonSchemaService service,
ThrowableProxyConverter throwableProxyConverter, JsonWriter.Members<ILoggingEvent> members) {
members.add("@timestamp", ILoggingEvent::getInstant);
members.add("log.level", ILoggingEvent::getLevel);
members.add("process.pid", metadata::pid).whenNotNull();
members.add("process.pid", pid).when(ApplicationPid::isAvailable).as(ApplicationPid::toLong);
members.add("process.thread.name", ILoggingEvent::getThreadName);
members.add("service.name", metadata::name).whenHasLength();
members.add("service.version", metadata::version).whenHasLength();
members.add("service.environment", metadata::environment).whenHasLength();
members.add("service.node.name", metadata::nodeName).whenHasLength();
service.jsonMembers(members);
members.add("log.logger", ILoggingEvent::getLoggerName);
members.add("message", ILoggingEvent::getFormattedMessage);
members.addMapEntries(ILoggingEvent::getMDCPropertyMap);
Expand All @@ -72,9 +67,4 @@ private void loggingEventJson(ApplicationMetadata metadata, ThrowableProxyConver
members.add("ecs.version", "8.11");
}

@Override
public String format(ILoggingEvent event) {
return this.writer.writeToString(event);
}

}
Loading

0 comments on commit de3b14f

Please sign in to comment.