Medición del tiempo de ejecución de código Java con StopWatch de Spring

En este tutorial, veremos cómo medir el tiempo de ejecución del código Java para proyectos basados ​​en Spring a través de StopWatch y su API simple.

Introducción

Medir el tiempo de ejecución del código es un paso vital para tratar de escribir aplicaciones eficientes. El conocimiento temporal de su código en una máquina que podría estar sirviendo a una gran cantidad de usuarios le permite planificar más, teniendo en cuenta el tiempo de ejecución.

En sistemas de subprocesos múltiples, también es útil para medir el tiempo de ejecución de subprocesos individuales o tareas asincrónicas.

Dado que no existe una forma conveniente e integrada de medir la ejecución del código en Java, para las soluciones basadas en Spring, se nos presentó la herramienta StopWatch.

En este tutorial, veremos cómo medir el tiempo de ejecución del código en Java con StopWatch de Spring.

Clase StopWatch de Spring\

El StopWatch es una clase de utilidad, que reside en el paquete util. Tiene una API muy simple y nos permite cronometrar tareas con nombre, grupos de tareas y el tiempo total de ejecución de un programa.

Esta clase se usa normalmente para verificar el rendimiento del código durante la fase de desarrollo, en lugar de una parte de las aplicaciones de producción.

Nota: Vale la pena señalar que StopWatch no es seguro para subprocesos.

Realiza un seguimiento del tiempo en nansegundos, basándose en System.nanoTime(), que es lo que la gente ha estado haciendo manualmente para cronometrar la ejecución de su código.

Medición del tiempo de ejecución del código con StopWatch

El StopWatch pertenece al paquete central util de Spring:

1
2
3
4
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-core</artifactId>
</dependency>

Naturalmente, también está presente en la dependencia spring-boot-starter-web:

1
2
3
4
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
</dependency>

La API de StopWatch se reduce a crear una instancia y llamar a start() y stop(), como si estuviera cronometrando el código con un cronómetro real. Al comenzar el tiempo, también puede proporcionar una Cadena para usarla como nombre o anotación para la tarea asociada. Esto ayuda a diferenciarlos en los resultados.

Una tarea es simplemente el período entre una llamada start() y stop(). Para cada tarea, creada cuando se inicia un ‘StopWatch’, su nombre y tiempo de ejecución se guardan en una instancia de ‘TaskInfo’ y se agregan a la lista de tareas.

Avancemos y creemos una tarea, con un nombre y midamos el tiempo de ejecución de un fragmento de código:

1
2
3
4
5
6
7
8
StopWatch timeMeasure = new StopWatch();

timeMeasure.start("Task 1");
Thread.sleep(1000);
timeMeasure.stop();

System.out.println("Last task time in Millis: " 
             + timeMeasure.getLastTaskMillis());

Esto resulta en:

1
Last task time in Millis: 1009

Puede acceder a la suma de todas las tareas a través de getTotalTimeSeconds(), getTotalTimeMillis() y getTotalTimeNanos().

También puede acceder a la última tarea de StopWatch a través de getLastTaskInfo(), que devuelve una instancia TaskInfo. Esta instancia contiene información sobre la última tarea, como el nombre y cuánto tiempo tomó en segundos, milisegundos y nanosegundos:

1
2
3
4
5
6
7
8
9
StopWatch stopWatch = new StopWatch();

stopWatch.start("Task 1");
Thread.sleep(1000);
stopWatch.stop();

System.out.println(stopWatch.getLastTaskInfo().getTaskName());

System.out.println(stopWatch.getLastTaskInfo().getTimeMillis());

Esto ahora resulta en:

1
2
Task 1
1008

Cuando se trata de múltiples tareas, un método realmente útil es el método prettyPrint(), que imprime todos los registros en forma de tabla, con un formato simple:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
// Naming this StopWatch instance
StopWatch stopWatch = new StopWatch("Measure Code Execution");
    
stopWatch.start("1. Task");
Thread.sleep(2000);
stopWatch.stop();
    
stopWatch.start("2. Task");
Thread.sleep(5000);
stopWatch.stop();
 
stopWatch.start("3. Task");
Thread.sleep(3000);
stopWatch.stop();
  
System.out.println(stopWatch.prettyPrint());

Producción:

1
2
3
4
5
6
7
StopWatch 'Measure Code Execution': running time = 10012348500 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
2002729600  020%  1. Task
5006985700  050%  2. Task
3002633200  030%  3. Task

Nota: Si usamos StopWatch para medir el tiempo de ejecución del código durante una gran cantidad de intervalos (del orden de cientos de miles o millones), la lista TaskInfo consumirá una parte significativa de tu memoria de trabajo. Puede desactivarlo a través de:

1
stopWatch.setKeepTaskList(false);

Conclusión

En este tutorial, echamos un vistazo a la clase de utilidad StopWatch: la respuesta de Spring a la falta inherente de herramientas de medición de tiempo en Java.