Java: problem with capturing runtime to iterate on map

Question

I have a requirement to fix the execution time of some code in iterations. I decided to use Map<Integer,Long> to write this data, where the Integer (key) is the iteration number, and Long (value) is the time it takes for the iteration in milliseconds .

I wrote java code to calculate the time spent on each iteration. I want to make sure that the time taken for all iterations is zero before calling the actual code. Surprisingly, the code below behaves differently for each execution.

Sometimes I get the desired result (zero milliseconds for all iterations), but sometimes I get positive and even negative values ​​for some random iterations.

I tried replacing System.currentTimeMillis(); the code below:

new java.util.Date().getTime();

System.nanoTime();

org.apache.commons.lang.time.StopWatch

but still no luck.

Any suggestions why some iterations take extra time and how to fix it?

 package com.stackoverflow.programmer; import java.util.HashMap; import java.util.Map; public class TestTimeConsumption { public static void main(String[] args) { Integer totalIterations = 100000; Integer nonZeroMilliSecondsCounter = 0; Map<Integer, Long> timeTakenMap = new HashMap<>(); for (Integer iteration = 1; iteration <= totalIterations; iteration++) { timeTakenMap.put(iteration, getTimeConsumed(iteration)); if (timeTakenMap.get(iteration) != 0) { nonZeroMilliSecondsCounter++; System.out.format("Iteration %6d has taken %d millisecond(s).\n", iteration, timeTakenMap.get(iteration)); } } System.out.format("Total non zero entries : %d", nonZeroMilliSecondsCounter); } private static Long getTimeConsumed(Integer iteration) { long startTime = System.currentTimeMillis(); // Execute code for which execution time needs to be captured long endTime = System.currentTimeMillis(); return (endTime - startTime); } } 

Here, the sample is derived from 5 different executions of the same code:

Execution # 1 (NOT OK)

 Iteration 42970 has taken 1 millisecond(s). Total non zero entries : 1 

Execution # 2 (OK)

 Total non zero entries : 0 

Execution # 3 (OK)

 Total non zero entries : 0 

Execution # 4 (NOT OK)

 Iteration 65769 has taken -1 millisecond(s). Total non zero entries : 1 

Execution # 5 (NOT OK)

 Iteration 424 has taken 1 millisecond(s). Iteration 33053 has taken 1 millisecond(s). Iteration 76755 has taken -1 millisecond(s). Total non zero entries : 3 

I am looking for a Java-based solution that ensures that all iterations consume zero milliseconds in sequence. I prefer to do this using pure Java code without using a profiler.

Note. I was also able to accomplish this using C code.

Answer 1

HashMap performance may decrease as you resize. The default capacity is 16, which you exceed. If you know the expected capacity up, create a HashMap with the appropriate size, given a default load factor of 0.75

If you repeat iterations without defining a new map, and the Integer key does not start again from scratch, you will need to resize the map, taking into account the total number of all possible iterations.

 int capacity = (int) ((100000/0.75)+1); Map<Integer, Long> timeTakenMap = new HashMap<>(capacity); 

Answer 2

As you begin to study here, writing microobjects in Java is not as easy as you might first guess. At some point, everyone bites, even seasoned efficiency experts who have been doing this for many years.

A lot of things happen in the JVM and OS that skew results, such as GC, hotspot on-the-fly optimization, recompilation, clock correction, conflicts / thread scheduling, memory conflicts and cache misses. To name just a few. And, unfortunately, these distortions are consistent, and they can very easily dominate a micro-object.

To answer your question about why timings can go negative several times, this is because currentTimeMillis is designed to capture wall clock time and no elapsed time. The wall clock is not accurate on the computer, and there are times when the clock will be adjusted .. maybe vice versa. For more information on Java watches, see the next Oracle blog Inside the Oracle Hotspot VM Watch .

More information and support for nanoTime currentTimeMillis styles can be found here.

Before continuing my own test, I highly recommend that you read how I can write an example micro-test in java . A quick overview is to 1) warm up the JVM before accepting the results, 2) jump over hoops to avoid dead code, 3) make sure nothing is working on one computer, but accept that thread scheduling will be performed. you can even bind threads to kernels, depending on how much you want to do this, 4) use a framework specifically designed for microdetection, such as JMH or for fast weight loss JUnitMosaic gives good results.

Answer 3

You are hinting at it right ... System.currentTimeMillis(); is a way to go in this case.

There is no guarantee that increasing the value of an integer object I represents a millisecond or a cycle-time without a system ...

you should take System.currentTimeMillis () and calculate the elapsed time

Example:

 public static void main(String[] args) { long lapsedTime = System.currentTimeMillis(); doFoo(); lapsedTime -= System.currentTimeMillis(); System.out.println("Time:" + -lapsedTime); } 

Answer 4

I am not sure if I understand your question. You are trying to execute a specific set of S statements and expect runtime to be zero. Then you check this premise by doing it several times and checking the result.

This is a strange expectation: everything consumes some time and, possibly, even more. Therefore, although it could be successfully tested, this does not prove that time was not used, since your program save_time();execute(S);compare_time() . Even if execute(S) nothing, your time is discrete, and as such, it is possible that the "tick" of your overclocking just happens only between save_time and compare_time , which leads to the fact that some time has clearly passed.
Thus, I expect your C program to behave exactly the same. Have you run this several times? What happens when you increase iterations to millions? If this still does not happen, then, apparently, your C compiler has optimized the code in such a way that time is not measured, and, apparently, Java does not.

Or do I understand that you are wrong?

Answer 5

I'm also not exactly sure you are trying to execute certain code and trying to execute for each iteration of execution.

I hope I understood correctly if this is the way I would suggest, please use System.nanoTime() instead of System.currentTimeMillis(); , because if your block statement is very small, you always get zero in milliseconds.

A simple example:

 public static void main(String[] args) { long lapsedTime = System.nanoTime(); //do your stuff here. lapsedTime -= System.nanoTime(); System.out.println("Time Taken" + -lapsedTime); } 

If System.nanoTime() and System.currentTimeMillis(); doesn't really matter. But how accurately do you need the exact result and the time difference in milliseconds, you can get zero if your set of operators is not larger at each iteration.