1.选择恰当的日志级别
日常开发中常见日志级别有:trace、debug、info、warn、error(级别依次增大):
1.trace:最详细的日志信息,一般记录到日志文件中
2.debug:一般用于开发中DEBUG的关键逻辑的运行时数据
3.info:记录排查问题的关键信息,如出参,入参等
4.warn:警告日志,一般的错误,对正常业务影响不大,需要开发者关注
5.error:错误日志,对正常业务有影响,需要运维配置日志监控
2.日志要打印方法的入参和出参
例如在Controller层,请求入参、响应出参和响应异常,一般需要打印日志,出问题时,方便追踪代码逻辑运行的路线。建议这里使用日志切面进行统一日志打印;
public String doSth(String id, String type){ log.info("start: {}, {}", id, type); String res = process(id, type); log.info("end: {}, {}, {}", id, type, res};}
其他层级的方法入参和出参,如有必要,可以打印整个出参和入参的数据,反之可以打印有效的关键日志,方便问题定位即可;
建议只打印必要的参数,不要整个对象打印反例:
分析:
首先分析下自己是否必须把所有对象里的字段打印出来?如果对象中有50个字段,但只需其中两个参数就可以定位具体的原因,那么全量打印字段将浪费内容空间且因为字段过多,影响根因排查。正例:
使用这个种方法需及时防止npe,并考虑是否核心场景,核心场景建议还是打全,避免漏打、少打影响线上问题定位&排查。
public void doSth(){ log.info("print log, data={}", data.toString()); // 业务逻辑 ...}
public void doSth(){ log.info("print log, id={}, type={}", data.getId(), data.getType()); // 业务逻辑 ...}
3.日志格式
一般日志中包含:时间、日志级别、线程名称、日志具体内容等
%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger:%line - %msg%n
4.在多个if-else等条件时,每个分支首行尽量打印日志
可以在进入分支前打印日志,后续可以快速定位到进入了哪个分支,方便排查问题
建议:
public void doSth(){ if(user.isVip()){ log.info("该用户是会员,Id:{},开始处理会员逻辑",user,getUserId()); //会员逻辑 }else{ log.info("该用户是非会员,Id:{},开始处理非会员逻辑",user,getUserId()) //非会员逻辑 }}
5.日志级别比较低时,进行日志开关判断
对于trace、debug级别的日志打印,需要进行开关判断
if (log.isTraceEnabled()) { log.trace("trace log detail......"); }
if (log.isDebugEnabled()) { log.debug("debug log detail......"); }
比如需要打印如下日志
log.debug("Payment processing,requestNo=" requestNo ",channel=" channel);
当前配置的日志级别为info,则上面日志不会打印,但会进行字符串拼接;
如果是对象,还会执行toString()方法,浪费了系统资源
6.不要直接使用日志系统(Log4j、Logback)中的 API,而是使用日志框架SLF4J中的API
SLF4J是门面模式的日志框架,需要更换日志框架实现时,在不改动代码的情况下,可以方便切换到不同的日志实现框架
import org.slf4j.Logger; import org.slf4j.LoggerFactory; private static final Logger logger = LoggerFactory.getLogger(Demo.class);
// 或者使用Lombok @Slf4j
7.建议使用参数占位{},而不是用 拼接
反例:
log.debug("Payment processing,requestNo=" requestNo ",channel=" channel);
字符串使用" "进行拼接操作,会有一定的性能损耗,虽然高版本的jdk对字符串拼接进行了性能优化,但不建议使用
正例:
log.info("Payment processing,requestNo={},channel={}", requestNo, channel);
使用大括号{}进行占位符的替换,相比字符串拼接,性能上更高,日志代码也更加优雅
8.不要使用e.printStackTrace() 和 System.out.println();
反例:
try{ // TODO 业务代码处理 }catch(Exception e){ //System.out.println("xxx业务处理异常,异常信息:" e); e.printStackTrace(); }
正例:
try { // TODO 业务代码处理 } catch (Exception e) { log.error("xxx业务处理异常 requestNo={}", requestNo, e); }
e.printStackTrace()打印在堆栈信息中,如果异常过多,会导致堆栈内存不足,出现卡(运行极慢)的现象,最后出现OOM,这是一种非常糟糕的现象;使用log来打印日志会记录到日志文件中,占用的是磁盘内存,一般不会经常出现卡(运行极慢)的现象,但如果磁盘内存占用比较高时,需要对日志进行备份处理,然后清理日志;
9.异常日志不要只打一半,要输出全部错误信息
反例:
log.error("xxx业务处理异常");
log.error("xxx业务处理异常", e.getMessage());
e.getMessage()不会记录详细的堆栈异常信息,只会记录错误基本描述信息,不利于排查问题。
正例:
log.error("xxx业务处理异常 requestNo={}", requestNo, e);
10.禁止在线上环境开启 debug
一般业务系统的debug日志较多,引入的第三方框架debug日志也较多,随着业务交易的增多,容易占用磁盘内存空间,最后可能会影响正常业务系统的运行
,所以生产环境禁止开启debug
11.不要既打印了异常日志,又抛出异常
try { // TODO 业务代码处理 } catch (Exception e) { log.error("xxx业务处理异常", e); // BusinessException:自定义业务处理异常类 throw new BusinessException("xxx业务处理异常", e); }
此处会打印两次异常日志:
第一次是log.error("xxx业务处理异常", e)会打印一次;第二次是throw new BusinessException("xxx业务处理异常", e)会打印一次;
可以根据具体情况来选择,例如此处就应该抛异常处理,那么可以仅使用throw new BusinessException("xxx业务处理异常", e)即可
12.避免重复打印日志
如果一行日志可以表达清楚,则使用一行打印即可,避免日志信息冗余
反例:
log.info("创建用户信息 userId={}", userId); log.info("创建用户信息 userName={}", userName);
正例:
log.info("创建用户信息 userId={},userName={}", userId, userName);
13.日志文件分离
根据不同的日志级别,打印在不同的日志文件中,例如debug、info、warn、error日志级别的日志分别创建一个日志文件debug.log、info.log、warn.log、error.log进行日志打印;
将不同类型的日志进行日志分类,例如access.log、error.log等
14.核心功能模块,建议打印较完整的日志
业务系统中,核心功能的代码,尽可能打印日志完整,核心代码执行频率极高,出问题时,根据日志信息能快速定位。
15. 避免敏感信息输出
16. 日志单行大小必须不超过200K
17.日志打印时禁止直接用JSON工具将对象转换成String
反例:
public void doSth(){ log.info("do sth and print log, data={}", JSON.toJSONString(data)); // 业务逻辑 ...}
分析:
- fastjson等序列化组件是通过调用对象的get方法将对象进行序列化,如果对象里某些get方法被覆写,存在抛出异常的情况,则可能会因为打印日志而影响正常业务流程的执行。
- 打日志过程中对一些对象的序列化过程也是比较耗性能的。首先序列化过程本身时一个计算密集型过程,费cpu。其次这个过程会产生很多中间对象,对内存也不太友好。
正例:可以使用对象的toString()方法打印对象信息,如果代码中没有对toString()有定制化逻辑的话,可以使用apache的ToStringBulider工具。
public void doSth(){ log.info("do sth and print log, data={}", data.toString()); log.info("do sth and print log, data={}", ToStringBuilder.reflectionToString(data, ToStringStyle.SHORT_PREFIX_STYLE));}
18.常见日志格式
摘要日志摘要日志是格式化的标准日志文件,可用于监控系统进行监控配置和离线日志分析的日志,通常系统对外提供的服务以及集成的第三方服务都需要打印对应的服务摘要日志,摘要日志格式一般需包含以下几类关键信息:
- 调用时间
- 日志链路id(traceId、rpcId)
- 线程名
- 接口名
- 方法名
- 调用耗时
- 调用是否成功(Y/N)
- 错误码
- 系统上下文信息(调用系统名、调用系统ip、调用时间戳、是否压测(Y/N))
2022-12-12 06:05:05,129 [0b26053315407142451016402xxxxx 0.3 - /// - ] INFO [SofaBizProcessor-4-thread-333] - [(interfaceName,methodName,1ms,Y,SUCCESS)(appName,ip地址,时间戳,Y)
详细日志详细日志是用于补充摘要日志中的一些业务参数的日志文件,用于问题排查。详细日志一般包含以下几类信息:
- 调用时间
- 日志链路id(traceId、rpcId)
- 线程名
- 接口名
- 方法名
- 调用耗时
- 调用是否成功(Y/N)
- 系统上下文信息(调用系统名、调用系统ip、调用时间戳、是否压测(Y/N))
- 请求入参
- 请求出参
2022-12-12 06:05:05,129 [0b26053315407142451016402xxxxx 0.3 - /// - ] INFO [SofaBizProcessor-4-thread-333] - [(interfaceName,methodName,1ms,Y,SUCCESS)(appName,ip地址,时间戳,Y)(参数1,参数2)(xxxx)
业务执行日志业务执行日志就是系统执行过程中输出的日志,一般没有特定格式,是开发人员用于跟踪代码执行逻辑而打印的日志,个人看来在摘要日志、详细日志、错误日志齐全的情况下,需要打印系统执行日志的地方比较少。如果一定要打印业务执行日志,需要关注以下几个点:
- 这个日志是否一定要打印?如果不打印是否会影响后续问题排查,如果打印这个日志后续输出频率是否会太高,造成线上日志打印过多。
- 日志格式是否辨识度高?如果后续对该条日志进行监控或清洗,是否存在无法与其他日志区分或者每次打印的日志格式都不一致的问题?
- 输出当前执行的关键步骤和描述,明确的表述出打印该条日志的作用,方便后续维护人员阅读。
- 日志中需包含明确的打印意义,当前执行步骤的关键参数。
建议格式:[日志场景][日志含义]带业务参数的具体信息
[scene_bind_feature][feature_exists]功能已经存在[tagSource='MIF_TAG',tagValue='123']
,