Bring Java’s System.currentTimeMillis() Back into the Fold for Transaction Monitoring

any developers who work on high-volume transactional software (such as real-time financial or accounting systems) are skeptical of using Java’s System.currentTimeMillis() method for capturing transaction times. You’ll often hear the suggestion to avoid it due to fear that it will introduce unwanted delay in transaction response time, especially in multi-threaded applications. But don’t swallow this advice whole. Although currentTimeMillis can have poor resolution, it generally has great performance.

There are a few things to note about the currentTimeMillis method:

  • It is native
  • Its resolution (or granularity) depends on the underlying OS
  • It generally has a very fast response time
  • The method signature is not synchronized but the implementation usually is

The method signature for currentTimeMillis is defined as native. A native method is one that makes a direct call to the operating system through the Java Native Interface (JNI). Because the implementation of a native method can vary, the performance behavior may vary on different operating systems.


You’re using JDK 1.4 and want to use System.currentTimeMillis() to capture transaction times for a high-volume transactional system, but you’ve heard that this method causes performance problems. What should you do?


In most cases, you can rest assured that you won’t be affected. The advice to avoid System.currentTimeMillis() is generally misinformed. This solution will show you why.

Comon Misconceptions
The resolution or granularity of a clock is the smallest time difference that can be measured between two consecutive calls. For example, on many Microsoft Windows systems, the resolution of the call to currentTimeMillis is 10 ms. This is because the native implementation makes an operating-system call that has a resolution of 10 ms. Most other operating systems claim to have a resolution of 1 ms.

A common misconception is that if the resolution is 10 ms, a call to currentTimeMillis will take 10 ms to return. This is not true; the response time and the resolution of a method are unrelated.

Listing 1 will help clarify. This code calls currentTimeMillis 500,000 times, printing the return value of the call only if it differs from the last result stored in a variable.

I ran this code on a machine with the following stats:

  • AMD Athlon XP 2000+
  • 1.66 GHz Processor
  • 512 MB of RAM

  • Microsoft Windows XP Professional
  • JVM version 1.4.1_02

When I ran this code, I got the following output:

11198442806031119844280613111984428062311198442806331119844280643111984428065311198442806731119844280683This test took approximately: 80 msThe throughput is approximately: 6250000.0 calls / sEach call took approximately: 1.6E-7 s

The printed values are unique values of the currentTimeMillis calls. The first thing to notice is that each printed time is 10 ms apart. This is the resolution of the call on the system that I ran. The next thing to notice is that 500,000 calls to currentTimeMillis only took approximately 80 ms. I say approximately because the elapsed time was measured using currentTimeMillis, so because of the 10 ms resolution, the actual time could have been anywhere between 80 – 90 ms.

If I assume that the 500,000 calls took 80 ms, I can estimate the throughput of currentTimeMillis to be approximately 6.25 million calls per second:

500,000 calls / 80 ms = 6,250 calls / ms
6,250 calls / ms * 1,000 ms / s = 6,250,000 calls / s

I can also assume that the response time for each call took approximately 1.6 x 10-7 seconds:

80 ms / 500,000 calls = 0.00016 ms / call
(0.00016 ms / call) / (1000 ms / s) = 0.00000016 s / call

This data alone should quell most worries about the performance of currentTimeMillis. But I want to take a closer look at what happens when you call the method using multiple threads.

Multi-threaded Tests
Though the method signature for currentTimeMillis is not defined as synchronized, the underlying operating-system call that a native implementation makes is usually synchronized. This is what usually worries developers. What happens if you are running multiple threads that are trying to make simultaneous calls to currentTimeMillis? If a resource is synchronized, and multiple threads try to access it, you run the risk of encountering contention. Contention is the blocking that occurs when multiple threads contend for a resource that cannot be accessed concurrently?a synchronized resource.

Listing 2 is a more complex test that creates multiple threads that simultaneously call currentTimeMillis. This code runs several tests that range from 1 to 200 threads and make 10 to 10,000,000 calls to currentTimeMillis (incrementing by multiples of 10). For each test, the number of calls is divided among the threads. Each test is run four times and the average of the four tests is printed to the screen. Here is some sample output:

1 Threads:1 Calls/Thread - Time: 0 ms10 Calls/Thread - Time: 0 ms100 Calls/Thread - Time: 0 ms1000 Calls/Thread - Time: 0 ms10000 Calls/Thread - Time: 0 ms100000 Calls/Thread - Time: 15 ms1000000 Calls/Thread - Time: 130 ms10000000 Calls/Thread - Time: 1264 ms-----2 Threads:0 Calls/Thread - Time: 2 ms5 Calls/Thread - Time: 0 ms50 Calls/Thread - Time: 0 ms500 Calls/Thread - Time: 0 ms5000 Calls/Thread - Time: 2 ms50000 Calls/Thread - Time: 17 ms500000 Calls/Thread - Time: 125 ms5000000 Calls/Thread - Time: 1256 ms 

In this test, approximately the same number of calls are made to currentTimeMillis, but those calls are divided over multiple threads as the number of threads increases. Figure 1 shows how long it takes to make 10,000,000 calls to currentTimeMillis as I increase the number of threads.

Figure 1. Time to 10 Million: The chart shows the time to execute 10 million calls to System.currentTimeMillis(). The data on which this chart is based is available in the download that accompanies this article (see left column).

Figure 1 demonstrates that it’s impossible to determine the response time of the currentTimeMillis method using a single thread. A single thread takes 1249 ms to execute 10,000,000 calls, but 200 threads (making 50,000 calls each) take 37 ms to execute 10,000,000 calls. The graph approaches 31 ms as the number of threads increases. This is the approximate limit of the currentTimeMillis method. Thus, I can calculate:

Throughput = 322,580,645 calls / secondResponse time = 3.1 x 10-9 seconds / call

So, you can see that even though currentTimeMillis‘s resolution is poor, calls to the method are very fast, even when you are running a large number of threads. Most software applications that process transactions are not capable of handling anywhere near this many transactions each second.

In general, there is little need to worry about how currentTimeMillis will affect your performance. If you are using currentTimeMillis to profile an application, the poor resolution on some operating systems may cause some concern with precision. If profiling is your concern, there are other ways to get sub-millisecond timing precision. This article by Vladimir Roubtsov shows you how to write you own native method to accomplish this on Windows.

If you are using JDK 1.5.0, then you’re in luck. Not only can you get better resolution by using the System.nanoTime() method, but you can also get even better performance. The specification does not guarantee a certain resolution, but after running tests on a few different systems, I’ve discovered that I can generally get better resolution and performance.

Share the Post:
Share on facebook
Share on twitter
Share on linkedin

Overview

Recent Articles: