From 3859533ce6deae63579ab372304be5fa1dea5fb2 Mon Sep 17 00:00:00 2001 From: brunobat Date: Mon, 23 Sep 2024 18:37:22 +0100 Subject: [PATCH] More tests and address PR reviews --- docs/src/main/asciidoc/logging.adoc | 5 + .../main/asciidoc/opentelemetry-logging.adoc | 6 +- .../deployment/OpenTelemetryProcessor.java | 1 - .../logging/LogHandlerProcessor.java | 7 +- .../exporter/InMemoryLogRecordExporter.java | 10 + .../deployment/logs/LoggingFrameworkTest.java | 39 ++-- .../deployment/logs/OtelLoggingFileTest.java | 43 ++-- .../deployment/logs/OtelLoggingTest.java | 99 +++++---- .../logs/OtelLogsHandlerDisabledTest.java | 74 +++++++ .../runtime/logs/OpenTelemetryLogHandler.java | 136 ++++++------ .../logs/OpenTelemetryLogRecorder.java | 9 +- .../opentelemetry-logging/pom.xml | 128 ------------ .../it/LogRecordExporterProducer.java | 18 -- .../opentelemetry/it/LoggingResource.java | 45 ---- .../src/main/resources/application.properties | 4 - .../opentelemetry/it/LoggingResourceTest.java | 72 ------- .../it/opentelemetry/ExporterResource.java | 38 ++++ .../it/opentelemetry/SimpleResource.java | 16 +- .../it/opentelemetry/TracedService.java | 7 + .../output/LogRecordDataSerializer.java | 48 +++++ ...ializer.java => OtelModuleSerializer.java} | 4 +- .../src/main/resources/application.properties | 2 + .../it/opentelemetry}/LoggingResourceIT.java | 2 +- .../it/opentelemetry/LoggingResourceTest.java | 197 ++++++++++++++++++ integration-tests/pom.xml | 1 - 25 files changed, 587 insertions(+), 424 deletions(-) create mode 100644 extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLogsHandlerDisabledTest.java delete mode 100644 integration-tests/opentelemetry-logging/pom.xml delete mode 100644 integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LogRecordExporterProducer.java delete mode 100644 integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LoggingResource.java delete mode 100644 integration-tests/opentelemetry-logging/src/main/resources/application.properties delete mode 100644 integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceTest.java create mode 100644 integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/LogRecordDataSerializer.java rename integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/{SpanDataModuleSerializer.java => OtelModuleSerializer.java} (72%) rename integration-tests/{opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it => opentelemetry/src/test/java/io/quarkus/it/opentelemetry}/LoggingResourceIT.java (75%) create mode 100644 integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceTest.java diff --git a/docs/src/main/asciidoc/logging.adoc b/docs/src/main/asciidoc/logging.adoc index 8c9f685c13194..3a0503f20f1d6 100644 --- a/docs/src/main/asciidoc/logging.adoc +++ b/docs/src/main/asciidoc/logging.adoc @@ -628,6 +628,11 @@ Use a centralized location to efficiently collect, store, and analyze log data f To send logs to a centralized tool such as Graylog, Logstash, or Fluentd, see the Quarkus xref:centralized-log-management.adoc[Centralized log management] guide. +=== OpenTelemetry logging +Logging entries from all appenders can be sent using OpenTelemetry Logging. + +For details, see the Quarkus xref:opentelemetry-logging.adoc[OpenTelemetry Logging] guide. + == Configure logging for `@QuarkusTest` Enable proper logging for `@QuarkusTest` by setting the `java.util.logging.manager` system property to `org.jboss.logmanager.LogManager`. diff --git a/docs/src/main/asciidoc/opentelemetry-logging.adoc b/docs/src/main/asciidoc/opentelemetry-logging.adoc index cd2a64823c4f2..9c53a762730a4 100644 --- a/docs/src/main/asciidoc/opentelemetry-logging.adoc +++ b/docs/src/main/asciidoc/opentelemetry-logging.adoc @@ -104,8 +104,6 @@ If you have followed the tracing guide, this class will seem familiar. The main === Create the configuration -=== Create the configuration - The only mandatory configuration for OpenTelemetry Logging is the one enabling it: [source,properties] ---- @@ -149,10 +147,10 @@ This features a Quarkus Dev service including a Grafana for visualizing data, Lo ==== Logging exporter -You can output all metrics to the console by setting the exporter to `logging` in the `application.properties` file: +You can output all logs to the console by setting the exporter to `logging` in the `application.properties` file: [source, properties] ---- -quarkus.otel.metrics.exporter=logging <1> +quarkus.otel.logs.exporter=logging <1> ---- <1> Set the exporter to `logging`. diff --git a/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/OpenTelemetryProcessor.java b/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/OpenTelemetryProcessor.java index 173c3288c24fa..ce33cb38fd099 100644 --- a/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/OpenTelemetryProcessor.java +++ b/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/OpenTelemetryProcessor.java @@ -180,7 +180,6 @@ void handleServices(OTelBuildConfig config, Set.of("META-INF/services/io.opentelemetry.sdk.autoconfigure.spi.logs.ConfigurableLogRecordExporterProvider"))); } - // TODO these classes don't exist! runtimeReinitialized.produce( new RuntimeReinitializedClassBuildItem("io.opentelemetry.sdk.autoconfigure.TracerProviderConfiguration")); runtimeReinitialized.produce( diff --git a/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/logging/LogHandlerProcessor.java b/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/logging/LogHandlerProcessor.java index 7916166b2cf5d..1409bf71aa518 100644 --- a/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/logging/LogHandlerProcessor.java +++ b/extensions/opentelemetry/deployment/src/main/java/io/quarkus/opentelemetry/deployment/logging/LogHandlerProcessor.java @@ -4,6 +4,7 @@ import java.util.function.Function; import io.quarkus.agroal.spi.OpenTelemetryInitBuildItem; +import io.quarkus.arc.deployment.BeanContainerBuildItem; import io.quarkus.deployment.annotations.BuildStep; import io.quarkus.deployment.annotations.BuildSteps; import io.quarkus.deployment.annotations.Consume; @@ -20,8 +21,10 @@ class LogHandlerProcessor { @BuildStep @Record(ExecutionTime.RUNTIME_INIT) @Consume(OpenTelemetryInitBuildItem.class) - LogHandlerBuildItem build(OpenTelemetryLogRecorder recorder, OpenTelemetryLogConfig config) { - return new LogHandlerBuildItem(recorder.initializeHandler(config)); + LogHandlerBuildItem build(OpenTelemetryLogRecorder recorder, + OpenTelemetryLogConfig config, + BeanContainerBuildItem beanContainerBuildItem) { + return new LogHandlerBuildItem(recorder.initializeHandler(beanContainerBuildItem.getValue(), config)); } public static class LogsEnabled implements BooleanSupplier { diff --git a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/common/exporter/InMemoryLogRecordExporter.java b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/common/exporter/InMemoryLogRecordExporter.java index c5ba99a9fc780..d473ac39377b6 100644 --- a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/common/exporter/InMemoryLogRecordExporter.java +++ b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/common/exporter/InMemoryLogRecordExporter.java @@ -3,6 +3,7 @@ import static java.util.concurrent.TimeUnit.SECONDS; import static org.assertj.core.api.Assertions.assertThat; +import java.time.Duration; import java.util.ArrayList; import java.util.Collection; import java.util.Collections; @@ -38,6 +39,15 @@ public List getFinishedLogRecordItemsAtLeast(final int count) { return getFinishedLogRecordItems(); } + public List getFinishedLogRecordItemsWithWait(final Duration duration) { + try { + Thread.sleep(duration.toMillis()); + } catch (InterruptedException e) { + throw new RuntimeException(e); + } + return getFinishedLogRecordItems(); + } + private List getFinishedLogRecordItems() { return Collections.unmodifiableList(new ArrayList(this.finishedLogItems)); } diff --git a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/LoggingFrameworkTest.java b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/LoggingFrameworkTest.java index c0a90bfaeb873..980d5e6db918d 100644 --- a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/LoggingFrameworkTest.java +++ b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/LoggingFrameworkTest.java @@ -1,6 +1,6 @@ package io.quarkus.opentelemetry.deployment.logs; -import static org.assertj.core.api.Assertions.assertThat; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; import static org.junit.jupiter.api.Assertions.assertEquals; import java.util.List; @@ -16,7 +16,6 @@ import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.RegisterExtension; -import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.sdk.logs.data.LogRecordData; import io.quarkus.opentelemetry.deployment.common.exporter.InMemoryLogRecordExporter; import io.quarkus.opentelemetry.deployment.common.exporter.InMemoryLogRecordExporterProvider; @@ -63,9 +62,12 @@ public void testJBossLogging() { assertEquals("hello", jBossLoggingBean.hello(message)); List finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1); LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1); - assertThat(last.getBody().asString()).isEqualTo(message); - assertThat(last.getAttributes().asMap().get(AttributeKey.stringKey("log.logger.namespace"))) - .isEqualTo("org.jboss.logging.Logger"); + + assertThat(last) + .hasBody(message) + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry("log.logger.namespace", "org.jboss.logging.Logger")); } @Test @@ -74,9 +76,12 @@ public void testSLF4JLogging() { assertEquals("hello", slf4jBean.hello(message)); List finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1); LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1); - assertThat(last.getBody().asString()).isEqualTo(message); - assertThat(last.getAttributes().asMap().get(AttributeKey.stringKey("log.logger.namespace"))) - .isEqualTo("org.slf4j.impl.Slf4jLogger"); + + assertThat(last) + .hasBody(message) + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry("log.logger.namespace", "org.slf4j.impl.Slf4jLogger")); } @Test @@ -85,9 +90,12 @@ public void testLog4jLogging() { assertEquals("hello", log4j2Bean.hello(message)); List finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1); LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1); - assertThat(last.getBody().asString()).isEqualTo(message); - assertThat(last.getAttributes().asMap().get(AttributeKey.stringKey("log.logger.namespace"))) - .isEqualTo("org.apache.logging.log4j.spi.AbstractLogger"); + + assertThat(last) + .hasBody(message) + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry("log.logger.namespace", "org.apache.logging.log4j.spi.AbstractLogger")); } @Test @@ -96,9 +104,12 @@ public void testJulLogging() { assertEquals("hello", julBean.hello(message)); List finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1); LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1); - assertThat(last.getBody().asString()).isEqualTo(message); - assertThat(last.getAttributes().asMap().get(AttributeKey.stringKey("log.logger.namespace"))) - .isEqualTo("org.jboss.logmanager.Logger"); + + assertThat(last) + .hasBody(message) + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry("log.logger.namespace", "org.jboss.logmanager.Logger")); } @ApplicationScoped diff --git a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingFileTest.java b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingFileTest.java index 4cf4caadb8c29..8f0794f0fe580 100644 --- a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingFileTest.java +++ b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingFileTest.java @@ -1,5 +1,7 @@ package io.quarkus.opentelemetry.deployment.logs; +import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE; +import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE; import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE; import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FUNCTION; import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_LINENO; @@ -7,11 +9,9 @@ import static io.opentelemetry.semconv.incubating.LogIncubatingAttributes.LOG_FILE_PATH; import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID; import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME; -import static org.assertj.core.api.Assertions.assertThat; import static org.junit.jupiter.api.Assertions.assertEquals; import java.util.List; -import java.util.Map; import jakarta.enterprise.context.ApplicationScoped; import jakarta.inject.Inject; @@ -24,9 +24,9 @@ import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.RegisterExtension; -import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.logs.Severity; import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import io.quarkus.opentelemetry.deployment.common.exporter.InMemoryLogRecordExporter; import io.quarkus.opentelemetry.deployment.common.exporter.InMemoryLogRecordExporterProvider; import io.quarkus.test.QuarkusUnitTest; @@ -66,22 +66,27 @@ public void testLoggingData() { List finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1); LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1); - assertThat(last.getTimestampEpochNanos()).isNotNull().isLessThan(System.currentTimeMillis() * 1_000_000); - assertThat(last.getSeverityText()).isEqualTo("INFO"); - assertThat(last.getSeverity()).isEqualTo(Severity.INFO); - assertThat(last.getBody().asString()).isEqualTo(message); - - Map, Object> attributesMap = last.getAttributes().asMap(); - assertThat(attributesMap.get(CODE_NAMESPACE)) - .isEqualTo("io.quarkus.opentelemetry.deployment.logs.OtelLoggingFileTest$JBossLoggingBean"); - assertThat(attributesMap.get(CODE_FUNCTION)).isEqualTo("hello"); - assertThat((Long) attributesMap.get(CODE_LINENO)).isGreaterThan(0); - assertThat(attributesMap.get(THREAD_NAME)).isEqualTo(Thread.currentThread().getName()); - assertThat(attributesMap.get(THREAD_ID)).isEqualTo(Thread.currentThread().getId()); - assertThat(attributesMap.get(AttributeKey.stringKey("log.logger.namespace"))).isEqualTo("org.jboss.logging.Logger"); - assertThat(attributesMap.get(EXCEPTION_TYPE)).isNull(); - // using the default location for the log file - assertThat(attributesMap.get(LOG_FILE_PATH)).isEqualTo("target/quarkus.log"); + OpenTelemetryAssertions.assertThat(last) + .hasSeverity(Severity.INFO) + .hasSeverityText("INFO") + .hasBody(message) + .hasAttributesSatisfying( + attributes -> OpenTelemetryAssertions.assertThat(attributes) + .containsEntry(CODE_NAMESPACE.getKey(), + "io.quarkus.opentelemetry.deployment.logs.OtelLoggingFileTest$JBossLoggingBean") + .containsEntry(CODE_FUNCTION.getKey(), "hello") + .containsEntry(THREAD_NAME.getKey(), Thread.currentThread().getName()) + .containsEntry(THREAD_ID.getKey(), Thread.currentThread().getId()) + .containsEntry("log.logger.namespace", "org.jboss.logging.Logger") + .containsEntry(LOG_FILE_PATH, "target/quarkus.log") + .containsKey(CODE_LINENO.getKey()) + .doesNotContainKey(EXCEPTION_TYPE) + .doesNotContainKey(EXCEPTION_MESSAGE) + .doesNotContainKey(EXCEPTION_STACKTRACE) + // attributed do not duplicate tracing data + .doesNotContainKey("spanId") + .doesNotContainKey("traceId") + .doesNotContainKey("sampled")); } @ApplicationScoped diff --git a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingTest.java b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingTest.java index e8827cc9ae3a5..7099ab11bf565 100644 --- a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingTest.java +++ b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLoggingTest.java @@ -1,6 +1,7 @@ package io.quarkus.opentelemetry.deployment.logs; import static io.opentelemetry.api.trace.SpanKind.INTERNAL; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE; import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE; import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE; @@ -11,14 +12,12 @@ import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID; import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME; import static io.quarkus.opentelemetry.deployment.common.exporter.TestSpanExporter.getSpanByKindAndParentId; -import static org.assertj.core.api.Assertions.assertThat; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertTrue; import java.io.PrintWriter; import java.io.StringWriter; import java.util.List; -import java.util.Map; import jakarta.enterprise.context.ApplicationScoped; import jakarta.inject.Inject; @@ -31,7 +30,6 @@ import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.RegisterExtension; -import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.logs.Severity; import io.opentelemetry.instrumentation.annotations.WithSpan; import io.opentelemetry.sdk.logs.data.LogRecordData; @@ -87,26 +85,28 @@ public void testLoggingData() { 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.getSeverityText()).isEqualTo("INFO"); - assertThat(last.getSeverity()).isEqualTo(Severity.INFO); - assertThat(last.getBody().asString()).isEqualTo(message); - - Map, Object> attributesMap = last.getAttributes().asMap(); - assertThat(attributesMap.get(CODE_NAMESPACE)) - .isEqualTo("io.quarkus.opentelemetry.deployment.logs.OtelLoggingTest$JBossLoggingBean"); - assertThat(attributesMap.get(CODE_FUNCTION)).isEqualTo("hello"); - assertThat((Long) attributesMap.get(CODE_LINENO)).isGreaterThan(0); - assertThat(attributesMap.get(THREAD_NAME)).isEqualTo(Thread.currentThread().getName()); - assertThat(attributesMap.get(THREAD_ID)).isEqualTo(Thread.currentThread().getId()); - assertThat(attributesMap.get(AttributeKey.stringKey("log.logger.namespace"))).isEqualTo("org.jboss.logging.Logger"); - assertThat(attributesMap.get(EXCEPTION_TYPE)).isNull(); - assertThat(attributesMap.get(EXCEPTION_MESSAGE)).isNull(); - assertThat(attributesMap.get(EXCEPTION_STACKTRACE)).isNull(); - assertThat(attributesMap.get(LOG_FILE_PATH)).isNull(); - // attributed do not duplicate tracing data - assertThat(attributesMap.keySet().contains(AttributeKey.stringKey("spanId"))).isFalse(); - assertThat(attributesMap.keySet().contains(AttributeKey.stringKey("traceId"))).isFalse(); - assertThat(attributesMap.keySet().contains(AttributeKey.stringKey("sampled"))).isFalse(); + + assertThat(last) + .hasSeverity(Severity.INFO) + .hasSeverityText("INFO") + .hasBody(message) + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry(CODE_NAMESPACE.getKey(), + "io.quarkus.opentelemetry.deployment.logs.OtelLoggingTest$JBossLoggingBean") + .containsEntry(CODE_FUNCTION.getKey(), "hello") + .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 @@ -124,16 +124,28 @@ public void testTrace() { assertThat(last.getSpanContext().getSpanId()).isEqualTo(span.getSpanId()); assertThat(last.getSpanContext().getTraceId()).isEqualTo(span.getTraceId()); assertThat(last.getSpanContext().getTraceFlags()).isEqualTo(span.getSpanContext().getTraceFlags()); - assertThat(last.getBody().asString()).isEqualTo(message); - - Map, Object> attributesMap = last.getAttributes().asMap(); - assertThat(attributesMap.get(CODE_NAMESPACE)) - .isEqualTo("io.quarkus.opentelemetry.deployment.logs.OtelLoggingTest$JBossLoggingBean"); - assertThat(attributesMap.get(CODE_FUNCTION)).isEqualTo("helloTraced"); - // attributed do not duplicate tracing data - assertThat(attributesMap.keySet().contains(AttributeKey.stringKey("spanId"))).isFalse(); - assertThat(attributesMap.keySet().contains(AttributeKey.stringKey("traceId"))).isFalse(); - assertThat(attributesMap.keySet().contains(AttributeKey.stringKey("sampled"))).isFalse(); + + assertThat(last) + .hasSeverity(Severity.INFO) + .hasSeverityText("INFO") + .hasBody(message) + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry(CODE_NAMESPACE.getKey(), + "io.quarkus.opentelemetry.deployment.logs.OtelLoggingTest$JBossLoggingBean") + .containsEntry(CODE_FUNCTION.getKey(), "helloTraced") + .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 @@ -144,13 +156,20 @@ public void testException() { List finishedLogRecordItems = logRecordExporter.getFinishedLogRecordItemsAtLeast(1); LogRecordData last = finishedLogRecordItems.get(finishedLogRecordItems.size() - 1); - assertThat(last.getSeverityText()).isEqualTo("ERROR"); - assertThat(last.getSeverity()).isEqualTo(Severity.ERROR); - Map, Object> attributesMap = last.getAttributes().asMap(); - assertThat(attributesMap.get(EXCEPTION_TYPE)).isEqualTo("java.lang.RuntimeException"); - assertThat(attributesMap.get(EXCEPTION_MESSAGE)).isEqualTo("Crafted exception"); - assertThat(attributesMap.get(EXCEPTION_STACKTRACE)).isEqualTo(extractStackTrace(craftedException)); - assertThat(attributesMap.get(LOG_FILE_PATH)).isNull(); + assertThat(last) + .hasSeverity(Severity.ERROR) + .hasSeverityText("ERROR") + .hasAttributesSatisfying( + attributes -> assertThat(attributes) + .containsEntry("log.logger.namespace", "org.jboss.logging.Logger") + .containsEntry(EXCEPTION_TYPE, "java.lang.RuntimeException") + .containsEntry(EXCEPTION_MESSAGE, "Crafted exception") + .containsEntry(EXCEPTION_STACKTRACE, extractStackTrace(craftedException)) + .doesNotContainKey(LOG_FILE_PATH) + // attributed do not duplicate tracing data + .doesNotContainKey("spanId") + .doesNotContainKey("traceId") + .doesNotContainKey("sampled")); } private String extractStackTrace(final Throwable throwable) { diff --git a/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLogsHandlerDisabledTest.java b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLogsHandlerDisabledTest.java new file mode 100644 index 0000000000000..19be176c7e935 --- /dev/null +++ b/extensions/opentelemetry/deployment/src/test/java/io/quarkus/opentelemetry/deployment/logs/OtelLogsHandlerDisabledTest.java @@ -0,0 +1,74 @@ +package io.quarkus.opentelemetry.deployment.logs; + +import static org.junit.jupiter.api.Assertions.assertEquals; + +import java.time.Duration; +import java.util.List; + +import jakarta.enterprise.context.ApplicationScoped; +import jakarta.inject.Inject; + +import org.jboss.logging.Logger; +import org.jboss.shrinkwrap.api.ShrinkWrap; +import org.jboss.shrinkwrap.api.asset.StringAsset; +import org.jboss.shrinkwrap.api.spec.JavaArchive; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.quarkus.opentelemetry.deployment.common.exporter.InMemoryLogRecordExporter; +import io.quarkus.opentelemetry.deployment.common.exporter.InMemoryLogRecordExporterProvider; +import io.quarkus.test.QuarkusUnitTest; + +public class OtelLogsHandlerDisabledTest { + @RegisterExtension + static final QuarkusUnitTest TEST = new QuarkusUnitTest() + .setArchiveProducer( + () -> ShrinkWrap.create(JavaArchive.class) + .addClasses(JBossLoggingBean.class) + .addClasses(InMemoryLogRecordExporter.class, InMemoryLogRecordExporterProvider.class) + .addAsResource(new StringAsset(InMemoryLogRecordExporterProvider.class.getCanonicalName()), + "META-INF/services/io.opentelemetry.sdk.autoconfigure.spi.logs.ConfigurableLogRecordExporterProvider") + .add(new StringAsset( + "quarkus.otel.logs.enabled=true\n" + + "quarkus.log.handler.open-telemetry.enabled=false\n\n" + + "quarkus.otel.traces.enabled=false\n"), + "application.properties")); + + @Inject + InMemoryLogRecordExporter logRecordExporter; + + @Inject + JBossLoggingBean jBossLoggingBean; + + @BeforeEach + void setup() { + logRecordExporter.reset(); + } + + @Test + public void testLoggingData() { + final String message = "Logging handler disabled"; + assertEquals("hello", jBossLoggingBean.hello(message)); + + List finishedLogRecordItems = logRecordExporter + .getFinishedLogRecordItemsWithWait(Duration.ofMillis(1000)); + assertEquals(0, finishedLogRecordItems.size()); + } + + @ApplicationScoped + public static class JBossLoggingBean { + private static final Logger LOG = Logger.getLogger(JBossLoggingBean.class.getName()); + + public String hello(final String message) { + LOG.info(message); + return "hello"; + } + + public boolean logException(final Throwable throwable) { + LOG.error("logging an exception", throwable); + return true; + } + } +} diff --git a/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogHandler.java b/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogHandler.java index b5d28fc28469c..45d79293af753 100644 --- a/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogHandler.java +++ b/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogHandler.java @@ -26,88 +26,84 @@ import io.opentelemetry.api.common.AttributesBuilder; import io.opentelemetry.api.logs.LogRecordBuilder; import io.opentelemetry.api.logs.Severity; -import io.quarkus.arc.Arc; -import io.quarkus.arc.ArcContainer; -import io.quarkus.arc.InstanceHandle; public class OpenTelemetryLogHandler extends Handler { private static final String THROWN_ATTRIBUTE = "thrown"; + private final OpenTelemetry openTelemetry; + + public OpenTelemetryLogHandler(final OpenTelemetry openTelemetry) { + this.openTelemetry = openTelemetry; + } @Override public void publish(LogRecord record) { - ArcContainer container = Arc.container(); - if (container == null || !container.instance(OpenTelemetry.class).isAvailable()) { - // "quarkus-opentelemetry-deployment stopped in Xs" will never be sent. - return; // evaluate creating cache of log entries here and replay them later. + if (openTelemetry == null) { + return; // might happen at shutdown } - try (InstanceHandle openTelemetry = container.instance(OpenTelemetry.class)) { - if (openTelemetry.isAvailable()) { - final LogRecordBuilder logRecordBuilder = openTelemetry.get().getLogsBridge() - .loggerBuilder(INSTRUMENTATION_NAME) - .build().logRecordBuilder() - .setObservedTimestamp(record.getInstant()); - - if (record.getLevel() != null) { - logRecordBuilder.setSeverity(mapSeverity(record.getLevel())) - .setSeverityText(record.getLevel().getName()); - } - - if (record.getMessage() != null) { - logRecordBuilder.setBody(record.getMessage()); - } - - final AttributesBuilder attributes = Attributes.builder(); - attributes.put(CODE_NAMESPACE, record.getSourceClassName()); - attributes.put(CODE_FUNCTION, record.getSourceMethodName()); - - if (record instanceof ExtLogRecord) { - attributes.put(CODE_LINENO, ((ExtLogRecord) record).getSourceLineNumber()); - attributes.put(THREAD_NAME, ((ExtLogRecord) record).getThreadName()); - attributes.put(THREAD_ID, ((ExtLogRecord) record).getLongThreadID()); - attributes.put(AttributeKey.stringKey("log.logger.namespace"), - ((ExtLogRecord) record).getLoggerClassName()); - - final Map mdcCopy = ((ExtLogRecord) record).getMdcCopy(); - if (mdcCopy != null) { - mdcCopy.forEach((k, v) -> { - // ignore duplicated span data already in the MDC - if (!k.toLowerCase().equals("spanid") && - !k.toLowerCase().equals("traceid") && - !k.toLowerCase().equals("sampled")) { - attributes.put(AttributeKey.stringKey(k), v); - } - }); - } - } - - if (record.getThrown() != null) { - // render as a standard out string - // TODO make bytes configurable - try (StringWriter sw = new StringWriter(1024); PrintWriter pw = new PrintWriter(sw)) { - record.getThrown().printStackTrace(pw); - sw.flush(); - attributes.put(EXCEPTION_STACKTRACE, sw.toString()); - } catch (Throwable t) { - attributes.put(EXCEPTION_STACKTRACE, - "Unable to get the stacktrace of the exception"); - } - attributes.put(EXCEPTION_TYPE, record.getThrown().getClass().getName()); - attributes.put(EXCEPTION_MESSAGE, record.getThrown().getMessage()); - } - - // required by spec - final Config config = ConfigProvider.getConfig(); - config.getOptionalValue("quarkus.log.file.enable", Boolean.class).ifPresent(enable -> { - Optional filePath = config.getOptionalValue("quarkus.log.file.path", String.class); - if (enable.equals(Boolean.TRUE) && filePath.isPresent()) { - attributes.put(LOG_FILE_PATH, filePath.get()); + final LogRecordBuilder logRecordBuilder = openTelemetry.getLogsBridge() + .loggerBuilder(INSTRUMENTATION_NAME) + .build().logRecordBuilder() + .setObservedTimestamp(record.getInstant()); + + if (record.getLevel() != null) { + logRecordBuilder.setSeverity(mapSeverity(record.getLevel())) + .setSeverityText(record.getLevel().getName()); + } + + if (record.getMessage() != null) { + logRecordBuilder.setBody(record.getMessage()); + } + + final AttributesBuilder attributes = Attributes.builder(); + attributes.put(CODE_NAMESPACE, record.getSourceClassName()); + attributes.put(CODE_FUNCTION, record.getSourceMethodName()); + + if (record instanceof ExtLogRecord) { + attributes.put(CODE_LINENO, ((ExtLogRecord) record).getSourceLineNumber()); + attributes.put(THREAD_NAME, ((ExtLogRecord) record).getThreadName()); + attributes.put(THREAD_ID, ((ExtLogRecord) record).getLongThreadID()); + attributes.put(AttributeKey.stringKey("log.logger.namespace"), + ((ExtLogRecord) record).getLoggerClassName()); + + final Map mdcCopy = ((ExtLogRecord) record).getMdcCopy(); + if (mdcCopy != null) { + mdcCopy.forEach((k, v) -> { + // ignore duplicated span data already in the MDC + if (!k.toLowerCase().equals("spanid") && + !k.toLowerCase().equals("traceid") && + !k.toLowerCase().equals("sampled")) { + attributes.put(AttributeKey.stringKey(k), v); } }); + } + } - logRecordBuilder.setAllAttributes(attributes.build()); - logRecordBuilder.emit(); + if (record.getThrown() != null) { + // render as a standard out string + // TODO make bytes configurable + try (StringWriter sw = new StringWriter(1024); PrintWriter pw = new PrintWriter(sw)) { + record.getThrown().printStackTrace(pw); + sw.flush(); + attributes.put(EXCEPTION_STACKTRACE, sw.toString()); + } catch (Throwable t) { + attributes.put(EXCEPTION_STACKTRACE, + "Unable to get the stacktrace of the exception"); } + attributes.put(EXCEPTION_TYPE, record.getThrown().getClass().getName()); + attributes.put(EXCEPTION_MESSAGE, record.getThrown().getMessage()); } + + // required by spec + final Config config = ConfigProvider.getConfig(); + config.getOptionalValue("quarkus.log.file.enable", Boolean.class).ifPresent(enable -> { + Optional filePath = config.getOptionalValue("quarkus.log.file.path", String.class); + if (enable.equals(Boolean.TRUE) && filePath.isPresent()) { + attributes.put(LOG_FILE_PATH, filePath.get()); + } + }); + + logRecordBuilder.setAllAttributes(attributes.build()); + logRecordBuilder.emit(); } private Severity mapSeverity(Level level) { diff --git a/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogRecorder.java b/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogRecorder.java index af762c98520f4..7f2c46e8176b6 100644 --- a/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogRecorder.java +++ b/extensions/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/logs/OpenTelemetryLogRecorder.java @@ -3,16 +3,19 @@ import java.util.Optional; import java.util.logging.Handler; +import io.opentelemetry.api.OpenTelemetry; +import io.quarkus.arc.runtime.BeanContainer; import io.quarkus.runtime.RuntimeValue; import io.quarkus.runtime.annotations.Recorder; @Recorder public class OpenTelemetryLogRecorder { - public RuntimeValue> initializeHandler(final OpenTelemetryLogConfig config) { + public RuntimeValue> initializeHandler(final BeanContainer beanContainer, + final OpenTelemetryLogConfig config) { if (!config.enabled()) { return new RuntimeValue<>(Optional.empty()); } - - return new RuntimeValue<>(Optional.of(new OpenTelemetryLogHandler())); + OpenTelemetry openTelemetry = beanContainer.beanInstance(OpenTelemetry.class); + return new RuntimeValue<>(Optional.of(new OpenTelemetryLogHandler(openTelemetry))); } } diff --git a/integration-tests/opentelemetry-logging/pom.xml b/integration-tests/opentelemetry-logging/pom.xml deleted file mode 100644 index f0b646c21849d..0000000000000 --- a/integration-tests/opentelemetry-logging/pom.xml +++ /dev/null @@ -1,128 +0,0 @@ - - - 4.0.0 - - io.quarkus - quarkus-integration-tests-parent - 999-SNAPSHOT - - quarkus-logging-opentelemetry-integration-tests - Quarkus - Integration Tests - Logging - OpenTelemetry - - true - - - - io.quarkus - quarkus-resteasy - - - io.quarkus - quarkus-opentelemetry - - - io.opentelemetry - opentelemetry-sdk-testing - - - - io.quarkus - quarkus-junit5 - test - - - io.rest-assured - rest-assured - test - - - org.awaitility - awaitility - test - - - io.quarkus - quarkus-opentelemetry-deployment - ${project.version} - pom - test - - - * - * - - - - - io.quarkus - quarkus-resteasy-deployment - ${project.version} - pom - test - - - * - * - - - - - - - - io.quarkus - quarkus-maven-plugin - - - - build - - - - - - maven-failsafe-plugin - - - - integration-test - verify - - - - ${project.build.directory}/${project.build.finalName}-runner - org.jboss.logmanager.LogManager - ${maven.home} - - - - - - - - - - native-image - - - native - - - - - - maven-surefire-plugin - - ${native.surefire.skip} - - - - - - false - native - - - - diff --git a/integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LogRecordExporterProducer.java b/integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LogRecordExporterProducer.java deleted file mode 100644 index 08285d48263d5..0000000000000 --- a/integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LogRecordExporterProducer.java +++ /dev/null @@ -1,18 +0,0 @@ -package io.quarkus.logging.opentelemetry.it; - -import jakarta.enterprise.context.ApplicationScoped; -import jakarta.enterprise.inject.Produces; -import jakarta.inject.Singleton; - -import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; -import io.quarkus.arc.Unremovable; - -@ApplicationScoped -public class LogRecordExporterProducer { - @Produces - @Singleton - @Unremovable - public InMemoryLogRecordExporter createInMemoryExporter() { - return InMemoryLogRecordExporter.create(); - } -} diff --git a/integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LoggingResource.java b/integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LoggingResource.java deleted file mode 100644 index f22b661d06189..0000000000000 --- a/integration-tests/opentelemetry-logging/src/main/java/io/quarkus/logging/opentelemetry/it/LoggingResource.java +++ /dev/null @@ -1,45 +0,0 @@ -/* -* Licensed to the Apache Software Foundation (ASF) under one or more -* contributor license agreements. See the NOTICE file distributed with -* this work for additional information regarding copyright ownership. -* The ASF licenses this file to You under the Apache License, Version 2.0 -* (the "License"); you may not use this file except in compliance with -* the License. You may obtain a copy of the License at -* -* http://www.apache.org/licenses/LICENSE-2.0 -* -* Unless required by applicable law or agreed to in writing, software -* distributed under the License is distributed on an "AS IS" BASIS, -* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -* See the License for the specific language governing permissions and -* limitations under the License. -*/ -package io.quarkus.logging.opentelemetry.it; - -import jakarta.enterprise.context.ApplicationScoped; -import jakarta.ws.rs.GET; -import jakarta.ws.rs.Path; - -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -@Path("/logging-opentelemetry") -@ApplicationScoped -public class LoggingResource { - private static final Logger LOG = LoggerFactory.getLogger(LoggingResource.class); - - @GET - @Path("/hello") - public String hello() { - LOG.info("Hello {}", "World"); - return "Hello World"; - } - - @GET - @Path("/exception") - public String exception() { - var exception = new RuntimeException("Exception!"); - LOG.error("Oh no {}", exception.getMessage(), exception); - return "Oh no! An exception"; - } -} diff --git a/integration-tests/opentelemetry-logging/src/main/resources/application.properties b/integration-tests/opentelemetry-logging/src/main/resources/application.properties deleted file mode 100644 index 84a32ad5d23cd..0000000000000 --- a/integration-tests/opentelemetry-logging/src/main/resources/application.properties +++ /dev/null @@ -1,4 +0,0 @@ -quarkus.log.handler.open-telemetry.enabled=true -quarkus.otel.exporter.otlp.logs.endpoint=http://localhost:4317 -quarkus.otel.traces.enabled=false -quarkus.otel.logs.enabled=true \ No newline at end of file diff --git a/integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceTest.java b/integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceTest.java deleted file mode 100644 index 9fb4b0267d3ba..0000000000000 --- a/integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceTest.java +++ /dev/null @@ -1,72 +0,0 @@ -package io.quarkus.logging.opentelemetry.it; - -import static io.restassured.RestAssured.given; -import static org.awaitility.Awaitility.await; -import static org.hamcrest.Matchers.is; -import static org.junit.jupiter.api.Assertions.assertEquals; -import static org.junit.jupiter.api.Assertions.assertTrue; - -import java.time.Duration; - -import jakarta.inject.Inject; - -import org.junit.jupiter.api.Test; - -import io.opentelemetry.api.common.AttributeKey; -import io.opentelemetry.api.logs.Severity; -import io.opentelemetry.sdk.logs.data.LogRecordData; -import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; -import io.quarkus.test.junit.QuarkusTest; - -@QuarkusTest -public class LoggingResourceTest { - @Inject - InMemoryLogRecordExporter exporter; - - @Test - public void testHelloEndpoint() { - // This will create 1 log, but some logs could already exist. - given() - .when().get("/logging-opentelemetry/hello") - .then() - .statusCode(200) - .body(is("Hello World")); - - // Wait for logs to be available as everything is async - await().atMost(Duration.ofSeconds(10)).until(() -> hasLog(exporter, "Hello World")); - - LogRecordData item = exporter.getFinishedLogRecordItems().get(exporter.getFinishedLogRecordItems().size() - 1); - assertEquals("Hello World", item.getBody().asString()); - assertEquals(Severity.INFO, item.getSeverity()); - } - - @Test - public void testException() { - // This will create 1 log, but some logs could already exist. - given() - .when().get("/logging-opentelemetry/exception") - .then() - .statusCode(200) - .body(is("Oh no! An exception")); - - // Wait for logs to be available as everything is async - await().atMost(Duration.ofSeconds(10)).until(() -> hasLog(exporter, "Oh no Exception!")); - - LogRecordData item = exporter.getFinishedLogRecordItems().get(exporter.getFinishedLogRecordItems().size() - 1); - assertEquals("Oh no Exception!", item.getBody().asString()); - assertEquals(Severity.ERROR, item.getSeverity()); - assertEquals(1, item.getAttributes().size()); - assertTrue(item.getAttributes().get(AttributeKey.stringKey("thrown")).startsWith(""" - java.lang.RuntimeException: Exception! - at io.quarkus.logging.opentelemetry.it.LoggingResource.exception(LoggingResource.java:41) - at io.quarkus.logging.opentelemetry.it.LoggingResource_ClientProxy.exception(Unknown Source)""")); - } - - private Boolean hasLog(InMemoryLogRecordExporter exporter, String body) { - return exporter.getFinishedLogRecordItems() != null && - !exporter.getFinishedLogRecordItems().isEmpty() && - exporter.getFinishedLogRecordItems().get(exporter.getFinishedLogRecordItems().size() - 1).getBody().asString() - .equals(body); - - } -} diff --git a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/ExporterResource.java b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/ExporterResource.java index 19048542c7907..df75f065e3122 100644 --- a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/ExporterResource.java +++ b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/ExporterResource.java @@ -16,7 +16,9 @@ import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.metrics.data.MetricData; +import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; import io.opentelemetry.sdk.testing.exporter.InMemoryMetricExporter; import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; import io.opentelemetry.sdk.trace.data.SpanData; @@ -28,15 +30,21 @@ public class ExporterResource { InMemorySpanExporter inMemorySpanExporter; @Inject InMemoryMetricExporter inMemoryMetricExporter; + @Inject + InMemoryLogRecordExporter inMemoryLogRecordExporter; @GET @Path("/reset") public Response reset() { inMemorySpanExporter.reset(); inMemoryMetricExporter.reset(); + inMemoryLogRecordExporter.reset(); return Response.ok().build(); } + /** + * Will exclude export endpoint related traces + */ @GET @Path("/export") public List exportTraces() { @@ -46,6 +54,9 @@ public List exportTraces() { .collect(Collectors.toList()); } + /** + * Export metrics with optional filtering by name and target + */ @GET @Path("/export/metrics") public List exportMetrics(@QueryParam("name") String name, @QueryParam("target") String target) { @@ -59,6 +70,24 @@ public List exportMetrics(@QueryParam("name") String name, @QueryPar .collect(Collectors.toList()))); } + /** + * Will exclude Quarkus startup logs + */ + @GET + @Path("/export/logs") + public List exportLogs(@QueryParam("body") String message) { + if (message == null) { + return inMemoryLogRecordExporter.getFinishedLogRecordItems().stream() + .filter(logRecordData -> !logRecordData.getAttributes().asMap() + .get(AttributeKey.stringKey("code.namespace")) + .equals("io.quarkus.bootstrap.runner.Timing")) + .collect(Collectors.toList()); + } + return inMemoryLogRecordExporter.getFinishedLogRecordItems().stream() + .filter(logRecordData -> logRecordData.getBody().asString().equals(message)) + .collect(Collectors.toList()); + } + private static boolean isPathFound(String path, Attributes attributes) { if (path == null) { return true;// any match @@ -87,4 +116,13 @@ InMemoryMetricExporter inMemoryMetricsExporter() { return InMemoryMetricExporter.create(); } } + + @ApplicationScoped + static class InMemoryLogRecordExporterProducer { + @Produces + @Singleton + public InMemoryLogRecordExporter createInMemoryExporter() { + return InMemoryLogRecordExporter.create(); + } + } } diff --git a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/SimpleResource.java b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/SimpleResource.java index 878ea3a44e6ac..aa1ef41f604cd 100644 --- a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/SimpleResource.java +++ b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/SimpleResource.java @@ -9,6 +9,8 @@ import org.eclipse.microprofile.rest.client.inject.RegisterRestClient; import org.eclipse.microprofile.rest.client.inject.RestClient; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import io.opentelemetry.api.baggage.Baggage; import io.opentelemetry.api.common.AttributeKey; @@ -19,6 +21,9 @@ @Path("") @Produces(MediaType.APPLICATION_JSON) public class SimpleResource { + + private static final Logger LOG = LoggerFactory.getLogger(SimpleResource.class); + @RegisterRestClient(configKey = "simple") public interface SimpleClient { @Path("") @@ -88,9 +93,9 @@ public TraceData fromBaggageValue() { @GET @Path("/direct") public TraceData directTrace() { + LOG.info("directTrace called"); TraceData data = new TraceData(); data.message = "Direct trace"; - return data; } @@ -110,6 +115,7 @@ public TraceData directTraceWithMetrics() { @GET @Path("/chained") public TraceData chainedTrace() { + LOG.info("chainedTrace called"); TraceData data = new TraceData(); data.message = tracedService.call(); @@ -133,4 +139,12 @@ public TraceData pathParameters(@PathParam("paramId") String paramId) { return data; } + + @GET + @Path("/exception") + public String exception() { + var exception = new RuntimeException("Exception!"); + LOG.error("Oh no {}", exception.getMessage(), exception); + return "Oh no! An exception"; + } } diff --git a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/TracedService.java b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/TracedService.java index 98d6e23ae5b36..ac90c481305fc 100644 --- a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/TracedService.java +++ b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/TracedService.java @@ -2,12 +2,19 @@ import jakarta.enterprise.context.ApplicationScoped; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + import io.opentelemetry.instrumentation.annotations.WithSpan; @ApplicationScoped public class TracedService { + + private static final Logger LOG = LoggerFactory.getLogger(TracedService.class); + @WithSpan public String call() { + LOG.info("Chained trace called"); return "Chained trace"; } } diff --git a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/LogRecordDataSerializer.java b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/LogRecordDataSerializer.java new file mode 100644 index 0000000000000..2d45824eca161 --- /dev/null +++ b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/LogRecordDataSerializer.java @@ -0,0 +1,48 @@ +package io.quarkus.it.opentelemetry.output; + +import java.io.IOException; + +import com.fasterxml.jackson.core.JsonGenerator; +import com.fasterxml.jackson.databind.SerializerProvider; +import com.fasterxml.jackson.databind.ser.std.StdSerializer; + +import io.opentelemetry.sdk.logs.data.LogRecordData; + +public class LogRecordDataSerializer extends StdSerializer { + + public LogRecordDataSerializer() { + this(null); + } + + public LogRecordDataSerializer(Class type) { + super(type); + } + + @Override + public void serialize(LogRecordData logRecordData, JsonGenerator jsonGenerator, SerializerProvider serializerProvider) + throws IOException { + jsonGenerator.writeStartObject(); + + jsonGenerator.writeStringField("severityText", logRecordData.getSeverityText()); + jsonGenerator.writeObjectField("spanContext", logRecordData.getSpanContext()); + jsonGenerator.writeStringField("body_body", logRecordData.getBody().asString()); + + logRecordData.getAttributes().forEach((k, v) -> { + try { + jsonGenerator.writeStringField("attr_" + k.getKey(), v.toString()); + } catch (IOException e) { + e.printStackTrace(); + } + }); + + logRecordData.getResource().getAttributes().forEach((k, v) -> { + try { + jsonGenerator.writeStringField("resource_" + k.getKey(), v.toString()); + } catch (IOException e) { + e.printStackTrace(); + } + }); + + jsonGenerator.writeEndObject(); + } +} diff --git a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/SpanDataModuleSerializer.java b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/OtelModuleSerializer.java similarity index 72% rename from integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/SpanDataModuleSerializer.java rename to integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/OtelModuleSerializer.java index 83564dfe092bb..bdd4b62157f20 100644 --- a/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/SpanDataModuleSerializer.java +++ b/integration-tests/opentelemetry/src/main/java/io/quarkus/it/opentelemetry/output/OtelModuleSerializer.java @@ -5,15 +5,17 @@ import com.fasterxml.jackson.databind.ObjectMapper; import com.fasterxml.jackson.databind.module.SimpleModule; +import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.trace.data.SpanData; import io.quarkus.jackson.ObjectMapperCustomizer; @Singleton -public class SpanDataModuleSerializer implements ObjectMapperCustomizer { +public class OtelModuleSerializer implements ObjectMapperCustomizer { @Override public void customize(ObjectMapper objectMapper) { SimpleModule simpleModule = new SimpleModule(); simpleModule.addSerializer(SpanData.class, new SpanDataSerializer()); + simpleModule.addSerializer(LogRecordData.class, new LogRecordDataSerializer()); objectMapper.registerModule(simpleModule); } } diff --git a/integration-tests/opentelemetry/src/main/resources/application.properties b/integration-tests/opentelemetry/src/main/resources/application.properties index 6ea19c81c9929..3df96e1b77b03 100644 --- a/integration-tests/opentelemetry/src/main/resources/application.properties +++ b/integration-tests/opentelemetry/src/main/resources/application.properties @@ -8,6 +8,8 @@ quarkus.otel.bsp.export.timeout=5s quarkus.otel.metrics.enabled=true quarkus.otel.metric.export.interval=100ms +quarkus.otel.logs.enabled=true + pingpong/mp-rest/url=${test.url} simple/mp-rest/url=${test.url} diff --git a/integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceIT.java b/integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceIT.java similarity index 75% rename from integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceIT.java rename to integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceIT.java index c3e8e518f2e51..eadbcb7212dd1 100644 --- a/integration-tests/opentelemetry-logging/src/test/java/io/quarkus/logging/opentelemetry/it/LoggingResourceIT.java +++ b/integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceIT.java @@ -1,4 +1,4 @@ -package io.quarkus.logging.opentelemetry.it; +package io.quarkus.it.opentelemetry; import io.quarkus.test.junit.QuarkusIntegrationTest; diff --git a/integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceTest.java b/integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceTest.java new file mode 100644 index 0000000000000..99049ca7e3248 --- /dev/null +++ b/integration-tests/opentelemetry/src/test/java/io/quarkus/it/opentelemetry/LoggingResourceTest.java @@ -0,0 +1,197 @@ +package io.quarkus.it.opentelemetry; + +import static io.opentelemetry.api.trace.SpanKind.INTERNAL; +import static io.opentelemetry.api.trace.SpanKind.SERVER; +import static io.restassured.RestAssured.get; +import static io.restassured.RestAssured.given; +import static java.net.HttpURLConnection.HTTP_OK; +import static java.util.concurrent.TimeUnit.SECONDS; +import static java.util.stream.Collectors.toList; +import static java.util.stream.Collectors.toSet; +import static org.awaitility.Awaitility.await; +import static org.hamcrest.Matchers.equalTo; +import static org.hamcrest.Matchers.is; +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import java.net.URL; +import java.time.Duration; +import java.util.List; +import java.util.Map; + +import org.hamcrest.CoreMatchers; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +import io.opentelemetry.api.trace.SpanId; +import io.opentelemetry.api.trace.SpanKind; +import io.opentelemetry.api.trace.TraceId; +import io.quarkus.test.common.http.TestHTTPResource; +import io.quarkus.test.junit.QuarkusTest; +import io.restassured.common.mapper.TypeRef; + +@QuarkusTest +public class LoggingResourceTest { + + @TestHTTPResource("deep/path") + URL deepPathUrl; + + @BeforeEach + @AfterEach + void reset() { + await().atMost(5, SECONDS).until(() -> { + List> logs = getLogs(); + if (logs.size() == 0) { + return true; + } else { + given().get("/reset").then().statusCode(HTTP_OK); + return false; + } + }); + } + + private List> getLogs() { + return get("/export/logs").body().as(new TypeRef<>() { + }); + } + + private List> getLogs(final String message) { + return given() + .when() + .queryParam("body", message) + .get("/export/logs") + .body() + .as(new TypeRef<>() { + }); + } + + private List> getSpans() { + return get("/export").body().as(new TypeRef<>() { + }); + } + + @Test + public void testDirectEndpoint() { + // This will create 1 log, but some logs could already exist. + given() + .contentType("application/json") + .when().get("/direct") + .then() + .statusCode(200) + .body("message", equalTo("Direct trace")); + + // Wait for logs to be available as everything is async + await().atMost(Duration.ofSeconds(100)).until(() -> getLogs("directTrace called").size() == 1); + Map logLine = getLogs("directTrace called").get(0); + + await().atMost(Duration.ofMinutes(2)).until(() -> getSpans().size() == 1); + Map spanData = getSpans().get(0); + + assertEquals(SpanId.getInvalid(), spanData.get("parent_spanId")); + assertEquals(TraceId.getInvalid(), spanData.get("parent_traceId")); + + assertEquals("INFO", logLine.get("severityText")); + Map logLineSpanContext = (Map) logLine.get("spanContext"); + assertEquals(spanData.get("traceId"), logLineSpanContext.get("traceId")); + assertEquals(spanData.get("spanId"), logLineSpanContext.get("spanId")); + } + + @Test + public void testException() { + // This will create 1 log, but some logs could already exist. + given() + .when().get("/exception") + .then() + .statusCode(200) + .body(is("Oh no! An exception")); + + // Wait for logs to be available as everything is async + await().atMost(Duration.ofSeconds(100)).until(() -> getLogs("Oh no Exception!").size() == 1); + Map logLine = getLogs("Oh no Exception!").get(0); + + await().atMost(Duration.ofMinutes(2)).until(() -> getSpans().size() == 1); + Map spanData = getSpans().get(0); + + assertEquals(SpanId.getInvalid(), spanData.get("parent_spanId")); + assertEquals(TraceId.getInvalid(), spanData.get("parent_traceId")); + + Map logLineSpanContext = (Map) logLine.get("spanContext"); + assertEquals(spanData.get("traceId"), logLineSpanContext.get("traceId")); + assertEquals(spanData.get("spanId"), logLineSpanContext.get("spanId")); + assertEquals(true, logLineSpanContext.get("sampled")); + + assertEquals("ERROR", logLine.get("severityText")); + assertEquals("java.lang.RuntimeException", logLine.get("attr_exception.type")); + assertTrue(((String) logLine.get("attr_exception.stacktrace")).startsWith(""" + java.lang.RuntimeException: Exception! + at io.quarkus.it.opentelemetry.SimpleResource.exception(SimpleResource.java:"""), + " Stacktrace found: " + logLine.get("attr_exception.stacktrace")); + } + + @Test + void testChainedResourceTracing() { + given() + .contentType("application/json") + .when().get("/chained") + .then() + .statusCode(200) + .body("message", CoreMatchers.equalTo("Chained trace")); + + await().atMost(5, SECONDS).until(() -> getSpans().size() == 2); + final List> spans = getSpans(); + assertEquals(2, spans.size()); + assertEquals(1, spans.stream().map(map -> map.get("traceId")).collect(toSet()).size()); + + // Server span + final Map server = getSpanByKindAndParentId(spans, SERVER, "0000000000000000"); + assertEquals(SERVER.toString(), server.get("kind")); + assertEquals("GET /chained", server.get("name")); + assertEquals(SERVER.toString(), server.get("kind")); + assertEquals(SpanId.getInvalid(), server.get("parent_spanId")); + assertEquals(TraceId.getInvalid(), server.get("parent_traceId")); + assertEquals(deepPathUrl.getHost(), server.get("attr_server.address")); + assertEquals(deepPathUrl.getPort(), Integer.valueOf((String) server.get("attr_server.port"))); + assertEquals("http", server.get("attr_url.scheme")); + assertEquals("200", server.get("attr_http.response.status_code")); + + // Wait for logs to be available as everything is async + await().atMost(Duration.ofSeconds(100)).until(() -> getLogs("chainedTrace called").size() == 1); + final Map serverLine = getLogs("chainedTrace called").get(0); + + final Map serverLineSpanContext = (Map) serverLine.get("spanContext"); + assertEquals(server.get("traceId"), serverLineSpanContext.get("traceId")); + assertEquals(server.get("spanId"), serverLineSpanContext.get("spanId")); + assertEquals(true, serverLineSpanContext.get("sampled")); + assertEquals("INFO", serverLine.get("severityText")); + + // chained CDI call + final Map cdi = getSpanByKindAndParentId(spans, INTERNAL, server.get("spanId")); + assertEquals("TracedService.call", cdi.get("name")); + assertEquals(SpanKind.INTERNAL.toString(), cdi.get("kind")); + assertEquals(server.get("spanId"), cdi.get("parent_spanId")); + + await().atMost(Duration.ofSeconds(100)).until(() -> getLogs("Chained trace called").size() == 1); + final Map cdiLine = getLogs("Chained trace called").get(0); + + final Map cdiLineSpanContext = (Map) cdiLine.get("spanContext"); + assertEquals(cdi.get("traceId"), cdiLineSpanContext.get("traceId")); + assertEquals(cdi.get("spanId"), cdiLineSpanContext.get("spanId")); + assertEquals(true, cdiLineSpanContext.get("sampled")); + assertEquals("INFO", cdiLine.get("severityText")); + } + + private static List> getSpansByKindAndParentId(List> spans, SpanKind kind, + Object parentSpanId) { + return spans.stream() + .filter(map -> map.get("kind").equals(kind.toString())) + .filter(map -> map.get("parentSpanId").equals(parentSpanId)).collect(toList()); + } + + private static Map getSpanByKindAndParentId(List> spans, SpanKind kind, + Object parentSpanId) { + List> span = getSpansByKindAndParentId(spans, kind, parentSpanId); + assertEquals(1, span.size()); + return span.get(0); + } +} diff --git a/integration-tests/pom.xml b/integration-tests/pom.xml index c762f3987440b..68478d3870851 100644 --- a/integration-tests/pom.xml +++ b/integration-tests/pom.xml @@ -413,7 +413,6 @@ virtual-threads mutiny-native-jctools - opentelemetry-logging