你滥用log了吗

代码Review的时候，遇到过一些log滥用的情况，今天聊一聊滥用（过渡使用）日志。

好的log能够帮助开发人员快速定位bug，而差的log各有各的不同。

你滥用日志了吗？

是什么导致了滥用log？是不是存在这些误解：

1. 害怕出了问题，现有的log无法定位，要多加一些log，恨不得每段都有一个log，log数简直越多越好，看日志有一种，每一步都非常清晰的错觉。

2. 不知道log多了，定位效率更低，试问你有没有经历过几分钟刷出了G级别日志文件？在这种日志文件里定位bug，简直是大海捞针，这让log的价值非常低。

3. 不知道log多了会影响性能，log自身涉及格式化和文件读写，虽然现在各log库都已经比较高效了，但是，这也扛不住“海量”的log啊，积少成多，势必影响程序性能。

4. 对log级别错误的认知：日志级别设置为Info，Debug、Trace级别的日志不会打印，Debug、Trace级别日志多没关系。虽然日志不会输出，并不代表相关代码没执行啊。

第4点重点解释一下：

debug-demo

这是一个打印Debug级别的日志，它还有1项日志信息，是来自func()的结果，请问：

1. 日志级别设置为Info，log.Debug会执行吗？func()还会执行吗？
2. 如果这行日志频繁被执行，是不是浪费了CPU做无用功？

如果你认为不会执行，看下面的Demo，log使用zap。

log-test

结果：

log-ret

事实证明无论限制的日志级别是什么，log.***一定会被调用，它入参中的函数也一定会被调用，只不过是日记级别不满足打印时，不会打印而已。被调函数的结果只被这条log.***使用，结果这个日志根本不打印，这就浪费了CPU。

日志级别都设置为Info了，Debug级别的日志为何还会打印？

如果你有这个问题，你可能没有理解2个地方。

日志级别设置为Info，不代表log.Debug函数不执行。log.Debug函数一定会执行，看下图，log.Info，Error等接口会调用相同的真实实现函数log.log，log.log的入参包含了log.Info等接口的入参，以及当前的log_level，比如以下2种是等价的：

log-log

所以，无论设置的是什么日志级别控制，log.Debug一定会被执行，至于当前日志是否会打印，会在log.log里决定。

image-20190712072742045

日志为Warn级别，Debug日志不会打印，func()会不会执行？

日志打印本质是函数调用，会先计算入参，再调用函数。比如：

log-debug

所以func()一定会被调用。

总结

针对滥用日志的情况给几点建议：

1. 1条日志描述清when、where、what，提供有效信息，这就对定位很有帮助了。
2. 只在“可能”出问题的地方打印日志，一些能根据上下文日志推断的地方，就无需再增加日志。
3. 日志打印不要调用函数。