這樣統(tǒng)計(jì)代碼執(zhí)行耗時(shí)，才足夠優(yōu)雅！

一、前言

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

可能也是受限于 Java 的語(yǔ)言特性，總覺(jué)得代碼寫(xiě)起來(lái)不夠優(yōu)雅，大量的耗時(shí)統(tǒng)計(jì)代碼，干擾了業(yè)務(wù)邏輯。特別是開(kāi)發(fā)功能的時(shí)候，有個(gè)感受就是剛剛開(kāi)發(fā)完代碼很清爽優(yōu)雅，結(jié)果加了一大堆輔助代碼后，整個(gè)代碼就變得臃腫了，自己看著都挺難受。因此總想著能不能把這塊寫(xiě)的更優(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í)間差類(lèi)型指標(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í)間差類(lèi)型指標(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í)間差類(lèi)型
?????*??@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)，寫(xiě)了 TraceWatch 類(lèi)，這個(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é)提到的兩種方法，用大白話(huà)來(lái)說(shuō)都是“直來(lái)直去”的感覺(jué)，我們還可以嘗試把代碼寫(xiě)的更簡(jiǎn)便一點(diǎn)。

3.1 Function

在 jdk 1.8 中，引入了 java.util.function 包，通過(guò)該類(lèi)提供的接口，能夠?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 類(lèi)中，在核心代碼塊的前后，分別調(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 類(lèi)進(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

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