Example of Spring StopWatch Utility Class

0

There comes a phase in programming where after the use cases are implemented and as we test, we may run into few performance issues. Knowing how much each piece of code is taking helps us to narrow down which task is taking more time. Spring StopWatch is a utility class provided by spring framework that allows us to know the time taken by each individual task and the the total running time. For other spring articles click here.

Here is the example:

StopWatchTest:

package com.javarticles.spring.utils;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.util.StopWatch;

@SpringBootApplication
public class StopWatchTest {

	public static void main(String[] args) {
		SpringApplication.run(SpringBootApplication.class, args);
		callTasks();
	}
	
	private static void callTasks() {
		StopWatch stopWatch = new StopWatch("Tasks-1");
		runTasks(stopWatch, "Tasks-1", 3);
		runTasks(stopWatch, "Tasks-2", 1);
		runTasks(stopWatch, "Tasks-3", 4);
		System.out.println(stopWatch.toString());
	}
	
	private static void runTasks(StopWatch stopWatch, String name, int timeInSecs) {
		stopWatch.start(name);
		doSomething(timeInSecs);
		stopWatch.stop();		
	}

	private static void doSomething(int secs) {
		try {
			Thread.currentThread().sleep(secs * 1000);
		} catch (InterruptedException e) {
			e.printStackTrace();
		}
	}

}

As you can see, we first create a StopWatch with an ID. ID is useful if we have multiple stop watches and you want to identify each one. We then use it for three different tasks. We start the stop watch using StopWatch.start() and stop it using StopWatch.stop(). If we are using this stop watch for multiple tasks, just pass in the task ID to the start() method.
Once we print the stopWatch object, we can see the summary and the details for each task. Summary contains the stop watch ID and total time taken. We also print details of each task, the time taken and the percentage of total time the task has used.

Output:

StopWatch 'Tasks-1': running time (millis) = 8001; [Tasks-1] took 3000 = 37%; [Tasks-2] took 1001 = 13%; [Tasks-3] took 4000 = 50%

If you want the details to be printed in a pretty way, use StopWatch.prettyPrint() instead of StopWatch.toString().

Output:

StopWatch 'Tasks-1': running time (millis) = 8006
-----------------------------------------
ms     %     Task name
-----------------------------------------
03000  037%  Tasks-1
01006  013%  Tasks-2
04000  050%  Tasks-3

If you are using the stop watch for millions of intervals, as you stop, the task info structure will go on increasing with each stop thus consuming excessive memory. You can turn off this using StopWatch.setKeepTaskList(false).
Other details you can figure out through StopWatch is the last task that is running, time taken by the last task, the name of the currently running task, whether the stop watch is running or not and the total task count.
One can also just the task info if one wants to deal with it differently.

Share.

Comments are closed.