Jetty 9.4.x 1931 rollover (#1932)

* Issue #1931 Rollover log file

Added a protected method that is called whenever a log file is rolled over.
Support a date format of "" so that a rollover file may have the same name and a backup file is created.

Signed-off-by: Greg Wilkins <gregw@webtide.com>

* removed bad javadoc

Signed-off-by: Greg Wilkins <gregw@webtide.com>

* Issue #1931 Rollover

Replaced FilteredOutputStream with a volatile field so that rollover events will be seen immediately

* Issue #1931 Rollover

use mutex to avoid write and close race

jetty-util/src/main/java/org/eclipse/jetty/util/RolloverFileOutputStream.java

@@ -20,7 +20,6 @@ package org.eclipse.jetty.util;
 
 import java.io.File;
 import java.io.FileOutputStream;
-import java.io.FilterOutputStream;
 import java.io.IOException;
 import java.io.OutputStream;
 import java.text.SimpleDateFormat;
@@ -44,7 +43,7 @@ import java.util.TimerTask;
  * Old files are retained for a number of days before being deleted.
  * </p>
  */
-public class RolloverFileOutputStream extends FilterOutputStream
+public class RolloverFileOutputStream extends OutputStream
 {
     private static Timer __rollover;
     
@@ -53,6 +52,7 @@ public class RolloverFileOutputStream extends FilterOutputStream
     final static String ROLLOVER_FILE_BACKUP_FORMAT = "HHmmssSSS";
     final static int ROLLOVER_FILE_RETAIN_DAYS = 31;
 
+    private OutputStream _out;
     private RollTask _rollTask;
     private SimpleDateFormat _fileBackupFormat;
     private SimpleDateFormat _fileDateFormat;
@@ -128,7 +128,8 @@ public class RolloverFileOutputStream extends FilterOutputStream
      * @param append If true, existing files will be appended to.
      * @param retainDays The number of days to retain files before deleting them. 0 to retain forever.
      * @param zone the timezone for the output
-     * @param dateFormat The format for the date file substitution. The default is "yyyy_MM_dd". 
+     * @param dateFormat The format for the date file substitution. The default is "yyyy_MM_dd". If set to the
+     * empty string, the file is rolledover to the same filename, with the current file being renamed to the backup filename.
      * @param backupFormat The format for the file extension of backup files. The default is "HHmmssSSS". 
      * @throws IOException if unable to create output
      */
@@ -144,6 +145,7 @@ public class RolloverFileOutputStream extends FilterOutputStream
     }
     
 
+    /* ------------------------------------------------------------ */
     RolloverFileOutputStream(String filename,
         boolean append,
         int retainDays,
@@ -153,8 +155,6 @@ public class RolloverFileOutputStream extends FilterOutputStream
         ZonedDateTime now)
             throws IOException
     {
-        super(null);
-
         if (dateFormat==null)
             dateFormat=ROLLOVER_FILE_DATE_FORMAT;
         _fileDateFormat = new SimpleDateFormat(dateFormat);
@@ -179,16 +179,17 @@ public class RolloverFileOutputStream extends FilterOutputStream
         _append=append;
         _retainDays=retainDays;
         
+        // Calculate Today's Midnight, based on Configured TimeZone (will be in past, even if by a few milliseconds)
+        setFile(now);  
+        
         synchronized(RolloverFileOutputStream.class)
         {
             if (__rollover==null)
                 __rollover=new Timer(RolloverFileOutputStream.class.getName(),true);
-    
-            // Calculate Today's Midnight, based on Configured TimeZone (will be in past, even if by a few milliseconds)
-            setFile(now);        
-            // This will schedule the rollover event to the next midnight
-            scheduleNextRollover(now);
         }
+
+        // This will schedule the rollover event to the next midnight
+        scheduleNextRollover(now);
     }
 
     /* ------------------------------------------------------------ */
@@ -212,7 +213,10 @@ public class RolloverFileOutputStream extends FilterOutputStream
 
         // Schedule next rollover event to occur, based on local machine's Unix Epoch milliseconds
         long delay = midnight.toInstant().toEpochMilli() - now.toInstant().toEpochMilli();
-        __rollover.schedule(_rollTask,delay);
+        synchronized(RolloverFileOutputStream.class)
+        {
+            __rollover.schedule(_rollTask,delay);
+        }
     }
 
     /* ------------------------------------------------------------ */
@@ -236,44 +240,68 @@ public class RolloverFileOutputStream extends FilterOutputStream
     }
 
     /* ------------------------------------------------------------ */
-    synchronized void setFile(ZonedDateTime now)
+    void setFile(ZonedDateTime now)
         throws IOException
     {
-        // Check directory
+        File oldFile = null;
-        File file = new File(_filename);
+        File newFile = null;
-        _filename=file.getCanonicalPath();
+        File backupFile = null;
-        file=new File(_filename);
+        synchronized (this)
-        File dir= new File(file.getParent());
-        if (!dir.isDirectory() || !dir.canWrite())
-            throw new IOException("Cannot write log directory "+dir);
-            
-        // Is this a rollover file?
-        String filename=file.getName();
-        int i=filename.toLowerCase(Locale.ENGLISH).indexOf(YYYY_MM_DD);
-        if (i>=0)
         {
-            file=new File(dir,
+            // Check directory
-                          filename.substring(0,i)+
+            File file = new File(_filename);
-                          _fileDateFormat.format(new Date(now.toInstant().toEpochMilli()))+
+            _filename=file.getCanonicalPath();
-                          filename.substring(i+YYYY_MM_DD.length()));
+            file=new File(_filename);
+            File dir= new File(file.getParent());
+            if (!dir.isDirectory() || !dir.canWrite())
+                throw new IOException("Cannot write log directory "+dir);
+
+            // Is this a rollover file?
+            String filename=file.getName();
+            int datePattern=filename.toLowerCase(Locale.ENGLISH).indexOf(YYYY_MM_DD);
+            if (datePattern>=0)
+            {
+                file=new File(dir,
+                        filename.substring(0,datePattern)+
+                        _fileDateFormat.format(new Date(now.toInstant().toEpochMilli()))+
+                        filename.substring(datePattern+YYYY_MM_DD.length()));
+            }
+
+            if (file.exists()&&!file.canWrite())
+                throw new IOException("Cannot write log file "+file);
+
+            // Do we need to change the output stream?
+            if (_out==null || datePattern>=0)
+            {
+                // Yep
+                oldFile = _file;
+                _file=file;
+                newFile = _file;
+                if (!_append && file.exists())
+                {
+                    backupFile = new File(file.toString()+"."+_fileBackupFormat.format(new Date(now.toInstant().toEpochMilli())));
+                    file.renameTo(backupFile);
+                }
+                OutputStream oldOut=_out;
+                _out=new FileOutputStream(file.toString(),_append);
+                if (oldOut!=null)
+                    oldOut.close();
+                //if(log.isDebugEnabled())log.debug("Opened "+_file);
+            }
         }
         
-        if (file.exists()&&!file.canWrite())
+        if (newFile!=null)
-            throw new IOException("Cannot write log file "+file);
+            rollover(oldFile,backupFile,newFile);
+    }
 
-        // Do we need to change the output stream?
+    /* ------------------------------------------------------------ */
-        if (out==null || !file.equals(_file))
+    /** This method is called whenever a log file is rolled over
-        {
+     * @param oldFile  The original filename or null if this is the first creation
-            // Yep
+     * @param backupFile The backup filename or null if the filename is dated.
-            _file=file;
+     * @param newFile The new filename that is now being used for logging
-            if (!_append && file.exists())
+     */
-                file.renameTo(new File(file.toString()+"."+_fileBackupFormat.format(new Date(now.toInstant().toEpochMilli()))));
+    protected void rollover(File oldFile, File backupFile, File newFile)
-            OutputStream oldOut=out;
+    {
-            out=new FileOutputStream(file.toString(),_append);
-            if (oldOut!=null)
-                oldOut.close();
-            //if(log.isDebugEnabled())log.debug("Opened "+_file);
-        }
     }
     
     /* ------------------------------------------------------------ */
@@ -309,20 +337,44 @@ public class RolloverFileOutputStream extends FilterOutputStream
         }
     }
 
+    /* ------------------------------------------------------------ */
+    public void write(int b) throws IOException
+    {
+        synchronized(this)
+        {
+            _out.write(b);
+        }
+    }
+
     /* ------------------------------------------------------------ */
     @Override
     public void write (byte[] buf)
-        throws IOException
+            throws IOException
     {
-        out.write (buf);
+        synchronized(this)
+        {
+            _out.write (buf);
+        }
     }
 
     /* ------------------------------------------------------------ */
     @Override
     public void write (byte[] buf, int off, int len)
-        throws IOException
+            throws IOException
     {
-        out.write (buf, off, len);
+        synchronized(this)
+        {
+            _out.write (buf, off, len);
+        }
+    }
+
+    /* ------------------------------------------------------------ */
+    public void flush() throws IOException
+    {
+        synchronized(this)
+        {
+            _out.flush();
+        }
     }
     
     /* ------------------------------------------------------------ */
@@ -330,15 +382,21 @@ public class RolloverFileOutputStream extends FilterOutputStream
     public void close()
         throws IOException
     {
-        synchronized(RolloverFileOutputStream.class)
+        synchronized(this)
         {
-            try{super.close();}
+            try
+            {
+                _out.close();
+            }
             finally
             {
-                out=null;
+                _out=null;
                 _file=null;
             }
+        }
 
+        synchronized(RolloverFileOutputStream.class)
+        {
             if (_rollTask != null)
             {
                 _rollTask.cancel();
@@ -354,13 +412,10 @@ public class RolloverFileOutputStream extends FilterOutputStream
         {
             try
             {
-                synchronized(RolloverFileOutputStream.class)
+                ZonedDateTime now = ZonedDateTime.now(_fileDateFormat.getTimeZone().toZoneId());
-                {
+                RolloverFileOutputStream.this.setFile(now);
-                    ZonedDateTime now = ZonedDateTime.now(_fileDateFormat.getTimeZone().toZoneId());
+                RolloverFileOutputStream.this.removeOldFiles(now);
-                    RolloverFileOutputStream.this.setFile(now);
+                RolloverFileOutputStream.this.scheduleNextRollover(now);
-                    RolloverFileOutputStream.this.scheduleNextRollover(now);
-                    RolloverFileOutputStream.this.removeOldFiles(now);
-                }
             }
             catch(Throwable t)
             {

jetty-util/src/test/java/org/eclipse/jetty/util/RolloverFileOutputStreamTest.java

@@ -325,4 +325,44 @@ public class RolloverFileOutputStreamTest
             }
         }
     }
+    
+    @Test
+    public void testRolloverBackup() throws Exception
+    {
+        File testDir = MavenTestingUtils.getTargetTestingDir(RolloverFileOutputStreamTest.class.getName() + "_testRollover");
+        FS.ensureEmpty(testDir);
+
+        ZoneId zone = toZoneId("Australia/Sydney");
+        ZonedDateTime now = toDateTime("2016.04.10-11:59:55.0 PM AEDT", zone);
+        
+        File template = new File(testDir,"test-rofosyyyy_mm_dd.log");
+        
+        try (RolloverFileOutputStream rofos = 
+            new RolloverFileOutputStream(template.getAbsolutePath(),false,0,TimeZone.getTimeZone(zone),"",null,now))
+        {
+            rofos.write("BEFORE".getBytes());
+            rofos.flush();
+            String[] ls = testDir.list();
+            assertThat(ls.length,is(1));
+            assertThat(ls[0],is("test-rofos.log"));
+
+            TimeUnit.SECONDS.sleep(10);
+            rofos.write("AFTER".getBytes());
+            ls = testDir.list();
+            assertThat(ls.length,is(2));
+            
+            for (String n : ls)
+            {
+                String content = IO.toString(new FileReader(new File(testDir,n)));
+                if ("test-rofos.log".equals(n))
+                {
+                    assertThat(content,is("AFTER"));
+                }
+                else
+                {
+                    assertThat(content,is("BEFORE"));
+                }
+            }
+        }
+    }
 }