更优雅的计算方法或接口耗时

一、背景#

开发时，记录某方法或任务的执行时间，或者一段代码的执行时间，如果使用System.currentTimeMillis()，很麻烦且不直观。
spring-framework和apache-common包，都提供了StopWatch类，类似计时器的逻辑封装的工具类，用法类似，spring封装的支持多任务计时，apache提供的仅支持单任务。

二、示例#

1.输出方法总耗时(秒)#

Copy
	StopWatch sw = new StopWatch();
	sw.start();
	// 逻辑处理
	Thread.sleep(6000);
	sw.stop();
	logger.debug("总耗时：{}秒",sw.getTotalTimeSeconds());

输出结果：

Copy
09:35:06.534 [main] INFO com.slup.authority.controller.AuthorityController - 总耗时：6.0072394秒

2.多任务计时#

Copy
	StopWatch sw = new StopWatch();
	sw.start("任务A");
	// 任务A逻辑处理
	Thread.sleep(3000);
	sw.stop();
	sw.start("任务B");
	// 任务B逻辑处理
	Thread.sleep(1000);
	sw.stop();
	logger.debug("总耗时：{}秒",sw.getTotalTimeSeconds());
	for(TaskInfo task: sw.getTaskInfo()) {
		logger.debug("[{}]耗时：{}秒",task.getTaskName(),task.getTimeSeconds());
	}

输出结果：

Copy
09:49:56.517 [main] INFO com.slup.authority.controller.AuthorityController - 总耗时：4.0179818秒
09:49:56.522 [main] INFO com.slup.authority.controller.AuthorityController - [任务A]耗时：3.0099562秒
09:49:56.522 [main] INFO com.slup.authority.controller.AuthorityController - [任务B]耗时：1.0080256秒

3.其他方法#

1. sw.prettyPrint() 优雅格式输出所有任务耗时及占比
2. sw.getTaskInfo() 获取所有任务对象
3. sw.isRunning() 判断当前计时器是否正在计时
4. sw.shortSummary() 返回简短的总耗时描述
5. sw.currentTaskName() 获取当前正在执行的任务名称

4.总结#

1. 统计代码的执行效率，推荐使用spring-framework的StopWatch对象，方法足够满足使用。
2. 希望大家更多地在开发、调试的环节，就多多关注，特别是涉及多次复杂查询、内部间接口调用或者三方接口调用的情况。
3. 如果觉得代码优化后不存在效率问题，则不需要将统计耗时的代码提交。
4. 除非提前已知较大可能存在效率问题（比如第三方接口），否则使用debug级别日志即可，没必要使用info日志。