io.opentracing.mock.MockSpan.LogEntry Java Examples

@Test
void delegatesLogs() {
    unit.log(singletonMap("first", 1));
    unit.log(1337, singletonMap("first", 1));
    unit.log("test");
    unit.log(1337, "test");

    final List<LogEntry> entries = delegate.logEntries();

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

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());
}
 

private void assertLogging(ContextData contextData) {
  await().until(() -> mockTracer.finishedSpans().size() == 1);
  List<MockSpan> mockSpans = mockTracer.finishedSpans();
  assertEquals(1, mockSpans.size());
  MockSpan mockSpan = mockSpans.get(0);
  // preHandle log
  // standard log
  // afterCompletion log
  assertEquals(3, mockSpan.logEntries().size());
  LogEntry logEntry = mockSpan.logEntries().get(1);

  if (contextData.getThrowable() == null && !contextData.isError()) {
    assertEquals(4, logEntry.fields().size());
  } else if (contextData.getThrowable() != null && contextData.isError()) {
    assertEquals(6, logEntry.fields().size());
  } else {
    assertEquals(5, logEntry.fields().size());
  }


  assertEquals(Controller.class.getName(), logEntry.fields().get("logger"));
  assertEquals(LOG, logEntry.fields().get("message"));
  assertEquals(contextData.getThread(), logEntry.fields().get("thread"));
  assertEquals(contextData.getLevel(), logEntry.fields().get("level"));
  if (contextData.getThrowable() != null) {
    assertEquals(contextData.getThrowable().getMessage(), ((Throwable)logEntry.fields().get("error.object")).getMessage());
  }
  if (contextData.isError()) {
    assertEquals(Tags.ERROR, logEntry.fields().get("event"));
  }
  // now >= timestamp +Nms > now
  assertTrue(contextData.getTimestamp() >= logEntry.timestampMicros()  && logEntry.timestampMicros() + 100 * 1000 > contextData.getTimestamp());
}
 

@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 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 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();
            }
        }
    }
}
 

@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);
    }
}