Add GCP complient tracing data to JSON logging

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/<my-trace-project>/traces/12345"`. Where `<my-trace-project>` has the same value as the `quarkus.application.name` config property.
++
+
+
+==== Configuration
 
 Configure the JSON logging extension using supported properties to customize its behavior.
 

extensions/logging-json/deployment/pom.xml

@@ -52,6 +52,11 @@
             <artifactId>quarkus-jackson-deployment</artifactId>
             <scope>test</scope>
         </dependency>
+        <dependency>
+            <groupId>io.quarkus</groupId>
+            <artifactId>quarkus-vertx-deployment</artifactId>
+            <scope>test</scope>
+        </dependency>
     </dependencies>
 
     <build>

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;
+    }
+}

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("");
+    }
+}