Examples with SpanInfo org.apache.phoenix.trace.TraceReader.SpanInfo used on opensource projects

Example 1 with SpanInfo

use of org.apache.phoenix.trace.TraceReader.SpanInfo in project phoenix by apache.

the class PhoenixTableMetricsWriterIT method writeMetrics.

/**
     * Simple metrics writing and reading check, that uses the standard wrapping in the
     * {@link TraceWriter}
     * @throws Exception on failure
     */
@Test
public void writeMetrics() throws Exception {
    Connection conn = getConnectionWithoutTracing();
    String tableName = generateUniqueName();
    TraceSpanReceiver traceSpanReceiver = new TraceSpanReceiver();
    latch = new CountDownLatch(1);
    testTraceWriter = new TestTraceWriter(tableName, defaultTracingThreadPoolForTest, defaultTracingBatchSizeForTest);
    // create a simple metrics record
    long traceid = 987654;
    String description = "Some generic trace";
    long spanid = 10;
    long parentid = 11;
    long startTime = 12;
    long endTime = 13;
    String processid = "Some process";
    String annotation = "test annotation for a span";
    Span span = createNewSpan(traceid, parentid, spanid, description, startTime, endTime, processid, annotation);
    traceSpanReceiver.getSpanQueue().add(span);
    assertTrue("Span never committed to table", latch.await(30, TimeUnit.SECONDS));
    // make sure we only get expected stat entry (matcing the trace id), otherwise we could the
    // stats for the update as well
    TraceReader reader = new TraceReader(conn, tableName);
    Collection<TraceHolder> traces = reader.readAll(10);
    assertEquals("Wrong number of traces in the tracing table", 1, traces.size());
    // validate trace
    TraceHolder trace = traces.iterator().next();
    // we are just going to get an orphan span b/c we don't send in a parent
    assertEquals("Didn't get expected orphaned spans!" + trace.orphans, 1, trace.orphans.size());
    assertEquals(traceid, trace.traceid);
    SpanInfo spanInfo = trace.orphans.get(0);
    assertEquals(description, spanInfo.description);
    assertEquals(parentid, spanInfo.getParentIdForTesting());
    assertEquals(startTime, spanInfo.start);
    assertEquals(endTime, spanInfo.end);
    assertEquals("Wrong number of tags", 0, spanInfo.tagCount);
    assertEquals("Wrong number of annotations", 1, spanInfo.annotationCount);
}

Example 2 with SpanInfo

use of org.apache.phoenix.trace.TraceReader.SpanInfo in project phoenix by apache.

the class PhoenixTracingEndToEndIT method validateTrace.

/**
     * @param spans
     * @param trace
     */
private void validateTrace(List<Span> spans, TraceHolder trace) {
    // drop each span into a sorted list so we get the expected ordering
    Iterator<SpanInfo> spanIter = trace.spans.iterator();
    for (Span span : spans) {
        SpanInfo spanInfo = spanIter.next();
        LOG.info("Checking span:\n" + spanInfo);
        long parentId = span.getParentId();
        if (parentId == Span.ROOT_SPAN_ID) {
            assertNull("Got a parent, but it was a root span!", spanInfo.parent);
        } else {
            assertEquals("Got an unexpected parent span id", parentId, spanInfo.parent.id);
        }
        assertEquals("Got an unexpected start time", span.getStartTimeMillis(), spanInfo.start);
        assertEquals("Got an unexpected end time", span.getStopTimeMillis(), spanInfo.end);
        int annotationCount = 0;
        for (Map.Entry<byte[], byte[]> entry : span.getKVAnnotations().entrySet()) {
            int count = annotationCount++;
            assertEquals("Didn't get expected annotation", count + " - " + Bytes.toString(entry.getValue()), spanInfo.annotations.get(count));
        }
        assertEquals("Didn't get expected number of annotations", annotationCount, spanInfo.annotationCount);
    }
}

Example 3 with SpanInfo

use of org.apache.phoenix.trace.TraceReader.SpanInfo in project phoenix by apache.

the class PhoenixTracingEndToEndIT method testWriteSpans.

/**
     * Simple test that we can correctly write spans to the phoenix table
     * @throws Exception on failure
     */
@Test
public void testWriteSpans() throws Exception {
    // watch our sink so we know when commits happen
    latch = new CountDownLatch(1);
    testTraceWriter = new TestTraceWriter(tracingTableName, defaultTracingThreadPoolForTest, defaultTracingBatchSizeForTest);
    // write some spans
    TraceScope trace = Trace.startSpan("Start write test", Sampler.ALWAYS);
    Span span = trace.getSpan();
    // add a child with some annotations
    Span child = span.child("child 1");
    child.addTimelineAnnotation("timeline annotation");
    TracingUtils.addAnnotation(child, "test annotation", 10);
    child.stop();
    // sleep a little bit to get some time difference
    Thread.sleep(100);
    trace.close();
    // pass the trace on
    Tracing.getTraceSpanReceiver().receiveSpan(span);
    // wait for the tracer to actually do the write
    assertTrue("Sink not flushed. commit() not called on the connection", latch.await(60, TimeUnit.SECONDS));
    // look for the writes to make sure they were made
    Connection conn = getConnectionWithoutTracing();
    checkStoredTraces(conn, new TraceChecker() {

        @Override
        public boolean foundTrace(TraceHolder trace, SpanInfo info) {
            if (info.description.equals("child 1")) {
                assertEquals("Not all annotations present", 1, info.annotationCount);
                assertEquals("Not all tags present", 1, info.tagCount);
                boolean found = false;
                for (String annotation : info.annotations) {
                    if (annotation.startsWith("test annotation")) {
                        found = true;
                    }
                }
                assertTrue("Missing the annotations in span: " + info, found);
                found = false;
                for (String tag : info.tags) {
                    if (tag.endsWith("timeline annotation")) {
                        found = true;
                    }
                }
                assertTrue("Missing the tags in span: " + info, found);
                return true;
            }
            return false;
        }
    });
}

Example 4 with SpanInfo

use of org.apache.phoenix.trace.TraceReader.SpanInfo in project phoenix by apache.

the class PhoenixTracingEndToEndIT method testClientServerIndexingTracing.

/**
     * Test that span will actually go into the this sink and be written on both side of the wire,
     * through the indexing code.
     * @throws Exception
     */
@Test
public void testClientServerIndexingTracing() throws Exception {
    // one call for client side, one call for server side
    latch = new CountDownLatch(2);
    testTraceWriter = new TestTraceWriter(tracingTableName, defaultTracingThreadPoolForTest, defaultTracingBatchSizeForTest);
    // separate connection so we don't create extra traces
    Connection conn = getConnectionWithoutTracing();
    createTestTable(conn, true);
    // trace the requests we send
    Connection traceable = getTracingConnection();
    LOG.debug("Doing dummy the writes to the tracked table");
    String insert = "UPSERT INTO " + enabledForLoggingTable + " VALUES (?, ?)";
    PreparedStatement stmt = traceable.prepareStatement(insert);
    stmt.setString(1, "key1");
    stmt.setLong(2, 1);
    // this first trace just does a simple open/close of the span. Its not doing anything
    // terribly interesting because we aren't auto-committing on the connection, so it just
    // updates the mutation state and returns.
    stmt.execute();
    stmt.setString(1, "key2");
    stmt.setLong(2, 2);
    stmt.execute();
    traceable.commit();
    // wait for the latch to countdown, as the metrics system is time-based
    LOG.debug("Waiting for latch to complete!");
    // should be way more than GC pauses
    latch.await(200, TimeUnit.SECONDS);
    // read the traces back out
    /* Expected:
         * 1. Single element trace - for first PreparedStatement#execute span
         * 2. Two element trace for second PreparedStatement#execute span
         *  a. execute call
         *  b. metadata lookup*
         * 3. Commit trace.
         *  a. Committing to tables
         *    i. Committing to single table
         *    ii. hbase batch write*
         *    i.I. span on server
         *    i.II. building index updates
         *    i.III. waiting for latch
         * where '*' is a generically named thread (e.g phoenix-1-thread-X)
         */
    boolean indexingCompleted = checkStoredTraces(conn, new TraceChecker() {

        @Override
        public boolean foundTrace(TraceHolder trace, SpanInfo span) {
            String traceInfo = trace.toString();
            // skip logging traces that are just traces about tracing
            if (traceInfo.contains(tracingTableName)) {
                return false;
            }
            return traceInfo.contains("Completing index");
        }
    });
    assertTrue("Never found indexing updates", indexingCompleted);
}