log4j2自动删除过期日志文件 log4j2 自动删除过期日志文件的配置及实现原理
等你归去来 人气:5日志文件自动删除功能必不可少,当然你可以让运维去做这事,只是这不地道。而日志组件是一个必备组件,让其多做一件删除的工作,无可厚非。本文就来探讨下 log4j 的日志文件自动删除实现吧。
0.自动删除配置参考样例: (log4j2.xml)
<?xml version="1.0" encoding="UTF-8" ?> <Configuration status="warn" monitorInterval="30" strict="true" schema="Log4J-V2.2.xsd"> <Properties> <Property name="log_level">info</Property> </Properties> <Appenders> <!-- 输出到控制台 --> <Console name="Console" target="SYSTEM_OUT"> <ThresholdFilter level="${log_level}" onMatch="ACCEPT" onMismatch="DENY" /> <PatternLayout pattern="%d{yyyy-MM-dd'T'HH:mm:ss.SSS} [%t] %p - %c - %m%n" /> </Console> <!-- 与properties文件中位置存在冲突,如有问题,请注意调整 --> <RollingFile name="logFile" fileName="logs/app/test.log" filePattern="logs/app/history/test-%d{MM-dd-yyyy}-%i.log.gz"> <ThresholdFilter level="${log_level}" onMatch="ACCEPT" onMismatch="DENY" /> <PatternLayout pattern="%d{yyyy-MM-dd'T'HH:mm:ss.SSS} [%p] [%c:%L] -- %m%n" /> <Policies> <!-- 按天递计算频率 --> <TimeBasedTriggeringPolicy interval="1" /> <SizeBasedTriggeringPolicy size="500 MB" /> <OnStartupTriggeringPolicy /> </Policies> <!-- 删除策略配置 --> <DefaultRolloverStrategy max="5"> <Delete basePath="logs/app/history" maxDepth="1"> <IfFileName glob="*.log.gz"/> <IfLastModified age="7d"/> </Delete> <Delete basePath="logs/app/history" maxDepth="1"> <IfFileName glob="*.docx"/> </Delete> <Delete basePath="logs/app/history" maxDepth="1"> <IfFileName glob="*.vsdx"/> </Delete> </DefaultRolloverStrategy> </RollingFile> <Async name="Async" bufferSize="2000" blocking="false"> <AppenderRef ref="logFile"/> </Async> </Appenders> <Loggers> <Root level="${log_level}"> <AppenderRef ref="Console" /> <AppenderRef ref="Async" /> </Root> <!-- 配置个例 --> <Logger name="com.xx.filter" level="info" /> </Loggers> </Configuration>
如果仅想停留在使用层面,如上log4j2.xml配置文件足矣!
不过,至少得注意一点,以上配置需要基于log4j2, 而如果你是 log4j1.x,则需要做下无缝升级:主要就是换下jar包版本,换个桥接包之类的,比如下参考配置:
<dependency> <groupId>commons-logging</groupId> <artifactId>commons-logging</artifactId> <version>1.2</version> </dependency> <!-- 桥接:告诉commons logging使用Log4j2 --> <dependency> <groupId>org.slf4j</groupId> <artifactId>jcl-over-slf4j</artifactId> <version>1.7.26</version> </dependency> <!-- 此处老版本,需注释掉 --> <!--<dependency> <groupId>log4j</groupId> <artifactId>log4j</artifactId> <version>1.2.17</version> </dependency>--> <dependency> <groupId>org.apache.commons</groupId> <artifactId>commons-compress</artifactId> <version>1.10</version> </dependency> <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-slf4j-impl</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>org.apache.logging.log4j</groupId> <artifactId>log4j-web</artifactId> <version>2.8.2</version> </dependency>
如果还想多了解一点其运行原理,就跟随本文的脚步吧:
1.自动清理大体运行流程
自动删除工作的运行原理大体流程如下。(大抵都是如此)
1. 加载log4j2.xml配置文件;
2. 读取appenders,并添加到log4j上下文中;
3. 加载 policy, 加载 rollover 配置;
4. 写入日志时判断是否满足rollover配置, 默认是一天运行一次, 可自行添加各种运行测试, 比如大小、启动时;
所以,删除策略的核心是每一次添加日志时。代码验证如下:
// 在每次添加日志时判定 // org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender#append /** * Write the log entry rolling over the file when required. * * @param event The LogEvent. */ @Override public void append(final LogEvent event) { final RollingRandomAccessFileManager manager = getManager(); // 重点:直接检查是否需要 rollover, 如需要直接进行 manager.checkRollover(event); // Leverage the nice batching behaviour of async Loggers/Appenders: // we can signal the file manager that it needs to flush the buffer // to disk at the end of a batch. // From a user's point of view, this means that all log events are // _always_ available in the log file, without incurring the overhead // of immediateFlush=true. manager.setEndOfBatch(event.isEndOfBatch()); // FIXME manager's EndOfBatch threadlocal can be deleted // LOG4J2-1292 utilize gc-free Layout.encode() method: taken care of in superclass super.append(event); } // org.apache.logging.log4j.core.appender.rolling.RollingFileManager#checkRollover /** * Determines if a rollover should occur. * @param event The LogEvent. */ public synchronized void checkRollover(final LogEvent event) { // 由各触发策略判定是否需要进行 rolling // 如需要, 则调用 rollover() if (triggeringPolicy.isTriggeringEvent(event)) { rollover(); } }
所以,何时进行删除?答案是在适当的时机,这个时机可以是任意时候。
2. log4j 日志滚动
日志滚动,可以是重命名,也可以是删除文件。但总体判断是否可触发滚动的前提是一致的。我们这里主要关注文件删除。我们以时间作为依据看下判断过程。
// 1. 判断是否是 触发事件时机 // org.apache.logging.log4j.core.appender.rolling.TimeBasedTriggeringPolicy#isTriggeringEvent /** * Determines whether a rollover should occur. * @param event A reference to the currently event. * @return true if a rollover should occur. */ @Override public boolean isTriggeringEvent(final LogEvent event) { if (manager.getFileSize() == 0) { return false; } final long nowMillis = event.getTimeMillis(); // TimeBasedTriggeringPolicy, 是基于时间判断的, 此处为每天一次 if (nowMillis >= nextRolloverMillis) { nextRolloverMillis = manager.getPatternProcessor().getNextTime(nowMillis, interval, modulate); return true; } return false; } // org.apache.logging.log4j.core.appender.rolling.RollingFileManager#rollover() public synchronized void rollover() { if (!hasOutputStream()) { return; } // strategy 是xml配置的策略 if (rollover(rolloverStrategy)) { try { size = 0; initialTime = System.currentTimeMillis(); createFileAfterRollover(); } catch (final IOException e) { logError("Failed to create file after rollover", e); } } } // RollingFileManager 统一管理触发器 // org.apache.logging.log4j.core.appender.rolling.RollingFileManager#rollover private boolean rollover(final RolloverStrategy strategy) { boolean releaseRequired = false; try { // Block until the asynchronous operation is completed. // 上锁保证线程安全 semaphore.acquire(); releaseRequired = true; } catch (final InterruptedException e) { logError("Thread interrupted while attempting to check rollover", e); return false; } boolean success = true; try { // 由各触发器运行 rollover 逻辑 final RolloverDescription descriptor = strategy.rollover(this); if (descriptor != null) { writeFooter(); closeOutputStream(); if (descriptor.getSynchronous() != null) { LOGGER.debug("RollingFileManager executing synchronous {}", descriptor.getSynchronous()); try { // 先使用同步方法,改名,然后再使用异步方法操作更多 success = descriptor.getSynchronous().execute(); } catch (final Exception ex) { success = false; logError("Caught error in synchronous task", ex); } } // 如果配置了异步器, 则使用异步进行 rollover if (success && descriptor.getAsynchronous() != null) { LOGGER.debug("RollingFileManager executing async {}", descriptor.getAsynchronous()); // CompositeAction, 使用异步线程池运行用户的 action asyncExecutor.execute(new AsyncAction(descriptor.getAsynchronous(), this)); // 在异步运行action期间,锁是不会被释放的,以避免线程安全问题 // 直到异步任务完成,再主动释放锁 releaseRequired = false; } return true; } return false; } finally { if (releaseRequired) { semaphore.release(); } } }
此处滚动有两个处理点,1. 每个滚动策略可以自行处理业务; 2. RollingFileManager 统一管理触发同步和异步的滚动action;
3. DefaultRolloverStrategy 默认滚动策略驱动
DefaultRolloverStrategy 作为一个默认的滚动策略实现,可以配置多个 Action, 然后处理删除操作。
删除有两种方式: 1. 当次滚动的文件数过多,会立即进行删除; 2. 配置单独的 DeleteAction, 根据配置的具体策略进行删除。(但该Action只会被返回给外部调用,自身则不会执行)
// org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy#rollover /** * Performs the rollover. * * @param manager The RollingFileManager name for current active log file. * @return A RolloverDescription. * @throws SecurityException if an error occurs. */ @Override public RolloverDescription rollover(final RollingFileManager manager) throws SecurityException { int fileIndex; // 默认 minIndex=1 if (minIndex == Integer.MIN_VALUE) { final SortedMap<Integer, Path> eligibleFiles = getEligibleFiles(manager); fileIndex = eligibleFiles.size() > 0 ? eligibleFiles.lastKey() + 1 : 1; } else { if (maxIndex < 0) { return null; } final long startNanos = System.nanoTime(); // 删除case1: 获取符合条件的文件数,同时清理掉大于 max 配置的日志文件 // 如配置 max=5, 当前只有4个满足时, 不会立即清理文件, 但也不会阻塞后续流程 // 只要没有出现错误, fileIndex 不会小于0 fileIndex = purge(minIndex, maxIndex, manager); if (fileIndex < 0) { return null; } if (LOGGER.isTraceEnabled()) { final double durationMillis = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNanos); LOGGER.trace("DefaultRolloverStrategy.purge() took {} milliseconds", durationMillis); } } // 进入此区域即意味着,必然有文件需要滚动,重新命名了 final StringBuilder buf = new StringBuilder(255); manager.getPatternProcessor().formatFileName(strSubstitutor, buf, fileIndex); final String currentFileName = manager.getFileName(); String renameTo = buf.toString(); final String compressedName = renameTo; Action compressAction = null; FileExtension fileExtension = manager.getFileExtension(); if (fileExtension != null) { renameTo = renameTo.substring(0, renameTo.length() - fileExtension.length()); compressAction = fileExtension.createCompressAction(renameTo, compressedName, true, compressionLevel); } // 未发生文件重命名情况,即文件未被重命名未被滚动 // 该种情况应该不太会发生 if (currentFileName.equals(renameTo)) { LOGGER.warn("Attempt to rename file {} to itself will be ignored", currentFileName); return new RolloverDescriptionImpl(currentFileName, false, null, null); } // 新建一个重命令的 action, 返回待用 final FileRenameAction renameAction = new FileRenameAction(new File(currentFileName), new File(renameTo), manager.isRenameEmptyFiles()); // 异步处理器,会处理用户配置的异步action,如本文配置的 DeleteAction // 它将会在稍后被提交到异步线程池中运行 final Action asyncAction = merge(compressAction, customActions, stopCustomActionsOnError); // 封装Rollover返回, renameAction 是同步方法, 其他用户配置的动态action 则是异步方法 // 删除case2: 封装异步返回action return new RolloverDescriptionImpl(currentFileName, false, renameAction, asyncAction); } private int purge(final int lowIndex, final int highIndex, final RollingFileManager manager) { // 默认使用 accending 的方式进行清理文件 return useMax ? purgeAscending(lowIndex, highIndex, manager) : purgeDescending(lowIndex, highIndex, manager); } // org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy#purgeAscending /** * Purges and renames old log files in preparation for rollover. The oldest file will have the smallest index, the * newest the highest. * * @param lowIndex low index. Log file associated with low index will be deleted if needed. * @param highIndex high index. * @param manager The RollingFileManager * @return true if purge was successful and rollover should be attempted. */ private int purgeAscending(final int lowIndex, final int highIndex, final RollingFileManager manager) { final SortedMap<Integer, Path> eligibleFiles = getEligibleFiles(manager); final int maxFiles = highIndex - lowIndex + 1; boolean renameFiles = false; // 依次迭代 eligibleFiles, 删除 while (eligibleFiles.size() >= maxFiles) { try { LOGGER.debug("Eligible files: {}", eligibleFiles); Integer key = eligibleFiles.firstKey(); LOGGER.debug("Deleting {}", eligibleFiles.get(key).toFile().getAbsolutePath()); // 调用nio的接口删除文件 Files.delete(eligibleFiles.get(key)); eligibleFiles.remove(key); renameFiles = true; } catch (IOException ioe) { LOGGER.error("Unable to delete {}, {}", eligibleFiles.firstKey(), ioe.getMessage(), ioe); break; } } final StringBuilder buf = new StringBuilder(); if (renameFiles) { // 针对未完成删除的文件,继续处理 // 比如使用 匹配的方式匹配文件, 则不能被正常删除 // 还有些未超过maxFiles的文件 for (Map.Entry<Integer, Path> entry : eligibleFiles.entrySet()) { buf.setLength(0); // LOG4J2-531: directory scan & rollover must use same format manager.getPatternProcessor().formatFileName(strSubstitutor, buf, entry.getKey() - 1); String currentName = entry.getValue().toFile().getName(); String renameTo = buf.toString(); int suffixLength = suffixLength(renameTo); if (suffixLength > 0 && suffixLength(currentName) == 0) { renameTo = renameTo.substring(0, renameTo.length() - suffixLength); } Action action = new FileRenameAction(entry.getValue().toFile(), new File(renameTo), true); try { LOGGER.debug("DefaultRolloverStrategy.purgeAscending executing {}", action); if (!action.execute()) { return -1; } } catch (final Exception ex) { LOGGER.warn("Exception during purge in RollingFileAppender", ex); return -1; } } } // 此处返回的 findIndex 一定是 >=0 的 return eligibleFiles.size() > 0 ? (eligibleFiles.lastKey() < highIndex ? eligibleFiles.lastKey() + 1 : highIndex) : lowIndex; }
4. 符合过滤条件的文件查找
当配置了 max 参数,这个参数是如何匹配的呢?比如我某个文件夹下有很历史文件,是否都会匹配呢?
// 文件查找规则 // org.apache.logging.log4j.core.appender.rolling.AbstractRolloverStrategy#getEligibleFiles protected SortedMap<Integer, Path> getEligibleFiles(final RollingFileManager manager) { return getEligibleFiles(manager, true); } protected SortedMap<Integer, Path> getEligibleFiles(final RollingFileManager manager, final boolean isAscending) { final StringBuilder buf = new StringBuilder(); // 此处的pattern 即是在appender上配置的 filePattern, 一般会受限于 MM-dd-yyyy-$i.log.gz String pattern = manager.getPatternProcessor().getPattern(); // 此处会将时间替换为当前, 然后按照此规则进行匹配要处理的文件 manager.getPatternProcessor().formatFileName(strSubstitutor, buf, NotANumber.NAN); return getEligibleFiles(buf.toString(), pattern, isAscending); } // 细节匹配要处理的文件 protected SortedMap<Integer, Path> getEligibleFiles(String path, String logfilePattern, boolean isAscending) { TreeMap<Integer, Path> eligibleFiles = new TreeMap<>(); File file = new File(path); File parent = file.getParentFile(); if (parent == null) { parent = new File("."); } else { parent.mkdirs(); } if (!logfilePattern.contains("%i")) { return eligibleFiles; } Path dir = parent.toPath(); String fileName = file.getName(); int suffixLength = suffixLength(fileName); if (suffixLength > 0) { fileName = fileName.substring(0, fileName.length() - suffixLength) + ".*"; } String filePattern = fileName.replace(NotANumber.VALUE, "(\\d+)"); Pattern pattern = Pattern.compile(filePattern); try (DirectoryStream<Path> stream = Files.newDirectoryStream(dir)) { for (Path entry: stream) { // 该匹配相当精确 // 只会删除当天或者在时间交替的时候删除上一天的数据咯 // 如果在这个时候进行了重启操作,就再也不会删除此文件了 Matcher matcher = pattern.matcher(entry.toFile().getName()); if (matcher.matches()) { Integer index = Integer.parseInt(matcher.group(1)); eligibleFiles.put(index, entry); } } } catch (IOException ioe) { throw new LoggingException("Error reading folder " + dir + " " + ioe.getMessage(), ioe); } return isAscending? eligibleFiles : eligibleFiles.descendingMap(); } // 此处会将 各种格式的文件名,替换为当前时间或者最后一次滚动的文件的时间。所以匹配的时候,并不会匹配超时当前认知范围的文件 /** * Formats file name. * @param subst The StrSubstitutor. * @param buf string buffer to which formatted file name is appended, may not be null. * @param obj object to be evaluated in formatting, may not be null. */ public final void formatFileName(final StrSubstitutor subst, final StringBuilder buf, final boolean useCurrentTime, final Object obj) { // LOG4J2-628: we deliberately use System time, not the log4j.Clock time // for creating the file name of rolled-over files. final long time = useCurrentTime && currentFileTime != 0 ? currentFileTime : prevFileTime != 0 ? prevFileTime : System.currentTimeMillis(); formatFileName(buf, new Date(time), obj); final LogEvent event = new Log4jLogEvent.Builder().setTimeMillis(time).build(); final String fileName = subst.replace(event, buf); buf.setLength(0); buf.append(fileName); }
AsyncAction 是一个 Runnable 的实现, 被直接提交到线程池运行. AsyncAction -> AbstractAction -> Action -> Runnable
它是一个统一管理异步Action的包装,主要是管理锁和异常类操作。
// org.apache.logging.log4j.core.appender.rolling.RollingFileManager.AsyncAction /** * Performs actions asynchronously. */ private static class AsyncAction extends AbstractAction { private final Action action; private final RollingFileManager manager; /** * Constructor. * @param act The action to perform. * @param manager The manager. */ public AsyncAction(final Action act, final RollingFileManager manager) { this.action = act; this.manager = manager; } /** * Executes an action. * * @return true if action was successful. A return value of false will cause * the rollover to be aborted if possible. * @throws java.io.IOException if IO error, a thrown exception will cause the rollover * to be aborted if possible. */ @Override public boolean execute() throws IOException { try { // 门面调用 action.execute(), 一般是调用 CompositeAction, 里面封装了多个 action return action.execute(); } finally { // 任务执行完成,才会释放外部的锁 // 虽然不是很优雅,但是很准确很安全 manager.semaphore.release(); } } ... } // CompositeAction 封装了多个 action 处理 // org.apache.logging.log4j.core.appender.rolling.action.CompositeAction#run /** * Execute sequence of actions. * * @return true if all actions were successful. * @throws IOException on IO error. */ @Override public boolean execute() throws IOException { if (stopOnError) { // 依次调用action for (final Action action : actions) { if (!action.execute()) { return false; } } return true; } boolean status = true; IOException exception = null; for (final Action action : actions) { try { status &= action.execute(); } catch (final IOException ex) { status = false; if (exception == null) { exception = ex; } } } if (exception != null) { throw exception; } return status; }
DeleteAction是我们真正关心的动作。
// CompositeAction 封装了多个 action 处理 // org.apache.logging.log4j.core.appender.rolling.action.CompositeAction#run /** * Execute sequence of actions. * * @return true if all actions were successful. * @throws IOException on IO error. */ @Override public boolean execute() throws IOException { if (stopOnError) { // 依次调用action for (final Action action : actions) { if (!action.execute()) { return false; } } return true; } boolean status = true; IOException exception = null; for (final Action action : actions) { try { status &= action.execute(); } catch (final IOException ex) { status = false; if (exception == null) { exception = ex; } } } if (exception != null) { throw exception; } return status; } // DeleteAction 做真正的删除动作 // org.apache.logging.log4j.core.appender.rolling.action.DeleteAction#execute() @Override public boolean execute() throws IOException { // 如果没有script配置,则直接委托父类处理 return scriptCondition != null ? executeScript() : super.execute(); } org.apache.logging.log4j.core.appender.rolling.action.AbstractPathAction#execute() @Override public boolean execute() throws IOException { // 根据指定的basePath, 和过滤条件,选择相关文件 // 调用 DeleteAction 的 createFileVisitor(), 返回 DeletingVisitor return execute(createFileVisitor(getBasePath(), pathConditions)); } // org.apache.logging.log4j.core.appender.rolling.action.DeleteAction#execute(java.nio.file.FileVisitor<java.nio.file.Path>) @Override public boolean execute(final FileVisitor<Path> visitor) throws IOException { // 根据maxDepth设置,遍历所有可能的文件路径 // 使用 Files.walkFileTree() 实现, 添加到 collected 中 final List<PathWithAttributes> sortedPaths = getSortedPaths(); trace("Sorted paths:", sortedPaths); for (final PathWithAttributes element : sortedPaths) { try { // 依次调用 visitFile, 依次判断是否需要删除 visitor.visitFile(element.getPath(), element.getAttributes()); } catch (final IOException ioex) { LOGGER.error("Error in post-rollover Delete when visiting {}", element.getPath(), ioex); visitor.visitFileFailed(element.getPath(), ioex); } } // TODO return (visitor.success || ignoreProcessingFailure) return true; // do not abort rollover even if processing failed }
最终,即和想像的一样:找到要查找的文件夹,遍历各文件,用多个条件判断是否满足。删除符合条件的文件。
只是这其中注意的点:如何删除文件的线程安全性;如何保证删除工作不影响业务线程;很常见的锁和多线程的应用。
5.真正的删除
真正的删除动作就是在DeleteAction中配置的,但上面可以看它是调用visitor的visitFile方法,所以有必要看看是如何真正处理删除的。(实际上前面在purge时已经做过一次删除操作了,所以别被两个点迷惑了,建议尽量只依赖于Delete配置,可以将外部max设置很大以避免两处生效)
// org.apache.logging.log4j.core.appender.rolling.action.DeletingVisitor#visitFile @Override public FileVisitResult visitFile(final Path file, final BasicFileAttributes attrs) throws IOException { for (final PathCondition pathFilter : pathConditions) { final Path relative = basePath.relativize(file); // 遍历所有条件,只要有一个不符合,即不进行删除。 // 所以,所以条件是 AND 关系, 没有 OR 关系 // 如果想配置 OR 关系,只能配置多个DELETE if (!pathFilter.accept(basePath, relative, attrs)) { LOGGER.trace("Not deleting base={}, relative={}", basePath, relative); return FileVisitResult.CONTINUE; } } // 直接删除文件 if (isTestMode()) { LOGGER.info("Deleting {} (TEST MODE: file not actually deleted)", file); } else { delete(file); } return FileVisitResult.CONTINUE; }
删除策略配置比如:
<RollingFile name="logFile" fileName="logs/app/test.log" filePattern="logs/app/history/test-%d{MM-dd-yyyy}-%i.log.gz"> <ThresholdFilter level="${log_level}" onMatch="ACCEPT" onMismatch="DENY" /> <PatternLayout pattern="%d{yyyy-MM-dd'T'HH:mm:ss.SSS} [%p] [%c:%L] -- %m%n" /> <Policies> <!-- 按天递计算频率 --> <TimeBasedTriggeringPolicy interval="1" /> <SizeBasedTriggeringPolicy size="500 MB" /> <OnStartupTriggeringPolicy /> </Policies> <!-- 删除策略配置 --> <DefaultRolloverStrategy max="5000"> <Delete basePath="logs/app/history" maxDepth="1"> <!-- 配置且关系 --> <IfFileName glob="*.log.gz"/> <IfLastModified age="7d"/> </Delete> <!-- 配置或关系 --> <Delete basePath="logs/app/history" maxDepth="1"> <IfFileName glob="*.docx"/> </Delete> <Delete basePath="logs/app/history" maxDepth="1"> <IfFileName glob="*.vsdx"/> </Delete> </DefaultRolloverStrategy> </RollingFile>
另外说明,之所以能够无缝替换,是因为利用了不同实现版本的 org/slf4j/impl/StaticLoggerBinder.class, 而外部都使用 slf4j 接口定义实现的,比如 org.apache.logging.log4j:log4j-slf4j-impl 包的实现。
总结
加载全部内容