From 43db7b53c2359aba08c2a8f3f95915ee6fc79325 Mon Sep 17 00:00:00 2001 From: Sergei Malafeev Date: Sun, 13 Aug 2017 14:55:38 +0800 Subject: [PATCH 01/16] add 'common handler' test --- .../contrib/examples/TestUtils.java | 10 ++++ .../common_request_handler/Client.java | 54 +++++++++++++++++++ .../common_request_handler/Context.java | 7 +++ .../RequestHandler.java | 45 ++++++++++++++++ .../common_request_handler/TestHandler.java | 48 +++++++++++++++++ 5 files changed, 164 insertions(+) create mode 100644 src/test/java/io/opentracing/contrib/examples/common_request_handler/Client.java create mode 100644 src/test/java/io/opentracing/contrib/examples/common_request_handler/Context.java create mode 100644 src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java create mode 100644 src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java diff --git a/src/test/java/io/opentracing/contrib/examples/TestUtils.java b/src/test/java/io/opentracing/contrib/examples/TestUtils.java index ef987ec..e0264b2 100644 --- a/src/test/java/io/opentracing/contrib/examples/TestUtils.java +++ b/src/test/java/io/opentracing/contrib/examples/TestUtils.java @@ -4,7 +4,9 @@ import io.opentracing.mock.MockTracer; import io.opentracing.tag.AbstractTag; import java.util.List; +import java.util.Random; import java.util.concurrent.Callable; +import java.util.concurrent.TimeUnit; public class TestUtils { @@ -26,4 +28,12 @@ public static MockSpan getByTag(List spans, AbstractTag key, Object va return null; } + public static void sleep() { + try { + TimeUnit.MILLISECONDS.sleep(new Random().nextInt(2000)); + } catch (InterruptedException e) { + e.printStackTrace(); + Thread.currentThread().interrupt(); + } + } } diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/Client.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/Client.java new file mode 100644 index 0000000..b2cda35 --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/Client.java @@ -0,0 +1,54 @@ +package io.opentracing.contrib.examples.common_request_handler; + +import io.opentracing.contrib.examples.TestUtils; +import java.util.concurrent.Callable; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class Client { + + private static final Logger logger = LoggerFactory.getLogger(Client.class); + + private final ExecutorService executor = Executors.newCachedThreadPool(); + + private final RequestHandler requestHandler; + + + public Client(RequestHandler requestHandler) { + this.requestHandler = requestHandler; + } + + + public Future send(final Object message) { + + final Context context = new Context(); + return executor.submit(new Callable() { + @Override + public Object call() throws Exception { + logger.info("send {}", message); + TestUtils.sleep(); + executor.submit(new Runnable() { + @Override + public void run() { + TestUtils.sleep(); + requestHandler.beforeRequest(message, context); + } + }).get(); + + executor.submit(new Runnable() { + @Override + public void run() { + TestUtils.sleep(); + requestHandler.afterResponse(message, context); + } + }).get(); + + return message + ":response"; + } + }); + + } +} diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/Context.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/Context.java new file mode 100644 index 0000000..583ea7e --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/Context.java @@ -0,0 +1,7 @@ +package io.opentracing.contrib.examples.common_request_handler; + +import java.util.HashMap; + +public class Context extends HashMap { + +} diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java new file mode 100644 index 0000000..a28b3fa --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java @@ -0,0 +1,45 @@ +package io.opentracing.contrib.examples.common_request_handler; + +import io.opentracing.Span; +import io.opentracing.Tracer; +import io.opentracing.tag.Tags; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * One instance per Client. Executed concurrently for all requests of one client. 'beforeRequest' + * and 'afterResponse' are executed in different threads for one 'send' + */ +public class RequestHandler { + + private static final Logger logger = LoggerFactory.getLogger(RequestHandler.class); + + private final Tracer tracer; + + public RequestHandler(Tracer tracer) { + this.tracer = tracer; + } + + public void beforeRequest(Object request, Context context) { + logger.info("before send {}", request); + + // we cannot use active span because we don't know in which thread it is executed + // and we cannot therefore activate span. thread can come from common thread pool. + Span span = tracer.buildSpan("send") + .ignoreActiveSpan() + .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT) + .startManual(); + + context.put("span", span); + } + + public void afterResponse(Object response, Context context) { + logger.info("after response {}", response); + + Object spanObject = context.get("span"); + if (spanObject != null && spanObject instanceof Span) { + Span span = (Span) spanObject; + span.finish(); + } + } +} diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java new file mode 100644 index 0000000..2e3b15d --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java @@ -0,0 +1,48 @@ +package io.opentracing.contrib.examples.common_request_handler; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotEquals; +import static org.junit.Assert.assertNull; + +import io.opentracing.mock.MockSpan; +import io.opentracing.mock.MockTracer; +import io.opentracing.mock.MockTracer.Propagator; +import io.opentracing.tag.Tags; +import io.opentracing.util.ThreadLocalActiveSpanSource; +import java.util.List; +import java.util.concurrent.Future; +import org.junit.Test; + +/** + * There is only one instance of 'RequestHandler' per 'Client'. Methods of 'RequestHandler' are + * executed concurrently in different threads which are reused (common pool). Therefore we cannot + * use current active span and activate span. + */ +public class TestHandler { + + private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), + Propagator.TEXT_MAP); + + @Test + public void test() throws Exception { + Client client = new Client(new RequestHandler(tracer)); + + Future responseFuture = client.send("message"); + Future responseFuture2 = client.send("message2"); + + assertEquals("message:response", responseFuture.get()); + assertEquals("message2:response", responseFuture2.get()); + + List finished = tracer.finishedSpans(); + assertEquals(2, finished.size()); + + for (MockSpan span : finished) { + assertEquals(Tags.SPAN_KIND_CLIENT, span.tags().get(Tags.SPAN_KIND.getKey())); + } + + assertNotEquals(finished.get(0).context().traceId(), finished.get(1).context().traceId()); + assertEquals(finished.get(0).parentId(), finished.get(1).parentId()); + + assertNull(tracer.activeSpan()); + } +} From 26b97cde69e511869c8df2cadd6546c4feef9d96 Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Tue, 15 Aug 2017 05:03:15 +0200 Subject: [PATCH 02/16] Add an example for multiple callbacks for an active span. --- .../contrib/examples/TestUtils.java | 9 ++++ .../examples/multiple_callbacks/Client.java | 44 +++++++++++++++++++ .../TestMultipleCallbacks.java | 44 +++++++++++++++++++ 3 files changed, 97 insertions(+) create mode 100644 src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java create mode 100644 src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java diff --git a/src/test/java/io/opentracing/contrib/examples/TestUtils.java b/src/test/java/io/opentracing/contrib/examples/TestUtils.java index e0264b2..e2f85af 100644 --- a/src/test/java/io/opentracing/contrib/examples/TestUtils.java +++ b/src/test/java/io/opentracing/contrib/examples/TestUtils.java @@ -36,4 +36,13 @@ public static void sleep() { Thread.currentThread().interrupt(); } } + + public static void sleep(long milliseconds) { + try { + TimeUnit.MILLISECONDS.sleep(milliseconds); + } catch (InterruptedException e) { + e.printStackTrace(); + Thread.currentThread().interrupt(); + } + } } diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java new file mode 100644 index 0000000..31b7442 --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java @@ -0,0 +1,44 @@ +package io.opentracing.contrib.examples.multiple_callbacks; + +import static io.opentracing.contrib.examples.TestUtils.sleep; + +import io.opentracing.ActiveSpan; +import io.opentracing.Span; +import io.opentracing.Tracer; +import java.util.concurrent.Callable; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import org.slf4j.LoggerFactory; +import org.slf4j.Logger; + +public class Client { + + private static final Logger logger = LoggerFactory.getLogger(Client.class); + + private final ExecutorService executor = Executors.newCachedThreadPool(); + private final Tracer tracer; + + public Client(Tracer tracer) { + this.tracer = tracer; + } + + public void send(final Object message, ActiveSpan parentSpan, final long milliseconds) { + final ActiveSpan.Continuation cont = parentSpan.capture(); + executor.submit(new Callable() { + @Override + public Object call() throws Exception { + logger.info("Child thread with message '" + message + "' started"); + + try (ActiveSpan parentSpan = cont.activate()) { + try (ActiveSpan span = tracer.buildSpan("subtask").startActive()) { + // Simulate work. + sleep(milliseconds); + } + } + + logger.info("Child thread with message '" + message + "' finished"); + return message + "::response"; + } + }); + } +} diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java new file mode 100644 index 0000000..e552db7 --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java @@ -0,0 +1,44 @@ +package io.opentracing.contrib.examples.multiple_callbacks; + +import static com.jayway.awaitility.Awaitility.await; +import static io.opentracing.contrib.examples.TestUtils.reportedSpansSize; +import static org.hamcrest.core.IsEqual.equalTo; +import static org.junit.Assert.assertEquals; + +import io.opentracing.ActiveSpan; +import io.opentracing.mock.MockSpan; +import io.opentracing.mock.MockTracer; +import io.opentracing.mock.MockTracer.Propagator; +import io.opentracing.util.ThreadLocalActiveSpanSource; +import java.util.List; +import java.util.concurrent.TimeUnit; +import org.junit.Test; + +public class TestMultipleCallbacks { + + private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), + Propagator.TEXT_MAP); + + @Test + public void test() throws Exception { + Client client = new Client(tracer); + try (ActiveSpan span = tracer.buildSpan("parent").startActive()) { + client.send("task1", span, 100); + client.send("task2", span, 200); + client.send("task3", span, 300); + } + + await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(4)); + + List spans = tracer.finishedSpans(); + assertEquals(4, spans.size()); + assertEquals("parent", spans.get(3).operationName()); + + MockSpan parentSpan = spans.get(3); + for (int i = 0; i < 3; i++) { + assertEquals(true, parentSpan.finishMicros() >= spans.get(i).finishMicros()); + assertEquals(parentSpan.context().traceId(), spans.get(i).context().traceId()); + assertEquals(parentSpan.context().spanId(), spans.get(i).parentId()); + } + } +} From 661a6ff4cc1ef26b2d153b310fd0ba2fb5d3e916 Mon Sep 17 00:00:00 2001 From: Sergei Malafeev Date: Tue, 15 Aug 2017 14:25:16 +0800 Subject: [PATCH 03/16] apply received feedback --- .../activate_deactivate/Callback.java | 11 +++- .../activate_deactivate/TestCallback.java | 65 +++++++++++++++++-- .../examples/client_server/Client.java | 14 ++-- .../examples/client_server/Server.java | 7 +- .../client_server/TestClientServer.java | 2 +- .../RequestHandler.java | 4 +- .../common_request_handler/TestHandler.java | 52 +++++++++++++-- 7 files changed, 124 insertions(+), 31 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java index 7928a7f..2d378f4 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java @@ -2,7 +2,7 @@ import io.opentracing.ActiveSpan; import io.opentracing.ActiveSpan.Continuation; -import io.opentracing.tag.Tags; +import java.util.Random; import java.util.concurrent.TimeUnit; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -22,6 +22,10 @@ public class Callback implements Runnable { logger.info("Callback created"); } + /** + * Can be used continuation.activate().deactivate() chain only. It is splitted for testing + * purposes (span should not be finished before deactivate() called here). + */ @Override public void run() { logger.info("Callback started"); @@ -33,8 +37,9 @@ public void run() { e.printStackTrace(); } - activeSpan - .setTag(Tags.HTTP_STATUS.getKey(), 200); // we need it to test that finished span has it + // set random tag starting with 'test_tag_' to test that finished span has all of them + activeSpan.setTag("test_tag_" + new Random().nextInt(), "random"); + activeSpan.deactivate(); logger.info("Callback finished"); } diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java index ea1474c..ba55ba2 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java @@ -9,9 +9,10 @@ import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; -import io.opentracing.tag.Tags; import io.opentracing.util.ThreadLocalActiveSpanSource; import java.util.List; +import java.util.Map; +import java.util.Random; import java.util.concurrent.Executors; import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; @@ -39,7 +40,34 @@ public void test() throws Exception { List finished = tracer.finishedSpans(); assertEquals(1, finished.size()); - assertEquals(200, finished.get(0).tags().get(Tags.HTTP_STATUS.getKey())); + assertEquals(1, getTestTagsCount(finished.get(0))); + } + + @Test + public void test_two_callbacks() throws Exception { + Thread entryThread = entryThreadWithTwoCallbacks(); + entryThread.start(); + entryThread.join(10_000); + // Entry thread is completed but Callbacks are still running (or even not started) + + await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(1)); + + List finished = tracer.finishedSpans(); + assertEquals(1, finished.size()); + + // Check that two callbacks finished and each added to span own tag ('test_tag_{random}') + assertEquals(2, getTestTagsCount(finished.get(0))); + } + + private int getTestTagsCount(MockSpan mockSpan) { + Map tags = mockSpan.tags(); + int tagCounter = 0; + for (String tagKey : tags.keySet()) { + if (tagKey.startsWith("test_tag_")) { + tagCounter++; + } + } + return tagCounter; } /** @@ -50,13 +78,36 @@ private Thread entryThread() { @Override public void run() { logger.info("Entry thread started"); - ActiveSpan activeSpan = tracer.buildSpan("parent").startActive(); - Runnable callback = new Callback(activeSpan); + try (ActiveSpan activeSpan = tracer.buildSpan("parent").startActive()) { + Runnable callback = new Callback(activeSpan); + + // Callback is executed at some unpredictable time and we are not able to check status of the callback + service.schedule(callback, 500, TimeUnit.MILLISECONDS); + } + logger.info("Entry thread finished"); + } + }); + } + + /** + * Thread will be completed before callback completed. + */ + private Thread entryThreadWithTwoCallbacks() { + return new Thread(new Runnable() { + @Override + public void run() { + logger.info("Entry thread 2x started"); + try (ActiveSpan activeSpan = tracer.buildSpan("parent").startActive()) { + Runnable callback = new Callback(activeSpan); + Runnable callback2 = new Callback(activeSpan); + + Random random = new Random(); - // Callback is executed at some unpredictable time and we are not able to check status of the callback - service.schedule(callback, 500, TimeUnit.MILLISECONDS); + // Callbacks are executed at some unpredictable time + service.schedule(callback, random.nextInt(1000) + 100, TimeUnit.MILLISECONDS); + service.schedule(callback2, random.nextInt(1000) + 100, TimeUnit.MILLISECONDS); - activeSpan.deactivate(); + } logger.info("Entry thread finished"); } }); diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/Client.java b/src/test/java/io/opentracing/contrib/examples/client_server/Client.java index 346fd9c..88e4110 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/Client.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/Client.java @@ -17,19 +17,13 @@ public Client(ArrayBlockingQueue queue, Tracer tracer) { this.tracer = tracer; } - public void send() { + public void send() throws InterruptedException { Message message = new Message(); - ActiveSpan activeSpan = tracer.buildSpan("send").startActive(); - activeSpan.setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT); - tracer.inject(activeSpan.context(), Builtin.TEXT_MAP, new TextMapInjectAdapter(message)); - - try { + try (ActiveSpan activeSpan = tracer.buildSpan("send").startActive()) { + activeSpan.setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT); + tracer.inject(activeSpan.context(), Builtin.TEXT_MAP, new TextMapInjectAdapter(message)); queue.put(message); - } catch (InterruptedException e) { - e.printStackTrace(); - } finally { - activeSpan.deactivate(); } } diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/Server.java b/src/test/java/io/opentracing/contrib/examples/client_server/Server.java index d6946c6..97a7946 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/Server.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/Server.java @@ -20,10 +20,9 @@ public Server(ArrayBlockingQueue queue, Tracer tracer) { private void process(Message message) { SpanContext context = tracer.extract(Builtin.TEXT_MAP, new TextMapExtractAdapter(message)); - ActiveSpan activeSpan = tracer.buildSpan("receive").asChildOf(context).startActive(); - activeSpan.setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER); - - activeSpan.deactivate(); + try (ActiveSpan activeSpan = tracer.buildSpan("receive").asChildOf(context).startActive()) { + activeSpan.setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER); + } } @Override diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java b/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java index 311ff71..340aa47 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java @@ -40,7 +40,7 @@ public void after() throws InterruptedException { } @Test - public void test() { + public void test() throws Exception { Client client = new Client(queue, tracer); client.send(); diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java index a28b3fa..a2b00fb 100644 --- a/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java @@ -14,6 +14,8 @@ public class RequestHandler { private static final Logger logger = LoggerFactory.getLogger(RequestHandler.class); + static final String OPERATION_NAME = "send"; + private final Tracer tracer; public RequestHandler(Tracer tracer) { @@ -25,7 +27,7 @@ public void beforeRequest(Object request, Context context) { // we cannot use active span because we don't know in which thread it is executed // and we cannot therefore activate span. thread can come from common thread pool. - Span span = tracer.buildSpan("send") + Span span = tracer.buildSpan(OPERATION_NAME) .ignoreActiveSpan() .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT) .startManual(); diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java index 2e3b15d..0000f1c 100644 --- a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java @@ -2,8 +2,10 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNotEquals; +import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertNull; +import io.opentracing.ActiveSpan; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; @@ -11,27 +13,34 @@ import io.opentracing.util.ThreadLocalActiveSpanSource; import java.util.List; import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; +import org.junit.Before; import org.junit.Test; /** * There is only one instance of 'RequestHandler' per 'Client'. Methods of 'RequestHandler' are * executed concurrently in different threads which are reused (common pool). Therefore we cannot - * use current active span and activate span. + * use current active span and activate span. So one issue here is that we cannot create + * parent-child relation. */ public class TestHandler { private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), Propagator.TEXT_MAP); + private final Client client = new Client(new RequestHandler(tracer)); + + @Before + public void before() { + tracer.reset(); + } @Test public void test() throws Exception { - Client client = new Client(new RequestHandler(tracer)); - Future responseFuture = client.send("message"); Future responseFuture2 = client.send("message2"); - assertEquals("message:response", responseFuture.get()); - assertEquals("message2:response", responseFuture2.get()); + assertEquals("message:response", responseFuture.get(15, TimeUnit.SECONDS)); + assertEquals("message2:response", responseFuture2.get(15, TimeUnit.SECONDS)); List finished = tracer.finishedSpans(); assertEquals(2, finished.size()); @@ -45,4 +54,37 @@ public void test() throws Exception { assertNull(tracer.activeSpan()); } + + /** + * there is no way to create parent-child relation + */ + @Test + public void never_parent() throws Exception { + try (ActiveSpan parent = tracer.buildSpan("parent").startActive()) { + Object response = client.send("no_parent").get(15, TimeUnit.SECONDS); + assertEquals("no_parent:response", response); + } + + List finished = tracer.finishedSpans(); + assertEquals(2, finished.size()); + + MockSpan child = getByOperationName(finished, RequestHandler.OPERATION_NAME); + assertNotNull(child); + + MockSpan parent = getByOperationName(finished, "parent"); + assertNotNull(parent); + + // Here check that there is no parent-child relation although it should be because child is + // created when parent is active + assertNotEquals(parent.context().spanId(), child.parentId()); + } + + private static MockSpan getByOperationName(List spans, String name) { + for (MockSpan span : spans) { + if (name.equals(span.operationName())) { + return span; + } + } + return null; + } } From 193058007f66b8ce0c8afc93a60a72091304e3c5 Mon Sep 17 00:00:00 2001 From: Sergei Malafeev Date: Tue, 15 Aug 2017 14:28:08 +0800 Subject: [PATCH 04/16] fix thread name --- .../contrib/examples/activate_deactivate/TestCallback.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java index ba55ba2..d223a57 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java @@ -108,7 +108,7 @@ public void run() { service.schedule(callback2, random.nextInt(1000) + 100, TimeUnit.MILLISECONDS); } - logger.info("Entry thread finished"); + logger.info("Entry thread 2x finished"); } }); } From 6b4e51859fdef44bd565e45c48e64e887bda770c Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Tue, 15 Aug 2017 17:07:12 +0200 Subject: [PATCH 05/16] Let the Logger format the message instead of concatenating values. --- .../contrib/examples/multiple_callbacks/Client.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java index 31b7442..0342d26 100644 --- a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java @@ -27,7 +27,7 @@ public void send(final Object message, ActiveSpan parentSpan, final long millise executor.submit(new Callable() { @Override public Object call() throws Exception { - logger.info("Child thread with message '" + message + "' started"); + logger.info("Child thread with message '{}' started", message); try (ActiveSpan parentSpan = cont.activate()) { try (ActiveSpan span = tracer.buildSpan("subtask").startActive()) { @@ -36,7 +36,7 @@ public Object call() throws Exception { } } - logger.info("Child thread with message '" + message + "' finished"); + logger.info("Child thread with message '{}' finished", message); return message + "::response"; } }); From 9d9e3f517f9efadaefbb0bd4f5abea30a11de8a5 Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Tue, 15 Aug 2017 17:08:25 +0200 Subject: [PATCH 06/16] Reverse the sleep time for the threads in TestMultipleCallbacks. --- .../examples/multiple_callbacks/TestMultipleCallbacks.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java index e552db7..31d0d82 100644 --- a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java @@ -23,9 +23,9 @@ public class TestMultipleCallbacks { public void test() throws Exception { Client client = new Client(tracer); try (ActiveSpan span = tracer.buildSpan("parent").startActive()) { - client.send("task1", span, 100); + client.send("task1", span, 300); client.send("task2", span, 200); - client.send("task3", span, 300); + client.send("task3", span, 100); } await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(4)); From 7b0720a3383ac44de83cd780596702fcd2a78c25 Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Thu, 17 Aug 2017 16:36:59 +0200 Subject: [PATCH 07/16] Add an example of nested callbacks. 'Only' put 3 levels of callbacks, to not make it too hard to read. --- .../nested_callbacks/TestNestedCallbacks.java | 77 +++++++++++++++++++ 1 file changed, 77 insertions(+) create mode 100644 src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java diff --git a/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java b/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java new file mode 100644 index 0000000..d05a33e --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java @@ -0,0 +1,77 @@ +package io.opentracing.contrib.examples.nested_callbacks; + +import static com.jayway.awaitility.Awaitility.await; +import static io.opentracing.contrib.examples.TestUtils.reportedSpansSize; +import static org.hamcrest.core.IsEqual.equalTo; +import static org.junit.Assert.assertEquals; + +import io.opentracing.ActiveSpan; +import io.opentracing.mock.MockSpan; +import io.opentracing.mock.MockTracer; +import io.opentracing.mock.MockTracer.Propagator; +import io.opentracing.util.ThreadLocalActiveSpanSource; +import java.util.List; +import java.util.Map; +import java.util.concurrent.Executors; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.TimeUnit; +import org.junit.Test; + +public class TestNestedCallbacks { + + private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), + Propagator.TEXT_MAP); + private final ExecutorService executor = Executors.newCachedThreadPool(); + + @Test + public void test() throws Exception { + + try (ActiveSpan span = tracer.buildSpan("one").startActive()) { + submitCallbacks(span); + } + + await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(1)); + + List spans = tracer.finishedSpans(); + assertEquals(1, spans.size()); + assertEquals("one", spans.get(0).operationName()); + + Map tags = spans.get(0).tags(); + assertEquals(3, tags.size()); + for (int i = 1; i <= 3; i++) + assertEquals(Integer.toString(i), tags.get("key" + i)); + } + + void submitCallbacks(ActiveSpan span) { + final ActiveSpan.Continuation cont = span.capture(); + + executor.submit(new Runnable() { + @Override + public void run() { + try (ActiveSpan span = cont.activate()) { + span.setTag("key1", "1"); + final ActiveSpan.Continuation cont = span.capture(); + + executor.submit(new Runnable() { + @Override + public void run() { + try (ActiveSpan span = cont.activate()) { + span.setTag("key2", "2"); + final ActiveSpan.Continuation cont = span.capture(); + + executor.submit(new Runnable() { + @Override + public void run() { + try (ActiveSpan span = cont.activate()) { + span.setTag("key3", "3"); + } + } + }); + } + } + }); + } + } + }); + } +} From 6ba0b1cb6414765fc9f5d5aa823122b344600107 Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Thu, 17 Aug 2017 18:13:00 +0200 Subject: [PATCH 08/16] Add a late-finish Span example. --- .../late_span_finish/TestLateSpanFinish.java | 79 +++++++++++++++++++ 1 file changed, 79 insertions(+) create mode 100644 src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java diff --git a/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java b/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java new file mode 100644 index 0000000..f99be00 --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java @@ -0,0 +1,79 @@ +package io.opentracing.contrib.examples.late_span_finish; + +import static io.opentracing.contrib.examples.TestUtils.sleep; +import static org.junit.Assert.assertEquals; + +import io.opentracing.ActiveSpan; +import io.opentracing.Span; +import io.opentracing.mock.MockSpan; +import io.opentracing.mock.MockTracer; +import io.opentracing.mock.MockTracer.Propagator; +import io.opentracing.util.ThreadLocalActiveSpanSource; +import java.util.List; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.Executors; +import java.util.concurrent.ExecutorService; +import org.junit.Test; + +public class TestLateSpanFinish { + + private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), + Propagator.TEXT_MAP); + private final ExecutorService executor = Executors.newCachedThreadPool(); + + @Test + public void test() throws Exception { + /* Create a Span manually and use it as parent of a pair of subtasks */ + Span parentSpan = tracer.buildSpan("parent").startManual(); + submitTasks(parentSpan); + + /* Wait for the threadpool to be done first, instead of polling/waiting */ + executor.shutdown(); + executor.awaitTermination(15, TimeUnit.SECONDS); + + /* Late-finish the parent Span now */ + parentSpan.finish(); + + List spans = tracer.finishedSpans(); + assertEquals(3, spans.size()); + assertEquals("task1", spans.get(0).operationName()); + assertEquals("task2", spans.get(1).operationName()); + assertEquals("parent", spans.get(2).operationName()); + + for (int i = 0; i < 2; i++) { + assertEquals(true, spans.get(2).finishMicros() >= spans.get(i).finishMicros()); + assertEquals(spans.get(2).context().traceId(), spans.get(i).context().traceId()); + assertEquals(spans.get(2).context().spanId(), spans.get(i).parentId()); + } + } + + /* Fire away a few subtasks, passing a parent Span whose lifetime + * is not tied at-all to the children */ + void submitTasks(final Span parentSpan) { + + executor.submit(new Runnable() { + @Override + public void run() { + // Alternative to calling makeActive() is to pass it manually to asChildOf() for each created Span. + try (ActiveSpan span = tracer.makeActive(parentSpan)) { + try (ActiveSpan childSpan1 = tracer.buildSpan("task1").startActive()) { + sleep(55); + } + span.capture(); // Workaround, prevent parentSpan from being finished here. + } + } + }); + + executor.submit(new Runnable() { + @Override + public void run() { + try (ActiveSpan span = tracer.makeActive(parentSpan)) { + try (ActiveSpan childSpan1 = tracer.buildSpan("task2").startActive()) { + sleep(85); + } + span.capture(); // Workaround, prevent parentSpan from being finished here. + } + } + }); + } +} From c1390b0166c11638eb19a36d1e96f86766e6eea7 Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Thu, 17 Aug 2017 20:09:36 +0200 Subject: [PATCH 09/16] Add an example for an active span being temporary replaced. --- .../TestActiveSpanReplacement.java | 74 +++++++++++++++++++ 1 file changed, 74 insertions(+) create mode 100644 src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java diff --git a/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java b/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java new file mode 100644 index 0000000..64355fd --- /dev/null +++ b/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java @@ -0,0 +1,74 @@ +package io.opentracing.contrib.examples.active_span_replacement; + +import static com.jayway.awaitility.Awaitility.await; +import static io.opentracing.contrib.examples.TestUtils.reportedSpansSize; +import static io.opentracing.contrib.examples.TestUtils.sleep; +import static org.hamcrest.core.IsEqual.equalTo; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotEquals; + +import io.opentracing.ActiveSpan; +import io.opentracing.mock.MockSpan; +import io.opentracing.mock.MockTracer; +import io.opentracing.mock.MockTracer.Propagator; +import io.opentracing.util.ThreadLocalActiveSpanSource; +import java.util.List; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.Executors; +import java.util.concurrent.ExecutorService; +import org.junit.Test; + +public class TestActiveSpanReplacement { + + private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), + Propagator.TEXT_MAP); + + private final ExecutorService executor = Executors.newCachedThreadPool(); + + @Test + public void test() throws Exception { + /* Start an isolated task and query for its result in another task/thread */ + try (ActiveSpan span = tracer.buildSpan("initial").startActive()) { + submitAnotherTask(span); + } + + await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(3)); + + List spans = tracer.finishedSpans(); + assertEquals(3, spans.size()); + assertEquals("initial", spans.get(0).operationName()); /* Isolated task. */ + assertEquals("subtask", spans.get(1).operationName()); + assertEquals("task", spans.get(2).operationName()); + + /* task/subtask are part of the same trace, + * and subtask is a child of task */ + assertEquals(spans.get(1).context().traceId(), spans.get(2).context().traceId()); + assertEquals(spans.get(2).context().spanId(), spans.get(1).parentId()); + + /* initial task is not related in any way to those two tasks */ + assertNotEquals(spans.get(0).context().traceId(), spans.get(1).context().traceId()); + assertEquals(0, spans.get(0).parentId()); + } + + void submitAnotherTask(ActiveSpan span) { + final ActiveSpan.Continuation cont = span.capture(); + + executor.submit(new Runnable() { + @Override + public void run () { + /* Create a new Span for this task */ + try (ActiveSpan taskSpan = tracer.buildSpan("task").startActive()) { + + /* Simulate work strictly related to the initial Span. */ + try (ActiveSpan initialSpan = cont.activate()) { + sleep(50); + } + + /* Restore the span for this task and create a subspan */ + try (ActiveSpan subTask = tracer.buildSpan("subtask").startActive()) { + } + } + } + }); + } +} From 211e8be81c078555c676849c3f2e1b55fa61411a Mon Sep 17 00:00:00 2001 From: Sergei Malafeev Date: Fri, 18 Aug 2017 10:39:19 +0800 Subject: [PATCH 10/16] one more check --- .../TestActiveSpanReplacement.java | 5 ++++- .../examples/late_span_finish/TestLateSpanFinish.java | 5 ++++- .../multiple_callbacks/TestMultipleCallbacks.java | 3 +++ .../examples/nested_callbacks/TestNestedCallbacks.java | 10 +++++++--- 4 files changed, 18 insertions(+), 5 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java b/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java index 64355fd..22c8c3a 100644 --- a/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java +++ b/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java @@ -6,6 +6,7 @@ import static org.hamcrest.core.IsEqual.equalTo; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNotEquals; +import static org.junit.Assert.assertNull; import io.opentracing.ActiveSpan; import io.opentracing.mock.MockSpan; @@ -48,9 +49,11 @@ public void test() throws Exception { /* initial task is not related in any way to those two tasks */ assertNotEquals(spans.get(0).context().traceId(), spans.get(1).context().traceId()); assertEquals(0, spans.get(0).parentId()); + + assertNull(tracer.activeSpan()); } - void submitAnotherTask(ActiveSpan span) { + private void submitAnotherTask(ActiveSpan span) { final ActiveSpan.Continuation cont = span.capture(); executor.submit(new Runnable() { diff --git a/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java b/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java index f99be00..f192472 100644 --- a/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java +++ b/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java @@ -2,6 +2,7 @@ import static io.opentracing.contrib.examples.TestUtils.sleep; import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNull; import io.opentracing.ActiveSpan; import io.opentracing.Span; @@ -45,11 +46,13 @@ public void test() throws Exception { assertEquals(spans.get(2).context().traceId(), spans.get(i).context().traceId()); assertEquals(spans.get(2).context().spanId(), spans.get(i).parentId()); } + + assertNull(tracer.activeSpan()); } /* Fire away a few subtasks, passing a parent Span whose lifetime * is not tied at-all to the children */ - void submitTasks(final Span parentSpan) { + private void submitTasks(final Span parentSpan) { executor.submit(new Runnable() { @Override diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java index 31d0d82..40c04e3 100644 --- a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java @@ -4,6 +4,7 @@ import static io.opentracing.contrib.examples.TestUtils.reportedSpansSize; import static org.hamcrest.core.IsEqual.equalTo; import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNull; import io.opentracing.ActiveSpan; import io.opentracing.mock.MockSpan; @@ -40,5 +41,7 @@ public void test() throws Exception { assertEquals(parentSpan.context().traceId(), spans.get(i).context().traceId()); assertEquals(parentSpan.context().spanId(), spans.get(i).parentId()); } + + assertNull(tracer.activeSpan()); } } diff --git a/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java b/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java index d05a33e..6b3135e 100644 --- a/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java +++ b/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java @@ -4,6 +4,7 @@ import static io.opentracing.contrib.examples.TestUtils.reportedSpansSize; import static org.hamcrest.core.IsEqual.equalTo; import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNull; import io.opentracing.ActiveSpan; import io.opentracing.mock.MockSpan; @@ -12,8 +13,8 @@ import io.opentracing.util.ThreadLocalActiveSpanSource; import java.util.List; import java.util.Map; -import java.util.concurrent.Executors; import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; import org.junit.Test; @@ -38,11 +39,14 @@ public void test() throws Exception { Map tags = spans.get(0).tags(); assertEquals(3, tags.size()); - for (int i = 1; i <= 3; i++) + for (int i = 1; i <= 3; i++) { assertEquals(Integer.toString(i), tags.get("key" + i)); + } + + assertNull(tracer.activeSpan()); } - void submitCallbacks(ActiveSpan span) { + private void submitCallbacks(ActiveSpan span) { final ActiveSpan.Continuation cont = span.capture(); executor.submit(new Runnable() { From bf5ac9aed73d943ed1ceb71f783f681adcc86bd7 Mon Sep 17 00:00:00 2001 From: Sergei Malafeev Date: Fri, 18 Aug 2017 10:47:16 +0800 Subject: [PATCH 11/16] use one Random, return Future --- .../contrib/examples/activate_deactivate/Callback.java | 4 +++- .../contrib/examples/multiple_callbacks/Client.java | 6 +++--- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java index 2d378f4..111cb6e 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java @@ -15,6 +15,8 @@ public class Callback implements Runnable { private static final Logger logger = LoggerFactory.getLogger(Callback.class); + private final Random random = new Random(); + private final Continuation continuation; Callback(ActiveSpan activeSpan) { @@ -38,7 +40,7 @@ public void run() { } // set random tag starting with 'test_tag_' to test that finished span has all of them - activeSpan.setTag("test_tag_" + new Random().nextInt(), "random"); + activeSpan.setTag("test_tag_" + random.nextInt(), "random"); activeSpan.deactivate(); logger.info("Callback finished"); diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java index 0342d26..29cbe08 100644 --- a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java @@ -3,11 +3,11 @@ import static io.opentracing.contrib.examples.TestUtils.sleep; import io.opentracing.ActiveSpan; -import io.opentracing.Span; import io.opentracing.Tracer; import java.util.concurrent.Callable; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; +import java.util.concurrent.Future; import org.slf4j.LoggerFactory; import org.slf4j.Logger; @@ -22,9 +22,9 @@ public Client(Tracer tracer) { this.tracer = tracer; } - public void send(final Object message, ActiveSpan parentSpan, final long milliseconds) { + public Future send(final Object message, ActiveSpan parentSpan, final long milliseconds) { final ActiveSpan.Continuation cont = parentSpan.capture(); - executor.submit(new Callable() { + return executor.submit(new Callable() { @Override public Object call() throws Exception { logger.info("Child thread with message '{}' started", message); From e925d8657e21230cd4d80d919aee856d22266efb Mon Sep 17 00:00:00 2001 From: Sergei Malafeev Date: Fri, 18 Aug 2017 12:16:00 +0800 Subject: [PATCH 12/16] refactoring + one more case for parent-span issue --- .../contrib/examples/TestUtils.java | 26 +++++++-- .../client_server/TestClientServer.java | 6 +- .../RequestHandler.java | 20 +++++-- .../common_request_handler/TestHandler.java | 56 +++++++++++++++---- .../listener_per_request/TestListener.java | 4 +- 5 files changed, 88 insertions(+), 24 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/TestUtils.java b/src/test/java/io/opentracing/contrib/examples/TestUtils.java index e2f85af..3c61b81 100644 --- a/src/test/java/io/opentracing/contrib/examples/TestUtils.java +++ b/src/test/java/io/opentracing/contrib/examples/TestUtils.java @@ -3,6 +3,9 @@ import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.tag.AbstractTag; +import java.util.ArrayList; +import java.util.Collections; +import java.util.Comparator; import java.util.List; import java.util.Random; import java.util.concurrent.Callable; @@ -19,13 +22,17 @@ public Integer call() throws Exception { }; } - public static MockSpan getByTag(List spans, AbstractTag key, Object value) { + public static MockSpan getOneByTag(List spans, AbstractTag key, Object value) { + List found = new ArrayList<>(); for (MockSpan span : spans) { if (span.tags().get(key.getKey()).equals(value)) { - return span; + found.add(span); } } - return null; + if (found.size() > 1) { + throw new RuntimeException("Ups, it's too much"); + } + return found.isEmpty() ? null : found.get(0); } public static void sleep() { @@ -41,8 +48,17 @@ public static void sleep(long milliseconds) { try { TimeUnit.MILLISECONDS.sleep(milliseconds); } catch (InterruptedException e) { - e.printStackTrace(); - Thread.currentThread().interrupt(); + e.printStackTrace(); + Thread.currentThread().interrupt(); } } + + public static void sortByStartMicros(List spans) { + Collections.sort(spans, new Comparator() { + @Override + public int compare(MockSpan o1, MockSpan o2) { + return Long.compare(o1.startMicros(), o2.startMicros()); + } + }); + } } diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java b/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java index 340aa47..de99786 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java @@ -1,7 +1,7 @@ package io.opentracing.contrib.examples.client_server; import static com.jayway.awaitility.Awaitility.await; -import static io.opentracing.contrib.examples.TestUtils.getByTag; +import static io.opentracing.contrib.examples.TestUtils.getOneByTag; import static io.opentracing.contrib.examples.TestUtils.reportedSpansSize; import static org.hamcrest.core.IsEqual.equalTo; import static org.junit.Assert.assertEquals; @@ -49,8 +49,8 @@ public void test() throws Exception { List finished = tracer.finishedSpans(); assertEquals(2, finished.size()); assertEquals(finished.get(0).context().traceId(), finished.get(1).context().traceId()); - assertNotNull(getByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_CLIENT)); - assertNotNull(getByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_SERVER)); + assertNotNull(getOneByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_CLIENT)); + assertNotNull(getOneByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_SERVER)); assertNull(tracer.activeSpan()); } } diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java index a2b00fb..63ba2f9 100644 --- a/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/RequestHandler.java @@ -1,7 +1,9 @@ package io.opentracing.contrib.examples.common_request_handler; import io.opentracing.Span; +import io.opentracing.SpanContext; import io.opentracing.Tracer; +import io.opentracing.Tracer.SpanBuilder; import io.opentracing.tag.Tags; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -18,8 +20,15 @@ public class RequestHandler { private final Tracer tracer; + private final SpanContext parentContext; + public RequestHandler(Tracer tracer) { + this(tracer, null); + } + + public RequestHandler(Tracer tracer, SpanContext parentContext) { this.tracer = tracer; + this.parentContext = parentContext; } public void beforeRequest(Object request, Context context) { @@ -27,12 +36,15 @@ public void beforeRequest(Object request, Context context) { // we cannot use active span because we don't know in which thread it is executed // and we cannot therefore activate span. thread can come from common thread pool. - Span span = tracer.buildSpan(OPERATION_NAME) + SpanBuilder spanBuilder = tracer.buildSpan(OPERATION_NAME) .ignoreActiveSpan() - .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT) - .startManual(); + .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT); + + if (parentContext != null) { + spanBuilder.asChildOf(parentContext); + } - context.put("span", span); + context.put("span", spanBuilder.startManual()); } public void afterResponse(Object response, Context context) { diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java index 0000f1c..61354af 100644 --- a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java @@ -1,5 +1,6 @@ package io.opentracing.contrib.examples.common_request_handler; +import static io.opentracing.contrib.examples.TestUtils.sortByStartMicros; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNotEquals; import static org.junit.Assert.assertNotNull; @@ -11,6 +12,7 @@ import io.opentracing.mock.MockTracer.Propagator; import io.opentracing.tag.Tags; import io.opentracing.util.ThreadLocalActiveSpanSource; +import java.util.ArrayList; import java.util.List; import java.util.concurrent.Future; import java.util.concurrent.TimeUnit; @@ -20,8 +22,7 @@ /** * There is only one instance of 'RequestHandler' per 'Client'. Methods of 'RequestHandler' are * executed concurrently in different threads which are reused (common pool). Therefore we cannot - * use current active span and activate span. So one issue here is that we cannot create - * parent-child relation. + * use current active span and activate span. So one issue here is setting correct parent span. */ public class TestHandler { @@ -35,7 +36,7 @@ public void before() { } @Test - public void test() throws Exception { + public void two_requests() throws Exception { Future responseFuture = client.send("message"); Future responseFuture2 = client.send("message2"); @@ -56,10 +57,10 @@ public void test() throws Exception { } /** - * there is no way to create parent-child relation + * active parent is not picked up by child */ @Test - public void never_parent() throws Exception { + public void parent_not_picked_up() throws Exception { try (ActiveSpan parent = tracer.buildSpan("parent").startActive()) { Object response = client.send("no_parent").get(15, TimeUnit.SECONDS); assertEquals("no_parent:response", response); @@ -68,10 +69,10 @@ public void never_parent() throws Exception { List finished = tracer.finishedSpans(); assertEquals(2, finished.size()); - MockSpan child = getByOperationName(finished, RequestHandler.OPERATION_NAME); + MockSpan child = getOneByOperationName(finished, RequestHandler.OPERATION_NAME); assertNotNull(child); - MockSpan parent = getByOperationName(finished, "parent"); + MockSpan parent = getOneByOperationName(finished, "parent"); assertNotNull(parent); // Here check that there is no parent-child relation although it should be because child is @@ -79,12 +80,47 @@ public void never_parent() throws Exception { assertNotEquals(parent.context().spanId(), child.parentId()); } - private static MockSpan getByOperationName(List spans, String name) { + /** + * Solution is bad because parent is per client (we don't have better choice) + */ + @Test + public void bad_solution_to_set_parent() throws Exception { + Client client; + try (ActiveSpan parent = tracer.buildSpan("parent").startActive()) { + client = new Client(new RequestHandler(tracer, parent.context())); + Object response = client.send("correct_parent").get(15, TimeUnit.SECONDS); + assertEquals("correct_parent:response", response); + } + + // Send second request, now there is no active parent, but it will be set, ups + Object response = client.send("wrong_parent").get(15, TimeUnit.SECONDS); + assertEquals("wrong_parent:response", response); + + List finished = tracer.finishedSpans(); + assertEquals(3, finished.size()); + + sortByStartMicros(finished); + + MockSpan parent = getOneByOperationName(finished, "parent"); + assertNotNull(parent); + + // now there is parent/child relation between first and second span: + assertEquals(parent.context().spanId(), finished.get(1).parentId()); + + // third span should not have parent, but it has, damn it + assertEquals(parent.context().spanId(), finished.get(2).parentId()); + } + + private static MockSpan getOneByOperationName(List spans, String name) { + List found = new ArrayList<>(); for (MockSpan span : spans) { if (name.equals(span.operationName())) { - return span; + found.add(span); } } - return null; + if (found.size() > 1) { + throw new RuntimeException("Ups, it's too much"); + } + return found.isEmpty() ? null : found.get(0); } } diff --git a/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java b/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java index 874757d..d8b1fb0 100644 --- a/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java +++ b/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java @@ -1,6 +1,6 @@ package io.opentracing.contrib.examples.listener_per_request; -import static io.opentracing.contrib.examples.TestUtils.getByTag; +import static io.opentracing.contrib.examples.TestUtils.getOneByTag; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertNull; @@ -29,7 +29,7 @@ public void test() throws Exception { List finished = tracer.finishedSpans(); assertEquals(1, finished.size()); - assertNotNull(getByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_CLIENT)); + assertNotNull(getOneByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_CLIENT)); assertNull(tracer.activeSpan()); } } From 5209880e6369402a0d527f5b40e98741456fa310 Mon Sep 17 00:00:00 2001 From: Ben Sigelman Date: Sat, 12 Aug 2017 20:40:28 -0700 Subject: [PATCH 13/16] Make all tests pass with the Scope API --- .../examples/activate_deactivate/Callback.java | 17 ++++++++++------- .../activate_deactivate/TestCallback.java | 16 ++++++++++------ .../contrib/examples/client_server/Client.java | 9 +++++---- .../contrib/examples/client_server/Server.java | 8 +++++--- .../client_server/TestClientServer.java | 8 ++++---- .../listener_per_request/TestListener.java | 8 ++++---- 6 files changed, 38 insertions(+), 28 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java index 111cb6e..2d1ac0a 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java @@ -1,7 +1,10 @@ package io.opentracing.contrib.examples.activate_deactivate; -import io.opentracing.ActiveSpan; -import io.opentracing.ActiveSpan.Continuation; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; +import io.opentracing.ScopeManager; +import io.opentracing.Span; +import io.opentracing.tag.Tags; import java.util.Random; import java.util.concurrent.TimeUnit; import org.slf4j.Logger; @@ -17,10 +20,10 @@ public class Callback implements Runnable { private final Random random = new Random(); - private final Continuation continuation; + private final Span continuation; - Callback(ActiveSpan activeSpan) { - continuation = activeSpan.capture(); + Callback(Span activeSpan) { + continuation = activeSpan; logger.info("Callback created"); } @@ -31,8 +34,8 @@ public class Callback implements Runnable { @Override public void run() { logger.info("Callback started"); - ActiveSpan activeSpan = continuation.activate(); + Scope scope = continuation.activate(Observer.FINISH_ON_CLOSE); try { TimeUnit.SECONDS.sleep(1); } catch (InterruptedException e) { @@ -42,7 +45,7 @@ public void run() { // set random tag starting with 'test_tag_' to test that finished span has all of them activeSpan.setTag("test_tag_" + random.nextInt(), "random"); - activeSpan.deactivate(); + scope.close(); logger.info("Callback finished"); } } diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java index d223a57..3e90fd0 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java @@ -5,11 +5,13 @@ import static org.hamcrest.core.IsEqual.equalTo; import static org.junit.Assert.assertEquals; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.tag.Tags; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.List; import java.util.Map; import java.util.Random; @@ -24,12 +26,12 @@ public class TestCallback { private static final Logger logger = LoggerFactory.getLogger(TestCallback.class); - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final ScheduledExecutorService service = Executors.newScheduledThreadPool(1); @Test public void test() throws Exception { + tracer.setScopeManager(new ThreadLocalScopeManager()); Thread entryThread = entryThread(); entryThread.start(); entryThread.join(10_000); @@ -78,12 +80,14 @@ private Thread entryThread() { @Override public void run() { logger.info("Entry thread started"); - try (ActiveSpan activeSpan = tracer.buildSpan("parent").startActive()) { - Runnable callback = new Callback(activeSpan); + + try (Scope scope = tracer.buildSpan("parent").startActive()) { + Runnable callback = new Callback(scope.span()); // Callback is executed at some unpredictable time and we are not able to check status of the callback service.schedule(callback, 500, TimeUnit.MILLISECONDS); } + logger.info("Entry thread finished"); } }); diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/Client.java b/src/test/java/io/opentracing/contrib/examples/client_server/Client.java index 88e4110..f9ea60b 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/Client.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/Client.java @@ -1,6 +1,7 @@ package io.opentracing.contrib.examples.client_server; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; import io.opentracing.Tracer; import io.opentracing.propagation.Format.Builtin; import io.opentracing.propagation.TextMapInjectAdapter; @@ -20,9 +21,9 @@ public Client(ArrayBlockingQueue queue, Tracer tracer) { public void send() throws InterruptedException { Message message = new Message(); - try (ActiveSpan activeSpan = tracer.buildSpan("send").startActive()) { - activeSpan.setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT); - tracer.inject(activeSpan.context(), Builtin.TEXT_MAP, new TextMapInjectAdapter(message)); + try (Scope scope = tracer.buildSpan("send").startActive(Observer.FINISH_ON_CLOSE)) { + scope.span().setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_CLIENT); + tracer.inject(scope.span().context(), Builtin.TEXT_MAP, new TextMapInjectAdapter(message)); queue.put(message); } } diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/Server.java b/src/test/java/io/opentracing/contrib/examples/client_server/Server.java index 97a7946..a39a9b6 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/Server.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/Server.java @@ -1,6 +1,7 @@ package io.opentracing.contrib.examples.client_server; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; import io.opentracing.SpanContext; import io.opentracing.Tracer; import io.opentracing.propagation.Format.Builtin; @@ -20,8 +21,9 @@ public Server(ArrayBlockingQueue queue, Tracer tracer) { private void process(Message message) { SpanContext context = tracer.extract(Builtin.TEXT_MAP, new TextMapExtractAdapter(message)); - try (ActiveSpan activeSpan = tracer.buildSpan("receive").asChildOf(context).startActive()) { - activeSpan.setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER); + try (Scope scope = tracer.buildSpan("receive") + .asChildOf(context).startActive(Observer.FINISH_ON_CLOSE)) { + scope.span().setTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER); } } diff --git a/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java b/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java index de99786..a8eb64a 100644 --- a/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java +++ b/src/test/java/io/opentracing/contrib/examples/client_server/TestClientServer.java @@ -12,7 +12,7 @@ import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; import io.opentracing.tag.Tags; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.List; import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.TimeUnit; @@ -22,13 +22,13 @@ public class TestClientServer { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final ArrayBlockingQueue queue = new ArrayBlockingQueue<>(10); private Server server; @Before public void before() { + tracer.setScopeManager(new ThreadLocalScopeManager()); server = new Server(queue, tracer); server.start(); } @@ -51,6 +51,6 @@ public void test() throws Exception { assertEquals(finished.get(0).context().traceId(), finished.get(1).context().traceId()); assertNotNull(getOneByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_CLIENT)); assertNotNull(getOneByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_SERVER)); - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } } diff --git a/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java b/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java index d8b1fb0..f19d43f 100644 --- a/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java +++ b/src/test/java/io/opentracing/contrib/examples/listener_per_request/TestListener.java @@ -9,7 +9,7 @@ import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; import io.opentracing.tag.Tags; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.List; import org.junit.Test; @@ -18,11 +18,11 @@ */ public class TestListener { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); @Test public void test() throws Exception { + tracer.setScopeManager(new ThreadLocalScopeManager()); Client client = new Client(tracer); Object response = client.send("message").get(); assertEquals("message:response", response); @@ -30,6 +30,6 @@ public void test() throws Exception { List finished = tracer.finishedSpans(); assertEquals(1, finished.size()); assertNotNull(getOneByTag(finished, Tags.SPAN_KIND, Tags.SPAN_KIND_CLIENT)); - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } } From f91856cd2274b9c757d45b24a721ab14a4064e7f Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Tue, 22 Aug 2017 05:07:52 +0200 Subject: [PATCH 14/16] Update the latest examples with the Scope prototype. --- .../activate_deactivate/Callback.java | 15 ++++---- .../activate_deactivate/TestCallback.java | 18 ++++++--- .../TestActiveSpanReplacement.java | 34 ++++++++++------- .../common_request_handler/TestHandler.java | 17 +++++---- .../late_span_finish/TestLateSpanFinish.java | 27 ++++++++------ .../examples/multiple_callbacks/Client.java | 13 ++++--- .../TestMultipleCallbacks.java | 19 +++++----- .../nested_callbacks/TestNestedCallbacks.java | 37 +++++++++++-------- 8 files changed, 103 insertions(+), 77 deletions(-) diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java index 2d1ac0a..ec8f384 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/Callback.java @@ -1,9 +1,8 @@ package io.opentracing.contrib.examples.activate_deactivate; import io.opentracing.Scope; -import io.opentracing.Scope.Observer; -import io.opentracing.ScopeManager; -import io.opentracing.Span; +import io.opentracing.usecases.AutoFinishScopeManager; +import io.opentracing.usecases.AutoFinishScopeManager.AutoFinishScope; import io.opentracing.tag.Tags; import java.util.Random; import java.util.concurrent.TimeUnit; @@ -20,10 +19,10 @@ public class Callback implements Runnable { private final Random random = new Random(); - private final Span continuation; + private final AutoFinishScope.Continuation continuation; - Callback(Span activeSpan) { - continuation = activeSpan; + Callback(Scope activeSpan) { + continuation = ((AutoFinishScope)activeSpan).defer(); logger.info("Callback created"); } @@ -35,7 +34,7 @@ public class Callback implements Runnable { public void run() { logger.info("Callback started"); - Scope scope = continuation.activate(Observer.FINISH_ON_CLOSE); + Scope scope = continuation.activate(); try { TimeUnit.SECONDS.sleep(1); } catch (InterruptedException e) { @@ -43,7 +42,7 @@ public void run() { } // set random tag starting with 'test_tag_' to test that finished span has all of them - activeSpan.setTag("test_tag_" + random.nextInt(), "random"); + scope.span().setTag("test_tag_" + random.nextInt(), "random"); scope.close(); logger.info("Callback finished"); diff --git a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java index 3e90fd0..3833401 100644 --- a/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java +++ b/src/test/java/io/opentracing/contrib/examples/activate_deactivate/TestCallback.java @@ -11,13 +11,14 @@ import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; import io.opentracing.tag.Tags; -import io.opentracing.util.ThreadLocalScopeManager; +import io.opentracing.usecases.AutoFinishScopeManager; import java.util.List; import java.util.Map; import java.util.Random; import java.util.concurrent.Executors; import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; +import org.junit.Before; import org.junit.Test; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -29,9 +30,14 @@ public class TestCallback { private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final ScheduledExecutorService service = Executors.newScheduledThreadPool(1); + @Before + public void before() { + tracer.reset(); + tracer.setScopeManager(new AutoFinishScopeManager()); + } + @Test public void test() throws Exception { - tracer.setScopeManager(new ThreadLocalScopeManager()); Thread entryThread = entryThread(); entryThread.start(); entryThread.join(10_000); @@ -82,7 +88,7 @@ public void run() { logger.info("Entry thread started"); try (Scope scope = tracer.buildSpan("parent").startActive()) { - Runnable callback = new Callback(scope.span()); + Runnable callback = new Callback(scope); // Callback is executed at some unpredictable time and we are not able to check status of the callback service.schedule(callback, 500, TimeUnit.MILLISECONDS); @@ -101,9 +107,9 @@ private Thread entryThreadWithTwoCallbacks() { @Override public void run() { logger.info("Entry thread 2x started"); - try (ActiveSpan activeSpan = tracer.buildSpan("parent").startActive()) { - Runnable callback = new Callback(activeSpan); - Runnable callback2 = new Callback(activeSpan); + try (Scope scope = tracer.buildSpan("parent").startActive()) { + Runnable callback = new Callback(scope); + Runnable callback2 = new Callback(scope); Random random = new Random(); diff --git a/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java b/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java index 22c8c3a..3bb7515 100644 --- a/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java +++ b/src/test/java/io/opentracing/contrib/examples/active_span_replacement/TestActiveSpanReplacement.java @@ -8,30 +8,37 @@ import static org.junit.Assert.assertNotEquals; import static org.junit.Assert.assertNull; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; +import io.opentracing.Span; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.List; import java.util.concurrent.TimeUnit; import java.util.concurrent.Executors; import java.util.concurrent.ExecutorService; +import org.junit.Before; import org.junit.Test; public class TestActiveSpanReplacement { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final ExecutorService executor = Executors.newCachedThreadPool(); + @Before + public void before() { + tracer.reset(); + tracer.setScopeManager(new ThreadLocalScopeManager()); + } + @Test public void test() throws Exception { - /* Start an isolated task and query for its result in another task/thread */ - try (ActiveSpan span = tracer.buildSpan("initial").startActive()) { - submitAnotherTask(span); - } + /* Start an isolated task and query for its result -and finish it- in another task/thread */ + Span span = tracer.buildSpan("initial").startManual(); + submitAnotherTask(span); await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(3)); @@ -50,25 +57,24 @@ public void test() throws Exception { assertNotEquals(spans.get(0).context().traceId(), spans.get(1).context().traceId()); assertEquals(0, spans.get(0).parentId()); - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } - private void submitAnotherTask(ActiveSpan span) { - final ActiveSpan.Continuation cont = span.capture(); + private void submitAnotherTask(final Span span) { executor.submit(new Runnable() { @Override public void run () { /* Create a new Span for this task */ - try (ActiveSpan taskSpan = tracer.buildSpan("task").startActive()) { + try (Scope taskSpan = tracer.buildSpan("task").startActive(Observer.FINISH_ON_CLOSE)) { /* Simulate work strictly related to the initial Span. */ - try (ActiveSpan initialSpan = cont.activate()) { + try (Scope initialSpan = span.activate(Observer.FINISH_ON_CLOSE)) { sleep(50); } /* Restore the span for this task and create a subspan */ - try (ActiveSpan subTask = tracer.buildSpan("subtask").startActive()) { + try (Scope subTask = tracer.buildSpan("subtask").startActive(Observer.FINISH_ON_CLOSE)) { } } } diff --git a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java index 61354af..23e8f02 100644 --- a/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java +++ b/src/test/java/io/opentracing/contrib/examples/common_request_handler/TestHandler.java @@ -6,12 +6,13 @@ import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertNull; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; import io.opentracing.tag.Tags; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.ArrayList; import java.util.List; import java.util.concurrent.Future; @@ -26,13 +27,13 @@ */ public class TestHandler { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final Client client = new Client(new RequestHandler(tracer)); @Before public void before() { tracer.reset(); + tracer.setScopeManager(new ThreadLocalScopeManager()); } @Test @@ -53,7 +54,7 @@ public void two_requests() throws Exception { assertNotEquals(finished.get(0).context().traceId(), finished.get(1).context().traceId()); assertEquals(finished.get(0).parentId(), finished.get(1).parentId()); - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } /** @@ -61,7 +62,7 @@ public void two_requests() throws Exception { */ @Test public void parent_not_picked_up() throws Exception { - try (ActiveSpan parent = tracer.buildSpan("parent").startActive()) { + try (Scope parent = tracer.buildSpan("parent").startActive(Observer.FINISH_ON_CLOSE)) { Object response = client.send("no_parent").get(15, TimeUnit.SECONDS); assertEquals("no_parent:response", response); } @@ -86,8 +87,8 @@ public void parent_not_picked_up() throws Exception { @Test public void bad_solution_to_set_parent() throws Exception { Client client; - try (ActiveSpan parent = tracer.buildSpan("parent").startActive()) { - client = new Client(new RequestHandler(tracer, parent.context())); + try (Scope parent = tracer.buildSpan("parent").startActive(Observer.FINISH_ON_CLOSE)) { + client = new Client(new RequestHandler(tracer, parent.span().context())); Object response = client.send("correct_parent").get(15, TimeUnit.SECONDS); assertEquals("correct_parent:response", response); } diff --git a/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java b/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java index f192472..6f73cfe 100644 --- a/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java +++ b/src/test/java/io/opentracing/contrib/examples/late_span_finish/TestLateSpanFinish.java @@ -4,24 +4,31 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNull; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; import io.opentracing.Span; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.List; import java.util.concurrent.TimeUnit; import java.util.concurrent.Executors; import java.util.concurrent.ExecutorService; +import org.junit.Before; import org.junit.Test; public class TestLateSpanFinish { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final ExecutorService executor = Executors.newCachedThreadPool(); + @Before + public void before() { + tracer.reset(); + tracer.setScopeManager(new ThreadLocalScopeManager()); + } + @Test public void test() throws Exception { /* Create a Span manually and use it as parent of a pair of subtasks */ @@ -47,7 +54,7 @@ public void test() throws Exception { assertEquals(spans.get(2).context().spanId(), spans.get(i).parentId()); } - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } /* Fire away a few subtasks, passing a parent Span whose lifetime @@ -58,11 +65,10 @@ private void submitTasks(final Span parentSpan) { @Override public void run() { // Alternative to calling makeActive() is to pass it manually to asChildOf() for each created Span. - try (ActiveSpan span = tracer.makeActive(parentSpan)) { - try (ActiveSpan childSpan1 = tracer.buildSpan("task1").startActive()) { + try (Scope span = parentSpan.activate()) { + try (Scope childSpan1 = tracer.buildSpan("task1").startActive(Observer.FINISH_ON_CLOSE)) { sleep(55); } - span.capture(); // Workaround, prevent parentSpan from being finished here. } } }); @@ -70,11 +76,10 @@ public void run() { executor.submit(new Runnable() { @Override public void run() { - try (ActiveSpan span = tracer.makeActive(parentSpan)) { - try (ActiveSpan childSpan1 = tracer.buildSpan("task2").startActive()) { + try (Scope span = parentSpan.activate()) { + try (Scope childSpan1 = tracer.buildSpan("task2").startActive(Observer.FINISH_ON_CLOSE)) { sleep(85); } - span.capture(); // Workaround, prevent parentSpan from being finished here. } } }); diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java index 29cbe08..2d68c11 100644 --- a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/Client.java @@ -2,8 +2,10 @@ import static io.opentracing.contrib.examples.TestUtils.sleep; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Span; import io.opentracing.Tracer; +import io.opentracing.usecases.AutoFinishScopeManager.AutoFinishScope; import java.util.concurrent.Callable; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; @@ -22,15 +24,16 @@ public Client(Tracer tracer) { this.tracer = tracer; } - public Future send(final Object message, ActiveSpan parentSpan, final long milliseconds) { - final ActiveSpan.Continuation cont = parentSpan.capture(); + public Future send(final Object message, final Scope parentScope, final long milliseconds) { + final AutoFinishScope.Continuation cont = ((AutoFinishScope)parentScope).defer(); + return executor.submit(new Callable() { @Override public Object call() throws Exception { logger.info("Child thread with message '{}' started", message); - try (ActiveSpan parentSpan = cont.activate()) { - try (ActiveSpan span = tracer.buildSpan("subtask").startActive()) { + try (Scope parentScope = cont.activate()) { + try (Scope scope = tracer.buildSpan("subtask").startActive()) { // Simulate work. sleep(milliseconds); } diff --git a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java index 40c04e3..7901f31 100644 --- a/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java +++ b/src/test/java/io/opentracing/contrib/examples/multiple_callbacks/TestMultipleCallbacks.java @@ -6,27 +6,28 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNull; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.usecases.AutoFinishScopeManager; import java.util.List; import java.util.concurrent.TimeUnit; import org.junit.Test; public class TestMultipleCallbacks { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); @Test public void test() throws Exception { + tracer.setScopeManager(new AutoFinishScopeManager()); + Client client = new Client(tracer); - try (ActiveSpan span = tracer.buildSpan("parent").startActive()) { - client.send("task1", span, 300); - client.send("task2", span, 200); - client.send("task3", span, 100); + try (Scope scope = tracer.buildSpan("parent").startActive()) { + client.send("task1", scope, 300); + client.send("task2", scope, 200); + client.send("task3", scope, 100); } await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(4)); @@ -42,6 +43,6 @@ public void test() throws Exception { assertEquals(parentSpan.context().spanId(), spans.get(i).parentId()); } - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } } diff --git a/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java b/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java index 6b3135e..4675105 100644 --- a/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java +++ b/src/test/java/io/opentracing/contrib/examples/nested_callbacks/TestNestedCallbacks.java @@ -6,30 +6,37 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNull; -import io.opentracing.ActiveSpan; +import io.opentracing.Scope; +import io.opentracing.Scope.Observer; +import io.opentracing.Span; import io.opentracing.mock.MockSpan; import io.opentracing.mock.MockTracer; import io.opentracing.mock.MockTracer.Propagator; -import io.opentracing.util.ThreadLocalActiveSpanSource; +import io.opentracing.util.ThreadLocalScopeManager; import java.util.List; import java.util.Map; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; +import org.junit.Before; import org.junit.Test; public class TestNestedCallbacks { - private final MockTracer tracer = new MockTracer(new ThreadLocalActiveSpanSource(), - Propagator.TEXT_MAP); + private final MockTracer tracer = new MockTracer(Propagator.TEXT_MAP); private final ExecutorService executor = Executors.newCachedThreadPool(); + @Before + public void before() { + tracer.reset(); + tracer.setScopeManager(new ThreadLocalScopeManager()); + } + @Test public void test() throws Exception { - - try (ActiveSpan span = tracer.buildSpan("one").startActive()) { - submitCallbacks(span); - } + /* Start a Span and let the callback-chain + * finish it when the task is done */ + submitCallbacks(tracer.buildSpan("one").startManual()); await().atMost(15, TimeUnit.SECONDS).until(reportedSpansSize(tracer), equalTo(1)); @@ -43,30 +50,28 @@ public void test() throws Exception { assertEquals(Integer.toString(i), tags.get("key" + i)); } - assertNull(tracer.activeSpan()); + assertNull(tracer.scopeManager().active()); } - private void submitCallbacks(ActiveSpan span) { - final ActiveSpan.Continuation cont = span.capture(); + private void submitCallbacks(final Span span) { executor.submit(new Runnable() { @Override public void run() { - try (ActiveSpan span = cont.activate()) { + try (Scope scope = span.activate()) { span.setTag("key1", "1"); - final ActiveSpan.Continuation cont = span.capture(); executor.submit(new Runnable() { @Override public void run() { - try (ActiveSpan span = cont.activate()) { + try (Scope scope = span.activate()) { span.setTag("key2", "2"); - final ActiveSpan.Continuation cont = span.capture(); executor.submit(new Runnable() { @Override public void run() { - try (ActiveSpan span = cont.activate()) { + /* Decide explicitly when to finish the Span */ + try (Scope scope = span.activate(Observer.FINISH_ON_CLOSE)) { span.setTag("key3", "3"); } } From f62b2e832cd6354ff63a306e03e50672258bcc4c Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Wed, 23 Aug 2017 19:13:12 +0200 Subject: [PATCH 15/16] Update the README with instructions to build/test the PR. --- README.md | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) diff --git a/README.md b/README.md index 6cc8f8a..2219ef4 100644 --- a/README.md +++ b/README.md @@ -6,3 +6,32 @@ tester examples of common instrumentation patterns [ci-img]: https://travis-ci.org/opentracing-contrib/java-examples.svg?branch=master [ci]: https://travis-ci.org/opentracing-contrib/java-examples + +## Testing against a Java Opentracing PR/branch. + +In order to test these examples against https://github.com/bhs/opentracing-java/pull/5, you have to install it first in the local Maven repository: + + $ cd opentracing_java/ + $ git remote add bhs https://github.com/bhs/opentracing-java + $ git fetch bhs pull/5/head:bhs/scopes + $ git checkout bhs/scopes + $ mvn compile install + +By default the version for a build looks like `0.30.1-SNAPSHOT`, which helps to keep the stable and the testing one side by side. + +Next, look for the `` section in the `pom.xml` file under this directory, updating the `opentracing` version; and also add a dependency to the `usecases` package: + +```xml +0.30.1-SNAPSHOT +... + + io.opentracing + opentracing-usecases + ${opentracing.version} + test + +``` + +Finally, run (under this directory as well): + + $ mvn test From a144e92c8ff286c6de110c373fe59ee642f13b42 Mon Sep 17 00:00:00 2001 From: Carlos Alberto Cortez Date: Wed, 23 Aug 2017 20:49:24 +0200 Subject: [PATCH 16/16] Clarify the PR installation step/need. --- README.md | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/README.md b/README.md index 2219ef4..e63015e 100644 --- a/README.md +++ b/README.md @@ -9,7 +9,7 @@ tester examples of common instrumentation patterns ## Testing against a Java Opentracing PR/branch. -In order to test these examples against https://github.com/bhs/opentracing-java/pull/5, you have to install it first in the local Maven repository: +In order to test these examples against https://github.com/bhs/opentracing-java/pull/5, you have to fetch the PR locally, and then install it in local Maven repository (required once only): $ cd opentracing_java/ $ git remote add bhs https://github.com/bhs/opentracing-java @@ -35,3 +35,5 @@ Next, look for the `` section in the `pom.xml` file under this direc Finally, run (under this directory as well): $ mvn test + +Any further changes under this repository will not need re-installing anything, simply re-running this last command.