使用Log4j2代码方式配置实现线程级动态控制
作者:柠檬睡客
一 需求
最近平台进行升级,要求日志工具从Log4j升级到Log4j2,以求性能上的提升。之前我写过以代码方式的配置Log4j,来实现线程级日志对象的管理,今天把版本升级到Log4j2,依然采用原有思路来做,但是实现上有诸多区别,这是因为Log4j2的实现较老版本改动太多。
至于以配置文件方式配置的方法,我不做介绍,对于Log4j2的详细实现亦然,这些部分有兴趣的朋友可以自己网络搜索,也可以自行跟踪源码查阅。
主要需求为每个线程单独一个日志对象处理,可动态控制日志输出级别等参数,可控制的同步及异步输出模式,标准的日志头格式等。
大体思路同我之前写的Log4j配置,只不过日志对象的创建管理等功能实现上略有区别。
二 对外暴露的接口
设计的重中之重,这部分一旦设计完成便不可轻易改动,后续的维护只能尽其可能的向前兼容。
首先我们需要提供对外可用的预设参数值,包括日志输出等级、日志的输出目标(文件、控制台、网络及数据库等)等,这些值设定我们均以static final来修饰。
第二部分是全局参数的设置,这些参数不随日志对象的状态而发生变动,反而是作为日志对象构造的属性值来源,比如说日志文件的路径、日志文件的最大容量、日志文件的备份数量,以及每个线程的日志对象初始的日志输出等级等等。这部分参数可以从外部配置读取,当然也需要有默认值设定,属全局参数配置,以static修饰。
第三部分为日志输出的接口定义,这部分可有可无,但是对于大型项目来说极为重要,以规范的接口进行日志输出,可以为日志的采集、分析带来巨大便利,如通讯日志、异常日志等内容的格式化输出。
所以,按总体思路预先定义日志工具的外对暴露接口,如下:
public class LogUtil { public static final int LevelTrace = 0; public static final int LevelDebug = 1; public static final int LevelInfo = 2; public static final int LevelWarn = 3; public static final int LevelError = 4; public static final String[] LevelName = new String[] { "TRACE", "DEBUG", "INFO", "WARN", "ERROR" }; public static final String TypeCommunication = "comm"; public static final String TypeProcess = "proc"; public static final String TypeException = "exce"; public static final int AppenderConsole = 1; public static final int AppenderFile = 2; private static int DefaultLogLevel = LevelDebug; private static String FilePath = null; private static String FileSize = "100MB"; private static int BackupIndex = -1; private static int BufferSize = 0; private static String LinkChar = "-"; private static int LogAppender = AppenderFile; public static void log(int logLevel, String logType, String logText) { getThreadLogger().log(logLevel, logType, logText); } public static void logCommunication() { // TODO } public static void logException() { // TODO } …… }
这里我暂定了一个公用的日志输出接口名为log(),参数列表为日志的输出等级、日志的类型以及日志内容。而通讯日志的输出接口为logCommunication(),其参数列表暂时空着,按各位读者的需求自行填写,异常日志的输出亦然。后文我会在测试部分对其填写。
为了描述方便,我仅定义了两个日志输出目标,一为控制台,二为文件。
三 代码方式配置Log4j2日志对象
接下来是重头戏,如果不采取配置文件的方式进行Log4j2的配置,那么Log4j2会自行采用默认的配置,这不是我们想要的。虽然这个过程我们无法选择,也规避不了,但是我们最后都是使用Logger对象来进行日志输出的,所以我们只需要按需构造Logger对象,并将其管理起来即可。
这里提供一个思路,首先LogUtil维护一组线程级日志对象,然后这一组线程级日志对象共同访问同一组Logger对象。
跟踪源码我发现Log4j2对Logger对象的构造还是较为复杂的,使用了大量的Builder,其实较为早期的版本中也提供了构造函数方式来初始化对象,但是后期的版本却都被标记了@depreciation。对于Builder模式大家自己查阅其他信息了解吧。
好消息是Log4j2的核心组件依然是Appender、Logger,只不过提供了更多的可配置内容,包括日志同时按日期和文件大小进行备份,这才是我想要的,之前写Log4j的时候我可是自己派生了一个Appender类才实现的同时备份。
向控制台输出的Appender具体类型为ConsoleAppender,我使用默认的构造函数来处理,这是唯一一个被公开出来,且没有被@depreciation修饰的构造函数,想来只要是能通过默认配置实现的都是被Log4j2认可的吧,不然为啥要弄这么多Builder嘞。
向文件输出的Appender我采用RollingFileAppender,无他,就是为了能够实现同时按日期及文件大小进行备份,而且该Appender可适用全局异步模式,性能较AsyncAppender高了不少。它的创建方式要麻烦许多,因为我需要设置触发器来控制何时触发备份,以及备份策略。
整体设计如下:
private Logger createLogger(String loggerName) { Appender appender = null; PatternLayout.Builder layoutBuilder = PatternLayout.newBuilder(); layoutBuilder.withCharset(Charset.forName(DefaultCharset)); layoutBuilder.withConfiguration(loggerConfiguration); Layout<String> layout = layoutBuilder.build(); if (LogUtil.AppenderConsole == LogUtil.getAppender()) { appender = ConsoleAppender.createDefaultAppenderForLayout(layout); } if (LogUtil.AppenderFile == LogUtil.getAppender()) { RollingFileAppender.Builder<?> loggerBuilder = RollingFileAppender.newBuilder(); if (LogUtil.getBufferSize() > 0) { loggerBuilder.withImmediateFlush(false); loggerBuilder.withBufferedIo(true); loggerBuilder.withBufferSize(LogUtil.getBufferSize()); System.setProperty(AsyncPropKey, AsyncPropVal); } else { loggerBuilder.withImmediateFlush(true); loggerBuilder.withBufferedIo(false); loggerBuilder.withBufferSize(0); System.getProperties().remove(AsyncPropKey); } loggerBuilder.withAppend(true); loggerBuilder.withFileName(getFilePath(loggerName)); loggerBuilder.withFilePattern(spellBackupFileName(loggerName)); loggerBuilder.withLayout(layout); loggerBuilder.withName(loggerName); loggerBuilder.withPolicy(CompositeTriggeringPolicy.createPolicy( SizeBasedTriggeringPolicy.createPolicy(LogUtil.getFileSize()), TimeBasedTriggeringPolicy.createPolicy("1", "true"))); loggerBuilder.withStrategy(DefaultRolloverStrategy.createStrategy( LogUtil.getBackupIndex() > 0 ? String.valueOf(LogUtil.getBackupIndex()) : "-1", "1", LogUtil.getBackupIndex() > 0 ? null : "nomax", null, null, true, loggerConfiguration)); appender = loggerBuilder.build(); } appender.start(); loggerConfiguration.addAppender(appender); AppenderRef appenderRef = AppenderRef.createAppenderRef(loggerName, Level.ALL, null); AppenderRef[] appenderRefs = new AppenderRef[] { appenderRef }; LoggerConfig loggerConfig = LoggerConfig.createLogger(false, Level.ALL, loggerName, "false", appenderRefs, null, loggerConfiguration, null); loggerConfig.addAppender(appender, null, null); loggerConfiguration.addLogger(loggerName, loggerConfig); loggerContext.updateLoggers(); loggerConfiguration.start(); Logger logger = LogManager.getLogger(loggerName); return logger; }
注意!!我在初始化Logger对象的时候,是根据LogUtil是否开启了异步输出模式来判定是否需要开启全局异步模式的,这里简单说一些Log4j2的异步模式。
Log4j2提供了两种异步模式,第一种是使用AsyncAppender,这种方式跟我以前写的Log4j的异步输出模式一样,都是单独开启一个线程来输出日志。第二种方式是AsychLogger,这个就厉害了,官推,而且官方提供了两种使用模式,一个是混合异步,一个是全局异步,全局异步时不需要对配置文件进行任何改动,尽在应用启动时添加一个jvm参数即可,并且据压测数据显示,全局异步模式下性能飙升。
更多的配置信息建议读者朋友自行查阅官方文档。
最后还有一点需要注意的是,Log4j2的全局异步是要依赖队列缓存的,其实现采用的是disruptor,所以需要依赖这个外部jar,不然在初始化Logger对象的时候,你会看到相关异常。
贴一下依赖的Maven:
<dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.8.2</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> <version>2.8.2</version> </dependency> <dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>3.3.6</version> </dependency>
严重强调:AsyncAppender、AsyncLogger以及全局异步的System.property设置,不要同时出现!!!
最最后,我特么还是要嘴贱啰嗦一下,不见得“异步”就是好的,你想想看异步模式无非是额外线程或者缓存来实现,这些也是要吃资源的,日志量大的场景下其带来的收益很高,但小量日志场景下其对性能资源的消耗很可能大于其带来的性能收益,请酌情使用。
四 线程级日志对象的设计
按上文中的设计思路,LogUtil持有一组线程级日志对象,而这一组日志对象又共享一组Logger对象。延续Log4j版本的设计,线程级日志对象类型依然为ThreadLogger,其基础属性为线程ID、日志类型以及日志的输出级别等。
为了解决多并发问题,使用ConcurrentHashMap来存储Logger对象,其Key值为线程ID,这里需要注意的是ConcurrentHashMap的put操作尽管能保证可见性,但是不能保证操作的原子性,所以在其put操作上需要额外加锁。
class ThreadLogger { private static final String AsyncPropKey = "log4j2.contextSelector"; private static final String AsyncPropVal = "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector"; private static final String DefaultCharset = "UTF-8"; private static final String DefaultDateFormat = "yyyy-MM-dd HH:mm:ss.SSSSSS"; private static final Object LoggerMapLock = new Object(); private static final ConcurrentHashMap<String, Logger> LoggerMap = new ConcurrentHashMap<>(); private static LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false); private static Configuration loggerConfiguration = loggerContext.getConfiguration(); public static void cleanLoggerMap() { synchronized (LoggerMapLock) { LoggerMap.clear(); } } private Logger getLogger(String loggerName) { if (StringUtil.isEmpty(loggerName)) return null; Logger logger = LoggerMap.get(loggerName); if (logger == null) { synchronized (LoggerMapLock) { logger = createLogger(loggerName); LoggerMap.put(loggerName, logger); } } return logger; } }
五 标准日志头
头部内容应包含当前的日志输出级别,日志打印所在的类名、行号,当前的线程号、进程号等信息。这里简单介绍下进程号及类名行号的获取。
每个应用进程的进程号唯一,所以仅在第一次获取该信息时获取即可,类名行号则通过方法栈的栈信息获取,如下:
private static String ProcessID = null; private String logLocation = null; public static String getProcessID() { if (ProcessID == null) { ProcessID = ManagementFactory.getRuntimeMXBean().getName().split("@")[0]; } return ProcessID; } private static String getLocation() { StackTraceElement[] stackTraceElements = Thread.currentThread().getStackTrace(); StringBuilder builder = new StringBuilder(stackTraceElements[3].getClassName()); builder.append(":"); builder.append(stackTraceElements[3].getLineNumber()); return builder.toString(); }
这里需要注意,类名行号信息对于每一条日志都不尽相同,所以不能声明为static,并且需要在LogUtil中获取,并通过ThreadLogger的setLocation()方法传入到ThreadLogger对象,最后由ThreadLogger的日志头拼装函数拼接到日志头部信息中:
private String spellLogText(int logLevel, String logText) { StringBuilder builder = new StringBuilder(); SimpleDateFormat sdf = new SimpleDateFormat(DefaultDateFormat); builder.append(sdf.format(Calendar.getInstance().getTime())); builder.append("|"); builder.append(LogUtil.LevelName[logLevel]); builder.append("|"); builder.append(getProcessID()); builder.append("|"); builder.append(this.threadID); builder.append("|"); builder.append(this.threadUUID); builder.append("|"); builder.append(this.logLocation); builder.append("|"); builder.append(logText); return builder.toString(); }
六 异常日志的堆栈信息打印
需要注意咯,异常的日志输出略微复杂些,这也是我经常被人问起的一个问题,很多从事400或大机开发的同事转入java开发后,最常问的就是异常堆栈的问题,看不懂,不知道怎么来的。
这里我只提一个事情,Exception的构造,其成员有两个,其一为cause,Throwable类型,其二为message,String类型,构造函数提供较多,请大家自己做一个测试,看看不同构造其输出的内容有何不同,cause和message成员又有何关系。
如果你弄明白了Exception的构造,那么下面的逻辑不难理解:
private static String getExceptionStackTrace(Exception e) { StringBuilder builder = new StringBuilder(); builder.append(e.toString()); StackTraceElement[] stackTraceElements = e.getStackTrace(); for (int i = 0; i < stackTraceElements.length; i++) { builder.append("\r\nat "); builder.append(stackTraceElements[i].toString()); } Throwable throwable = e.getCause(); while (throwable != null) { builder.append("\r\nCaused by:"); builder.append(throwable.toString()); stackTraceElements = throwable.getStackTrace(); for (int i = 0; i < stackTraceElements.length; i++) { builder.append("\r\nat "); builder.append(stackTraceElements[i].toString()); } throwable = throwable.getCause(); } return builder.toString(); }
七 测试
补充一个逻辑实现,这里我以异常日志的打印作为测试接口,并在多线程并发场景下实现异步输出。
异常日志输出接口补充完整:
public static void logException(String desc, Exception exception) { getThreadLogger().setLogLocation(getLocation()); StringBuilder builder = new StringBuilder("Description="); builder.append(StringUtil.isEmpty(desc) ? "" : desc); builder.append(",Exception="); builder.append(getExceptionStackTrace(exception)); log(LevelError, TypeException, builder.toString()); }
测试代码:
public static void main(String[] args) { LogUtil.setAppender(LogUtil.AppenderFile); LogUtil.setBufferSize(1024); // 1KB缓存 LogUtil.setFileSize("1MB"); LogUtil.setBackupIndex(10); LogUtil.setFilePath("C:\\log"); for (int i = 0; i < 4; i++) { Thread thread = new Thread(new Runnable() { @Override public void run() { LogUtil.setModule(Thread.currentThread().getId() + ""); for (int j = 0; j < 100000; j++) { LogUtil.logException("test", new Exception("my test")); } } }); thread.start(); } }
测试结果:
以上为个人经验,希望能给大家一个参考,也希望大家多多支持脚本之家。