日志打印在开发中一般都是有2个极端,首先是什么都不打印,出了问题之后一看后台啥也没有,然后修改;修改的结果就是什么地方都打印,一出错误,找日志找半天,定位一个问题要1,2个小时,甚至是更多的,之前遇到过一个开发团队,定位解决一个问题用了三天(并不是什么特别特殊的业务)。之前也出现过几次前台出错没有日志,测试环境无法重现,把日志加上走个变更再操作再看日志定位的事情。
开发久了,总会遇到“这个问题生产环境上能重现,但是没有日志,业务很复杂,不知道哪一步出错了?”,又或者“这几行代码的异常被捕获了,但是异常一直没有打印出来” 这个时候,怎么办? 还能怎么办,发个版本,就是把所有地方加上日志,没有任何新功能,然后在让用户重现一遍,拿下日志来看,呵呵,,原来是这个问题!。
还有另外一种场景:现在很多系统都是分布式的,一个系统有好多节点,出了问题找日志真是痛苦,一个一个机器翻,N分钟后终于找到了,找到了后发现好多相似日志,一个一个排查;日志有了,发现逻辑很复杂,不知道走到那个分支,只能根据逻辑分析,不停的翻看代码,半天过去了,终于找到了原因。。。一个问题定位就过去了2个小时,变更时间过去了一半。。。
—日志要求基本—
1、能找到那个机器
2、 能找到用户做了什么
—开发日志要求—
1、分支语句的变量需要打印变量
// optype决定代码走向,需要打印日志
logger.info("edit user, opType:" + opType);
if (opType == CREATE) {
// 新增操作
} else if (opType == UPDATE) {
// 修改操作
} else {
// 错误的类型,抛出异常
throw new IllegalArgumentException("unknown optype:" + opType);
}
重要建议:养成把不合法参数抛出异常的好习惯,抛异常的时候把对应的非法值抛出来。
2、修改操作需要打印操作的对象
3、大量数据操作的时候需要打印数据长度
处理了多少数据用了多少时间
。如一个操作用了3秒钟,性能是好还是坏? 如果处理了1条数据,那么可能就是性能差,如果处理了10000条数据,那么可能就是性能好。
logger.info("query docment start ...");
List<Document> docList = query(params);
logger.info("query docment done, size:" + docList.size())
4、使用log4j的MDC打印用户名等额外信息
有时候,业务量大的系统要找到某一个用户的操作日志定位问题非常痛苦,每一个日志上加用户名又低效也容易漏掉,所以我们要在更高层级上解决这些共性问题。
我们使用log4j的MDC功能达成这个目的。
在单点登录后,设置用户信息的时候,把用户标志放到MDC中。
private final static ThreadLocal<String> tlUser = new ThreadLocal<>();
public static final String KEY_USER = "user";
public static void setUser(String userid) {
tlUser.set(userid);
// 把用户信息放到log4j
MDC.put(KEY_USER, userid);
}
然后修改log4j配置,pattern上增加 %X{user}
,位置随意。
增加线程相关配置 [%t]
,完整参数详见log4j变量
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="[%t]%-d{MM-dd HH:mm:ss,SSS} %-5p: %X{user} - %c - %m%n" />/>
</layout>
参考文章:
https://zhuanlan.zhihu.com/p/28629319