如何優(yōu)雅的統(tǒng)計(jì)代碼耗時(shí)？

程序員的成長(zhǎng)之路

互聯(lián)網(wǎng)/程序員/技術(shù)/資料共享?

關(guān)注

閱讀本文大概需要 6 分鐘。

來(lái)自：jitwxs.cn/5aa91d10.html

今天，跟大家分享一下，如何在代碼中，統(tǒng)計(jì)接口耗時(shí)，最優(yōu)雅，性能最高，接下來(lái)我將介紹4種統(tǒng)計(jì)方式。

如果你有更好的方式，歡迎文末留言區(qū)，交流。

一、前言

代碼耗時(shí)統(tǒng)計(jì)在日常開(kāi)發(fā)中算是一個(gè)十分常見(jiàn)的需求，特別是在需要找出代碼性能瓶頸時(shí)。

可能也是受限于 Java 的語(yǔ)言特性，總覺(jué)得代碼寫起來(lái)不夠優(yōu)雅，大量的耗時(shí)統(tǒng)計(jì)代碼，干擾了業(yè)務(wù)邏輯。特別是開(kāi)發(fā)功能的時(shí)候，有個(gè)感受就是剛剛開(kāi)發(fā)完代碼很清爽優(yōu)雅，結(jié)果加了一大堆輔助代碼后，整個(gè)代碼就變得臃腫了，自己看著都挺難受。因此總想著能不能把這塊寫的更優(yōu)雅一點(diǎn)，今天本文就嘗試探討下“代碼耗時(shí)統(tǒng)計(jì)”這一塊。

在開(kāi)始正文前，先說(shuō)下前提，“代碼耗時(shí)統(tǒng)計(jì)”的并不是某個(gè)方法的耗時(shí)，而是任意代碼段之間的耗時(shí)。這個(gè)代碼段，可能是一個(gè)方法中的幾行代碼，也有可能是從這個(gè)方法的某一行到另一個(gè)被調(diào)用方法的某一行，因此通過(guò) AOP 方式是不能實(shí)現(xiàn)這個(gè)需求的。

二、常規(guī)方法

2.1 時(shí)間差統(tǒng)計(jì)

這種方式是最簡(jiǎn)單的方法，記錄下開(kāi)始時(shí)間，再記錄下結(jié)束時(shí)間，計(jì)算時(shí)間差即可。

public?class?TimeDiffTest?{
????public?static?void?main(String[]?args)?throws?InterruptedException?{
????????final?long?startMs?=?TimeUtils.nowMs();

????????TimeUnit.SECONDS.sleep(5);?//?模擬業(yè)務(wù)代碼

????????System.out.println("timeCost:?"?+?TimeUtils.diffMs(startMs));
????}
}

/*?output:
timeCost:?5005
*/
public?class?TimeUtils?{
????/**
?????*?@return?當(dāng)前毫秒數(shù)
?????*/
????public?static?long?nowMs()?{
????????return?System.currentTimeMillis();
????}

????/**
?????*?當(dāng)前毫秒與起始毫秒差
?????*?@param?startMillis?開(kāi)始納秒數(shù)
?????*?@return?時(shí)間差
?????*/
????public?static?long?diffMs(long?startMillis)?{
???????return?diffMs(startMillis,?nowMs());
????}
}

這種方式的優(yōu)點(diǎn)是實(shí)現(xiàn)簡(jiǎn)單，利于理解；缺點(diǎn)就是對(duì)代碼的侵入性較大，看著很傻瓜，不優(yōu)雅。

2.2 StopWatch

第二種方式是參考 StopWatch ，StopWatch 通常被用作統(tǒng)計(jì)代碼耗時(shí)，各個(gè)框架和 Common 包都有自己的實(shí)現(xiàn)。

public?class?TraceWatchTest?{
????public?static?void?main(String[]?args)?throws?InterruptedException?{
????????TraceWatch?traceWatch?=?new?TraceWatch();

????????traceWatch.start("function1");
????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????traceWatch.stop();

????????traceWatch.start("function2");
????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????traceWatch.stop();

????????traceWatch.record("function1",?1);?//?直接記錄耗時(shí)

????????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>?taskMap?=?new?HashMap<>();

????/**
?????*?開(kāi)始時(shí)間差類型指標(biāo)記錄，如果需要終止，請(qǐng)調(diào)用?{@link?#stop()}
?????*
?????*?@param?taskName?指標(biāo)名
?????*/
????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();
????}

????/**
?????*?終止時(shí)間差類型指標(biāo)記錄，調(diào)用前請(qǐng)確保已經(jīng)調(diào)用
?????*/
????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;
????}

????/**
?????*?直接記錄指標(biāo)數(shù)據(jù)，不局限于時(shí)間差類型
?????*??@param?taskName?指標(biāo)名
?????*?@param?data?指標(biāo)數(shù)據(jù)
?????*/
????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?的實(shí)現(xiàn)，寫了 TraceWatch 類，這個(gè)方法提供了兩種耗時(shí)統(tǒng)計(jì)的方法：

通過(guò)調(diào)用?Start(name)?和?Stop()?方法，進(jìn)行耗時(shí)統(tǒng)計(jì)。通過(guò)調(diào)用?Record(name, timeCost)，方法，直接記錄耗時(shí)信息。這種方式本質(zhì)上和“時(shí)間差統(tǒng)計(jì)”是一致的，只是抽取了一層，稍微優(yōu)雅了一點(diǎn)。

注：你可以根據(jù)自己的業(yè)務(wù)需要，自行修改?TraceWatch?內(nèi)部的數(shù)據(jù)結(jié)構(gòu)，我這里簡(jiǎn)單起見(jiàn)，內(nèi)部的數(shù)據(jù)結(jié)構(gòu)只是隨便舉了個(gè)例子。

三、高級(jí)方法

第二節(jié)提到的兩種方法，用大白話來(lái)說(shuō)都是“直來(lái)直去”的感覺(jué)，我們還可以嘗試把代碼寫的更簡(jiǎn)便一點(diǎn)。

3.1 Function

在 jdk 1.8 中，引入了?java.util.function?包，通過(guò)該類提供的接口，能夠?qū)崿F(xiàn)在指定代碼段的上下文執(zhí)行額外代碼的功能。

public?class?TraceHolderTest?{
????public?static?void?main(String[]?args)?{
????????TraceWatch?traceWatch?=?new?TraceWatch();

????????TraceHolder.run(traceWatch,?"function1",?i?->?{
????????????try?{
????????????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????????}?catch?(InterruptedException?e)?{
????????????????e.printStackTrace();
????????????}
????????});

????????String?result?=?TraceHolder.run(traceWatch,?"function2",?()?->?{
????????????try?{
????????????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????????????return?"YES";
????????????}?catch?(InterruptedException?e)?{
????????????????e.printStackTrace();
????????????????return?"NO";
????????????}
????????});

????????TraceHolder.run(traceWatch,?"function1",?i?->?{
????????????try?{
????????????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????????}?catch?(InterruptedException?e)?{
????????????????e.printStackTrace();
????????????}
????????});

????????System.out.println(JSON.toJSONString(traceWatch.getTaskMap()));
????}
}

/*?output:
{"function2":[{"data":1004,"taskName":"function2"}],"function1":[{"data":1001,"taskName":"function1"},{"data":1002,"taskName":"function1"}]}
*/
public?class?TraceHolder?{
????/**
?????*?有返回值調(diào)用
?????*/
????public?static??T?run(TraceWatch?traceWatch,?String?taskName,?Supplier?supplier)?{
????????try?{
????????????traceWatch.start(taskName);

????????????return?supplier.get();
????????}?finally?{
????????????traceWatch.stop();
????????}
????}

????/**
?????*?無(wú)返回值調(diào)用
?????*/
????public?static?void?run(TraceWatch?traceWatch,?String?taskName,?IntConsumer?function)?{
????????try?{
????????????traceWatch.start(taskName);

????????????function.accept(0);
????????}?finally?{
????????????traceWatch.stop();
????????}
????}
}

這里我利用了?Supplier?和?IntConsumer?接口，對(duì)外提供了有返回值和無(wú)返回值得調(diào)用，在 TraceHolder 類中，在核心代碼塊的前后，分別調(diào)用了前文的?TraceWatch?的方法，實(shí)現(xiàn)了耗時(shí)統(tǒng)計(jì)的功能。

3.2 AutoCloseable

除了利用?Function?的特性，我們還可以使用 jdk 1.7 的?AutoCloseable?特性。說(shuō)?AutoCloseable?可能有同學(xué)沒(méi)聽(tīng)過(guò)，但是給大家展示下以下代碼，就會(huì)立刻明白是什么東西了。

//?未使用?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?后方可以加載一個(gè)實(shí)現(xiàn)了?AutoCloseable?接口的對(duì)象，該對(duì)象作用于整個(gè)?try?語(yǔ)句塊中，并且在執(zhí)行完畢后回調(diào)?AutoCloseable#close()?方法。

讓我們對(duì) TraceWatch 類進(jìn)行改造：

實(shí)現(xiàn)?AutoCloseable?接口，實(shí)現(xiàn)?close()?接口：

@Override
public?void?close()?{
????this.stop();
}

修改?start()?方法，使其支持鏈?zhǔn)秸{(diào)用：

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);?//?模擬業(yè)務(wù)代碼
????????????}?catch?(InterruptedException?e)?{
????????????????e.printStackTrace();
????????????}
????????}

????????try(TraceWatch?ignored?=?traceWatch.start("function2"))?{
????????????try?{
????????????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????????}?catch?(InterruptedException?e)?{
????????????????e.printStackTrace();
????????????}
????????}

????????try(TraceWatch?ignored?=?traceWatch.start("function1"))?{
????????????try?{
????????????????TimeUnit.SECONDS.sleep(1);?//?模擬業(yè)務(wù)代碼
????????????}?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"}]}
*/

四、總結(jié)

本文列舉了四種統(tǒng)計(jì)代碼耗時(shí)的方法：

• 時(shí)間差統(tǒng)計(jì)
• StopWatch
• Function
• AutoCloseable

列舉的方案是我目前能想到的方案。

推薦閱讀：

我用Java幾分鐘處理完30億個(gè)數(shù)據(jù)...

MySQL 去重的 3 種方法，還有誰(shuí)不會(huì)？！

互聯(lián)網(wǎng)初中高級(jí)大廠面試題(9個(gè)G)

內(nèi)容包含Java基礎(chǔ)、JavaWeb、MySQL性能優(yōu)化、JVM、鎖、百萬(wàn)并發(fā)、消息隊(duì)列、高性能緩存、反射、Spring全家桶原理、微服務(wù)、Zookeeper......等技術(shù)棧！

?戳閱讀原文領(lǐng)取！? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ??朕已閱?