Java Code Examples for io.opentracing.mock.MockSpan#logEntries()

@Test
void shouldTagException() {
    final ResponseEntity<String> response = client
            .getForEntity("http://localhost:8080/exception", String.class);

    assertTrue(response.getStatusCode().is5xxServerError());

    final MockSpan span = span();
    final Map<String, Object> tags = span.tags();

    assertThat(tags, hasEntry("error", true));

    final List<MockSpan.LogEntry> logs = span.logEntries();
    assertThat(logs, hasSize(3));

    assertThat(logs.get(0).fields(), hasEntry(equalTo("message"),
            hasFeature(Objects::toString, containsString("Error"))));
    assertThat(logs.get(1).fields(),
            hasEntry("error.kind", "NestedServletException"));
    assertThat((Throwable) logs.get(1).fields().get("error.object"),
            hasFeature(Throwables::getRootCause,
                    instanceOf(UnsupportedOperationException.class)));
    assertThat(logs.get(2).fields(),
            hasEntry(equalTo("stack"), instanceOf(String.class)));
}
 

@Test
public void testGetSpanFromHeaders() {
  long traceID = 1;
  long spanID = 2;
  MockTracer spyTracer = spy(serverTracer);
  doReturn(new MockSpan.MockContext(traceID, spanID, Collections.<String, String>emptyMap()))
      .when(spyTracer)
      .extract(eq(Format.Builtin.HTTP_HEADERS), any(TextMapAdapter.class));

  Span span =
      TracingServerInterceptor.newBuilder()
          .withTracer(spyTracer)
          .build()
          .getSpanFromHeaders(Collections.<String, String>emptyMap(), "operationName");
  assertNotNull("span is not null", span);
  MockSpan mockSpan = (MockSpan) span;
  assertEquals(
      "span parentID is set to extracted span context spanID", spanID, mockSpan.parentId());
  List<MockSpan.LogEntry> logEntries = mockSpan.logEntries();
  assertTrue("span contains no log entries", logEntries.isEmpty());
}
 

private static void assertLogs(final JsonObject expectedSpan, final MockSpan span, final String message) {
  final JsonArray expectedLogs = expectedSpan.getArray("logs");
  final List<MockSpan.LogEntry> logEntries = span.logEntries();
  if (expectedLogs == null) {
    assertEquals(message, 0, logEntries.size());
    return;
  }

  assertEquals(message, expectedLogs.size(), logEntries.size());
  for (int i = 0; i < expectedLogs.size(); ++i)
    assertLog(Objects.requireNonNull(expectedLogs.getObject(i)), logEntries.get(i), message + " log " + i);
}
 

@Test
void interceptsTimestampedLogs() {
    unit.buildSpan("test").start()
            .log(1337, "test")
            .finish();

    final MockSpan span = getOnlyElement(tracer.finishedSpans());
    final List<LogEntry> entries = span.logEntries();

    assertThat(entries, hasSize(2));
    assertThat(entries.get(0).timestampMicros(), is(1337L));
    assertThat(entries.get(0).fields(), hasEntry("event", "test"));
    assertThat(entries.get(1).timestampMicros(), is(1337L));
    assertThat(entries.get(1).fields(), hasEntry("v", 1));
}
 

@Test
void interceptsLogs() {
    unit.buildSpan("test").start()
            .log("test")
            .finish();

    final MockSpan span = getOnlyElement(tracer.finishedSpans());
    final List<LogEntry> entries = span.logEntries();

    assertThat(entries, hasSize(2));
    assertThat(entries.get(0).fields(), hasEntry("event", "test"));
    assertThat(entries.get(1).fields(), hasEntry("v", 1));
}
 

@Test
void shouldTagException() {
    final ResponseEntity<String> response = client
            .getForEntity("http://localhost:8080/exception", String.class);

    assertThat(response.getStatusCode().series(), is(SERVER_ERROR));

    waitFor(Duration.ofSeconds(1));

    final MockSpan span = span();
    final Map<String, Object> tags = span.tags();

    assertThat(tags, hasEntry("http.path", "/exception"));
    assertThat(tags, hasEntry("error", true));

    final List<MockSpan.LogEntry> logs = span.logEntries();
    assertThat(logs, hasSize(3));

    assertThat(logs.get(0).fields(), hasEntry("message", "Error"));
    assertThat(logs.get(1).fields(),
            hasEntry("error.kind", "UnsupportedOperationException"));
    assertThat(logs.get(1).fields(), hasEntry(
            equalTo("error.object"),
            instanceOf(UnsupportedOperationException.class)));

    assertThat(logs.get(2).fields(),
            hasEntry(equalTo("stack"), instanceOf(String.class)));
}
 

@Test
void shouldTagException() {
    final ClientResponse response = client.get()
            .uri("/exception")
            .exchange()
            .block();

    assertTrue(response.statusCode().is5xxServerError());

    final MockSpan span = span();
    final Map<String, Object> tags = span.tags();

    assertThat(tags, hasEntry("http.path", "/exception"));
    assertThat(tags, hasEntry("error", true));

    final List<MockSpan.LogEntry> logs = span.logEntries();
    assertThat(logs, hasSize(3));

    assertThat(logs.get(0).fields(), hasEntry(equalTo("message"),
            hasFeature(Objects::toString, containsString("Error"))));
    assertThat(logs.get(1).fields(),
            hasEntry("error.kind", "UnsupportedOperationException"));
    assertThat(logs.get(1).fields().get("error.object"),
            instanceOf(UnsupportedOperationException.class));
    assertThat(logs.get(2).fields(),
            hasEntry(equalTo("stack"), instanceOf(String.class)));
}
 

@Test
void shouldTraceErrors() {
    final DataSource dataSource = unit.trace(original);

    assertThrows(SQLException.class, () -> {
        try (final Connection connection = dataSource.getConnection();
             final Statement statement = connection.createStatement()) {

            statement.execute("SELECT * FROM MATRIX(4)");
        }
    });

    final List<MockSpan> spans = tracer.finishedSpans();
    final MockSpan span = getOnlyElement(spans);

    assertThat(span.operationName(), is("execute"));
    assertThat(span.tags(), hasEntry("component", "JDBC"));
    assertThat(span.tags(), hasEntry("db.statement", "SELECT * FROM MATRIX(4)"));
    assertThat(span.tags(), hasEntry("db.type", "sql"));
    assertThat(span.tags(), hasEntry("span.kind", "client"));
    assertThat(span.tags(), hasEntry("flow_id", "REcCvlqMSReeo7adheiYFA"));
    assertThat(span.tags(), hasEntry("error", true));

    final List<MockSpan.LogEntry> entries = span.logEntries();
    assertThat(entries, hasSize(3));

    assertThat(entries.get(0).fields().get("message").toString(),
            containsString("Function \"MATRIX\" not found"));

    assertThat(entries.get(1).fields(), hasEntry("error.kind", "JdbcSQLSyntaxErrorException"));
    assertThat(entries.get(1).fields(), hasEntry(equalTo("error.object"), instanceOf(SQLException.class)));

    assertThat(entries.get(2).fields().get("stack").toString(), containsString("at org.h2.jdbc"));
}
 

protected final void assertSpanError(final Class<? extends Throwable> expectedException, final String expectedErrorMessage) {
    final MockSpan actual = getActualSpan();
    assertTrue((Boolean) actual.tags().get(Tags.ERROR.getKey()));
    List<MockSpan.LogEntry> actualLogEntries = actual.logEntries();
    assertThat(actualLogEntries.size(), is(1));
    assertThat(actualLogEntries.get(0).fields().size(), is(3));
    assertThat(actualLogEntries.get(0).fields().get(ShardingErrorLogTags.EVENT), is(ShardingErrorLogTags.EVENT_ERROR_TYPE));
    assertThat(actualLogEntries.get(0).fields().get(ShardingErrorLogTags.ERROR_KIND), is(expectedException.getName()));
    assertThat(actualLogEntries.get(0).fields().get(ShardingErrorLogTags.MESSAGE), is(expectedErrorMessage));
}
 

@Test
public void testTracedClientWithStreaming() {
  TracingClientInterceptor tracingInterceptor =
      TracingClientInterceptor.newBuilder().withTracer(clientTracer).withStreaming().build();
  TracedClient client = new TracedClient(grpcServer.getChannel(), tracingInterceptor);

  assertEquals("call should complete successfully", "Hello world", client.greet().getMessage());
  await().atMost(5, TimeUnit.SECONDS).until(reportedSpansSize(clientTracer), equalTo(1));
  assertEquals(
      "one span should have been created and finished for one client request",
      clientTracer.finishedSpans().size(),
      1);

  MockSpan span = clientTracer.finishedSpans().get(0);
  assertEquals("span should have prefix", span.operationName(), "helloworld.Greeter/SayHello");
  assertEquals("span should have no parents", span.parentId(), 0);
  List<String> events = new ArrayList<>(span.logEntries().size());
  for (MockSpan.LogEntry logEntry : span.logEntries()) {
    events.add((String) logEntry.fields().get(Fields.EVENT));
  }
  Assertions.assertThat(events)
      .as("span should contain streaming log fields")
      .contains(
          GrpcFields.CLIENT_CALL_SEND_MESSAGE,
          GrpcFields.CLIENT_CALL_HALF_CLOSE,
          GrpcFields.CLIENT_CALL_LISTENER_ON_MESSAGE);
  Assertions.assertThat(span.tags())
      .as("span should have base client tags")
      .isEqualTo(BASE_CLIENT_TAGS);
  assertFalse("span should have no baggage", span.context().baggageItems().iterator().hasNext());
}
 

@Test
public void testTracedClientWithVerbosity() {
  TracingClientInterceptor tracingInterceptor =
      TracingClientInterceptor.newBuilder().withTracer(clientTracer).withVerbosity().build();
  TracedClient client = new TracedClient(grpcServer.getChannel(), tracingInterceptor);

  assertEquals("call should complete successfully", "Hello world", client.greet().getMessage());
  await().atMost(5, TimeUnit.SECONDS).until(reportedSpansSize(clientTracer), equalTo(1));
  assertEquals(
      "one span should have been created and finished for one client request",
      clientTracer.finishedSpans().size(),
      1);

  MockSpan span = clientTracer.finishedSpans().get(0);
  assertEquals("span should have prefix", span.operationName(), "helloworld.Greeter/SayHello");
  assertEquals("span should have no parents", span.parentId(), 0);
  System.out.println(span.logEntries());
  List<String> events = new ArrayList<>(span.logEntries().size());
  for (MockSpan.LogEntry logEntry : span.logEntries()) {
    events.add((String) logEntry.fields().get(Fields.EVENT));
  }
  Assertions.assertThat(events)
      .as("span should contain verbose log fields")
      .contains(
          GrpcFields.CLIENT_CALL_START,
          GrpcFields.CLIENT_CALL_SEND_MESSAGE,
          GrpcFields.CLIENT_CALL_HALF_CLOSE,
          GrpcFields.CLIENT_CALL_LISTENER_ON_HEADERS,
          GrpcFields.CLIENT_CALL_LISTENER_ON_MESSAGE,
          GrpcFields.CLIENT_CALL_LISTENER_ON_CLOSE);
  Assertions.assertThat(span.tags())
      .as("span should have base client tags")
      .isEqualTo(BASE_CLIENT_TAGS);
  assertFalse("span should have no baggage", span.context().baggageItems().iterator().hasNext());
}
 

@Test
public void testTracedServerWithStreaming() {
  TracingServerInterceptor tracingInterceptor =
      TracingServerInterceptor.newBuilder().withTracer(serverTracer).withStreaming().build();
  TracedService.addGeeterService(grpcServer.getServiceRegistry(), tracingInterceptor);

  assertEquals("call should complete successfully", "Hello world", client.greet().getMessage());
  await().atMost(5, TimeUnit.SECONDS).until(reportedSpansSize(serverTracer), equalTo(1));
  assertEquals(
      "one span should have been created and finished for one client request",
      serverTracer.finishedSpans().size(),
      1);

  MockSpan span = serverTracer.finishedSpans().get(0);
  assertEquals(
      "span should have default name", span.operationName(), "helloworld.Greeter/SayHello");
  assertEquals("span should have no parents", span.parentId(), 0);
  List<String> events = new ArrayList<>(span.logEntries().size());
  for (MockSpan.LogEntry logEntry : span.logEntries()) {
    events.add((String) logEntry.fields().get(Fields.EVENT));
  }
  Assertions.assertThat(events)
      .as("span should contain streaming log fields")
      .contains(
          GrpcFields.SERVER_CALL_LISTENER_ON_MESSAGE,
          GrpcFields.SERVER_CALL_LISTENER_ON_HALF_CLOSE,
          GrpcFields.SERVER_CALL_SEND_MESSAGE);
  Assertions.assertThat(span.tags())
      .as("span should have base server tags")
      .isEqualTo(BASE_SERVER_TAGS);
  assertFalse("span should have no baggage", span.context().baggageItems().iterator().hasNext());
}
 

@Test
public void testTracedServerWithVerbosity() {
  TracingServerInterceptor tracingInterceptor =
      TracingServerInterceptor.newBuilder().withTracer(serverTracer).withVerbosity().build();
  TracedService.addGeeterService(grpcServer.getServiceRegistry(), tracingInterceptor);

  assertEquals("call should complete successfully", "Hello world", client.greet().getMessage());
  await().atMost(5, TimeUnit.SECONDS).until(reportedSpansSize(serverTracer), equalTo(1));
  assertEquals(
      "one span should have been created and finished for one client request",
      serverTracer.finishedSpans().size(),
      1);

  MockSpan span = serverTracer.finishedSpans().get(0);
  assertEquals(
      "span should have default name", span.operationName(), "helloworld.Greeter/SayHello");
  assertEquals("span should have no parents", span.parentId(), 0);
  List<String> events = new ArrayList<>(span.logEntries().size());
  for (MockSpan.LogEntry logEntry : span.logEntries()) {
    events.add((String) logEntry.fields().get(Fields.EVENT));
  }
  Assertions.assertThat(events)
      .as("span should contain verbose log fields")
      .contains(
          GrpcFields.SERVER_CALL_LISTENER_ON_MESSAGE,
          GrpcFields.SERVER_CALL_LISTENER_ON_HALF_CLOSE,
          GrpcFields.SERVER_CALL_SEND_HEADERS,
          GrpcFields.SERVER_CALL_SEND_MESSAGE,
          GrpcFields.SERVER_CALL_CLOSE,
          GrpcFields.SERVER_CALL_LISTENER_ON_COMPLETE);
  Assertions.assertThat(span.tags())
      .as("span should have base server tags")
      .isEqualTo(BASE_SERVER_TAGS);
  assertFalse("span should have no baggage", span.context().baggageItems().iterator().hasNext());
}
 

private static void printSpan(final MockSpan span) {
  System.out.println("Span: " + span);
  System.out.println("\tComponent: " + span.tags().get(Tags.COMPONENT.getKey()));
  System.out.println("\tTags: " + span.tags());
  System.out.println("\tLogs: ");
  for (final LogEntry logEntry : span.logEntries())
    System.out.println("\t" + logEntry.fields());
}
 

private static void printSpan(final MockSpan span) {
  System.out.println("Span: " + span);
  System.out.println("\tComponent: " + span.tags().get(Tags.COMPONENT.getKey()));
  System.out.println("\tTags: " + span.tags());
  System.out.println("\tLogs: ");
  for (final LogEntry logEntry : span.logEntries())
    System.out.println("\t" + logEntry.fields());
}
 

private static void printSpan(final MockSpan span) {
  System.out.println("Span: " + span);
  System.out.println("\tComponent: " + span.tags().get(Tags.COMPONENT.getKey()));
  System.out.println("\tTags: " + span.tags());
  System.out.println("\tLogs: ");
  for (final LogEntry logEntry : span.logEntries())
    System.out.println("\t" + logEntry.fields());
}
 

@Test
void shouldTraceRequestAndServerError() {
    driver.addExpectation(onRequestTo("/"), giveEmptyResponse().withStatus(500));

    final MockSpan parent = tracer.buildSpan("test").start();

    try (final Scope ignored = tracer.activateSpan(parent)) {
        final CompletableFuture<ClientHttpResponse> future = unit.get(URI.create(driver.getBaseUrl()))
                .attribute(OpenTracingPlugin.TAGS, singletonMap("test", "true"))
                .attribute(OpenTracingPlugin.LOGS, singletonMap("retry_number", 2))
                .call(noRoute());

        final CompletionException error = assertThrows(CompletionException.class, future::join);
        assertThat(error.getCause(), is(instanceOf(UnexpectedResponseException.class)));
    } finally {
        parent.finish();
    }

    final List<MockSpan> spans = tracer.finishedSpans();
    assertThat(spans, hasSize(2));

    assertThat(spans.get(1), is(parent));

    final MockSpan child = spans.get(0);
    assertThat(child.parentId(), is(parent.context().spanId()));

    assertThat(child.tags(), hasEntry("component", "Riptide"));
    assertThat(child.tags(), hasEntry("span.kind", "client"));
    assertThat(child.tags(), hasEntry("peer.address", "localhost:" + driver.getPort()));
    assertThat(child.tags(), hasEntry("peer.hostname", "localhost"));
    assertThat(child.tags(), hasEntry("peer.port", driver.getPort()));
    assertThat(child.tags(), hasEntry("http.method", "GET"));
    assertThat(child.tags(), hasEntry("http.status_code", 500));
    assertThat(child.tags(), hasEntry("error", true));
    assertThat(child.tags(), hasEntry("test", "true"));
    assertThat(child.tags(), hasEntry("test.environment", "JUnit"));
    assertThat(child.tags(), hasEntry("spi", true));

    // since we didn't use a uri template
    assertThat(child.tags(), not(hasKey("http.path")));

    final List<LogEntry> logs = child.logEntries();
    assertThat(logs, hasSize(1));
    final LogEntry log = logs.get(0);
    assertThat(log.fields(), hasEntry("retry_number", 2));
}
 

@Test
void shouldTraceRequestAndNetworkError() {
    driver.addExpectation(onRequestTo("/"), giveEmptyResponse().after(1, SECONDS));

    final MockSpan parent = tracer.buildSpan("test").start();

    try (final Scope ignored = tracer.activateSpan(parent)) {
        final CompletableFuture<ClientHttpResponse> future = unit.get(URI.create(driver.getBaseUrl()))
                .call(noRoute());

        final CompletionException error = assertThrows(CompletionException.class, future::join);
        assertThat(error.getCause(), is(instanceOf(SocketTimeoutException.class)));
    } finally {
        parent.finish();
    }

    final List<MockSpan> spans = tracer.finishedSpans();
    assertThat(spans, hasSize(2));

    assertThat(spans.get(1), is(parent));

    final MockSpan child = spans.get(0);
    assertThat(child.parentId(), is(parent.context().spanId()));

    assertThat(child.tags(), hasEntry("component", "Riptide"));
    assertThat(child.tags(), hasEntry("span.kind", "client"));
    assertThat(child.tags(), hasEntry("peer.address", "localhost:" + driver.getPort()));
    assertThat(child.tags(), hasEntry("peer.hostname", "localhost"));
    assertThat(child.tags(), hasEntry("peer.port", driver.getPort()));
    assertThat(child.tags(), hasEntry("http.method", "GET"));
    assertThat(child.tags(), hasEntry("error", true));

    // since we didn't use a uri template
    assertThat(child.tags(), not(hasKey("http.path")));

    // since we didn't get any response
    assertThat(child.tags(), not(hasKey("http.status_code")));

    final List<LogEntry> logs = child.logEntries();
    assertThat(logs, hasSize(3));

    for (int i = 0; i < logs.size(); i++) {
        final LogEntry log = logs.get(i);

        switch (i) {
            case 0: {
                assertThat(log.fields(), hasEntry("error.kind", "SocketTimeoutException"));
                assertThat(log.fields(), hasEntry(is("error.object"), is(instanceOf(SocketTimeoutException.class))));
                break;
            }
            case 1: {
                assertThat(log.fields().get("stack").toString(),
                        containsString("java.net.SocketTimeoutException: Read timed out"));
                break;
            }
            case 2: {
                assertThat(log.fields(), hasEntry("message", "Read timed out"));
                break;
            }
            default: {
                throw new AssertionError();
            }
        }
    }
}
 

void assertNoErrorLogged(MockSpan span) {
    for (final MockSpan.LogEntry logEntry : span.logEntries()) {
        assertNotEquals("error", logEntry.fields().get("event"));
    }
}
 

@Test(timeout = 20000)
public void testSend() throws Exception {
    try (TestAmqpPeer testPeer = new TestAmqpPeer();) {
        JmsConnectionFactory factory = new JmsConnectionFactory(createPeerURI(testPeer));

        MockTracer mockTracer = new MockTracer();
        JmsTracer tracer = OpenTracingTracerFactory.create(mockTracer);
        factory.setTracer(tracer);

        testPeer.expectSaslAnonymous();
        testPeer.expectOpen();
        testPeer.expectBegin();

        Connection connection = factory.createConnection();
        connection.start();

        testPeer.expectBegin();

        Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
        String queueName = "myQueue";
        Queue queue = session.createQueue(queueName);

        testPeer.expectSenderAttach();

        MessageProducer producer = session.createProducer(queue);

        // Expect a message with the trace info annotation set
        String msgContent = "myTracedMessageContent";
        TransferPayloadCompositeMatcher messageMatcher = new TransferPayloadCompositeMatcher();
        messageMatcher.setHeadersMatcher(new MessageHeaderSectionMatcher(true));
        MessageAnnotationsSectionMatcher msgAnnotationsMatcher = new MessageAnnotationsSectionMatcher(true);
        msgAnnotationsMatcher.withEntry(Symbol.valueOf(ANNOTATION_KEY), Matchers.any(Map.class));
        messageMatcher.setMessageAnnotationsMatcher(msgAnnotationsMatcher);
        messageMatcher.setPropertiesMatcher(new MessagePropertiesSectionMatcher(true));
        messageMatcher.setMessageContentMatcher(new EncodedAmqpValueMatcher(msgContent));

        testPeer.expectTransfer(messageMatcher);

        TextMessage message = session.createTextMessage(msgContent);
        producer.send(message);

        testPeer.waitForAllHandlersToComplete(2000);

        List<MockSpan> finishedSpans = mockTracer.finishedSpans();
        assertEquals("Expected 1 finished span: " + finishedSpans, 1, finishedSpans.size());
        Span sendSpan = finishedSpans.get(0);
        assertEquals("Unexpected span class", MockSpan.class, sendSpan.getClass());
        MockSpan sendMockSpan = (MockSpan) sendSpan;

        assertEquals("Expected span to have no parent", 0, sendMockSpan.parentId());
        assertEquals("Unexpected span operation name", SEND_SPAN_NAME, sendMockSpan.operationName());

        // Verify tags set on the completed span
        Map<String, Object> spanTags = sendMockSpan.tags();
        assertFalse("Expected some tags", spanTags.isEmpty());
        assertFalse("Expected error tag not to be set", spanTags.containsKey(Tags.ERROR.getKey()));
        assertEquals(Tags.SPAN_KIND_PRODUCER, spanTags.get(Tags.SPAN_KIND.getKey()));
        assertEquals(queueName, spanTags.get(Tags.MESSAGE_BUS_DESTINATION.getKey()));
        assertEquals(COMPONENT, spanTags.get(Tags.COMPONENT.getKey()));

        // Verify log set on the completed span
        List<LogEntry> entries = sendMockSpan.logEntries();
        assertEquals("Expected 1 log entry: " + entries, 1, entries.size());

        Map<String, ?> entryFields = entries.get(0).fields();
        assertFalse("Expected some log entry fields", entryFields.isEmpty());
        assertNotNull("Expected a state description", entryFields.get(STATE));
        assertEquals(DELIVERY_SETTLED, entryFields.get(Fields.EVENT));

        // Verify the context sent on the wire matches the original span
        Object obj = msgAnnotationsMatcher.getReceivedAnnotation(Symbol.valueOf(ANNOTATION_KEY));
        assertTrue("annotation was not a map", obj instanceof Map);
        @SuppressWarnings("unchecked")
        Map<String, String> traceInfo = (Map<String, String>) obj;
        assertFalse("Expected some content in map", traceInfo.isEmpty());

        SpanContext extractedContext = mockTracer.extract(Format.Builtin.TEXT_MAP, new TextMapAdapter(traceInfo));
        assertEquals("Unexpected context class", MockContext.class, extractedContext.getClass());
        assertEquals("Extracted context spanId did not match original", sendMockSpan.context().spanId(), ((MockContext) extractedContext).spanId());

        testPeer.expectClose();
        connection.close();

        testPeer.waitForAllHandlersToComplete(2000);
    }
}