How to Measure and Log API Execution Time in Spring Boot

 

How to Measure and Log API Execution Time in Spring Boot

As developers, we often need to measure the time it takes for an API to execute, especially when performance is a critical factor. This article provides a step-by-step guide to measure API execution time in Spring Boot and log it in a readable format like ### Total Execution Time: 35.567 seconds ###. Additionally, we'll discuss how to store this data in an Oracle database column defined as NUMBER(5,3).

---

Why Measure API Execution Time?

Understanding the execution time of your APIs provides critical insights into your application's performance. By identifying bottlenecks, you can optimize your system and ensure a smooth user experience. Logging this information helps in debugging, monitoring, and improving overall system efficiency.

---

Step 1: Measuring Execution Time in the Service Layer

We will calculate the time from the beginning to the end of the method execution and log it. Here's an example:

Example Service Code

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;

@Service
public class ExampleService {

    private static final Logger logger = LoggerFactory.getLogger(ExampleService.class);

    public double executeSomeLogic() {
        long startTime = System.currentTimeMillis();

        try {
            // Simulate logic execution
            Thread.sleep(500); // Replace with actual logic
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
            logger.error("Error during execution", e);
        }

        long endTime = System.currentTimeMillis();
        double totalTimeInSeconds = (endTime - startTime) / 1000.0;
        logger.info("### Total Execution Time: {} seconds ###", totalTimeInSeconds);
        
        return totalTimeInSeconds;
    }
}

Key Points

1. The System.currentTimeMillis() method captures the start and end times in milliseconds.
2. The execution time is calculated in seconds by dividing the difference by 1000.
3. We use SLF4J for logging the result in a human-readable format.

---

Step 2: Storing Execution Time in an Oracle Database

If you want to store the measured execution time in a database column defined as NUMBER(5,3), ensure your DTO and database mapping handle the precision correctly.

DTO Design

public class ExecutionTimeDTO {
    private int id; // Example primary key
    private double executionTime; // Matches the precision of NUMBER(5,3)

    // Getters and Setters
}

Mapper XML (for MyBatis)

<insert id="insertExecutionTime" parameterType="ExecutionTimeDTO">
    INSERT INTO execution_time_log (id, execution_time)
    VALUES (#{id}, #{executionTime})
</insert>

Database Table Structure

CREATE TABLE execution_time_log (
    id NUMBER PRIMARY KEY,
    execution_time NUMBER(5,3)
);

By using double in Java and NUMBER(5,3) in Oracle, you ensure compatibility for precision and scale.

---

Bonus: Advanced Logging with AOP

For a more reusable approach, you can use Aspect-Oriented Programming (AOP) to measure execution time across multiple service methods without adding code to each method.

AOP Example

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class ExecutionTimeAspect {

    private static final Logger logger = LoggerFactory.getLogger(ExecutionTimeAspect.class);

    @Around("execution(* com.example.service..*(..))")
    public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
        long startTime = System.currentTimeMillis();

        Object proceed = joinPoint.proceed();

        long endTime = System.currentTimeMillis();
        double totalTimeInSeconds = (endTime - startTime) / 1000.0;
        logger.info("### Method {} executed in {} seconds ###", joinPoint.getSignature(), totalTimeInSeconds);

        return proceed;
    }
}

With this approach:

• All methods in the com.example.service package will automatically log their execution time.
• No additional code is required in individual service methods.

---

Conclusion

Measuring and logging API execution time is an essential step in understanding and optimizing your application’s performance. Whether you log this information in your application logs or store it in a database, the steps outlined here provide a robust and scalable approach. For advanced use cases, integrating AOP allows you to minimize boilerplate code and maintain cleaner services.

By implementing these techniques, you can ensure better performance monitoring and smoother operations in your Spring Boot application.