From 93334e5189d5d9d0dd8f78442740b63c2859ea53 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Tue, 23 Jul 2019 14:25:05 -0400 Subject: [PATCH 1/6] How to get ShellStepTest.missingNewline to pass. --- pom.xml | 2 +- .../steps/durable_task/DurableTaskStep.java | 2 + .../steps/durable_task/ShellStepTest.java | 46 ++++++++++--------- 3 files changed, 27 insertions(+), 23 deletions(-) diff --git a/pom.xml b/pom.xml index 8fca2ceb..ff1fec5c 100644 --- a/pom.xml +++ b/pom.xml @@ -132,7 +132,7 @@ org.jenkins-ci.plugins credentials-binding - 1.16 + 1.17 test 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 fb3a3c2a..8eb97d5d 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 @@ -584,6 +584,7 @@ private interface OutputSupplier { byte[] produce() throws IOException, InterruptedException; } private void handleExit(int exitCode, OutputSupplier output) throws IOException, InterruptedException { + listener().getLogger().println(); // TODO Throwable originalCause = causeOfStoppage; if ((returnStatus && originalCause == null) || exitCode == 0) { getContext().onSuccess(returnStatus ? exitCode : returnStdout ? new String(output.produce(), StandardCharsets.UTF_8) : null); @@ -658,6 +659,7 @@ private static class HandlerImpl extends Handler { synchronized (ps) { // like PrintStream.write overloads do IOUtils.copy(stream, os); } + ps.println(); // TODO } else { // A subclass. Who knows why, but trust any write(…) overrides it may have. IOUtils.copy(stream, ps); 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 1a8c25cf..f4ac7462 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 @@ -17,9 +17,13 @@ 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.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; @@ -44,7 +48,6 @@ import java.util.Locale; import java.util.Map; import java.util.Set; -import java.util.concurrent.Callable; import java.util.logging.Level; import java.util.logging.LogRecord; import javax.annotation.CheckForNull; @@ -85,7 +88,6 @@ import org.junit.Assume; import static org.junit.Assume.assumeFalse; import org.junit.ClassRule; -import org.junit.Ignore; import org.junit.Rule; import org.junit.Test; import org.junit.rules.ErrorCollector; @@ -601,7 +603,6 @@ private static final class HelloNote extends ConsoleNote { j.assertLogContains("¡Čau → there!", j.buildAndAssertSuccess(p)); } - @Ignore("TODO missing final line and in some cases even the `+ set +x` (but passes without withCredentials)") @Test public void missingNewline() throws Exception { assumeFalse(Functions.isWindows()); // TODO create Windows equivalent String credentialsId = "creds"; @@ -609,31 +610,32 @@ private static final class HelloNote extends ConsoleNote { String password = "s3cr3t"; UsernamePasswordCredentialsImpl c = new UsernamePasswordCredentialsImpl(CredentialsScope.GLOBAL, credentialsId, "sample", username, password); CredentialsProvider.lookupStores(j.jenkins).iterator().next().addCredentials(Domain.global(), c); - j.createSlave("remote", null, null); + DumbSlave s = j.createSlave("remote", null, null); + j.waitOnline(s); + 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))); p.setDefinition(new CpsFlowDefinition( - "node('master') {\n" + - " withCredentials([usernameColonPassword(variable: 'USERPASS', credentialsId: '" + credentialsId + "')]) {\n" + - " sh 'set +x; printf \"some local output\"'\n" + - " }\n" + - "}\n" + - "node('remote') {\n" + - " withCredentials([usernameColonPassword(variable: 'USERPASS', credentialsId: '" + credentialsId + "')]) {\n" + - " sh 'set +x; printf \"some remote output\"'\n" + + "['master', '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" + + " }\n" + " }\n" + "}", true)); - Callable test = () -> { - WorkflowRun b = j.assertBuildStatusSuccess(p.scheduleBuild2(0)); - j.assertLogContains("some local output", b); - j.assertLogContains("some remote output", b); - return null; - }; boolean origUseWatching = DurableTaskStep.USE_WATCHING; try { - DurableTaskStep.USE_WATCHING = false; - errors.checkSucceeds(test); - DurableTaskStep.USE_WATCHING = true; - errors.checkSucceeds(test); + 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[] {"master", "remote"}) { + for (String mode : new String[] {"with", "missing"}) { + errors.checkThat(log, containsString(mode + " final newline node=" + node + " watching=" + watching)); + } + } + } } finally { DurableTaskStep.USE_WATCHING = origUseWatching; } From 5a9db486bac8fac9af439f117bc7f501fce428d7 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Tue, 23 Jul 2019 14:32:23 -0400 Subject: [PATCH 2/6] Integrate better logging. --- pom.xml | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/pom.xml b/pom.xml index ff1fec5c..3f8b5a1e 100644 --- a/pom.xml +++ b/pom.xml @@ -65,6 +65,7 @@ 2.33 -SNAPSHOT 2.176.1 + 2.54-rc1207.a9cdd7c1192a 8 true 2.20 @@ -79,7 +80,7 @@ org.jenkins-ci.plugins durable-task - 1.29 + 1.31-rc427.7bfff1482201 org.jenkins-ci.plugins.workflow From c98bce4c790757658672c109c10f58c592319bd4 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Tue, 23 Jul 2019 14:50:19 -0400 Subject: [PATCH 3/6] PrintStream.close also works. It is a bit scary, however, and produces poorly formatted log text like: missing final newline node=remote watching=true[Pipeline] } which would confuse, for example, pipeline-cloudwatch-logs. --- .../plugins/workflow/steps/durable_task/DurableTaskStep.java | 5 ++--- 1 file changed, 2 insertions(+), 3 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 8eb97d5d..b108c86e 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 @@ -584,7 +584,6 @@ private interface OutputSupplier { byte[] produce() throws IOException, InterruptedException; } private void handleExit(int exitCode, OutputSupplier output) throws IOException, InterruptedException { - listener().getLogger().println(); // TODO Throwable originalCause = causeOfStoppage; if ((returnStatus && originalCause == null) || exitCode == 0) { getContext().onSuccess(returnStatus ? exitCode : returnStdout ? new String(output.produce(), StandardCharsets.UTF_8) : null); @@ -600,6 +599,7 @@ private void handleExit(int exitCode, OutputSupplier output) throws IOException, getContext().onFailure(new AbortException("script returned exit code " + exitCode)); } } + listener().getLogger().close(); } // ditto @@ -659,7 +659,6 @@ private static class HandlerImpl extends Handler { synchronized (ps) { // like PrintStream.write overloads do IOUtils.copy(stream, os); } - ps.println(); // TODO } else { // A subclass. Who knows why, but trust any write(…) overrides it may have. IOUtils.copy(stream, ps); @@ -680,7 +679,7 @@ private static class HandlerImpl extends Handler { } @Override public void exited(int code, byte[] output) throws Exception { - listener.getLogger().flush(); + listener.getLogger().close(); execution.exited(code, output); } From d8b279b4bafbdff7932107b87d2295c5336a7310 Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Tue, 23 Jul 2019 16:03:53 -0400 Subject: [PATCH 4/6] https://github.com/jenkinsci/jenkins-test-harness/pull/149 was released, and we can do without https://github.com/jenkinsci/durable-task-plugin/pull/102. --- pom.xml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pom.xml b/pom.xml index 3f8b5a1e..7d172fa0 100644 --- a/pom.xml +++ b/pom.xml @@ -65,7 +65,7 @@ 2.33 -SNAPSHOT 2.176.1 - 2.54-rc1207.a9cdd7c1192a + 2.54 8 true 2.20 @@ -80,7 +80,7 @@ org.jenkins-ci.plugins durable-task - 1.31-rc427.7bfff1482201 + 1.29 org.jenkins-ci.plugins.workflow From 10ff08c00abf847f7639bd2e6771f2a3efe4d6cf Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Tue, 23 Jul 2019 16:04:09 -0400 Subject: [PATCH 5/6] Proper fix using NewlineSafeTaskListener. --- .../steps/durable_task/DurableTaskStep.java | 57 ++++++++++++++++++- .../steps/durable_task/ShellStepTest.java | 3 + 2 files changed, 58 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 b108c86e..e6dc3d9b 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 @@ -48,6 +48,7 @@ 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; @@ -254,6 +255,7 @@ static final class Execution extends AbstractStepExecutionImpl implements Runnab private static final long MAX_RECURRENCE_PERIOD = 15000; // 15s private static final float RECURRENCE_PERIOD_BACKOFF = 1.2f; + private transient TaskListener newlineSafeTaskListener; /** Used only during {@link #start}. */ private transient final DurableTaskStep step; /** Current “live” connection to the workspace, or null if we might be offline at the moment. */ @@ -303,7 +305,7 @@ static final class Execution extends AbstractStepExecutionImpl implements Runnab if (returnStdout) { durableTask.captureOutput(); } - TaskListener listener = context.get(TaskListener.class); + TaskListener listener = listener(); if (step.encoding != null) { durableTask.charset(Charset.forName(step.encoding)); } else { @@ -398,7 +400,14 @@ private void getWorkspaceProblem(Exception x) { } } - private @Nonnull TaskListener listener() { + private synchronized @Nonnull TaskListener listener() { + if (newlineSafeTaskListener == null) { + newlineSafeTaskListener = new NewlineSafeTaskListener(_listener()); + } + return newlineSafeTaskListener; + } + + private @Nonnull TaskListener _listener() { TaskListener l; StepContext context = getContext(); try { @@ -417,6 +426,50 @@ private void getWorkspaceProblem(Exception x) { return l; } + /** + * Interprets {@link PrintStream#close} as a signal to end a final newline if necessary. + */ + private static final class NewlineSafeTaskListener implements TaskListener { + + private static final long serialVersionUID = 1; + + private final TaskListener delegate; + private transient PrintStream logger; + + NewlineSafeTaskListener(TaskListener delegate) { + this.delegate = delegate; + } + + // Similar to DecoratedTaskListener: + @Override public synchronized PrintStream getLogger() { + if (logger == null) { + LOGGER.fine("creating filtered stream"); + OutputStream base = delegate.getLogger(); + OutputStream filtered = new FilterOutputStream(base) { + boolean nl = true; // empty string does not need a newline + @Override public void write(int b) throws IOException { + super.write(b); + nl = b == '\n'; + } + @Override public void close() throws IOException { + LOGGER.log(Level.FINE, "calling close with nl={0}", nl); + if (!nl) { + super.write('\n'); + } + flush(); // do *not* call base.close() here, unlike super.close() + } + }; + try { + logger = new PrintStream(filtered, false, "UTF-8"); + } catch (UnsupportedEncodingException x) { + throw new AssertionError(x); + } + } + return logger; + } + + } + private @Nonnull Launcher launcher() throws IOException, InterruptedException { StepContext context = getContext(); Launcher l = context.get(Launcher.class); 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 f4ac7462..7ed647de 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 @@ -635,6 +635,9 @@ private static final class HelloNote extends ConsoleNote { 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]"))); } } finally { DurableTaskStep.USE_WATCHING = origUseWatching; From 6677baa4c21f14dfc9995493c16ade992f06166f Mon Sep 17 00:00:00 2001 From: Jesse Glick Date: Thu, 25 Jul 2019 13:37:18 -0400 Subject: [PATCH 6/6] More efficient to also override write(byte[], int, int). --- .../workflow/steps/durable_task/DurableTaskStep.java | 6 ++++++ 1 file changed, 6 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 e6dc3d9b..061b1bac 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 @@ -451,6 +451,12 @@ private static final class NewlineSafeTaskListener implements TaskListener { super.write(b); nl = b == '\n'; } + @Override public void write(byte[] b, int off, int len) throws IOException { + super.write(b, off, len); + if (len > 0) { + nl = b[off + len - 1] == '\n'; + } + } @Override public void close() throws IOException { LOGGER.log(Level.FINE, "calling close with nl={0}", nl); if (!nl) {