From 362a73dc467ea5e0beb69018c7606e85c5d313b7 Mon Sep 17 00:00:00 2001 From: Ladislav Thon Date: Thu, 19 Mar 2020 16:34:47 +0100 Subject: [PATCH 1/2] fix OpenTracing trace context propagation with Fault Tolerance @Asynchronous methods There used to be a test for that, but didn't involve `@Asynchronous` methods, so was in fact useless. This commit changes the test to actually call an `@Asynchronous` method, which revealed an issue. The `smallrye-fault-tolerance-tracing-propagation` dependency was missing, so trace context propagation didn't actually work. Then, the test also uncovered an issue in SmallRye Fault Tolerance (see https://github.com/smallrye/smallrye-fault-tolerance/pull/208), which is why this commit also brings a new version of it. In addition to that, this commit also adds a test for tracing JDBC. --- bom/runtime/pom.xml | 7 ++- .../smallrye-opentracing/deployment/pom.xml | 5 ++ .../opentracing/deployment/RestService.java | 15 +++-- .../opentracing/deployment/Service.java | 25 ++++++-- .../opentracing/deployment/TestResource.java | 12 +++- .../opentracing/deployment/TracingTest.java | 61 +++++++++++++++---- .../smallrye-opentracing/runtime/pom.xml | 10 +++ 7 files changed, 111 insertions(+), 24 deletions(-) diff --git a/bom/runtime/pom.xml b/bom/runtime/pom.xml index b06f04bb2ae91..b463a7d74cb63 100644 --- a/bom/runtime/pom.xml +++ b/bom/runtime/pom.xml @@ -37,7 +37,7 @@ 2.4.1 1.2.1 1.3.4 - 4.1.1 + 4.2.0 2.1.1 1.0.11 1.0.10 @@ -1447,6 +1447,11 @@ smallrye-fault-tolerance-context-propagation ${smallrye-fault-tolerance.version} + + io.smallrye + smallrye-fault-tolerance-tracing-propagation + ${smallrye-fault-tolerance.version} + io.smallrye smallrye-context-propagation diff --git a/extensions/smallrye-opentracing/deployment/pom.xml b/extensions/smallrye-opentracing/deployment/pom.xml index 0274703ba91d7..66bcd1acdd9a9 100644 --- a/extensions/smallrye-opentracing/deployment/pom.xml +++ b/extensions/smallrye-opentracing/deployment/pom.xml @@ -39,6 +39,11 @@ quarkus-jsonp-deployment + + io.quarkus + quarkus-resteasy-jackson + test + io.quarkus quarkus-rest-client-deployment diff --git a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/RestService.java b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/RestService.java index b1a340af3f4f3..67ba3ae5a3951 100644 --- a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/RestService.java +++ b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/RestService.java @@ -1,11 +1,14 @@ package io.quarkus.smallrye.opentracing.deployment; +import java.util.List; +import java.util.concurrent.CompletionStage; + import javax.ws.rs.GET; import javax.ws.rs.Path; +import javax.ws.rs.Produces; +import javax.ws.rs.core.MediaType; import javax.ws.rs.core.Response; -import org.eclipse.microprofile.opentracing.Traced; - @Path("/") public interface RestService { @@ -22,7 +25,11 @@ public interface RestService { Response restClient(); @GET - @Traced(false) @Path("/faultTolerance") - Response faultTolerance(); + CompletionStage faultTolerance(); + + @GET + @Path("/jpa") + @Produces(MediaType.APPLICATION_JSON) + List jpa(); } diff --git a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/Service.java b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/Service.java index 4ef743c4de634..2547e672cc275 100644 --- a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/Service.java +++ b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/Service.java @@ -1,10 +1,15 @@ package io.quarkus.smallrye.opentracing.deployment; import java.time.temporal.ChronoUnit; +import java.util.List; +import java.util.concurrent.CompletableFuture; +import java.util.concurrent.CompletionStage; import javax.enterprise.context.ApplicationScoped; import javax.inject.Inject; +import javax.persistence.EntityManager; +import org.eclipse.microprofile.faulttolerance.Asynchronous; import org.eclipse.microprofile.faulttolerance.Fallback; import org.eclipse.microprofile.faulttolerance.Retry; import org.eclipse.microprofile.faulttolerance.Timeout; @@ -12,25 +17,37 @@ import io.opentracing.Tracer; -@Traced @ApplicationScoped public class Service { @Inject Tracer tracer; + @Inject + EntityManager em; + + @Traced public void foo() { } + // @Asynchronous methods (and their fallback methods) shouldn't be @Traced + // because https://github.com/eclipse/microprofile-opentracing/issues/189 + @Asynchronous @Fallback(fallbackMethod = "fallback") @Timeout(value = 20L, unit = ChronoUnit.MILLIS) @Retry(delay = 10L, maxRetries = 2) - public String faultTolerance() { + public CompletionStage faultTolerance() { tracer.buildSpan("ft").start().finish(); throw new RuntimeException(); } - public String fallback() { - return "fallback"; + public CompletionStage fallback() { + tracer.buildSpan("fallback").start().finish(); + return CompletableFuture.completedFuture("fallback"); + } + + @Traced + public List getFruits() { + return em.createNamedQuery("Fruits.findAll", Fruit.class).getResultList(); } } diff --git a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TestResource.java b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TestResource.java index 3be1f0897913f..904fa837545ac 100644 --- a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TestResource.java +++ b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TestResource.java @@ -1,5 +1,8 @@ package io.quarkus.smallrye.opentracing.deployment; +import java.util.List; +import java.util.concurrent.CompletionStage; + import javax.inject.Inject; import javax.ws.rs.Path; import javax.ws.rs.core.Context; @@ -38,8 +41,11 @@ public Response restClient() { } @Override - public Response faultTolerance() { - String ret = service.faultTolerance(); - return Response.ok(ret).build(); + public CompletionStage faultTolerance() { + return service.faultTolerance(); + } + + public List jpa() { + return service.getFruits(); } } diff --git a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TracingTest.java b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TracingTest.java index bd4e9f5fb29a4..bab13fd6f490a 100644 --- a/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TracingTest.java +++ b/extensions/smallrye-opentracing/deployment/src/test/java/io/quarkus/smallrye/opentracing/deployment/TracingTest.java @@ -1,5 +1,8 @@ package io.quarkus.smallrye.opentracing.deployment; +import static org.hamcrest.Matchers.equalTo; +import static org.hamcrest.Matchers.hasSize; + import java.util.List; import java.util.concurrent.TimeUnit; @@ -20,7 +23,6 @@ import io.quarkus.test.QuarkusUnitTest; import io.restassured.RestAssured; import io.restassured.parsing.Parser; -import io.restassured.response.Response; public class TracingTest { @@ -41,7 +43,7 @@ public class TracingTest { } @BeforeEach - public void after() { + public void before() { mockTracer.reset(); } @@ -104,9 +106,10 @@ public void testMPRestClient() { public void testContextPropagationInFaultTolerance() { try { RestAssured.defaultParser = Parser.TEXT; - Response response = RestAssured.when().get("/faultTolerance"); - response.then().statusCode(200); - Assertions.assertEquals("fallback", response.body().asString()); + RestAssured.when().get("/faultTolerance") + .then() + .statusCode(200) + .body(equalTo("fallback")); Awaitility.await().atMost(5, TimeUnit.SECONDS) .until(() -> mockTracer.finishedSpans().size() == 5); List spans = mockTracer.finishedSpans(); @@ -115,13 +118,47 @@ public void testContextPropagationInFaultTolerance() { for (MockSpan mockSpan : spans) { Assertions.assertEquals(spans.get(0).context().traceId(), mockSpan.context().traceId()); } - Assertions.assertEquals("ft", mockTracer.finishedSpans().get(0).operationName()); - Assertions.assertEquals("ft", mockTracer.finishedSpans().get(1).operationName()); - Assertions.assertEquals("ft", mockTracer.finishedSpans().get(2).operationName()); - Assertions.assertEquals("io.quarkus.smallrye.opentracing.deployment.Service.fallback", - mockTracer.finishedSpans().get(3).operationName()); - Assertions.assertEquals("io.quarkus.smallrye.opentracing.deployment.Service.faultTolerance", - mockTracer.finishedSpans().get(4).operationName()); + + // if timeout occurs, subsequent retries/fallback can be interleaved with the execution that timed out, + // resulting in varying span order + Assertions.assertEquals(3, countSpansWithOperationName(spans, "ft")); + Assertions.assertEquals(1, countSpansWithOperationName(spans, "fallback")); + Assertions.assertEquals(1, countSpansWithOperationName(spans, + "GET:io.quarkus.smallrye.opentracing.deployment.TestResource.faultTolerance")); + } finally { + RestAssured.reset(); + } + } + + private long countSpansWithOperationName(List spans, String operationName) { + return spans.stream().filter(span -> span.operationName().equals(operationName)).count(); + } + + @Test + public void testJPA() { + try { + RestAssured.defaultParser = Parser.JSON; + RestAssured.when().get("/jpa") + .then() + .statusCode(200) + .body("", hasSize(3)) + .body("name[0]", equalTo("Apple")) + .body("name[1]", equalTo("Banana")) + .body("name[2]", equalTo("Cherry")); + List spans = mockTracer.finishedSpans(); + + Assertions.assertEquals(3, spans.size()); + for (MockSpan mockSpan : spans) { + Assertions.assertEquals(spans.get(0).context().traceId(), mockSpan.context().traceId()); + } + MockSpan firstSpan = mockTracer.finishedSpans().get(0); + Assertions.assertEquals("Query", firstSpan.operationName()); + Assertions.assertTrue(firstSpan.tags().containsKey("db.statement")); + Assertions.assertTrue(firstSpan.tags().get("db.statement").toString().contains("known_fruits")); + Assertions.assertEquals("io.quarkus.smallrye.opentracing.deployment.Service.getFruits", + mockTracer.finishedSpans().get(1).operationName()); + Assertions.assertEquals("GET:io.quarkus.smallrye.opentracing.deployment.TestResource.jpa", + mockTracer.finishedSpans().get(2).operationName()); } finally { RestAssured.reset(); } diff --git a/extensions/smallrye-opentracing/runtime/pom.xml b/extensions/smallrye-opentracing/runtime/pom.xml index 8c5fa2420bddb..47094da891cfd 100644 --- a/extensions/smallrye-opentracing/runtime/pom.xml +++ b/extensions/smallrye-opentracing/runtime/pom.xml @@ -32,6 +32,16 @@ + + io.smallrye + smallrye-fault-tolerance-tracing-propagation + + + * + * + + + jakarta.inject jakarta.inject-api From 1b676f39b236dca7b88db9bf79fac496f512d171 Mon Sep 17 00:00:00 2001 From: Ladislav Thon Date: Thu, 9 Apr 2020 12:52:27 +0200 Subject: [PATCH 2/2] fix Jaeger metrics collection when SmallRye Metrics is absent The Jaeger extension used to collect metrics unconditionally, even when the SmallRye Metrics extension wasn't present. With this commit, the Jaeger extension uses `NoopMetricsFactory` if SmallRye Metrics are missing, and only uses the real metrics factory if SmallRye Metrics are present. This is not totally consistent with how metrics are enabled/disabled in all other extensions. Fixing that is left for future. --- .../quarkus/jaeger/deployment/JaegerProcessor.java | 7 +++++-- extensions/jaeger/runtime/pom.xml | 11 ++++------- .../jaeger/runtime/JaegerDeploymentRecorder.java | 3 ++- .../quarkus/jaeger/runtime/QuarkusJaegerTracer.java | 12 +++++++++++- 4 files changed, 22 insertions(+), 11 deletions(-) diff --git a/extensions/jaeger/deployment/src/main/java/io/quarkus/jaeger/deployment/JaegerProcessor.java b/extensions/jaeger/deployment/src/main/java/io/quarkus/jaeger/deployment/JaegerProcessor.java index 807c9260031a7..5a44493fa4c54 100644 --- a/extensions/jaeger/deployment/src/main/java/io/quarkus/jaeger/deployment/JaegerProcessor.java +++ b/extensions/jaeger/deployment/src/main/java/io/quarkus/jaeger/deployment/JaegerProcessor.java @@ -2,6 +2,7 @@ import javax.inject.Inject; +import io.quarkus.deployment.Capabilities; import io.quarkus.deployment.annotations.BuildProducer; import io.quarkus.deployment.annotations.BuildStep; import io.quarkus.deployment.annotations.ExecutionTime; @@ -21,13 +22,15 @@ public class JaegerProcessor { @BuildStep @Record(ExecutionTime.RUNTIME_INIT) void setupTracer(JaegerDeploymentRecorder jdr, JaegerBuildTimeConfig buildTimeConfig, JaegerConfig jaeger, - ApplicationConfig appConfig) { + ApplicationConfig appConfig, Capabilities capabilities) { // Indicates that this extension would like the SSL support to be enabled extensionSslNativeSupport.produce(new ExtensionSslNativeSupportBuildItem(FeatureBuildItem.JAEGER)); if (buildTimeConfig.enabled) { - jdr.registerTracer(jaeger, appConfig); + boolean metricsEnabled = capabilities.isCapabilityPresent(Capabilities.METRICS); + + jdr.registerTracer(jaeger, appConfig, metricsEnabled); } } diff --git a/extensions/jaeger/runtime/pom.xml b/extensions/jaeger/runtime/pom.xml index 1571984a5b2aa..34c5e1581541e 100644 --- a/extensions/jaeger/runtime/pom.xml +++ b/extensions/jaeger/runtime/pom.xml @@ -18,7 +18,7 @@ io.quarkus quarkus-core - + io.jaegertracing jaeger-core @@ -31,12 +31,9 @@ svm - io.smallrye - smallrye-metrics - - - org.eclipse.microprofile.metrics - microprofile-metrics-api + io.quarkus + quarkus-smallrye-metrics + true diff --git a/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/JaegerDeploymentRecorder.java b/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/JaegerDeploymentRecorder.java index c9824f468ccdc..5481c0d9b22c5 100644 --- a/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/JaegerDeploymentRecorder.java +++ b/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/JaegerDeploymentRecorder.java @@ -15,7 +15,7 @@ public class JaegerDeploymentRecorder { private static final Optional UNKNOWN_SERVICE_NAME = Optional.of("quarkus/unknown"); private static final QuarkusJaegerTracer quarkusTracer = new QuarkusJaegerTracer(); - synchronized public void registerTracer(JaegerConfig jaeger, ApplicationConfig appConfig) { + synchronized public void registerTracer(JaegerConfig jaeger, ApplicationConfig appConfig, boolean metricsEnabled) { if (!jaeger.serviceName.isPresent()) { if (appConfig.name.isPresent()) { jaeger.serviceName = appConfig.name; @@ -24,6 +24,7 @@ synchronized public void registerTracer(JaegerConfig jaeger, ApplicationConfig a } } initTracerConfig(jaeger); + quarkusTracer.setMetricsEnabled(metricsEnabled); quarkusTracer.reset(); // register Quarkus tracer to GlobalTracer. // Usually the tracer will be registered only here, although consumers diff --git a/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerTracer.java b/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerTracer.java index 5c2ea3186b795..7764e7fbc9133 100644 --- a/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerTracer.java +++ b/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerTracer.java @@ -2,6 +2,8 @@ import io.jaegertracing.Configuration; import io.jaegertracing.internal.JaegerTracer; +import io.jaegertracing.internal.metrics.NoopMetricsFactory; +import io.jaegertracing.spi.MetricsFactory; import io.opentracing.ScopeManager; import io.opentracing.Span; import io.opentracing.SpanContext; @@ -14,11 +16,16 @@ public class QuarkusJaegerTracer implements Tracer { private volatile JaegerTracer tracer; private boolean logTraceContext; + private boolean metricsEnabled; void setLogTraceContext(boolean logTraceContext) { this.logTraceContext = logTraceContext; } + void setMetricsEnabled(boolean metricsEnabled) { + this.metricsEnabled = metricsEnabled; + } + @Override public String toString() { return tracer().toString(); @@ -35,8 +42,11 @@ private Tracer tracer() { if (tracer == null) { synchronized (this) { if (tracer == null) { + MetricsFactory metricsFactory = metricsEnabled + ? new QuarkusJaegerMetricsFactory() + : new NoopMetricsFactory(); tracer = Configuration.fromEnv() - .withMetricsFactory(new QuarkusJaegerMetricsFactory()) + .withMetricsFactory(metricsFactory) .getTracerBuilder() .withScopeManager(getScopeManager()) .build();