如何优雅地统计代码耗时？
程序员考拉
共 15983字，需浏览 32分钟
· 2021-03-03
一、前言
代码耗时统计在日常开发中算是一个十分常见的需求，特别是在需要找出代码性能瓶颈时。
可能也是受限于 Java 的语言特性，总觉得代码写起来不够优雅，大量的耗时统计代码，干扰了业务逻辑。特别是开发功能的时候，有个感受就是刚刚开发完代码很清爽优雅，结果加了一大堆辅助代码后，整个代码就变得臃肿了，自己看着都挺难受。因此总想着能不能把这块写的更优雅一点，今天本文就尝试探讨下“代码耗时统计”这一块。
在开始正文前，先说下前提，“代码耗时统计”的并不是某个方法的耗时，而是任意代码段之间的耗时。这个代码段，可能是一个方法中的几行代码，也有可能是从这个方法的某一行到另一个被调用方法的某一行，因此通过 AOP 方式是不能实现这个需求的。
二、常规方法
2.1 时间差统计
这种方式是最简单的方法，记录下开始时间，再记录下结束时间，计算时间差即可。
public class TimeDiffTest {
public static void main(String[] args) throws InterruptedException {
final long startMs = TimeUtils.nowMs();
TimeUnit.SECONDS.sleep(5); // 模拟业务代码
System.out.println("timeCost: " + TimeUtils.diffMs(startMs));
}
}
/* output:
timeCost: 5005
*/public class TimeUtils {
/**
* @return 当前毫秒数
*/
public static long nowMs() {
return System.currentTimeMillis();
}
/**
* 当前毫秒与起始毫秒差
* @param startMillis 开始纳秒数
* @return 时间差
*/
public static long diffMs(long startMillis) {
return diffMs(startMillis, nowMs());
}
}这种方式的优点是实现简单，利于理解；缺点就是对代码的侵入性较大，看着很傻瓜，不优雅。
2.2 StopWatch
第二种方式是参考 StopWatch ，StopWatch 通常被用作统计代码耗时，各个框架和 Common 包都有自己的实现。
public class TraceWatchTest {
public static void main(String[] args) throws InterruptedException {
TraceWatch traceWatch = new TraceWatch();
traceWatch.start("function1");
TimeUnit.SECONDS.sleep(1); // 模拟业务代码
traceWatch.stop();
traceWatch.start("function2");
TimeUnit.SECONDS.sleep(1); // 模拟业务代码
traceWatch.stop();
traceWatch.record("function1", 1); // 直接记录耗时
System.out.println(JSON.toJSONString(traceWatch.getTaskMap()));
}
}
/* output:
{"function2":[{"data":1000,"taskName":"function2"}],"function1":[{"data":1000,"taskName":"function1"},{"data":1,"taskName":"function1"}]}
*/public class TraceWatch {
/** Start time of the current task. */
private long startMs;
/** Name of the current task. */
@Nullable
private String currentTaskName;
@Getter
private final Map<String, List<TaskInfo>> taskMap = new HashMap<>();
/**
* 开始时间差类型指标记录，如果需要终止，请调用 {@link #stop()}
*
* @param taskName 指标名
*/
public void start(String taskName) throws IllegalStateException {
if (this.currentTaskName != null) {
throw new IllegalStateException("Can't start TraceWatch: it's already running");
}
this.currentTaskName = taskName;
this.startMs = TimeUtils.nowMs();
}
/**
* 终止时间差类型指标记录，调用前请确保已经调用
*/
public void stop() throws IllegalStateException {
if (this.currentTaskName == null) {
throw new IllegalStateException("Can't stop TraceWatch: it's not running");
}
long lastTime = TimeUtils.nowMs() - this.startMs;
TaskInfo info = new TaskInfo(this.currentTaskName, lastTime);
this.taskMap.computeIfAbsent(this.currentTaskName, e -> new LinkedList<>()).add(info);
this.currentTaskName = null;
}
/**
* 直接记录指标数据，不局限于时间差类型
* @param taskName 指标名
* @param data 指标数据
*/
public void record(String taskName, Object data) {
TaskInfo info = new TaskInfo(taskName, data);
this.taskMap.computeIfAbsent(taskName, e -> new LinkedList<>()).add(info);
}
@Getter
@AllArgsConstructor
public static final class TaskInfo {
private final String taskName;
private final Object data;
}
}我是仿照 org.springframework.util.StopWatch 的实现，写了 TraceWatch 类，这个方法提供了两种耗时统计的方法：
通过调用 Start(name) 和 Stop() 方法，进行耗时统计。
通过调用 Record(name, timeCost)，方法，直接记录耗时信息。
这种方式本质上和“时间差统计”是一致的，只是抽取了一层，稍微优雅了一点。
注：你可以根据自己的业务需要，自行修改 TraceWatch 内部的数据结构，我这里简单起见，内部的数据结构只是随便举了个例子。
三、高级方法
第二节提到的两种方法，用大白话来说都是“直来直去”的感觉，我们还可以尝试把代码写的更简便一点。
3.1 Function
在 jdk 1.8 中，引入了 java.util.function 包，通过该类提供的接口，能够实现在指定代码段的上下文执行额外代码的功能。
public class TraceWatch {
/** Start time of the current task. */
private long startMs;
/** Name of the current task. */
@Nullable
private String currentTaskName;
@Getter
private final Map<String, List<TaskInfo>> taskMap = new HashMap<>();
/**
* 开始时间差类型指标记录，如果需要终止，请调用 {@link #stop()}
*
* @param taskName 指标名
*/
public void start(String taskName) throws IllegalStateException {
if (this.currentTaskName != null) {
throw new IllegalStateException("Can't start TraceWatch: it's already running");
}
this.currentTaskName = taskName;
this.startMs = TimeUtils.nowMs();
}
/**
* 终止时间差类型指标记录，调用前请确保已经调用
*/
public void stop() throws IllegalStateException {
if (this.currentTaskName == null) {
throw new IllegalStateException("Can't stop TraceWatch: it's not running");
}
long lastTime = TimeUtils.nowMs() - this.startMs;
TaskInfo info = new TaskInfo(this.currentTaskName, lastTime);
this.taskMap.computeIfAbsent(this.currentTaskName, e -> new LinkedList<>()).add(info);
this.currentTaskName = null;
}
/**
* 直接记录指标数据，不局限于时间差类型
* @param taskName 指标名
* @param data 指标数据
*/
public void record(String taskName, Object data) {
TaskInfo info = new TaskInfo(taskName, data);
this.taskMap.computeIfAbsent(taskName, e -> new LinkedList<>()).add(info);
}
@Getter
@AllArgsConstructor
public static final class TaskInfo {
private final String taskName;
private final Object data;
}
}public class TraceHolder {
/**
* 有返回值调用
*/
public static <T> T run(TraceWatch traceWatch, String taskName, Supplier<T> supplier) {
try {
traceWatch.start(taskName);
return supplier.get();
} finally {
traceWatch.stop();
}
}
/**
* 无返回值调用
*/
public static void run(TraceWatch traceWatch, String taskName, IntConsumer function) {
try {
traceWatch.start(taskName);
function.accept(0);
} finally {
traceWatch.stop();
}
}
}这里我利用了 Supplier 和 IntConsumer 接口，对外提供了有返回值和无返回值得调用，在 TraceHolder 类中，在核心代码块的前后，分别调用了前文的 TraceWatch 的方法，实现了耗时统计的功能。
3.2 AutoCloseable
除了利用 Function 的特性，我们还可以使用 jdk 1.7 的 AutoCloseable 特性。说 AutoCloseable 可能有同学没听过，但是给大家展示下以下代码，就会立刻明白是什么东西了。
// 未使用 AutoCloseable
public static String readFirstLingFromFile(String path) throws IOException {
BufferedReader br = null;
try {
br = new BufferedReader(new FileReader(path));
return br.readLine();
} catch (IOException e) {
e.printStackTrace();
} finally {
if (br != null) {
br.close();
}
}
return null;
}
// 使用 AutoCloseable
public static String readFirstLineFromFile(String path) throws IOException {
try (BufferedReader br = new BufferedReader(new FileReader(path))) {
return br.readLine();
}
}在 try 后方可以加载一个实现了 AutoCloseable 接口的对象，该对象作用于整个 try 语句块中，并且在执行完毕后回调 AutoCloseable#close() 方法。
让我们对 TraceWatch 类进行改造：
1.实现 AutoCloseable 接口，实现 close() 接口：
@Override
public void close() {
this.stop();
}2.修改 start() 方法，使其支持链式调用：
public TraceWatch start(String taskName) throws IllegalStateException {
if (this.currentTaskName != null) {
throw new IllegalStateException("Can't start TraceWatch: it's already running");
}
this.currentTaskName = taskName;
this.startMs = TimeUtils.nowMs();
return this;
}public class AutoCloseableTest {
public static void main(String[] args) {
TraceWatch traceWatch = new TraceWatch();
try(TraceWatch ignored = traceWatch.start("function1")) {
try {
TimeUnit.SECONDS.sleep(1); // 模拟业务代码
} catch (InterruptedException e) {
e.printStackTrace();
}
}
try(TraceWatch ignored = traceWatch.start("function2")) {
try {
TimeUnit.SECONDS.sleep(1); // 模拟业务代码
} catch (InterruptedException e) {
e.printStackTrace();
}
}
try(TraceWatch ignored = traceWatch.start("function1")) {
try {
TimeUnit.SECONDS.sleep(1); // 模拟业务代码
} catch (InterruptedException e) {
e.printStackTrace();
}
}
System.out.println(JSON.toJSONString(traceWatch.getTaskMap()));
}
}
/* output:
{"function2":[{"data":1001,"taskName":"function2"}],"function1":[{"data":1002,"taskName":"function1"},{"data":1002,"taskName":"function1"}]}
*/四、总结
本文列举了四种统计代码耗时的方法：
1.时间差统计
2.StopWatch
3.Function
4.AutoCloseable
列举的方案是我目前能想到的方案。当然可能有更加优雅的方案，希望有相关经验的同学能在评论区一起交流下~
出处: https://jitwxs.cn/5aa91d10.html
关注GitHub今日热榜，专注挖掘好用的开发工具，致力于分享优质高效的工具、资源、插件等，助力开发者成长！
点个在看 你最好看
评论
什么是以太坊期货ETF？它们如何运作？
作者：Jagjit Singh，CoinTelegraph；编译：陶朱，金色财经一、以太坊期货 ETF 介绍以太坊期货 ETF 是追踪以太坊期货合约而非以太坊本身的投资基金。考虑一份承诺在未来某个时间以特定价格购买以太坊的合约。这些衍生品合约通过以太坊 (ETH) 期货交易所交易基金 (ETF) 进
区块链头条
0
字节面试：如何解决MQ消息积压问题？
面试题大全：www.javacn.siteMQ（Message Queue）消息积压问题指的是在消息队列中累积了大量未处理的消息，导致消息队列中的消息积压严重，超出系统处理能力，影响系统性能和稳定性的现象。1.消息积压是哪个环节的问题？MQ 执行有三大阶段：消息生产阶段。消息存储阶段。消息消费阶段。
Java中文社群
0
【第126期】效地利用AI辅助编程并提高编程效率
概述 AI可以在编程的多个环节中提供帮助，从而显著提高编程效率。同时，也要注意AI工具的选择和使用，确保它们能够真正提升你的工作效率，而不是成为额外的负担。通过这些工具通过不同的方式辅助编程，包括代码生成、错误检测与修复、代码审查、自动化测试、性能优化等，旨在提高编程效率和代码质量。开发者可以根据
前端微服务
0
如何动手做出一个 CPU，很简单
将Python客栈设为“星标⭐”第一时间收到最新资讯来源：无聊的闪客纯手工打造一个 CPU 这个事儿。在电子专业的同学眼里，很容易。在计算机专业的同学眼里，稍稍有点复杂，有的专业课的实验课可能会带着同学做一个，或者用 Logisim 这样的仿真软件去模拟实现一个。在非计算机专业的同学眼里，就有点不敢
Python客栈
0
会写代码的总理！全球第一“开源”名门望族
转自：OSC开源社区4 月 15 日，新加坡总理公署发表声明宣布，总理李显龙将于 5 月 15 日辞职，并正式交棒给副总理兼财政部长黄循财。对于李氏家族下一代是否会继续活跃在新加坡政坛，目前外界说法不一。但在开源圈里，李氏家族绝对有一席之地。李显龙有 4 名子女，其本人、次子，以及幼子都有非常专业的
开源前哨
0
面试官：MySQL 上亿大表，如何深度优化？
来源：cnblogs.com/YangJiaXin/p/10828244.html背景分析测试实施索引优化后delete大表优化为小批量删除总结前段时间刚入职一家公司，就遇上这事！背景XX实例（一主一从）xxx告警中每天凌晨在报SLA报警，该报警的意思是存在一定的主从延迟（若在此时发生主从切换，需要
好好学java
0
原来Matplotlib能画股票K线图！！附代码
之前在一篇文章中提到Matplotlib可视化，甚至可以用来画股票K线图，许多同学也在问代码，这次来发个文回应下。Python用matplotlib绘制K线图，需要配合talib、numpy、mpl_finance等第三方库来使用，效果展示如下：简单讲讲K线图的结构，我不搞股票，所以不太懂，特地查了
Python大数据分析
9
文末送书 | 大模型时代下如何学习云原生
《containerd 原理剖析与实战》新书内购中，点击阅读原文，限时 69.9 元购买。文末免费赠书大模型与云原生近年来，大语言模型的热度可谓是愈发高涨，尤其是今年年初 Sora 的出现，更是让全球再次看到了AIGC 的巨大威力。Sora 生成实例视频---几头巨大的长毛猛犸踏着积雪的草地而来在当
云原生实验室
10