From 72358326329c6b77a7f344bc65bd8ff3defda7f3 Mon Sep 17 00:00:00 2001 From: Ladislav Thon Date: Thu, 19 Mar 2020 16:34:47 +0100 Subject: [PATCH] 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 fixes a devmode issue where on hot reload, the Jaeger extension tried to register a gauge that was already present. That ended up with an exception. And finally, this commit also adds a test for tracing JDBC. --- bom/runtime/pom.xml | 7 ++- .../runtime/QuarkusJaegerMetricsFactory.java | 10 ++- .../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 +++ 8 files changed, 119 insertions(+), 26 deletions(-) diff --git a/bom/runtime/pom.xml b/bom/runtime/pom.xml index 11c8f780374f30..d62a4323dcf952 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 @@ -1415,6 +1415,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/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerMetricsFactory.java b/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerMetricsFactory.java index d28a1f0232641f..abdf43058e8764 100644 --- a/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerMetricsFactory.java +++ b/extensions/jaeger/runtime/src/main/java/io/quarkus/jaeger/runtime/QuarkusJaegerMetricsFactory.java @@ -5,6 +5,7 @@ import java.util.concurrent.atomic.AtomicLong; import org.eclipse.microprofile.metrics.Metadata; +import org.eclipse.microprofile.metrics.MetricID; import org.eclipse.microprofile.metrics.MetricRegistry; import org.eclipse.microprofile.metrics.MetricType; import org.eclipse.microprofile.metrics.Tag; @@ -45,12 +46,17 @@ public void durationMicros(long time) { @Override public Gauge createGauge(final String name, final Map tags) { - JaegerGauge gauge = registry.register(meta(name, MetricType.GAUGE), new JaegerGauge(), toTagArray(tags)); + Tag[] tagArray = toTagArray(tags); + JaegerGauge gauge = (JaegerGauge) registry.getGauges().get(new MetricID(name, tagArray)); + if (gauge == null) { + gauge = registry.register(meta(name, MetricType.GAUGE), new JaegerGauge(), tagArray); + } + JaegerGauge finalGauge = gauge; return new Gauge() { @Override public void update(long amount) { - gauge.update(amount); + finalGauge.update(amount); } }; } diff --git a/extensions/smallrye-opentracing/deployment/pom.xml b/extensions/smallrye-opentracing/deployment/pom.xml index 0274703ba91d73..66bcd1acdd9a90 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 b1a340af3f4f3e..67ba3ae5a39510 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 4ef743c4de6349..2547e672cc2755 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 3be1f0897913f5..904fa837545ac4 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 bd4e9f5fb29a4c..bab13fd6f490ac 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 8c5fa2420bddb8..47094da891cfd6 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