Featured White Papers

• Measuring Risk to Improve Java Software Quality
• Do You Really Get Classloaders?
• Pragmatic Continuous Delivery with Jenkins, Nexus, and LiveRebel
• Your Next Java Web App: Less XML, No Long Restarts, Fewer Hassles
• Coding with JRebel, Java Forever Changed
• 2012 Developer Productivity Report: Java Tools, Tech, Devs, and Data

Sponsored Links

• Graph databases are 1000x faster than relational.

  Learn More!

• Career opportunities at Harman- Careers That'll Rock Your Socks Off.

  Learn More!

• Developer-friendly Java PDF libraries by Qoppa Software

  Live Demos

• Stop blaming your app! Diagnose Java performance issues.

  Free tool >

• UrbanCode: Go From Continuous Integration to
  Continuous Delivery

  Learn More!

Sponsored Links

Optimize with a SATA RAID Storage Solution
Range of capacities as low as $1250 per TB. Ideal if you currently rely on servers/disks/JBODs

My kingdom for a good timer!

Reach submillisecond timing precision in Java

By Vladimir Roubtsov, JavaWorld.com, 01/10/03

January 10, 2003

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

Evaluating the actual resolution is easy enough. The following code snippet,

    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: