日志满天飞总是不好的,代码是程序员的艺术品,日志也是其中一部分。
写在前面的话
程序员在程序中打印日志的目的一般有两个:定位问题和显示程序运行状态。试想有那么一个夜晚,突然手机响了,美梦中惊醒,报警短信,然后不到两分钟leader电话来了,你用快速又娴熟的动作爬起来,打开电脑当你打开日志文件准备查问题的时候,傻了,这日志谁写的,问题被杂乱的日志埋葬了,一时急火攻心,终于通过对照源代码和日志,在数小时之后解决了问题。可见日志的重要性。
其实好的日志打印方式还有一个作用,能实现一些业务运营方面的统计工作,比如你在每个操作的关键位置都有对当前用户的操作记下一条日志,这样就能统计出,该业务功能走到每一步的用户数,从而能分辨出是在哪一步损失了用户,从而做相应的业务流程的优化。
可能大家认为日志不管咋打印都不会影响功能逻辑,抛开影响系统性能不说,这有点高级了,其实从上面的话中也可以看出,日志其实很重要的,所以下面我将从几个方面讨论一下如何打印日志,以便理清我自己的思路,同时提醒程序员同行们,这样后面维护你的代码的程序员,少一点吃屎,更少一点对你的咒骂,为和谐美好的程序员天堂添砖加瓦(好伟大呀,哈哈)。
目录:
1. 方便定位问题的日志如何打
2. 显示程序运行状态的日志如何打
3. 可以用作运营统计的日志如何打
4. 什么样的日志不应该打
1. 方便定位问题的日志
这是日志的最主要的用途。
- 日志明确标志属于哪次请求
打印的每一条日志中尽量包含请求流水号,以便区分这条日志是属于哪次请求的日志,日志样例:
log.warn("账户创建和升级功能,无法识别操作类型(0:创建,1:升级),请求流水号:{},当前值:{}" , flowNo, operType);
如果获取不到流水号,则需要打印明确能缩小日志归属范围的字段信息,如用户号、协议号、手机号等。
- 在对外提供的接口入口处打印一条日志
打印接口的唯一标识和中文(如果你English enough可以打英文)简短描述,并且要将调用方传入的参数原样打印出来。这样当系统出现问题时,你就能很容易的判断出是否是调用方出现了问题。日志样例:
log.info("addUpAccount&账户创建和升级接口,外部系统入参:{}" , JSONObject.toJSONString(request));
- 在调用其它系统接口的前后各打印一条日志
打印所调用接口的系统名称/接口名称和传入参数/响应参数,这样能方便做问题定界,通过这两条日志可以清楚地看出是否是所调用的系统出现了问题,传染到我了。日志样例:
log.info("调用cif业务订购,bcc入参:{}" , JSONObject.toJSONString(request));
log.info("调用cif业务订购,cif响应:{}" , JSONObject.toJSONString(cifResponse));
- 不符合业务逻辑预期打印一条日志
打印关键的参数,要能从这些参数中清楚地看出,谁的操作与预期不符,为什么与预期不符。并且唯一定位到这条日志,要包含用户id或者流水号。日志样例:
// 校验重复签约
int count = agreementService.countSignAndPre(externalUserId, userInfo.getUserId(), agreementType);
if (count == 1) {
// 已经签约过,不允许重复签约
log.warn("签约失败,不允许重复签约!用户信息:{},协议类型:{},来源系统:{},外部系统用户号:{}",
JSONObject.toJSONString(userInfo), agreementType, systemCode, externalUserId);
}
- 业务处理出现异常打印一条日志
主要打印异常信息和业务逻辑描述。日志样例:
try {
//业务逻辑处理
} catch (BizException e) {
log.warn("账户升级过程中出现业务异常", e);
}catch (Exception e) {
log.error("账户升级过程中出现无法识别的异常", e);
}
- 极少出现的else情况打印一条日志
打印业务功能描述和该极少出现的参数值,还有唯一定位一次请求的请求流水号。日志样例:
if("0".equals(operType)){
//创建账户
}else if("1".equals(operType)){
//升级账户
}else{
log.warn("账户创建和升级功能,无法识别操作类型(0:创建,1:升级),请求流水号:{},当前值:{}" , flowNo, operType);
}
2. 显示程序运行状态的日志
系统程序日复一日/月复一月/年复一年的运行着,查看系统的运行状态是必不可少的,比如一些可能和耗时的业务处理,批处理,IO操作等。
- 耗时(可能出现超时)业务逻辑处理时间打印一条日志
打印业务逻辑描述和处理时间。日志样例:
long startTime = System.currentTime();
//业务逻辑处理
log.info("绑定银行卡总耗时 : " + (System.currentTime() - startTime) + "ms");
- 批量处理大量数据时显示处理进度打印n条日志
在夜间做对账处理时,一般都是批量处理大量数据,这是应打印的日志包括:对账功能描述和处理进度,每处理1000(视情况而定)条打印一条。日志样例:
log.info("业务开通状态对账功能处理中,总数据量:{},当前处理到:{}", total, current);
3. 可用作运营统计的日志
从业务上来说,一个大的功能往往是由多个小功能组成,这些大的功能组成一个完整的系统。比如一个系统包括注册用户/开通某项业务/绑定银行卡/消费下单,从而达到一个电商类系统的最终目的。针对这个系统运营人员经常会要一些数据如多少注册用户,多少开通业务用户,多少绑卡用户,多少下过单的用户,如果是这样的粗粒度的统计需求,可能写几条sql搂一下数据库就搞定了。但是如果需要更加细致统计,如绑卡功能分为这样几步:用户实名校验,银行卡校验,发送短信验证码,校验短信验证码,签协议绑卡。日志样例:
...
log.info("用户绑卡,实名校验,用户信息:{}", JSONObject.toJSONString(userInfo));
...
log.info("用户绑卡,银行卡校验,用户信息:{}", JSONObject.toJSONString(userInfo));
...
log.info("用户绑卡,发送短信验证码,用户信息:{}", JSONObject.toJSONString(userInfo));
...
log.info("用户绑卡,校验短信验证码,用户信息:{}", JSONObject.toJSONString(userInfo));
...
log.info("用户绑卡,签协议绑卡,用户信息:{}", JSONObject.toJSONString(userInfo));
...
通过后台日志可以做到细粒度的运营统计分析,当然还有其他更专业的技术实现这种运营分析的功能,这种方法可以作为一个过渡期的方法。只要有一个好的打印日志的习惯,通过大数据的分析,日志还有其它的价值。
4. 不应该打印的日志
- 无意义的日志
日志样例:
log.info("调用客户系统开始...");
...
log.info("调用客户系统结束...");
...
log.info("用户签约失败...");
当我们看到这样的日志的时候,没有包含任何有意义的信息。调用开始,我想知道谁调用的,入参是啥;调用结束,我想知道调用结果,出参是啥,调用成功还是失败;同样,用户签约失败,我想知道的是哪个用户失败,为什么失败;显然都没展示,所以这样的日志是没有任何意义的。
- 混淆信息的日志
所打印出来的日志都应该是清楚准确的表达,当你不能确定具体原因的时候,不能在日志中只是展示一种可能的情况,这样会影响对问题的判断,这样的日志千万不能打。日志样例:
Connection connection = ConnectionFactory.getConnection();
if (connection == null) {
log.warn("System initialized unsuccessfully");
}
结束lala