1.日志的主要作用
1)日志是系统运行的“照妖镜”,通过它能够实时反映系统的运行状态;
如上图所示,系统A中producer不断产生数据放入到data queue中,sender不断从data queue中取数据发送给下游系统B的receiver,那么对于系统A来说,data queue中的待发送数据量便是一个非常关键的指标,它能够从侧面真实反应当前系统的运行状况,如果data queue中的element个数超过容量的90%了,那么标志着此时系统可能运行不正常了,会有队列堵塞的风险;如果data queue中的element个数不到容量的10%,那么标志着此时系统运行比较正常,出现队列堵塞的风险较低。
如果这个指标没有输出到日志中,开发和运维人员是无法确切知道当前系统A的运行状态的(当然也有其他的方式来获取这个指标,比如通过http接口暴露出来也是一种方式之一)。
2)良好的日志便于后期运维和开发人员迅速定位线上问题,加快止损速度,减少系统故障带来的损失;
3)日志还有另外一个作用便是能够无缝与监控系统结合,通过监控系统进行日志采集,拿到系统运行的相关性能指标,有利于分析系统的性能瓶颈、提前规避风险;
举例说明:
假如有一个商城系统,在初期,数据库通过2台服务器提供服务(1台master,1台slave),此时大部分接口能在秒级内响应用户请求。随着时间的推移,商城系统的用户量逐渐增多,并发查询和写入量都出现了一定的增长,数据库中的数据量也慢慢增多,导致部分sql语句查询越来越慢,突然有一天,数据库的slave机器由于过多的慢查询导致被拖垮,彻底宕机了,导致商城服务不可用。
如果商城系统在日志中记录了每个http请求的耗时情况,通过监控系统配置日志采集,同时配置相应的报警,那么便能提前发现由于业务增长带来的系统性能瓶颈,提前进行系统优化(如机器扩容、sql语句优化、分库分表等),规避风险。
4)便于统计与业务相关的指标数据,进行相关业务分析和功能优化。
举例说明:
比如一个搜索系统,想统计过去一周不同地域(如南北地域)的搜索使用占比,如果日志中本身打印了每个搜索query请求的ip,则很容易统计,否则需要重新上线加日志才能统计。
因此,大家在日常编写代码过程中要注重日志书写的规范性,让它发挥出它应有的价值,在辅助保障我们服务稳定运行的同时,能够有效提升后期系统维护效率。
2.如何规范地打印程序日志?
接下来,我们从以下几个方面来谈谈如何规范地打印日志。
- 日志文件命名
- 日志滚动
- 日志级别
- 日志打印时机的选择
2.1 日志文件命名
通常来说日志文件的命名可包括以下几个关键信息:
- 类型标识(logTypeName)
- 日志级别(logLevel)
- 日志生成时间(logCreateTime)
- 日志备份编号(logBackupNum)
类型标识:指此日志文件的功能或者用途,比如一个web服务,记录http请求的日志通常命名为request.log或者access.log,request、access就是类型标识,而java的gc日志通常命名为gc.log,这样看一目了然;而通常用来记录服务的整体运行的日志一般用服务名称(serviceName、appKey)或者机器名(hostName)来命名,如 nginx.log;
日志级别:打印日志的时候直接通过文件来区分级别是一种比较推荐的方式,如果把所有级别的日志打到同一个日志文件中,在定位问题时,还需要去文件中进行查找操作,相对繁琐。日志级别一般包括DEBUG、INFO、WARN、ERROR、FATAL这五个级别,在实际编写代码中,可以采取严格匹配模式或者非严格匹配模式,严格匹配模式即INFO日志文件中只打印INFO日志,ERROR日志文件只打印ERROR日志;非严格匹配模式即INFO日志文件可以打印INFO日志、WARN日志、ERROR日志、FATAL日志,WARN日志文件可以打印WARN日志、ERROR日志、FATAL日志,以此类推。
日志生成时间:即在日志文件名称中附带上日志文件创建的时间,方便在查找日志文件时进行排序;
日志备份编号:当进行日志切割时,如果是以文件大小进行滚动,此时可以在日志文件名称末尾加上编号;
2.2 日志滚动
虽然日志中能够保存系统运行时的关键信息,但是由于磁盘空间有限,所以我们不能无限制地保留日志,因此必须有日志滚动策略。日志滚动通常有以下几种模式:
- 第一种:按照时间滚动
- 第二种:按照单个日志文件大小滚动
- 第三种:同时按照时间和单个日志文件大小滚动。
按照时间滚动,即每隔一定的时间建立一个新的日志文件,通常可以按照小时级别滚动或者天级别滚动,具体采取哪种方式取决于系统日志的打印量。如果系统日志比较少,可以采取天级别滚动;而如果系统日常量比较大,则建议采取小时级别滚动。
按照单个日志文件大小滚动,即每当日志文件达到一定大小则建立一个新的日志文件,通常建议单个日志文件大小不要超过500M,日志文件过大的话,对于日志监控或者问题定位排查都可能会造成一定影响。
按照时间和单个日志文件大小滚动,这种模式通常适用于希望保留一定时间的日志,但是又不希望单个日志文件过大的场景。
对于日志滚动策略来说,有2个比较关键的参数:最大保留日志数量和最大磁盘占用空间。这2个参数切记一定要设置,如果没有设置,则很有可能会出现把线上机器磁盘打满的情况。
2.3 日志级别
日志的级别通常有以下几种:
debug/trace、info、warning、error、fatal
这几种日志级别的严重程序依次递增:
-
debug/trace:debug和trace级别的日志由于打印内容较多,所以通常情况下不适用于线上生产环境使用,一般使用于前期线下环境调试。即使线上环境要使用,也需要通过开关来控制,只在定位追踪线上问题时才开启;
-
info:info日志一般用来记录系统运行的关键状态、关键业务逻辑或者关键执行节点。但切记一点,info日志绝不可滥用,如果info日志滥用,则和debug/trace日志没有太大区别了。
-
warning:warning日志一般用来记录系统运行时的一些非预期情况,顾名思义,是作为一种警示,提醒开发和运维人员需要关注,但是不用人为介入立刻去处理的。
-
error:error日志一般用来记录系统运行时的一些普通错误,这些错误一旦出现,则表示已经影响了用户的正常访问或者使用,通常意味着需要人为介入处理。但很多时候在生产环境中,也不一定是出现error日志就需要人工立即介入处理的,通常会结合error日志的数量以及持续时间来进行综合判断。
-
fatal:属于系统致命错误,一般出现意味着系统基本等于挂掉了,需要人工立即介入处理。
下面举个简单的例子来说明,假如我们有这样一个场景,我们有一个工资计算系统,每隔月1号需要从员工考勤系统获取公司所有员工的考勤数据,然后根据考勤数据来计算上月应发工资,那么需要有一个函数从考勤系统获取员工考勤数据:
public Map<Long, Double> getEmployeeWorkDaysFromAttendance(int year, int month, Set<Long> employeeList) throws BusiessException {
// 入口关键日志,需要打印关键的参数,因为employeeList可能数量较大,所以次数没有直接打印employeeList列表内容,只打印了size
logger.info("get employee work days, year:{}, month:{}, employeeList.size:{}", year, month, employeeList.size());
// 如果需要临时检验员工列表,可以把debug日志开关打开
if (debugOpen()) {
logger.debug("employ list content:{}", JSON.toJsonString(employeeList));
}
int retry = 1;
while (retry <= MAX_RETRY_TIMES) {
try {
Map<Long, Double> employeeWo