Better fix of timeout activity tick after restart

jenkinsci · Aug 29, 2022 · 85b6c33 · 85b6c33
1 parent 43d80fe
commit 85b6c33
Show file tree

Hide file tree

Showing 2 changed files with 10 additions and 11 deletions.
diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/TimeoutStepExecution.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/TimeoutStepExecution.java
@@ -142,6 +142,7 @@ private void setupTimer(final long now, boolean forceReset) {
     }
 
     private void resetTimer() {
+        LOGGER.fine(() -> "resetting timer on " + id);
         long now = System.currentTimeMillis();
         end = now + timeout;
         setupTimer(now, true);
@@ -340,9 +341,6 @@ public OutputStream decorateLogger(@SuppressWarnings("rawtypes") Run build, fina
             OutputStream decorated = new LineTransformationOutputStream() {
                 @Override
                 protected void eol(byte[] b, int len) throws IOException {
-                    if (channel == null) {
-                        new ResetTimer(id).call();
-                    }
                     logger.write(b, 0, len);
                     active.set(true);
                 }
@@ -359,9 +357,7 @@ public void close() throws IOException {
                     logger.close();
                 }
             };
-            if (channel != null) {
-                new Tick(active, new WeakReference<>(decorated), timeout, channel, id).schedule();
-            }
+            new Tick(active, new WeakReference<>(decorated), timeout, channel, id).schedule(0);
             return decorated;
         }
     }
@@ -397,16 +393,14 @@ public void run() {
                 } else {
                     resetTimer.call();
                 }
-                schedule();
+                schedule(timeout / 2); // less than the full timeout, to give some grace period, but in the same ballpark to avoid overhead
             } else {
                 // Idle at the moment, but check well before the timeout expires in case new output appears.
                 schedule(timeout / 10);
             }
         }
-        void schedule() {
-            schedule(timeout / 2); // less than the full timeout, to give some grace period, but in the same ballpark to avoid overhead
-        }
         private void schedule(long delay) {
+            LOGGER.fine(() -> "scheduling tick for " + Util.getTimeSpanString(delay));
             Timer.get().schedule(this, delay, TimeUnit.MILLISECONDS);
         }
     }

diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/TimeoutStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/TimeoutStepTest.java
@@ -33,6 +33,7 @@
 import java.util.List;
 import java.util.Set;
 import java.util.concurrent.TimeUnit;
+import java.util.logging.Level;
 import jenkins.model.CauseOfInterruption;
 import jenkins.model.InterruptedBuildAction;
 import jenkins.plugins.git.GitSampleRepoRule;
@@ -59,6 +60,7 @@
 import org.jvnet.hudson.test.BuildWatcher;
 import org.jvnet.hudson.test.Issue;
 import org.jvnet.hudson.test.JenkinsSessionRule;
+import org.jvnet.hudson.test.LoggerRule;
 import org.jvnet.hudson.test.TestExtension;
 import org.jvnet.hudson.test.recipes.LocalData;
 import org.kohsuke.stapler.DataBoundConstructor;
@@ -71,6 +73,8 @@ public class TimeoutStepTest {
 
     @Rule public GitSampleRepoRule git = new GitSampleRepoRule();
 
+    @Rule public LoggerRule logging = new LoggerRule().record(TimeoutStepExecution.class, Level.FINE);
+
     @Test public void configRoundTrip() throws Throwable {
         sessions.then(j -> {
                 TimeoutStep s1 = new TimeoutStep(3);
@@ -212,13 +216,14 @@ public void activityRestart() throws Throwable {
                         + "    echo 'NotHereYet';\n"
                         + "    sleep 10;\n"
                         + "    echo 'JustHere!';\n"
-                        + "    sleep 30;\n"
+                        + "    sleep 20;\n"
                         + "    echo 'ShouldNot!';\n"
                         + "  }\n"
                         + "}\n", true));
                 WorkflowRun b = p.scheduleBuild2(0).getStartCondition().get();
                 SemaphoreStep.waitForStart("restarted/1", b);
         });
+        Thread.sleep(10_000); // restarting should count as activity
         sessions.then(j -> {
                 WorkflowJob p = j.jenkins.getItemByFullName("restarted", WorkflowJob.class);
                 WorkflowRun b = p.getBuildByNumber(1);