Fixed log rotation on Windows

Synchronizes the operations on logs to make sure that we can safely
close the file stream before performing rotation.

Previously we did not close the stream which prevented log rotation
from ever working on Windows.

community/logging/src/main/java/org/neo4j/logging/RotatingFileOutputStreamSupplier.java

@@ -75,6 +75,7 @@ public void rotationError( @SuppressWarnings("unused") Exception e, @SuppressWar
     private final int maxArchives;
     private final RotationListener rotationListener;
     private final Executor rotationExecutor;
+    private final OutputStream streamWrapper;
     private final AtomicBoolean closed = new AtomicBoolean( false );
     private final AtomicBoolean rotating = new AtomicBoolean( false );
     private final AtomicLong earliestRotationTimeRef = new AtomicLong( 0 );
@@ -129,10 +130,49 @@ public RotatingFileOutputStreamSupplier( FileSystemAbstraction fileSystem, File
         this.rotationListener = rotationListener;
         this.rotationExecutor = rotationExecutor;
         this.outRef.set( openOutputFile() );
+        // Wrap the actual reference to prevent race conditions during log rotation
+        this.streamWrapper = new OutputStream()
+        {
+            @Override
+            public void write( int i ) throws IOException
+            {
+                synchronized ( outRef )
+                {
+                    outRef.get().write( i );
+                }
+            }
+
+            @Override
+            public void write( byte[] bytes ) throws IOException
+            {
+                synchronized ( outRef )
+                {
+                    outRef.get().write( bytes );
+                }
+            }
+
+            @Override
+            public void write( byte[] bytes, int off, int len ) throws IOException
+            {
+                synchronized ( outRef )
+                {
+                    outRef.get().write( bytes, off, len );
+                }
+            }
+
+            @Override
+            public void flush() throws IOException
+            {
+                synchronized ( outRef )
+                {
+                    outRef.get().flush();
+                }
+            }
+        };
     }
 
     /**
-     * @return An stream outputting to the latest output file
+     * @return A stream outputting to the latest output file
      */
     @Override
     public OutputStream get()
@@ -144,13 +184,13 @@ public OutputStream get()
                 rotate();
             }
         }
-        return outRef.get();
+        return this.streamWrapper;
     }
 
     @Override
     public void close() throws IOException
     {
-        synchronized (outRef)
+        synchronized ( outRef )
         {
             closed.set( true );
             for ( WeakReference<OutputStream> archivedStream : archivedStreams )
@@ -190,40 +230,58 @@ private void rotate()
             return;
         }
 
-        Runnable runnable = () -> {
-            OutputStream newStream;
-            try
+        Runnable runnable = () ->
+        {
+            synchronized ( outRef )
             {
-                if ( fileSystem.fileExists( outputFile ) )
+                OutputStream oldStream = outRef.get();
+
+                // Must close file prior to doing any operations on it or else it won't work on Windows
+                try
                 {
-                    shiftArchivedOutputFiles();
-                    fileSystem.renameFile( outputFile, archivedOutputFile( 1 ) );
+                    oldStream.flush();
+                    oldStream.close();
                 }
-                newStream = openOutputFile();
-            }
-            catch ( Exception e )
-            {
-                rotationListener.rotationError( e, outRef.get() );
-                rotating.set( false );
-                return;
-            }
-            OutputStream oldStream = outRef.get();
-            rotationListener.outputFileCreated( newStream, oldStream );
-            synchronized ( outRef )
-            {
+                catch ( Exception e )
+                {
+                    rotationListener.rotationError( e, outRef.get() );
+                    rotating.set( false );
+                    return;
+                }
+
+                OutputStream newStream;
+                try
+                {
+                    if ( fileSystem.fileExists( outputFile ) )
+                    {
+                        shiftArchivedOutputFiles();
+                        fileSystem.renameFile( outputFile, archivedOutputFile( 1 ) );
+                    }
+                    newStream = openOutputFile();
+                }
+                catch ( Exception e )
+                {
+                    rotationListener.rotationError( e, outRef.get() );
+                    rotating.set( false );
+                    return;
+                }
+
+                rotationListener.outputFileCreated( newStream, oldStream );
+
                 if ( !closed.get() )
                 {
                     outRef.set( newStream );
                     removeCollectedReferences( archivedStreams );
                     archivedStreams.add( new WeakReference<>( oldStream ) );
                 }
+
+                if ( rotationDelay > 0 )
+                {
+                    earliestRotationTimeRef.set( currentTimeSupplier.getAsLong() + rotationDelay );
+                }
+                rotationListener.rotationCompleted( newStream, oldStream );
+                rotating.set( false );
             }
-            if ( rotationDelay > 0 )
-            {
-                earliestRotationTimeRef.set( currentTimeSupplier.getAsLong() + rotationDelay );
-            }
-            rotationListener.rotationCompleted( newStream, oldStream );
-            rotating.set( false );
         };
 
         try

enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerIT.java

@@ -43,20 +43,25 @@
 import org.neo4j.io.fs.FileSystemAbstraction;
 import org.neo4j.kernel.configuration.Settings;
 import org.neo4j.logging.AssertableLogProvider;
+import org.neo4j.test.DefaultFileSystemRule;
 import org.neo4j.test.EphemeralFileSystemRule;
 import org.neo4j.test.TargetDirectory;
 import org.neo4j.test.TestGraphDatabaseFactory;
 
 import static org.hamcrest.Matchers.endsWith;
 import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertFalse;
 import static org.junit.Assert.assertThat;
 import static org.junit.Assert.assertTrue;
+import static org.neo4j.function.Predicates.await;
 
 public class QueryLoggerIT
 {
 
+    // It is imperitive that this test executes using a real filesystem; otherwise rotation failures will not be
+    // detected on Windows.
     @Rule
-    public final EphemeralFileSystemRule fileSystem = new EphemeralFileSystemRule();
+    public final DefaultFileSystemRule fileSystem = new DefaultFileSystemRule();
     @Rule
     public final TargetDirectory.TestDirectory testDirectory = TargetDirectory.testDirForTest( getClass() );
     private AssertableLogProvider inMemoryLog;
@@ -150,33 +155,40 @@ public void disabledQueryLogging() throws IOException
 
         executeQueryAndShutdown( database );
 
-        List<String> lines = readAllLines( logFilename );
-        assertTrue( "Should not have any queries logged since query log is disabled", lines.isEmpty() );
+        assertFalse( "Should not have any queries logged since query log is disabled", logFilename.exists() );
     }
 
     @Test
     public void queryLogRotation() throws Exception
     {
         final File logsDirectory = new File( testDirectory.graphDbDir(), "logs" );
         final File logFilename = new File( logsDirectory, "query.log" );
-        final File shiftedLogFilename = new File( logsDirectory, "query.log.1" );
+        final File shiftedLogFilename1 = new File( logsDirectory, "query.log.1" );
+        final File shiftedLogFilename2 = new File( logsDirectory, "query.log.2" );
         GraphDatabaseService database = databaseBuilder.setConfig( GraphDatabaseSettings.log_queries, Settings.TRUE )
                 .setConfig( GraphDatabaseSettings.logs_directory, logsDirectory.getPath() )
                 .setConfig( GraphDatabaseSettings.log_queries_rotation_threshold, "1" )
                 .newGraphDatabase();
 
-        database.execute( QUERY );
-        database.execute( QUERY );
-        // wait for file rotation to finish
-        Thread.sleep( TimeUnit.SECONDS.toMillis( 1 ) );
-        // execute one more slow query which should go to new log file
-        database.execute( QUERY );
+
+        // Logging is done asynchronously, and it turns out it's really hard to make it all work the same on Linux
+        // and on Windows, so just write maaaaany times to make sure we rotate several times.
+
+        for ( int i = 0; i < 100; i++ )
+        {
+            database.execute( QUERY );
+        }
+
         database.shutdown();
 
         List<String> lines = readAllLines( logFilename );
-        assertEquals( 1, lines.size() );
-        List<String> shiftedLines = readAllLines( shiftedLogFilename );
-        assertEquals( 2, shiftedLines.size() );
+        assertTrue( "Expected log file to have at least one log entry", lines.size() >= 1 );
+
+        lines = readAllLines( shiftedLogFilename1 );
+        assertTrue( "Expected shifted log file to have at least one log entry", lines.size() >= 1 );
+
+        lines = readAllLines( shiftedLogFilename2 );
+        assertTrue( "Expected second shifted log file to have at least one log entry", lines.size() >= 1 );
     }
 
     private void executeQueryAndShutdown( GraphDatabaseService database )