diff --git a/.github/workflows/maven.yml b/.github/workflows/maven.yml index 83e2b135..192ef44b 100644 --- a/.github/workflows/maven.yml +++ b/.github/workflows/maven.yml @@ -36,7 +36,7 @@ jobs: 17 21 - name: Build and Test - run: mvn -B clean verify "-Djava11.home=${{env.JAVA_HOME_11_X64}}" "-Djava17.home=${{env.JAVA_HOME_17_X64}}" + run: mvn -B clean verify "-Djava11.home=${{env.JAVA_HOME_11_X64}}" "-Djava17.home=${{env.JAVA_HOME_17_X64}}" "-Dorg.jboss.test.timeout=60" - uses: actions/upload-artifact@v4 if: failure() with: diff --git a/pom.xml b/pom.xml index 509531f5..e21e8e56 100644 --- a/pom.xml +++ b/pom.xml @@ -240,6 +240,7 @@ ${org.jboss.test.address} ${org.jboss.test.port} ${org.jboss.test.alt.port} + 10 ${project.build.testOutputDirectory}${file.separator}configs diff --git a/src/main/java/org/jboss/logmanager/handlers/SuffixRotator.java b/src/main/java/org/jboss/logmanager/handlers/SuffixRotator.java index 661e8d0b..20c2fa28 100644 --- a/src/main/java/org/jboss/logmanager/handlers/SuffixRotator.java +++ b/src/main/java/org/jboss/logmanager/handlers/SuffixRotator.java @@ -34,6 +34,9 @@ import java.text.SimpleDateFormat; import java.util.Date; import java.util.Locale; +import java.util.concurrent.CompletableFuture; +import java.util.concurrent.CompletionStage; +import java.util.function.Supplier; import java.util.logging.ErrorManager; import java.util.zip.GZIPOutputStream; import java.util.zip.ZipEntry; @@ -46,6 +49,8 @@ */ class SuffixRotator { + private static final int MAX_FAILED = 100; + /** * The compression type for the rotation */ @@ -160,20 +165,18 @@ CompressionType getCompressionType() { */ void rotate(final ErrorManager errorManager, final Path source, final String suffix) { final Path target = Paths.get(source + suffix + compressionSuffix); - if (compressionType == CompressionType.GZIP) { - try { - archiveGzip(source, target); - // Delete the file after it's archived to behave like a file move or rename - deleteFile(source); - } catch (Exception e) { - errorManager.error(String.format("Failed to compress %s to %s. Compressed file may be left on the " + - "filesystem corrupted.", source, target), e, ErrorManager.WRITE_FAILURE); - } - } else if (compressionType == CompressionType.ZIP) { + if (compressionType == CompressionType.GZIP || compressionType == CompressionType.ZIP) { try { - archiveZip(source, target); - // Delete the file after it's archived to behave like a file move or rename - deleteFile(source); + archive(errorManager, source, target) + .whenComplete((file, error) -> { + if (error != null) { + final Exception e = (error instanceof Exception) ? (Exception) error : new Exception(error); + errorManager.error( + String.format("Failed to archive file %s. Log file should be available at %s.", source, + file), + e, ErrorManager.WRITE_FAILURE); + } + }); } catch (Exception e) { errorManager.error(String.format("Failed to compress %s to %s. Compressed file may be left on the " + "filesystem corrupted.", source, target), e, ErrorManager.WRITE_FAILURE); @@ -263,8 +266,63 @@ private void move(final ErrorManager errorManager, final Path src, final Path ta } } + private CompletionStage archive(final ErrorManager errorManager, final Path source, final Path target) + throws IOException { + // Copy the file to a temporary file + final Path temp = Files.createTempFile(source.getFileName().toString(), ".tmp"); + Files.move(source, temp, StandardCopyOption.REPLACE_EXISTING); + // Create the callable for the move + final Supplier task = () -> { + try { + if (compressionType == CompressionType.GZIP) { + archiveGzip(temp, target); + } else if (compressionType == CompressionType.ZIP) { + archiveZip(source.getFileName(), temp, target); + } else { + // This should never happen, but in case an error occurs elsewhere, we can't lose logs. + errorManager.error( + String.format("Invalid compression type %s. File preserved at %s.", compressionType, temp), null, + ErrorManager.WRITE_FAILURE); + } + return target; + } catch (Exception e) { + // Determine the new target file name + final Path dir = source.getParent(); + Path failedTarget; + if (dir == null) { + failedTarget = Path.of(source.getFileName().toString() + ".failed"); + } else { + failedTarget = dir.resolve(source.getFileName().toString() + ".failed"); + } + final Path root = failedTarget; + int index = 0; + while (Files.exists(failedTarget)) { + if (dir == null) { + failedTarget = Path.of(root.getFileName().toString() + ++index); + } else { + failedTarget = dir.resolve(root.getFileName().toString() + ++index); + } + if (index >= MAX_FAILED) { + errorManager.error(String.format("The maximum number of failed attempts, %d, as been reached. " + + "No more attempts will be made to rotate the file.", MAX_FAILED), null, + ErrorManager.WRITE_FAILURE); + return temp; + } + } + try { + return Files.move(temp, failedTarget); + } catch (IOException ioe) { + errorManager.error(String.format("Failed to move file %s back to %s.", temp, failedTarget), ioe, + ErrorManager.WRITE_FAILURE); + return temp; + } + } + }; + return CompletableFuture.supplyAsync(task); + } + private void archiveGzip(final Path source, final Path target) throws IOException { - final byte[] buff = new byte[512]; + final byte[] buff = new byte[2048]; try (final GZIPOutputStream out = new GZIPOutputStream(newOutputStream(target), true)) { try (final InputStream in = newInputStream(source)) { int len; @@ -276,10 +334,10 @@ private void archiveGzip(final Path source, final Path target) throws IOExceptio } } - private void archiveZip(final Path source, final Path target) throws IOException { - final byte[] buff = new byte[512]; + private void archiveZip(final Path fileName, final Path source, final Path target) throws IOException { + final byte[] buff = new byte[2048]; try (final ZipOutputStream out = new ZipOutputStream(newOutputStream(target), StandardCharsets.UTF_8)) { - final ZipEntry entry = new ZipEntry(source.getFileName().toString()); + final ZipEntry entry = new ZipEntry(fileName.toString()); out.putNextEntry(entry); try (final InputStream in = newInputStream(source)) { int len; diff --git a/src/test/java/org/jboss/logmanager/handlers/AbstractHandlerTest.java b/src/test/java/org/jboss/logmanager/handlers/AbstractHandlerTest.java index 7e0a20f0..75bcad44 100644 --- a/src/test/java/org/jboss/logmanager/handlers/AbstractHandlerTest.java +++ b/src/test/java/org/jboss/logmanager/handlers/AbstractHandlerTest.java @@ -33,6 +33,10 @@ import java.util.Collection; import java.util.Collections; import java.util.List; +import java.util.Set; +import java.util.concurrent.ConcurrentSkipListSet; +import java.util.concurrent.TimeUnit; +import java.util.stream.Stream; import java.util.zip.GZIPInputStream; import org.jboss.logmanager.ExtHandler; @@ -46,10 +50,13 @@ * @author James R. Perkins */ public class AbstractHandlerTest { + + private static final long TIMEOUT; static final File BASE_LOG_DIR; static { BASE_LOG_DIR = new File(System.getProperty("log.dir")); + TIMEOUT = Long.parseLong(System.getProperty("org.jboss.test.timeout", "10")); } final static PatternFormatter FORMATTER = new PatternFormatter("%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n"); @@ -124,6 +131,53 @@ protected ExtLogRecord createLogRecord(final org.jboss.logmanager.Level level, f return new ExtLogRecord(level, String.format(format, args), getClass().getName()); } + /** + * Waits for all files to be rotated before exiting. + * + * @param archiveSuffix the type of the archive + * @param expectedFiles the files which need to exist + * + * @throws InterruptedException if an error occurs while waiting + */ + @SuppressWarnings("SameParameterValue") + static void waitForRotation(final String archiveSuffix, final Path... expectedFiles) throws InterruptedException { + final Set files = new ConcurrentSkipListSet<>(Set.of(expectedFiles)); + final long millis = TIMEOUT * 1000L; + final Thread task = new Thread(() -> { + long t = millis; + while (t > 0) { + files.removeIf(f -> { + try { + if (Files.exists(f)) { + // Attempt to read the archive, if it ends in an error then we assume the write is not complete + if (".gz".equalsIgnoreCase(archiveSuffix)) { + readAllLinesFromGzip(f); + return true; + } + return isValidZip(f); + } + } catch (Throwable ignore) { + ignore.printStackTrace(); + } + return false; + }); + if (files.isEmpty()) { + break; + } + try { + TimeUnit.MILLISECONDS.sleep(200L); + } catch (InterruptedException ignore) { + } + t -= 200L; + } + }); + task.start(); + task.join(); + if (!files.isEmpty()) { + Assertions.fail(String.format("Failed to find all files within %d seconds. Missing files: %s", TIMEOUT, files)); + } + } + /** * Validates that at least one line of the GZIP'd file contains the expected text. * @@ -229,4 +283,17 @@ private static Collection readAllLinesFromGzip(final Path path) throws I } return lines; } + + private static boolean isValidZip(final Path path) { + try ( + final FileSystem zipFs = FileSystems.newFileSystem(URI.create("jar:" + path.toUri().toASCIIString()), + Collections.singletonMap("create", "true"))) { + // Simply walk the file stream and assume if there are any entries, the ZIP is fully written + try (Stream files = Files.list(zipFs.getPath("/"))) { + return files.findAny().isPresent(); + } + } catch (IOException e) { + return false; + } + } } diff --git a/src/test/java/org/jboss/logmanager/handlers/PeriodicRotatingFileHandlerTests.java b/src/test/java/org/jboss/logmanager/handlers/PeriodicRotatingFileHandlerTests.java index ae8da07d..3f80f79d 100644 --- a/src/test/java/org/jboss/logmanager/handlers/PeriodicRotatingFileHandlerTests.java +++ b/src/test/java/org/jboss/logmanager/handlers/PeriodicRotatingFileHandlerTests.java @@ -212,6 +212,7 @@ record = createLogRecord(Level.INFO, "Date: %s", thirdDay); final Path logDir = BASE_LOG_DIR.toPath(); final Path rotated1 = logDir.resolve(FILENAME + firstDateSuffix + archiveSuffix); final Path rotated2 = logDir.resolve(FILENAME + secondDateSuffix + archiveSuffix); + waitForRotation(archiveSuffix, rotated1, rotated2); Assertions.assertTrue(Files.exists(logFile), () -> "Missing file " + logFile); Assertions.assertTrue(Files.exists(rotated1), () -> "Missing rotated file " + rotated1); Assertions.assertTrue(Files.exists(rotated2), () -> "Missing rotated file " + rotated2); diff --git a/src/test/java/org/jboss/logmanager/handlers/PeriodicSizeRotatingFileHandlerTests.java b/src/test/java/org/jboss/logmanager/handlers/PeriodicSizeRotatingFileHandlerTests.java index a0e222dd..1cc4e7e0 100644 --- a/src/test/java/org/jboss/logmanager/handlers/PeriodicSizeRotatingFileHandlerTests.java +++ b/src/test/java/org/jboss/logmanager/handlers/PeriodicSizeRotatingFileHandlerTests.java @@ -260,6 +260,7 @@ private void testArchiveRotate(final String dateSuffix, final String archiveSuff final Path logDir = BASE_LOG_DIR.toPath(); final Path path1 = logDir.resolve(FILENAME + currentDate + ".1" + archiveSuffix); final Path path2 = logDir.resolve(FILENAME + currentDate + ".2" + archiveSuffix); + waitForRotation(archiveSuffix, path1, path2); Assertions.assertTrue(logFile.exists()); Assertions.assertTrue(Files.exists(path1)); Assertions.assertTrue(Files.exists(path2)); diff --git a/src/test/java/org/jboss/logmanager/handlers/SizeRotatingFileHandlerTests.java b/src/test/java/org/jboss/logmanager/handlers/SizeRotatingFileHandlerTests.java index decbe516..03018b8d 100644 --- a/src/test/java/org/jboss/logmanager/handlers/SizeRotatingFileHandlerTests.java +++ b/src/test/java/org/jboss/logmanager/handlers/SizeRotatingFileHandlerTests.java @@ -259,6 +259,7 @@ private void testArchiveRotate(final String archiveSuffix, final boolean rotateO final Path logDir = BASE_LOG_DIR.toPath(); final Path path1 = logDir.resolve(FILENAME + ".1" + archiveSuffix); final Path path2 = logDir.resolve(FILENAME + ".2" + archiveSuffix); + waitForRotation(archiveSuffix, path1, path2); Assertions.assertTrue(logFile.exists()); Assertions.assertTrue(Files.exists(path1)); Assertions.assertTrue(Files.exists(path2));