log is判断引发的一系列事件，哭哭

柔光的暖阳◎ 2023-10-03 21:22 5阅读 0赞

## 序 ##

首先来源是 老大code Review的时候 说到日志，让我从 log.debug 加上一个if 判断，log.isDebug ，这一听就想到是 为了防止debug 日志不打印，导致的String拼接等 没必要的损耗

嗯嗯 老大说的确实有道理，改吧

我靠，这一查几百个 log 需要加，这一个一个改也太累了

## 总 需求列表 ##

1.  log 自动加上if判断 如果外面有if判断了，忽略
2.  最后 写了个**idea 插件**。。。。

## log 自动加上if判断 调研 ##

刚上来，我先百度下 是不是有现成的，我现在用的lombok，按道理应该有一个属性 控制 是否加if的，嗯嗯 没错，找找，我一般先看看 @Sl4J 给我提供了什么参数配置

![format_png][]

### 思考 这个topic干什么的啊？ ###

说实话 我之前没有用过这个属性。。。。狗头。。

@Slf4j 注解有个topic 属性可以进行设置要采用的logger，  
topic 的值对应的就是logback.xml中定的logger name。root logger是默认就存在的。

到这 你可能要问了，**root logger 是默认实现，你说是默认实现就是默认实现了？ 证据呢？**

![format_png 1][]

对应的启动Config类为 ch.qos.logback.classic.BasicConfigurator

![format_png 2][]

嗯嗯 根上是ROOT

有一个细节，我们在配置logback.xml的时候 都会写这种

<logger name="com" level="DEBUG" >
        <appender-ref ref="STDOUT"/>
    </logger>
    <logger name="com.example.demo" level="warn" >
        <appender-ref ref="STDOUT"/>
    </logger>
    复制代码

你是不是好奇 这种的name怎么解析的？

![format_png 3][]

他是从头开始 遍历包名 从loggerCache 中看看是否有匹配的，一层层找

### 思考 ###

不说这些理论了，一句话 按照上面配置 logback.xml 在 com.example.demo.controller 下的类执行会打印log.info日志么？

@RestController
    @RequestMapping
    @Slf4j
    public class DemoController {
    
        @RequestMapping("/test")
        public String test(){
            log.info("sad");
            return "success";
        }
    }
    复制代码

嗯嗯 这么一实验 没打印啊

![format_png 4][]

有人可能问了，那把2个logger 顺序反过来？ 不用试了，也不行

这一看 com.example.demo的warn生效了啊，debug/info 都没打印出来，那为什么呢？

先看一个图

![format_png 5][]

下面就要看下 这个children 当时怎么赋值的了 其实就是从 最底下 往上找，在这里找到了 com.example.demo 的配置并且应用，是因为 logger类中

int h;
    do {
        h = LoggerNameUtil.getSeparatorIndexOf(name, i);
        String childName;
        if (h == -1) {
            childName = name;
        } else {
            childName = name.substring(0, h);
        }
    
        i = h + 1;
        synchronized(logger) {
            childLogger = logger.getChildByName(childName);
            if (childLogger == null) {
                childLogger = logger.createChildByName(childName);
                this.loggerCache.put(childName, childLogger);
                this.incSize();
            }
        }
    
        logger = childLogger;
    } while(h != -1);
    复制代码

一直找到最后，返回的就是最后/最靠近 目标类的logger 配置

### 总结： ###

logger 配置不是按照pom.xml的那种优先顺序，而是包名匹配 最多的生效，如果你发现 日志打印和你想的不一样，你可以去看下 LoggerContext 类中 loggerCache 属性的值，检查下

如果是一个业务系统，可能是一种logback.xml模板，如果你是中间件/组件，就需要对logback.xml 进行改动了，因为中间件可能是 binlog监听等等 大数据量的，如果按照业务系统那种搞法 **有的日志是没必要，根据你的业务 请自由配置**

### 说回来 lombok 到底有没有自动加if的插件啊 ###

lombok @Sl4j 是没有了，百度下吧

![format_png 6][]

好吧，这也什么都没有，官网看看，哎 也没有，按道理应该有啊，也不难。。。

我突然在想是不是这个优化 也不像我们想的那么有优化效果，肯定还是有必要的

![format_png 7][]

### log isDebug 判断的必要性 ###

#### 错误案例 ####

现象描述：发现某些服务器的pv数不高，但服务器的load却不低，高于平均水平

#### 错误分析 ####

分析过程： 通过内存监控发现，GC的动作比较频繁，但无法找到原因，一次PLA偶然的发现了大量如log.debug(“memberId:” + member.getMemberId())代码

#### 原因分析 ####

在代码中发现如下代码段很多： log.debug(“memberId:” + member.getMemberId())

以上代码执行时，分两步：

1.  先执行的是括号中的字符串相”+”的动作，而每次”+”运算都会导致新字符串的生成，这样就产生了很多“中间字符串”，在极大次数被调用时，这种字符串被创建和销毁的数量非常庞大，从而造成了jvm gc频繁执行，进而影响了性能。
2.  再执行log.debug()函数，在生产环境log level一般大于info，所以实际不会打印debug信息综上所述，这些代码在生产环境不会产生日志，但会执行字符串”+”运算，而这些运算是无意义的，所以需要先判断日志的优先级，方式是log.isXXXEnabled() \{ log.XXX(……); \}

Log Level的级别： Fatal->error->warn->info->debug，级别从高到低 一般我们生成环境的log level都是error，所以对于Error以上级别的日志，不用判断；对于error以下级别的都要加上判断。

## 总结 ##

is 判断还是有必要的，目前没什么别的办法，我在写一个idea 插件，来一个按钮/快捷键 自动添加log if判断，正好玩玩

![format_png 8][]

## 后续 ##

行吧，既然说了做一个idea 插件，搞起来，周末花了几个小时搞了一版，提交了idea 审核 ，**等待审核中 起名叫java-tools 开发会用的功能 我会迭代进去，有什么是你们需要的可以评论下，我会排下优先级 开发**

![format_png 9][]

简单效果：

![format_png 10][]

点击 ctrl + 8 一起按 或者 右键

![format_png 11][]

变为

![format_png 12][]

[format_png]: https://img-blog.csdnimg.cn/img_convert/48d22bfe6773f78ebc730445e643b60c.webp?x-oss-process=image/format,png
[format_png 1]: https://img-blog.csdnimg.cn/img_convert/08162edc63191d023a11a55b77f34a31.webp?x-oss-process=image/format,png
[format_png 2]: https://img-blog.csdnimg.cn/img_convert/c5f4e90c625a4d56461085b59cf94001.webp?x-oss-process=image/format,png
[format_png 3]: https://img-blog.csdnimg.cn/img_convert/62c5cd6006810fd5ef43ab6c6344f492.webp?x-oss-process=image/format,png
[format_png 4]: https://img-blog.csdnimg.cn/img_convert/06488d8fded865ab551294040ed3ede9.webp?x-oss-process=image/format,png
[format_png 5]: https://img-blog.csdnimg.cn/img_convert/f106dabc9c5a45ae388aa84afba6d691.webp?x-oss-process=image/format,png
[format_png 6]: https://img-blog.csdnimg.cn/img_convert/297be395e1b15ac81e44f024bdbca7e4.webp?x-oss-process=image/format,png
[format_png 7]: https://img-blog.csdnimg.cn/img_convert/2f56a622c5247c167c89e7e549f850e6.webp?x-oss-process=image/format,png
[format_png 8]: https://img-blog.csdnimg.cn/img_convert/5ab9e2fce5f28bdb7e94f25afa20a499.webp?x-oss-process=image/format,png
[format_png 9]: https://img-blog.csdnimg.cn/img_convert/6ad8ca75425ad579d79a638a0c921d54.webp?x-oss-process=image/format,png
[format_png 10]: https://img-blog.csdnimg.cn/img_convert/35a11be6e662d8697db216abf6aa6c13.webp?x-oss-process=image/format,png
[format_png 11]: https://img-blog.csdnimg.cn/img_convert/e301c0f5882410bd0eba9775e0d22fda.webp?x-oss-process=image/format,png
[format_png 12]: https://img-blog.csdnimg.cn/img_convert/dc916fa8f0c022ead7eb2bcd03d10ffc.webp?x-oss-process=image/format,png