Creating a Spring Boot Starter to Log Method Execution Time

Introduction: When using Spring Boot you often rely on various spring-boot-starter dependencies. This article demonstrates how to write a custom starter in four steps that logs method execution time using AOP.

Step 1 – Create Maven project: The article discusses naming conventions (spring-boot-starter-XX for official starters, XX-spring-boot-starter for third‑party extensions) and provides a pom.xml that includes spring-boot-autoconfigure-processor, spring-boot-starter-aop, and the optional configuration‑processor.

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>org.example</groupId>
    <artifactId>aspectlog-spring-boot-starter</artifactId>
    <version>1.0.2</version>
    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.1.15.RELEASE</version>
    </parent>
    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-autoconfigure</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-configuration-processor</artifactId>
            <optional>true</optional>
        </dependency>
    </dependencies>
</project>

The spring-boot-configuration-processor generates META-INF/spring-autoconfigure-metadata.properties at compile time, which speeds up auto‑configuration detection.

Step 2 – Write auto‑configuration logic: The tutorial chooses @ConditionalOnProperty so the configuration is activated only when aspectLog.enable=true. It then defines three Java components:

A custom annotation @AspectLog to mark methods whose execution time should be logged.

A properties class AspectLogProperties bound to the aspectLog prefix.

An auto‑configuration class AspectLogAutoConfiguration that registers an @Around advice, measures execution time, and logs the result.

package com.shanyuan.autoconfiguration.aspectlog;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/**
 * Annotation to mark methods for execution‑time logging.
 */
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface AspectLog {}

package com.shanyuan.autoconfiguration.aspectlog;

import org.springframework.boot.context.properties.ConfigurationProperties;

@ConfigurationProperties("aspectLog")
public class AspectLogProperties {
    private boolean enable;
    public boolean isEnable() { return enable; }
    public void setEnable(boolean enable) { this.enable = enable; }
}

package com.shanyuan.autoconfiguration.aspectlog;

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.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.EnableAspectJAutoProxy;
import org.springframework.core.PriorityOrdered;

@Aspect
@EnableAspectJAutoProxy(exposeProxy = true, proxyTargetClass = true)
@Configuration
@ConditionalOnProperty(prefix = "aspectLog", name = "enable", havingValue = "true", matchIfMissing = true)
public class AspectLogAutoConfiguration implements PriorityOrdered {
    protected Logger logger = LoggerFactory.getLogger(getClass());

    @Around("@annotation(com.shanyuan.autoconfiguration.aspectlog.AspectLog)")
    public Object logExecutionTime(ProceedingJoinPoint thisJoinPoint) throws Throwable {
        String taskName = thisJoinPoint.getSignature().toString()
                .substring(thisJoinPoint.getSignature().toString().indexOf(" ") + 1,
                           thisJoinPoint.getSignature().toString().indexOf("("))
                .trim();
        long start = System.currentTimeMillis();
        Object result = thisJoinPoint.proceed();
        logger.info("method:{} run :{} ms", taskName, (System.currentTimeMillis() - start));
        return result;
    }

    @Override
    public int getOrder() {
        // Ensure this aspect runs after transactional aspects
        return Integer.MAX_VALUE;
    }
}

Step 3 – Register the auto‑configuration: Add an entry to META-INF/spring.factories so Spring Boot discovers the configuration automatically.

org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
com.shanyuan.autoconfiguration.aspectlog.AspectLogAutoConfiguration

Step 4 – Package and test: Build the starter with mvn install, include it as a dependency in another project, and verify that any method annotated with @AspectLog produces a log line such as method:myMethod run :12 ms.

The article concludes with screenshots of the Maven build process and a final directory layout, and provides references to the official Spring Boot documentation and related blog posts.