2

I designed a program aiming to measure time consumption while avoid System.currentTimeMillis() threshold for tiny execution(may take less than 1 milli)(it will inevitably produce acceptable inaccuracy for extra operations), but the count turns out to be 222 whatever statements inside the run() method are(limited to basic algorithms). I cannot figure out any possible explanation, sounds incredible but maybe a lower limit for execution?

public static void main(String[] args) throws Exception{
     long result=TinyTimer(new Runnable(){
        @Override
        public void run(){
            double d=190283758/287365628;
        }
     });
     System.out.println(result);
}

public static long TinyTimer(Runnable r){
    long count=0;
    long origin=System.currentTimeMillis();
    while(System.currentTimeMillis()==origin){
        r.run();
        count++;
    }
    return count;
}
Eureka Zheng
  • 21
  • 2
  • I'm sure you can get less than 222 if you put a lot of operations in the method (such as a Thread.sleep). – Thilo Apr 06 '16 at 04:16
  • 1
    You can use System.nanoTime for higher precision measurements. – Thilo Apr 06 '16 at 04:16
  • 1
    That's odd, I ran your code several times and received counts ranging from 2,000 to 700,000. – Jonny Henly Apr 06 '16 at 04:20
  • 1
    This is not going to be predictable, reliable, or effective at what you're trying to do. – Louis Wasserman Apr 06 '16 at 04:21
  • @Thilo Actually, using statements beyond basic algorithms does exceed 222(using List and add d returns 52), but why basic algorithm remains to be the same? – Eureka Zheng Apr 06 '16 at 04:27
  • 2
    Probably because something as simple as what you've written in your example is evaluated at compile time (because it only uses constant values) and/or eliminated completely (because you don't do anything with the result of the calculation). – Ross Ridge Apr 06 '16 at 04:52
  • The granularity of `currentTimeMillis()` is 16ms on Windows. That's a lot of cycles. – user207421 Apr 06 '16 at 06:18

1 Answers1

2

You should note that

  • the resolution of System.currentTimeMillis() is 16 ms on some older windows systems, not 1 ms.
  • the performance of code which hasn't warmed up, is interesting as an exercise but is rarely relevant for a production system. I suggest you ignore the first 2 seconds of warmup at least.
  • code which doesn't do anything can be eliminated using Dead Code Elimination. In this case you should expect the code to be eliminated and all your are timing after warmup is the time it takes to call System.currentTimeMillis() which should be between 25 - 50 nano-seconds depending on your CPU.

I suggest you look at using JMH (Java Microbenchamrk Harness) which is designed to handle most of the common mistakes in writing micro-benchmarks.

but the count turns out to be 222 whatever statements inside the run() method are(limited to basic algorithms)

Most likely the time is spend running the interpreter to execute this code and the overhead is so high, your choice of operation doesn't make much difference.

Peter Lawrey
  • 525,659
  • 79
  • 751
  • 1,130
  • The choice of operation makes no difference because these operations are all evaluated at compile-time. And the `222` seems to be very specific to the OP’s environment. As a side note, an optimizer can even remove the overhead of the `currentTimeMillis()` when it understands its semantics. So the entire `TinyTimer` method can be replaced by “wait at least one milli second and return an arbitrary `long` value”… – Holger Apr 07 '16 at 11:33
  • @Holger the System.currentTimeMillis() could only be removed provided it is replaced with some other timer. I have never seen the Oracle JDK do this. It have an understanding of a limited set of methods and this is not one of them. – Peter Lawrey Apr 07 '16 at 11:36
  • I’m not saying that this happens today, but still `System.currentTimeMillis()` [is an intrinsic function](http://hg.openjdk.java.net/jdk8/jdk8/hotspot/file/87ee5ee27509/src/share/vm/classfile/vmSymbols.hpp#l700) so the optimizer must know it, regardless of whether it knows how to elide it. – Holger Apr 07 '16 at 12:39
  • @Holger it can't be elided as the value it returns is volatile i.e. it keeps changing without any action in the current thread. The code which uses it might be optimized in interesting ways in the future. e.g. in the original code, the Jvm could add a `Thread.sleep(1);` at the end of the loop. – Peter Lawrey Apr 07 '16 at 12:42
  • Maybe my last phrase was misleading. I’m not talking about eliding all invocations without a replacement, but eliding the repeated invocation in each loop iteration. Replacing the entire loop by a wait of at least one millisecond, is what I already mentioned in the first comment. And replacing *n* increments with just one increment by *n* is a standard optimization. All the JVM has to do then, is to make up a particular *n* that is supposed to be the number of pseudo-iterations within the millisecond (overflow allowed)… – Holger Apr 07 '16 at 12:50
  • @Holger it could also replace the counter with a funny number e.g. just set it with `count = Integer.MAX_VALUE;` – Peter Lawrey Apr 07 '16 at 13:21
  • 1
    That’s what I meant with “make up a particular *n*” (and mind that overflow is possible). Any `long` number will do, including negative ones. – Holger Apr 07 '16 at 13:45