From b5e7302031224ae67e6dac8ecd4dfea2b116fb07 Mon Sep 17 00:00:00 2001 From: Moritz Halbritter Date: Tue, 10 Sep 2024 10:50:01 +0200 Subject: [PATCH] Polish "Add Graylog Extended Log Format (GELF) for structured logging" See gh-42158 --- .../reference/pages/features/logging.adoc | 4 +- ...tendedLogFormatStructuredLogFormatter.java | 73 +++++++--------- ...tendedLogFormatStructuredLogFormatter.java | 85 +++++++------------ .../GraylogExtendedLogFormatService.java | 10 +-- ...itional-spring-configuration-metadata.json | 10 --- ...dLogFormatStructuredLogFormatterTests.java | 68 +++++++++++++-- .../log4j2/StructuredLoggingLayoutTests.java | 2 +- ...dLogFormatStructuredLogFormatterTests.java | 69 +++++++++++++-- .../GraylogExtendedLogFormatServiceTests.java | 16 ++-- 9 files changed, 194 insertions(+), 143 deletions(-) diff --git a/spring-boot-project/spring-boot-docs/src/docs/antora/modules/reference/pages/features/logging.adoc b/spring-boot-project/spring-boot-docs/src/docs/antora/modules/reference/pages/features/logging.adoc index 9041e89692a..cc3ae220d7f 100644 --- a/spring-boot-project/spring-boot-docs/src/docs/antora/modules/reference/pages/features/logging.adoc +++ b/spring-boot-project/spring-boot-docs/src/docs/antora/modules/reference/pages/features/logging.adoc @@ -516,7 +516,7 @@ 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"} +{"version":"1.1","short_message":"No active profile set, falling back to 1 default profile: \"default\"","timestamp":1725958035.857,"level":6,"_level_name":"INFO","_process_pid":47649,"_process_thread_name":"main","_log_logger":"org.example.Application"} ---- This format also adds every key value pair contained in the MDC to the JSON object. @@ -532,8 +532,6 @@ logging: 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. diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatter.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatter.java index 270de27f5ca..8a31b50b997 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatter.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatter.java @@ -19,23 +19,26 @@ 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.function.BiConsumer; import java.util.regex.Pattern; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; 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.json.JsonWriter.WritableJson; 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.core.log.LogMessage; import org.springframework.util.Assert; import org.springframework.util.ObjectUtils; @@ -45,14 +48,17 @@ import org.springframework.util.ObjectUtils; * 1.1. * * @author Samuel Lissner + * @author Moritz Halbritter */ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructuredLogFormatter { + private static final Log logger = LogFactory.getLog(GraylogExtendedLogFormatStructuredLogFormatter.class); + /** * 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\\.\\-]*$"); + 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 @@ -64,13 +70,7 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure * Libraries SHOULD not allow to send id as additional field ("_id"). Graylog server * nodes omit this field automatically. */ - private static final Set 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 Set ADDITIONAL_FIELD_ILLEGAL_KEYS = Set.of("id", "_id"); GraylogExtendedLogFormatStructuredLogFormatter(Environment environment) { super((members) -> jsonMembers(environment, members)); @@ -78,40 +78,30 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure private static void jsonMembers(Environment environment, JsonWriter.Members 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))); - + .forEach((key, value) -> createAdditionalField(key, value, pairs))); members.add().whenNotNull(LogEvent::getThrownProxy).usingMembers((eventMembers) -> { - final Function throwableProxyGetter = LogEvent::getThrownProxy; - eventMembers.add("full_message", GraylogExtendedLogFormatStructuredLogFormatter::formatFullMessageWithThrowable); - eventMembers.add("_error_type", throwableProxyGetter.andThen(ThrowableProxy::getThrowable)) + eventMembers.add("_error_type", (event) -> event.getThrownProxy().getThrowable()) .whenNotNull() .as(ObjectUtils::nullSafeClassName); - eventMembers.add("_error_stack_trace", - throwableProxyGetter.andThen(ThrowableProxy::getExtendedStackTraceAsString)); - eventMembers.add("_error_message", throwableProxyGetter.andThen(ThrowableProxy::getMessage)); + eventMembers.add("_error_stack_trace", (event) -> event.getThrownProxy().getExtendedStackTraceAsString()); + eventMembers.add("_error_message", (event) -> event.getThrownProxy().getMessage()); }); } @@ -123,8 +113,8 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure * `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(); + private static WritableJson formatTimeStamp(Instant timeStamp) { + return (out) -> out.append(new BigDecimal(timeStamp.getEpochMillisecond()).movePointLeft(3).toPlainString()); } /** @@ -133,30 +123,27 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure * @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) { + private static int convertLevel(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 formatFullMessageWithThrowable(LogEvent event) { + return event.getMessage().getFormattedMessage() + "\n\n" + + event.getThrownProxy().getExtendedStackTraceAsString(); } - private static String makeAdditionalFieldName(String fieldName) { + private static void createAdditionalField(String fieldName, Object value, BiConsumer pairs) { 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; + if (!FIELD_NAME_VALID_PATTERN.matcher(fieldName).matches()) { + logger.warn(LogMessage.format("'%s' is not a valid field name according to GELF standard", fieldName)); + return; } - - return ADDITIONAL_FIELD_PREFIX + fieldName; + if (ADDITIONAL_FIELD_ILLEGAL_KEYS.contains(fieldName)) { + logger.warn(LogMessage.format("'%s' is an illegal field name according to GELF standard", fieldName)); + return; + } + String key = (fieldName.startsWith(ADDITIONAL_FIELD_PREFIX)) ? fieldName : ADDITIONAL_FIELD_PREFIX + fieldName; + pairs.accept(key, value); } } diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatter.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatter.java index b9f1d1fe62b..4d9df6a8149 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatter.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatter.java @@ -17,27 +17,28 @@ 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.function.BiConsumer; 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.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; import org.springframework.boot.json.JsonWriter; -import org.springframework.boot.json.JsonWriter.PairExtractor; +import org.springframework.boot.json.JsonWriter.WritableJson; 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.core.log.LogMessage; import org.springframework.util.Assert; +import org.springframework.util.CollectionUtils; /** * Logback {@link StructuredLogFormatter} for @@ -45,14 +46,17 @@ import org.springframework.util.Assert; * 1.1. * * @author Samuel Lissner + * @author Moritz Halbritter */ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructuredLogFormatter { + private static final Log logger = LogFactory.getLog(GraylogExtendedLogFormatStructuredLogFormatter.class); + /** * 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\\.\\-]*$"); + 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 @@ -64,16 +68,7 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure * Libraries SHOULD not allow to send id as additional field ("_id"). Graylog server * nodes omit this field automatically. */ - private static final Set 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 keyValuePairExtractor = PairExtractor - .of((pair) -> makeAdditionalFieldName(pair.key), (pair) -> pair.value); + private static final Set ADDITIONAL_FIELD_ILLEGAL_KEYS = Set.of("id", "_id"); GraylogExtendedLogFormatStructuredLogFormatter(Environment environment, ThrowableProxyConverter throwableProxyConverter) { @@ -83,30 +78,25 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure private static void jsonMembers(Environment environment, ThrowableProxyConverter throwableProxyConverter, JsonWriter.Members 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::getMDCPropertyMap) + .when((mdc) -> !CollectionUtils.isEmpty(mdc)) + .usingPairs((mdc, pairs) -> mdc.forEach((key, value) -> createAdditionalField(key, value, pairs))); members.from(ILoggingEvent::getKeyValuePairs) - .whenNotEmpty() - .usingExtractedPairs(Iterable::forEach, keyValuePairExtractor); - + .when((keyValuePairs) -> !CollectionUtils.isEmpty(keyValuePairs)) + .usingPairs((keyValuePairs, pairs) -> keyValuePairs + .forEach((keyValuePair) -> createAdditionalField(keyValuePair.key, keyValuePair.value, pairs))); members.add().whenNotNull(ILoggingEvent::getThrowableProxy).usingMembers((throwableMembers) -> { throwableMembers.add("full_message", (event) -> formatFullMessageWithThrowable(throwableProxyConverter, event)); @@ -123,38 +113,27 @@ class GraylogExtendedLogFormatStructuredLogFormatter extends JsonWriterStructure * @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 WritableJson formatTimeStamp(long timeStamp) { + return (out) -> out.append(new BigDecimal(timeStamp).movePointLeft(3).toPlainString()); } - private static String formatFullMessageWithThrowable(final ThrowableProxyConverter throwableProxyConverter, + private static String formatFullMessageWithThrowable(ThrowableProxyConverter throwableProxyConverter, ILoggingEvent event) { - return String.format(DEFAULT_FULL_MESSAGE_WITH_THROWABLE_FORMAT, event.getFormattedMessage(), - throwableProxyConverter.convert(event)); + return event.getFormattedMessage() + "\n\n" + throwableProxyConverter.convert(event); } - private static Function> mapMDCProperties( - Function> 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; + private static void createAdditionalField(String key, Object value, BiConsumer pairs) { + Assert.notNull(key, "fieldName must not be null"); + if (!FIELD_NAME_VALID_PATTERN.matcher(key).matches()) { + logger.warn(LogMessage.format("'%s' is not a valid field name according to GELF standard", key)); + return; } - - return ADDITIONAL_FIELD_PREFIX + fieldName; + if (ADDITIONAL_FIELD_ILLEGAL_KEYS.contains(key)) { + logger.warn(LogMessage.format("'%s' is an illegal field name according to GELF standard", key)); + return; + } + String keyWithPrefix = (key.startsWith(ADDITIONAL_FIELD_PREFIX)) ? key : ADDITIONAL_FIELD_PREFIX + key; + pairs.accept(keyWithPrefix, value); } } diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatService.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatService.java index 75216bb1adf..bbe854a1a98 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatService.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatService.java @@ -26,19 +26,17 @@ import org.springframework.util.StringUtils; * * @param name the application name * @param version the version of the application - * @param environment the name of the environment the application is running in - * @param nodeName the name of the node the application is running on * @author Samuel Lissner * @since 3.4.0 */ -public record GraylogExtendedLogFormatService(String name, String version, String environment, String nodeName) { +public record GraylogExtendedLogFormatService(String name, String version) { - static final GraylogExtendedLogFormatService NONE = new GraylogExtendedLogFormatService(null, null, null, null); + static final GraylogExtendedLogFormatService NONE = new GraylogExtendedLogFormatService(null, null); private GraylogExtendedLogFormatService withDefaults(Environment environment) { String name = withFallbackProperty(environment, this.name, "spring.application.name"); String version = withFallbackProperty(environment, this.version, "spring.application.version"); - return new GraylogExtendedLogFormatService(name, version, this.environment, this.nodeName); + return new GraylogExtendedLogFormatService(name, version); } private String withFallbackProperty(Environment environment, String value, String property) { @@ -53,8 +51,6 @@ public record GraylogExtendedLogFormatService(String name, String version, Strin // note "host" is a field name prescribed by GELF members.add("host", this::name).whenHasLength(); members.add("_service_version", this::version).whenHasLength(); - members.add("_service_environment", this::environment).whenHasLength(); - members.add("_service_node_name", this::nodeName).whenHasLength(); } /** diff --git a/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json b/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json index 44c11cc162b..db3716f03d4 100644 --- a/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json +++ b/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json @@ -254,21 +254,11 @@ "type": "java.lang.String", "description": "Structured logging format for output to a file. Must be either a format id or a fully qualified class name." }, - { - "name": "logging.structured.gelf.service.environment", - "type": "java.lang.String", - "description": "Structured GELF service environment." - }, { "name": "logging.structured.gelf.service.name", "type": "java.lang.String", "description": "Structured GELF service name (defaults to 'spring.application.name')." }, - { - "name": "logging.structured.gelf.service.node-name", - "type": "java.lang.String", - "description": "Structured GELF service node name." - }, { "name": "logging.structured.gelf.service.version", "type": "java.lang.String", diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatterTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatterTests.java index 11f29846aca..5a777888e22 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatterTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/GraylogExtendedLogFormatStructuredLogFormatterTests.java @@ -22,7 +22,10 @@ import org.apache.logging.log4j.core.impl.JdkMapAdapterStringMap; import org.apache.logging.log4j.core.impl.MutableLogEvent; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; +import org.springframework.boot.testsupport.system.CapturedOutput; +import org.springframework.boot.testsupport.system.OutputCaptureExtension; import org.springframework.mock.env.MockEnvironment; import static org.assertj.core.api.Assertions.assertThat; @@ -31,7 +34,9 @@ import static org.assertj.core.api.Assertions.assertThat; * Tests for {@link GraylogExtendedLogFormatStructuredLogFormatter}. * * @author Samuel Lissner + * @author Moritz Halbritter */ +@ExtendWith(OutputCaptureExtension.class) class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStructuredLoggingTests { private GraylogExtendedLogFormatStructuredLogFormatter formatter; @@ -41,8 +46,6 @@ class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStruct MockEnvironment environment = new MockEnvironment(); environment.setProperty("logging.structured.gelf.service.name", "name"); environment.setProperty("logging.structured.gelf.service.version", "1.0.0"); - environment.setProperty("logging.structured.gelf.service.environment", "test"); - environment.setProperty("logging.structured.gelf.service.node-name", "node-1"); environment.setProperty("spring.application.pid", "1"); this.formatter = new GraylogExtendedLogFormatStructuredLogFormatter(environment); } @@ -54,23 +57,72 @@ class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStruct String json = this.formatter.format(event); assertThat(json).endsWith("\n"); Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf( + map("version", "1.1", "host", "name", "timestamp", 1719910193.0, "level", 6, "_level_name", "INFO", + "_process_pid", 1, "_process_thread_name", "main", "_service_version", "1.0.0", "_log_logger", + "org.example.Test", "short_message", "message", "_mdc-1", "mdc-v-1")); + } + + @Test + void shouldFormatMillisecondsInTimestamp() { + MutableLogEvent event = createEvent(); + event.setTimeMillis(1719910193123L); + String json = this.formatter.format(event); + assertThat(json).contains("\"timestamp\":1719910193.123"); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); assertThat(deserialized).containsExactlyInAnyOrderEntriesOf(map("version", "1.1", "host", "name", "timestamp", - 1719910193.000D, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", - "_service_version", "1.0.0", "_service_environment", "test", "_service_node_name", "node-1", - "_log_logger", "org.example.Test", "short_message", "message", "_mdc-1", "mdc-v-1")); + 1719910193.123, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", + "_service_version", "1.0.0", "_log_logger", "org.example.Test", "short_message", "message")); + } + + @Test + void shouldNotAllowInvalidFieldNames(CapturedOutput output) { + MutableLogEvent event = createEvent(); + event.setContextData(new JdkMapAdapterStringMap(Map.of("/", "value"), true)); + String json = this.formatter.format(event); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf(map("version", "1.1", "host", "name", "timestamp", + 1719910193.0, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", + "_service_version", "1.0.0", "_log_logger", "org.example.Test", "short_message", "message")); + assertThat(output).contains("'/' is not a valid field name according to GELF standard"); + } + + @Test + void shouldNotAllowIllegalFieldNames(CapturedOutput output) { + MutableLogEvent event = createEvent(); + event.setContextData(new JdkMapAdapterStringMap(Map.of("id", "1"), true)); + String json = this.formatter.format(event); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf(map("version", "1.1", "host", "name", "timestamp", + 1719910193.0, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", + "_service_version", "1.0.0", "_log_logger", "org.example.Test", "short_message", "message")); + assertThat(output).contains("'id' is an illegal field name according to GELF standard"); + } + + @Test + void shouldNotAddDoubleUnderscoreToCustomFields() { + MutableLogEvent event = createEvent(); + event.setContextData(new JdkMapAdapterStringMap(Map.of("_custom", "value"), true)); + String json = this.formatter.format(event); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf( + map("version", "1.1", "host", "name", "timestamp", 1719910193.0, "level", 6, "_level_name", "INFO", + "_process_pid", 1, "_process_thread_name", "main", "_service_version", "1.0.0", "_log_logger", + "org.example.Test", "short_message", "message", "_custom", "value")); } @Test void shouldFormatException() { MutableLogEvent event = createEvent(); event.setThrown(new RuntimeException("Boom")); - String json = this.formatter.format(event); Map deserialized = deserialize(json); - String fullMessage = (String) deserialized.get("full_message"); String stackTrace = (String) deserialized.get("_error_stack_trace"); - assertThat(fullMessage).startsWith( """ message diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/StructuredLoggingLayoutTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/StructuredLoggingLayoutTests.java index 64e56d6a775..cf688e167d7 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/StructuredLoggingLayoutTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/StructuredLoggingLayoutTests.java @@ -110,7 +110,7 @@ class StructuredLoggingLayoutTests extends AbstractStructuredLoggingTests { void shouldFailIfNoCommonOrCustomFormatIsSet() { assertThatIllegalArgumentException().isThrownBy(() -> newBuilder().setFormat("does-not-exist").build()) .withMessageContaining("Unknown format 'does-not-exist'. " - + "Values can be a valid fully-qualified class name or one of the common formats: [ecs, logstash]"); + + "Values can be a valid fully-qualified class name or one of the common formats: [ecs, gelf, logstash]"); } private Builder newBuilder() { diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatterTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatterTests.java index fe1df90cf9b..39ab27c638f 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatterTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/GraylogExtendedLogFormatStructuredLogFormatterTests.java @@ -23,7 +23,10 @@ import ch.qos.logback.classic.spi.LoggingEvent; import ch.qos.logback.classic.spi.ThrowableProxy; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; +import org.springframework.boot.testsupport.system.CapturedOutput; +import org.springframework.boot.testsupport.system.OutputCaptureExtension; import org.springframework.mock.env.MockEnvironment; import static org.assertj.core.api.Assertions.assertThat; @@ -32,7 +35,9 @@ import static org.assertj.core.api.Assertions.assertThat; * Tests for {@link GraylogExtendedLogFormatStructuredLogFormatter}. * * @author Samuel Lissner + * @author Moritz Halbritter */ +@ExtendWith(OutputCaptureExtension.class) class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStructuredLoggingTests { private GraylogExtendedLogFormatStructuredLogFormatter formatter; @@ -44,8 +49,6 @@ class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStruct MockEnvironment environment = new MockEnvironment(); environment.setProperty("logging.structured.gelf.service.name", "name"); environment.setProperty("logging.structured.gelf.service.version", "1.0.0"); - environment.setProperty("logging.structured.gelf.service.environment", "test"); - environment.setProperty("logging.structured.gelf.service.node-name", "node-1"); environment.setProperty("spring.application.pid", "1"); this.formatter = new GraylogExtendedLogFormatStructuredLogFormatter(environment, getThrowableProxyConverter()); } @@ -58,10 +61,63 @@ class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStruct String json = this.formatter.format(event); assertThat(json).endsWith("\n"); Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf( + map("version", "1.1", "host", "name", "timestamp", 1719910193.0, "level", 6, "_level_name", "INFO", + "_process_pid", 1, "_process_thread_name", "main", "_service_version", "1.0.0", "_log_logger", + "org.example.Test", "short_message", "message", "_mdc-1", "mdc-v-1", "_kv-1", "kv-v-1")); + } + + @Test + void shouldFormatMillisecondsInTimestamp() { + LoggingEvent event = createEvent(); + event.setTimeStamp(1719910193123L); + event.setMDCPropertyMap(Collections.emptyMap()); + String json = this.formatter.format(event); + assertThat(json).contains("\"timestamp\":1719910193.123"); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); assertThat(deserialized).containsExactlyInAnyOrderEntriesOf(map("version", "1.1", "host", "name", "timestamp", - 1719910193.000D, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", - "_service_version", "1.0.0", "_service_environment", "test", "_service_node_name", "node-1", - "_log_logger", "org.example.Test", "short_message", "message", "_mdc-1", "mdc-v-1", "_kv-1", "kv-v-1")); + 1719910193.123, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", + "_service_version", "1.0.0", "_log_logger", "org.example.Test", "short_message", "message")); + } + + @Test + void shouldNotAllowInvalidFieldNames(CapturedOutput output) { + LoggingEvent event = createEvent(); + event.setMDCPropertyMap(Map.of("/", "value")); + String json = this.formatter.format(event); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf(map("version", "1.1", "host", "name", "timestamp", + 1719910193.0, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", + "_service_version", "1.0.0", "_log_logger", "org.example.Test", "short_message", "message")); + assertThat(output).contains("'/' is not a valid field name according to GELF standard"); + } + + @Test + void shouldNotAllowIllegalFieldNames(CapturedOutput output) { + LoggingEvent event = createEvent(); + event.setMDCPropertyMap(Map.of("id", "1")); + String json = this.formatter.format(event); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf(map("version", "1.1", "host", "name", "timestamp", + 1719910193.0, "level", 6, "_level_name", "INFO", "_process_pid", 1, "_process_thread_name", "main", + "_service_version", "1.0.0", "_log_logger", "org.example.Test", "short_message", "message")); + assertThat(output).contains("'id' is an illegal field name according to GELF standard"); + } + + @Test + void shouldNotAddDoubleUnderscoreToCustomFields() { + LoggingEvent event = createEvent(); + event.setMDCPropertyMap(Map.of("_custom", "value")); + String json = this.formatter.format(event); + assertThat(json).endsWith("\n"); + Map deserialized = deserialize(json); + assertThat(deserialized).containsExactlyInAnyOrderEntriesOf( + map("version", "1.1", "host", "name", "timestamp", 1719910193.0, "level", 6, "_level_name", "INFO", + "_process_pid", 1, "_process_thread_name", "main", "_service_version", "1.0.0", "_log_logger", + "org.example.Test", "short_message", "message", "_custom", "value")); } @Test @@ -69,16 +125,13 @@ class GraylogExtendedLogFormatStructuredLogFormatterTests extends AbstractStruct LoggingEvent event = createEvent(); event.setMDCPropertyMap(Collections.emptyMap()); event.setThrowableProxy(new ThrowableProxy(new RuntimeException("Boom"))); - String json = this.formatter.format(event); Map deserialized = deserialize(json); String fullMessage = (String) deserialized.get("full_message"); String stackTrace = (String) deserialized.get("_error_stack_trace"); - assertThat(fullMessage).startsWith( "message\n\njava.lang.RuntimeException: Boom%n\tat org.springframework.boot.logging.logback.GraylogExtendedLogFormatStructuredLogFormatterTests.shouldFormatException" .formatted()); - assertThat(deserialized) .containsAllEntriesOf(map("_error_type", "java.lang.RuntimeException", "_error_message", "Boom")); diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatServiceTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatServiceTests.java index 5dd7fa9e458..b80e9c9946d 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatServiceTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/structured/GraylogExtendedLogFormatServiceTests.java @@ -35,10 +35,8 @@ class GraylogExtendedLogFormatServiceTests { MockEnvironment environment = new MockEnvironment(); environment.setProperty("logging.structured.gelf.service.name", "spring"); environment.setProperty("logging.structured.gelf.service.version", "1.2.3"); - environment.setProperty("logging.structured.gelf.service.environment", "prod"); - environment.setProperty("logging.structured.gelf.service.node-name", "boot"); GraylogExtendedLogFormatService service = GraylogExtendedLogFormatService.get(environment); - assertThat(service).isEqualTo(new GraylogExtendedLogFormatService("spring", "1.2.3", "prod", "boot")); + assertThat(service).isEqualTo(new GraylogExtendedLogFormatService("spring", "1.2.3")); } @Test @@ -46,7 +44,7 @@ class GraylogExtendedLogFormatServiceTests { MockEnvironment environment = new MockEnvironment(); environment.setProperty("spring.application.name", "spring"); GraylogExtendedLogFormatService service = GraylogExtendedLogFormatService.get(environment); - assertThat(service).isEqualTo(new GraylogExtendedLogFormatService("spring", null, null, null)); + assertThat(service).isEqualTo(new GraylogExtendedLogFormatService("spring", null)); } @Test @@ -54,23 +52,21 @@ class GraylogExtendedLogFormatServiceTests { MockEnvironment environment = new MockEnvironment(); environment.setProperty("spring.application.version", "1.2.3"); GraylogExtendedLogFormatService service = GraylogExtendedLogFormatService.get(environment); - assertThat(service).isEqualTo(new GraylogExtendedLogFormatService(null, "1.2.3", null, null)); + assertThat(service).isEqualTo(new GraylogExtendedLogFormatService(null, "1.2.3")); } @Test void getWhenNoPropertiesToBind() { MockEnvironment environment = new MockEnvironment(); GraylogExtendedLogFormatService service = GraylogExtendedLogFormatService.get(environment); - assertThat(service).isEqualTo(new GraylogExtendedLogFormatService(null, null, null, null)); + assertThat(service).isEqualTo(new GraylogExtendedLogFormatService(null, null)); } @Test void addToJsonMembersCreatesValidJson() { - GraylogExtendedLogFormatService service = new GraylogExtendedLogFormatService("spring", "1.2.3", "prod", - "boot"); + GraylogExtendedLogFormatService service = new GraylogExtendedLogFormatService("spring", "1.2.3"); JsonWriter writer = JsonWriter.of(service::jsonMembers); - assertThat(writer.writeToString(service)).isEqualTo("{\"host\":\"spring\",\"_service_version\":\"1.2.3\"," - + "\"_service_environment\":\"prod\",\"_service_node_name\":\"boot\"}"); + assertThat(writer.writeToString(service)).isEqualTo("{\"host\":\"spring\",\"_service_version\":\"1.2.3\"}"); } }