驳《阿里「Java开发手册」中的1个bug》？

太过爱你忘了你带给我的痛 2023-10-06 10:46 32阅读 0赞

![format_png][]

这是我的第 211 期分享

作者 | 王磊

来源 | Java中文社群（ID：javacn666）

转载请联系授权（微信ID：GG\_Stone）

前两天写了一篇关于[《阿里Java开发手册中的 1 个bug》][Java_ 1 _bug]的文章，评论区有点炸锅了，基本分为两派，支持老王的和质疑老王的。

首先来说，无论是那一方，我都真诚的感谢你们。特别是「二师兄」，本来是打算周五晚上好好休息一下的（周五晚上发布的文章），结果因为和我讨论这个问题，一直搞到晚上 12 点左右，可以看出，他对技术的那份痴迷。这一点我们是一样的，和阅读本文的你一样，**我们属于一类人，一类对技术无限痴迷的人**。

![format_png 1][]

### 对与错的意义 ###

其实在准备发这篇文章时，已经预料到这种局面了，当你提出质疑时，无论对错，一定有相反的声音，因为别人也有质疑的权利，而此刻你要做的，就是尽量保持冷静，用客观的态度去理解和验证这些问题。而这些问题（不同的声音）终将成为一笔宝贵的财富，因为你在这个验证的过程中一定会有所收获。

同时我也希望我的理解是错的，因为和大家一样，也是阿里《Java开发手册》的忠实“信徒”，只是意外的窥见了“不同”，然后顺手把自己的思路和成果分享给了大家。

但我也相信，任何“权威”都有犯错的可能，老祖宗曾告诉过我们“人非圣贤孰能无过”。我倒不是非要纠结谁对谁错，相反**我认为一味的追求谁对谁错是件非常幼稚的事情**，只有小孩子才这样做，我们要做的是**通过辩论这件事的“对与错”，学习到更多的知识，帮助我们更好的成长**，这才是我今天这篇文章诞生的意义。

乔布斯曾说过：**我最喜欢和聪明人一起工作，因为完全不用顾忌他们的尊严**。我倒不是聪明人，但我知道任何一件“错事”的背后，一定有它的价值。因此我不怕被“打脸”，如果想要快速成长的话，我劝你也要这样。

好了，就聊这么多，接下来咱们进入今天正题。

### 反对的声音 ###

持不同看法的朋友的主要观点有以下这些：

![format_png 2][]

![format_png 3][]

我把这些意见整理了一下，其实说的是一件事，我们先来看原文的内容。

在《Java开发手册》泰山版（最新版）的第二章第三小节的第 4 条规范中指出：

> 【强制】在日志输出时，字符串变量之间的拼接使用占位符的方式。
> 
> 说明：因为 String 字符串的拼接会使用 StringBuilder 的 append() 方式，有一定的性能损耗。使用占位符仅 是替换动作，可以有效提升**性能**。
> 
> 正例：logger.debug("Processing trade with id: \{\} and symbol: \{\}", id, symbol);

反对者（注意这个“反对者”不是贬义词，而是为了更好的区分角色）的意思是这样的：

> 使用占位符会先判断日志的输出级别再决定是否要进行拼接输出，而直接使用 StringBuilder 的方式会先进行拼接再进行判断，这样的话，当日志级别设置的比较高时，因为 StringBuilder 是先拼接再判断的，因此造成系统资源的浪费，所以使用占位符的方式比 StringBuilder 的方式性能要高。

咱先放下反对者说的这个含义在阿里《Java开发手册》中是否有体现，因为我确实没有看出来，咱们先顺着这个思路来证实一下这个结论是否正确。

### 性能评测 ###

还是老规矩，咱们用数据和代码说话，为了测试 JMH（测试工具）能和 Spring Boot 很好的结合，首先我们要做的就是先测试一下日志输出级别设置，是否能在 JMH 的测试代码中生效。

那么接下来我们先来编写「日志级别设置」的测试代码：

在测试代码中，我们使用了 3 个级别的日志输出指令：`debug` 级别、 `info` 级别和 `error` 级别。

然后我们再在配置文件（application.properties）中的设置日志的输出级别，配置如下：

logging.level.root=info

可以看出我们把所有的日志输出级别设置成了 `info` 级别，然后我们执行以上程序，执行结果如下：

![format_png 4][]

从上图中我们可以看出，日志只输出了 `info` 和 `error` 级别，也就是说我们设置的日志输出级别生效了，为了保证万无一失，我们再把日志的输出级别降为 `debug` 级别，测试的结果如下图所示：

![format_png 5][]

从上面的结果可以看出，我们设置的日志级别没有任何问题，也就是说，**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` 级别，然后执行以上代码，测试结果如下：

![format_png 6][]

哇，测试结果真令人满意。从上面的结果可以看出使用占位符的方式的性能，真的比 `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` 循环内。

那么此时我们再来执行测试的代码，执行结果如下图所示：

![format_png 7][]

从上述结果可以看出，使用先判断再拼接字符串的方式还是要比使用占位符的方式性能要高。

那么，**我们依然没有办法证明阿里《Java开发手册》中的占位符性能高的结论**。

所以我依旧保持我的看法，**使用占位符而非字符串拼接，主要可以保证代码的优雅性，可以在代码中少些一些逻辑判断，但这样写和性能无关**。

### 扩展知识：格式化日志 ###

在上面的评测过程中，我们发现日志的输出格式非常“乱”，那有没有办法可以格式化日志呢？

答案是：有的，默认日志的输出效果如下：

![format_png 8][]

格式化日志可以通过配置 Spring Boot 中的 `logging.pattern.console` 选项实现的，配置示例如下：

logging.pattern.console=%d | %msg %n

日志的输出结果如下：

![format_png 9][]

可以看出，格式化日志之后，内容简洁多了，但千万不能因为简洁，而遗漏输出关键性的调试信息。

### 总结 ###

本文我们测试了读者提出质疑的字符串拼接和占位符的性能评测，发现占位符方式性能高的观点依然无从考证，所以我们的基本看法还是，**使用占位符的方式更加优雅，可以通过更少的代码实现更多的功能；至于性能方面，只能说还不错，但不能说很优秀**。在文章的最后我们讲了 Spring Boot 日志格式化的知识，希望本文可以切实的帮助到你，也欢迎你在评论区留言和我互动。

最后的话原创不易，都看到这了，点个「在看」再走呗，这是对我最大的支持与鼓励，谢谢你！
    
    往期推荐

[阿里《Java开发手册》中的 1 个bug！][Java_ 1 _bug]

[![format_png 10][]][format_png 10 1]

[阿里新版《Java 开发手册(泰山版)》内容解读（附下载地址）][format_png 10 1]

关注下方二维码，每一天都有干货！

![format_png 11][]

**点亮“在看”，助我写出更多好文！**![format_png 12][]

[format_png]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X2pwZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVduWjBpYkMzOVVSZTdEbkl4ejgwaFRSMnN1V25Scm5PVmZLNXQwbG5kbXlod2lhWmdyVlJvT1NBdy82NDA?x-oss-process=image/format,png
[Java_ 1 _bug]: https://blog.csdn.net/sufu1065/article/details/106581253
[format_png 1]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdHd0lPRWh0TEx6aWFWM05TTXc1N0RIbnlTUzNicWRGVlI5eU82SFlVamJpYjRqYThIMEY3SXRTdy82NDA?x-oss-process=image/format,png
[format_png 2]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVc5eGo5bVhWMEVCdXQ2aHRHTUxRMmJEeUxkOG54aWI5RXh4YTY3MzFMenBpY2Rob2NJTE9LZ1hidy82NDA?x-oss-process=image/format,png
[format_png 3]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdJQ091aDlsaDdUY3l4WG5Pa0JuMDBmRGI4OXg1c04yaWF5U2xKY21pYlZRRXpURzJJbVFzaWJkcEEvNjQw?x-oss-process=image/format,png
[format_png 4]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdqSEt3TVd3NG9pYmJpYmRKaWFjaWE5cXNlc2xJalVQUGZSRXI1UzVxNHBRR1FZdEpZeVBoNGZpYVF3QS82NDA?x-oss-process=image/format,png
[format_png 5]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdZUmZCZXBtWkF0bWZPbU56azNNMzA0RHhUTTV1Vk1iR0tpY2FDSU1JN2liUUpEcnJwbGFaNW1pYWcvNjQw?x-oss-process=image/format,png
[format_png 6]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdQUWd6YXFzaWF4Y3dPVGtwOThTNGhtOGo3ZnJpYjlsWW5iN3M1MXA4c1c5a01MVTBGd0pvMHo2Zy82NDA?x-oss-process=image/format,png
[format_png 7]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdnanZwUzltbHZ1QURnS0dTOWZ2YWtoMlFHZ283TUNHaWF5ajV1dDl4QVBYdzlpYVVTVUM2YnNJZy82NDA?x-oss-process=image/format,png
[format_png 8]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVdSTjVWZ3o1U01kVUp1dW1UdzVYNXVzaWNpYmV4RXV5YXBNWkpsWnIwOW45UnlhZ25UcnQ5NmRqUS82NDA?x-oss-process=image/format,png
[format_png 9]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9Icld3Nlp1WENzZzdPMXJkQ3NQN2ljYWpvdklPS2hxQVcwSnRJZ204QTRGd1lQV2YzeW5mOXFJVlJwZUxid3FremNwc2NSenNRREtLMW5oanlpY2dtbG5nLzY0MA?x-oss-process=image/format,png
[format_png 10]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X2pwZy9Icld3Nlp1WENzaWF5YktCWGliM1NxU2lidmpTcVJzSUE5SlhSUEU3WEhPeGY1Y0xCUTQ4WE5Ub3hDelEyWkk3T2lidXVBdFNLVkNpYnBxR3BDaE9QUGlhZU1Fdy82NDA?x-oss-process=image/format,png
[format_png 10 1]: http://mp.weixin.qq.com/s?__biz=MzU1NTkwODE4Mw%3D%3D&chksm=fbcc6bfbccbbe2ed2dbd1edf19a480930b6008a17230cec3a3556d8892bb747d0ab2d1cbefbe&idx=1&mid=2247485123&scene=21&sn=ba7292b22daedcd8b69e7cf49357c115#wechat_redirect
[format_png 11]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X2pwZy9zWnlBSnRpYWVzV2NqajRZNmIyUnNZampPNGNtc0E3OXZKY2RyY080RDZxb2t6V1l6NjQ4S2ZQVFNsSWhCeWVKbGZzQmtLaWFzWHR4a2JSTFRUSUxRcGlidy82NDA?x-oss-process=image/format,png
[format_png 12]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X2dpZi9ub3oyancyaFBsV2lhQ3JHdUp4QmljVTVtY2liM1FhcERMeW82ZUtuTlZtOWRQVFY0WjFTaWNITHRyQ0N3T0c5Z2JsTUJGbEtmN3A5Y3Z3TDZ3SWtaSnZhbWcvNjQw?x-oss-process=image/format,png