前两天写了一篇关于《阿里Java开发手册中的 1 个bug》的文章,评论区有点炸锅了,基本分为两派,支持老王的和质疑老王的。java
首先来讲,不管是那一方,我都真诚的感谢大家。特别是「二师兄」,原本是打算周五晚上好好休息一下的(周五晚上发布的文章),结果由于和我讨论这个问题,一直搞到晚上 12 点左右,能够看出,他对技术的那份痴迷。这一点咱们是同样的,和阅读本文的你同样,咱们属于一类人,一类对技术无限痴迷的人。spring
其实在准备发这篇文章时,已经预料到这种局面了,当你提出质疑时,不管对错,必定有相反的声音,由于别人也有质疑的权利,而此刻你要作的,就是尽可能保持冷静,用客观的态度去理解和验证这些问题。而这些问题(不一样的声音)终将成为一笔宝贵的财富,由于你在这个验证的过程当中必定会有所收获。编程
同时我也但愿个人理解是错的,由于和你们同样,也是阿里《Java开发手册》的忠实“信徒”,只是意外的窥见了“不一样”,而后顺手把本身的思路和成果分享给了你们。app
但我也相信,任何“权威”都有犯错的可能,老祖宗曾告诉过咱们“人非圣贤孰能无过”。我倒不是非要纠结谁对谁错,相反我认为一味的追求谁对谁错是件很是幼稚的事情,只有小孩子才这样作,咱们要作的是经过辩论这件事的“对与错”,学习到更多的知识,帮助咱们更好的成长,这才是我今天这篇文章诞生的意义。框架
乔布斯曾说过:我最喜欢和聪明人一块儿工做,由于彻底不用顾忌他们的尊严。我倒不是聪明人,但我知道任何一件“错事”的背后,必定有它的价值。所以我不怕被“打脸”,若是想要快速成长的话,我劝你也要这样。工具
好了,就聊这么多,接下来我们进入今天正题。性能
持不一样见解的朋友的主要观点有如下这些:学习
我把这些意见整理了一下,其实说的是一件事,咱们先来看原文的内容。测试
在《Java开发手册》泰山版(最新版)的第二章第三小节的第 4 条规范中指出:ui
【强制】在日志输出时,字符串变量之间的拼接使用占位符的方式。说明:由于 String 字符串的拼接会使用 StringBuilder 的 append() 方式,有必定的性能损耗。使用占位符仅 是替换动做,能够有效提高性能。
正例:logger.debug("Processing trade with id: {} and symbol: {}", id, symbol);
反对者(注意这个“反对者”不是贬义词,而是为了更好的区分角色)的意思是这样的:
使用占位符会先判断日志的输出级别再决定是否要进行拼接输出,而直接使用 StringBuilder 的方式会先进行拼接再进行判断,这样的话,当日志级别设置的比较高时,由于 StringBuilder 是先拼接再判断的,所以形成系统资源的浪费,因此使用占位符的方式比 StringBuilder 的方式性能要高。
咱先放下反对者说的这个含义在阿里《Java开发手册》中是否有体现,由于我确实没有看出来,我们先顺着这个思路来证明一下这个结论是否正确。
仍是老规矩,我们用数据和代码说话,为了测试 JMH(测试工具)能和 Spring Boot 很好的结合,首先咱们要作的就是先测试一下日志输出级别设置,是否能在 JMH 的测试代码中生效。
那么接下来咱们先来编写「日志级别设置」的测试代码:
import lombok.extern.slf4j.Slf4j; 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.springframework.boot.SpringApplication; import java.util.concurrent.TimeUnit; @BenchmarkMode(Mode.AverageTime) // 测试完成时间 @OutputTimeUnit(TimeUnit.NANOSECONDS) @Warmup(iterations = 2, time = 2, timeUnit = TimeUnit.SECONDS) // 预热 2 轮,每次 2s @Measurement(iterations = 5, time = 3, timeUnit = TimeUnit.SECONDS) // 测试 5 轮,每次 3s @Fork(1) // fork 1 个线程 @State(Scope.Thread) // 每一个测试线程一个实例 @Slf4j public class LogPrintAmend { public static void main(String[] args) throws RunnerException { // 启动基准测试 Options opt = new OptionsBuilder() .include(LogPrintAmend.class.getName() + ".*") // 要导入的测试类 .build(); new Runner(opt).run(); // 执行测试 } @Setup public void init() { // 启动 spring boot SpringApplication.run(DemoApplication.class); } @Benchmark public void logPrint() { log.debug("show debug"); log.info("show info"); log.error("show error"); } }
在测试代码中,咱们使用了 3 个级别的日志输出指令:debug
级别、 info
级别和 error
级别。
而后咱们再在配置文件(application.properties)中的设置日志的输出级别,配置以下:
logging.level.root=info
能够看出咱们把全部的日志输出级别设置成了 info
级别,而后咱们执行以上程序,执行结果以下:
从上图中咱们能够看出,日志只输出了 info
和 error
级别,也就是说咱们设置的日志输出级别生效了,为了保证万无一失,咱们再把日志的输出级别降为 debug
级别,测试的结果以下图所示:
从上面的结果能够看出,咱们设置的日志级别没有任何问题,也就是说,JMH 框架能够很好的搭配 SpringBoot 来使用。
小贴士,日志的等级权重为:TRACE < DEBUG < INFO < WARN < ERROR < FATAL
有了上面日志等级的设置基础以后,咱们来测试一下,若是先拼接字符串再判断输出的性能和占位符的性能评测结果,完整的测试代码以下:
import lombok.extern.slf4j.Slf4j; 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.springframework.boot.SpringApplication; import java.util.concurrent.TimeUnit; @BenchmarkMode(Mode.AverageTime) // 测试完成时间 @OutputTimeUnit(TimeUnit.NANOSECONDS) @Warmup(iterations = 2, time = 2, timeUnit = TimeUnit.SECONDS) // 预热 2 轮,每次 2s @Measurement(iterations = 5, time = 3, timeUnit = TimeUnit.SECONDS) // 测试 5 轮,每次 3s @Fork(1) // fork 1 个线程 @State(Scope.Thread) // 每一个测试线程一个实例 @Slf4j public class LogPrintAmend { private final static int MAX_FOR_COUNT = 100; // for 循环次数 public static void main(String[] args) throws RunnerException { // 启动基准测试 Options opt = new OptionsBuilder() .include(LogPrintAmend.class.getName() + ".*") // 要导入的测试类 .build(); new Runner(opt).run(); // 执行测试 } @Setup public void init() { SpringApplication.run(DemoApplication.class); } @Benchmark public 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("."); // 再判断 if (log.isInfoEnabled()) { log.info(sb.toString()); } } } @Benchmark public void logPrint() { for (int i = 0; i < MAX_FOR_COUNT; i++) { // 循环的意图是为了放大性能测试效果 log.info("Hello, {}.Hello, {}.Hello, {}.", "Java", "Redis", "MySQL"); } } }
能够看出代码中使用了 info
的日志数据级别,那么此时咱们再将配置文件中的日志级别设置为大于 info
的 error
级别,而后执行以上代码,测试结果以下:
哇,测试结果然使人满意。从上面的结果能够看出使用占位符的方式的性能,真的比 StringBuilder
的方式高不少,这就说明阿里的《Java开发手册》说的没问题喽。
但事情并无那么简单,就好比你正在路上走着,迎面而来了一个自行车,眼看就要撞到你了,此时你会怎么作?毫无疑问你会下意识的躲开。
那么对于上面的那个评测也是同样,为何要在字符串拼接以后再进行判断呢?
若是编程已是你的一份正式职业,那么先判断再拼接字符串是最基础的职业技能要求,这和你会下意识的躲开迎面相撞的自行车的道理是同样的,在你彻底有能力规避问题的时候,必定是先规避问题,再进行其余操做的,不然在团队 review 代码的时候或者月底裁人的时候时,你必定是首选的“受害”对象了。由于像这么简单的(错误)问题,只有刚入门的新手才可能会出现。
那么按照一个程序最基本的要求,咱们应该这样写代码:
import lombok.extern.slf4j.Slf4j; 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.springframework.boot.SpringApplication; import java.util.concurrent.TimeUnit; @BenchmarkMode(Mode.AverageTime) // 测试完成时间 @OutputTimeUnit(TimeUnit.NANOSECONDS) @Warmup(iterations = 2, time = 2, timeUnit = TimeUnit.SECONDS) // 预热 2 轮,每次 2s @Measurement(iterations = 5, time = 3, timeUnit = TimeUnit.SECONDS) // 测试 5 轮,每次 3s @Fork(1) // fork 1 个线程 @State(Scope.Thread) // 每一个测试线程一个实例 @Slf4j public class LogPrintAmend { private final static int MAX_FOR_COUNT = 100; // for 循环次数 public static void main(String[] args) throws RunnerException { // 启动基准测试 Options opt = new OptionsBuilder() .include(LogPrintAmend.class.getName() + ".*") // 要导入的测试类 .build(); new Runner(opt).run(); // 执行测试 } @Setup public void init() { SpringApplication.run(DemoApplication.class); } @Benchmark public void appendLogPrint() { for (int i = 0; i < MAX_FOR_COUNT; i++) { // 循环的意图是为了放大性能测试效果 // 再判断 if (log.isInfoEnabled()) { 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()); } } } @Benchmark public void logPrint() { for (int i = 0; i < MAX_FOR_COUNT; i++) { // 循环的意图是为了放大性能测试效果 log.info("Hello, {}.Hello, {}.Hello, {}.", "Java", "Redis", "MySQL"); } } }
甚至是把 if
判断提到 for
循环外,但本文的 for
不表明具体的业务,而是为了更好的放大测试效果而写的代码,所以咱们会把判断写到 for
循环内。
那么此时咱们再来执行测试的代码,执行结果以下图所示:
从上述结果能够看出,使用先判断再拼接字符串的方式仍是要比使用占位符的方式性能要高。
那么,咱们依然没有办法证实阿里《Java开发手册》中的占位符性能高的结论。
因此我依旧保持个人见解,使用占位符而非字符串拼接,主要能够保证代码的优雅性,能够在代码中少些一些逻辑判断,但这样写和性能无关。
在上面的评测过程当中,咱们发现日志的输出格式很是“乱”,那有没有办法能够格式化日志呢?
答案是:有的,默认日志的输出效果以下:
格式化日志能够经过配置 Spring Boot 中的 logging.pattern.console
选项实现的,配置示例以下:
logging.pattern.console=%d | %msg %n
日志的输出结果以下:
能够看出,格式化日志以后,内容简洁多了,但千万不能由于简洁,而遗漏输出关键性的调试信息。
本文咱们测试了读者提出质疑的字符串拼接和占位符的性能评测,发现占位符方式性能高的观点依然无从考证,因此咱们的基本见解仍是,使用占位符的方式更加优雅,能够经过更少的代码实现更多的功能;至于性能方面,只能说还不错,但不能说很优秀。在文章的最后咱们讲了 Spring Boot 日志格式化的知识,但愿本文能够切实的帮助到你,也欢迎你在评论区留言和我互动。
原创不易,都看到这了,点个「赞」再走呗,这是对我最大的支持与鼓励,谢谢你!