Merge pull request #45640 from brunobat/44440-otel-log-formatting

Fix Otel logging message formatting

Author: gsmet

extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingTest.java

@@ -172,6 +172,80 @@ public void testException() {
                                 .doesNotContainKey("sampled"));
     }
 
+    @Test
+    public void testLogFormatingData() {
+        final String message = "Replacement string";
+        final String expected = "infof " + message;
+        assertEquals("hello " + message, jBossLoggingBean.helloLogFormating(message));
+
+        List<LogRecordData> finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1);
+        LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1);
+
+        assertThat(last.getSpanContext().getSpanId()).isEqualTo("0000000000000000");
+        assertThat(last.getSpanContext().getTraceId()).isEqualTo("00000000000000000000000000000000");
+        assertThat(last.getSpanContext().getTraceFlags().asHex()).isEqualTo("00");
+        assertThat(last.getTimestampEpochNanos()).isNotNull().isLessThan(System.currentTimeMillis() * 1_000_000);
+
+        assertThat(last)
+                .hasSeverity(Severity.INFO)
+                .hasSeverityText("INFO")
+                .hasBody(expected)
+                .hasAttributesSatisfying(
+                        attributes -> assertThat(attributes)
+                                .containsEntry(CODE_NAMESPACE.getKey(),
+                                        "io.quarkus.opentelemetry.deployment.logs.OtelLoggingTest$JBossLoggingBean")
+                                .containsEntry(CODE_FUNCTION.getKey(), "helloLogFormating")
+                                .containsEntry(THREAD_NAME.getKey(), Thread.currentThread().getName())
+                                .containsEntry(THREAD_ID.getKey(), Thread.currentThread().getId())
+                                .containsEntry("log.logger.namespace", "org.jboss.logging.Logger")
+                                .containsKey(CODE_LINENO.getKey())
+                                .doesNotContainKey(EXCEPTION_TYPE)
+                                .doesNotContainKey(EXCEPTION_MESSAGE)
+                                .doesNotContainKey(EXCEPTION_STACKTRACE)
+                                .doesNotContainKey(LOG_FILE_PATH)
+                                // attributed do not duplicate tracing data
+                                .doesNotContainKey("spanId")
+                                .doesNotContainKey("traceId")
+                                .doesNotContainKey("sampled"));
+    }
+
+    @Test
+    public void testLogParameterValue() {
+        final String message = "Replacement parameter value";
+        final String expected = "infov " + message;
+        assertEquals("hello " + message, jBossLoggingBean.helloLogParameterValue(message));
+
+        List<LogRecordData> finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1);
+        LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1);
+
+        assertThat(last.getSpanContext().getSpanId()).isEqualTo("0000000000000000");
+        assertThat(last.getSpanContext().getTraceId()).isEqualTo("00000000000000000000000000000000");
+        assertThat(last.getSpanContext().getTraceFlags().asHex()).isEqualTo("00");
+        assertThat(last.getTimestampEpochNanos()).isNotNull().isLessThan(System.currentTimeMillis() * 1_000_000);
+
+        assertThat(last)
+                .hasSeverity(Severity.INFO)
+                .hasSeverityText("INFO")
+                .hasBody(expected)
+                .hasAttributesSatisfying(
+                        attributes -> assertThat(attributes)
+                                .containsEntry(CODE_NAMESPACE.getKey(),
+                                        "io.quarkus.opentelemetry.deployment.logs.OtelLoggingTest$JBossLoggingBean")
+                                .containsEntry(CODE_FUNCTION.getKey(), "helloLogParameterValue")
+                                .containsEntry(THREAD_NAME.getKey(), Thread.currentThread().getName())
+                                .containsEntry(THREAD_ID.getKey(), Thread.currentThread().getId())
+                                .containsEntry("log.logger.namespace", "org.jboss.logging.Logger")
+                                .containsKey(CODE_LINENO.getKey())
+                                .doesNotContainKey(EXCEPTION_TYPE)
+                                .doesNotContainKey(EXCEPTION_MESSAGE)
+                                .doesNotContainKey(EXCEPTION_STACKTRACE)
+                                .doesNotContainKey(LOG_FILE_PATH)
+                                // attributed do not duplicate tracing data
+                                .doesNotContainKey("spanId")
+                                .doesNotContainKey("traceId")
+                                .doesNotContainKey("sampled"));
+    }
+
     private String extractStackTrace(final Throwable throwable) {
         try (StringWriter sw = new StringWriter(1024); PrintWriter pw = new PrintWriter(sw)) {
             throwable.printStackTrace(pw);
@@ -201,5 +275,15 @@ public boolean logException(final Throwable throwable) {
             LOG.error("logging an exception", throwable);
             return true;
         }
+
+        public String helloLogFormating(final String replacement) {
+            LOG.infof("infof %s", replacement);
+            return "hello " + replacement;
+        }
+
+        public String helloLogParameterValue(final String replacement) {
+            LOG.infov("infov {0}", replacement);
+            return "hello " + replacement;
+        }
     }
 }

extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogHandler.java

@@ -13,6 +13,7 @@
 import java.time.Instant;
 import java.util.Map;
 import java.util.Optional;
+import java.util.logging.Formatter;
 import java.util.logging.Level;
 
 import org.eclipse.microprofile.config.Config;
@@ -52,7 +53,15 @@ protected void doPublish(ExtLogRecord record) {
         }
 
         if (record.getMessage() != null) {
-            logRecordBuilder.setBody(record.getMessage());
+            // Get the message
+            final Formatter formatter = getFormatter();
+            String logMsg;
+            if (formatter != null) {
+                logMsg = formatter.format(record);
+            } else {
+                logMsg = record.getFormattedMessage();
+            }
+            logRecordBuilder.setBody(logMsg);
         }
 
         final AttributesBuilder attributes = Attributes.builder();