0

Here is my code in my main that calculates for the time difference of selectionSort() using nanoTime(): 

    System.out.println("Start time :: " + test.start());
    test.selectionSort();
    System.out.println("End time :: " + test.end());
    System.out.println(test);
    System.out.print("Time took to run selectionSort() == ");
    System.out.println((test.getElapsedTime()) + " nanoseconds");

and my start(), end(), and getElapsedTime() methods are:

    public long start(){
    startTime = System.nanoTime();
    return startTime;
    }

    public long end(){
    endTime = System.nanoTime();
    return endTime;
    }

    public long getElapsedTime(){
    return end() - start();
    }

After running this program, the output is:

    5 2 9 7 4 3 0 1 6 8 
    Start time :: 915929737160723
    End time :: 915929737309925
    0 1 2 3 4 5 6 7 8 9 
    Time took to run selectionSort() == -5921 nanoseconds

How come the getElapsedTime() method returns a negative number when it's supposed to be a positive?

Phillip
  • 21
  • 6
  • 1
    I guess this is Java. You should edit the question and add a tag for the programming language. Thanks! – stholzm Mar 26 '17 at 10:57
  • By the way, benchmarking is tricky, and especially unreliable with tasks that only take a few milliseconds, like sorting 10 elements. Have a look at the related answers. – stholzm Mar 26 '17 at 11:04

2 Answers2

1

Because getElapsedTime does not substract startTime from endTime, but resets them in the calls to end() and start(). Both calls happen nearly simultaneously, and return new nanotimes. start() apparently happens to be evaluated a bit later, so the result is a small negative number.

Proposed fix:

public long getElapsedTime() {
  return endTime - startTime;
}
stholzm
  • 3,395
  • 19
  • 31
  • Weird. I'm familiar with Java, only know c c++. How can you work with a language that reschedules commands for you in a way that they behave unpredictable? I mean, `end()` should IMHO never be called before `start()` – JHBonarius Mar 26 '17 at 11:10
  • @J.H.Bonarius added the fix to my answer, maybe this helps? There is no black magic going on - the measured nanotimes just get overwritten in nearly the same moment. – stholzm Mar 26 '17 at 11:21
  • Thanks. But I still don't fully grasp the bigger picture. Even though they're called very close to each other, `start ()` should always be called before `end()`. And their output should refer to the system time, that should never decrease. How can the result ever be negative? – JHBonarius Mar 26 '17 at 12:05
  • 1
    @J.H.Bonarius I am talking about the line `return end() - start();` - do you really expect `start()` to be evaluated before `end()`? – stholzm Mar 26 '17 at 12:14
  • Hmm, good point... let me think about this. I'm probably saying something stupid.... – JHBonarius Mar 26 '17 at 12:43
0

You will have to save the time in a variable, like this:

startTime = System.nanoTime();
doThings(); //This is what you want to measure
elapsedTime = System.nanoTime() - startTime;
System.out.println((elapsedTime + " nanoseconds");
Dan
  • 630
  • 5
  • 8