Daniel Mitterdorfer

Simplicity
Written on February 06, 2017 by Daniel Mitterdorfer

I admit it: I use noscript, I block trackers like Google Analytics and all sorts of ads. If you browse the web this way, you see strange things: in the best case layouts are completely broken but in some cases pages even do not show up. And no, I am not talking about interactive pages like Google Maps. I am talking about pages that are content heavy. To me these people are just downright sloppy.

As a counter-statement I have eliminated most waste on my own page now ("the one who is without sin is the one who should cast the first stone"). From today on, this page does NOT use:

What is left? The essentials: HTML, CSS and images. There are some old presentations that I made with reveal.js but the rest of this page will not see Javascript any time soon.

There goes my low latency: Analyzing hiccups with jHiccup, Elasticsearch and Kibana
Written on April 18, 2016 by Daniel Mitterdorfer

Who crosses the finish line first?

Image by USMC Archives ; license: CC

The other day I had to analyze search latency spikes in Elasticsearch for a customer. When latency spikes are involved, one of the first things I want to know is the "noiseness" of the host where the problem occurs.

A great tool that helps with this analysis is Gil Tene's jHiccup. It records hiccups in the application and also in a control process. One thing that bugged me about jHiccup for a long time is that you need to Microsoft Excel to visualize the data. However, I don't own an MS Office license and as much as I like jHiccup, I won't buy a license just for that.

So I thought about alternatives. At Elastic, we store our benchmark results also in Elasticsearch and visualize the data in Kibana. As I wanted to analyze multiple data sources anyway, it made sense to import the data into Elasticsearch. jHiccup comes with a tool, called jHiccupLogProcessor that can convert jHiccup files to CSV. After a few unsatisfying experiences with a few CSV to JSON converters, I hacked together a small Python script that can convert just jHiccup's CSV file format to Elasticsearch bulk requests and imported the file with curl.

This approach worked but is also cumbersome. Apart from that I figured other people might benefit from an import tool to Elasticsearch too. So I spiced up the script a little bit and the result is hiccup2es. Although it is really basic, it is a start and allows you to import data into Elasticsearch in one step. It even creates the index for you.

It is quite easy to use (I hope). Suppose you have a CSV jHiccup log called "hiccuplog.csv" that has been created by jHiccupLogProcessor. Then you can import the data into your local Elasticsearch cluster in one step:

python3 hiccup2es.py --input-file=hiccuplog.csv --create-index

That's it! hiccup2es assumes a lot of defaults, so if you want to know what you can configure, run hiccup2es --help to find out.

After the data are imported, you can easily create a nice looking visualization in Kibana. Here is a hiccup log during a benchmark I ran on my local machine:

I hope you find hiccup2es as useful as I do. If you want to know more, just contact me on Twitter. If you find a problem or can think of any enhancement, just raise an issue on Github.

Hidden Gems in the JVM: jcmd
Written on May 27, 2015 by Daniel Mitterdorfer

jcmd is one of those neat tools that only a few people seem to know about. It is a command line tool that is shipped with each Oracle JDK installation and provides basic information about a running Java process, which is practical for unobtrusively inspecting a running production instance.

How to Use jcmd

To use jcmd we need to specify the process id of a running Java process. When jcmd is invoked without any arguments, it prints a list of all running Java processes:

daniel@thebe:~ $ jcmd
10322 name.mitterdorfer.demos.jcmd.Main
10307 org.gradle.launcher.GradleMain run
10325 sun.tools.jcmd.JCmd

Next, we can list the available commands for a process by issuing jcmd <<PID>> help:

daniel@thebe:~ $ jcmd 10322 help
10322:
The following commands are available:
JFR.stop
JFR.start
JFR.dump
JFR.check
VM.native_memory
VM.check_commercial_features
VM.unlock_commercial_features
ManagementAgent.stop
ManagementAgent.start_local
ManagementAgent.start
Thread.print
GC.class_stats
GC.class_histogram
GC.heap_dump
GC.run_finalization
GC.run
VM.uptime
VM.flags
VM.system_properties
VM.command_line
VM.version
help

For more information about a specific command use 'help <command>'.

The supported options vary from process to process (e.g. due to VM options). For this example, there are four categories of commands:

There is also one option that is not listed here, called "PerfCounter.print". It prints JVM-internal performance counters which contain lots of details on the behavior of components like the classloader, the JIT, the GC and a few others. To get started, the commands listed above should do but if you are really curios just try it.

A Practical Example

Suppose an application takes ages to start on a production system although it worked fine in development. To determine what's going on, we can take a thread dump:

daniel@thebe:~ $ jcmd 10378 Thread.print
10378:
2015-04-20 11:21:04
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.0-b70 mixed mode):

"Attach Listener" #10 daemon prio=9 os_prio=31 tid=0x00007fa7ef008000 nid=0x5b03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

[...]

"main" #1 prio=5 os_prio=31 tid=0x00007fa7ee800000 nid=0x1903 waiting on condition [0x0000000102dbf000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at name.mitterdorfer.demos.jcmd.Main.main(Main.java:8)

"VM Thread" os_prio=31 tid=0x00007fa7ec857800 nid=0x3503 runnable 

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007fa7ee80d000 nid=0x2503 runnable 

[...]

"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007fa7ec80b800 nid=0x3303 runnable 

"VM Periodic Task Thread" os_prio=31 tid=0x00007fa7ed801800 nid=0x5903 waiting on condition 

JNI global references: 7

Can you see what's going on? The main thread is in TIMED_WAITING state which means it is sleeping. Although this is not a very realistic example, such a thread dump once helped me find a weird startup issue in production: The logging framework of an application was misconfigured to log everything on DEBUG level but without specifying one of our application's file appenders. Therefore, no log statement ever reached the application's log files but it seemed that the application was not doing anything for minutes. I took a few thread dumps which revealed the problem quickly: Most thread dumps revealed that a debug statement was issued deep in library code. We corrected the log configuration and the application started smoothly again.

Summary

jcmd supports basic inspections in limited environments such as a production machine. Sure, there are more sophisticated tools like jconsole, Java Mission Control or third-party tools like AppDynamics. However, for a quick glimpse jcmd is quite handy as it comes with every JDK installation and requires no graphical interface.

  1. Disclaimer: I am not a lawyer. Please read the license terms of Java SE yourself.↩

Handling InterruptedException Properly
Written on January 20, 2015 by Daniel Mitterdorfer

Stop

Image by Juan Antonio Capó Alonso; license: CC

InterruptedException is among the most misunderstood exceptions in the JDK. How often did we come across exception handlers like this one:

public void enqueue(Object value) {
  try {
    queue.put(value);
  } catch (InterruptedException e) {
    // ignore
  }
}

Or even:

public void enqueue(Object value) {
  try {
    queue.put(value);
  } catch (InterruptedException e) {
    throw new RuntimeException(e);
  }
}

In most cases, these handler implementations are wrong.

Stopping a Thread in Java

To understand why these exception handlers are wrong, we have to know the purpose of this exception. As its name indicates, some method has been interrupted during execution. In Java, cancellation of a running thread is cooperative. That means that we cannot force a thread to terminate from the outside 1 but instead we can just request that it interrupts itself and rely that the code executed within a thread will notice the request and act accordingly. To achieve that, each thread manages a flag, the interruption status. It can be set with Thread#interrupt() and reset with Thread#interrupted(). Additionally, Thread#isInterrupted() is used to check the interruption status.

Let's suppose a user wants to cancel a background operation running in a dedicated thread. To do so, client code calls interrupt() on this thread. Assuming that the background operation is in progress, i.e. it has been started but it has not yet finished, the thread can be in one of those states:2

If the thread is in RUNNABLE state, it is rather simple to respond properly to interruption. We can periodically check the status of the interrupted flag with Thread#isInterrupted():

class ComplicatedCalculator implements Runnable {
  @Override
  public void run() {
    while (!Thread.currentThread.isInterrupted()) {
      // calculate something here
    }
  }
}

ComplicatedCalculator periodically checks the interruption status of the thread it is currently running in by calling Thread.currentThread.isInterrupted(). This ensures that the corresponding thread can terminate timely upon a request to interrupt itself.

However, what shall we do if the code is not in the state RUNNABLE, i.e. in one of the states BLOCKED, WAITING or TIMED_WAITING? Consider this simulation that recalculates its state roughly every second. There is InterruptedException again:

class Simulation implements Runnable {
  @Override
  public void run() {
    while (!Thread.currentThread.isInterrupted()) {
      // ... simulation calculations here ...
      try {
        Thread.sleep(1000);
      } catch (InterruptedException e) {
        // empty
      }
    }
  }
}

To understand what's wrong here, consider you are the implementor of Thread#sleep(). How should you indicate that the method did not return normally but has been interrupted? You could use a special return code, but this is brittle because it places the burden of checking the return value on the caller. Instead, Thread#sleep() resets the thread's interrupt status and throws InterruptedException. This means, whenever InterruptedException is thrown, some part of the system requested to terminate the current thread while it was not in RUNNABLE state, and we should get out of the way as quickly as possible.

In general, there are multiple strategies on how to handle InterruptedException:

There are cases which justify other strategies, but for the majority of situations, these three strategies work fine.

Canonical Solution

To conclude the simulation example, support for interruption can be implemented using the "catch, restore and terminate" strategy as follows:

class Simulation implements Runnable {
  @Override
  public void run() {
    while (!Thread.currentThread.isInterrupted()) {
      // ... simulation calculations here ...
      try {
        Thread.sleep(1000);
      } catch (InterruptedException e) {
        // restore interruption status of the corresponding thread
        Thread.currentThread.interrupt();
      }
    }
  }
}

The run loop will terminate quickly when the corresponding thread is interrupted either in Thread#sleep() or immediately after calculation hence guaranteeing timely termination of the corresponding thread. By the way: If the simulation would have contained just an empty catch block, it is almost impossible to ever interrupt it. As Thread#sleep() will reset the interruption status flag when it throws InterruptedException, the check at the beginning of the loop will hardly ever have a chance to observe that the interruption status flag is set.

Cancellation in Thread Pools

Java 5 has brought us ExecutorService, which means that client code does not have a Thread reference to call interrupt() on it. Instead, ExcecutorService#submit(Runnable) returns a Future. To request interruption, just invoke Future#cancel(true). Here's a minimalistic example:

Simulation simulation = new Simulation();
ExecutorService e = Executors.newFixedThreadPool(4);
Future<?> f = e.submit(simulation);
// ...
// now cancel the running simulation
f.cancel(true);

This is not the only situation where interruption occurs in a thread pool: ExecutorService#shutdownNow() will terminate all running tasks by calling Thread#interrupt() internally on pool threads. So proper handling of InterruptedException is also important to shutdown a thread pool properly.

  1. There was a misguided effort in the early days of Java with Thread#stop(). An Oracle technote describes its problems more deeply.↩

  2. Actually, the Java thread state model defines some more states, but we don’t bother about it for this article.↩

Microbenchmarking in Java with JMH: Digging Deeper
Written on August 20, 2014 by Daniel Mitterdorfer

This is the fifth and last post in a series about microbenchmarking on the JVM with the Java Microbenchmarking Harness (JMH).

part 1: Microbenchmarking in Java with JMH: An Introduction

part 2: Microbenchmarks and their environment

part 3: Common Flaws of Handwritten Benchmarks

part 4: Hello JMH

In the previous post, I have introduced JMH with a Hello World benchmark. Now, let's dig a bit deeper to find out more about the capabilities of JMH.

A Date Format Benchmark

In this blog post, we'll implement a microbenchmark that compares the multithreaded performance of different date formatting approaches in Java. In this microbenchmark, we can exercise more features of JMH than just in a Hello World example. There are three contenders:

  1. JDK SimpleDateFormat wrapped in a synchronized block: As SimpleDateFormat is not thread-safe, we have to guard access to it using a synchronized block.
  2. Thread-confined JDK SimpleDateFormat: One alternative to a global lock is to use one instance per thread. We'd expect this alternative to scale much better than the first alternative, as there is no contention.
  3. FastDateFormat from Apache Commons Lang: This class is a drop-in replacement for SimpleDateFormat (see also its Javadoc)

To measure how these three implementations behave when formatting a date in a multithreaded environment, they will be tested with one, two, four and eight benchmark threads. The key metric that should be reported is the time that is needed per invocation of the format method.

Phew, that's quite a bit to chew on. So let's tackle the challenge step by step.

Choosing the Metric

Let's start with the metric that we want to determine. JMH defines the output metric in the enum Mode. As the Javadoc of Mode is already quite detailed, I won't duplicate the information here. After we've looked at the options, we choose Mode.AverageTime as benchmark mode. We can specify the benchmark mode on the benchmark class using @BenchmarkMode(Mode.AverageTime). Additionally, we want the output time unit to be µs.

import org.openjdk.jmh.annotations.*;

import java.util.concurrent.TimeUnit;

@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
public class DateFormatMicroBenchmark {
  // more code to come...
}

When the microbenchmark is run, results will be reported as µs/op, i.e. how many µs one invocation of the benchmark method took. Let's move on.

Defining Microbenchmark Candidates

Next, we need to define the three microbenchmark candidates. We need to keep the three implementations around during a benchmark run. That's what @State is for in JMH. We also define the scope here; in our case either Scope.Benchmark, i.e. one instance for the whole benchmark and Scope.Thread, i.e. one instance per benchmark thread. The benchmark class now looks as follows:

import org.apache.commons.lang3.time.FastDateFormat;
import org.openjdk.jmh.annotations.*;

import java.text.DateFormat;
import java.text.Format;
import java.util.Date;
import java.util.concurrent.TimeUnit;

@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
public class DateFormatMicroBenchmark {
    // This is the date that will be formatted in the benchmark methods
    @State(Scope.Benchmark)
    public static class DateToFormat {
        final Date date = new Date();
    }

    // These are the three benchmark candidates

    @State(Scope.Thread)
    public static class JdkDateFormatHolder {
        final Format format = DateFormat.getDateInstance(DateFormat.MEDIUM);

        public String format(Date d) {
            return format.format(d);
        }
    }

    @State(Scope.Benchmark)
    public static class SyncJdkDateFormatHolder {
        final Format format = DateFormat.getDateInstance(DateFormat.MEDIUM);

        public synchronized String format(Date d) {
            return format.format(d);
        }
    }
    
    @State(Scope.Benchmark)
    public static class CommonsDateFormatHolder {
        final Format format = FastDateFormat.getDateInstance(FastDateFormat.MEDIUM);

        public String format(Date d) {
            return format.format(d);
        }
    }
}

We defined holder classes for each Format implementation. That's needed, as we need a place to put the @State annotation. Later on, we can have JMH inject instances of these classes to benchmark methods. Additionally, JMH will ensure that instances have a proper scope. Note that SyncJdkDateFormatHolder achieves thread-safety by defining #format() as synchronized. Now we're almost there; only the actual benchmark code is missing.

Multithreaded Benchmarking

The actual benchmark code is dead-simple. Here is one example:

@Benchmark
public String measureJdkFormat_1(JdkDateFormatHolder df, DateToFormat date) {
    return df.format(date.date);
}

Two things are noteworthy: First, JMH figures out that we need an instance of JdkDateFormatHolder and DateToFormat and injects a properly scoped instance. Second, the method needs to return the result in order to avoid dead-code elimination.

As we did not specify anything, the method will run single-threaded. So let's add the last missing piece:

@Benchmark
@Threads(2)
public String measureJdkFormat_2(JdkDateFormatHolder df, DateToFormat date) {
    return df.format(date.date);
}

With @Threads we can specify the number of benchmark threads. The actual benchmark code contains methods for each microbenchmark candidate for one, two, four and eight threads. It's not particularly interesting to copy the whole benchmark code here, so just have a look at Github.

Running the Benchmark

This benchmark is included in benchmarking-experiments on Github. Just follow the installation instructions, and then issue java -jar build/libs/benchmarking-experiments-0.1.0-all.jar "name.mitterdorfer.benchmark.jmh.DateFormat.*".

Results

I've run the benchmark on my machine with an Intel Core i7-2635QM with 4 physical cores and Hyperthreading enabled. The results can be found below:

Results of the DateFormatMicroBenchmark

Unsurprisingly, the synchronized version of SimpleDateFormat does not scale very well, whereas the thread-confined version and FastDateFormat are much better.

There's (Much) More

DateFormatMicroBenchmark is a more realistic use case of a microbenchmark than what we have seen before in this article series. As you have seen in this example, JMH has a lot to offer: Support for different scopes for state, multithreaded benchmarking and customization of reported metrics.

Apart from these features, JMH provides a lot more such as support for asymmetric microbenchmarks (think readers and writers), control on the behavior of the benchmark (How many VM forks are created? Which output formats should be used for reporting? How many warm-up iterations should be run?), etc. etc.. It also supports arcane features such as the possibility to control the certain aspects of compiler behavior with the @CompilerControl annotation, a Control class that allows to get information about state transitions in microbenchmarks, support for profilers and many more. Just have a look at the examples yourself, or look for usages of JMH in the wild, such as JCTools microbenchmarks from Nitsan Wakart, the benchmark suite of the Reactor project or Chris Vest's XorShift microbenchmark.

Alternatives

There are also some alternatives to JMH, but for me none of them is currently as compelling as JMH:

Final Thoughts

Although writing correct microbenchmarks on the JVM is really hard, JMH helps to avoid many issues. It is written by experts on the OpenJDK team and solves issues you might not even knew you may have had in a handwritten benchmark, e.g. false sharing. JMH makes it much easier to write correct microbenchmarks without requiring an intimate knowledge of the JVM at the level of an engineer on the HotSpot team. JMH's benefits are so compelling that you should never consider rolling your own handwritten microbenchmarks.

Questions or comments?

Just ping me on Twitter