From 741c2523805408dca7e280f79f8a73a6ca2b8ce2 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 7 Jul 2023 14:46:53 -0400 Subject: [PATCH 01/18] [JENKINS-52165] Enable `USE_WATCHING` by default --- .../plugins/workflow/steps/durable_task/DurableTaskStep.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index fea45e67..6f4bd627 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -64,6 +64,7 @@ import java.util.logging.Logger; import jenkins.model.Jenkins; import jenkins.tasks.filters.EnvVarsFilterableBuilder; +import jenkins.util.SystemProperties; import jenkins.util.Timer; import org.apache.commons.io.IOUtils; import org.apache.commons.lang.StringUtils; @@ -203,7 +204,7 @@ interface ExecutionRemotable { /** If set to false, disables {@link Execution#watching} mode. */ @SuppressFBWarnings(value = "MS_SHOULD_BE_FINAL", justification = "public & mutable only for tests") @Restricted(NoExternalUse.class) - public static boolean USE_WATCHING = Boolean.getBoolean(DurableTaskStep.class.getName() + ".USE_WATCHING"); // JENKINS-52165: turn back on by default + public static boolean USE_WATCHING = SystemProperties.getBoolean(DurableTaskStep.class.getName() + ".USE_WATCHING", true); /** How many seconds to wait before interrupting remote calls and before forcing cleanup when the step is stopped */ @SuppressFBWarnings(value = "MS_SHOULD_BE_FINAL", justification = "public & mutable for script console access") From 4159ede7f00b87e351fa7e831df3c377ee630b78 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 7 Jul 2023 15:39:28 -0400 Subject: [PATCH 02/18] c98bce4 broke diagnostic prints inside `handleExit` in `USE_WATCHING` mode since the `NewlineSafeTaskListener` was already closed by `HandlerImpl.exited` --- .../plugins/workflow/steps/durable_task/DurableTaskStep.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index 6f4bd627..9244d021 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -658,11 +658,11 @@ private void handleExit(int exitCode, OutputSupplier output) throws IOException, getContext().onSuccess(returnStatus ? exitCode : returnStdout ? new String(output.produce(), StandardCharsets.UTF_8) : null); } else { if (returnStdout) { - listener().getLogger().write(output.produce()); // diagnostic + _listener().getLogger().write(output.produce()); // diagnostic } if (originalCause != null) { // JENKINS-28822: Use the previous cause instead of throwing a new AbortException - listener().getLogger().println("script returned exit code " + exitCode); + _listener().getLogger().println("script returned exit code " + exitCode); getContext().onFailure(originalCause); } else { getContext().onFailure(new AbortException("script returned exit code " + exitCode)); From c69c1aa7d6fb99a54b98137c65d509e13b9f25cd Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 7 Jul 2023 16:44:16 -0400 Subject: [PATCH 03/18] `WATCHING_RECURRENCE_PERIOD` was too slow for `ExecutorStepTest.buildShellScriptAcrossDisconnect` & `.contextualizeFreshFilePathAfterAgentReconnection` --- .../steps/durable_task/DurableTaskStep.java | 27 +++++++++++++++++++ 1 file changed, 27 insertions(+) diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index 9244d021..0a09e0ce 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -30,17 +30,21 @@ import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; import hudson.AbortException; import hudson.EnvVars; +import hudson.Extension; import hudson.FilePath; import hudson.Functions; import hudson.Launcher; import hudson.Util; import hudson.init.Terminator; +import hudson.model.Computer; import hudson.model.Node; import hudson.model.Result; import hudson.model.Run; import hudson.model.TaskListener; import hudson.remoting.Channel; import hudson.remoting.ChannelClosedException; +import hudson.slaves.ComputerListener; +import hudson.slaves.OfflineCause; import hudson.util.DaemonThreadFactory; import hudson.util.FormValidation; import hudson.util.LogTaskListener; @@ -763,4 +767,27 @@ private static class HandlerImpl extends Handler { } + @Extension public static final class AgentReconnectionListener extends ComputerListener { + + @Override public void onOffline(Computer c, OfflineCause cause) { + check(c); + } + + @Override public void onOnline(Computer c, TaskListener listener) throws IOException, InterruptedException { + check(c); + } + + private void check(Computer c) { + String name = c.getName(); + StepExecution.applyAll(Execution.class, exec -> { + if (exec.watching && exec.node.equals(name)) { + LOGGER.fine(() -> "Online/offline event on " + name + ", checking current status of " + exec.remote + " immediately"); + threadPool().schedule(exec, 1, TimeUnit.SECONDS); + } + return null; + }); + } + + } + } From 97e3735501dca5af9c695bfa64706ce3b12a05b3 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 7 Jul 2023 18:19:33 -0400 Subject: [PATCH 04/18] It was `Execution.check` I wanted, not `.run` --- .../plugins/workflow/steps/durable_task/DurableTaskStep.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index 0a09e0ce..ff848bc6 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -781,8 +781,8 @@ private void check(Computer c) { String name = c.getName(); StepExecution.applyAll(Execution.class, exec -> { if (exec.watching && exec.node.equals(name)) { - LOGGER.fine(() -> "Online/offline event on " + name + ", checking current status of " + exec.remote + " immediately"); - threadPool().schedule(exec, 1, TimeUnit.SECONDS); + LOGGER.fine(() -> "Online/offline event on " + name + ", checking current status of " + exec.remote + " shortly"); + threadPool().schedule(exec::check, 1, TimeUnit.SECONDS); } return null; }); From a10a726aa740a9719212c5c831fe51279de7a371 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Mon, 10 Jul 2023 19:16:48 -0400 Subject: [PATCH 05/18] Added `RealJenkinsRule`-based test, and tuning `handleExit` behavior which seemed flaky --- .../steps/durable_task/DurableTaskStep.java | 20 +++- .../steps/durable_task/RealShellStepTest.java | 91 +++++++++++++++++++ 2 files changed, 107 insertions(+), 4 deletions(-) create mode 100644 src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index ff848bc6..3039997e 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -77,6 +77,7 @@ import org.jenkinsci.plugins.durabletask.Handler; import org.jenkinsci.plugins.workflow.FilePathUtils; import org.jenkinsci.plugins.workflow.actions.LabelAction; +import org.jenkinsci.plugins.workflow.flow.FlowExecutionList; import org.jenkinsci.plugins.workflow.graph.FlowNode; import org.jenkinsci.plugins.workflow.steps.AbstractStepExecutionImpl; import org.jenkinsci.plugins.workflow.steps.FlowInterruptedException; @@ -594,9 +595,12 @@ private void check() { Integer exitCode = controller.exitStatus(workspace, launcher(), listener); if (exitCode == null) { LOGGER.log(Level.FINE, "still running in {0} on {1}", new Object[] {remote, node}); + } else if (recurrencePeriod == 0) { + LOGGER.fine(() -> "late check in " + remote + " on " + node + " ignored"); } else if (awaitingAsynchExit) { recurrencePeriod = 0; - getContext().onFailure(new AbortException("script apparently exited with code " + exitCode + " but asynchronous notification was lost")); + listener.getLogger().println("script apparently exited with code " + exitCode + " but asynchronous notification was lost"); + handleExit(exitCode, () -> controller.getOutput(workspace, launcher())); } else { LOGGER.log(Level.FINE, "exited with {0} in {1} on {2}; expect asynchronous exit soon", new Object[] {exitCode, remote, node}); awaitingAsynchExit = true; @@ -632,6 +636,7 @@ private void check() { // called remotely from HandlerImpl @Override public void exited(int exitCode, byte[] output) throws Exception { + recurrencePeriod = 0; try { getContext().get(TaskListener.class); } catch (IOException | InterruptedException x) { @@ -648,7 +653,6 @@ private void check() { getContext().onFailure(new IllegalStateException("did not expect output but got some")); return; } - recurrencePeriod = 0; handleExit(exitCode, () -> output); } @@ -770,10 +774,18 @@ private static class HandlerImpl extends Handler { @Extension public static final class AgentReconnectionListener extends ComputerListener { @Override public void onOffline(Computer c, OfflineCause cause) { + if (Jenkins.get().isTerminating()) { + LOGGER.fine(() -> "Skipping check on " + c.getName() + " during shutdown"); + return; + } check(c); } @Override public void onOnline(Computer c, TaskListener listener) throws IOException, InterruptedException { + if (!FlowExecutionList.get().isResumptionComplete()) { + LOGGER.fine(() -> "Skipping check on " + c.getName() + " before builds are ready"); + return; + } check(c); } @@ -781,8 +793,8 @@ private void check(Computer c) { String name = c.getName(); StepExecution.applyAll(Execution.class, exec -> { if (exec.watching && exec.node.equals(name)) { - LOGGER.fine(() -> "Online/offline event on " + name + ", checking current status of " + exec.remote + " shortly"); - threadPool().schedule(exec::check, 1, TimeUnit.SECONDS); + LOGGER.fine(() -> "Online/offline event on " + name + ", checking current status of " + exec.remote + " soon"); + threadPool().schedule(exec::check, 15, TimeUnit.SECONDS); } return null; }); diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java new file mode 100644 index 00000000..c5aadf2c --- /dev/null +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java @@ -0,0 +1,91 @@ +/* + * The MIT License + * + * Copyright 2023 CloudBees, Inc. + * + * Permission is hereby granted, free of charge, to any person obtaining a copy + * of this software and associated documentation files (the "Software"), to deal + * in the Software without restriction, including without limitation the rights + * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell + * copies of the Software, and to permit persons to whom the Software is + * furnished to do so, subject to the following conditions: + * + * The above copyright notice and this permission notice shall be included in + * all copies or substantial portions of the Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE + * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, + * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN + * THE SOFTWARE. + */ + +package org.jenkinsci.plugins.workflow.steps.durable_task; + +import hudson.Functions; +import hudson.model.ParametersAction; +import hudson.model.ParametersDefinitionProperty; +import hudson.model.StringParameterDefinition; +import hudson.model.StringParameterValue; +import java.io.File; +import java.util.logging.Level; +import java.util.logging.Logger; +import static org.awaitility.Awaitility.await; +import org.jenkinsci.plugins.durabletask.FileMonitoringTask; +import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition; +import org.jenkinsci.plugins.workflow.job.WorkflowJob; +import org.junit.Assume; +import org.junit.Rule; +import org.junit.Test; +import org.jvnet.hudson.test.InboundAgentRule; +import org.jvnet.hudson.test.JenkinsRule; +import org.jvnet.hudson.test.PrefixedOutputStream; +import org.jvnet.hudson.test.RealJenkinsRule; +import org.jvnet.hudson.test.TailLog; + +public final class RealShellStepTest { + + private static final Logger LOGGER = Logger.getLogger(RealShellStepTest.class.getName()); + + @Rule public RealJenkinsRule rr = new RealJenkinsRule(). + withColor(PrefixedOutputStream.Color.BLUE). + withLogger(DurableTaskStep.class, Level.FINE). + withLogger(FileMonitoringTask.class, Level.FINE); + + @Rule public InboundAgentRule inboundAgents = new InboundAgentRule(); + + @Test public void shellScriptExitingAcrossRestart() throws Throwable { + Assume.assumeFalse("TODO translate to batch script", Functions.isWindows()); + rr.startJenkins(); + inboundAgents.createAgent(rr, InboundAgentRule.Options.newBuilder().color(PrefixedOutputStream.Color.MAGENTA).label("remote").build()); + try (var tailLog = new TailLog(rr, "p", 1).withColor(PrefixedOutputStream.Color.YELLOW)) { + rr.runRemotely(RealShellStepTest::shellScriptExitingAcrossRestart1); + rr.stopJenkins(); + var f = new File(rr.getHome(), "f"); + LOGGER.info(() -> "Waiting for " + f + " to be written…"); + await().until(f::isFile); + LOGGER.info("…done."); + rr.startJenkins(); + rr.runRemotely(RealShellStepTest::shellScriptExitingAcrossRestart2); + tailLog.waitForCompletion(); + } + } + private static void shellScriptExitingAcrossRestart1(JenkinsRule r) throws Throwable { + var p = r.createProject(WorkflowJob.class, "p"); + var f = new File(r.jenkins.getRootDir(), "f"); + p.addProperty(new ParametersDefinitionProperty(new StringParameterDefinition("F"))); + p.setDefinition(new CpsFlowDefinition("node('remote') {sh 'sleep 5 && touch \"$F\"'}", true)); + var b = p.scheduleBuild2(0, new ParametersAction(new StringParameterValue("F", f.getAbsolutePath()))).waitForStart(); + r.waitForMessage("+ sleep 5", b); + r.jenkins.doQuietDown(true, 0, null); + } + private static void shellScriptExitingAcrossRestart2(JenkinsRule r) throws Throwable { + var p = (WorkflowJob) r.jenkins.getItem("p"); + var b = p.getLastBuild(); + r.assertBuildStatusSuccess(r.waitForCompletion(b)); + r.assertLogContains("+ touch " + new File(r.jenkins.getRootDir(), "f"), b); + } + +} From fa91baad64fa5824adce7ebbd61b66cac24492e3 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Mon, 10 Jul 2023 19:35:04 -0400 Subject: [PATCH 06/18] Late output is sometimes lost in push mode --- .../plugins/workflow/steps/durable_task/RealShellStepTest.java | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java index c5aadf2c..700c401f 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java @@ -85,7 +85,9 @@ private static void shellScriptExitingAcrossRestart2(JenkinsRule r) throws Throw var p = (WorkflowJob) r.jenkins.getItem("p"); var b = p.getLastBuild(); r.assertBuildStatusSuccess(r.waitForCompletion(b)); + /* TODO this late output is sometimes lost: r.assertLogContains("+ touch " + new File(r.jenkins.getRootDir(), "f"), b); + */ } } From 4f2b7e20afddab92271579b866173c146553e395 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Tue, 11 Jul 2023 07:46:47 -0400 Subject: [PATCH 07/18] Pick up https://github.com/jenkinsci/durable-task-plugin/pull/185 & https://github.com/jenkinsci/workflow-api-plugin/pull/290 --- pom.xml | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/pom.xml b/pom.xml index c439c936..64e9e8e8 100644 --- a/pom.xml +++ b/pom.xml @@ -76,10 +76,21 @@ io.jenkins.tools.bom bom-2.361.x - 1654.vcb_69d035fa_20 + 2081.v85885a_d2e5c5 import pom + + + org.jenkins-ci.plugins + durable-task + 510.v324450f8dca_4 + + + org.jenkins-ci.plugins.workflow + workflow-api + 1232.v1679fa_2f0f76 + From b7498d9bf6815e26ff3c0203defb4aa93df97c8c Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Thu, 13 Jul 2023 19:00:33 -0400 Subject: [PATCH 08/18] Ensuring that log streaming ceases when the channel is closed --- pom.xml | 3 +- .../steps/durable_task/DurableTaskStep.java | 72 +++++++------------ .../steps/durable_task/RealShellStepTest.java | 27 ++++++- .../steps/durable_task/ShellStepTest.java | 21 ++++-- 4 files changed, 66 insertions(+), 57 deletions(-) diff --git a/pom.xml b/pom.xml index 64e9e8e8..6df41cb7 100644 --- a/pom.xml +++ b/pom.xml @@ -67,6 +67,7 @@ 999999-SNAPSHOT 2.361.4 + 2040.v39c760a_432f9 true jenkinsci/${project.artifactId}-plugin 2.40 @@ -89,7 +90,7 @@ org.jenkins-ci.plugins.workflow workflow-api - 1232.v1679fa_2f0f76 + 1233.vc57a_f92b_a_278 diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index 3039997e..cf84b06c 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -55,8 +55,6 @@ import java.io.InputStream; import java.io.OutputStream; import java.io.PrintStream; -import java.io.UnsupportedEncodingException; -import java.lang.reflect.Field; import java.nio.charset.Charset; import java.nio.charset.StandardCharsets; import java.util.Set; @@ -79,6 +77,7 @@ import org.jenkinsci.plugins.workflow.actions.LabelAction; import org.jenkinsci.plugins.workflow.flow.FlowExecutionList; import org.jenkinsci.plugins.workflow.graph.FlowNode; +import org.jenkinsci.plugins.workflow.log.OutputStreamTaskListener; import org.jenkinsci.plugins.workflow.steps.AbstractStepExecutionImpl; import org.jenkinsci.plugins.workflow.steps.FlowInterruptedException; import org.jenkinsci.plugins.workflow.steps.Step; @@ -443,13 +442,14 @@ private void getWorkspaceProblem(Exception x) { } /** - * Interprets {@link PrintStream#close} as a signal to end a final newline if necessary. + * Interprets {@link OutputStream#close} as a signal to end a final newline if necessary. */ - private static final class NewlineSafeTaskListener implements TaskListener { + private static final class NewlineSafeTaskListener implements OutputStreamTaskListener { private static final long serialVersionUID = 1; private final TaskListener delegate; + private transient OutputStream out; private transient PrintStream logger; NewlineSafeTaskListener(TaskListener delegate) { @@ -457,12 +457,9 @@ private static final class NewlineSafeTaskListener implements TaskListener { } // Similar to DecoratedTaskListener: - @NonNull - @Override public synchronized PrintStream getLogger() { - if (logger == null) { - LOGGER.fine("creating filtered stream"); - OutputStream base = delegate.getLogger(); - OutputStream filtered = new FilterOutputStream(base) { + @Override public synchronized OutputStream getOutputStream() { + if (out == null) { + out = new FilterOutputStream(OutputStreamTaskListener.getOutputStream(delegate)) { boolean nl = true; // empty string does not need a newline @Override public void write(int b) throws IOException { super.write(b); @@ -481,12 +478,18 @@ private static final class NewlineSafeTaskListener implements TaskListener { } flush(); // do *not* call base.close() here, unlike super.close() } + @Override public String toString() { + return "NewlineSafeTaskListener.output[" + out + "]"; + } }; - try { - logger = new PrintStream(filtered, false, "UTF-8"); - } catch (UnsupportedEncodingException x) { - throw new AssertionError(x); - } + } + return out; + } + + @NonNull + @Override public synchronized PrintStream getLogger() { + if (logger == null) { + logger = new PrintStream(getOutputStream(), false, StandardCharsets.UTF_8); } return logger; } @@ -703,21 +706,6 @@ private void setupTimer(long initialRecurrencePeriod) { private static class HandlerImpl extends Handler { - private static final Field printStreamDelegate; - static { - try { - printStreamDelegate = FilterOutputStream.class.getDeclaredField("out"); - } catch (NoSuchFieldException x) { - // Defined in Java Platform and protected, so should not happen. - throw new ExceptionInInitializerError(x); - } - try { - printStreamDelegate.setAccessible(true); - } catch (/* TODO Java 11+ InaccessibleObjectException */RuntimeException x) { - LOGGER.log(Level.WARNING, "On Java 17 error handling is degraded unless `--add-opens java.base/java.io=ALL-UNNAMED` is passed to the agent", x); - } - } - private static final long serialVersionUID = 1L; private final ExecutionRemotable execution; @@ -730,34 +718,24 @@ private static class HandlerImpl extends Handler { @Override public void output(@NonNull InputStream stream) throws Exception { PrintStream ps = listener.getLogger(); + OutputStream os = OutputStreamTaskListener.getOutputStream(listener); try { - if (ps.getClass() == PrintStream.class) { - // Try to extract the underlying stream, since swallowing exceptions is undesirable and PrintStream.checkError is useless. - OutputStream os = ps; - try { - os = (OutputStream) printStreamDelegate.get(ps); - } catch (IllegalAccessException x) { - LOGGER.log(Level.FINE, "using PrintStream rather than underlying FilterOutputStream.out", x); - } - if (os == null) { // like PrintStream.ensureOpen - throw new IOException("Stream closed"); - } - synchronized (ps) { // like PrintStream.write overloads do - IOUtils.copy(stream, os); - } - } else { - // A subclass. Who knows why, but trust any write(…) overrides it may have. - IOUtils.copy(stream, ps); + synchronized (ps) { // like PrintStream.write overloads do + IOUtils.copy(stream, os); } + LOGGER.finest(() -> "print to " + os + " succeeded"); } catch (ChannelClosedException x) { + LOGGER.log(Level.FINE, null, x); // We are giving up on this watch. Wait for some call to getWorkspace to rewatch. throw x; } catch (Exception x) { + LOGGER.log(Level.FINE, null, x); // Try to report it to the controller. try { execution.problem(x); // OK, printed to log on controller side, we may have lost some text but could continue. } catch (Exception x2) { // e.g., RemotingSystemException + LOGGER.log(Level.FINE, null, x2); // No, channel seems to be broken, give up on this watch. throw x; } diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java index 700c401f..23cac779 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java @@ -24,18 +24,23 @@ package org.jenkinsci.plugins.workflow.steps.durable_task; +import hudson.ExtensionList; import hudson.Functions; import hudson.model.ParametersAction; import hudson.model.ParametersDefinitionProperty; import hudson.model.StringParameterDefinition; import hudson.model.StringParameterValue; +import hudson.slaves.AbstractCloudSlave; +import hudson.slaves.ComputerListener; import java.io.File; import java.util.logging.Level; import java.util.logging.Logger; +import jenkins.slaves.restarter.JnlpSlaveRestarterInstaller; import static org.awaitility.Awaitility.await; import org.jenkinsci.plugins.durabletask.FileMonitoringTask; import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition; import org.jenkinsci.plugins.workflow.job.WorkflowJob; +import org.jenkinsci.plugins.workflow.log.FileLogStorage; import org.junit.Assume; import org.junit.Rule; import org.junit.Test; @@ -59,7 +64,14 @@ public final class RealShellStepTest { @Test public void shellScriptExitingAcrossRestart() throws Throwable { Assume.assumeFalse("TODO translate to batch script", Functions.isWindows()); rr.startJenkins(); - inboundAgents.createAgent(rr, InboundAgentRule.Options.newBuilder().color(PrefixedOutputStream.Color.MAGENTA).label("remote").build()); + rr.runRemotely(RealShellStepTest::disableJnlpSlaveRestarterInstaller); + inboundAgents.createAgent(rr, InboundAgentRule.Options.newBuilder(). + color(PrefixedOutputStream.Color.MAGENTA). + label("remote"). + withLogger(FileMonitoringTask.class, Level.FINER). + withLogger(DurableTaskStep.class, Level.FINEST). + withPackageLogger(FileLogStorage.class, Level.FINE). + build()); try (var tailLog = new TailLog(rr, "p", 1).withColor(PrefixedOutputStream.Color.YELLOW)) { rr.runRemotely(RealShellStepTest::shellScriptExitingAcrossRestart1); rr.stopJenkins(); @@ -72,6 +84,16 @@ public final class RealShellStepTest { tailLog.waitForCompletion(); } } + + /** + * Simulate {@link AbstractCloudSlave} as in https://github.com/jenkinsci/jenkins/pull/7693. + * Most users should be using cloud agents, + * and this lets us preserve {@link InboundAgentRule.Options.Builder#withLogger(Class, Level)}. + */ + private static void disableJnlpSlaveRestarterInstaller(JenkinsRule r) throws Throwable { + ComputerListener.all().remove(ExtensionList.lookupSingleton(JnlpSlaveRestarterInstaller.class)); + } + private static void shellScriptExitingAcrossRestart1(JenkinsRule r) throws Throwable { var p = r.createProject(WorkflowJob.class, "p"); var f = new File(r.jenkins.getRootDir(), "f"); @@ -81,13 +103,12 @@ private static void shellScriptExitingAcrossRestart1(JenkinsRule r) throws Throw r.waitForMessage("+ sleep 5", b); r.jenkins.doQuietDown(true, 0, null); } + private static void shellScriptExitingAcrossRestart2(JenkinsRule r) throws Throwable { var p = (WorkflowJob) r.jenkins.getItem("p"); var b = p.getLastBuild(); r.assertBuildStatusSuccess(r.waitForCompletion(b)); - /* TODO this late output is sometimes lost: r.assertLogContains("+ touch " + new File(r.jenkins.getRootDir(), "f"), b); - */ } } diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java index 302476af..11db294f 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java @@ -97,6 +97,7 @@ import static org.junit.Assert.assertNull; import static org.junit.Assert.assertSame; import static org.hamcrest.MatcherAssert.assertThat; +import org.jenkinsci.plugins.workflow.log.OutputStreamTaskListener; import static org.junit.Assert.assertTrue; import org.junit.Assume; import static org.junit.Assume.assumeFalse; @@ -442,12 +443,13 @@ private static class Decorator extends LauncherDecorator implements Serializable }; } } - private static class RemotableBuildListener implements BuildListener { + private static class RemotableBuildListener implements BuildListener, OutputStreamTaskListener { private static final long serialVersionUID = 1; /** actual implementation */ private final TaskListener delegate; /** records allocation & deserialization history; e.g., {@code master → agent} */ private final String id; + private transient OutputStream out; private transient PrintStream logger; RemotableBuildListener(TaskListener delegate) { this(delegate, "master"); @@ -457,10 +459,10 @@ private RemotableBuildListener(TaskListener delegate, String id) { this.id = id; } @NonNull - @Override public PrintStream getLogger() { - if (logger == null) { - final OutputStream os = delegate.getLogger(); - logger = new PrintStream(new LineTransformationOutputStream() { + @Override public OutputStream getOutputStream() { + if (out == null) { + final OutputStream os = OutputStreamTaskListener.getOutputStream(delegate); + out = new LineTransformationOutputStream() { @Override protected void eol(byte[] b, int len) throws IOException { for (int i = 0; i < len - 1; i++) { // all but NL os.write(id.equals("master") ? b[i] : Character.toUpperCase(b[i])); @@ -475,7 +477,14 @@ private RemotableBuildListener(TaskListener delegate, String id) { super.close(); os.close(); } - }, true); + }; + } + return out; + } + @NonNull + @Override public PrintStream getLogger() { + if (logger == null) { + logger = new PrintStream(getOutputStream(), true, StandardCharsets.UTF_8); } return logger; } From 64c44609b42ebdcfe27dca63c3da97ff97a27fb3 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Thu, 13 Jul 2023 19:24:58 -0400 Subject: [PATCH 09/18] Using `OutputStreamTaskListener.Default` --- pom.xml | 2 +- .../workflow/steps/durable_task/DurableTaskStep.java | 11 +---------- .../workflow/steps/durable_task/ShellStepTest.java | 11 +---------- 3 files changed, 3 insertions(+), 21 deletions(-) diff --git a/pom.xml b/pom.xml index 6df41cb7..8ab54e6f 100644 --- a/pom.xml +++ b/pom.xml @@ -90,7 +90,7 @@ org.jenkins-ci.plugins.workflow workflow-api - 1233.vc57a_f92b_a_278 + 1235.v9b_7f964a_a_d70 diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index cf84b06c..1b1a9b22 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -444,13 +444,12 @@ private void getWorkspaceProblem(Exception x) { /** * Interprets {@link OutputStream#close} as a signal to end a final newline if necessary. */ - private static final class NewlineSafeTaskListener implements OutputStreamTaskListener { + private static final class NewlineSafeTaskListener extends OutputStreamTaskListener.Default { private static final long serialVersionUID = 1; private final TaskListener delegate; private transient OutputStream out; - private transient PrintStream logger; NewlineSafeTaskListener(TaskListener delegate) { this.delegate = delegate; @@ -486,14 +485,6 @@ private static final class NewlineSafeTaskListener implements OutputStreamTaskLi return out; } - @NonNull - @Override public synchronized PrintStream getLogger() { - if (logger == null) { - logger = new PrintStream(getOutputStream(), false, StandardCharsets.UTF_8); - } - return logger; - } - } private @NonNull Launcher launcher() throws IOException, InterruptedException { diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java index 11db294f..55a6e1ab 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java @@ -42,7 +42,6 @@ import java.io.File; import java.io.IOException; import java.io.OutputStream; -import java.io.PrintStream; import java.io.Serializable; import java.io.StringWriter; import java.io.UncheckedIOException; @@ -443,14 +442,13 @@ private static class Decorator extends LauncherDecorator implements Serializable }; } } - private static class RemotableBuildListener implements BuildListener, OutputStreamTaskListener { + private static class RemotableBuildListener extends OutputStreamTaskListener.Default implements BuildListener { private static final long serialVersionUID = 1; /** actual implementation */ private final TaskListener delegate; /** records allocation & deserialization history; e.g., {@code master → agent} */ private final String id; private transient OutputStream out; - private transient PrintStream logger; RemotableBuildListener(TaskListener delegate) { this(delegate, "master"); } @@ -481,13 +479,6 @@ private RemotableBuildListener(TaskListener delegate, String id) { } return out; } - @NonNull - @Override public PrintStream getLogger() { - if (logger == null) { - logger = new PrintStream(getOutputStream(), true, StandardCharsets.UTF_8); - } - return logger; - } private Object writeReplace() { /* To see serialization happening from BourneShellScript.launchWithCookie & FileMonitoringController.watch: Thread.dumpStack(); From 3973de2615b8d8b5158c8309d93ddbaf9a93e842 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Wed, 19 Jul 2023 19:00:30 -0400 Subject: [PATCH 10/18] Bumps --- pom.xml | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/pom.xml b/pom.xml index 8ab54e6f..ddf1166a 100644 --- a/pom.xml +++ b/pom.xml @@ -67,7 +67,8 @@ 999999-SNAPSHOT 2.361.4 - 2040.v39c760a_432f9 + + 2042.v787a_641a_9b_26 true jenkinsci/${project.artifactId}-plugin 2.40 @@ -90,7 +91,7 @@ org.jenkins-ci.plugins.workflow workflow-api - 1235.v9b_7f964a_a_d70 + 1243.v14eedc2295ed From 3296a8dac5496f15724a20259f36b7125eb63b20 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Wed, 26 Jul 2023 12:29:43 -0400 Subject: [PATCH 11/18] Bump --- pom.xml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pom.xml b/pom.xml index ddf1166a..7ac6103f 100644 --- a/pom.xml +++ b/pom.xml @@ -91,7 +91,7 @@ org.jenkins-ci.plugins.workflow workflow-api - 1243.v14eedc2295ed + 1246.v59f1a_f2e70ca_ From b20d22ae299bdf99fa378337fa7d09e0605f0771 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Wed, 26 Jul 2023 13:44:33 -0400 Subject: [PATCH 12/18] Pick up https://github.com/jenkinsci/credentials-binding-plugin/pull/258 --- pom.xml | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/pom.xml b/pom.xml index 7ac6103f..d65a31dc 100644 --- a/pom.xml +++ b/pom.xml @@ -93,6 +93,11 @@ workflow-api 1246.v59f1a_f2e70ca_ + + org.jenkins-ci.plugins + credentials-binding + 621.v58c0fb_d285a_c + From a819ad2c764ae031b34cfb7b0c8d4152a651f487 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Thu, 27 Jul 2023 19:25:51 -0400 Subject: [PATCH 13/18] Noting https://github.com/jenkinsci/remoting/pull/657 --- .../workflow/support/steps/AgentErrorCondition.java | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/src/main/java/org/jenkinsci/plugins/workflow/support/steps/AgentErrorCondition.java b/src/main/java/org/jenkinsci/plugins/workflow/support/steps/AgentErrorCondition.java index 72e70d28..129e7b09 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/support/steps/AgentErrorCondition.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/support/steps/AgentErrorCondition.java @@ -61,7 +61,7 @@ public final class AgentErrorCondition extends ErrorCondition { c -> c instanceof ExecutorStepExecution.RemovedNodeCause || c instanceof ExecutorStepExecution.QueueTaskCancelled)) { return true; } - if (isClosedChannel(t)) { + if (isClosedChannelException(t)) { return true; } if (t instanceof MissingContextVariableException) { @@ -75,7 +75,8 @@ public final class AgentErrorCondition extends ErrorCondition { return false; } - private static boolean isClosedChannel(Throwable t) { + // TODO https://github.com/jenkinsci/remoting/pull/657 + private static boolean isClosedChannelException(Throwable t) { if (t instanceof ClosedChannelException) { return true; } else if (t instanceof ChannelClosedException) { @@ -85,7 +86,7 @@ private static boolean isClosedChannel(Throwable t) { } else if (t == null) { return false; } else { - return isClosedChannel(t.getCause()) || Stream.of(t.getSuppressed()).anyMatch(AgentErrorCondition::isClosedChannel); + return isClosedChannelException(t.getCause()) || Stream.of(t.getSuppressed()).anyMatch(AgentErrorCondition::isClosedChannelException); } } From b68e15f69da3e62d0d4af0113b9a46879cb599a6 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Thu, 27 Jul 2023 19:55:40 -0400 Subject: [PATCH 14/18] Picking up https://github.com/jenkinsci/durable-task-plugin/pull/186, and bumping https://github.com/jenkinsci/workflow-api-plugin/pull/294 --- pom.xml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pom.xml b/pom.xml index 69936f5a..72f0979c 100644 --- a/pom.xml +++ b/pom.xml @@ -86,12 +86,12 @@ org.jenkins-ci.plugins durable-task - 510.v324450f8dca_4 + 512.vb_fa_f04b_09178 org.jenkins-ci.plugins.workflow workflow-api - 1246.v59f1a_f2e70ca_ + 1247.v12f6b_094cea_d org.jenkins-ci.plugins From 8e06d621ce1693bf72d13e41953a15d1e30e741e Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 28 Jul 2023 15:22:08 -0400 Subject: [PATCH 15/18] Turn `USE_WATCHING` back off by default, but run all relevant tests both ways --- .../steps/durable_task/DurableTaskStep.java | 3 +- .../steps/durable_task/RealShellStepTest.java | 11 +++ .../steps/durable_task/ShellStepTest.java | 80 ++++++++++--------- .../support/steps/ExecutorStepTest.java | 38 ++++++--- 4 files changed, 78 insertions(+), 54 deletions(-) diff --git a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java index 1b1a9b22..0057eaad 100644 --- a/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java +++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java @@ -66,7 +66,6 @@ import java.util.logging.Logger; import jenkins.model.Jenkins; import jenkins.tasks.filters.EnvVarsFilterableBuilder; -import jenkins.util.SystemProperties; import jenkins.util.Timer; import org.apache.commons.io.IOUtils; import org.apache.commons.lang.StringUtils; @@ -208,7 +207,7 @@ interface ExecutionRemotable { /** If set to false, disables {@link Execution#watching} mode. */ @SuppressFBWarnings(value = "MS_SHOULD_BE_FINAL", justification = "public & mutable only for tests") @Restricted(NoExternalUse.class) - public static boolean USE_WATCHING = SystemProperties.getBoolean(DurableTaskStep.class.getName() + ".USE_WATCHING", true); + public static boolean USE_WATCHING = Boolean.getBoolean(DurableTaskStep.class.getName() + ".USE_WATCHING"); // JENKINS-52165: turn back on by default /** How many seconds to wait before interrupting remote calls and before forcing cleanup when the step is stopped */ @SuppressFBWarnings(value = "MS_SHOULD_BE_FINAL", justification = "public & mutable for script console access") diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java index 23cac779..e76d4310 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java @@ -33,6 +33,7 @@ import hudson.slaves.AbstractCloudSlave; import hudson.slaves.ComputerListener; import java.io.File; +import java.util.List; import java.util.logging.Level; import java.util.logging.Logger; import jenkins.slaves.restarter.JnlpSlaveRestarterInstaller; @@ -44,14 +45,23 @@ import org.junit.Assume; import org.junit.Rule; import org.junit.Test; +import org.junit.runner.RunWith; +import org.junit.runners.Parameterized; import org.jvnet.hudson.test.InboundAgentRule; import org.jvnet.hudson.test.JenkinsRule; import org.jvnet.hudson.test.PrefixedOutputStream; import org.jvnet.hudson.test.RealJenkinsRule; import org.jvnet.hudson.test.TailLog; +@RunWith(Parameterized.class) public final class RealShellStepTest { + @Parameterized.Parameters(name = "watching={0}") public static List data() { + return List.of(false, true); + } + + @Parameterized.Parameter public boolean useWatching; + private static final Logger LOGGER = Logger.getLogger(RealShellStepTest.class.getName()); @Rule public RealJenkinsRule rr = new RealJenkinsRule(). @@ -62,6 +72,7 @@ public final class RealShellStepTest { @Rule public InboundAgentRule inboundAgents = new InboundAgentRule(); @Test public void shellScriptExitingAcrossRestart() throws Throwable { + rr.javaOptions("-D" + DurableTaskStep.class.getName() + ".USE_WATCHING=" + useWatching); Assume.assumeFalse("TODO translate to batch script", Functions.isWindows()); rr.startJenkins(); rr.runRemotely(RealShellStepTest::disableJnlpSlaveRestarterInstaller); diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java index 55a6e1ab..b8c7ac12 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/ShellStepTest.java @@ -1,13 +1,23 @@ package org.jenkinsci.plugins.workflow.steps.durable_task; +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.*; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertSame; +import static org.junit.Assert.assertTrue; +import static org.junit.Assume.assumeFalse; +import static org.junit.Assume.assumeTrue; + import com.cloudbees.plugins.credentials.CredentialsProvider; import com.cloudbees.plugins.credentials.CredentialsScope; import com.cloudbees.plugins.credentials.domains.Domain; import com.cloudbees.plugins.credentials.impl.UsernamePasswordCredentialsImpl; import edu.umd.cs.findbugs.annotations.CheckForNull; import edu.umd.cs.findbugs.annotations.NonNull; -import hudson.FilePath; import hudson.EnvVars; +import hudson.FilePath; import hudson.Functions; import hudson.Launcher; import hudson.LauncherDecorator; @@ -18,19 +28,15 @@ import hudson.console.ConsoleNote; import hudson.console.LineTransformationOutputStream; import hudson.model.BallColor; -import hudson.model.BooleanParameterDefinition; -import hudson.model.BooleanParameterValue; import hudson.model.BuildListener; import hudson.model.Descriptor; import hudson.model.FreeStyleProject; import hudson.model.Node; -import hudson.model.ParametersAction; -import hudson.model.ParametersDefinitionProperty; import hudson.model.Result; import hudson.model.Run; -import hudson.remoting.Channel; import hudson.model.Slave; import hudson.model.TaskListener; +import hudson.remoting.Channel; import hudson.slaves.DumbSlave; import hudson.slaves.EnvironmentVariablesNodeProperty; import hudson.tasks.BatchFile; @@ -61,12 +67,8 @@ import jenkins.tasks.filters.EnvVarsFilterGlobalConfiguration; import jenkins.util.JenkinsJVM; import org.apache.commons.lang.StringUtils; - -import static org.hamcrest.Matchers.*; - import org.hamcrest.MatcherAssert; import org.jenkinsci.plugins.durabletask.FileMonitoringTask; - import org.jenkinsci.plugins.workflow.actions.ArgumentsAction; import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition; import org.jenkinsci.plugins.workflow.cps.CpsStepContext; @@ -81,6 +83,7 @@ import org.jenkinsci.plugins.workflow.log.FileLogStorage; import org.jenkinsci.plugins.workflow.log.LogStorage; import org.jenkinsci.plugins.workflow.log.LogStorageFactory; +import org.jenkinsci.plugins.workflow.log.OutputStreamTaskListener; import org.jenkinsci.plugins.workflow.steps.BodyExecutionCallback; import org.jenkinsci.plugins.workflow.steps.BodyInvoker; import org.jenkinsci.plugins.workflow.steps.Step; @@ -91,22 +94,15 @@ import org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution; import org.jenkinsci.plugins.workflow.support.visualization.table.FlowGraphTable; import org.jenkinsci.plugins.workflow.support.visualization.table.FlowGraphTable.Row; -import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertFalse; -import static org.junit.Assert.assertNull; -import static org.junit.Assert.assertSame; -import static org.hamcrest.MatcherAssert.assertThat; -import org.jenkinsci.plugins.workflow.log.OutputStreamTaskListener; -import static org.junit.Assert.assertTrue; import org.junit.Assume; -import static org.junit.Assume.assumeFalse; import org.junit.ClassRule; import org.junit.Rule; import org.junit.Test; import org.junit.rules.ErrorCollector; import org.junit.rules.TemporaryFolder; +import org.junit.runner.RunWith; +import org.junit.runners.Parameterized; import org.jvnet.hudson.test.BuildWatcher; -import org.jvnet.hudson.test.FlagRule; import org.jvnet.hudson.test.Issue; import org.jvnet.hudson.test.JenkinsRule; import org.jvnet.hudson.test.LoggerRule; @@ -115,8 +111,19 @@ import org.kohsuke.stapler.DataBoundConstructor; import org.kohsuke.stapler.DataBoundSetter; +@RunWith(Parameterized.class) public class ShellStepTest { + @Parameterized.Parameters(name = "watching={0}") public static List data() { + return List.of(false, true); + } + + @Parameterized.BeforeParam public static void useWatching(boolean x) { + DurableTaskStep.USE_WATCHING = x; + } + + @Parameterized.Parameter public boolean useWatching; + @ClassRule public static BuildWatcher buildWatcher = new BuildWatcher(); @@ -124,7 +131,6 @@ public class ShellStepTest { @Rule public TemporaryFolder tmp = new TemporaryFolder(); @Rule public ErrorCollector errors = new ErrorCollector(); @Rule public LoggerRule logging = new LoggerRule(); - @Rule public FlagRule useWatching = new FlagRule<>(() -> DurableTaskStep.USE_WATCHING, x -> DurableTaskStep.USE_WATCHING = x); /** * Failure in the shell script should mark the step as red @@ -275,7 +281,7 @@ private static class Decorator extends LauncherDecorator implements Serializable return launcher.decorateByPrefix("nice"); } } - @TestExtension("launcherDecorator") public static class DescriptorImpl extends StepDescriptor { + @TestExtension({"launcherDecorator[watching=false]", "launcherDecorator[watching=true]"}) public static class DescriptorImpl extends StepDescriptor { @Override public Set> getRequiredContext() { return Collections.emptySet(); } @@ -382,8 +388,8 @@ private static class Decorator extends LauncherDecorator implements Serializable @Issue("JENKINS-38381") @Test public void remoteLogger() throws Exception { + assumeTrue(useWatching); logging.record(DurableTaskStep.class, Level.FINE).record(FileMonitoringTask.class, Level.FINE); - DurableTaskStep.USE_WATCHING = true; assumeFalse(Functions.isWindows()); // TODO create Windows equivalent final String credentialsId = "creds"; final String username = "bob"; @@ -414,7 +420,7 @@ private static class Decorator extends LauncherDecorator implements Serializable j.assertLogNotContains(password.toUpperCase(Locale.ENGLISH), b); j.assertLogContains("CURL -U **** HTTP://SERVER/ [master → remote]", b); } - @TestExtension("remoteLogger") public static class LogFile implements LogStorageFactory { + @TestExtension("remoteLogger[watching=true]") public static class LogFile implements LogStorageFactory { @Override public LogStorage forBuild(FlowExecutionOwner b) { final LogStorage base; try { @@ -490,7 +496,7 @@ private Object writeReplace() { @Issue("JENKINS-54133") @Test public void remoteConsoleNotes() throws Exception { - DurableTaskStep.USE_WATCHING = true; + assumeTrue(useWatching); assumeFalse(Functions.isWindows()); // TODO create Windows equivalent j.createSlave("remote", null, null); WorkflowJob p = j.jenkins.createProject(WorkflowJob.class, "p"); @@ -628,29 +634,25 @@ private static final class HelloNote extends ConsoleNote> { logging.record(DurableTaskStep.class, Level.FINE).record(FileMonitoringTask.class, Level.FINE); j.showAgentLogs(s, logging); WorkflowJob p = j.jenkins.createProject(WorkflowJob.class, "p"); - p.addProperty(new ParametersDefinitionProperty(new BooleanParameterDefinition("WATCHING", false, null))); String builtInNodeLabel = j.jenkins.getSelfLabel().getName(); // compatibility with 2.307+ p.setDefinition(new CpsFlowDefinition( "['" + builtInNodeLabel + "', 'remote'].each {label ->\n" + " node(label) {\n" + " withCredentials([usernameColonPassword(variable: 'USERPASS', credentialsId: '" + credentialsId + "')]) {\n" + - " sh 'set +x; echo \"with final newline node=$NODE_NAME watching=$WATCHING\"'\n" + - " sh 'set +x; printf \"missing final newline node=$NODE_NAME watching=$WATCHING\"'\n" + + " sh 'set +x; echo \"node=$NODE_NAME with final newline\"'\n" + + " sh 'set +x; printf \"node=$NODE_NAME missing final newline\"'\n" + " }\n" + " }\n" + "}", true)); - for (boolean watching : new boolean[] {false, true}) { - DurableTaskStep.USE_WATCHING = watching; - String log = JenkinsRule.getLog(j.assertBuildStatusSuccess(p.scheduleBuild2(0, new ParametersAction(new BooleanParameterValue("WATCHING", watching))))); - for (String node : new String[] {builtInNodeLabel, "remote"}) { - for (String mode : new String[] {"with", "missing"}) { - errors.checkThat(log, containsString(mode + " final newline node=" + node + " watching=" + watching)); - } - } - errors.checkThat("no blank lines with watching=" + watching, log, not(containsString("\n\n"))); - errors.checkThat(log, not(containsString("watching=false[Pipeline]"))); - errors.checkThat(log, not(containsString("watching=true[Pipeline]"))); + String log = JenkinsRule.getLog(j.buildAndAssertSuccess(p)); + for (String node : new String[] {builtInNodeLabel, "remote"}) { + for (String mode : new String[] {"with", "missing"}) { + errors.checkThat(log, containsString("node=" + node + " " + mode + " final newline")); } + } + errors.checkThat("no blank lines", log, not(containsString("\n\n"))); + // TODO more robust to assert against /missing final newline./ in line mode + errors.checkThat(log, not(containsString("missing final newline[Pipeline]"))); } @Issue("JENKINS-34021") @@ -769,7 +771,7 @@ private void ensureForWhile(int timeout, T o, Predicate predicate) throws } } - @TestExtension(value = "shouldInvokeLauncherDecoratorForShellStep") + @TestExtension({"shouldInvokeLauncherDecoratorForShellStep[watching=false]", "shouldInvokeLauncherDecoratorForShellStep[watching=true]"}) public static final class MyNodeLauncherDecorator extends LauncherDecorator { @NonNull diff --git a/src/test/java/org/jenkinsci/plugins/workflow/support/steps/ExecutorStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/support/steps/ExecutorStepTest.java index a9a0f0bb..c8f54b48 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/support/steps/ExecutorStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/support/steps/ExecutorStepTest.java @@ -24,7 +24,16 @@ package org.jenkinsci.plugins.workflow.support.steps; -import org.htmlunit.Page; +import static org.awaitility.Awaitility.await; +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.*; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNotEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertTrue; +import static org.junit.Assert.fail; + import com.google.common.base.Predicate; import edu.umd.cs.findbugs.annotations.Nullable; import hudson.FilePath; @@ -70,8 +79,6 @@ import java.util.regex.Matcher; import java.util.regex.Pattern; import java.util.stream.Collectors; - -import hudson.util.VersionNumber; import jenkins.model.Jenkins; import jenkins.security.QueueItemAuthenticator; import jenkins.security.QueueItemAuthenticatorConfiguration; @@ -80,8 +87,7 @@ import net.sf.json.groovy.JsonSlurper; import org.acegisecurity.Authentication; import org.apache.commons.io.IOUtils; -import static org.awaitility.Awaitility.await; -import static org.hamcrest.Matchers.*; +import org.htmlunit.Page; import org.jenkinsci.plugins.durabletask.FileMonitoringTask; import org.jenkinsci.plugins.workflow.actions.LogAction; import org.jenkinsci.plugins.workflow.actions.QueueItemAction; @@ -100,31 +106,37 @@ import org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep; import org.jenkinsci.plugins.workflow.steps.durable_task.Messages; import org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep; -import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertFalse; -import static org.junit.Assert.assertNotEquals; -import static org.junit.Assert.assertNotNull; -import static org.hamcrest.MatcherAssert.assertThat; -import static org.junit.Assert.assertTrue; -import static org.junit.Assert.fail; import org.junit.Assume; import org.junit.ClassRule; import org.junit.Rule; import org.junit.Test; import org.junit.rules.TemporaryFolder; +import org.junit.runner.RunWith; +import org.junit.runners.Parameterized; import org.jvnet.hudson.test.BuildWatcher; import org.jvnet.hudson.test.InboundAgentRule; import org.jvnet.hudson.test.Issue; import org.jvnet.hudson.test.JenkinsRule; +import org.jvnet.hudson.test.JenkinsSessionRule; import org.jvnet.hudson.test.LoggerRule; import org.jvnet.hudson.test.MockAuthorizationStrategy; import org.jvnet.hudson.test.MockFolder; -import org.jvnet.hudson.test.JenkinsSessionRule; import org.jvnet.hudson.test.TestExtension; /** Tests pertaining to {@code node} and {@code sh} steps. */ +@RunWith(Parameterized.class) public class ExecutorStepTest { + @Parameterized.Parameters(name = "watching={0}") public static List data() { + return List.of(false, true); + } + + @Parameterized.BeforeParam public static void useWatching(boolean x) { + DurableTaskStep.USE_WATCHING = x; + } + + @Parameterized.Parameter public boolean useWatching; + private static final Logger LOGGER = Logger.getLogger(ExecutorStepTest.class.getName()); @ClassRule public static BuildWatcher buildWatcher = new BuildWatcher(); From ed44750475b64b09dcb130b18d7fb6a032536863 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 28 Jul 2023 15:22:29 -0400 Subject: [PATCH 16/18] Try `forkCount` --- Jenkinsfile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Jenkinsfile b/Jenkinsfile index 9ceab421..ed1f8d49 100644 --- a/Jenkinsfile +++ b/Jenkinsfile @@ -1,4 +1,4 @@ -buildPlugin(useContainerAgent: true, configurations: [ +buildPlugin(useContainerAgent: true, forkCount: '1C', configurations: [ [platform: 'linux', jdk: 17], [platform: 'windows', jdk: 11], ]) From 1f55bd46852f56767bd2d664fa055deaa98c88cf Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 28 Jul 2023 16:44:21 -0400 Subject: [PATCH 17/18] Running the new `RealJenkinsRule` test also on Windows --- ...StepTest.java => DurableTaskStepTest.java} | 28 ++++++++++--------- 1 file changed, 15 insertions(+), 13 deletions(-) rename src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/{RealShellStepTest.java => DurableTaskStepTest.java} (76%) diff --git a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStepTest.java similarity index 76% rename from src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java rename to src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStepTest.java index e76d4310..5358e820 100644 --- a/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/RealShellStepTest.java +++ b/src/test/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStepTest.java @@ -33,6 +33,7 @@ import hudson.slaves.AbstractCloudSlave; import hudson.slaves.ComputerListener; import java.io.File; +import java.time.Duration; import java.util.List; import java.util.logging.Level; import java.util.logging.Logger; @@ -42,7 +43,6 @@ import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition; import org.jenkinsci.plugins.workflow.job.WorkflowJob; import org.jenkinsci.plugins.workflow.log.FileLogStorage; -import org.junit.Assume; import org.junit.Rule; import org.junit.Test; import org.junit.runner.RunWith; @@ -54,7 +54,7 @@ import org.jvnet.hudson.test.TailLog; @RunWith(Parameterized.class) -public final class RealShellStepTest { +public final class DurableTaskStepTest { @Parameterized.Parameters(name = "watching={0}") public static List data() { return List.of(false, true); @@ -62,20 +62,20 @@ public final class RealShellStepTest { @Parameterized.Parameter public boolean useWatching; - private static final Logger LOGGER = Logger.getLogger(RealShellStepTest.class.getName()); + private static final Logger LOGGER = Logger.getLogger(DurableTaskStepTest.class.getName()); @Rule public RealJenkinsRule rr = new RealJenkinsRule(). + javaOptions("-Dorg.jenkinsci.plugins.workflow.support.pickles.ExecutorPickle.timeoutForNodeMillis=" + Duration.ofMinutes(5).toMillis()). // reconnection could be >15s esp. on Windows withColor(PrefixedOutputStream.Color.BLUE). withLogger(DurableTaskStep.class, Level.FINE). withLogger(FileMonitoringTask.class, Level.FINE); @Rule public InboundAgentRule inboundAgents = new InboundAgentRule(); - @Test public void shellScriptExitingAcrossRestart() throws Throwable { + @Test public void scriptExitingAcrossRestart() throws Throwable { rr.javaOptions("-D" + DurableTaskStep.class.getName() + ".USE_WATCHING=" + useWatching); - Assume.assumeFalse("TODO translate to batch script", Functions.isWindows()); rr.startJenkins(); - rr.runRemotely(RealShellStepTest::disableJnlpSlaveRestarterInstaller); + rr.runRemotely(DurableTaskStepTest::disableJnlpSlaveRestarterInstaller); inboundAgents.createAgent(rr, InboundAgentRule.Options.newBuilder(). color(PrefixedOutputStream.Color.MAGENTA). label("remote"). @@ -84,14 +84,14 @@ public final class RealShellStepTest { withPackageLogger(FileLogStorage.class, Level.FINE). build()); try (var tailLog = new TailLog(rr, "p", 1).withColor(PrefixedOutputStream.Color.YELLOW)) { - rr.runRemotely(RealShellStepTest::shellScriptExitingAcrossRestart1); + rr.runRemotely(DurableTaskStepTest::scriptExitingAcrossRestart1); rr.stopJenkins(); var f = new File(rr.getHome(), "f"); LOGGER.info(() -> "Waiting for " + f + " to be written…"); await().until(f::isFile); LOGGER.info("…done."); rr.startJenkins(); - rr.runRemotely(RealShellStepTest::shellScriptExitingAcrossRestart2); + rr.runRemotely(DurableTaskStepTest::scriptExitingAcrossRestart2); tailLog.waitForCompletion(); } } @@ -105,21 +105,23 @@ private static void disableJnlpSlaveRestarterInstaller(JenkinsRule r) throws Thr ComputerListener.all().remove(ExtensionList.lookupSingleton(JnlpSlaveRestarterInstaller.class)); } - private static void shellScriptExitingAcrossRestart1(JenkinsRule r) throws Throwable { + private static void scriptExitingAcrossRestart1(JenkinsRule r) throws Throwable { var p = r.createProject(WorkflowJob.class, "p"); var f = new File(r.jenkins.getRootDir(), "f"); p.addProperty(new ParametersDefinitionProperty(new StringParameterDefinition("F"))); - p.setDefinition(new CpsFlowDefinition("node('remote') {sh 'sleep 5 && touch \"$F\"'}", true)); + p.setDefinition(new CpsFlowDefinition("node('remote') {if (isUnix()) {sh 'sleep 5 && touch \"$F\"'} else {bat 'ping -n 5 localhost && copy nul \"%F%\" && dir \"%F%\"'}}", true)); var b = p.scheduleBuild2(0, new ParametersAction(new StringParameterValue("F", f.getAbsolutePath()))).waitForStart(); - r.waitForMessage("+ sleep 5", b); + r.waitForMessage(Functions.isWindows() ? ">ping -n 5 localhost" : "+ sleep 5", b); r.jenkins.doQuietDown(true, 0, null); } - private static void shellScriptExitingAcrossRestart2(JenkinsRule r) throws Throwable { + private static void scriptExitingAcrossRestart2(JenkinsRule r) throws Throwable { var p = (WorkflowJob) r.jenkins.getItem("p"); var b = p.getLastBuild(); r.assertBuildStatusSuccess(r.waitForCompletion(b)); - r.assertLogContains("+ touch " + new File(r.jenkins.getRootDir(), "f"), b); + // In the case of Bourne shell, `+ touch …` is printed when the command actually runs. + // In the case of batch shell, the whole command is printed immediately, so we need to assert that the _output_ of `dir` is there. + r.assertLogContains(Functions.isWindows() ? "Directory of " + r.jenkins.getRootDir() : "+ touch " + new File(r.jenkins.getRootDir(), "f"), b); } } From efdb3c0721c1ea5aefd82e614ac74095b8f8294b Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Fri, 28 Jul 2023 18:00:09 -0400 Subject: [PATCH 18/18] https://github.com/jenkinsci/durable-task-plugin/pull/186 & https://github.com/jenkinsci/workflow-api-plugin/pull/294 released --- pom.xml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pom.xml b/pom.xml index 72f0979c..faea9298 100644 --- a/pom.xml +++ b/pom.xml @@ -86,12 +86,12 @@ org.jenkins-ci.plugins durable-task - 512.vb_fa_f04b_09178 + 513.vc48a_a_075a_d93 org.jenkins-ci.plugins.workflow workflow-api - 1247.v12f6b_094cea_d + 1248.v4b_91043341d2 org.jenkins-ci.plugins