From 93bd8a91957037d883a462bce1db3a53c4dc128f Mon Sep 17 00:00:00 2001 From: Mike Dobozy Date: Thu, 3 Oct 2019 10:10:23 -0400 Subject: [PATCH] Fix for #139. --- .../handlers/PeriodicRotatingFileHandler.java | 107 +++++- .../PeriodicRotatingFileHandlerTests.java | 319 +++++++++++++++++- .../configs/prune-logging.properties | 47 +++ 3 files changed, 456 insertions(+), 17 deletions(-) create mode 100644 ext/src/test/resources/configs/prune-logging.properties diff --git a/ext/src/main/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandler.java b/ext/src/main/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandler.java index 323f1407..1d279350 100644 --- a/ext/src/main/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandler.java +++ b/ext/src/main/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandler.java @@ -19,17 +19,20 @@ package org.jboss.logmanager.ext.handlers; +import org.jboss.logmanager.ExtLogRecord; +import org.jboss.logmanager.handlers.FileHandler; + import java.io.File; import java.io.FileNotFoundException; import java.io.IOException; +import java.nio.file.Files; +import java.nio.file.Path; import java.text.SimpleDateFormat; -import java.util.Calendar; -import java.util.Date; -import java.util.TimeZone; +import java.util.*; import java.util.logging.ErrorManager; - -import org.jboss.logmanager.ExtLogRecord; -import org.jboss.logmanager.handlers.FileHandler; +import java.util.regex.Pattern; +import java.util.stream.Collectors; +import java.util.stream.IntStream; /** * A file handler which rotates the log at a preset time interval. The interval is determined by the content of the @@ -44,6 +47,13 @@ public class PeriodicRotatingFileHandler extends FileHandler { private TimeZone timeZone = TimeZone.getDefault(); private SuffixRotator suffixRotator = SuffixRotator.EMPTY; + private enum PruningStrategy { NONE, PERIODS, SIZE }; + + private String pruneSize; + private long pruneSizeResolved = 0L; + private PruningStrategy pruningStrategy = PruningStrategy.NONE; + + /** * Construct a new instance with no formatter and no output file. */ @@ -198,9 +208,72 @@ private void rollOver() { suffixRotator.rotate(getErrorManager(), file.toPath(), nextSuffix); // start new file setFile(file); + + if (pruneSizeResolved > 0) { + pruneFiles(file); + } + } catch (IOException e) { reportError("Unable to rotate log file", e, ErrorManager.OPEN_FAILURE); } + + } + + private void pruneFiles(File baseFile) throws IOException { + + synchronized (outputLock) { + + String baseName = baseFile.getName(); + Path parent = baseFile.toPath().getParent(); + String suffixPattern = this.getSuffixRotator().getDatePattern(); + + Pattern namePattern = Pattern.compile("^" + Pattern.quote(baseName) + ".*$"); + + /* + * Pruneable files are files in the current file's directory that are: + * + * a) regular (not symlinks, dirs, or hidden) + * b) not the current log + * c) match the current file syntax + * d) at a max depth of 1 (files in nested dirs aren't considered) + */ + List pruneables = Files + .find(parent, 1, (p, a) -> + a.isRegularFile() && + !p.getFileName().toString().equals(baseName) && + namePattern.matcher(p.getFileName().toString()).matches() + ) + .map(Path::toFile) + .filter(File::canWrite) + .sorted(Comparator.comparingLong(File::lastModified).thenComparing(File::getName)) + .collect(Collectors.toList()); + + if (pruningStrategy == PruningStrategy.SIZE) { + long total = pruneables.stream().mapToLong(File::length).sum(); + if (total > pruneSizeResolved) { + for (int i = 0, size = pruneables.size(); i < size && total > pruneSizeResolved; i++) { + long fsize = pruneables.get(i).length(); + try { + Files.deleteIfExists(pruneables.get(i).toPath()); + } catch (IOException ex) { + reportError("Unable to prune log file", ex, ErrorManager.GENERIC_FAILURE); + } + total -= fsize; + } + } + } else if (pruningStrategy == PruningStrategy.PERIODS) { + int periods = Long.valueOf(pruneSizeResolved).intValue(); + if (pruneables.size() > periods) { + for (int i = 0; i < periods; i++) { + try { + Files.deleteIfExists(pruneables.get(i).toPath()); + } catch (IOException ex) { + reportError("Unable to prune log file", ex, ErrorManager.GENERIC_FAILURE); + } + } + } + } + } } private void calcNextRollover(final long fromTime) { @@ -293,6 +366,28 @@ public void setTimeZone(final TimeZone timeZone) { this.timeZone = timeZone; } + public String getPruneSize() { + return pruneSize; + } + + public void setPruneSize(String pruneSize) { + this.pruneSize = pruneSize; + try { + if (pruneSize.endsWith("p") || pruneSize.endsWith("P")) { + pruningStrategy = PruningStrategy.PERIODS; + pruneSizeResolved = Long.parseLong(pruneSize.substring(0, pruneSize.length() - 1)); + } else { + pruningStrategy = PruningStrategy.SIZE; + pruneSizeResolved = Long.parseLong(pruneSize); + } + } catch (NumberFormatException e) { + reportError("Unable to parse prune size", e, ErrorManager.FORMAT_FAILURE); + } + if (pruneSizeResolved < 0) { + reportError("Prune size must be positive", null, ErrorManager.GENERIC_FAILURE); + } + } + private static > T min(T a, T b) { return a.compareTo(b) <= 0 ? a : b; } diff --git a/ext/src/test/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandlerTests.java b/ext/src/test/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandlerTests.java index 06d5144a..c1e6aa00 100644 --- a/ext/src/test/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandlerTests.java +++ b/ext/src/test/java/org/jboss/logmanager/ext/handlers/PeriodicRotatingFileHandlerTests.java @@ -19,27 +19,34 @@ package org.jboss.logmanager.ext.handlers; +import org.jboss.byteman.contrib.bmunit.BMRule; +import org.jboss.byteman.contrib.bmunit.BMUnitRunner; +import org.jboss.logmanager.ExtLogRecord; +import org.jboss.logmanager.Level; +import org.junit.After; +import org.junit.Assert; +import org.junit.Before; +import org.junit.Test; +import org.junit.runner.RunWith; + import java.io.BufferedWriter; +import java.io.File; import java.io.FileNotFoundException; +import java.io.IOException; import java.nio.charset.StandardCharsets; import java.nio.file.Files; import java.nio.file.Path; +import java.nio.file.Paths; +import java.nio.file.attribute.PosixFilePermissions; import java.text.SimpleDateFormat; import java.time.ZonedDateTime; import java.time.format.DateTimeFormatter; import java.util.Calendar; +import java.util.Comparator; import java.util.List; +import java.util.TimeZone; import java.util.logging.ErrorManager; - -import org.jboss.byteman.contrib.bmunit.BMRule; -import org.jboss.byteman.contrib.bmunit.BMUnitRunner; -import org.jboss.logmanager.ExtLogRecord; -import org.jboss.logmanager.Level; -import org.junit.After; -import org.junit.Assert; -import org.junit.Before; -import org.junit.Test; -import org.junit.runner.RunWith; +import java.util.stream.Collectors; /** * @author James R. Perkins @@ -64,7 +71,7 @@ public void createHandler() throws FileNotFoundException { } @After - public void closeHandler() { + public void closeHandler() throws IOException { handler.close(); handler = null; } @@ -146,6 +153,296 @@ record = createLogRecord(Level.INFO, "Date: %s", nextDate); Assert.assertTrue("The rotated file '" + rotatedFile.toString() + "' exists and should not", Files.notExists(rotatedFile)); } + private List getBaseDirPaths() throws Exception { + System.out.println("Paths:"); + List paths = Files.list(BASE_LOG_DIR.toPath()) + .sorted(Comparator.comparingLong((Path p) -> p.toFile().lastModified()).reversed()) + .collect(Collectors.toList()); + paths.forEach(System.out::println); + return paths; + } + + private List getBaseDirFiles() throws Exception { + System.out.println("Files:"); + List files = Files.list(BASE_LOG_DIR.toPath()) + .map(Path::toFile) + .sorted(Comparator.comparingLong(File::lastModified).reversed()) + .collect(Collectors.toList()); + files.forEach(System.out::println); + return files; + } + + @Test + public void testPruneBasic() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("55"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirPaths(); + + Assert.assertEquals(2, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getFileName().toString()); + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()), files.get(1).getFileName().toString()); + + } + + @Test + public void testPrunePeriods() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("5p"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirPaths(); + Assert.assertEquals(6, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getFileName().toString()); + for (int i = 0; i < 5; i++) { + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()), files.get(i + 1).getFileName().toString()); + cal.add(Calendar.DAY_OF_MONTH, -1); + } + + } + + @Test + public void testPruneInvalidSize() throws Exception { + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("-50"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + } + @Test + public void testPruneInvalidPeriods() throws Exception { + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("-5p"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + } + + @Test + public void testPruneIgnoreExtraFilesInDir() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + + Files.createFile(Paths.get(BASE_LOG_DIR.toString(), "chaff.txt")); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("55"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirPaths(); + Assert.assertEquals(3, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getFileName().toString()); + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()), files.get(1).getFileName().toString()); + Assert.assertEquals("chaff.txt", files.get(2).getFileName().toString()); + + } + + @Test + public void testPruneIgnoreFilesInNestedDir() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + + Files.createDirectories(Paths.get(BASE_LOG_DIR.toString(), "nested")); + Files.createFile(Paths.get(BASE_LOG_DIR.toString(), "nested", "periodic-rotating-file-handler.log.2019-10-15")); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("55"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirFiles(); + Assert.assertEquals(3, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getName()); + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()), files.get(1).getName()); + Assert.assertEquals("nested", files.get(2).getName()); + } + + @Test + public void testPruneIgnoreSymlinks() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + final Path rotatedFile = BASE_LOG_DIR.toPath().resolve(FILENAME + rotateFormatter.format(cal.getTime())); + + Path temp = Files.createTempFile("mytemp", ".tmp"); + Path linkPath = Files.createLink(Paths.get(BASE_LOG_DIR.toString(), "mytemp"), temp); + Assert.assertTrue(linkPath.toFile().exists()); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("55"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirFiles(); + Assert.assertEquals(3, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getName()); + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()), files.get(1).getName()); + Assert.assertEquals("mytemp", files.get(2).getName()); + + } + + @Test + public void testPruneIgnoreFilesWithInsufficientPerms() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + final Path rotatedFile = BASE_LOG_DIR.toPath().resolve(FILENAME + rotateFormatter.format(cal.getTime())); + + Path roFile = Files.createFile(Paths.get(BASE_LOG_DIR.toString(), "periodic-rotating-file-handler.log.foo")); + Assert.assertTrue(roFile.toFile().setReadable(true)); + Assert.assertTrue(roFile.toFile().setWritable(false)); + + Assert.assertFalse(roFile.toFile().canWrite()); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd"); + + createLogRecords(10, cal, currentDate, sdf); + + handler.setPruneSize("55"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirFiles(); + Assert.assertEquals(3, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getName()); + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()), files.get(1).getName()); + Assert.assertEquals("periodic-rotating-file-handler.log.foo", files.get(2).getName()); + + Assert.assertTrue(roFile.toFile().setWritable(true)); + Assert.assertTrue(roFile.toFile().setExecutable(true)); + + } + + @Test + public void testPruneArchive() throws Exception { + + final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); + Calendar cal = Calendar.getInstance(TimeZone.getDefault()); + final Path rotatedFile = BASE_LOG_DIR.toPath().resolve(FILENAME + rotateFormatter.format(cal.getTime())); + + String currentDate = sdf.format(cal.getTime()); + handler.setSuffix(".YYYY-MM-dd.zip"); + + for (int i = 0; i < 10; i++) { + + // Create a log message to be logged + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + Assert.assertTrue("File '" + logFile + "' does not exist", Files.exists(logFile)); + + // Read the contents of the log file and ensure there's only one line + List lines = Files.readAllLines(logFile, StandardCharsets.UTF_8); + Assert.assertEquals("More than 1 line found", 1, lines.size()); + Assert.assertTrue("Expected the line to contain the date: " + currentDate, lines.get(0).contains(currentDate)); + + cal.add(Calendar.DAY_OF_MONTH, 1); + cal.add(Calendar.MINUTE, 1); + currentDate = sdf.format(cal.getTime()); + } + + handler.setPruneSize("400"); + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(cal.getTimeInMillis()); + handler.publish(record); + + cal.add(Calendar.DAY_OF_MONTH, -1); + + List files = getBaseDirPaths(); + Assert.assertEquals(2, files.size()); + Assert.assertEquals("periodic-rotating-file-handler.log", files.get(0).getFileName().toString()); + Assert.assertEquals("periodic-rotating-file-handler.log." + sdf.format(cal.getTime()) + ".zip", files.get(1).getFileName().toString()); + + } + + private void createLogRecords(int number, Calendar now, String currentDate, SimpleDateFormat formatter) throws Exception { + for (int i = 0; i < number; i++) { + + // Create a log message to be logged + ExtLogRecord record = createLogRecord(Level.INFO, "Date: %s", currentDate); + record.setMillis(now.getTimeInMillis()); + handler.publish(record); + + // introduce a small pause to ensure that tests are determinate + Thread.sleep(250L); + + Assert.assertTrue("File '" + logFile + "' does not exist", Files.exists(logFile)); + + // Read the contents of the log file and ensure there's only one line + List lines = Files.readAllLines(logFile, StandardCharsets.UTF_8); + Assert.assertEquals("More than 1 line found", 1, lines.size()); + Assert.assertTrue("Expected the line to contain the date: " + currentDate, lines.get(0).contains(currentDate)); + + now.add(Calendar.DAY_OF_MONTH, 1); + now.add(Calendar.MINUTE, 1); + currentDate = formatter.format(now.getTime()); + + } + } private void testRotate(final Calendar cal, final Path rotatedFile) throws Exception { final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd"); diff --git a/ext/src/test/resources/configs/prune-logging.properties b/ext/src/test/resources/configs/prune-logging.properties new file mode 100644 index 00000000..93da4045 --- /dev/null +++ b/ext/src/test/resources/configs/prune-logging.properties @@ -0,0 +1,47 @@ +# +# JBoss, Home of Professional Open Source. +# +# Copyright 2014 Red Hat, Inc., and individual contributors +# as indicated by the @author tags. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +loggers=org.jboss.logmanager + +# Root logger +logger.level=INFO +logger.handlers=CONSOLE,FILE + +logger.org.jboss.logmanager.useParentHandlers=true +logger.org.jboss.logmanager.level=INFO + +handler.CONSOLE=org.jboss.logmanager.handlers.ConsoleHandler +handler.CONSOLE.formatter=PATTERN +handler.CONSOLE.properties=autoFlush,target +handler.CONSOLE.autoFlush=true +handler.CONSOLE.target=SYSTEM_OUT + +handler.FILE=org.jboss.logmanager.handlers.FileHandler +handler.FILE.formatter=PATTERN +handler.FILE.level=TRACE +handler.FILE.properties=autoFlush,append,fileName +handler.FILE.constructorProperties=fileName,append +handler.FILE.autoFlush=true +handler.FILE.append=false +handler.FILE.fileName=${log.dir:target}/test.log +handler.FILE.encoding=UTF-8 +handler.FILE.pruneSize=50 + +formatter.PATTERN=org.jboss.logmanager.formatters.PatternFormatter +formatter.PATTERN.properties=pattern +formatter.PATTERN.pattern=%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n \ No newline at end of file