针对业务开发人员通常面对的业务需求,我们将日志分为操作(请求)日志和系统运行日志,操作(请求)日志可以让管理员或者运营人员方便简单的在系统界面中查询追踪用户具体做了哪些操作,便于分析统计用户行为;系统运行日志又分为不同的级别
(Log4j2): OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL,这些日志级别由开发人员在代码编写时确定,并编写在代码中,系统运行时记录,方便系统开发人员分析定位解决问题,查找系统性能瓶颈。
我们可以自定义注解利用AOP拦截Controller请求实现系统(日志)操作日志的记录,系统运行日志可以使用log4j2或者logback。在SpringCloud微服务架构下,可以使用Gateway统一记录操作(请求)日志,由于微服务分布式集群部署,同一服务也存在多个,这里的日志追踪就需要借助Skywalking和ELK来实现具体的追踪分析记录。
由于最近爆发的log4j2和logback的漏洞问题,请选择最新修复漏洞的版本。根据网上很多性能的对比,log4j2显著优于logback,所以我们将SpringBoot默认的日志Logback修改为Log4j2。
在框架设计时,我们尽可能的考虑到日志系统的使用场景,将日志系统实现方式设计为可动态配置的,然后具体根据业务需求,选择使用合适的日志系统,根据常用业务需求,我们暂将微服务日志系统以如下方式实现:
操作日志:
- 使用AOP特性,自定义注解拦截Controller请求实现系统操作日志
优势:实现简单,通过注解即实现记录操作日志。
缺点:需要硬编码到代码中,灵活性差。
- 在网关Gateway通过读取配置,统一记录操作日志
优势:可配置,实时更改需要记录哪些操作日志。
缺点:配置实现稍复杂。
操作日志分为两种实现方式,各有优劣,不管哪种实现方式,日志记录都通过Log4j2来记录,通过Log4j2的配置,可动态选择记录到文件、关系型数据库MySQL、NoSQL数据库MongoDB、消息中间件Kafka等。
系统日志:
- Log4j2记录日志,ELK采集分析展示
系统日志我们就采取通用的日志记录方式即可,通过Log4j2记录到日志文件,在通过ELK采集分析展示。
下面是具体实现步骤:
一、配置SkyWalking+Log4j2打印链路追踪TraceId
很早之前,大家最常用的Java日志记录工具是log4j,后来由log4j的创始人设计了另外一款日志记录工具logback,它比log4j更加优秀,详细对比可参照官方说明,所以SpringBoot默认使用logback作为日志记录工具。近年来Apache对Log4j进行了升级,推出了log4j2版本,无论从设计还是性能方面都优于log4j和logback,详细对比可自行测试,网上也有相应的测试报告,这里不详细说明。所以,我们肯定需要选择目前最合适的日志记录工具。
1、将SpringBoot默认日志Logback修改为Log4j2
排除spring-boot-starter-web等依赖的logback
<dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> <!-- 去除springboot默认的logback配置--> <exclusions> <exclusion> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-logging</artifactId> </exclusion> </exclusions> </dependency>
引入spring-boot-starter-log4j2依赖,因为对应版本的SpringBoot引入的Log4j2版本漏洞问题,这里排除默认log4j2版本,引入最新的修复漏洞版本。
<dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-log4j2</artifactId> <exclusions> <exclusion> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> </exclusion> <exclusion> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> </exclusion> </exclusions> </dependency>
引入log4j2修复漏洞版本的依赖
<!-- 修复log4j2漏洞 --> <log4j2.version>2.17.1</log4j2.version> <!-- log4j2支持异步日志,导入disruptor依赖,不需要支持异步日志,也可以去掉该依赖包 --> <log4j2.disruptor.version>3.4.4</log4j2.disruptor.version> <!-- 修复log4j2漏洞 --> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> <version>${log4j2.version}</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>${log4j2.version}</version> </dependency> <!-- log4j2读取spring配置的依赖库 --> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-spring-boot</artifactId> <version>${log4j2.version}</version> </dependency> <!-- log4j2支持异步日志,导入disruptor依赖,不需要支持异步日志,也可以去掉该依赖包 --> <dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>${log4j2.disruptor.version}</version> </dependency>
因为在SpringBoot中存在很多子依赖,以及在jar包中存在其他依赖logback的jar包,这里需要使用Maven工具来定位查找这些依赖Logback的jar包,逐一排除掉。在工程文件夹下执行Maven命令:
mvn dependency:tree -Dverbose -Dincludes="ch.qos.logback:logback-classic"
logback依赖
如上图所示都是依赖logback的jar包,需要都排除,否则会和log4j2冲突。
2、集成可打印SkyWalking链路追踪TraceId的依赖
<!-- skywalking-log4j2链路id版本号 --> <skywalking.log4j2.version>6.4.0</skywalking.log4j2.version> <!-- skywalking-log4j2链路id --> <dependency> <groupId>org.apache.skywalking</groupId> <artifactId>apm-toolkit-log4j-2.x</artifactId> <version>${skywalking.log4j2.version}</version> </dependency>
2、Log4j2配置实例
配置自己需要的log4j2.xml,在Pattern中配置[%traceId]可以显示链路追踪ID, 如果要读取springboot中yaml的配置,一定要引入log4j-spring-boot依赖。
<?xml version="1.0" encoding="UTF-8"?> <!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL --> <configuration monitorInterval="5" packages="org.apache.skywalking.apm.toolkit.log.log4j.v2.x"> <!--变量配置--> <Properties> <!-- 格式化输出:%date表示日期,traceId表示微服务Skywalking追踪id,%thread表示线程名,%-5level:级别从左显示5个字符宽度 %m:日志消息,%n是换行符--> <!-- %c 输出类详情 %M 输出方法名 %pid 输出pid %line 日志在哪一行被打印 --> <!-- %logger{80} 表示 Logger 名字最长80个字符 --> <!-- value="${LOCAL_IP_HOSTNAME} %date [%p] %C [%thread] pid:%pid line:%line %throwable %c{10} %m%n"/>--> <property name="CONSOLE_LOG_PATTERN" value="%d %highlight{%-5level [%traceId] pid:%pid-%line}{ERROR=Bright RED, WARN=Bright Yellow, INFO=Bright Green, DEBUG=Bright Cyan, TRACE=Bright White} %style{[%t]}{bright,magenta} %style{%c{1.}.%M(%L)}{cyan}: %msg%n"/> <property name="LOG_PATTERN" value="%d %highlight{%-5level [%traceId] pid:%pid-%line}{ERROR=Bright RED, WARN=Bright Yellow, INFO=Bright Green, DEBUG=Bright Cyan, TRACE=Bright White} %style{[%t]}{bright,magenta} %style{%c{1.}.%M(%L)}{cyan}: %msg%n"/> <!-- 读取application.yaml文件中设置的日志路径 logging.file.path--> <property name="FILE_PATH" value="/var/log"/> <property name="FILE_STORE_MAX" value="50MB"/> <property name="FILE_WRITE_INTERVAL" value="1"/> <property name="LOG_MAX_HISTORY" value="60"/> </Properties> <appenders> <!-- 控制台输出 --> <console name="Console" target="SYSTEM_OUT"> <!-- 输出日志的格式 --> <PatternLayout pattern="${CONSOLE_LOG_PATTERN}"/> <!-- 控制台只输出level及其以上级别的信息(onMatch),其他的直接拒绝(onMismatch) --> <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/> </console> <!-- 这个会打印出所有的info及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档 --> <RollingRandomAccessFile name="RollingFileInfo" fileName="${FILE_PATH}/info.log" filePattern="${FILE_PATH}/INFO-%d{yyyy-MM-dd}_%i.log.gz"> <!-- 控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)--> <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/> <PatternLayout pattern="${LOG_PATTERN}"/> <Policies> <!--interval属性用来指定多久滚动一次,默认是1 hour--> <TimeBasedTriggeringPolicy interval="${FILE_WRITE_INTERVAL}"/> <SizeBasedTriggeringPolicy size="${FILE_STORE_MAX}"/> </Policies> <!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖--> <DefaultRolloverStrategy max="${LOG_MAX_HISTORY}"/> </RollingRandomAccessFile> <!-- 这个会打印出所有的debug及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档--> <RollingRandomAccessFile name="RollingFileDebug" fileName="${FILE_PATH}/debug.log" filePattern="${FILE_PATH}/DEBUG-%d{yyyy-MM-dd}_%i.log.gz"> <!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)--> <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/> <PatternLayout pattern="${LOG_PATTERN}"/> <Policies> <!--interval属性用来指定多久滚动一次,默认是1 hour--> <TimeBasedTriggeringPolicy interval="${FILE_WRITE_INTERVAL}"/> <SizeBasedTriggeringPolicy size="${FILE_STORE_MAX}"/> </Policies> <!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖--> <DefaultRolloverStrategy max="${LOG_MAX_HISTORY}"/> </RollingRandomAccessFile> <!-- 这个会打印出所有的warn及以上级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档--> <RollingRandomAccessFile name="RollingFileWarn" fileName="${FILE_PATH}/warn.log" filePattern="${FILE_PATH}/WARN-%d{yyyy-MM-dd}_%i.log.gz"> <!-- 控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)--> <ThresholdFilter level="warn" onMatch="ACCEPT" onMismatch="DENY"/> <PatternLayout pattern="${LOG_PATTERN}"/> <Policies> <!-- interval属性用来指定多久滚动一次,默认是1 hour --> <TimeBasedTriggeringPolicy interval="${FILE_WRITE_INTERVAL}"/> <SizeBasedTriggeringPolicy size="${FILE_STORE_MAX}"/> </Policies> <!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖 --> <DefaultRolloverStrategy max="${LOG_MAX_HISTORY}"/> </RollingRandomAccessFile> <!-- 这个会打印出所有的error及以上级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档 --> <RollingRandomAccessFile name="RollingFileError" fileName="${FILE_PATH}/error.log" filePattern="${FILE_PATH}/ERROR-%d{yyyy-MM-dd}_%i.log.gz"> <!--只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)--> <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/> <PatternLayout pattern="${LOG_PATTERN}"/> <Policies> <!--interval属性用来指定多久滚动一次,默认是1 hour--> <TimeBasedTriggeringPolicy interval="${FILE_WRITE_INTERVAL}"/> <SizeBasedTriggeringPolicy size="${FILE_STORE_MAX}"/> </Policies> <!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖--> <DefaultRolloverStrategy max="${LOG_MAX_HISTORY}"/> </RollingRandomAccessFile> </appenders> <!-- Logger节点用来单独指定日志的形式,比如要为指定包下的class指定不同的日志级别等 --> <!-- 然后定义loggers,只有定义了logger并引入的appender,appender才会生效 --> <loggers> <!--过滤掉spring和mybatis的一些无用的DEBUG信息--> <logger name="org.mybatis" level="info" additivity="false"> <AppenderRef ref="Console"/> </logger> <!--若是additivity设为false,则子Logger 只会在自己的appender里输出,而不会在父Logger 的appender里输出 --> <Logger name="org.springframework" level="info" additivity="false"> <AppenderRef ref="Console"/> </Logger> <AsyncLogger name="AsyncLogger" level="debug" additivity="false"> <AppenderRef ref="Console"/> <AppenderRef ref="RollingFileDebug"/> <AppenderRef ref="RollingFileInfo"/> <AppenderRef ref="RollingFileWarn"/> <AppenderRef ref="RollingFileError"/> </AsyncLogger> <root level="trace"> <appender-ref ref="Console"/> <appender-ref ref="RollingFileDebug"/> <appender-ref ref="RollingFileInfo"/> <appender-ref ref="RollingFileWarn"/> <appender-ref ref="RollingFileError"/> </root> </loggers> </configuration>
3、IDEA控制台显示彩色日志
在上面Log4j2.xml中*LOG_PATTERN的配置已经设置了,每种日志显示同的颜色,在IDEA中默认没有效果,这里需要设置一下:点击右上角运行窗口的Edit
Configurations,在VM options中添加-Dlog4j.skipJansi=false ,再次运行,就可以看到IDEA控制台显示彩色日志了。
二、自定义扩展日志级别,实现可配置的日志存取方式
虽然Log4j2提供了将日志保存到MySQL、MongoDB等,但是这里并不建议直接使用Log4j2将日志保存到MySQL、MongoDB等数据库,这样做不但在每个微服务引入Log4j2组件的时候,增加数据库链接池数量(不要考虑复用业务系统已有的数据库连接池,因为不是每个微服务都要有日志表),还有在高并发的情况下,对于整个业务系统来说这将是致命的问题。如果考虑到项目系统访问和操作很少,为了降低系统维护的复杂度,避免引入过多组件和环境,使用这种方式的话,那么就需要考虑业务系统是否需要使用微服务架构的问题了。
在高并发等情况下,我们推荐有两种方式来记录操作日志:一是将日志先保存到消息队列,作为数据库的一个缓冲,由消费者分批将日志数据保存到数据库,降低耦合,尽量使日志的操作不影响业务操作;二是使用Log4j2的异步文件日志,配合搭建ELK日志采集分析系统,来实现保存操作日志功能。
1、自定义操作日志和接口访问日志级别
默认的日志记录级别不能够满足我们记录操作日志和接口日志的需求,这里我们自己扩展Log4j2的日志级别来实现自定义的操作日志和接口日志。
新建LogLevelConstant定义日志级别
/** * 自定义日志级别 * 业务操作日志级别(级别越高,数字越小) off 0, fatal 100, error 200, warn 300, info 400, debug 500 * warn operation api * @author GitEgg */ public class LogLevelConstant { /** * 操作日志 */ public static final Level OPERATION_LEVEL = Level.forName("OPERATION", 310); /** * 接口日志 */ public static final Level API_LEVEL = Level.forName("API", 320); /** * 操作日志信息 */ public static final String OPERATION_LEVEL_MESSAGE = "{type:'operation', content:{}}"; /** * 接口日志信息 */ public static final String API_LEVEL_MESSAGE = "{type:'api', content:{}}"; }
这里需要注意在使用日志时,需要使用@Log4j2注解而不是@Slf4j,因为@Slf4j默认提供的方法不能设置日志级别,测试代码:
log.log(LogLevelConstant.OPERATION_LEVEL,"操作日志:{} , {}", "参数1", "参数2"); log.log(LogLevelConstant.API_LEVEL,"接口日志:{} , {}", "参数1", "参数2");
2、自定义操作日志注解
在记录操作日志时,我们可能不需要在代码中直接写记录日志的代码,这里可以自定义注解,通过注解来实现操作日志的记录。首先根据Spring AOP的特性自定义三类日志记录类型、BeforeLog(执行方法之前)AfterLog(执行方法之后)、AroundLog(执行前和执行后)
BeforeLog
/** * * @ClassName: BeforeLog * @Description: 记录前置日志 * @author GitEgg * @date 2019年4月27日 下午3:36:29 * */ @Retention(RetentionPolicy.RUNTIME) @Target({ ElementType.METHOD }) public @interface BeforeLog { String name() default ""; }
AfterLog
/** * * @ClassName: AfterLog * @Description: 记录后置日志 * @author GitEgg * @date 2019年4月27日 下午3:36:29 * */ @Retention(RetentionPolicy.RUNTIME) @Target({ ElementType.METHOD }) public @interface AfterLog { String name() default ""; }
AroundLog
/** * * @ClassName: AroundLog * @Description:记录around日志 * @author GitEgg * @date 2019年4月27日 下午3:36:29 * */ @Retention(RetentionPolicy.RUNTIME) @Target({ ElementType.METHOD }) public @interface AroundLog { String name() default ""; }
上面自定义注解之后,再编写LogAspect日志记录的切面实现
/** * * @ClassName: LogAspect * @Description: * @author GitEgg * @date 2019年4月27日 下午4:02:12 * */ @Log4j2 @Aspect @Component public class LogAspect { /** * Before切点 */ @Pointcut("@annotation(com.gitegg.platform.base.annotation.log.BeforeLog)") public void beforeAspect() { } /** * After切点 */ @Pointcut("@annotation(com.gitegg.platform.base.annotation.log.AfterLog)") public void afterAspect() { } /** * Around切点 */ @Pointcut("@annotation(com.gitegg.platform.base.annotation.log.AroundLog)") public void aroundAspect() { } /** * 前置通知 记录用户的操作 * * @param joinPoint 切点 */ @Before("beforeAspect()") public void doBefore(JoinPoint joinPoint) { try { // 处理入参 Object[] args = joinPoint.getArgs(); StringBuffer inParams = new StringBuffer(""); for (Object obj : args) { if (null != obj && !(obj instanceof ServletRequest) && !(obj instanceof ServletResponse)) { String objJson = JsonUtils.objToJson(obj); inParams.append(objJson); } } Method method = getMethod(joinPoint); String operationName = getBeforeLogName(method); addSysLog(joinPoint, String.valueOf(inParams), "BeforeLog", operationName); } catch (Exception e) { log.error("doBefore日志记录异常,异常信息:{}", e.getMessage()); } } /** * 后置通知 记录用户的操作 * * @param joinPoint 切点 */ @AfterReturning(value = "afterAspect()", returning = "returnObj") public void doAfter(JoinPoint joinPoint, Object returnObj) { try { // 处理出参 String outParams = JsonUtils.objToJson(returnObj); Method method = getMethod(joinPoint); String operationName = getAfterLogName(method); addSysLog(joinPoint, "AfterLog", outParams, operationName); } catch (Exception e) { log.error("doAfter日志记录异常,异常信息:{}", e.getMessage()); } } /** * 前后通知 用于拦截记录用户的操作记录 * * @param joinPoint 切点 * @throws Throwable */ @Around("aroundAspect()") public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable { // 出参 Object value = null; // 拦截的方法是否执行 boolean execute = false; // 入参 Object[] args = joinPoint.getArgs(); try { // 处理入参 StringBuffer inParams = new StringBuffer(); for (Object obj : args) { if (null != obj && !(obj instanceof ServletRequest) && !(obj instanceof ServletResponse)) { String objJson = JsonUtils.objToJson(obj); inParams.append(objJson); } } execute = true; // 执行目标方法 value = joinPoint.proceed(args); // 处理出参 String outParams = JsonUtils.objToJson(value); Method method = getMethod(joinPoint); String operationName = getAroundLogName(method); // 记录日志 addSysLog(joinPoint, String.valueOf(inParams), String.valueOf(outParams), operationName); } catch (Exception e) { log.error("around日志记录异常,异常信息:{}", e.getMessage()); // 如果未执行则继续执行,日志异常不影响操作流程继续 if (!execute) { value = joinPoint.proceed(args); } throw e; } return value; } /** * 日志入库 addSysLog(这里用一句话描述这个方法的作用) * * @Title: addSysLog * @Description: * @param joinPoint * @param inParams * @param outParams * @param operationName * @return void */ @SneakyThrows public void addSysLog(JoinPoint joinPoint, String inParams, String outParams, String operationName) throws Exception { try { HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()) .getRequest(); String ip = request.getRemoteAddr(); GitEggLog gitEggLog = new GitEggLog(); gitEggLog.setMethodName(joinPoint.getSignature().getName()); gitEggLog.setInParams(String.valueOf(inParams)); gitEggLog.setOutParams(String.valueOf(outParams)); gitEggLog.setOperationIp(ip); gitEggLog.setOperationName(operationName); log.log(LogLevelConstant.OPERATION_LEVEL,LogLevelConstant.OPERATION_LEVEL_MESSAGE, JsonUtils.objToJson(gitEggLog)); } catch (Exception e) { log.error("addSysLog日志记录异常,异常信息:{}", e.getMessage()); throw e; } } /** * 获取注解中对方法的描述信息 * * @param joinPoint 切点 * @return 方法描述 * @throws Exception */ public Method getMethod(JoinPoint joinPoint) throws Exception { String targetName = joinPoint.getTarget().getClass().getName(); String methodName = joinPoint.getSignature().getName(); Object[] arguments = joinPoint.getArgs(); Class<?> targetClass = Class.forName(targetName); Method[] methods = targetClass.getMethods(); Method methodReturn = null; for (Method method : methods) { if (method.getName().equals(methodName)) { Class<?>[] clazzs = method.getParameterTypes(); if (clazzs.length == arguments.length) { methodReturn = method; break; } } } return methodReturn; } /** * * getBeforeLogName(获取before名称) * * @Title: getBeforeLogName * @Description: * @param method * @return String */ public String getBeforeLogName(Method method) { String name = method.getAnnotation(BeforeLog.class).name(); return name; } /** * * getAfterLogName(获取after名称) * * @Title: getAfterLogName * @Description: * @param method * @return String */ public String getAfterLogName(Method method) { String name = method.getAnnotation(AfterLog.class).name(); return name; } /** * * getAroundLogName(获取around名称) * @Title: getAroundLogName * @Description: * @param method * @return String * */ public String getAroundLogName(Method method) { String name = method.getAnnotation(AroundLog.class).name(); return name; }