Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

What is the point of Apache Lang3 StopWatch.split()?

I am currently evaluating implementations between Apache StopWatch and Guava's Stopwatch and the split functionality in the former intrigued me, but I am struggling to understand what exactly it does, and what value it has.

According to the documentation for StopWatch: https://commons.apache.org/proper/commons-lang/javadocs/api-3.9/org/apache/commons/lang3/time/StopWatch.html

split() the watch to get the time whilst the watch continues in the background. unsplit() will remove the effect of the split. At this point, these three options are available again.

And I found some examples, such as this, which offer very little, since it appears split is just cumulative. The page says the method is for "splitting the time", which I figured as much based on the method, but the page makes no mention to what that actually means. It would even appear that this example is utterly wrong, because the docs suggest that you should unsplit before you split again.

I initially thought it was for the following usecase:

StopWatch stopwatch = StopWatch.createStarted();
do something for 5 seconds
stopwatch.split();
do something for 10 seconds
stopwatch.stop();
System.out.println(stopwatch.getTime());
System.out.println(stopwatch.getSplitTime());

I thought that stopwatch total time would read as 15 seconds, and stopwatch split time would read as either 10 or 5 seconds, but it appears that both methods output 15 seconds.

Next, I thought maybe the split value is a delta you can take, and then remove from the total timer, something like:

StopWatch stopwatch = StopWatch.createStarted();
do something for 5 seconds
stopwatch.split();
do something for 10 seconds
stopwatch.unsplit();
stopwatch.stop();
System.out.println(stopwatch.getTime());
// System.out.println(stopwatch.getSplitTime()); errors because of unsplit

My thought here was that the split time would be 10 seconds, and when unsplit from the main timer, the main timer would read as 5 seconds... but this seems no different from a suspend() call... I also tried this, and the timings remain the same nonetheless for me.

Am I missing something here, or is my interpretation of what this is supposed to do all wrong?

like image 543
ryanlutgen Avatar asked Jul 08 '20 22:07

ryanlutgen


People also ask

How do I use Apache Commons stopwatch?

The simplest steps to use the StopWatch is to create an instance of the StopWatch class, start the stopwatch by calling the start() method. After the stopwatch is started you can execute the target method or block of code you want to watch and call the stop() method to complete the timing session.

How do you stopwatch in Java?

Stopwatch in Java Using System. In the Stopwatch1 two methods to start and stop the stopwatch, start() initializes the stopWatchStartTime with the current nanoseconds using System. nanoTime() and set the value of stopWatchRunning (checks if the stopwatch is running) as true .


Video Answer


1 Answers

This is the source code for getSplitTime() (it calls this other function internally):

public long getSplitNanoTime() {
  if (this.splitState != SplitState.SPLIT) {
     throw new IllegalStateException("Stopwatch must be split to get the split time. ");
  }
   return this.stopTime - this.startTime;
}

So it will return stopTime-startTime. Beware of stopTime. It's the liar that's confusing you.

This is the code for stop():

public void stop() {
  if (this.runningState != State.RUNNING && this.runningState != State.SUSPENDED) {
    throw new IllegalStateException("Stopwatch is not running. ");
  }
  if (this.runningState == State.RUNNING) 
  {
    //is this the same stopTime getSplitTime uses? yep, it is
     this.stopTime = System.nanoTime(); 
  }
  this.runningState = State.STOPPED;
}

What's happenning then?

Calling stop() updates the stopTime variable and makes the stopwatch "forget" the last time it was splitted.

Both split() and stop() modify the same variable, stopTime, which is overrided when you call stop() at the end of your process.

Although sharing the same variable may look wierd, it really makes sense, as an splittedTime of an StopWatch should never be bigger than the total elapsed time. So it's a game regarding the order of the functions executed in the StopWatch.

This is the code for split(), in order to see that both methods do use stopTime:

public void split() {
   if (this.runningState != State.RUNNING) {
      throw new IllegalStateException("Stopwatch is not running. ");
    }
    this.stopTime = System.nanoTime(); // you again little f..
    this.splitState = SplitState.SPLIT;
}

That's why this little adorable Apache liar shows you 15 seconds on the splittedTime: because stop() updated the stopTime variable getSplitTime() will use to return its value. (the first code snippet)

Note the simplicity of the split() function (this also barely answers OP's question). It is responsible of:

  1. Checking wether the StopWatch is running.
  2. Marking a new stopTime.
  3. Setting the splitState to SPLIT.

                                      TLDR lol

Calling getSplitTime() before stopping the StopWatch should show you the desired value:

  1. stopTime won't be updated by stop() yet.
  2. The returning value will now match the time elapsed between the last split() and the startTime.

Some examples: (yes, editing at saturday night cause I need a social life)

StopWatch stopwatch = StopWatch.createStarted();
do something for 5 seconds
stopwatch.split(); //stopTime is updated [by split()]
System.out.println(stopwatch.getSplitTime()); // will show 5 seconds
do something for 10 seconds
System.out.println(stopwatch.getSplitTime()); // will also show 5 seconds
stopwatch.stop(); //stopTime is updated again [by stop()]
System.out.println(stopwatch.getTime()); // 15s
System.out.println(stopwatch.getSplitTime()); // 15s

Another one:

StopWatch stopwatch = StopWatch.createStarted();
do something for 5 seconds
stopwatch.split(); 
System.out.println(stopwatch.getSplitTime()); // 5s
do something for 10 seconds
stopwatch.split(); 
System.out.println(stopwatch.getSplitTime()); // 15s
do something for 1 second
stopwatch.stop();
System.out.println(stopwatch.getTime()); // 16s

And a last one. Mocked the time with sleeps, just for the fun, you know. I was so bored I really imported the apache jar in order to test this locally:

StopWatch stopwatch = StopWatch.createStarted();
Thread.sleep(5000);
stopwatch.split(); 
System.out.println(stopwatch.getSplitTime()); // 5s
Thread.sleep(10000);
stopwatch.split(); 
System.out.println(stopwatch.getSplitTime()); // 15s

stopwatch.reset();  // allows the stopWatch to be started again
stopwatch.start();  // updates startTime

Thread.sleep(2000);
stopwatch.split(); 
System.out.println(stopwatch.getSplitTime()); // 2s
Thread.sleep(1000);
stopwatch.stop();
System.out.println(stopwatch.getTime());      // 3s
System.out.println(stopwatch.getSplitTime()); // 3s
//it was so fun putting the sleeps

Note that calling getSplitTime() on an stopped Watch won't throw any exception, because the method will only check wheter the splitState is SPLIT.

The confusion may be caused by these two facts:

  1. The code allows you to stop() regardless of the SplitState, making your last split() futile without you being aware. Futile, I love that word. Had to include it in my answer somehow. Futileeee
  2. It also allows you to check the splittedTime on an stopped watch (if it is still on SPLIT state), when it really just will return the total elapsed time between the last start() and the stopping time. (little liar)

In this scenario, where the stopwatch is stopped and splitted at the same time, getTime() and getSplitTime() will always show the same value when called after stop().


[Personal and subjective opinion]

Let's say you have a Counters class with different variables to check elapsed times. You also want to output the total elapsed time for each operation, every 60 seconds . In this example, counters is an instance of a Counters class that owns two long variables: fileTime and sendTime, that will accumulate the elapsed time within each operation during an specific interval (60s). This is just an example that assumes each iteration takes less than 1000 ms (so it will always show 60 seconds on the elapsed time):

long statsTimer = System.currentTimeMillis();
while (mustWork)
{
    long elapsedStatsTimer = System.currentTimeMillis()-statsTimer; //hits 60185 
   
    if (elapsedStatsTimer  > 60000)
    {
       //counters.showTimes()
       System.out.println("Showing elapsed times for the last "+
                            (elapsedStatsTimer/1000)+ " secs"); //(60185/1000) - 60 secs
       System.out.println("Files time: "+counters.fileTime+" ms"); //23695 ms
       System.out.println("Send time : "+counters.sendTime+" ms"); //36280 ms          
       long workTime = counters.sendTime+counters.fileTime;
       System.out.println("Work time : "+workTime+" ms"); //59975 ms
       System.out.println("Others    : "+(elapsedStatsTimer-workTime)+" ms"); //210 ms
       //counters.reset()
       counters.fileTime=0;
       counters.sendTime=0;
       statsTimer= System.currentTimeMillis();
     }
     
     long timer = System.currentTimeMillis();
     //do something with a file
     counters.fileTime+=System.currentTimeMillis-timer;
     timer = System.currentTimeMillis();
     //send a message
     counters.sendTime+=System.currentTimeMillis()-timer;
}

That Counters class could implement the reset() and showTimes() functions, in order to clean up the code above. It could also manage the elapsedStatsTimer variable. This is just an example to simplify its behaviour.

For this use case, in which you need to measure different operations persistently, I think this way is easier to use and seems to have a similar performance, as the StopWatch internally makes the exact same thing. But hey, it's just my way to do it : ).

I will accept downvotes for this opinion in an honorable and futile way.

I would love to finish with a minute of silence in honour of unsplit(), which may be one of the most irrelevant methods ever existed.

[/Personal and subjective opinion]


Just noticed TLDR section is actually bigger than the previous section :_ )

like image 157
aran Avatar answered Oct 18 '22 03:10

aran