Java Flight Recorder: profiling Kotlin and Java apps with fun

Introduction

The goal of this article is to examine the possibilities of profiling Kotlin and a similar Java application with JMC/JFR to get a better understanding of their behavior compared to each other.

Nowadays the IT world often spells  terms like Site Reliability Engineering - SRE [5] or latencies, but how to measure this in an accurate way without relying on “random” samples ?  The answer to this question is out of the scope, but we can show what possibilities there are for understanding the behaviour of an application based on simple examples. 

Starting slowly: what is the JVM? The JVM stands for Java Virtual Machine. The JVM enables a computer to run Java programs, but not just only them. JVM supports all languages that are able to be compiled into the Java byte-code. All good so far, but what is the JFR ?

The letters JFR stand for the Java Flight Recorder, which is an event-based toolset build directly into the JVM.

Exciting, isn't it ? The JFR can provide a view to the JVM internals through emitted events and more…

The purpose of the article is to compare a Kotlin and a Java app and touch “hidden” compiled code compositions.  

Let’s briefly introduce Koltin as Java is known a bit longer. I bet a couple of million articles have already been written about Java, so it’s fair to have a short Kotlin introduction. 

Kotlin belongs to the JVM language family. It was introduced in 2011 as a new language for JVM and has been developed by JetBrains company. 

The communicated goal was to become “better language” for the JVM. Kotlin has been successfully adopted by the Android community. In short, Kotlin is an object-oriented statistically typed language. It offers a set of quite handy features: data classes, concise, safety, smart casting, functional capabilities etc.  
Aside from the often spelled Kotlin "benefits",  it seems that nowadays more companies are thinking about or are already using a Kotlin stack for backend development. The reason for this may seem obvious but there are different perspectives. Such discussion may turn into the chicken-egg argumentation and it is out of the scope of this article. 

I have put the word "benefits" into the apostrophes intentionally as some nice concepts may look very neat in Kotlin but they may not be as optimized as Java’s counterpart (considering latest Java builds). The Java Ecosystem evolves pretty fast and Java stays the 1st JVM language and also the most optimized one. But nonetheless Kotlin has many nice constructs. Such constructs can help teams move faster without causing unwanted issues. An example of such an issue is the well known NPE  (Null Pointer Exception) .

Let’s profile  

The introduction is done. Let’s now compare the characteristics of a comparable Java & Kotlin apps using the JMC/JFR!

The setup goes first. For each measurement we use the current development state of the JMC/Java Flight Recorder - Early Access [1]. Each measurement is done in a 45 seconds time window. All examples  use OpenJDK 17 [4].

We consider the following 2 examples [2] to get some measurable data: 

• Hot-Methods
• Latencies

Each example uses similar JMC/JFR Events. Such events wrap equivalent sections of the application (Java/Kotlin) to obtain comparable results. The application Threads are also reduced in both cases in order to obtain comparable results. This means any detailed platform configuration is avoided as the goal is to compare basic platform configuration.  

1. Hot-Methods Example

The idea of this simple app is to have two “containers” held by the individual "worker". Those two containers each hold their own collection of numbers. The worker tries to find an intersection of those paired containers (see Img.1. in Kotlin, similar in Java)

Img.1.: example worker code - Kotlin

After running 1st not fixed code for 45 seconds we obtain for the Java app following results (see Img.2.)

Img.2.: Hot-Methods example: Java app - 431 400 events emitted

We repeat this process for the Kotlin version of the similar application for 45 seconds and obtain the following results (see, Img.3.)

Img.3.: Hot-Methods example: Kotlin app - 408 403 events emitted

Let's fix the code for both apps and observe the improvements in throughputs on both sides. We publish only the amount of JFR events that have been emitted. (Img.4.) as this is the identifier of the improvements that have been achieved.

Img.4.: Hot-Methods example Java, Kotlin comparison results

2. Latency Example

The second example is based on getting insights into latency that can be caused by many things. It could be unnecessary garbage collection, network issues or improper synchronization inside the application. In the current example we consider a problematic logger (Img.5.) that has a corrupted method log that is synchronized. It means it forces each tread to wait for it. 

Img.5.: Problematic Logger method

The Kotlin application uses the concept of Mutex (Kotlin Interface, coroutines library) to enforce synchronization. Let's take a look at the measurements. We try to answer the question of how many events can be emitted from the corrupted code in a 45 seconds time window (Img.6.: Java, Img.7.: Kotlin)

Img.6.: Java Problematic logger results, 222 JFR events

When we run the Kotlin application we receive almost identical results (Img.7)

Img.7.: Kotlin Problematic logger result, 222 JFR events

After the fixing a problematic logger we obtain the following results (Img.8.: Java, Img.9.: Kotlin). 

The results show that the blocking issue has been removed.

Img.8.: Java fixed logger, 957 JFR events

How is Kotlin app doing? 

Img.9.: Kotlin fixed logger, 808 JFR events

Conclusion

Watching the results we can observe that the results are almost very comparable. Important to note: the time window for the examples was just 45 seconds and the examples were more set up from a research perspective to highlight a specific issue.  We have seen the possibilities that are provided to us by the Java Platform in order to create our application better and understand the behavior in more detail. Mainly, by demonstrating the possibilities the Java Flight Recorder brought to us. We have also discovered, in a bit more details, a composition of the Kotlin itselves and coroutine framework (asynchronous and non-blocking lib)

 

Stay Tuned 

and Happy JVM coding !  

Stay Tuned 

and Happy JVM coding !

References:

1. Java Mission Control Project
2. JMC-JVM-Lang tutorial: profiling examples for different languages 
3. JMC-tutorial examples by Markus Hirt
4. OpenJDK 17
5. Site Reliability Engineering - SRE

Deep dive into distributed tracing with Spring Boot and Flight Recorder

Motivation
At Oracle CodeONE 2018 Marcus Hirt held very interesting presentation called "Diagnose Your Microservices: OpenTracing/Oracle Application Performance Monitoring Cloud [DEV5435]". This presentation gave an audience pretty intensive quick inside view to the large scale cloud application tracing.
Although his talk was not recorded, he has created pretty nice example, Robotshop, that he open-sourced.  You can find all information in his recently published blog posts (CLICK HERE). 
  His post also touched the Application Performance Management (APM) solutions that has been formed before OpenTracing standard has born.
  All intensive work crystallized into the previously mentioned OpenTracing standard, but what is it ?  As the web-site says It's a vendor-neutral APIs and instrumentation standard for distributed tracing (note: it's more about instrumentation). Companies like Datadog, Skywalking, Jaeger, LightStep are actively contributing into this standard, which is great news, it shows that the topic is pretty hot and we should probably think about it.
  Let's get back to my post topic. Many developers, world wide, are using spring-boot libraries stack to create a Spring based applications.

In this post you will learn how to connect some tracers (Jaeger, Zipkin) with your project. You will also learn how to connect Java Mission Control/Java Flight Recorder for very deep service analysis.

The post also stress the question how worthful it is to think about the application logging strategies. Why ? To be honest, who is reading couple of gigabytes big log files in order to spot the root case ;).  Who is writing continually very sophisticated regular expressions to get such information ?.

The source code is available on my GitHub account: [here] branch: [vehiclefactory-jfr-tracer]

Introduction
   In my previous post I've shown how to configure spring-boot project using opentracing [CLICK_HERE]. It was just  a simple producer consumer pattern based demo. In the following text we create a VehicleShop project with 4 independent micro-services : VehicleShopService, FactoryService, StorageService, CustomerService. All those services are spring-boot based ones.
The example project uses the Gradle build system. It does contain all services and you can start each of them separately, in docker or you can configure the docker-compose file.

  The monitoring is about to "extracting meaningful stories" from the defined Metrics (four golden signals, RED method etc.) or Logs (app events, stack-traces etc.), in other hand tracing is more about Spans, Spans analysis. Tracking gives the answer to individual request.
  What is such Span ? The Span is the primary building block of distributed trace. Such individual Span represents the work done within the distributed system. How we define such Span ?
By the opentracing standard Span has following properties:

• an operation name
• start and finish timestamp
• key:value Span Tag
• a SpanContext 
• carries date across the process boundaries

Having defined Span we define the space from where such Span is coming from. Let's consider one individual Span,  we name it "Active Span". Such Span is responsible for the work accomplished by the surrounding code. Active Span has actually one very important property:

• it can be only one Active Span inside the thread at time T.

Such property is managed by the Scope, which formalizes the activation and deactivation of a Span. 

OpenTracing standard defines the term Trace. Trace represents the interface which implementation creates the Spans.

The VehicleShop example 

Previously has been mentioned that VehicleShop project is the collection of micro-services. Those services are exchanging information between each other according to the schema (Img.1.)

Img.1.: VehicleShop project schema

The Customer service represents the set of the schedulers. Those schedulers generate a traffic that simulates the multiple customers behaviour like buying , searching or upgrading the car. The VehicleShop service sends requests to the vehicle elements storage (StorageService) in order to get information about available pieces. The VehicleShop sends requests to the FactoryService to check which cars are available to sell out.  The FactoryService before any car gets produces send the request to the StorageService whether the VehicleElement, necessary to build the car, are available (Img.2.)

Img.2.: example communication diagram

All services have enabled opentracing support by the following libraries:
opentracing-spring-jaeger-cloud-starter
opentracing-spring-zipkin-cloud-starter

when you add any of those libraries into the project class-path they will automatically configure the default tracer settings. You simple can start the tracer inside the docker container:
$docker run -d -p 6831:6831/udp -p 16686:16686 jaegertracing/all-in-one:latest
$docker run -d -p 9411:9411 openzipkin/zipkin:latest

Of course you can use the custom configuration of the tracer, but in such case you need properly re-configure spring @Configuration beans. The another alternative is to use the environment variables.
When the all services are up, you can open the Jaeger UI : http://localhost:16686/ (Img.3.)

Img.3.: JagerUI : VehicleShopService traces

The interface allows to analyze taken spans and observe a real application communication over the micro-services (Img.4.)

Img.4.: Tracing a specific request 

The Jaeger UI offers one very neat feature. It's ability to compare two spans by IDs. The span Id you can get from available traces (Img.5.)

Img.5.: Span comparison

As you can see the example architecture is very simple but it already shows the value of the tracing.

  Let's connect the example with Java Mission Control / Flight Recorder and see the traces from different perspectives.
  As the tracing provides you the ability to get the view into the application communication layer and here recognizing some potential issues, when the JFR is attached to the micro-service JVMs, you can directly analysize the potentially suspicious code.  It means that the trace may be very good initial signal to start the investigation.

Attaching Flight Recorder to the VehicleShop example
Marcus has recently published very neat library java-jfr-tracer . This library allows to record Scopes and Spans into the JDK Flight Recorder for very deep analysis.  To enable such feature it necessary to add following library into the project.

gradle.build:
implementation "se.hirt.jmc:jfr-tracer:0.0.3"

After having the library we need to register a new JFR Tracer, which is the wrap of the OpenTracing tracer, in following way:

@Autowired
public CustomTracerConfig(Tracer tracer) {
     GlobalTracer.register(new DelegatingJfrTracer(tracer));
}

Now information provided by tracers will be available also through the Flight Recorder interface through recorder Events (Img.6.)

Img.6.: Flight Recorder with recorded spans

The Flight Recorder gives you a chance to recognize a suspicious trace ids which may bring the significant value during the issue solving. The Spring framework is not just a one thread framework and using it may bring/open potential challenges (Img.7.)

Img.7.: VehicleShop threads view

Summary
Distributed Tracing is great and challenging.  As you can see from the image (Img.7.) there are bunch of threads and by adding new libraries to the project a new are coming. Distributed tracing is opening the way how to understand to what is really happening across the micro-services.
It means distributed tracing allows/supports:

• distributed transaction monitoring
• performance and latency optimization 
• root cause analysis
• service dependencies analysis
• distributed context propagation

The only OpenTracing standard implementation may not be enough. Often you may need to know what is happening inside the specific one and the trace may forward you directly to the issue.

Using Flight Recorder for Distributed Tracing is like using "weapon" from different galaxy, it's not the silver bullet but it may be very close to it .

Enjoy the Demo and happy tracing!

How to use Java Mission Control from the source

This blog post is intended to guide everyone who wants to try Java Mission Control and Java Flight Recorder build from the source code.  Although the one of the best  information source is Marcus's blog, very updated, I want to start mine to summarize or remember some parts, it maybe useful :)
  So let's start with quick overview. Maybe you have already heard about Java Mission Control or Flight Recorder before, for those who not Java Mission Control (JMC) is a tool suit for managing, monitoring, profiling and troubleshooting java application. The JMC consists from JMX Console and Java Flight Recorder (JFR). JMC as a tool creates a complete tool chain to collect low level and detailed information not only about Java runtime. The JFR is a tool used for collecting data at the runtime, it has very small overhead as Marcus said during one of the conference talks: "It has been designed since the very beginning for the production time JVM profiling". Already from such sentence you may feel the power of the tool.
  After an Oracle announcement to OpenSource JMC technology last year many people get excited. Currently JMC has still not been released, but it's planed on January 30 2019 (JFR has been released with OpenJDK 11)
 Before this date you can download and try Early Access Builds (here, JMC - Now serving OpenJDK binaries):


http://jdk.java.net/jmc/


If you are fine to build your own JMC build that includes all latest updates,  you are free to go.  In such case you will need to get Mercurial, on Mac OS (mode details here):


$brew install mercurial


Next step is to clone the repository:


$hg clone http://hg.openjdk.java.net/jmc/jmc/


important : Now you will need to open two terminals where in the first one is reserved for exposing p2 repo to your localhost.  


$cd releng/third-party
$mvn p2:site
$mvn jetty:run

Inside the second terminal you need to build and populate the jmc core first

$cd core
$mvn clean install

after the successful install you go back to the jmc folder 

$cd .. 
$mvn package

Having build JMC successfully done you can now run your local build. On Mac Os:

$target/products/org.openjdk.jmc/macosx/cocoa/x86_64/JDK\ Mission\ Control.app/Contents/MacOS/jmc -vm $JAVA_HOME/bin


Final though
  Although you can still enjoy already published binaries the JMC team is still working on improvements before the final release. It is quite handy to pull those changes and build the latest JMC version from the branch


$hg pull


When you are building JMC don't forget to have your local p2 repo running (third-party). It is described in the part marked as important. 
Enjoy JMC !