Log 问题域

• 如何不带来额外的效率损失
• 如何在程序运行出错时记录尽可能多的信息
• 如何方便查找特定条件的错误
• 如何横切的添加通用信息

如何不带来额外的效率损失

在之前接触的一个大型产品中见过散布着如下代码:

if (Log.Level > DEBUG) {
logger.write(some_method_to_build_the_log_string());
}

问为什么不在logger.write()里面判断日志级别, 这样外面写起来就很清爽

logger.write(some_method_to_build_the_log_string());

答曰效率问题, 后面一种写法会导致无论日志最终有没有被写入, some_method_to_build_the_log_string()都会先行被调用求值, 而这可能很耗时...

一个解决办法是额外的中间层: 能够延时求值的东东, 比如函数指针, 函数对象, 总而言之能够保存当前上下文而在将来某个时刻能够回调的东西, 诸如 C# 里的 Func<string>

这样logger.write()的签名就从 void write(string info) 变成 void write(Func<string> getInfo);

带来的一个问题是啥时真正写入, 一般可以是用户事务结束的时候. 其实当并发用户量大时, 表面上延时求值可以不阻碍当前请求的处理速度, 但当求值发生时, 可能会阻碍其它请求的处理. 所以Func<string>代替string效率上的优势并不明显, 更多的是代码上的简洁

(Func<string>的另一个好处是把IO操作推迟了, 当时没有IO操作，所有IO操作都被推到完成用户请求之后再进行，尤其是如果因为其它原因需要把Log存到数据库的时候. 当然不用Func<string>, 直接用string也可以实现推迟IO操作, 只需要把string都缓存起来, 找个时机再写出来即可)

然而Func<string>更大的意义是解决第二个问题:

如何在程序运行出错时记录尽可能多的信息

通常最终写到日志里的信息, 都是根据配置的级别决定的, 比如配置了日志级别是INFO, 那么无论出不出错, DEBUG级别的信息都不会被写到日志里. 然而现实情况是, 一旦出错, 我们可能需要DEBUG信息来定位问题. 于是我们不得不把日志级别设置成DEBUG,然后重新运行应用,企图复现. 但运行环境的差异使得复现像撞大运, 可遇不可得. 于是在案发第一现场就记录所有线索变得极具效率

对日志即时求值和写入是很难实现这个目的的, 而延时求值, 回调, 这层额外的间接则将其变得轻而易举.

我们要做的就是保存所有写日志的回调, 直到写入的那一刻, 根据某种规则, 从中挑选部分回调真正去执行; 规则可以是正常情况下根据日志级别设置, 出错的时候则全部写入, 等等

(这里的目的就是避免日志过于简略或者繁琐, 鼓励大家多写日志而不必担心运行时效率)

如何方便查找特定条件的错误

查找是数据库的强项, 把日志结构化, 存到数据库里即可. 这会带来事务的问题: 写日志是否和用户正常的业务放在一个事务里?

如何横切的添加通用信息

如果把log建模为一个对象, 可以应用builder模式, pipeline等, 让log对象依次通过一堆builder组成的pipeline, 每个builder负责给log增砖添瓦, 最后出来的就是一个包含了各种彼此独立的信息的对象