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

作者：Murat Derman

譯者：Darren Luo

想要了解更多有關(guān)測量方法執(zhí)行時(shí)間的信息？查看本教程，我們將著眼于使用 Spring AOP 和 AspectJ 來測量方法的執(zhí)行時(shí)間。

大家好！今天，我將討論如何在 Spring Boot 應(yīng)用程序中使用 AspectJ 來測量方法執(zhí)行的平均時(shí)間。我們將聲明一個(gè) quarts 作業(yè)并記錄其平均方法執(zhí)行時(shí)間。

首先，我們將定義我們的 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>

下面，我們需要?jiǎng)?chuàng)建一個(gè) Spring Boot 應(yīng)用程序配置：

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

為了激活我們在 Spring beans 中的切面記錄，我們聲明了一個(gè)名為“Loggable”的新注解。

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

我們?yōu)?Taget?設(shè)置屬性?ElementType.Method，它用于方法定義，我們并為類定義使用?ELemenetType.Type。

為了使注解在 JVM 運(yùn)行是可用，我們使用?RetentionPolicy.Runtime?配置。

接下來，我們創(chuàng)建一個(gè)名為?LoggingAspect?的類，它包含了一個(gè)名為“l(fā)oggable”的空方法。我們使用帶有?within?的?@Pointcut?通知來確定何時(shí)通知注解將被執(zhí)行。

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

我們創(chuàng)建兩個(gè)名為?beforeMethodStatistics?和?afterMethodStatistics?的方法。

我們在?beforeMethodStatistics?方法使用”Before“通知，以便于在方法發(fā)生之前以毫秒為單位獲取時(shí)間。它調(diào)用?JoinPoint?作為參數(shù)來捕獲方法執(zhí)行中傳遞的參數(shù)。

@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”通知來計(jì)算方法在執(zhí)行后的總時(shí)間。

@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;}}} }

我們創(chuàng)建?calculateStatistics?方法來設(shè)置方法在執(zhí)行計(jì)數(shù)和總執(zhí)行時(shí)間。logMethodStatistics?方法被用于記錄平均時(shí)間。

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));}} }

讓我們創(chuàng)建三個(gè)服務(wù)?ControllerService、PersistService?和?FetchDataService。

為了攔截這些服務(wù)方法，我們使用“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{ ? ?@Overridepublic 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 { ? ?@Overridepublic void persist(FetchDataRequest request) { ? ? ? ?try {Thread.sleep(new Random().nextInt(2000)+1000);} catch (InterruptedException e) {e.printStackTrace();}} }

因此，我們生成一個(gè)叫做?SomeJob?的作業(yè)來執(zhí)行我們的服務(wù)。高作業(yè)將獲取數(shù)據(jù)、執(zhí)行檢查并持久化到數(shù)據(jù)庫。

之后，它將記錄每個(gè)作業(yè)的平均執(zhí)行時(shí)間。

@Componentpublic class SomeJob implements Job { ? ?@Overridepublic 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);} }

這里是結(jié)果：

ASPECT_LOGGER_JOB Statistics: MethodName - MethodAverageTime (millis)mak

總結(jié)

以上是生活随笔為你收集整理的在 Spring Boot 中使用 Spring AOP 和 AspectJ 来测量方法的执行时间的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。