不要再纠结如何打印方法执行用时了，这个东西能帮你

Kripath_Rion
1,804 阅读8分钟

前言

如果你有这样的需求：

想要计算自己的spring项目中某些方法的执行用时，且每次执行时自动输出

那么这个框架就很适合你了，目前，这个计时框架有以下优点：

  • 使用简单，一行注解即可生效
  • 支持高度自定义的输出格式
  • 对方法无侵入
  • 自由选择输出到控制台或日志

其实这个也是我自己做的小框架，完全开源，项目地址在github-mayoi7/timer，目前正在开发的分支是1.x，最新版本是1.2.0-RELEASE

使用样例

引入依赖

首先创建一个简单的web项目

然后在pom.xml中引入我们项目需要的依赖：

    <properties>
        <java.version>1.8</java.version>
        <timer.version>1.2.0-RELEASE</timer.version>
    </properties>
    
    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>

        <!-- 计时器的依赖 -->
        <dependency>
            <groupId>com.github.mayoi7</groupId>
            <artifactId>timer</artifactId>
            <version>${timer.version}</version>
        </dependency>
    </dependencies>

创建基本结构

然后接下来新建配置文件application.yml，不过我们这里可以什么都先不写

接着新建一个Controller，我们里面就添加一个方法：

import com.github.mayoi7.timer.anno.Timer;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class DemoController {

    @RequestMapping("hi")
    @Timer
    public void hello() {
        try {
            Thread.sleep(826);
        } catch (Exception ignore) {}

        System.out.println("Hello World...");
    }
}

这里要注意一定要把我们com.github.mayoi7这个包下的类扫描进来，所以可以采用以下的配置方式：

@SpringBootApplication
// 下面两种配置任选一（com.example.demo是当前项目的源码包根目录）
// @ComponentScan(basePackages = "com.*")
@ComponentScan(basePackages = {"com.example.demo.*", "com.github.mayoi7.*"})
public class DemoApplication {

    public static void main(String[] args) {
        SpringApplication.run(DemoApplication.class, args);
    }

}

使用注解添加计时器

好了，然后就到了重头戏，如何给这个方法计时呢？既然我们引入了依赖，这里直接一个注解就够了：

import com.github.mayoi7.timer.anno.Timer;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class DemoController {

    @RequestMapping("hi")
    @Timer
    public void hello() {
        try {
            Thread.sleep(826);
        } catch (Exception ignore) {}

        System.out.println("Hello World...");
    }
}

测试

我们启动服务器，访问localhost:8080/hi，会发现控制台会打印出结果：

Hello World...

[(date=2019-06-08 22:22:31, name=825608c3, duration=830 ms, classInfo=com.example.demo.controller.DemoController, methodInfo=hello)]

我们来用JMeter测试下并发下的表现，这里同时开了1000个线程循环1000次（电脑比较渣，之前开了太多被卡死机了），这里截取了一小段输出[1]：

[(date=2019-06-08 22:36:08, name=0753f926, duration=826 ms, classInfo=com.example.demo.controller.DemoController, methodInfo=hello)]

[(date=2019-06-08 22:36:08, name=a0a242cd, duration=826 ms, classInfo=com.example.demo.controller.DemoController, methodInfo=hello)]
Hello World...

[(date=2019-06-08 22:36:08, name=96b67174, duration=827 ms, classInfo=com.example.demo.controller.DemoController, methodInfo=hello)]
Hello World...
Hello World...

[(date=2019-06-08 22:36:08, name=26676684, duration=827 ms, classInfo=com.example.demo.controller.DemoController, methodInfo=hello)]

[(date=2019-06-08 22:36:08, name=fc283e48, duration=827 ms, classInfo=com.example.demo.controller.DemoController, methodInfo=hello)]

可以发现输出的结果还是准确的

使用教程

输出属性含义

目前可供输出的有5个属性，即刚才输出的那些：

  • date：方法执行完毕的时间，也是结果输出的时间
  • name：计时器名称，可以自行设置，如果没有设置则会使用一个随机8位字符串
  • duration：方法执行用时
  • classInfo：方法所在类的信息
  • methodInfo：方法信息

这些属性大部分都可以在有限基础上自行修改，至于如何自定义我们接下来会进行讲解

配置项

配置项可以分为配置文件中的配置，和注解上的配置，我们分开来讲

配置文件

配置文件中以timer为前缀的是我们计时器的配置项，有两大类，timer.format和timer.mode，我们单独来说

timer.format 该类配置是用于配置输出格式，自由度较高，所以统一放在一起，包含有：

  • timer.format.fileFormat：日志文件名，包含了文件后缀（如果不输出到日志则无效）
  • timer.format.logPath：日志输出的绝对路径，即“/”为当前磁盘根目录（如果不输出到日志则无效）
  • timer.format.dateFormat：日期输出格式，形如“yyyy-MM-dd HH:mm:ss”，和SimpleFormatter一致
  • timer.format.formatterPath：自定义格式化器类的全路径（待会讲到了会说）

timer.mode 该类配置是用于一些既定输出模式的选择，均为枚举类型，所以统一放在一起，包含有：

  • timer.mode.timeMode：时间输出方式，目前仅有simple一种格式
  • timer.mode.unit：时间单位，可选范围为TimeUnit的所有枚举类
  • timer.mode.methodMode：方法名输出方式，有simple和param两种方式，分别是仅输出方法名，以及输出方法名和参数
  • timer.mode.classMode：类名输出方式，有full和simple两种方式，分别是类全路径输出，以及仅输出简单类名

以下是一份样例配置文件（暂时没有配置自定义格式化器）：

timer:
  format:
    file-format: timer-demo.log
    log-path: /
    date-format: yyyy-MM-dd HH:mm:ss
  mode:
    time-mode: simple
    unit: milliseconds
    method-mode: param
    class-mode: full

注解配置

@Timer注解中，目前有效的配置有以下几个：

  • name：计时器的名称，如果不设置，则会默认使用随机生成的8位字符串
  • unit：时间单位，默认为毫秒，在这里配置的优先级会高于配置文件
  • formatter：自定义的格式化器类路径，优先级高于配置文件
  • position：结果输出的位置，可选项有ResultPosition.CONSOLE和ResultPosition.LOG，默认输出到控制台

样例配置如下：

@Timer(name = "timer1", unit = TimeUnit.SECONDS, position = ResultPosition.LOG)

定制

如果刚才的这些配置不能够满足你的需要，这里还提供了高自由度的自定义配置

自定义输出格式

默认的输出格式不好看？没关系，现在教你如何自定义输出的格式

首先，我们在创建一个timer包，然后在包下建一个类，就叫MyFormatter，然后继承AbstractFormatter，注意千万不要引错包：

import com.github.mayoi7.timer.format.AbstractFormatter;
import com.github.mayoi7.timer.props.TimerOutputSource;
import com.github.mayoi7.timer.props.TimerProperties;

public class MyFormatter extends AbstractFormatter {

    public MyFormatter(TimerProperties properties, TimerOutputSource source) {
        super(properties, source);
    }
}

这里构造函数里两个对象我先说明一下，properties是我们所设置的各项配置，source是我们计时器的输出结果，不过这些都不用我们手动设置

然后我们在这个类中定义一个MyRecevier的内部类[2]，用于获取到输出属性，需要覆写其中的output()方法，并在我们自定义的MyFormatter格式化器类中重写getInfoReceiver()方法，返回我们的MyReceiver对象：

import com.github.mayoi7.timer.format.AbstractFormatter;
import com.github.mayoi7.timer.props.TimerOutputSource;
import com.github.mayoi7.timer.props.TimerProperties;

public class MyFormatter extends AbstractFormatter {

    public MyFormatter(TimerProperties properties, TimerOutputSource source) {
        super(properties, source);
    }

    private static class MyReceiver extends InfoReceiver {
    
        @Override
        public String output() {
            return "\n[myFormatter]" + date + "-" + duration;
        }
    }
    
    @Override
    public InfoReceiver getInfoReceiver() {
        return new MyReceiver();
    }
}

在output()方法中，可供使用的属性有以下5个（从InfoReceiver中得知）：

    class InfoReceiver {
        /** 日期 */
        protected String date;
        /** 名称 */
        protected String name;
        /** 执行时间 */
        protected String duration;
        /** 类信息 */
        protected String classInfo;
        /** 方法信息 */
        protected String methodInfo;

        // ...
    }

最后，最重要的一步来了，把MyFormatter类的路径通知给计时器，有配置文件和注解配置两种方式，我这里就在注解中配置了：

@Timer(formatter = "com.example.demo.timer.MyFormatter")

然后运行测试，会发现输出的结果改为我们配置的格式了：

Hello World...

[myFormatter]2019-06-08 23:34:20-828 ms

获取更多的信息

当然，仅仅改个格式还不够，如果你想获取更多的关于被计时方法和其所在类的信息，我们也提供了自定义的手段

比如，你想在类信息输出的FULL模式下获取更多的内容，我们就需要回到MyFormatter类中，再次添加一个内部类[3]MyClassFormatter，并继承ClassFormatter，选择性覆写其中的方法：

import com.github.mayoi7.timer.format.AbstractFormatter;
import com.github.mayoi7.timer.props.TimerOutputSource;
import com.github.mayoi7.timer.props.TimerProperties;

public class MyFormatter extends AbstractFormatter {

    // ...
    
    private static class MyClassFormatter extend ClassFormatter {

        @Override
        public String formatInFull(Class clazz) {
            return clazz.getName() + "-" + clazz.getTypeName();
        }
    } 
}

然后最重要的一点是，将这个新声明的类在构造方法中赋予对应的属性：

public class MyFormatter extends AbstractFormatter {

    public MyFormatter(TimerProperties properties, TimerOutputSource source) {
        // ...
        
        classFormatter = new MyClassFormatter();
    }

同样地，我们也为方法信息提供了对应的MethodFormatter类和methodFormatter属性，使用方法基本一致，不再进行演示

到此，配置已经完成，如果我们开启了类信息输出的FULL模式，则刚才的MyReceiver中的classInfo属性就为我们修改后的属性了，具体内容不再测试了，感兴趣的可以自行实验

注意事项

  • 一定要开启@ComponentScan注解，不管怎么配置，一定要把com.github.mayoi7.*下的所有类扫描到
  • 注解中的配置优先级高于配置文件，但是如果在注解中配置时间单位为毫秒时，优先级会降至最低
  • 目前项目还处于不稳定的阶段，可能会对方法执行时间有些许的影响
  • 该计时框架是基于spring-aop的，所以只能作用于spring的bean，不能在普通类下使用

结束

到此，整个框架的使用教程已经完全结束，如果有任何的问题可以发送邮件到acerola.orion@foxmail.com

最后，项目地址在github-mayoi7/timer，感兴趣的可以点个星星啦

  1. 聚合报告的结果显示加了注解之后响应时间慢了，但是错误率低了，可能是测试的方式有问题，我对于JMeter用的也不算熟练，这个报告没什么参考价值就暂且先不放 ↩︎

  2. 虽然这个类的声明位置不限，不过推荐声明为自定义格式化器的内部类 ↩︎

  3. 同样地，这个类声明位置不限 ↩︎

avatar
文章
阅读
粉丝