diff --git a/docs/src/main/asciidoc/logging.adoc b/docs/src/main/asciidoc/logging.adoc index d0b68adb07f8b..d5e20fe42309a 100644 --- a/docs/src/main/asciidoc/logging.adoc +++ b/docs/src/main/asciidoc/logging.adoc @@ -363,6 +363,8 @@ Although the root logger's handlers are usually configured directly via `quarkus == Logging format +=== Human-readable text + {project-name} uses a pattern-based logging formatter that generates human-readable text logs by default, but you can also configure the format for each log handler by using a dedicated property. For the console handler, the property is `quarkus.log.console.format`. @@ -399,14 +401,8 @@ The logging format string supports the following symbols: |%x|Nested Diagnostics context values|Renders all the values from Nested Diagnostics Context in format `{value1.value2}`. |=== - -[id="alt-console-format"] -=== Alternative console logging formats - -Changing the console log format is useful, for example, when the console output of the Quarkus application is captured by a service that processes and stores the log information for later analysis. - [id="json-logging"] -==== JSON logging format +=== JSON logging format The `quarkus-logging-json` extension might be employed to add support for the JSON logging format and its related configuration. @@ -441,7 +437,21 @@ This can be achieved using different profiles, as shown in the following configu %test.quarkus.log.console.json.enabled=false ---- -===== Configuration ++ +. Choose the JSON logging format by setting the config property: +[source, properties] +---- +quarkus.log.console.json.log-format +---- +This case will set the format for the console. The config values are: + +* *default*: Will generate structured logging based on the `key,values` present in the log record. MDC and NDC data will be also included nested in `mdc` and `ndc` fields. +* *ecs*: https://www.elastic.co/docs/reference/ecs/ecs-field-reference[Elastic Common Fields]. Some default fields names are modified and some otheres are added to better comply with ECS. Namely: `@timestamp`,`log.logger`, `log.level`, `process.pid`, `process.name`, `process.thread.name`, `process.thread.id`, `host.hostname`, `event.sequence`, `error.message`, `error.stack_trace`, `ecs.version`, `data_stream.type`, `service.name`, `service.version` and `service.environment`. +* *gcp*: https://cloud.google.com/logging/docs/structured-logging#structured_logging_special_fields[Google Cloud]. Follows the `Default` format and when the xref:opentelemetry-tracing.adoc[OpenTelemetry] is used, tracing data present in the `mdc` field is flattened and copied to `spanId`, `traceSampled` and `trace`, but this last one with a prefix. GCP requires the `trace` to follow this semantic: `"projects//traces/12345"`. Where `` has the same value as the `quarkus.application.name` config property. ++ + + +==== Configuration Configure the JSON logging extension using supported properties to customize its behavior. diff --git a/extensions/logging-json/deployment/pom.xml b/extensions/logging-json/deployment/pom.xml index 2412f617653c1..55f7a5f436c9a 100644 --- a/extensions/logging-json/deployment/pom.xml +++ b/extensions/logging-json/deployment/pom.xml @@ -52,6 +52,11 @@ quarkus-jackson-deployment test + + io.quarkus + quarkus-vertx-deployment + test + diff --git a/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/ConsoleJsonFormatterGCPConfigTest.java b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/ConsoleJsonFormatterGCPConfigTest.java new file mode 100644 index 0000000000000..d2340f075839f --- /dev/null +++ b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/ConsoleJsonFormatterGCPConfigTest.java @@ -0,0 +1,84 @@ +package io.quarkus.logging.json; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.time.ZoneId; +import java.time.format.DateTimeFormatter; +import java.util.Arrays; +import java.util.logging.Formatter; +import java.util.logging.Handler; +import java.util.logging.Level; +import java.util.logging.LogManager; +import java.util.logging.Logger; + +import org.jboss.logmanager.formatters.StructuredFormatter; +import org.jboss.logmanager.handlers.ConsoleHandler; +import org.jboss.shrinkwrap.api.asset.StringAsset; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import io.quarkus.bootstrap.logging.InitialConfigurator; +import io.quarkus.bootstrap.logging.QuarkusDelayedHandler; +import io.quarkus.logging.json.runtime.JsonFormatter; +import io.quarkus.test.QuarkusUnitTest; +import io.quarkus.vertx.core.runtime.VertxMDC; + +public class ConsoleJsonFormatterGCPConfigTest { + + @RegisterExtension + static final QuarkusUnitTest config = new QuarkusUnitTest() + .withApplicationRoot((jar) -> jar + .addAsResource(new StringAsset(""" + quarkus.log.level=INFO + quarkus.log.console.enabled=true + quarkus.log.console.level=WARNING + quarkus.log.console.format=%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c{3.}] (%t) %s%e%n + quarkus.log.console.json.enabled=true + quarkus.log.console.json.log-format=gcp + """), "application.properties")); + + @Test + public void jsonFormatterDefaultConfigurationTest() { + VertxMDC instance = VertxMDC.INSTANCE; + instance.put("traceId", "aaaaaaaaaaaaaaaaaaaaaaaa"); + instance.put("spanId", "bbbbbbbbbbbbbb"); + instance.put("sampled", "true"); + + JsonFormatter jsonFormatter = getJsonFormatter(); + assertThat(jsonFormatter.isPrettyPrint()).isFalse(); + assertThat(jsonFormatter.getDateTimeFormatter().toString()) + .isEqualTo(DateTimeFormatter.ISO_OFFSET_DATE_TIME.withZone(ZoneId.systemDefault()).toString()); + assertThat(jsonFormatter.getDateTimeFormatter().getZone()).isEqualTo(ZoneId.systemDefault()); + assertThat(jsonFormatter.getExceptionOutputType()).isEqualTo(StructuredFormatter.ExceptionOutputType.DETAILED); + assertThat(jsonFormatter.getRecordDelimiter()).isEqualTo("\n"); + assertThat(jsonFormatter.isPrintDetails()).isFalse(); + assertThat(jsonFormatter.getExcludedKeys()).isEmpty(); + assertThat(jsonFormatter.getAdditionalFields().entrySet()).isNotEmpty(); + assertThat(jsonFormatter.getAdditionalFields().get("trace")).isNotNull(); + assertThat(jsonFormatter.getAdditionalFields().get("spanId")).isNotNull(); + assertThat(jsonFormatter.getAdditionalFields().get("traceSampled")).isNotNull(); + + instance.remove("traceId"); + instance.remove("spanId"); + instance.remove("sampled"); + } + + public static JsonFormatter getJsonFormatter() { + LogManager logManager = LogManager.getLogManager(); + assertThat(logManager).isInstanceOf(org.jboss.logmanager.LogManager.class); + + QuarkusDelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER; + assertThat(Logger.getLogger("").getHandlers()).contains(delayedHandler); + assertThat(delayedHandler.getLevel()).isEqualTo(Level.ALL); + + Handler handler = Arrays.stream(delayedHandler.getHandlers()) + .filter(h -> (h instanceof ConsoleHandler)) + .findFirst().orElse(null); + assertThat(handler).isNotNull(); + assertThat(handler.getLevel()).isEqualTo(Level.WARNING); + + Formatter formatter = handler.getFormatter(); + assertThat(formatter).isInstanceOf(JsonFormatter.class); + return (JsonFormatter) formatter; + } +} diff --git a/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/FileJsonFormatterGCPConfigTest.java b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/FileJsonFormatterGCPConfigTest.java new file mode 100644 index 0000000000000..7edf7253255c0 --- /dev/null +++ b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/FileJsonFormatterGCPConfigTest.java @@ -0,0 +1,125 @@ +package io.quarkus.logging.json; + +import static io.quarkus.logging.json.FileJsonFormatterDefaultConfigTest.getJsonFormatter; +import static org.assertj.core.api.Assertions.assertThat; + +import java.time.ZoneId; +import java.util.logging.Level; +import java.util.logging.LogRecord; + +import org.assertj.core.api.Assertions; +import org.jboss.logmanager.formatters.StructuredFormatter; +import org.jboss.shrinkwrap.api.asset.StringAsset; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; + +import io.quarkus.logging.json.runtime.JsonFormatter; +import io.quarkus.logging.json.runtime.JsonLogConfig.AdditionalFieldConfig; +import io.quarkus.test.QuarkusUnitTest; +import io.quarkus.vertx.core.runtime.VertxMDC; + +public class FileJsonFormatterGCPConfigTest { + + @RegisterExtension + static final QuarkusUnitTest config = new QuarkusUnitTest() + .withApplicationRoot((jar) -> jar + .addClasses(FileJsonFormatterDefaultConfigTest.class) + .addAsResource(new StringAsset(""" + quarkus.log.level=INFO + quarkus.log.file.enabled=true + quarkus.log.file.level=WARNING + quarkus.log.file.json.enabled=true + quarkus.log.file.json.pretty-print=true + quarkus.log.file.json.date-format=d MMM uuuu + quarkus.log.file.json.record-delimiter=\\n; + quarkus.log.file.json.zone-id=UTC+05:00 + quarkus.log.file.json.exception-output-type=DETAILED_AND_FORMATTED + quarkus.log.file.json.print-details=true + quarkus.log.file.json.key-overrides=level=HEY + quarkus.log.file.json.excluded-keys=timestamp,sequence + quarkus.log.file.json.additional-field.foo.value=42 + quarkus.log.file.json.additional-field.foo.type=int + quarkus.log.file.json.additional-field.bar.value=baz + quarkus.log.file.json.additional-field.bar.type=string + quarkus.log.file.json.log-format=gcp + """), "application.properties")); + + @Test + public void jsonFormatterCustomConfigurationTest() { + JsonFormatter jsonFormatter = getJsonFormatter(); + assertThat(jsonFormatter.isPrettyPrint()).isTrue(); + assertThat(jsonFormatter.getDateTimeFormatter().toString()) + .isEqualTo("Value(DayOfMonth)' 'Text(MonthOfYear,SHORT)' 'Value(Year,4,19,EXCEEDS_PAD)"); + assertThat(jsonFormatter.getDateTimeFormatter().getZone()).isEqualTo(ZoneId.of("UTC+05:00")); + assertThat(jsonFormatter.getExceptionOutputType()) + .isEqualTo(StructuredFormatter.ExceptionOutputType.DETAILED_AND_FORMATTED); + assertThat(jsonFormatter.getRecordDelimiter()).isEqualTo("\n;"); + assertThat(jsonFormatter.isPrintDetails()).isTrue(); + assertThat(jsonFormatter.getExcludedKeys()).containsExactlyInAnyOrder("timestamp", "sequence"); + assertThat(jsonFormatter.getAdditionalFields().size()).isEqualTo(5); + assertThat(jsonFormatter.getAdditionalFields().containsKey("foo")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("foo").type()).isEqualTo(AdditionalFieldConfig.Type.INT); + assertThat(jsonFormatter.getAdditionalFields().get("foo").value()).isEqualTo("42"); + assertThat(jsonFormatter.getAdditionalFields().containsKey("bar")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("bar").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().get("bar").value()).isEqualTo("baz"); + assertThat(jsonFormatter.getAdditionalFields().containsKey("trace")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("trace").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().containsKey("spanId")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("spanId").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().containsKey("traceSampled")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("traceSampled").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + } + + @Test + public void jsonFormatterOutputTest() throws Exception { + VertxMDC instance = VertxMDC.INSTANCE; + instance.put("traceId", "aaaaaaaaaaaaaaaaaaaaaaaa"); + instance.put("spanId", "bbbbbbbbbbbbbb"); + instance.put("sampled", "true"); + + JsonFormatter jsonFormatter = getJsonFormatter(); + String line = jsonFormatter.format(new LogRecord(Level.INFO, "Hello, World!")); + + JsonNode node = new ObjectMapper().readTree(line); + // "level" has been renamed to HEY + Assertions.assertThat(node.has("level")).isFalse(); + Assertions.assertThat(node.has("HEY")).isTrue(); + Assertions.assertThat(node.get("HEY").asText()).isEqualTo("INFO"); + + // excluded fields + Assertions.assertThat(node.has("timestamp")).isFalse(); + Assertions.assertThat(node.has("sequence")).isFalse(); + + // additional fields + Assertions.assertThat(node.has("foo")).isTrue(); + Assertions.assertThat(node.get("foo").asInt()).isEqualTo(42); + Assertions.assertThat(node.has("bar")).isTrue(); + Assertions.assertThat(node.get("bar").asText()).isEqualTo("baz"); + Assertions.assertThat(node.get("message").asText()).isEqualTo("Hello, World!"); + Assertions.assertThat(node.has("trace")).isTrue(); + Assertions.assertThat(node.get("trace").asText()) + .isEqualTo("projects/quarkus-logging-json-deployment/traces/aaaaaaaaaaaaaaaaaaaaaaaa"); + Assertions.assertThat(node.has("spanId")).isTrue(); + Assertions.assertThat(node.get("spanId").asText()).isEqualTo("bbbbbbbbbbbbbb"); + Assertions.assertThat(node.has("traceSampled")).isTrue(); + Assertions.assertThat(node.get("traceSampled").asText()).isEqualTo("true"); + + instance.remove("traceId"); + instance.remove("spanId"); + instance.remove("sampled"); + + String line2 = jsonFormatter.format(new LogRecord(Level.INFO, "Make sure MDC data is not cached!")); + JsonNode node2 = new ObjectMapper().readTree(line2); + Assertions.assertThat(node2.get("message").asText()).isEqualTo("Make sure MDC data is not cached!"); + Assertions.assertThat(node2.has("trace")).isTrue(); + Assertions.assertThat(node2.get("trace").asText()).isEqualTo(""); + Assertions.assertThat(node2.has("spanId")).isTrue(); + Assertions.assertThat(node2.get("spanId").asText()).isEqualTo(""); + Assertions.assertThat(node2.has("traceSampled")).isTrue(); + Assertions.assertThat(node2.get("traceSampled").asText()).isEqualTo(""); + } +} diff --git a/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/SocketJsonFormatterGCPConfigTest.java b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/SocketJsonFormatterGCPConfigTest.java new file mode 100644 index 0000000000000..91d2b8ab8625e --- /dev/null +++ b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/SocketJsonFormatterGCPConfigTest.java @@ -0,0 +1,114 @@ +package io.quarkus.logging.json; + +import static io.quarkus.logging.json.SocketJsonFormatterDefaultConfigTest.getJsonFormatter; +import static org.assertj.core.api.Assertions.assertThat; + +import java.time.ZoneId; +import java.util.logging.Level; +import java.util.logging.LogRecord; + +import org.assertj.core.api.Assertions; +import org.jboss.logmanager.formatters.StructuredFormatter; +import org.jboss.shrinkwrap.api.asset.StringAsset; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; + +import io.quarkus.logging.json.runtime.JsonFormatter; +import io.quarkus.logging.json.runtime.JsonLogConfig.AdditionalFieldConfig; +import io.quarkus.test.QuarkusUnitTest; +import io.quarkus.vertx.core.runtime.VertxMDC; + +public class SocketJsonFormatterGCPConfigTest { + + @RegisterExtension + static final QuarkusUnitTest config = new QuarkusUnitTest() + .withApplicationRoot((jar) -> jar + .addClasses(SocketJsonFormatterDefaultConfigTest.class) + .addAsResource(new StringAsset(""" + quarkus.log.level=INFO + quarkus.log.socket.enabled=true + quarkus.log.socket.level=WARNING + quarkus.log.socket.json.enabled=true + quarkus.log.socket.json.pretty-print=true + quarkus.log.socket.json.date-format=d MMM uuuu + quarkus.log.socket.json.record-delimiter=\\n; + quarkus.log.socket.json.zone-id=UTC+05:00 + quarkus.log.socket.json.exception-output-type=DETAILED_AND_FORMATTED + quarkus.log.socket.json.print-details=true + quarkus.log.socket.json.key-overrides=level=HEY + quarkus.log.socket.json.excluded-keys=timestamp,sequence + quarkus.log.socket.json.additional-field.foo.value=42 + quarkus.log.socket.json.additional-field.foo.type=int + quarkus.log.socket.json.additional-field.bar.value=baz + quarkus.log.socket.json.additional-field.bar.type=string + quarkus.log.socket.json.log-format=gcp + """), "application.properties")); + + @Test + public void jsonFormatterCustomConfigurationTest() { + JsonFormatter jsonFormatter = getJsonFormatter(); + assertThat(jsonFormatter.isPrettyPrint()).isTrue(); + assertThat(jsonFormatter.getDateTimeFormatter().toString()) + .isEqualTo("Value(DayOfMonth)' 'Text(MonthOfYear,SHORT)' 'Value(Year,4,19,EXCEEDS_PAD)"); + assertThat(jsonFormatter.getDateTimeFormatter().getZone()).isEqualTo(ZoneId.of("UTC+05:00")); + assertThat(jsonFormatter.getExceptionOutputType()) + .isEqualTo(StructuredFormatter.ExceptionOutputType.DETAILED_AND_FORMATTED); + assertThat(jsonFormatter.getRecordDelimiter()).isEqualTo("\n;"); + assertThat(jsonFormatter.isPrintDetails()).isTrue(); + assertThat(jsonFormatter.getExcludedKeys()).containsExactlyInAnyOrder("timestamp", "sequence"); + assertThat(jsonFormatter.getAdditionalFields().size()).isEqualTo(5); + assertThat(jsonFormatter.getAdditionalFields().containsKey("foo")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("foo").type()).isEqualTo(AdditionalFieldConfig.Type.INT); + assertThat(jsonFormatter.getAdditionalFields().get("foo").value()).isEqualTo("42"); + assertThat(jsonFormatter.getAdditionalFields().containsKey("bar")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("bar").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().get("bar").value()).isEqualTo("baz"); + assertThat(jsonFormatter.getAdditionalFields().containsKey("trace")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("trace").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().containsKey("spanId")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("spanId").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().containsKey("traceSampled")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("traceSampled").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + } + + @Test + public void jsonFormatterOutputTest() throws Exception { + VertxMDC instance = VertxMDC.INSTANCE; + instance.put("traceId", "aaaaaaaaaaaaaaaaaaaaaaaa"); + instance.put("spanId", "bbbbbbbbbbbbbb"); + instance.put("sampled", "true"); + + JsonFormatter jsonFormatter = getJsonFormatter(); + String line = jsonFormatter.format(new LogRecord(Level.INFO, "Hello, World!")); + + JsonNode node = new ObjectMapper().readTree(line); + // "level" has been renamed to HEY + Assertions.assertThat(node.has("level")).isFalse(); + Assertions.assertThat(node.has("HEY")).isTrue(); + Assertions.assertThat(node.get("HEY").asText()).isEqualTo("INFO"); + + // excluded fields + Assertions.assertThat(node.has("timestamp")).isFalse(); + Assertions.assertThat(node.has("sequence")).isFalse(); + + // additional fields + Assertions.assertThat(node.has("foo")).isTrue(); + Assertions.assertThat(node.get("foo").asInt()).isEqualTo(42); + Assertions.assertThat(node.has("bar")).isTrue(); + Assertions.assertThat(node.get("bar").asText()).isEqualTo("baz"); + Assertions.assertThat(node.get("message").asText()).isEqualTo("Hello, World!"); + Assertions.assertThat(node.get("trace").asText()) + .isEqualTo("projects/quarkus-logging-json-deployment/traces/aaaaaaaaaaaaaaaaaaaaaaaa"); + Assertions.assertThat(node.has("spanId")).isTrue(); + Assertions.assertThat(node.get("spanId").asText()).isEqualTo("bbbbbbbbbbbbbb"); + Assertions.assertThat(node.has("traceSampled")).isTrue(); + Assertions.assertThat(node.get("traceSampled").asText()).isEqualTo("true"); + + instance.remove("traceId"); + instance.remove("spanId"); + instance.remove("sampled"); + } +} diff --git a/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/SyslogJsonFormatterGCPConfigTest.java b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/SyslogJsonFormatterGCPConfigTest.java new file mode 100644 index 0000000000000..6a6170e32f57d --- /dev/null +++ b/extensions/logging-json/deployment/src/test/java/io/quarkus/logging/json/SyslogJsonFormatterGCPConfigTest.java @@ -0,0 +1,115 @@ +package io.quarkus.logging.json; + +import static io.quarkus.logging.json.SyslogJsonFormatterDefaultConfigTest.getJsonFormatter; +import static org.assertj.core.api.Assertions.assertThat; + +import java.time.ZoneId; +import java.util.logging.Level; +import java.util.logging.LogRecord; + +import org.assertj.core.api.Assertions; +import org.jboss.logmanager.formatters.StructuredFormatter; +import org.jboss.shrinkwrap.api.asset.StringAsset; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; + +import io.quarkus.logging.json.runtime.JsonFormatter; +import io.quarkus.logging.json.runtime.JsonLogConfig.AdditionalFieldConfig; +import io.quarkus.test.QuarkusUnitTest; +import io.quarkus.vertx.core.runtime.VertxMDC; + +public class SyslogJsonFormatterGCPConfigTest { + + @RegisterExtension + static final QuarkusUnitTest config = new QuarkusUnitTest() + .withApplicationRoot((jar) -> jar + .addClasses(SyslogJsonFormatterDefaultConfigTest.class) + .addAsResource(new StringAsset(""" + quarkus.log.level=INFO + quarkus.log.syslog.enabled=true + quarkus.log.syslog.level=WARNING + quarkus.log.syslog.json.enabled=true + quarkus.log.syslog.json.pretty-print=true + quarkus.log.syslog.json.date-format=d MMM uuuu + quarkus.log.syslog.json.record-delimiter=\\n; + quarkus.log.syslog.json.zone-id=UTC+05:00 + quarkus.log.syslog.json.exception-output-type=DETAILED_AND_FORMATTED + quarkus.log.syslog.json.print-details=true + quarkus.log.syslog.json.key-overrides=level=HEY + quarkus.log.syslog.json.excluded-keys=timestamp,sequence + quarkus.log.syslog.json.additional-field.foo.value=42 + quarkus.log.syslog.json.additional-field.foo.type=int + quarkus.log.syslog.json.additional-field.bar.value=baz + quarkus.log.syslog.json.additional-field.bar.type=string + quarkus.log.syslog.json.log-format=gcp + """), "application.properties")); + + @Test + public void jsonFormatterCustomConfigurationTest() { + JsonFormatter jsonFormatter = getJsonFormatter(); + assertThat(jsonFormatter.isPrettyPrint()).isTrue(); + assertThat(jsonFormatter.getDateTimeFormatter().toString()) + .isEqualTo("Value(DayOfMonth)' 'Text(MonthOfYear,SHORT)' 'Value(Year,4,19,EXCEEDS_PAD)"); + assertThat(jsonFormatter.getDateTimeFormatter().getZone()).isEqualTo(ZoneId.of("UTC+05:00")); + assertThat(jsonFormatter.getExceptionOutputType()) + .isEqualTo(StructuredFormatter.ExceptionOutputType.DETAILED_AND_FORMATTED); + assertThat(jsonFormatter.getRecordDelimiter()).isEqualTo("\n;"); + assertThat(jsonFormatter.isPrintDetails()).isTrue(); + assertThat(jsonFormatter.getExcludedKeys()).containsExactlyInAnyOrder("timestamp", "sequence"); + assertThat(jsonFormatter.getAdditionalFields().size()).isEqualTo(5); + assertThat(jsonFormatter.getAdditionalFields().containsKey("foo")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("foo").type()).isEqualTo(AdditionalFieldConfig.Type.INT); + assertThat(jsonFormatter.getAdditionalFields().get("foo").value()).isEqualTo("42"); + assertThat(jsonFormatter.getAdditionalFields().containsKey("bar")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("bar").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().get("bar").value()).isEqualTo("baz"); + assertThat(jsonFormatter.getAdditionalFields().containsKey("trace")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("trace").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().containsKey("spanId")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("spanId").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + assertThat(jsonFormatter.getAdditionalFields().containsKey("traceSampled")).isTrue(); + assertThat(jsonFormatter.getAdditionalFields().get("traceSampled").type()).isEqualTo(AdditionalFieldConfig.Type.STRING); + } + + @Test + public void jsonFormatterOutputTest() throws Exception { + VertxMDC instance = VertxMDC.INSTANCE; + instance.put("traceId", "aaaaaaaaaaaaaaaaaaaaaaaab"); + instance.put("spanId", "bbbbbbbbbbbbbbc"); + instance.put("sampled", "false"); + + JsonFormatter jsonFormatter = getJsonFormatter(); + String line = jsonFormatter.format(new LogRecord(Level.INFO, "Hello, World!")); + + JsonNode node = new ObjectMapper().readTree(line); + // "level" has been renamed to HEY + Assertions.assertThat(node.has("level")).isFalse(); + Assertions.assertThat(node.has("HEY")).isTrue(); + Assertions.assertThat(node.get("HEY").asText()).isEqualTo("INFO"); + + // excluded fields + Assertions.assertThat(node.has("timestamp")).isFalse(); + Assertions.assertThat(node.has("sequence")).isFalse(); + + // additional fields + Assertions.assertThat(node.has("foo")).isTrue(); + Assertions.assertThat(node.get("foo").asInt()).isEqualTo(42); + Assertions.assertThat(node.has("bar")).isTrue(); + Assertions.assertThat(node.get("bar").asText()).isEqualTo("baz"); + Assertions.assertThat(node.get("message").asText()).isEqualTo("Hello, World!"); + Assertions.assertThat(node.has("trace")).isTrue(); + Assertions.assertThat(node.get("trace").asText()) + .isEqualTo("projects/quarkus-logging-json-deployment/traces/aaaaaaaaaaaaaaaaaaaaaaaab"); + Assertions.assertThat(node.has("spanId")).isTrue(); + Assertions.assertThat(node.get("spanId").asText()).isEqualTo("bbbbbbbbbbbbbbc"); + Assertions.assertThat(node.has("traceSampled")).isTrue(); + Assertions.assertThat(node.get("traceSampled").asText()).isEqualTo("false"); + + instance.remove("traceId"); + instance.remove("spanId"); + instance.remove("sampled"); + } +} diff --git a/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonFormatter.java b/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonFormatter.java index 3816d15fc208c..1c1919f2c084f 100644 --- a/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonFormatter.java +++ b/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonFormatter.java @@ -1,5 +1,9 @@ package io.quarkus.logging.json.runtime; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.*; +import static io.quarkus.logging.json.runtime.JsonLogConfig.AdditionalFieldConfig.Type.*; +import static java.util.Optional.*; + import java.io.Writer; import java.util.HashMap; import java.util.HashSet; @@ -8,10 +12,40 @@ import org.jboss.logmanager.ExtLogRecord; +import io.quarkus.logging.json.runtime.JsonLogConfig.JsonConfig.LogFormat; + public class JsonFormatter extends org.jboss.logmanager.formatters.JsonFormatter { private Set excludedKeys; private Map additionalFields; + private LogFormat logFormat = LogFormat.DEFAULT; + private String tracePrefix = ""; + + public enum AdditionalKey { + ECS_VERSION("ecs.version"), + DATA_STREAM_TYPE("data_stream.type"), + SERVICE_NAME("service.name"), + SERVICE_VERSION("service.version"), + SERVICE_ENVIRONMENT("service.environment"), + TRACE("trace"), + SPAN_ID("spanId"), + TRACE_SAMPLED("traceSampled"); + + private final String key; + + AdditionalKey(final String key) { + this.key = key; + } + + /** + * Returns the name of the key for the structure. + * + * @return the name of they key + */ + public String getKey() { + return key; + } + } /** * Creates a new JSON formatter. @@ -68,6 +102,14 @@ public void setAdditionalFields(Map additionalFields) { this.additionalFields = additionalFields; } + public void setLogFormat(LogFormat logFormat) { + this.logFormat = logFormat; + } + + public void setTracePrefix(String tracePrefix) { + this.tracePrefix = tracePrefix; + } + @Override protected Generator createGenerator(final Writer writer) { Generator superGenerator = super.createGenerator(writer); @@ -76,7 +118,37 @@ protected Generator createGenerator(final Writer writer) { @Override protected void after(final Generator generator, final ExtLogRecord record) throws Exception { - for (var entry : this.additionalFields.entrySet()) { + + if (logFormat.equals(LogFormat.GCP)) { + final Map mdcCopy = record.getMdcCopy(); + if (!mdcCopy.isEmpty()) { + Map current = new HashMap<>(additionalFields); + current.computeIfPresent(TRACE.getKey(), (key, value) -> { + final String traceId = mdcCopy.get("traceId"); + if (traceId != null && !traceId.isEmpty()) { + return new AdditionalField(tracePrefix + traceId, STRING); + } else { + return value; + } + }); + current.computeIfPresent(SPAN_ID.getKey(), + (key, value) -> new AdditionalField(ofNullable(mdcCopy.get("spanId")).orElse(""), STRING)); + current.computeIfPresent(TRACE_SAMPLED.getKey(), + (key, value) -> new AdditionalField(ofNullable(mdcCopy.get("sampled")).orElse(""), STRING)); + + addToGenerator(current, generator); + } else { + // fast path + addToGenerator(additionalFields, generator); + } + } else { + // fast path + addToGenerator(additionalFields, generator); + } + } + + private void addToGenerator(Map fields, Generator generator) throws Exception { + for (var entry : fields.entrySet()) { switch (entry.getValue().type()) { case STRING: generator.add(entry.getKey(), entry.getValue().value()); diff --git a/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonLogConfig.java b/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonLogConfig.java index 6123275b157d4..c84e04d318902 100644 --- a/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonLogConfig.java +++ b/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/JsonLogConfig.java @@ -129,7 +129,8 @@ public interface JsonConfig { public enum LogFormat { DEFAULT, - ECS + ECS, + GCP } } @@ -154,7 +155,7 @@ public interface AdditionalFieldConfig { public enum Type { STRING, INT, - LONG, + LONG } } } diff --git a/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/LoggingJsonRecorder.java b/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/LoggingJsonRecorder.java index eec43621233c9..2cf4cb9e78a57 100644 --- a/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/LoggingJsonRecorder.java +++ b/extensions/logging-json/runtime/src/main/java/io/quarkus/logging/json/runtime/LoggingJsonRecorder.java @@ -1,5 +1,14 @@ package io.quarkus.logging.json.runtime; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.DATA_STREAM_TYPE; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.ECS_VERSION; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.SERVICE_ENVIRONMENT; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.SERVICE_NAME; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.SERVICE_VERSION; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.SPAN_ID; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.TRACE; +import static io.quarkus.logging.json.runtime.JsonFormatter.AdditionalKey.TRACE_SAMPLED; + import java.util.EnumMap; import java.util.HashSet; import java.util.LinkedHashMap; @@ -17,15 +26,19 @@ import io.quarkus.logging.json.runtime.JsonLogConfig.AdditionalFieldConfig.Type; import io.quarkus.logging.json.runtime.JsonLogConfig.JsonConfig; +import io.quarkus.runtime.ApplicationConfig; import io.quarkus.runtime.RuntimeValue; import io.quarkus.runtime.annotations.Recorder; @Recorder public class LoggingJsonRecorder { private final RuntimeValue runtimeConfig; + private final RuntimeValue applicationConfig; - public LoggingJsonRecorder(final RuntimeValue runtimeConfig) { + public LoggingJsonRecorder(final RuntimeValue runtimeConfig, + final RuntimeValue applicationConfig) { this.runtimeConfig = runtimeConfig; + this.applicationConfig = applicationConfig; } public RuntimeValue> initializeConsoleJsonLogging() { @@ -55,6 +68,8 @@ private RuntimeValue> getFormatter(JsonConfig config) { if (config.logFormat() == JsonConfig.LogFormat.ECS) { overridableJsonConfig = addEcsFieldOverrides(overridableJsonConfig); + } else if (config.logFormat() == JsonConfig.LogFormat.GCP) { + overridableJsonConfig = addGCPFieldOverrides(overridableJsonConfig); } return getDefaultFormatter(config, overridableJsonConfig); @@ -72,6 +87,10 @@ private RuntimeValue> getDefaultFormatter(JsonConfig config, } else { formatter = new JsonFormatter(overridableJsonConfig.keyOverrides()); } + formatter.setLogFormat(config.logFormat()); + if (JsonConfig.LogFormat.GCP == config.logFormat()) { + formatter.setTracePrefix("projects/" + applicationConfig.getValue().name().orElse("") + "/traces/"); + } formatter.setExcludedKeys(overridableJsonConfig.excludedKeys()); formatter.setAdditionalFields(overridableJsonConfig.additionalFields()); formatter.setPrettyPrint(config.prettyPrint()); @@ -108,16 +127,30 @@ private OverridableJsonConfig addEcsFieldOverrides(OverridableJsonConfig overrid excludedKeys.add(Key.RECORD.getKey()); Map additionalFields = new LinkedHashMap<>(overridableJsonConfig.additionalFields()); - additionalFields.computeIfAbsent("ecs.version", k -> new AdditionalField("1.12.2", Type.STRING)); - additionalFields.computeIfAbsent("data_stream.type", k -> new AdditionalField("logs", Type.STRING)); + additionalFields.computeIfAbsent(ECS_VERSION.getKey(), k -> new AdditionalField("1.12.2", Type.STRING)); + additionalFields.computeIfAbsent(DATA_STREAM_TYPE.getKey(), k -> new AdditionalField("logs", Type.STRING)); Config quarkusConfig = ConfigProvider.getConfig(); quarkusConfig.getOptionalValue("quarkus.application.name", String.class).ifPresent( - s -> additionalFields.computeIfAbsent("service.name", k -> new AdditionalField(s, Type.STRING))); + s -> additionalFields.computeIfAbsent(SERVICE_NAME.getKey(), k -> new AdditionalField(s, Type.STRING))); quarkusConfig.getOptionalValue("quarkus.application.version", String.class).ifPresent( - s -> additionalFields.computeIfAbsent("service.version", k -> new AdditionalField(s, Type.STRING))); + s -> additionalFields.computeIfAbsent(SERVICE_VERSION.getKey(), k -> new AdditionalField(s, Type.STRING))); quarkusConfig.getOptionalValue("quarkus.profile", String.class).ifPresent( - s -> additionalFields.computeIfAbsent("service.environment", k -> new AdditionalField(s, Type.STRING))); + s -> additionalFields.computeIfAbsent(SERVICE_ENVIRONMENT.getKey(), k -> new AdditionalField(s, Type.STRING))); + + return new OverridableJsonConfig(PropertyValues.mapToString(keyOverrides), excludedKeys, additionalFields); + } + + private OverridableJsonConfig addGCPFieldOverrides(OverridableJsonConfig overridableJsonConfig) { + EnumMap keyOverrides = PropertyValues.stringToEnumMap(Key.class, overridableJsonConfig.keyOverrides()); + keyOverrides.putIfAbsent(Key.LEVEL, "severity"); + + Set excludedKeys = new HashSet<>(overridableJsonConfig.excludedKeys()); + Map additionalFields = new LinkedHashMap<>(overridableJsonConfig.additionalFields()); + // data comes from the MDC context and is only available in the JsonFormater + additionalFields.computeIfAbsent(TRACE.getKey(), k -> new AdditionalField("", Type.STRING)); + additionalFields.computeIfAbsent(SPAN_ID.getKey(), k -> new AdditionalField("", Type.STRING)); + additionalFields.computeIfAbsent(TRACE_SAMPLED.getKey(), k -> new AdditionalField("", Type.STRING)); return new OverridableJsonConfig(PropertyValues.mapToString(keyOverrides), excludedKeys, additionalFields); } diff --git a/integration-tests/logging-json/pom.xml b/integration-tests/logging-json/pom.xml index 380d77b785221..b47b9583a4d70 100644 --- a/integration-tests/logging-json/pom.xml +++ b/integration-tests/logging-json/pom.xml @@ -23,6 +23,10 @@ io.quarkus quarkus-logging-json + + io.quarkus + quarkus-opentelemetry + @@ -63,6 +67,20 @@ + + io.quarkus + quarkus-opentelemetry-deployment + ${project.version} + pom + test + + + * + * + + + + diff --git a/integration-tests/logging-json/src/main/resources/application.properties b/integration-tests/logging-json/src/main/resources/application.properties index e7b72560ddc4f..651bc0bb51300 100644 --- a/integration-tests/logging-json/src/main/resources/application.properties +++ b/integration-tests/logging-json/src/main/resources/application.properties @@ -1 +1,2 @@ quarkus.log.file.enabled=true +quarkus.log.file.json.log-format=gcp