Roll log files daily

log-manager/pom.xml

@@ -114,6 +114,12 @@
         </dependency>
 
         <!-- for testing -->
+        <dependency>
+            <groupId>io.airlift</groupId>
+            <artifactId>testing</artifactId>
+            <scope>test</scope>
+        </dependency>
+
         <dependency>
             <groupId>org.testng</groupId>
             <artifactId>testng</artifactId>

log-manager/src/main/java/io/airlift/log/LogFileName.java

@@ -151,21 +151,21 @@ private static Optional<LogFileName> parseLegacyLogName(String historyFileName,
         return Optional.of(new LogFileName(historyFileName, dateTime, OptionalInt.empty(), OptionalInt.of(legacyIndex), slug, compressed));
     }
 
-    public static LogFileName generateNextLogFileName(Path masterLogFile, Optional<String> compressionExtension)
+    public static LogFileName generateNextLogFileName(Path masterLogFile, LocalDateTime currentDateTime, Optional<String> compressionExtension)
     {
-        LocalDateTime dateTime = LocalDateTime.now().withNano(0);
-        String suffix = DATE_TIME_FORMATTER.format(dateTime);
+        currentDateTime = currentDateTime.withNano(0);
+        String suffix = DATE_TIME_FORMATTER.format(currentDateTime);
         for (int index = 0; index < MAX_GENERATED_INDEX; index++) {
             String newFileName = masterLogFile.getFileName() + suffix + (index > 0 ? "-" + index : "");
             Path newFile = masterLogFile.resolveSibling(newFileName);
             if (!fileAlreadyExists(newFile, compressionExtension)) {
-                return new LogFileName(newFileName, dateTime, OptionalInt.of(index), OptionalInt.empty(), Optional.empty(), false);
+                return new LogFileName(newFileName, currentDateTime, OptionalInt.of(index), OptionalInt.empty(), Optional.empty(), false);
             }
         }
         // something strange is happening, just use a random UUID, so we continue logging
         String slug = randomUUID().toString();
         String randomFileName = masterLogFile.getFileName() + suffix + "--" + slug;
-        return new LogFileName(randomFileName, dateTime, OptionalInt.of(0), OptionalInt.empty(), Optional.of(slug), false);
+        return new LogFileName(randomFileName, currentDateTime, OptionalInt.of(0), OptionalInt.empty(), Optional.of(slug), false);
     }
 
     private static boolean fileAlreadyExists(Path newFile, Optional<String> compressionExtension)

log-manager/src/main/java/io/airlift/log/Logging.java

@@ -41,6 +41,7 @@
 import static com.google.common.collect.Maps.fromProperties;
 import static io.airlift.configuration.ConfigurationLoader.loadPropertiesFrom;
 import static io.airlift.configuration.ConfigurationUtils.replaceEnvironmentVariables;
+import static io.airlift.log.RollingFileMessageOutput.FileTimeRoller.SYSTEM_FILE_TIME_ROLLER;
 import static io.airlift.log.RollingFileMessageOutput.createRollingFileHandler;
 import static io.airlift.log.SocketMessageOutput.createSocketHandler;
 
@@ -125,7 +126,7 @@ public void logToFile(boolean legacyLoggerImplementation, String logPath, int ma
             handler = new LegacyRollingFileHandler(logPath, maxHistory, maxFileSize.toBytes(), formatter);
         }
         else {
-            handler = createRollingFileHandler(logPath, maxFileSize, maxTotalSize, compressionType, formatter, new BufferedHandlerErrorManager(stdErr));
+            handler = createRollingFileHandler(logPath, maxFileSize, maxTotalSize, compressionType, formatter, new BufferedHandlerErrorManager(stdErr), SYSTEM_FILE_TIME_ROLLER);
         }
         ROOT.addHandler(handler);
     }

log-manager/src/main/java/io/airlift/log/RollingFileMessageOutput.java

@@ -13,6 +13,8 @@
  */
 package io.airlift.log;
 
+import com.google.common.annotations.VisibleForTesting;
+import com.google.common.base.Ticker;
 import com.google.common.collect.ImmutableSet;
 import com.google.common.io.ByteStreams;
 import com.google.common.io.MoreFiles;
@@ -31,13 +33,15 @@
 import java.nio.file.Path;
 import java.nio.file.Paths;
 import java.nio.file.attribute.BasicFileAttributes;
+import java.time.Instant;
 import java.time.LocalDateTime;
 import java.time.ZoneId;
 import java.time.format.DateTimeFormatter;
 import java.util.Optional;
 import java.util.Set;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.TimeUnit;
+import java.util.function.LongSupplier;
 import java.util.logging.ErrorManager;
 import java.util.logging.Formatter;
 import java.util.zip.GZIPOutputStream;
@@ -84,6 +88,7 @@ public Optional<String> getExtension()
     private final long maxFileSize;
     private final CompressionType compressionType;
     private final Formatter formatter;
+    private final FileTimeRoller fileTimeRoller;
 
     @GuardedBy("this")
     private Path currentOutputFile;
@@ -104,25 +109,34 @@ public static BufferedHandler createRollingFileHandler(
             DataSize maxTotalSize,
             CompressionType compressionType,
             Formatter formatter,
-            ErrorManager errorManager)
+            ErrorManager errorManager,
+            FileTimeRoller fileTimeRoller)
     {
-        RollingFileMessageOutput output = new RollingFileMessageOutput(filename, maxFileSize, maxTotalSize, compressionType, formatter);
+        RollingFileMessageOutput output = new RollingFileMessageOutput(filename, maxFileSize, maxTotalSize, compressionType, formatter, fileTimeRoller);
         BufferedHandler handler = new BufferedHandler(output, formatter, errorManager);
         handler.start();
         return handler;
     }
 
-    private RollingFileMessageOutput(String filename, DataSize maxFileSize, DataSize maxTotalSize, CompressionType compressionType, Formatter formatter)
+    private RollingFileMessageOutput(
+            String filename,
+            DataSize maxFileSize,
+            DataSize maxTotalSize,
+            CompressionType compressionType,
+            Formatter formatter,
+            FileTimeRoller fileTimeRoller)
     {
         requireNonNull(filename, "filename is null");
         requireNonNull(maxFileSize, "maxFileSize is null");
         requireNonNull(maxTotalSize, "maxTotalSize is null");
         requireNonNull(compressionType, "compressionType is null");
         requireNonNull(formatter, "formatter is null");
+        requireNonNull(fileTimeRoller, "fileTimeRoller is null");
 
         this.maxFileSize = maxFileSize.toBytes();
         this.compressionType = compressionType;
         this.formatter = formatter;
+        this.fileTimeRoller = fileTimeRoller;
 
         symlink = Paths.get(filename);
 
@@ -238,7 +252,7 @@ public synchronized void close()
     public synchronized void writeMessage(byte[] message)
             throws IOException
     {
-        if (currentFileSize + message.length > maxFileSize) {
+        if (currentFileSize + message.length > maxFileSize || fileTimeRoller.shouldRoll()) {
             try {
                 rollFile();
             }
@@ -264,7 +278,8 @@ private synchronized void rollFile()
         OutputStream newOutputStream = null;
         for (int i = 0; i < MAX_OPEN_NEW_LOG_ATTEMPTS; i++) {
             try {
-                newFileName = LogFileName.generateNextLogFileName(symlink, compressionType.getExtension());
+                // Note: use the current date time from the file time roller for the file name, to ensure tests work as expected
+                newFileName = LogFileName.generateNextLogFileName(symlink, fileTimeRoller.currentDateTime(), compressionType.getExtension());
                 newFile = symlink.resolveSibling(newFileName.getFileName());
                 newOutputStream = new BufferedOutputStream(Files.newOutputStream(newFile, CREATE_NEW), MAX_BATCH_BYTES);
                 break;
@@ -310,6 +325,7 @@ private synchronized void rollFile()
         currentOutputFileName = newFileName;
         currentOutputStream = newOutputStream;
         currentFileSize = 0;
+        fileTimeRoller.updateNextRollTime(newFileName.getDateTime());
 
         // update symlink
         try {
@@ -444,4 +460,48 @@ public synchronized Set<LogFileName> getFiles()
         }
         return files.build();
     }
+
+    @VisibleForTesting
+    static class FileTimeRoller
+    {
+        public static final FileTimeRoller SYSTEM_FILE_TIME_ROLLER = new FileTimeRoller(System::currentTimeMillis, Ticker.systemTicker());
+
+        private final LongSupplier systemTimeMillis;
+        private final Ticker ticker;
+
+        @GuardedBy("this")
+        private long lastRollNanos;
+
+        @GuardedBy("this")
+        private long nanosToNextRoll;
+
+        public FileTimeRoller(LongSupplier systemTimeMillis, Ticker ticker)
+        {
+            this.systemTimeMillis = requireNonNull(systemTimeMillis, "systemTimeMillis is null");
+            this.ticker = requireNonNull(ticker, "ticker is null");
+        }
+
+        public LocalDateTime currentDateTime()
+        {
+            return LocalDateTime.ofInstant(Instant.ofEpochMilli(systemTimeMillis.getAsLong()), ZoneId.systemDefault());
+        }
+
+        public synchronized boolean shouldRoll()
+        {
+            return ticker.read() - lastRollNanos >= nanosToNextRoll;
+        }
+
+        @VisibleForTesting
+        synchronized long getNextRollNanos()
+        {
+            return lastRollNanos + nanosToNextRoll;
+        }
+
+        public synchronized void updateNextRollTime(LocalDateTime logFileCreateTime)
+        {
+            lastRollNanos = ticker.read();
+            long epochMilli = logFileCreateTime.toLocalDate().plusDays(1).atStartOfDay(ZoneId.systemDefault()).toInstant().toEpochMilli();
+            nanosToNextRoll = TimeUnit.MILLISECONDS.toNanos(epochMilli - systemTimeMillis.getAsLong());
+        }
+    }
 }

log-manager/src/test/java/io/airlift/log/TestLogFileName.java

@@ -134,7 +134,7 @@ public void testComparisonNewAndLegacy()
     public void testGenerateNextLogFileName()
     {
         // note: no actual files are created here
-        LogFileName logFileName = LogFileName.generateNextLogFileName(Paths.get(BASE_NAME), Optional.empty());
+        LogFileName logFileName = LogFileName.generateNextLogFileName(Paths.get(BASE_NAME), LocalDateTime.now(), Optional.empty());
         assertEquals(logFileName.getIndex(), OptionalInt.of(0));
         assertEquals(logFileName.getLegacyIndex(), OptionalInt.empty());
 

log-manager/src/test/java/io/airlift/log/TestLogHistoryManager.java

@@ -19,6 +19,7 @@
 import java.io.IOException;
 import java.nio.file.Files;
 import java.nio.file.Path;
+import java.time.LocalDateTime;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.Optional;
@@ -141,7 +142,7 @@ public void testRuntimePrune()
     private static LogFileName createTestFile(Path masterLogName)
             throws IOException
     {
-        LogFileName logFileName = LogFileName.generateNextLogFileName(masterLogName, Optional.empty());
+        LogFileName logFileName = LogFileName.generateNextLogFileName(masterLogName, LocalDateTime.now(), Optional.empty());
         Files.write(masterLogName.resolveSibling(logFileName.getFileName()), new byte[FILE_SIZE], CREATE_NEW);
         return logFileName;
     }