Java日志

一、日志简介

1.1 日志是什么

日志：记录程序运行轨迹，方便查找关键信息，也方便快速定位解决问题。

       通常，Java程序员开发项目时都是依赖Ecplise/IDEA等集成开发工具的debug调试功能来跟踪解决bug。日志的作用就是在测试、生产环境没有debug调试工具时开发和测试人员定位问题的手段。

1.2 日志作用

问题追踪：辅助排查和定位线上问题，优化程序运行性能。

状态监控：通过日志分析，可以监控系统的运行状态。

安全审计：审计主要体现在安全上，可以发现非授权的操作。

---

二、日志框架

2.1 常用的日志框架

2.1.1 Logging

       这是Java自带的日志工具类，在JDK1.5开始就有，在java.util.logging包下。通常情况下使用的不多。

2.1.2 commons-logging

       日志的门面接口，也是Apache最早提供的日志门面接口，用户可以根据喜好选择不同的日志实现框架，而不必改动日志定义。现在已经不流行了。

2.1.3 Slf4j

       全称“Simple Logging Facade for Java”，为java提供简单日志门面。允许用户根据自己的喜好，在工程中通过slf4j接入不同的日志系统。
       因此slf4j入口就是众多接口的集合，他不负责具体的日志实现，只在编译时负责寻咋合适的日志系统进行绑定。具体有哪些接口全都定义在slf4j-api中。查看slf4j-api源码可以发现，里面除了public final class LoggerFactory类之外，都是接口定义。因此slf4j-api本质就是一个接口定义。

2.1.4 Log4j

       Log4j是Apache的一个开源日志框架，也是市场占有率最多的框架。log4j 在 2015.08.05 这一天被 Apache 宣布停止维护了。

2.1.5 Log4j2

       log4j升级版，不兼容log4j。

2.1.6 Logback

       是slf4j的原生实现框架，比log4j拥有更多的优点、特性和更强的性能，基本代替log4j称为主流。
       Logback相比log4j拥有更快的运行速度。logback重写了内部的实现，在某些特定的场景上面，甚至可以比之前的速度快上10倍。在保证logback组件更加快速的同时所需的内存则更少。

2.2 日志框架怎么选

       commons-loggin、slf4j是一种日志抽象门面，不是具体的日志框架。
       log4j、logback是具体的日志实现框架。

---

三、记录日志时机

3.1 编程语言提示异常

       如今各类主流编程语言都包括异常机制，业务相关的流行框架有完整的异常模块。这类捕获的异常是系统告知开发人员需要加以关注的，是质量非常高的报错。应当适当记录日志，根据实际结合业务的情况使用warn和error级别。

3.2 业务流程预期不符

       除开平台以及编程语言异常外，项目代码中结果与期望不符也是日志场景之一，简单来说所有流程分支都可以加入考虑。取决于开发人员判断能否容忍情形发生。常见的适合场景包括外部参数不正确，数据处理问题导致返回码不在合理范围内。

3.3 系统核心角色、组件、关键动作

       系统中核心角色触发的业务动作是需要多加关注的，是衡量系统正常运行的重要指标，建议记录INFO级别日志，比如电商系统用户从登录到下单的整个流程、微服务个服务节点交互、核心数据表增删改、核心组件运行等。如果日志频度高或打印量特别大，可以提炼关键点INFO记录，其余酌情考虑DEBUG级别。

3.4 系统初始化

       系统或服务的启动参数。核心模块或者组件初始化过程中往往依赖一些关键配置，根据参数不同会提供不一样的服务。务必在这里记录INFO日志，打印出参数以及启动完成态服务表述。

---

四、日志打印

4.1 日志变量定义

       日志变量往往不变，最好定义成final static。

private final static Logger logger = LoggerFactory.getLogger(StartApplication.class);

       通常一个类只有一个logger对象，如果有父类可以定义在父类中。
       日志变量类型定义为门面接口（org.slf4j.Logger），实现类可以是Log4j、Logback等日志实现框架，不要把实现类定义为变量类型，否则日志切换不方便，也不符合抽象编程思想。

4.2 参数占位格式

       使用参数化形式，{}占位，[]参数隔离

logger.info("Save order with order no：[{}], and order amount：[{}]",2,3);

       输出：

2021-03-12 13:51:20.510  INFO 1280 --- [  restartedMain] com.KafkaStartApplication : 
Save order with order no：[2], and order amount：[3]

       这种可读性好，这样一看就知道[]里面是输出的动态参数，{}用来占位类似绑定变量，而且只有真正准备打印的时候才会处理参数，方便定位问题。
       如果日志框架不支持参数化形式，且日志输出时不支持该日志级别时会导致对象冗余创建，浪费内存，此时需要使用isXXEnable判断

if(logger.isDebugEnabled()) {
	// 如果日志不支持参数化形式，debug又没开启，那字符串拼接就是无用的代码拼接，影响系统性能
	logger.debug("Save order with order no: "+orderNo+",and order amount: "+orderAmount);
}

4.3 日志基本格式

       日志输出主要在文件中，应包括以下内容：<b日志时间、日志级别主要作用、调用链表示(可选)、线程名称、日志记录器名称、日志内容、异常堆栈（不一定有）。

2021-03-12 14:09:37.117  INFO 8056 --- [  restartedMain] com.KafkaStartApplication : Started KafkaStartApplication in 9.03 seconds (JVM running for 9.683)

4.3.1 日志时间

       作为日志产生的日期和时间，这个数据非常重要，一般精确到毫秒。由于线上一般配置为按天滚动日志文件，日期标识在文件名上，所以可以不放在这个时间中，使用HH:mm:ss.SSS格式

4.3.2 日志级别

       日志输出都是分级别的，不同的设置不同的场合打印不同的日志。

4.3.2.1 DEBUG

       主要输出调试性质的内容，该级别日志主要用于在开发、测试阶段输出。该级别的日志应尽可能的详尽，开发人员可以将各类详细信息记录到DEBUG里，起调试作用，包括参数信息，调试细节信息，返回值信息等等，便于在开发、测试阶段出现问题或者异常时，对其进行分析。

4.3.2.2 INFO

       主要记录系统关键信息，旨在保留系统正常工作期间关键运行指标，开发人员可以将初始化系统配置、业务状态变化信息，或者用户业务流程中的核心处理记录到INFO日志中，方便日常运维工作以及错误回溯时上下文场景重现。建议在项目完成后，在测试环境将日志级别调成INFO，然后通过INFO级别的信息看卡能否了解这个应用的运用情况，如果出现问题后是否这些日志能否提供有用的排查问题的信息。

4.3.2.3 WARN

       主要输出警告性质的内容，这些内容是可以预知且是有规划的，比如，某个方法入参为空或者该参数的值不满足运行该方法的条件时。在WARN级别时应输出较为详尽的信息，以便于日后对日志进行分析。

4.3.2.4 ERROR

       主要针对于一些不可预知的信息，诸如，错误、异常等。在catch中抓获的网络通信、数据库连接异常，若异常对系统的整个流程影响不大，可以使用WARN级别日志输出。在输出ERROR级别的日志时，尽量多的输出方法参数、方法执行过程中产生的对象等数据，在带有错误、异常对象的数据时，需要将该对象一并输出。

4.3.2.5 INFO和DEBUG的选择

       DEBUG级别比INFO低，包含调试时更详细的了解系统运行状态的东西，比如变量的值等等，都可以输出到DEBUG日志里。INFO是在线日志默认的输出级别，反馈系统的当前状态给最终用户看。输出的信息，应该对最终用户具有实际意义。从功能角度来说，INFO输出的信息可以看作软件产品的一部分，所以需要谨慎对待，不可随便输出。尝试记录INFO日志时不妨在头脑中模拟线上运行，如果这条日志会被频繁打印或者大部分时间对于纠错起不到作用，就应该考虑下调为DEBUG级别。
       由于INFO和DEBUG打印量远大于ERROR，处于前文日志性能的考虑，如果代码为核心带啊，执行频率非常高，考虑下调为DEBUG级别。
       日志输出时多线程公用的，如果有另外一个线程正在输出日志，上面的记录就会被打断，最终显示输出和预想的就会不一样。

4.3.2.6 WARN和ERROR的选择

       当方法或功能处理过程中产生不符合预期结果或框架报错时可以考虑使用，常见问题处理方法包括：

增加判断处理逻辑，尝试本地解决：增加逻辑判断吞掉报警永远是最优解
抛出异常，交给上层逻辑
记录日志，报警提醒
使用返回码包装错误做返回

       一般来说，WARN级别不会短信报警，ERROR级别则会短信报警甚至电话报警，ERROR级别的日志意味着系统中发生了非常严重的问题，必须有人马上处理，比如数据库不可用，系统的关键业务流程走不下去。错误的使用反而带来严重的后果，不区分问题的重要程度，只要有问题就ERROR记录，其实是错误的。对于成熟的系统，都会有一套完整的报错机制，那这个错误信息什么时候需要发出来，很多时候都是依据单位时间内ERROR日志错误数量来决定的。因此如果我们不分轻重缓急，一律ERROR对待，就会徒增报错频率，久而久之，报警失去了原始意义。
       WARN代表可恢复的异常，此次失败不影响下次业务的执行，开发人员会苦恼某些场景下几次失败可容忍，频率高的时候需要提醒，记录ERROR的结果时线上时不时出现容忍范围内的报警，这是报警是无意义的。但反之不记录ERROR日志，真正出现问题则不会有实时报警，错过最佳处理时机。

4.3.3 调用链标识

在分布式应用中，用户的一个请求会调用若干个服务完成，这些服务可能还是嵌套调用的，因此完成一个请求的日志并不在一个应用的日志文件，而是分散在不同服务器上不同应用节点的日志文件中。该标识是为了串联一个请求在系统中的调用日志。

4.3.4 线程名称

       输出该日志的线程名称，一般在一个应用中一个同步请求由同一线程完成，输出完整线程名称可以在各个请求产生的日志中进行分类，便于分清当前请求上下文日志。

4.3.5 日志记录器名称

       一般使用类名，日志文件中可以输出简单的类名即可，看实际情况是否需要使用报名和行号等信息。主要用于看到日志后到哪个类中找日志输出，便于定位问题所在。

4.3.6 日志内容

       禁用System.out.println
       便餐替换日志拼接。
       输出日志对象，应在其类中实现快速的toString方法，以便在日志输出时仅输出这个对象名和hashCode。
       预防空指针：不要在日志中调用对象的方法获取值，除非确保该对象肯定不为null，否在很有可能因日志问题而导致应用产生空指针异常。

// 不推荐
log.debug( "Load student(id={}), name: {}" , id , student.getName() );
// 推荐
log.debug( "Load student(id={}), student: {}" , id , student );

       对于一些一定需要进行拼接字符串，或者需要耗费时间、浪费内存才能产生的日志内容作为日志输出时，应使用log.isXXXEnable()进行判断后再进行拼接处理。

if (log.isDebugEnable()) {
	StringBuilder builder = new StringBuilder();
	for (Student student : students) {
		builder.append("student: ").append(student);
	}
	builder.append("value: ").append(JSON.toJSONString(object));
	log.debug( "debug log example, detail: {}" , builder );
}

4.3.7 异常堆栈

       异常堆栈一般会出现在ERROR或者WARN级别日志中，异常堆栈含有丰富调用链的系统，以及异常产生的根源。异常堆栈的日志属于上一行日志的，在日志收集时需要将其划至上一行中。

4.4 日志文件

       日志文件放置于固定的目录中，按照一定的模板进行命名，推荐的日志文件名称：
       当前正在写入的日志文件名：[-].log
       已经滚入历史的日志文件名：[-].log.

4.5 日志配置

       根据不同的环境配置不同的日志输出方式：
       本地调试可以将日志输出到控制台。
       测试环境或者生产环境输出到文件中，每天产生一个文件，如果日志量庞大可以每小时产生一个日志文件。
       生产环境的文件输出，可以考虑使用异步文件输出，该种方法日志并不会马上刷新到文件中去，会产生日志延迟，在停止应用时可能导致一些还在内存中的日志未能及时刷新到新文件中而产生丢失，如果对于应用的要求不是非常高的话，可暂不考虑异步。
       logback日志工具可以在日志文件滚动后将前一文件进行压缩，以减少磁盘空间的占用，若使用logback对于日志量庞大的建议开启此功能。

4.6 日志使用规范

       在一个对象中通常只使用一个Logger对象，Logger是static final，只有在少数需要在构造方法中传递Logger的情况才private final。
       输出Exceptions的全部Throwable信息。因为log.error(msg)和log.error(msg,e.getMessage())这样的日志输出方法会丢失掉最重要的StackTrace信息。

void foo(){
	try{
		//do somehing
	}catch(Exception e){
		log.error(e.getMessage());//错误示范

		log.erroe("Bad Things",e.getMessage());//错误示范

		log.error("Bad Things",e);//正确演示
	}
}

       不允许记录日志后又抛出异常。如捕获异常后又抛出了自定义业务异常，此时无需记录错误日志，由最终捕获方进行异常处理。不能又抛出异常，又打印错误日志，不然会造成重复输出日志。

void foo() throws LogException{
	try{
		//do somehing
	}catch(Exception e){
	log.error("Bad Things",e);//正确
	throw new LogException("Bad Things",e);
	}
}

       不允许使用标准输出，包括System.out.println()和System.err.println()。因为这个只会打印到控制台，而不会记录到日志文件中，不方便管理日志。此外，标准输出不会显示类名和行号信息，一袋代码中大量出现标准输出的代码，且日志中打印有标准输出的内容，很难定位日志内容和日志打印的位置，根本无法排查问题，想删除无用日志输出也不改动。

void foo(){
	try{
		//do somehing
	}catch(Exception e){
	Syste.out.println(e.getMessage());//错误

	System.error.println(e.getMessage());//错误

	log.error("Bad Things",e);//正确
	}
}

void foo(){
	try{
		//do somehing
	}catch(Exception e){
	e.printStacktrace();//错误

	log.error("Bad Things",e);//正确
	}
}