论如何打印日志

博客原文

日志满天飞总是不好的,代码是程序员的艺术品,日志也是其中一部分。

写在前面的话

程序员在程序中打印日志的目的一般有两个:定位问题显示程序运行状态。试想有那么一个夜晚,突然手机响了,美梦中惊醒,报警短信,然后不到两分钟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

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,542评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,596评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 158,021评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,682评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,792评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,985评论 1 291
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,107评论 3 410
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,845评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,299评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,612评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,747评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,441评论 4 333
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,072评论 3 317
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,828评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,069评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,545评论 2 362
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,658评论 2 350

推荐阅读更多精彩内容