Merge pull request jenkinsci#296 from dwnusbaum/interruption-robustness

[JENKINS-56446] Do not permanently close the log stream in FileLogStorage if an interrupted thread attempts to write to it

Author: jglick

src/main/java/org/jenkinsci/plugins/workflow/log/FileLogStorage.java

@@ -48,6 +48,7 @@
 import java.util.logging.Level;
 import java.util.logging.Logger;
 import org.apache.commons.io.input.NullReader;
+import org.apache.commons.io.output.CountingOutputStream;
 import org.jenkinsci.plugins.workflow.flow.FlowExecutionOwner;
 import org.jenkinsci.plugins.workflow.graph.FlowNode;
 import org.kohsuke.accmod.Restricted;
@@ -58,6 +59,9 @@
  * Simple implementation of log storage in a single file that maintains a side file with an index indicating where node transitions occur.
  * Each line in the index file is a byte offset, optionally followed by a space and then a node ID.
  */
+/* Note: Avoid FileChannel methods in this class, as they close the channel and its parent stream if the thread is
+   interrupted, which is problematic given that we do not control the threads which write to the log file.
+*/
 @Restricted(Beta.class)
 public final class FileLogStorage implements LogStorage {
 
@@ -73,6 +77,10 @@ public static synchronized LogStorage forFile(File log) {
     private final File index;
     @SuppressFBWarnings(value = "IS2_INCONSISTENT_SYNC", justification = "actually it is always accessed within the monitor")
     private FileOutputStream os;
+    @SuppressFBWarnings(value = "IS2_INCONSISTENT_SYNC", justification = "actually it is always accessed within the monitor")
+    private long osStartPosition;
+    @SuppressFBWarnings(value = "IS2_INCONSISTENT_SYNC", justification = "actually it is always accessed within the monitor")
+    private CountingOutputStream cos;
     @SuppressFBWarnings(value = "IS2_INCONSISTENT_SYNC", justification = "we only care about synchronizing writes")
     private OutputStream bos;
     private Writer indexOs;
@@ -86,7 +94,9 @@ private FileLogStorage(File log) {
     private synchronized void open() throws IOException {
         if (os == null) {
             os = new FileOutputStream(log, true);
-            bos = new GCFlushedOutputStream(new DelayBufferedOutputStream(os));
+            osStartPosition = log.length();
+            cos = new CountingOutputStream(os);
+            bos = new GCFlushedOutputStream(new DelayBufferedOutputStream(cos));
             if (index.isFile()) {
                 try (BufferedReader r = Files.newBufferedReader(index.toPath(), StandardCharsets.UTF_8)) {
                     // TODO would be faster to scan the file backwards for the penultimate \n, then convert the byte sequence from there to EOF to UTF-8 and set lastId accordingly
@@ -126,7 +136,7 @@ private void checkId(String id) throws IOException {
         assert Thread.holdsLock(this);
         if (!Objects.equals(id, lastId)) {
             bos.flush();
-            long pos = os.getChannel().position();
+            long pos = osStartPosition + cos.getByteCount();
             if (id == null) {
                 indexOs.write(pos + "\n");
             } else {

src/test/java/org/jenkinsci/plugins/workflow/log/FileLogStorageTest.java

@@ -55,4 +55,18 @@ public class FileLogStorageTest extends LogStorageTestBase {
         assertOverallLog(0, lines("stuff"), true);
     }
 
+    @Test public void interruptionDoesNotCloseStream() throws Exception {
+        LogStorage ls = createStorage();
+        TaskListener overall = ls.overallListener();
+        overall.getLogger().println("overall 1");
+        Thread.currentThread().interrupt();
+        TaskListener stepLog = ls.nodeListener(new MockNode("1"));
+        stepLog.getLogger().println("step 1");
+        assertTrue(Thread.interrupted());
+        close(stepLog);
+        overall.getLogger().println("overall 2");
+        close(overall);
+        assertOverallLog(0, lines("overall 1", "<span class=\"pipeline-node-1\">step 1", "</span>overall 2"), true);
+    }
+
 }

src/test/java/org/jenkinsci/plugins/workflow/log/LogStorageTestBase.java

@@ -350,7 +350,7 @@ protected String lines(CharSequence... lines) {
         return String.join(System.lineSeparator(), lines) + System.lineSeparator();
     }
 
-    private static class MockNode extends FlowNode {
+    protected static class MockNode extends FlowNode {
         MockNode(String id) {super(new MockFlowExecution(), id);}
         @Override protected String getTypeDisplayName() {return null;}
     }