Skip to content

Commit

Permalink
Add Graylog Extended Log Format (GELF) for structured logging
Browse files Browse the repository at this point in the history
  • Loading branch information
slissner authored and mhalbritter committed Sep 10, 2024
1 parent 915fc2e commit 74a9d11
Show file tree
Hide file tree
Showing 12 changed files with 747 additions and 2 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -445,6 +445,7 @@ Structured logging is a technique where the log output is written in a well-defi
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.gelf[Graylog Extended Log Format (GELF)]
* xref:#features.logging.structured.logstash[Logstash]

To enable structured logging, set the property configprop:logging.structured.format.console[] (for console output) or configprop:logging.structured.format.file[] (for file output) to the id of the format you want to use.
Expand Down Expand Up @@ -492,6 +493,53 @@ logging:

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

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



[[features.logging.structured.gelf]]
=== Graylog Extended Log Format (GELF)
https://go2docs.graylog.org/current/getting_in_log_data/gelf.html[Graylog Extended Log Format] is a JSON based logging format for the Graylog log analytics platform.

To enable the Graylog Extended Log Format, set the appropriate `format` property to `gelf`:

[configprops,yaml]
----
logging:
structured:
format:
console: gelf
file: gelf
----

A log line looks like this:

[source,json]
----
{"version":"1.1","short_message":"Hello structured logging!","timestamp":1.725530750186E9,"level":6,"_level_name":"INFO","_process_pid":9086,"_process_thread_name":"main","host":"spring-boot-gelf","_log_logger":"com.slissner.springbootgelf.ExampleLogger","_userId":"1","_testkey_testmessage":"test"}
----

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.gelf.service` properties:

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

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

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



[[features.logging.structured.logstash]]
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,162 @@
/*
* Copyright 2012-2024 the original author or authors.
*
* Licensed 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
*
* https://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.springframework.boot.logging.log4j2;

import java.math.BigDecimal;
import java.util.Objects;
import java.util.Set;
import java.util.function.Function;
import java.util.regex.Pattern;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.impl.ThrowableProxy;
import org.apache.logging.log4j.core.net.Severity;
import org.apache.logging.log4j.core.time.Instant;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.util.ReadOnlyStringMap;

import org.springframework.boot.json.JsonWriter;
import org.springframework.boot.logging.structured.CommonStructuredLogFormat;
import org.springframework.boot.logging.structured.GraylogExtendedLogFormatService;
import org.springframework.boot.logging.structured.JsonWriterStructuredLogFormatter;
import org.springframework.boot.logging.structured.StructuredLogFormatter;
import org.springframework.core.env.Environment;
import org.springframework.util.Assert;
import org.springframework.util.ObjectUtils;

/**
* Log4j2 {@link StructuredLogFormatter} for
* {@link CommonStructuredLogFormat#GRAYLOG_EXTENDED_LOG_FORMAT}. Supports GELF version
* 1.1.
*
* @author Samuel Lissner
*/
class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructuredLogFormatter<LogEvent> {

/**
* Allowed characters in field names are any word character (letter, number,
* underscore), dashes and dots.
*/
private static final Pattern FIELD_NAME_VALID_PATTERN = Pattern.compile("^[\\w\\.\\-]*$");

/**
* Every field been sent and prefixed with an underscore "_" will be treated as an
* additional field.
*/
private static final String ADDITIONAL_FIELD_PREFIX = "_";

/**
* Libraries SHOULD not allow to send id as additional field ("_id"). Graylog server
* nodes omit this field automatically.
*/
private static final Set<String> ADDITIONAL_FIELD_ILLEGAL_KEYS = Set.of("_id");

/**
* Default format to be used for the `full_message` property when there is a throwable
* present in the log event.
*/
private static final String DEFAULT_FULL_MESSAGE_WITH_THROWABLE_FORMAT = "%s%n%n%s";

GraylogExtendedLogFormatStructuredLogFormatter(Environment environment) {
super((members) -> jsonMembers(environment, members));
}

private static void jsonMembers(Environment environment, JsonWriter.Members<LogEvent> members) {
members.add("version", "1.1");

// note: a blank message will lead to a Graylog error as of Graylog v6.0.x. We are
// ignoring this here.
members.add("short_message", LogEvent::getMessage).as(Message::getFormattedMessage);

members.add("timestamp", LogEvent::getInstant)
.as(GraylogExtendedLogFormatStructuredLogFormatter::formatTimeStamp);
members.add("level", GraylogExtendedLogFormatStructuredLogFormatter::convertLevel);
members.add("_level_name", LogEvent::getLevel).as(Level::name);

members.add("_process_pid", environment.getProperty("spring.application.pid", Long.class))
.when(Objects::nonNull);
members.add("_process_thread_name", LogEvent::getThreadName);

GraylogExtendedLogFormatService.get(environment).jsonMembers(members);

members.add("_log_logger", LogEvent::getLoggerName);

members.from(LogEvent::getContextData)
.whenNot(ReadOnlyStringMap::isEmpty)
.usingPairs((contextData, pairs) -> contextData
.forEach((key, value) -> pairs.accept(makeAdditionalFieldName(key), value)));

members.add().whenNotNull(LogEvent::getThrownProxy).usingMembers((eventMembers) -> {
final Function<LogEvent, ThrowableProxy> throwableProxyGetter = LogEvent::getThrownProxy;

eventMembers.add("full_message",
GraylogExtendedLogFormatStructuredLogFormatter::formatFullMessageWithThrowable);
eventMembers.add("_error_type", throwableProxyGetter.andThen(ThrowableProxy::getThrowable))
.whenNotNull()
.as(ObjectUtils::nullSafeClassName);
eventMembers.add("_error_stack_trace",
throwableProxyGetter.andThen(ThrowableProxy::getExtendedStackTraceAsString));
eventMembers.add("_error_message", throwableProxyGetter.andThen(ThrowableProxy::getMessage));
});
}

/**
* GELF requires "seconds since UNIX epoch with optional <b>decimal places for
* milliseconds</b>". To comply with this requirement, we format a POSIX timestamp
* with millisecond precision as e.g. "1725459730385" -> "1725459730.385"
* @param timeStamp the timestamp of the log message. Note it is not the standard Java
* `Instant` type but {@link org.apache.logging.log4j.core.time}
* @return the timestamp formatted as string with millisecond precision
*/
private static double formatTimeStamp(final Instant timeStamp) {
return new BigDecimal(timeStamp.getEpochMillisecond()).movePointLeft(3).doubleValue();
}

/**
* Converts the log4j2 event level to the Syslog event level code.
* @param event the log event
* @return an integer representing the syslog log level code
* @see Severity class from Log4j2 which contains the conversion logic
*/
private static int convertLevel(final LogEvent event) {
return Severity.getSeverity(event.getLevel()).getCode();
}

private static String formatFullMessageWithThrowable(final LogEvent event) {
return String.format(DEFAULT_FULL_MESSAGE_WITH_THROWABLE_FORMAT, event.getMessage().getFormattedMessage(),
event.getThrownProxy().getExtendedStackTraceAsString());
}

private static String makeAdditionalFieldName(String fieldName) {
Assert.notNull(fieldName, "fieldName must not be null");
Assert.isTrue(FIELD_NAME_VALID_PATTERN.matcher(fieldName).matches(),
() -> String.format("fieldName must be a valid according to GELF standard. [fieldName=%s]", fieldName));
Assert.isTrue(!ADDITIONAL_FIELD_ILLEGAL_KEYS.contains(fieldName), () -> String.format(
"fieldName must not be an illegal additional field key according to GELF standard. [fieldName=%s]",
fieldName));

if (fieldName.startsWith(ADDITIONAL_FIELD_PREFIX)) {
// No need to prepend the `ADDITIONAL_FIELD_PREFIX` in case the caller already
// has prepended the prefix.
return fieldName;
}

return ADDITIONAL_FIELD_PREFIX + fieldName;
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -105,6 +105,9 @@ private void addCommonFormatters(CommonFormatters<LogEvent> commonFormatters) {
commonFormatters.add(CommonStructuredLogFormat.ELASTIC_COMMON_SCHEMA,
(instantiator) -> new ElasticCommonSchemaStructuredLogFormatter(
instantiator.getArg(Environment.class)));
commonFormatters.add(CommonStructuredLogFormat.GRAYLOG_EXTENDED_LOG_FORMAT,
(instantiator) -> new GraylogExtendedLogFormatStructuredLogFormatter(
instantiator.getArg(Environment.class)));
commonFormatters.add(CommonStructuredLogFormat.LOGSTASH,
(instantiator) -> new LogstashStructuredLogFormatter());
}
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,160 @@
/*
* Copyright 2012-2024 the original author or authors.
*
* Licensed 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
*
* https://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.springframework.boot.logging.logback;

import java.math.BigDecimal;
import java.util.Map;
import java.util.Objects;
import java.util.Set;
import java.util.function.Function;
import java.util.regex.Pattern;
import java.util.stream.Collectors;

import ch.qos.logback.classic.pattern.ThrowableProxyConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.IThrowableProxy;
import ch.qos.logback.classic.util.LevelToSyslogSeverity;
import org.slf4j.event.KeyValuePair;

import org.springframework.boot.json.JsonWriter;
import org.springframework.boot.json.JsonWriter.PairExtractor;
import org.springframework.boot.logging.structured.CommonStructuredLogFormat;
import org.springframework.boot.logging.structured.GraylogExtendedLogFormatService;
import org.springframework.boot.logging.structured.JsonWriterStructuredLogFormatter;
import org.springframework.boot.logging.structured.StructuredLogFormatter;
import org.springframework.core.env.Environment;
import org.springframework.util.Assert;

/**
* Logback {@link StructuredLogFormatter} for
* {@link CommonStructuredLogFormat#GRAYLOG_EXTENDED_LOG_FORMAT}. Supports GELF version
* 1.1.
*
* @author Samuel Lissner
*/
class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructuredLogFormatter<ILoggingEvent> {

/**
* Allowed characters in field names are any word character (letter, number,
* underscore), dashes and dots.
*/
private static final Pattern FIELD_NAME_VALID_PATTERN = Pattern.compile("^[\\w\\.\\-]*$");

/**
* Every field been sent and prefixed with an underscore "_" will be treated as an
* additional field.
*/
private static final String ADDITIONAL_FIELD_PREFIX = "_";

/**
* Libraries SHOULD not allow to send id as additional field ("_id"). Graylog server
* nodes omit this field automatically.
*/
private static final Set<String> ADDITIONAL_FIELD_ILLEGAL_KEYS = Set.of("_id");

/**
* Default format to be used for the `full_message` property when there is a throwable
* present in the log event.
*/
private static final String DEFAULT_FULL_MESSAGE_WITH_THROWABLE_FORMAT = "%s%n%n%s";

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

GraylogExtendedLogFormatStructuredLogFormatter(Environment environment,
ThrowableProxyConverter throwableProxyConverter) {
super((members) -> jsonMembers(environment, throwableProxyConverter, members));
}

private static void jsonMembers(Environment environment, ThrowableProxyConverter throwableProxyConverter,
JsonWriter.Members<ILoggingEvent> members) {
members.add("version", "1.1");

// note: a blank message will lead to a Graylog error as of Graylog v6.0.x. We are
// ignoring this here.
members.add("short_message", ILoggingEvent::getFormattedMessage);

members.add("timestamp", ILoggingEvent::getTimeStamp)
.as(GraylogExtendedLogFormatStructuredLogFormatter::formatTimeStamp);
members.add("level", LevelToSyslogSeverity::convert);
members.add("_level_name", ILoggingEvent::getLevel);

members.add("_process_pid", environment.getProperty("spring.application.pid", Long.class))
.when(Objects::nonNull);
members.add("_process_thread_name", ILoggingEvent::getThreadName);

GraylogExtendedLogFormatService.get(environment).jsonMembers(members);

members.add("_log_logger", ILoggingEvent::getLoggerName);

members.addMapEntries(mapMDCProperties(ILoggingEvent::getMDCPropertyMap));

members.from(ILoggingEvent::getKeyValuePairs)
.whenNotEmpty()
.usingExtractedPairs(Iterable::forEach, keyValuePairExtractor);

members.add().whenNotNull(ILoggingEvent::getThrowableProxy).usingMembers((throwableMembers) -> {
throwableMembers.add("full_message",
(event) -> formatFullMessageWithThrowable(throwableProxyConverter, event));
throwableMembers.add("_error_type", ILoggingEvent::getThrowableProxy).as(IThrowableProxy::getClassName);
throwableMembers.add("_error_stack_trace", throwableProxyConverter::convert);
throwableMembers.add("_error_message", ILoggingEvent::getThrowableProxy).as(IThrowableProxy::getMessage);
});
}

/**
* GELF requires "seconds since UNIX epoch with optional <b>decimal places for
* milliseconds</b>". To comply with this requirement, we format a POSIX timestamp
* with millisecond precision as e.g. "1725459730385" -> "1725459730.385"
* @param timeStamp the timestamp of the log message
* @return the timestamp formatted as string with millisecond precision
*/
private static double formatTimeStamp(final long timeStamp) {
return new BigDecimal(timeStamp).movePointLeft(3).doubleValue();
}

private static String formatFullMessageWithThrowable(final ThrowableProxyConverter throwableProxyConverter,
ILoggingEvent event) {
return String.format(DEFAULT_FULL_MESSAGE_WITH_THROWABLE_FORMAT, event.getFormattedMessage(),
throwableProxyConverter.convert(event));
}

private static Function<ILoggingEvent, Map<String, String>> mapMDCProperties(
Function<ILoggingEvent, Map<String, String>> MDCPropertyMapGetter) {
return MDCPropertyMapGetter.andThen((mdc) -> mdc.entrySet()
.stream()
.collect(Collectors.toMap((entry) -> makeAdditionalFieldName(entry.getKey()), Map.Entry::getValue)));
}

private static String makeAdditionalFieldName(String fieldName) {
Assert.notNull(fieldName, "fieldName must not be null");
Assert.isTrue(FIELD_NAME_VALID_PATTERN.matcher(fieldName).matches(),
() -> String.format("fieldName must be a valid according to GELF standard. [fieldName=%s]", fieldName));
Assert.isTrue(!ADDITIONAL_FIELD_ILLEGAL_KEYS.contains(fieldName), () -> String.format(
"fieldName must not be an illegal additional field key according to GELF standard. [fieldName=%s]",
fieldName));

if (fieldName.startsWith(ADDITIONAL_FIELD_PREFIX)) {
// No need to prepend the `ADDITIONAL_FIELD_PREFIX` in case the caller already
// has prepended the prefix.
return fieldName;
}

return ADDITIONAL_FIELD_PREFIX + fieldName;
}

}
Loading

0 comments on commit 74a9d11

Please sign in to comment.