欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识！
您现在的位置是： 首页

在 Spring Boot 中使用 Spring AOP 和 AspectJ 来测量方法的执行时间

程序员文章站 2022-05-24 12:28:37
...

原文链接：https://dzone.com/articles/logging-average-method-execution-times-via-aspectj

作者：Murat Derman

译者：Darren Luo

想要了解更多有关测量方法执行时间的信息？查看本教程，我们将着眼于使用 Spring AOP 和 AspectJ 来测量方法的执行时间。

大家好！今天，我将讨论如何在 Spring Boot 应用程序中使用 AspectJ 来测量方法执行的平均时间。我们将声明一个 quarts 作业并记录其平均方法执行时间。

首先，我们将定义我们的 pom.xml，如下所示：

<?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>AspectProgramming</groupId>
    <artifactId>com.sample</artifactId>
    <version>1.0-SNAPSHOT</version>

    <packaging>war</packaging>

    <properties>
        <java.version>1.8</java.version>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
    </properties>

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.0.0.RELEASE</version>
    </parent>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-context-support</artifactId>
        </dependency>

        <dependency>
            <groupId>org.quartz-scheduler</groupId>
            <artifactId>quartz</artifactId>
            <version>2.2.1</version>
        </dependency>

        <dependency>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
            <version>1.2.17</version>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
            <version>1.7.13</version>
        </dependency>
        <dependency>
            <groupId>org.apache.commons</groupId>
            <artifactId>commons-lang3</artifactId>
            <version>3.4</version>
        </dependency>
        <dependency>
            <groupId>commons-logging</groupId>
            <artifactId>commons-logging</artifactId>
            <version>1.2</version>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-tomcat</artifactId>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
        </plugins>
    </build></project>

下面，我们需要创建一个 Spring Boot 应用程序配置：

@SpringBootApplication
public class MyApplication {    
    public static void main(String[] args) throws InterruptedException {
        SpringApplication.run(MyApplication.class, args);
    }
}

为了**我们在 Spring beans 中的切面记录，我们声明了一个名为“Loggable”的新注解。

@Target({ElementType.METHOD, ElementType.TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface  Loggable {

}

我们为 Taget 设置属性 ElementType.Method，它用于方法定义，我们并为类定义使用 ELemenetType.Type。

为了使注解在 JVM 运行是可用，我们使用 RetentionPolicy.Runtime 配置。

接下来，我们创建一个名为 LoggingAspect 的类，它包含了一个名为“loggable”的空方法。我们使用带有 within 的 @Pointcut 通知来确定何时通知注解将被执行。

public class LoggingAspect {    
    @Pointcut("within(@com.aspect.logging.Loggable *)")    
    public void loggable() {

    }
}

我们创建两个名为 beforeMethodStatistics 和 afterMethodStatistics 的方法。

我们在 beforeMethodStatistics 方法使用”Before“通知，以便于在方法发生之前以毫秒为单位获取时间。它调用 JoinPoint 作为参数来捕获方法执行中传递的参数。

@Before("loggable()")
public void beforeMethodStatistics(JoinPoint jp) throws Throwable {
    Object[] args = jp.getArgs();    
    if (null != args && args.length > 0) {        
        for (Object arg : args) {            
            if (arg instanceof BaseRequest) {
                ((BaseRequest) arg).setStartTimeInMillis(Calendar.getInstance().getTimeInMillis());                
                break;
            }
        }
    }
}

在 afterMethodStatistics 方法中，我们使用“After”通知来计算方法在执行后的总时间。

@After("loggable()")
public void afterMethodStatistics(JoinPoint jp) {
    Object[] args = jp.getArgs();    
    if (null != args && args.length > 0) {        
        for (Object arg : args) {            
            if (arg instanceof BaseRequest) {
                StatisticsUtils.calculateStatistics(jp, arg, StatisticsMapEnum.ASPECT_LOGGER_STATISTICS_MAP);                
                break;
            }
        }
    }
}

我们创建 calculateStatistics 方法来设置方法在执行计数和总执行时间。logMethodStatistics 方法被用于记录平均时间。

public class StatisticUtils {    
    private static AppLogger logger = AppLoggerFactory.getLogger(StatisticUtils.class);       
    public static void calculateStatistics(JoinPoint jp, Object arg, StatisticsMapEnum  statisticsMapEnum) {        
        try {            
            long resultTimemMillis = Calendar.getInstance().getTimeInMillis() - ((BaseRequest) arg).getStartTimeInMillis();

            StatisticsDto statisticsDto;
            Map<String, StatisticsDto> statisticsMap = CacheUtils.statisticsMap.get(statisticsMapEnum);            
            if (GeneralUtils.isNullOrEmptyMap(statisticsMap))
                statisticsMap = new HashMap<>();            
            if (GeneralUtils.isNullObject(statisticsMap.get(jp.getSignature().getName()))) {
                statisticsDto = new StatisticsDto();
                statisticsDto.setMethodName(jp.getSignature().getName());
                statisticsDto.setTotalTimeInMillis(resultTimemMillis);
                statisticsDto.setMethodCallCount(1);
            } else {
                statisticsDto = statisticsMap.get(jp.getSignature().getName());
                long totalTimeInMillis = statisticsDto.getTotalTimeMillis() + resultTimemMillis;
                statisticsDto.setTotalTimeInMillis((totalTimeInMillis));
                statisticsDto.setMethodCallCount(statisticsDto.getMethodCallCount() +1);
            }
            statisticsMap.put(jp.getSignature().getName(), statisticsDto);
            CacheUtils.statisticsMap.put(statisticsMapEnum,statisticsMap);
        } catch (Exception ex) {
            logger.error("Exception Occured while calculating statistics:" + ExceptionUtils.getStackTrace(ex));
        }
    }    

    public static void logMethodStatistics(StatisticsMapEnum  statisticsMapEnum, BatchTypeEnum batchTypeEnum) {        
        try {
            Map<String, StatisticsDto> statisticsDtoMap = CacheUtils.statisticsMap.get(statisticsMapEnum);            
            if (!GeneralUtils.isNullOrEmptyMap(statisticsDtoMap)) {
                logger.info(batchTypeEnum.toString() + " Statistics: MethodName  -  MethodAverageTime (millis)");
                Set<Map.Entry<String, StatisticsDto>> entrySet = statisticsDtoMap.entrySet();
                Iterator<Map.Entry<String, StatisticsDto>> iterator = entrySet.iterator();                
                while (iterator.hasNext()) {
                    Map.Entry<String, StatisticsDto> entry = iterator.next();
                    StatisticsDto statisticsDto = entry.getValue();
                    logger.info(statisticsDto.getMethodName() + " - " + 
            Long.valueOf(statisticsDto.getTotalTimeMillis() / statisticsDto.getMethodCallCount()) + " ms");
                }
            }
            statisticsDtoMap = new HashMap<>();
            CacheUtils.statisticsMap.put(statisticsMapEnum,statisticsDtoMap);
        } catch (Exception ex) {
            logger.error("Exception Occured while logging statistics:" + ExceptionUtils.getStackTrace(ex));
        }
    }
}

让我们创建三个服务 ControllerService、PersistService 和 FetchDataService。

为了拦截这些服务方法，我们使用“Loggable”注解并**方法拦截。

@Loggable
@Service
public class ControlServiceImpl implements ControlService {    
    public void makeSomeCheck(FetchDataRequest request) {        
        try {
            Thread.sleep(new Random().nextInt(2000)+1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

    }

}
@Loggable
@Service
public class FetchDataServiceImpl  implements FetchDataService{    
    @Override
    public void fetchSomeData(FetchDataRequest request) {        
        try {
            FetchDataDto fetchDto=new FetchDataDto();
            List<FetchDataDto> fetchDataDtoList=new ArrayList<>();

            fetchDto.setId(1001L);
            fetchDto.setName("Tom");
            fetchDto.setSurName("Walker");
            fetchDto.setAddressInfo("Chicago");
            fetchDataDtoList.add(fetchDto);

            fetchDto.setId(1002L);
            fetchDto.setName("Clark");
            fetchDto.setSurName("Michigan");
            fetchDto.setAddressInfo("New York");
            fetchDataDtoList.add(fetchDto);
            fetchDto.setId(1003L);
            fetchDto.setName("Tom");
            fetchDto.setSurName("Walker");
            fetchDto.setAddressInfo("Chicago");
            fetchDataDtoList.add(fetchDto);

            fetchDto.setId(1004L);
            fetchDto.setName("Clark");
            fetchDto.setSurName("Michigan");
            fetchDto.setAddressInfo("New York");
            fetchDataDtoList.add(fetchDto);
            fetchDto.setId(1005L);
            fetchDto.setName("Tom");
            fetchDto.setSurName("Walker");
            fetchDto.setAddressInfo("Chicago");
            fetchDataDtoList.add(fetchDto);

            fetchDto.setId(1006L);
            fetchDto.setName("Clark");
            fetchDto.setSurName("Michigan");
            fetchDto.setAddressInfo("New York");
            fetchDataDtoList.add(fetchDto);

            request.setFetchDataDtoList(fetchDataDtoList);

            Thread.sleep(new Random().nextInt(2000)+1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

    }
}
@Loggable
@Service
public class PersistDataServiceImpl implements PersistDataService {    
    @Override
    public void persist(FetchDataRequest request) {        
        try {
            Thread.sleep(new Random().nextInt(2000)+1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

因此，我们生成一个叫做 SomeJob 的作业来执行我们的服务。高作业将获取数据、执行检查并持久化到数据库。

之后，它将记录每个作业的平均执行时间。

@Componentpublic class SomeJob implements Job {    
    
    @Override
    public void execute(JobExecutionContext context) throws JobExecutionException {

        FetchDataService fetchDataService = (FetchDataService) ApplicationContextProvider.getApplicationContext().getBean("fetchDataServiceImpl");
        ThreadPoolService threadPoolService = (ThreadPoolService) ApplicationContextProvider.getApplicationContext().getBean("threadPoolServiceImpl");
        PersistDataService persistDataService =(PersistDataService) ApplicationContextProvider.getApplicationContext().getBean("persistDataServiceImpl");
        ControlService controlService =(ControlService) ApplicationContextProvider.getApplicationContext().getBean("controlServiceImpl");
        FetchDataRequest request=new FetchDataRequest() ;
        fetchDataService.fetchSomeData(request);
        controlService.makeSomeCheck(request);
        persistDataService.persist(request);

        StatisticsUtils.logMethodStatistics(BatchTypeEnum.ASPECT_LOGGER_JOB);
    }
}

这里是结果：

ASPECT_LOGGER_JOB Statistics: MethodName - MethodAverageTime (millis)mak
相关标签： springboot

上一篇： bboss持久层查询元数据缓存机制开启方法

下一篇： JDBC在Spring中的应用

推荐阅读