My kingdom for a good timer!

Reach submillisecond timing precision in Java

January 10, 2003

Q: Is the resolution of System.currentTimeMillis() enough for profiling Java code?

A:

    public static void main (String [] args)
    {
        // JIT/hotspot warmup:
        for (int r = 0; r < 3000; ++ r) System.currentTimeMillis ();
        long time = System.currentTimeMillis (), time_prev = time;
        for (int i = 0; i < 5; ++ i)
        {
            // Busy wait until system time changes: 
            while (time == time_prev)
                time = System.currentTimeMillis ();
            System.out.println ("delta = " + (time - time_prev) + " ms");
            time_prev = time;
        }
    }

when run in JDK 1.4.1 on a Windows 2000 system, produces the following:

delta = 10 ms
delta = 10 ms
delta = 10 ms
delta = 10 ms
delta = 10 ms

You will discover that results vary based on your platform. Java developers on Linux enjoy 1-millisecond (ms) resolution, while Windows 98 users suffer with 50-ms resolution. In most cases, the actual resolution has nothing to do with the fact that System.currenTimeMillis()'s return value is current time in milliseconds.

Java developer forums are full of arguments about whether a particular language trick offers performance advantages, with developers presenting "proofs" based on System.currentTimeMilllis() returning "0 ms versus 10 ms" for some new way of implementing a particular code paradigm. You should see now that this is naive at best. On the system used above, System.currentTimeMilllis() is suitable only for profiling relatively long-lasting (100 ms and longer) operations. If you cannot loop over code being profiled a sufficient number of times to get the cumulative execution time in this range, you need another approach.

Occasionally, you can find alternative suggestions based on Object.wait(long) or Thread.sleep(long) methods. Unfortunately, these are not good alternatives either, as the following code demonstrates:

    public static void main (String [] args) throws Exception
    {
        final DecimalFormat format = new DecimalFormat ();
        format.setMinimumFractionDigits (3);
        format.setMaximumFractionDigits (3);
        // Create an ITimer using the Factory class:
        final ITimer timer = TimerFactory.newTimer ();
        
        // JIT/hotspot warmup:
        for (int i = 0; i < 3000; ++ i)
        {
            timer.start ();
            timer.stop ();
            timer.getDuration ();
            timer.reset ();
        }
        final Object lock = new Object (); // used by monitor.wait() below
        
        for (int i = 0; i < 5; ++ i)
        {
            timer.start ();
           
            // Uncomment various lines below to see the resolution
            // offered by other Java time-related methods:
            
            synchronized (lock) { lock.wait (1); }
            //Thread.currentThread ().sleep (1);
            //Thread.currentThread ().sleep (0, 500);
            //Thread.currentThread ().join (1);
            timer.stop ();
            System.out.println ("duration = "
                + format.format (timer.getDuration ()) + " ms");            
            timer.reset ();
        }
    }

On the same system used for the first experiment, this results in:

duration = 5.678 ms
duration = 7.313 ms
duration = 14.805 ms
duration = 15.078 ms
duration = 15.105 ms

(You might be wondering about the mysterious ITimer timer object above. I will explain this shortly. For now, realize that I, of course, could not use System.currenTimeMillis() to measure resolution of anything that might be better than that method.)

Clearly, using Object.wait(long) with inputs smaller than 10 ms does not work as expected. Repeating the same experiment with Thread.sleep(long) will show an improvement because Sun Microsystems' JVM implementation makes special provisions for this method so it can deliver 1-ms resolution. However, exploiting this fact is far from trivial: The best you can do is create a Thread that loops continuously on Thread.sleep(1) and increment a counter on each loop iteration, thus hopefully providing you with a better "clock" than System.currenTimeMillis(). But thread scheduling in Java lacks guarantees needed to make this a reliable solution (if the JVM suspends the clock thread for whatever reason, your clock stops).

In my search for better timers in Java, I also looked at Java Media Framework (JMF), specifically the javax.media.TimeBase class, thinking that a media framework would definitely provide better timing support. Alas, TimeBase relies on the same java.lang.System timer.

So, once again (see Java Q&A article "Profiling CPU Usage From Within a Java Application"), the best solution is to step outside Java and code a simple Java Native Interface (JNI) alternative. I only need an OS-specific implementation of a single JNI method:

    private static native double getTime ();

getTime() is supposed to return a (fractional) number of milliseconds elapsed since some indeterminate moment in the past. It does not have to be the system time because I will use only the differences between successive returned values. Unlike System.currentTimeMillis(), the return value is a floating-point type because using integral values here would force me to decide now, and for all possible future platforms, whether the units are microseconds, nanoseconds, etc., and thus limit maximum possible resolution.

On a modern Windows system, this method can be implemented natively using Win32 QueryPerformanceFrequency and QueryPerformanceCounter methods. QueryPerformanceCounter returns the number of CPU clock cycles since powerup, and, as you can imagine, updates at a very high frequency (reported by QueryPerformanceFrequency).

The rest of my simple timing library (see Resources) is pure Java. getTime() is utilized to implement a simple ITimer interface: you surround a code segment to be profiled with calls to start() and stop() and then query the resulting elapsed time using getDuration(). Note how the HRTimer class is instantiated—never directly, but through a TimerFactory.newTimer() Factory method. This method will fall back safely to a pure Java ITimer implementation in JavaSystemTimer if the native library is unavailable. Should this happen, you get bad timing resolution again, but at least your application code is not broken.

So, what is the resolution supplied by HRTimer? To get an estimate, I comment out everything between lines containing timer.start() and timer.stop() in the previous code example and run it again. This gives me a reading on time elapsed between those methods when they execute back to back. The results are outstanding:

duration = 0.004 ms
duration = 0.006 ms
duration = 0.005 ms
duration = 0.004 ms
duration = 0.004 ms

Even with added Java and JNI method dispatch overhead, you can count on sub-10 microsecond resolution on a good system. This is orders of magnitude better than any other profiling options I've tried. As mentioned in Resources (Java Tip 92), commercial analysis tools based on the Java Virtual Machine Profiler Interface (JVMPI) won't beat the directness and simplicity of my approach, since the relevant JVMPI profiling methods are based on the same low-resolution system timer calls and require additional analysis to extrapolate measured data correctly.

I hope you find this article and the implementation code (downloadable in Resources) useful in your own work. I have been using it for several years when profiling general-purpose Java code, Java Database Connectivity queries, Java file and socket input/output, HTTP and Remote Method Invocation method call overhead, and many other code segments not quite "slow enough" to work well with the default system timer and when the full machinery of commercial profiling tools is an overkill.

Vladimir Roubtsov has programmed in a variety of languages for more than 12 years, including Java since 1995. Currently, he develops enterprise software as a senior developer for Trilogy in Austin, Texas.

Learn more about this topic

Join the discussion
Be the first to comment on this article. Our Commenting Policies