Documentation

Traces Subscription Protocol

When you configure your application to use the “Simple Tracing” level, you can subscribe with the tracing module to receive TraceInfo messages every time a trace is selected to be reported. To subscribe, simply use the Kamon.tracer.subscribe(...) method as shown in the example bellow:

Kamon.tracer.subscribe(subscriber)
Kamon.tracer().subscribe(subscriber);

As simple as that. Once you do this, your subscriber will be receiving TraceInfo messages every time a trace is sampled.

Please note that the simple traces subscriptions are very likely to change in future Kamon versions since we plan to enhance it's capabilities to allow for more detailed tracing as well as distributed tracing.

Creating a Simple Subscriber

The TraceInfo messages have a very simple structure, they have the basic attributes you would expect from a TraceContext: name, token, timestamp, elapsed time and a collection of SegmentInfo objects, which have their own name, category, library, timestamp and elapsed time attributes. With that in mind, let’s first create a trace with some segments on it and then a simple reporter that just dumps this information in the console.

Tracer.withNewContext("example-trace", autoFinish = true) {
    Tracer.currentContext.withNewSegment("quick-segment", "code", "kamon") {
      Thread.sleep(100)
    }

    Tracer.currentContext.withNewSegment("slow-segment", "code", "kamon") {
      Thread.sleep(3000)
    }
  }
Tracer.withNewContext("trace-with-segments", true, () -> {
      Tracer.currentContext().withNewSegment("quick-segment", "code", "kamon", () -> {
        try{ Thread.sleep(100); } catch (Exception e) { e.printStackTrace(); }
        return 0;
      });

      Tracer.currentContext().withNewSegment("slow-segment", "code", "kamon", () -> {
        try{ Thread.sleep(3000); } catch (Exception e) { e.printStackTrace(); }
        return 0;
      });

      return "done";
    });

The code above is simply creating a trace and then creating a couple segments that will have different durations; the first segment is named “quick-segment” and should have a elapsed time of around 100 milliseconds and the second segment is named “slow-segment” and should have a elapsed time of around 3 seconds.

Bellow we have the code for a subscriber actor that would just wait for TraceInfo messages and print them in the console with some formatting.

class TracePrinter extends Actor {
  def receive = {
    case traceInfo: TraceInfo =>

    println("#################################################");
    println("Trace Name: " + traceInfo.name)
    println("Timestamp: " + traceInfo.timestamp)
    println("Elapsed Time: " + traceInfo.elapsedTime)
    println("Segments: ");

    traceInfo.segments.foreach { segmentInfo =>
      println("    ------------------------------------------");
      println("    Name: " + segmentInfo.name)
      println("    Category: " + segmentInfo.category)
      println("    Library: " + segmentInfo.library)
      println("    Timestamp: " + segmentInfo.timestamp)
      println("    Elapsed Time: " + segmentInfo.elapsedTime)
    }
  }
}
public static class TracePrinter extends UntypedActor {

    @Override
    public void onReceive(Object message) throws Exception {
      if(message instanceof TraceInfo) {
        final TraceInfo traceInfo = (TraceInfo) message;
        final List<SegmentInfo> segments = seqAsJavaList(traceInfo.segments());

        System.out.println("#################################################");
        System.out.println("Trace Name: " + traceInfo.name());
        System.out.println("Timestamp: " + traceInfo.timestamp());
        System.out.println("Elapsed Time: " + traceInfo.elapsedTime());
        System.out.println("Segments: ");

        segments.forEach(segmentInfo -> {
          System.out.println("    ------------------------------------------");
          System.out.println("    Name: " + segmentInfo.name());
          System.out.println("    Category: " + segmentInfo.category());
          System.out.println("    Library: " + segmentInfo.library());
          System.out.println("    Timestamp: " + segmentInfo.timestamp());
          System.out.println("    Elapsed Time: " + segmentInfo.elapsedTime());
        });

      } else unhandled(message);
    }
  }

Once the trace is finished and reported, the generated output looks like this:

#################################################
Trace Name: example-trace
Timestamp: 1429311913406000000.nanos
Elapsed Time: 3103544112.nanos
Segments:
    ------------------------------------------
    Name: quick-segment
    Category: code
    Library: kamon
    Timestamp: 1429311913408589398.nanos
    Elapsed Time: 100184837.nanos
    ------------------------------------------
    Name: slow-segment
    Category: code
    Library: kamon
    Timestamp: 1429311913509367747.nanos
    Elapsed Time: 3000135844.nanos