目录
本文概览:在将一个jar包迁移成一个spring boot服务时,需要根据定时任务划分日志文件,通过Logback 的SiftingAppender和阿里的TTL线程池来实现。
1 问题背景
之前定时任务是一个jar包,每一个任务是一个main函数,通过执行一个shell命令或者shell脚本来执行一个任务。在执行任务之前通过设置一个环境变量filename,如通过-Dfilename=taskName设定,在log4j中通过如下配置可以为每个任务定义一个日志文件。
1 |
<RollingRandomAccessFile fileName="./logs/task-${filename}.log" .....> |
使用xxl-job改造任务之后,任务工程模块由一个jar包改成一个服务,每一个任务由原来的一个main函数改造成一个jobhandler(可以理解为一个http接口),现在我们需要每一个JobHandler相关操作日志输出到一个日志文件中,而且考虑到不同任务配置相同的JobHandler,所以此时我们需要根据JobHandler和任务参数 来共同决定一个日志文件名称。
为了解决这个问题需要:
(1)不同任务写入不同日志文件。通过logback SiftingAppender来完成,参考https://www.jianshu.com/p/a33902d58530
(2)线程池都是公用的,在两个任务JobHandler并发执行时,这两个任务会公用线程池的work线程,如何保证一个worker线程根据调用方输出到不同的日志文件。通过TTL来实现,参考:https://www.jianshu.com/p/4093add7f2cd
2 Logback SiftingAppender
2.1 SiftingAppender介绍
之前的logger是如下配置,在com.myapp.services包下面有个Services类,这个Service的日志都会输出到固定文件service.log中,
1 2 3 4 5 6 7 8 9 10 |
<logger name="com.myapp.services" level="INFO" additivity="false"> <appender-ref ref="SERVICES-APPENDER"/> <appender-ref ref="ERROR-APPENDER"/> </logger> <!--输出文件--> <appender name="SERVICES-APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>.logs/service.log</file> .. </appender> |
假设有两个请求接口/test1和/test2,都会调用这个Service类,但是需要为这两个接口分别建一个日志文件,一个接口相关操作日志都需要写入到同一个日志文件中:在/test1执行时,service日志写入到test1接口的日志文件中; 在执行/test2时,servcie日志写入到test2接口的日志文件中。SiftingAppender可以动态根据运行时参数来分离log,将log输出到不同日志文件。
2.2 SiftingAppender实例
实现一个根据userid来划分日志,参考官网https://logback.qos.ch/manual/appenders.html的例子。
1、在src/main/resuources添加logback.xml
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 |
<?xml version="1.0" encoding="UTF-8"?> <configuration debug="false" scan="true" scanPeriod="1 seconds"> <appender name="console" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %level %logger{35} - %msg%n</pattern> </encoder> </appender> <appender name="siftInfo" class="ch.qos.logback.classic.sift.SiftingAppender"> <!--discriminator鉴别器,设置运行时动态属性,siftingAppender根据这个属性来输出日志到不同文件 --> <discriminator> <key>userId</key> <defaultValue>unknown</defaultValue> </discriminator> <sift> <!--具体的写日志appender,每一个userId创建一个文件--> <appender name="FILE-${userId}" class="ch.qos.logback.core.rolling.RollingFileAppender"> <append>true</append> <encoder charset="UTF-8"> <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] %-5level %logger{35} - %msg%n</pattern> </encoder> <file>./logs/user-${userId}.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"> <!--定义文件滚动时的文件名的格式--> <fileNamePattern>./logs/%d{yyyyMMdd}/user-${userId}-%i.log</fileNamePattern> <maxFileSize>500MB</maxFileSize> <maxHistory>60</maxHistory> <totalSizeCap>20GB</totalSizeCap> </rollingPolicy> <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>INFO</level> </filter> </appender> </sift> </appender> <root level="info"> <appender-ref ref="console"/> <appender-ref ref="siftInfo"/> </root> </configuration> |
2、测试
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
public class TestLogback { public static final Logger logger = LoggerFactory.getLogger(TestLogback.class); public void test1(){ MDC.put("userId", "userId1"); logger.info("userId1 says hello"); } public void test2(){ MDC.put("userId", "userId2"); logger.info("userId2 says hello"); } public static void main(String[] args) { logger.info("Application started"); final TestLogback testLogback = new TestLogback(); testLogback.test1(); testLogback.test2(); } } |
执行结果如下
1 2 3 |
10:39:42.023 [main] INFO logback.TestLogback - Application started 10:39:42.223 [main] INFO logback.TestLogback - userId1 says hello 10:39:42.236 [main] INFO logback.TestLogback - userId2 says hello |
生成日志文件如下图
3、问题
刚开始没有生效,只有一个user-unkonwn.log,发现是<file>和<fileNamePattern>配置的文件名称不一致造成。
2.3 自定义描述符
在上面的logback.xml并没有使用具体类名来标识的描述符,表示我们使用了默认的描述符MDCBasedDiscriminator。
1 2 3 4 5 |
<!--discriminator鉴别器,设置运行时动态属性,siftingAppender根据这个属性来输出日志到不同文件 --> <discriminator> <key>userId</key> <defaultValue>unknown</defaultValue> </discriminator> |
MDCBasedDiscriminator实现了从MDC中根据key获取value作为日志文件名称,参考上面的例子,就是把${userid}的值放在MDC中。如上面的test1代码
1 2 3 4 |
public void test1(){ MDC.put("userId", "userId1"); logger.info("userId1 says hello"); } |
为了解决本文最初引入的问题:根据JobHandler和任务参数 来生成一个日志文件。我们通过自定义描述符来实现,这个自定义描述符不再从MDC中获取key,而是从自定义的Context中获取,代码如下:
1、自定义context
参考
(1)定义context。保存任务名字和任务参数信息
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
public class TaskContext { String taskName; String taskParam; public String getTaskName() { return taskName; } public void setTaskName(String taskName) { this.taskName = taskName; } public String getTaskParam() { return taskParam; } public void setTaskParam(String taskParam) { this.taskParam = taskParam; } } |
(2)定义TaskContextHolder
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 |
public class TaskContextHolder { private static final TransmittableThreadLocal<TaskContext> taskContextStore = new TransmittableThreadLocal<TaskContext>(); /** * 获取上下文 * * @return */ public static TaskContext getContext() { TaskContext context = taskContextStore.get(); // 没有保存上下文,则返回对象 if (context == null) { taskContextStore.set(new TaskContext()); return taskContextStore.get(); } return context; } /** * 设置上下文 * * @param context */ public static void setContext(TaskContext context) { taskContextStore.set(context); } /** * 清空 */ public static void clear() { taskContextStore.remove(); } |
2、自定义描述符。实现从自定义的context获取日志的名称。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 |
public class TaskContextBasedDiscriminator extends AbstractDiscriminator<ILoggingEvent> { private static String LOG_FILE_KEY = "userId"; private static String DEFAULT_VALUE = "unknown"; public String getKey() { return LOG_FILE_KEY; } public String getDiscriminatingValue(ILoggingEvent iLoggingEvent) { // 这里是从上下文中获取key的值。而MDCBasedDiscriminator从MDK中获取key。 String taskName = TaskContextHolder.getContext().getTaskName(); String taskParam = TaskContextHolder.getContext().getTaskParam(); if (StringUtils.isNotBlank(taskName)) { if (StringUtils.isNotBlank(taskParam)) { return taskName + "-" + taskParam; } else { return taskName; } } else { return DEFAULT_VALUE; } } } |
3、修改logback.xml
原来描述符配置
1 2 3 4 5 |
<!--discriminator鉴别器,设置运行时动态属性,siftingAppender根据这个属性来输出日志到不同文件 --> <discriminator> <key>userId</key> <defaultValue>unknown</defaultValue> </discriminator> |
替换为如下
1 2 |
<!-- 基于上下文获取key --> <discriminator class = "logback.TaskContextBasedDiscriminator"/> |
4、测试
如下一个简单测试demo
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 |
public class TestLogback2 { public static final Logger logger = LoggerFactory.getLogger(TestLogback2.class); public void test1(){ TaskContextHolder.getContext().setTaskName("taskName1"); TaskContextHolder.getContext().setTaskParam("userId1"); logger.info("userId1 says hello"); } public void test2(){ TaskContextHolder.getContext().setTaskName("taskName2"); TaskContextHolder.getContext().setTaskParam("userId2"); logger.info("userId2 says hello"); } public static void main(String[] args) { logger.info("Application started"); final TestLogback2 testLogback = new TestLogback2(); testLogback.test1(); testLogback.test2(); } } |
执行结果如下:
当使用Xxl-Job调度定时任务时,可以在JobHandler执行时进行初始化上下文的taskName和taskParam。如下
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
@JobHandler(value="demoJobHandler") @Component public class DemoJobHandler extends IJobHandler { @Override public ReturnT<String> execute(String param) throws Exception { // 设置上下文信息 TaskContextHolder.getContext().setTaskName("taskNameXXXXX"); TaskContextHolder.getContext().setTaskParam("userIdXXXXX"); // 执行任务 ..... return SUCCESS; } } |
2.4 Sift归档策略(时间和大小)
SiftingAppender通过RollingFileAppender来实现归档,RollingFileAppender的归档常用的策略有两种:基于时间(TimeBasedRollingPolicy)和基于大小(SizeBasedTriggeringPolicy)。
TimeBasedRollingPolicy和SizeBasedTriggeringPolicy这两种策略同时使用时,会有冲突,为了同时兼有两种策略功能,引入了SizeAndTimeBasedRollingPolicy。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 |
<sift> <!--具体的写日志appender,每一个action创建一个文件--> <appender name="file-${action}" class="ch.qos.logback.core.rolling.RollingFileAppender"> <append>true</append> <encoder charset="UTF-8"> <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] %-5level %logger{35} - %msg%n</pattern> </encoder> <file>./logs/executor-${action}.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"> <!--定义文件滚动时的文件名的格式--> <fileNamePattern>./logs/%d{yyyyMMdd}/executor-${action}-%i.log</fileNamePattern> <maxFileSize>500MB</maxFileSize> <maxHistory>60</maxHistory> <totalSizeCap>20GB</totalSizeCap> </rollingPolicy> <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>INFO</level> </filter> </appender> </sift> |
3 改造线程池
为了线程池的work线程可以获取调用线程的Threadlocal,使用阿里的TTL,参考 如下
在代码工程中,我们使用了spring的线程池ThreadPoolTaskExecutor。为了使用阿里TTL,需要重写一个线程池如下,这里只是重新了submit操作,如果使用到线程池其他操作,再重新实现下就可以了。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
public class TtlThreadPoolTaskExecutor extends ThreadPoolTaskExecutor { // 采用装饰线程池方式使用TTL。 private ExecutorService getTtlExecutorsExecutor() throws IllegalStateException { return TtlExecutors.getTtlExecutorService(super.getThreadPoolExecutor()); } // 使用新定义线程池来执行sumbmit操作 @Override public Future<?> submit(Runnable task) { ExecutorService executor = getTtlExecutorsExecutor(); try { return executor.submit(task); } catch (RejectedExecutionException ex) { throw new TaskRejectedException("Executor [" + executor + "] did not accept task: " + task, ex); } } @Override public <T> Future<T> submit(Callable<T> task) { ExecutorService executor = getTtlExecutorsExecutor(); try { return executor.submit(task); } catch (RejectedExecutionException ex) { throw new TaskRejectedException("Executor [" + executor + "] did not accept task: " + task, ex); } } } |
参考文章
1、logback根据不同任务ID输出到不同日志文件件 https://www.jianshu.com/p/a33902d58530
2、logback实现每个用户一个独立的日志文件 http://www.voidcn.com/article/p-vfnoregb-bob.html
3、了解logback的SiftingAppender https://lihuanghe.github.io/2015/08/15/logback.html
4、logback官网-介绍SiftingAppender:https://logback.qos.ch/manual/appenders.html
5、归档策略-同时按时间和大小归档 https://blog.csdn.net/bluestarjava/article/details/82722033