Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Best approach for dealing with time measures? [duplicate]

My goal is to write a framework for measuring method execution or transaction time and for processing the measurements, i.e. storing, analysis etc. Transaction may include calls to external systems, with synchronously or asynchronously waiting for the results.

There already have been some questions around that topic, like

  • "How do I time a method's execution"
  • "Measure execution time for a Java method"
  • "System.currentTimeMillis vs System.nanoTime"

And all the answers boil down to three approaches for taking the time

  • System.currentTimeMillis()
  • System.nanoTime()
  • Instant.now() and Duration(since Java 8)

I know, all of these have some implications

System.currentTimeMillis()

The result of this method depends on the platform. On Linux you get 1ms resolution, of Windows you get 10ms (single core) ~15ms (multi core). So it's ok for measuring large running operations or multiple executions of short running ops.

System.nanoTime()

You get a high resolution time measure, with nano second precision (but not necessarily nano second accuracy) and you get an overflow after 292 years (I could live with that).

Instant.now() and Duration

Since Java 8 there is the new time API. An instant has a second and a nano second field, so it uses on top of the Object reference two long values (same for Duration). You also get nano second precision, depending on the underlying clock (see "Java 8 Instant.now() with nanosecond resolution?"). The instantiaion is done by invoking Instant.now() which maps down to System.currentTimeMillis() for the normal System clock.

Given the facts, it becomes apparent, that best precision is only achievable with System.nanoTime(), but my question targets more towards a best-practice for dealing with the measures in general, which not only includes the measure taking but also the measure handling.

  • Instant and Duration provide best API support (calculating, comparing, etc) but have os-dependend precision in standard case, and more overhead for memory and creating a measure (Object construction, deeper callstack)

  • System.nanoTime() and System.currentTimeMillis() have different levels of precision but only have basic "api" support (math operations on long), but are faster to get and smaller to keep in memory.

So what would be the best approach? Are there any implications I didn't think of? Are there any alternatives?

like image 804
Gerald Mücke Avatar asked May 06 '16 08:05

Gerald Mücke


2 Answers

You are focusing too much on the unimportant detail of the precision. If you want to measure/profile the execution of certain operations, you have to make sure that these operation run long enough to make the measurement unaffected by one-time artifacts, small differences in thread scheduling timing, garbage collection or HotSpot optimization. In most cases, if the differences become smaller than the millisecond scale, they are not useful to draw conclusions from them.

The more important aspect is whether the tools are designed for your task. System.currentTimeMillis() and all other wall-clock based APIs, whether they are based on currentTimeMillis() or not, are designed to give you a clock which is intended to be synchronized with Earth’s rotation and its path around the Sun, which loads it with the burden of Leap Seconds and other correction measures, not to speak of the fact that your computer’s clock may be out of sync with the wall clock anyway and get corrected, e.g. via NTP updates, in the worst case jumping right when you are trying to measure your elapsed time, perhaps even backwards.

In contrast, System.nanoTime() is designed to measure elapsed time (exactly what you want to do) and nothing else. Since its return value has an unspecified origin and may even be negative, only differences between two values returned by this method make any sense at all. You will find this even in the documentation:

The values returned by this method become meaningful only when the difference between two such values, obtained within the same instance of a Java virtual machine, is computed.

So when you want to measure and process the elapsed time of your method execution or transactions, System.nanoTime() is the way to go. Granted, it only provides a naked long value, but it isn’t clear what kind of API support you want. Since points of time are irrelevant and even distracting here, you’ll have a duration only, which you may convert to other time units or, if you want to use the new time API, you can create a Duration object using Duration.ofNanos(long), allowing you to add and subtract duration values and compare them, but there isn’t much more you could do. You must not mix them up with wall-clock or calendar based durations…

As a final note, the documentation is a bit imprecise about the limitation. If you are calculating the difference between two values returned by System.nanoTime(), a numerical overflow isn’t bad per se. Since the counter has an unspecified origin, the start value of your operation might be close to Long.MAX_VALUE whereas the end value is close to Long.MIN_VALUE because the JVM’s counter had an overflow. In this case, calculating the difference will cause another overflow, producing a correct value for the difference. But if you store that difference in a signed long, it can hold at most 2⁶³ nanoseconds, limiting the difference to max 292 years, but if you treat it as unsigned long, e.g. via Long.compareUnsigned and Long.toUnsignedString, you may handle even 2⁶⁴ nanoseconds duration, in other words you can measure up to 584 years of elapsed time this way, if your computer doesn’t break in-between…

like image 79
Holger Avatar answered Sep 22 '22 06:09

Holger


I would recommend using getThreadCpuTime from ThreadMXBean (see also https://stackoverflow.com/a/7467299/185031). If you want to measure the execution time of a method, you are most of the time not so much interested in the wall clock, but more on the CPU execution time.

like image 34
spa Avatar answered Sep 24 '22 06:09

spa