欢迎在新的一年来到我的博客。在一个巴黎devops maillist上回复了一个关于监控和日志监控之后,我想起了很久以前我的一个博客计划。
尽管在写这篇博文的时候,我是在负责运维工作,不过本文主要是写给开发者的。
对我来说,明白如何记录日志和记录什么,是软件工程师必须明了的最艰巨的任务之一。之所以这么说,是因为这项任务与预测(divination)类 似,你不知道当你要调试的时候需要些什么信息……我希望这10个建议能帮助你更好地在应用程序中记录日志,让运维工程师们受益。:)
1. 你不应自己写log
绝对不要,即便是用printf或者是自己写入到log文件,又或自己处理logrotate。请给你的运维同志们省省心,调用标准库或者系统API来完成它。
这样,你可以保证程序的运行与其他系统组件好好相处,把log写到正确的位置或者网络服务上,而不需要专门的系统配置。
假如你要使用系统API,也就是syslog(3),学习好怎么用它。
如果你更喜欢用logging库,在Java里面你有很多选择,例如Log4j,JCL,slf4j和logback。我最喜欢用slf4j和logback的组合,因为它们特别给力,而且相对地容易配置(还允许使用JMX进行配置或者重载配置文件)。
slf4j最好的是你可以修改logging控制台的位置。如果你在编写一个库,这会变得非常重要,因为这可以让库的使用者使用自己的logging控制台而不需要修改你的库。
其他语言当然也有多种logging库,例如ruby的Log4r,stdlib logger,和几近完美的Jordan Sissel’s Ruby-cabin。
如果你想纠结CPU占用问题,那么你不用看这篇文章了。还有,不要把log语句放在紧内部循环体内,否则你永远看不出区别来。
2. 你应在适当级别上进行log
如果你遵循了上述第一点的做法,接下来你要对你程序中每一个log语句使用不同的log级别。其中最困难的一个任务是找出这个log应该是什么级别
以下是我的一些建议:
- TRACE level: 如果使用在生产环境中,这是一个代码异味(code smell)。它可以用于开发过程中追踪bug,但不要提交到你的版本控制系统
- DEBUG level: 把一切东西都记录在这里。这在debug过程中最常用到。我主张在进入生产阶段前减少debug语句的数量,只留下最有意义的部分,在调试(troubleshooting)的时候激活。
- INFO level: 把用户行为(user-driven)和系统的特定行为(例如计划任务…)
- NOTICE level: 这是生产环境中使用的级别。把一切不认为是错误的,可以记录的事件都log起来
- WARN level: 记录在这个级别的事件都有可能成为一个error。例如,一次调用数据库使用的时间超过了预设时间,或者内存缓存即将到达容量上限。这可以让你适当地发出警报,或者在调试时更好地理解系统在failure之前做了些什么
- ERROR level: 把每一个错误条件都记录在这。例如API调用返回了错误,或是内部错误条件
- FATAL level: 末日来了。它极少被用到,在实际程序中也不应该出现多少。在这个级别上进行log意味着程序要结束了。例如一个网络守护进程无法bind到socket上,那么它唯一能做的就只有log到这里,然后退出运行。
记住,在你的程序中,默认的运行级别是高度可变的。例如我通常用INFO运行我的服务端代码,但是我的桌面程序用的是DEBUG。这是因为你很难在 一台你没有接入权限的机器上进行调试,但你在做用户服务时,比起教他们怎么修改log level再把生成的log发给你,我的做法可以让你轻松得多。当然你可以有其他的做法:)
3. honor the log category
我在第一点中提到的大部分logging库允许指定一个logging类别。它可以分类log信息,并基于logging框架的配置,在最后以某一形式进行log或是不进行。
通常,Java开发者在log语句处使用完整,合格的类名作为类别名。如果你的程序遵循单一职责原则(Single responsibility principle,原文有误),这种模式还不错。
在Java的logging库中,Log类别是按等级划分的,例如在 com.daysofwonder.ranking.ELORankingComputation会匹配到顶级的 com.daysofwonder.ranking。这可以让运营工程师配置一个对此类别下指定的所有ranking子系统作用的logging。如果需 要的话,还可以同时生成子类别的logging配置。
拓展开来,我们讲解一下特定情况下的调试。假设你在做一个应答用户请求的服务端软件(如REST API)。它正在对my.service.api.<apitoken>进行log(其中apitoken用于识别用户)。那么你可以选择对 my.service.api类别进行log,记录所有的api,或是对某违规API用户的my.service.api.<bad-user- api-token>进行log。当然这需要系统允许你在运行中修改logging配置。
4. 你应该写有意义的log
这可能是最重要的建议了。没有什么比你深刻理解程序内部,却写出含糊的log更糟了。
在你写日志信息之前,总要提醒自己,有突发事件的时候,你唯一拥有的只有来自log文件,你必须从中明白发生了什么。这可能就是被开除和升职之间的微妙的差距。
当开发者写log的时候,它(log语句)是直接写在代码环境中的,在各种条件中我们应该写入基于当前环境的信息。不幸的是,在log文件中并没有这些环境,这可能导致这些信息无法被理解。
解决这个情况(在写warn和error level时尤为重要)的一个方法是,添加辅助信息到log信息中,如果做不到,那么改为把这个操作的作用写下。
还有,不要让一个log信息的内容基于上一个。这是因为前面的信息可能由于(与当前信息)处于不同的类别或者level而没被写入。更坏的情况是,它因多线程或异步操作,在另一个地方(或是以另一方式)出现。
5. 日志信息应该用英语
这个建议可能有点奇怪,尤其是对法国佬(French guy)来说。我还是认为英语远比法语更简炼,更适应技术语言。如果一个信息里面包含超过50%的英语单词,你有什么理由去用法语写log呢
把英法之争丢一边,下面是这个建议背后的原因:
- 英语意味着你的log是用ASCII编码的。这非常重要,因为你不会真正知道log信息会发生什么,或是它被归档前经过何种软件层和介质。如果你 的信息里面使用了特殊字符集,乃至UTF-8,它可能并不会被正确地显示(render),更糟的是,它可能在传输过程中被损坏,变得不可读。不过这还有 个问题,log用户输入时,可能有各种字符集或者编码。
- 如果你的程序被大多数人使用,而你又没有足够的资源做国际化,英语会成为你的不二之选。如果你有国际化,那么让界面与终端用户更亲近(closer)(这通常不会是你的log)
- 如果你国际化了你的log(例如所有的warning和error level信息),给他们一个特定的有意义的错误码。这样,用户做与语言无关的搜索,找到相关信息。这种良好的模式已经在虚拟内存(VMS)操作系统中应 用了很久,而我必须承认它非常有用。如果你曾经设计过这种模式,你还可以试试这种模式: APP-S-CODE 或者 APP-S-SUB-CODE,它们分别代表:
APP: 应用程序的3字缩写
S: 严重程度的1字缩写(例如D代表debug,I代表info)
SUB: 这个code所从属的应用程序的子部分
CODE: 一个数字代号,指定这个问题中的错误
#p#
6. 你应该给log带上上下文
没有什么比这样的log信息更糟的了
- Transaction failed
或是
- User operation succeeds
又或是API异常时:
- java.lang.IndexOutOfBoundsException
没有相应的上下文,这些信息不过是噪音,它们不会对调试过程中有意义的数值或是空间起作用(add value and consume space)。
带上上下文的信息要有价值得多,例如:
- Transaction 234632 failed: cc number checksum incorrect
或是
- User 54543 successfully registered e-mail<a href="mailto:user@domain.com">user@domain.com</a>
又或是
- IndexOutOfBoundsException: index 12 is greater than collection size 10
在上面这一例子中的异常,如果你想把它传播开, 确保在处理的时候带上与当前level相应的上下文,让调试更简单,如下一个java的例子:
- public void storeUserRank(int userId,int rank,String game) {
- try {
- ...deal database ...
- } catch (DatabaseException de) {
- throw new RankingException("Can't store ranking for user "+userId+" in game "+ game + " because " + de.getMessage() );
- }
- }
这样,rank API的上层客户端就可以有足够的上下文信息log这个error。更好的做法是让上下文成为exception的参数,而不是信息,如果需要的话,上层可以对它进行修正(use remediation)。
保留上下文的一个简单方法是使用一些java logging库的MDC实现。MDC是一个每线程关联数组(per thread associative array)。可以修改logger设置,让每一行log总是输出MDC内容。如果你的程序使用每线程模式,这可以帮助解决保留上下文的问题。这个 java的例子对给定的请求,使用MDC记录每用户的信息:
- class UserRequest {
- ...
- public void execute(int userid) {
- MDC.put("user",userid);
- // ... all logged message now will display the user=<userid> for this thread context ...
- log.info("Successful execution of request");
- // user request processing is now finished,no need to log our current user anymore
- MDC.remote("user");
- }
- }
提示,MDC系统在异步logging模式中的表现并不好,例如Akka的logging系统。因为MDC是保存在一个每线程存储区域的,而且在异 步系统中你无法保证在写入log的线程是有MDC的那一个。在这种情况下,你需要手动地使用每一个log语句来log这些上下文。
7. 你应该用机器可解析的格式来打日志
Log信息对人很友善,但是对机器就惨了。有时人工地读这些log文件并不足够,你需要进行一些自动化过程(例如通过警报和审查)。或是你想集中存储你的log,以进行搜索。
如下,如果你把log的上下文嵌在string中会发生什么:
- log.info("User {} plays {} in game {}",userId,card,gameId);
这会生成这样的文本:
- 2013-01-1217:49:37,656[T1]INFOc.d.g.UserRequestUser1334563plays4ofspadesingame23425656
现在,如果你想使它可解析,你需要下面这个(未测试过的)正则表达式:
- /User(\d+)plays(.+)ingame(\d+)$/
好了,这并不轻松而且容易出错,把它接入到你代码中已有的string参数中。
这个方法怎么样,我相信Jordan Sissel在他的ruby-cabin库中第一次介绍的: 在你的log里面加入机器可解析格式的上下文。我们上述的例子中这样可以使用JSON:
- 2013-01-1217:49:37,656[T1]INFOc.d.g.UserRequestUserplays{'user':1334563,'card':'4ofspade','game':23425656}
现在你的log分析器可以更容易地写入,更直接地索引,而且你可以释放logstash所有的威力。
8. 日志不宜太多或太少
这听着貌似很愚蠢。log的数量是有一个合适的平衡的。
太多的log会使从中获得有价值的东西变得困难。当人工地浏览这种十分混乱的log,尝试调试产品在早上3点的一个问题可不是一个好事。
太少的log,你可能无法调试问题: 调试就像在拼一个困难的拼图,你需要得到足够的拼块。
不幸的是,这没有魔法般的规则去知道应该log些什么。所以需要严格地遵从第一第二点,程序可以变得很灵活,轻松地增减log的长度(verbosity)。
解决这个问题的一个方法是,在开发过程中尽可能多地进行log(不要被加入用于程序调试的log所迷惑)。当应用程序进入生产过程时,对生成的 log进行一次分析,根据所发现的问题增减log语句。尤其是在调试时,在你需要的部分,你可以有更多的上下文或logging,确保在下一个版本中加入 这些语句(可以的话,同时解决它来让这个问题在记忆中保持新鲜)。当然,这需要运维人员和开发者之间大量的交流。
这是一个复杂的任务,但是我推荐你重构logging语句,如你重构代码一样多。这样可以在产品的log和它的log语句的修改中有一个紧密的反馈循环。如果你的组织有一个连续的交付进程的话,它会十分有效,正如持续的重构。
Logging语句是与代码注释同级的代码元数据。保持logging语句与代码相同步是很重要的。没什么比调试时获得与所运行的代码毫无关系的信息更糟了。
#p#
9. 你应该考虑阅读者
为什么要对应用程序做log
唯一的答案是,在某一天会有人去读它(或是它的意义)。更重要的是,猜猜谁会读它,这是很有趣的事。对于不同的”谁”,你将要写下的log信息的内容,上下文,类别和level会大不同。
这些”谁”包括:
- 一个尝试自己解决问题的终端用户(想象一个客户端或桌面程序)
- 一个在调试产品问题的系统管理员或者运维工程师
- 一个在开发中debug,或者在解决产品问题的开发者
开发者了解程序内部,所以给他的log信息可以比给终端用户的复杂得多。为你的目标阅读者调整你的表达方式,乃至为此加入额外的类别(dedicate separate catagories)。
10. 你不应该只为调试而log
正如log会有不同的阅读者,它也有不同的使用理由。即便调试是最显而易见的阅读log的目的,你同样可以有效地把log用在:
- 审查: 有时商业上会有需求。这可以获取与管理或者合法用户的有意义的事件。通常会有一些语句描述这个系统中的用户在做些什么(例如谁登录了,谁在编辑……)
- 建档: log是打上了时间戳的(有时是微妙级的),可以成为一个为程序各部分建档的好工具。例如记录一个操作的开始和结束,你可以自动化(通过解析log)或是在调试中,进行性能度量,而不需要把这些度量加到程序中。
- 统计: 如果你每次对一个特定事件(例如特定的错误或事件)进行log,你可以对运行中的程序(或用户行为)进行有趣的统计。这可以添加(hook)到一个警报系统中去连续地发现大量error。
总结
我希望这可以帮助你生成更多有用的log。如果我忘记了一些必须的(对你而言)建议,请谅解。对了,如果你看了这篇博客之后并不能更好地进行log,我并不负责
如果这10个建议还不够的话,尽管在评论中补充更多有用的建议。
原文链接:http://www.masterzen.fr/2013/01/13/the-10-commandments-of-logging/