How to use Spring Framework StopWatch() to Log ExecutionTime and ElapseTime of any Java Thread

Spring Framework – StopWatch() is a very handy utility for any Java developer if you have small Java application or production ready application. Most of the Java applications involve Thread pooling or multiple simultaneous job invocation at the same time.

Have below questions?

• How to measure execution time in Java
• How to measure elapsed time using Spring StopWatch

Then you are at right place. In this tutorial we will go over steps on how to measure and report time taken by each and every thread or Java Methods.

Let’s get started:

StopWatch is a simple stop watch, allowing for timing of a number of tasks, exposing total running time and running time for each named task.

You need Spring MVC core Maven dependency to get this program run.

<dependency>
	<groupId>org.springframework</groupId>
	<artifactId>spring-core</artifactId>
	<version>5.0.3.RELEASE</version>
</dependency>

Please add above maven dependency to your Maven Project and follow below steps.

• Create class CrunchifySpringFrameworkStopWatch.java
• Create StopWatch object crunchifyWatch
• Start and Stop crunchifyWatch object during performTask1() and performTask2() operation
• Return totalTimesInSeconds
• In addition to print complete StopWatch result in prettyPrint format
• We are using all below operations on StopWatch to print different results.
  • getTotalTimeSeconds()
  • prettyPrint()
  • shortSummary()
  • getTaskCount()
  • getLastTaskInfo().getTaskName()

Kindly take a look at code for more detailed description.

CrunchifySpringFrameworkStopWatch.java

package crunchify.com.tutorial;

import org.springframework.util.StopWatch;

/**
 * @author Crunchify.com Use StopWatch to expose total running time of any Java Threads
 */

public class CrunchifySpringFrameworkStopWatch {

	public static void main(String[] args) {

		// StopWatch is a simple stop watch, allowing for timing of a number of tasks, exposing total running time and running time for each
		// named task.
		StopWatch crunchifyWatch = new StopWatch("CrunchifyThreads");
		CrunchifySpringFrameworkStopWatch crunchifyThread = new CrunchifySpringFrameworkStopWatch();

		crunchifyWatch.start("CrunchifyThread-1");
		crunchifyThread.performTask1();
		crunchifyWatch.stop();

		crunchifyWatch.start("CrunchifyThread-2");
		crunchifyThread.performTask2();
		crunchifyWatch.stop();
		System.out.println("CrunchifyThreads took total: " + crunchifyWatch.getTotalTimeSeconds() + " seconds");

		// prettyPrint() return a string with a table describing all tasks performed. For custom reporting, call getTaskInfo() and use the
		// task info directly.
		System.out.println("\n1. prettyPrint Result: " + crunchifyWatch.prettyPrint());

		// Return a short description of the total running time.
		System.out.println("2. Short Summary: " + crunchifyWatch.shortSummary());

		// Return the number of tasks timed.
		System.out.println("3. Total Task Count: " + crunchifyWatch.getTaskCount());

		// Return the name of this task.
		System.out.println("4. Last Task Name: " + crunchifyWatch.getLastTaskInfo().getTaskName());
	}

	private void performTask1() {

		Runnable myRunnable = new Runnable() {

			public void run() {
				System.out.println("Crunchify Task 1 running");
			}
		};

		Thread crunchifyThread = new Thread(myRunnable);
		crunchifyThread.start();

	}

	private void performTask2() {

		System.out.println("Crunchify Task 2 running \n");
		for (int i = 1; i <= 5; i++) {
			try {
				Thread.sleep(2000);
				System.out.println("Running Loop # " + i);
			} catch (InterruptedException e) {
				e.printStackTrace();
			}
		}
		System.out.println("");
	}

}

Just run above program as a Java in your Eclipse environment or stand alone using Terminal or Windows DOS and you will see performTask2() method take 10 seconds as we have for loop with count 5 and 2 seconds Thread timeout.

Eclipse console output:

Crunchify Task 1 running
Crunchify Task 2 running 

Running Loop # 1
Running Loop # 2
Running Loop # 3
Running Loop # 4
Running Loop # 5

CrunchifyThreads took total: 10.006Seconds

1. prettyPrint Result: StopWatch 'CrunchifyThreads': running time (millis) = 10006
-----------------------------------------
ms     %     Task name
-----------------------------------------
00001  000%  CrunchifyThread-1
10005  100%  CrunchifyThread-2

2. Short Summary: StopWatch 'CrunchifyThreads': running time (millis) = 10006
3. Total Task Count: 2
4. Last Task Name: CrunchifyThread-2

Let me know what you think of StopWatch. I personally use SpringFramework’s StopWatch in all of my applications.