Merge pull request #2548 from christ66/JENKINS-34855

[JENKINS-34855] AtomicFileWriter is not Atomic

core/src/main/java/hudson/util/AtomicFileWriter.java

@@ -23,17 +23,20 @@
  */
 package hudson.util;
 
-import hudson.Util;
-import java.io.BufferedWriter;
+import javax.annotation.Nonnull;
+import javax.annotation.Nullable;
 import java.io.File;
-import java.io.FileOutputStream;
 import java.io.FileWriter;
 import java.io.IOException;
-import java.io.OutputStreamWriter;
 import java.io.Writer;
 import java.nio.charset.Charset;
+import java.nio.file.AtomicMoveNotSupportedException;
 import java.nio.file.Files;
 import java.nio.file.InvalidPathException;
+import java.nio.file.Path;
+import java.nio.file.StandardCopyOption;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 
 /**
  * Buffered {@link FileWriter} that supports atomic operations.
@@ -46,9 +49,11 @@ import java.nio.file.InvalidPathException;
  */
 public class AtomicFileWriter extends Writer {
 
+    private static final Logger LOGGER = Logger.getLogger(AtomicFileWriter.class.getName());
+
     private final Writer core;
-    private final File tmpFile;
-    private final File destFile;
+    private final Path tmpPath;
+    private final Path destPath;
 
     /**
      * Writes with UTF-8 encoding.
@@ -58,27 +63,62 @@ public class AtomicFileWriter extends Writer {
     }
 
     /**
-     * @param encoding
-     *      File encoding to write. If null, platform default encoding is chosen.
+     * @param encoding File encoding to write. If null, platform default encoding is chosen.
+     *
+     * @deprecated Use {@link #AtomicFileWriter(Path, Charset)}
      */
-    public AtomicFileWriter(File f, String encoding) throws IOException {
-        File dir = f.getParentFile();
-        try {
-            dir.mkdirs();
-            tmpFile = File.createTempFile("atomic",null, dir);
-        } catch (IOException e) {
-            throw new IOException("Failed to create a temporary file in "+ dir,e);
-        }
-        destFile = f;
-        if (encoding==null)
-            encoding = Charset.defaultCharset().name();
+    @Deprecated
+    public AtomicFileWriter(@Nonnull File f, @Nullable String encoding) throws IOException {
+        this(toPath(f), encoding == null ? Charset.defaultCharset() : Charset.forName(encoding));
+    }
+
+    /**
+     * Wraps potential {@link java.nio.file.InvalidPathException} thrown by {@link File#toPath()} in an
+     * {@link IOException} for backward compatibility.
+     *
+     * @param file
+     * @return the path for that file
+     * @see File#toPath()
+     */
+    private static Path toPath(@Nonnull File file) throws IOException {
         try {
-            core = new BufferedWriter(new OutputStreamWriter(Files.newOutputStream(tmpFile.toPath()), encoding));
+            return file.toPath();
         } catch (InvalidPathException e) {
             throw new IOException(e);
         }
     }
 
+    /**
+     * @param destinationPath the destination path where to write the content when committed.
+     * @param charset File charset to write.
+     */
+    public AtomicFileWriter(@Nonnull Path destinationPath, @Nonnull Charset charset) throws IOException {
+        if (charset == null) { // be extra-defensive if people don't care
+            throw new IllegalArgumentException("charset is null");
+        }
+        this.destPath = destinationPath;
+        Path dir = this.destPath.getParent();
+
+        if (Files.exists(dir) && !Files.isDirectory(dir)) {
+            throw new IOException(dir + " exists and is neither a directory nor a symlink to a directory");
+        }
+        else {
+            if (Files.isSymbolicLink(dir)) {
+                LOGGER.log(Level.CONFIG, "{0} is a symlink to a directory", dir);
+            } else {
+                Files.createDirectories(dir); // Cannot be called on symlink, so we are pretty defensive...
+            }
+        }
+
+        try {
+            tmpPath = Files.createTempFile(dir, "atomic", "tmp");
+        } catch (IOException e) {
+            throw new IOException("Failed to create a temporary file in "+ dir,e);
+        }
+
+        core = Files.newBufferedWriter(tmpPath, charset);
+    }
+
     @Override
     public void write(int c) throws IOException {
         core.write(c);
@@ -108,35 +148,77 @@ public class AtomicFileWriter extends Writer {
      * the {@link #commit()} is called, to simplify coding.
      */
     public void abort() throws IOException {
-        close();
-        tmpFile.delete();
+        closeAndDeleteTempFile();
     }
 
     public void commit() throws IOException {
         close();
-        if (destFile.exists()) {
+        try {
+            // Try to make an atomic move.
+            Files.move(tmpPath, destPath, StandardCopyOption.ATOMIC_MOVE);
+        } catch (IOException e) {
+            // If it falls here that can mean many things. Either that the atomic move is not supported,
+            // or something wrong happened. Anyway, let's try to be over-diagnosing
+            if (e instanceof AtomicMoveNotSupportedException) {
+                LOGGER.log(Level.WARNING, "Atomic move not supported. falling back to non-atomic move.", e);
+            } else {
+                LOGGER.log(Level.WARNING, "Unable to move atomically, falling back to non-atomic move.", e);
+            }
+
+            if (destPath.toFile().exists()) {
+                LOGGER.log(Level.INFO, "The target file {0} was already existing", destPath);
+            }
+
             try {
-                Util.deleteFile(destFile);
-            } catch (IOException x) {
-                tmpFile.delete();
-                throw x;
+                Files.move(tmpPath, destPath, StandardCopyOption.REPLACE_EXISTING);
+            } catch (IOException e1) {
+                e1.addSuppressed(e);
+                LOGGER.log(Level.WARNING, "Unable to move {0} to {1}. Attempting to delete {0} and abandoning.",
+                           new Path[]{tmpPath, destPath});
+                try {
+                    Files.deleteIfExists(tmpPath);
+                } catch (IOException e2) {
+                    e2.addSuppressed(e1);
+                    LOGGER.log(Level.WARNING, "Unable to delete {0}, good bye then!", tmpPath);
+                    throw e2;
+                }
+
+                throw e1;
             }
         }
-        tmpFile.renameTo(destFile);
     }
 
     @Override
     protected void finalize() throws Throwable {
+        closeAndDeleteTempFile();
+    }
+
+    private void closeAndDeleteTempFile() throws IOException {
         // one way or the other, temporary file should be deleted.
-        close();
-        tmpFile.delete();
+        try {
+            close();
+        } finally {
+            Files.deleteIfExists(tmpPath);
+        }
     }
 
     /**
      * Until the data is committed, this file captures
      * the written content.
+     *
+     * @deprecated Use getTemporaryPath()
      */
+    @Deprecated
     public File getTemporaryFile() {
-        return tmpFile;
+        return tmpPath.toFile();
+    }
+
+    /**
+     * Until the data is committed, this file captures
+     * the written content.
+     * @since TODO
+     */
+    public Path getTemporaryPath() {
+        return tmpPath;
     }
 }

core/src/test/java/hudson/util/AtomicFileWriterTest.java

+package hudson.util;
+
+import org.hamcrest.core.StringContains;
+import org.junit.Before;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.rules.TemporaryFolder;
+
+import java.io.File;
+import java.io.IOException;
+import java.nio.charset.Charset;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.nio.file.Paths;
+
+import static org.hamcrest.core.StringContains.*;
+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.junit.Assert.fail;
+
+public class AtomicFileWriterTest {
+    @Rule
+    public TemporaryFolder tmp = new TemporaryFolder();
+    File af;
+    AtomicFileWriter afw;
+    String expectedContent = "hello world";
+
+    @Before
+    public void setUp() throws IOException {
+        af = tmp.newFile();
+        afw = new AtomicFileWriter(af.toPath(), Charset.defaultCharset());
+    }
+
+    @Test
+    public void symlinkToDirectory() throws Exception {
+        final File folder = tmp.newFolder();
+        final File containingSymlink = tmp.newFolder();
+        final Path zeSymlink = Files.createSymbolicLink(Paths.get(containingSymlink.getAbsolutePath(), "ze_symlink"),
+                                                         folder.toPath());
+
+
+        final Path childFileInSymlinkToDir = Paths.get(zeSymlink.toString(), "childFileInSymlinkToDir");
+
+        new AtomicFileWriter(childFileInSymlinkToDir, Charset.forName("UTF-8"));
+    }
+
+    @Test
+    public void createFile() throws Exception {
+        // Verify the file we created exists
+        assertTrue(Files.exists(afw.getTemporaryPath()));
+    }
+
+    @Test
+    public void writeToAtomicFile() throws Exception {
+        // Given
+        afw.write(expectedContent, 0, expectedContent.length());
+
+        // When
+        afw.flush();
+
+        // Then
+        assertEquals("File writer did not properly flush to temporary file",
+                expectedContent.length(), Files.size(afw.getTemporaryPath()));
+    }
+
+    @Test
+    public void commitToFile() throws Exception {
+        // Given
+        afw.write(expectedContent, 0, expectedContent.length());
+
+        // When
+        afw.commit();
+
+        // Then
+        assertEquals(expectedContent.length(), Files.size(af.toPath()));
+    }
+
+    @Test
+    public void abortDeletesTmpFile() throws Exception {
+        // Given
+        afw.write(expectedContent, 0, expectedContent.length());
+
+        // When
+        afw.abort();
+
+        // Then
+        assertTrue(Files.notExists(afw.getTemporaryPath()));
+    }
+
+    @Test
+    public void badPath() throws Exception {
+        final File newFile = tmp.newFile();
+        File parentExistsAndIsAFile = new File(newFile, "badChild");
+
+        assertTrue(newFile.exists());
+        assertFalse(parentExistsAndIsAFile.exists());
+
+        try {
+            new AtomicFileWriter(parentExistsAndIsAFile.toPath(), Charset.forName("UTF-8"));
+            fail("Expected a failure");
+        } catch (IOException e) {
+            assertThat(e.getMessage(),
+                       containsString("exists and is neither a directory nor a symlink to a directory"));
+        }
+    }
+}

test/pom.xml

@@ -198,6 +198,18 @@ THE SOFTWARE.
       <version>4.0</version>
       <scope>test</scope>
     </dependency>
+    <dependency>
+      <groupId>org.awaitility</groupId>
+      <artifactId>awaitility</artifactId>
+      <version>3.0.0</version>
+      <scope>test</scope>
+    </dependency>
+    <dependency>
+      <groupId>org.objenesis</groupId>
+      <artifactId>objenesis</artifactId>
+      <version>2.5.1</version>
+      <scope>test</scope>
+    </dependency>
   </dependencies>
 
   <build>

test/src/test/java/hudson/cli/QuietDownCommandTest.java

@@ -50,6 +50,7 @@ import java.util.concurrent.atomic.AtomicInteger;
 import static hudson.cli.CLICommandInvoker.Matcher.failedWith;
 import static hudson.cli.CLICommandInvoker.Matcher.hasNoStandardOutput;
 import static hudson.cli.CLICommandInvoker.Matcher.succeededSilently;
+import static org.awaitility.Awaitility.await;
 import static org.hamcrest.MatcherAssert.assertThat;
 import static org.hamcrest.Matchers.containsString;
 import static org.hamcrest.Matchers.equalTo;
@@ -213,7 +214,6 @@ public class QuietDownCommandTest {
         try {
             threadPool.submit(exec_task);
             beforeCli.block();
-            Thread.sleep(1000); // Left a room for calling CLI
             assertJenkinsInQuietMode();
             exec_task.get(10, TimeUnit.SECONDS);
         } catch (TimeoutException e) {
@@ -259,7 +259,6 @@ public class QuietDownCommandTest {
         try {
             threadPool.submit(exec_task);
             beforeCli.block();
-            Thread.sleep(1000); // Left a room for calling CLI
             assertJenkinsInQuietMode();
             exec_task.get(10, TimeUnit.SECONDS);
         } catch (TimeoutException e) {
@@ -307,7 +306,6 @@ public class QuietDownCommandTest {
         });
         threadPool.submit(exec_task);
         beforeCli.block();
-        Thread.sleep(1000); // Left a room for calling CLI
         assertJenkinsInQuietMode();
         try {
             exec_task.get(2*TIMEOUT, TimeUnit.MILLISECONDS);
@@ -351,7 +349,6 @@ public class QuietDownCommandTest {
         });
         threadPool.submit(exec_task);
         beforeCli.block();
-        Thread.sleep(1000); // Left a room for calling CLI
         assertJenkinsInQuietMode();
         final boolean timeout_occured = false;
         try {
@@ -400,7 +397,6 @@ public class QuietDownCommandTest {
         });
         threadPool.submit(exec_task);
         beforeCli.block();
-        Thread.sleep(1000); // Left a room for calling CLI
         assertJenkinsInQuietMode();
 
         finish.signal();
@@ -409,7 +405,9 @@ public class QuietDownCommandTest {
         assertThat(project.isBuilding(), equalTo(false));
         j.assertBuildStatusSuccess(build);
         assertJenkinsInQuietMode();
-        exec_task.get(1, TimeUnit.SECONDS);
+
+        get(exec_task);
+
         assertJenkinsInQuietMode();
     }
 
@@ -427,7 +425,6 @@ public class QuietDownCommandTest {
         final Future<FreeStyleBuild> build = OnlineNodeCommandTest.startBlockingAndFinishingBuild(project, finish);
         assertThat(((FreeStyleProject) j.jenkins.getItem("aProject")).getBuilds(), hasSize(1));
 
-        boolean timeoutOccurred = false;
         final FutureTask exec_task = new FutureTask(new Callable() {
             public Object call() {
                 assertJenkinsNotInQuietMode();
@@ -445,7 +442,6 @@ public class QuietDownCommandTest {
         });
         threadPool.submit(exec_task);
         beforeCli.block();
-        Thread.sleep(1000); // Left a room for calling CLI
         assertJenkinsInQuietMode();
 
         finish.signal();
@@ -454,22 +450,50 @@ public class QuietDownCommandTest {
         assertThat(project.isBuilding(), equalTo(false));
         j.assertBuildStatusSuccess(build);
         assertJenkinsInQuietMode();
-        exec_task.get(1, TimeUnit.SECONDS);
+        get(exec_task);
+    }
+
+    /**
+     * Will try to get the result and retry for some time before failing.
+     */
+    private static void get(FutureTask exec_task) {
+        await().atMost(10, TimeUnit.SECONDS)
+                .until(exec_task::isDone);
     }
 
+    /**
+     * Asserts if Jenkins is in quiet mode.
+     * Will retry for some time before actually failing.
+     */
     private final void assertJenkinsInQuietMode() {
         assertJenkinsInQuietMode(j);
     }
 
+    /**
+     * Asserts if Jenkins is <strong>not</strong> in quiet mode.
+     * Will retry for some time before actually failing.
+     */
     private final void assertJenkinsNotInQuietMode() {
         assertJenkinsNotInQuietMode(j);
     }
 
+    /**
+     * Asserts if Jenkins is in quiet mode, retrying for some time before failing.
+     * @throws TimeoutException
+     */
     public static final void assertJenkinsInQuietMode(final JenkinsRule j) {
-        assertThat(j.jenkins.getActiveInstance().getQueue().isBlockedByShutdown(task), equalTo(true));
+        await().pollInterval(250, TimeUnit.MILLISECONDS)
+                .atMost(10, TimeUnit.SECONDS)
+                .until(() -> j.jenkins.getActiveInstance().getQueue().isBlockedByShutdown(task));
     }
 
+    /**
+     * Asserts if Jenkins is <strong>not</strong> in quiet mode, retrying for some time before failing.
+     * @throws TimeoutException
+     */
     public static final void assertJenkinsNotInQuietMode(final JenkinsRule j) {
-        assertThat(j.jenkins.getActiveInstance().getQueue().isBlockedByShutdown(task), equalTo(false));
+        await().pollInterval(250, TimeUnit.MILLISECONDS)
+                .atMost(10, TimeUnit.SECONDS)
+                .until(() -> !j.jenkins.getActiveInstance().getQueue().isBlockedByShutdown(task));
     }
 }

test/src/test/java/hudson/util/AtomicFileWriterPerfTest.java

+package hudson.util;
+
+import org.junit.ClassRule;
+import org.junit.Test;
+import org.jvnet.hudson.test.Issue;
+import org.jvnet.hudson.test.JenkinsRule;
+
+public class AtomicFileWriterPerfTest {
+
+    @ClassRule
+    public static final JenkinsRule rule = new JenkinsRule();
+
+    /**
+     * This test is meant to catch huge regressions in terms of serialization performance.
+     * <p>
+     * <p>Some data points to explain the timeout value below:</p>
+     * <ul>
+     * <li>On a modern SSD in 2017, it takes less than a second to run.</li>
+     * <li>Using Docker resource constraints, and setting in read&write to IOPS=40 and BPS=10m (i.e. roughly worse than
+     * an old 5400 RPM hard disk), this test takes 25 seconds</li>
+     * </ul>
+     * <p>
+     * So using slightly more than the worse value obtained above should avoid making this flaky and still catch
+     * <strong>really</strong> bad performance regressions.
+     */
+    @Issue("JENKINS-34855")
+    @Test(timeout = 30 * 1000L)
+    public void poorManPerformanceTestBed() throws Exception {
+        int count = 1000;
+        while (count-- > 0) {
+            rule.jenkins.save();
+        }
+    }
+}