无论是哪种程序员,日常开发中都离不开记日志。但是通过最近的review会,发现很多程序员在记日志的时候,还是会有些问题。那么如何科学地记录日志呢?
为什么要记日志在寻求方法前,我们先看看我们记日志的目标。
日志是程序运行时的x光,能够追踪到程序运行的状态,通过日志,程序员能够加速调试速度,还原异常情况出现的场景。
也有通过日志记录处理数据,方便后面统计和审计。
还有通过日志进行备份,当数据有问题时,通过日志恢复数据。
总之,我们记日志,是为了给人看,来了解程序运行的状态。今天我们只讲日常调试和发现异常的场景。
既然日志是给人看的,就要让人能读懂,给出足够的信息。要带有上下文,4w都要清晰。把日志记录时刻的时间when、地点where(发生的函数,代码行)、什么数据或请求导致(who)。通过这些我们推出why,和how。知道为什么会记录成这样,有什么影响。
日志的级别在程序中,日志也是分级别的,不同的级别表示日志的不同场景和用途。
通常有如下级别:
TRACE:打印最详尽,在开发过程中使用此级别。类似于单步调试,在发不到运营环境后应该屏蔽掉这个级别。
DEBUG:指出细粒度信息事件对调试应用程序是非常有帮助的,主要用于开发过程中打印一些运行信息。
INFO:消息在粗粒度级别上突出强调应用程序的运行过程。打印一些你感兴趣的或者重要的信息,这个可以用于生产环境中输出程序运行的一些重要信息,但是不能滥用,避免打印过多的日志。
WARN: 表明会出现潜在错误的情形,有些信息不是错误信息,但是也要给程序员的一些提示。
ERROR: 发生了错误事件,但仍然不影响系统的继续运行。打印错误和异常信息,需要记录后处理。
FATAL: 指出每个严重的错误事件将会导致应用程序的退出。严重错误,直接停止程序。
每一条日志都是以上级别中的一种,程序中通过配置默认打印的级别,控制哪些语句打印,哪些不打印。
一般开发阶段使用DEBUG级别,线上运营阶段使用INFO或WARN级别。
记录日志是旁路逻辑,和给用户使用的逻辑是互不影响的。但是日志会消耗程序性能,抢占给用户的计算机资源。所以在记录日志时,要控制好日志的量,不要因为记录日志而导致性能下降。
有些同学会觉得,我的业务现在量也不大,多记些日志也没什么。勿以善小而不为。要养成好的习惯,如果没有这种意识,是没有机会做大业务量的程序的。即使有,也会出问题。
即使量少,用户少,但是不保证程序运行的次数少。如果有个循环频繁调用,触发记录日志,也会导致出问题的。我就见过日志记录太多,把cpu给占满,机器连ssh都连不上。
看到有的同学在日志里,会写些特殊的字符串,例如「XXXXXXXXXX」。原因是为了好搜索。如果是为了解决号搜索的问题,使用有规则的格式,和有意义的名字是不是更好,把代码行号打进去是不是更容易搜索?而且大家还知道是什么意思。
注意日志级别一种是把DEBUG级别设置到生产环境。还有一种是在代码中没有日志级别的概念,都用一种级别,DEBUG或者ERROR。要么所有的日志在生产环境都打不出来,要么一下子全打出来了。
注意日志安全既然日志记录了这么多信息,要注意日志中的内容,不能什么都打。和用户隐私相关的要避免打印到日志中去。因为这些信息如果不影响查找bug,记录后容易泄露用户隐私。例如:用户的聊天记录、用户的密钥、用户的电话号码邮箱等。
日志可读性尽量用英文,尽量少用中文,防止机器或网页有字符问题,造成不必要的查找麻烦。
几种有效的日志形式以下这几种记录日志的形式都各有所长,值得大家学习。但是切记,都有好用的日志库,千万别自己实现,里面的水很深。
内存日志既然日志打印很耗费性能,一般是磁盘IO是瓶颈。但是在程序遇到问题时,还想把从程序开始,到出问题这段时间的日志都记录下来,怎么办呢?就用内存日志。
申请一个共享内存变量,在程序的各个运行节点,都把要记录的日志信息存储在这个变量中。当程序出错,或者要crash后。用工具把这段内存dump下来,相当于一些栈信息打印出来。如果程序运行正常,当新的请求再开始执行时,重新清空变量,再继续记录。
既记录了很多信息,有没有造成IO的花销,在寻找C++后台程序core的原因时是非常有用的一种方式。