本來打算寫一篇《阿里巴巴為什么不允許日志輸出時，使用字符串拼接？》的文章，主要是想從性能方面來說此問題，可在文章寫到一半進行性能測試時，卻發現了一個異常問題，實際測試的結果和手冊上描述的結果是截然相反的！

阿里巴巴的《Java開發手冊》泰山版（最新版）是這樣描述的，它在第二章第三小節的第 4 條規范中指出：

【強制】在日志輸出時，字符串變量之間的拼接使用占位符的方式。

說明：因為 String 字符串的拼接會使用 StringBuilder 的 append() 方式，有一定的性能損耗。使用占位符僅 是替換動作，可以有效提升性能。

正例：logger.debug("Processing trade with id: {} and symbol: {}", id, symbol);

從上述描述中可以看出，阿里強制要求在日志輸出時必須使用占位符的方式進行字符串拼接，因為這樣可以有效的提高程序的性能。

然而當我們使用 Oracle 官方提供的 JMH（Java Microbenchmark Harness，JAVA 微基準測試套件）框架來測試時，卻發現結果和手冊上描述的完全不一樣。

性能測試

本文我們借助 Spring Boot 2.2.6 來完成測試，首先我們先在 Spring Boot 的 pom.xml 中添加 JMH 框架的依賴：

<!--?https://mvnrepository.com/artifact/org.openjdk.jmh/jmh-core?--> <dependency><groupId>org.openjdk.jmh</groupId><artifactId>jmh-core</artifactId><version>1.23</version> </dependency> <!--?https://mvnrepository.com/artifact/org.openjdk.jmh/jmh-generator-annprocess?--> <dependency><groupId>org.openjdk.jmh</groupId><artifactId>jmh-generator-annprocess</artifactId><version>1.23</version><scope>provided</scope> </dependency>

這里需要注意一下，一般的項目我們只需要添加 jmh-core?的依賴包就可以了，但如果是 Spring Boot 項目的話，我們還必須添加 jmh-generator-annprocess?包依賴，并且要把 scope?設置為 provided 類型，如果使用它的默認值 test?就會導致程序報錯 Unable to find the resource: /META-INF/BenchmarkList。

scope 值說明：

• compile：默認值，它表示被依賴項目需要參與當前項目的編譯、測試和運行等階段，在打包時通常也需要添加進去；

• test：表示依賴項目僅僅參與測試相關的工作，在編譯和運行環境下都不會被使用，更別說打包了；

• provided：適用于編譯和測試的階段，他不會被打包到 lib 目錄下；

• runntime：僅僅適用于運行環境，在編譯和測試環境下都不會被使用。

緊接著，我們編寫了完整的測試代碼：

import?org.openjdk.jmh.annotations.*; import?org.openjdk.jmh.runner.Runner; import?org.openjdk.jmh.runner.RunnerException; import?org.openjdk.jmh.runner.options.Options; import?org.openjdk.jmh.runner.options.OptionsBuilder; import?org.slf4j.Logger; import?org.slf4j.LoggerFactory; import?org.springframework.web.bind.annotation.RequestMapping; import?org.springframework.web.bind.annotation.RestController;import?java.util.concurrent.TimeUnit;@BenchmarkMode(Mode.AverageTime)?//?測試完成時間 @OutputTimeUnit(TimeUnit.NANOSECONDS) @Warmup(iterations?=?2,?time?=?1,?timeUnit?=?TimeUnit.SECONDS)?//?預熱?2?輪，每次?1s @Measurement(iterations?=?5,?time?=?3,?timeUnit?=?TimeUnit.SECONDS)?//?測試?5?輪，每次?3s @Fork(1)?//?fork?1?個線程 @State(Scope.Thread)?//?每個測試線程一個實例 @RestController @RequestMapping("/log") public?class?LogPrint?{private?final?Logger?log?=?LoggerFactory.getLogger(LogPrint.class);private?final?static?int?MAX_FOR_COUNT?=?100;?//?for?循環次數public?static?void?main(String[]?args)?throws?RunnerException?{//?啟動基準測試Options?opt?=?new?OptionsBuilder().include(LogPrint.class.getName()?+?".*")?//?要導入的測試類.build();new?Runner(opt).run();?//?執行測試}@Benchmarkpublic?void?appendLogPrint()?{for?(int?i?=?0;?i?<?MAX_FOR_COUNT;?i++)?{?//?循環的意圖是為了放大性能測試效果StringBuilder?sb?=?new?StringBuilder();sb.append("Hello,?");sb.append("Java");sb.append(".");sb.append("Hello,?");sb.append("Redis");sb.append(".");sb.append("Hello,?");sb.append("MySQL");sb.append(".");log.info(sb.toString());}}@Benchmarkpublic?void?logPrint()?{for?(int?i?=?0;?i?<?MAX_FOR_COUNT;?i++)?{?//?循環的意圖是為了放大性能測試效果log.info("Hello,?{}.Hello,?{}.Hello,?{}.",?"Java",?"Redis",?"MySQL");}} }

測試結果如下：

從上述結果可以看出直接使用 StringBuilder?拼接的方式顯然要比使用占位符的方式性能要高，難道是我搞錯了？

備注：測試環境為 Spring Boot 2.2.6 RELEASE、JDK 8（JDK 1.8.0_10）、MacOS（MacMini 2018）

源碼分析

抱著懷疑的態度，我們打開了 slf4j 的源碼，看看占位符的底層方法到底是如何實現的，于是我就順著 log.info?方法找到了占位符最終的實現源碼：

final?public?static?FormattingTuple?arrayFormat(final?String?messagePattern,?final?Object[]?argArray,?Throwable?throwable)?{if?(messagePattern?==?null)?{return?new?FormattingTuple(null,?argArray,?throwable);}if?(argArray?==?null)?{return?new?FormattingTuple(messagePattern);}int?i?=?0;int?j;//?use?string?builder?for?better?multicore?performanceStringBuilder?sbuf?=?new?StringBuilder(messagePattern.length()?+?50);int?L;//?for?循環替換占位符for?(L?=?0;?L?<?argArray.length;?L++)?{j?=?messagePattern.indexOf(DELIM_STR,?i);if?(j?==?-1)?{//?no?more?variablesif?(i?==?0)?{?//?this?is?a?simple?stringreturn?new?FormattingTuple(messagePattern,?argArray,?throwable);}?else?{?//?add?the?tail?string?which?contains?no?variables?and?return//?the?result.sbuf.append(messagePattern,?i,?messagePattern.length());return?new?FormattingTuple(sbuf.toString(),?argArray,?throwable);}}?else?{if?(isEscapedDelimeter(messagePattern,?j))?{if?(!isDoubleEscaped(messagePattern,?j))?{L--;?//?DELIM_START?was?escaped,?thus?should?not?be?incrementedsbuf.append(messagePattern,?i,?j?-?1);sbuf.append(DELIM_START);i?=?j?+?1;}?else?{//?The?escape?character?preceding?the?delimiter?start?is//?itself?escaped:?"abc?x:\\{}"//?we?have?to?consume?one?backward?slashsbuf.append(messagePattern,?i,?j?-?1);deeplyAppendParameter(sbuf,?argArray[L],?new?HashMap<Object[],?Object>());i?=?j?+?2;}}?else?{//?normal?casesbuf.append(messagePattern,?i,?j);deeplyAppendParameter(sbuf,?argArray[L],?new?HashMap<Object[],?Object>());i?=?j?+?2;}}}//?append?the?characters?following?the?last?{}?pair.sbuf.append(messagePattern,?i,?messagePattern.length());return?new?FormattingTuple(sbuf.toString(),?argArray,?throwable); }

從上述源碼可以看出，所謂的占位符其實底層也是使用 StringBuilder?來實現的，怪不得性能不如直接使用 StringBuilder。因為在進行占位符替換的時候，還經過了一些列的驗證才進行替換的，而直接使用 StringBuilder 則可以省去這部分效驗的工作。

為了保證我沒有搞錯，于是我使用 Idea 開啟了調試模式，調試的結果如下圖所示：

從上圖可以看出，此方法就是占位符的實際執行方法，那也就是說，手冊上寫的性能問題確實是錯的。

擴展篇

我們在 Spring Boot 中使用日志通常會這樣寫：

private?final?Logger?log?=?LoggerFactory.getLogger(LogPrint.class);

并且每個類中都要寫這樣一行代碼，未免有些麻煩。

此時我們可以使用 @Slf4j?注解來替代上面的那行 Logger?對象創建的代碼，完整使用示例如下：

import?lombok.extern.slf4j.Slf4j; import?org.junit.jupiter.api.Test;@Slf4j class?LogTest?{@Testvoid?show()?{log.debug("Hello,?{}.",?"Debug");log.info("Hello,?{}.",?"Info");log.error("Hello,?{}.",?"Error");} }

程序的執行結果：

14:33:18.377 [main] DEBUG com.example.demo.LogTestTest - Hello, Debug.

14:33:18.382 [main] INFO com.example.demo.LogTestTest - Hello, Info.

14:33:18.382 [main] ERROR com.example.demo.LogTestTest - Hello, Error.

從上述結果可以看出，日志已經正常輸出到控制臺了。

注意：@Slf4j 注解屬于 lombok，因此要想在項目中使用 @Slf4j 注解，需要保證項目中已經添加了 lombok 的依賴。

總結

在進行日志輸出時，字符串變量之間的拼接要使用占位符的方式，因為這樣寫會比較優雅。我們查了 slf4j 的源碼發現，占位符的底層也是通過 StringBuilder?拼接來實現的。

想知道更多？掃描下面的二維碼關注我

后臺回復”加群“獲取公眾號專屬群聊入口

【原創系列 | 精彩推薦】

• Paxos、Raft不是一致性算法嘛？

• 越說越迷糊的CAP

• 分布式事務科普——初識篇

• 分布式事務科普——終結篇

• 面試官居然問我Raft為什么會叫做Raft!

• 面試官給我挖坑：URI中的//有什么用

• 面試官給我挖坑：a[i][j]和a[j][i]有什么區別？

• 面試官給我挖坑：單機并發TCP連接數到底有多少？
  

• 網關Zuul科普

• 網關Spring Cloud?Gateway科普

• Nginx架構原理科普

• OpenResty概要及原理科普

• 微服務網關 Kong 科普

• 云原生網關Traefik科普
  

點個在看少個 bug?????

總結

以上是生活随笔為你收集整理的阿里《Java开发手册》中的 1 个bug！的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。