Skip to content

Commit 49c2908

Browse files
dwnusbaumdwnusbaum
authored
Merge pull request #211 from jglick/diag-JENKINS-31314
[JENKINS-31314] Integrate and test a groovy-cps diagnostic trick
2 parents d81da71 + eb8355e commit 49c2908

File tree

7 files changed

+143
-36
lines changed

7 files changed

+143
-36
lines changed

‎pom.xml‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -71,8 +71,8 @@
7171
<git-plugin.version>3.1.0</git-plugin.version>
7272
<workflow-support-plugin.version>3.3</workflow-support-plugin.version>
7373
<scm-api-plugin.version>2.2.6</scm-api-plugin.version>
74-
<groovy-cps.version>1.27</groovy-cps.version>
75-
<structs-plugin.version>1.18</structs-plugin.version>
74+
<groovy-cps.version>1.28</groovy-cps.version>
75+
<structs-plugin.version>1.18</structs-plugin.version>
7676
<workflow-step-api-plugin.version>2.20</workflow-step-api-plugin.version>
7777
</properties>
7878
<dependencies>

‎src/main/java/org/jenkinsci/plugins/workflow/cps/CpsVmExecutorService.java‎

Lines changed: 53 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,15 +1,17 @@
11
package org.jenkinsci.plugins.workflow.cps;
22

3+
import com.cloudbees.groovy.cps.impl.CpsCallableInvocation;
4+
import hudson.Main;
35
import hudson.model.Computer;
46
import hudson.remoting.SingleLaneExecutorService;
57
import hudson.security.ACL;
6-
import jenkins.util.InterceptingExecutorService;
7-
8+
import java.io.IOException;
89
import java.util.concurrent.Callable;
910
import java.util.concurrent.ExecutorService;
11+
import java.util.logging.Level;
1012
import java.util.logging.Logger;
11-
12-
import static java.util.logging.Level.WARNING;
13+
import javax.annotation.CheckForNull;
14+
import jenkins.util.InterceptingExecutorService;
1315

1416
/**
1517
* {@link ExecutorService} for running CPS VM.
@@ -50,7 +52,7 @@ public void run() {
5052
* That makes it worth reporting.
5153
*/
5254
private void reportProblem(Throwable t) {
53-
LOGGER.log(WARNING, "Unexpected exception in CPS VM thread: " + cpsThreadGroup.getExecution(), t);
55+
LOGGER.log(Level.WARNING, "Unexpected exception in CPS VM thread: " + cpsThreadGroup.getExecution(), t);
5456
cpsThreadGroup.getExecution().croak(t);
5557
}
5658

@@ -105,9 +107,54 @@ private ThreadContext setUp() {
105107
assert cpsThreadGroup.getExecution().getShell().getClassLoader() != null;
106108
t.setContextClassLoader(cpsThreadGroup.getExecution().getShell().getClassLoader());
107109
}
110+
CpsCallableInvocation.registerMismatchHandler(this::handleMismatch);
108111
return context;
109112
}
110113

114+
private void handleMismatch(Object expectedReceiver, String expectedMethodName, Object actualReceiver, String actualMethodName) {
115+
String mismatchMessage = mismatchMessage(className(expectedReceiver), expectedMethodName, className(actualReceiver), actualMethodName);
116+
if (FAIL_ON_MISMATCH) {
117+
throw new IllegalStateException(mismatchMessage);
118+
} else {
119+
try {
120+
cpsThreadGroup.getExecution().getOwner().getListener().getLogger().println(mismatchMessage);
121+
} catch (IOException x) {
122+
LOGGER.log(Level.FINE, null, x);
123+
}
124+
}
125+
}
126+
127+
private static @CheckForNull String className(@CheckForNull Object receiver) {
128+
if (receiver == null) {
129+
return null;
130+
} else if (receiver instanceof Class) {
131+
return ((Class) receiver).getName();
132+
} else {
133+
return receiver.getClass().getName();
134+
}
135+
}
136+
137+
/**
138+
* Making false positives be fatal makes it much easier to detect mistakes here and in PCT.
139+
* But we would rather have this be nonfatal in production,
140+
* since there are sure to be some false positives in exotic situations not yet covered by tests.
141+
* (As well as some false negatives, but this is a best effort after all.)
142+
*/
143+
static boolean FAIL_ON_MISMATCH = Main.isUnitTest;
144+
145+
static String mismatchMessage(@CheckForNull String expectedReceiverClassName, String expectedMethodName, @CheckForNull String actualReceiverClassName, String actualMethodName) {
146+
StringBuilder b = new StringBuilder("expected to call ");
147+
if (expectedReceiverClassName != null) {
148+
b.append(expectedReceiverClassName).append('.');
149+
}
150+
b.append(expectedMethodName).append(" but wound up catching ");
151+
if (actualReceiverClassName != null) {
152+
b.append(actualReceiverClassName).append('.');
153+
}
154+
b.append(actualMethodName);
155+
return b.append("; see: https://jenkins.io/redirect/pipeline-cps-method-mismatches/").toString();
156+
}
157+
111158
private void tearDown(ThreadContext context) {
112159
CURRENT.set(null);
113160
cpsThreadGroup.busy = false;
@@ -116,6 +163,7 @@ private void tearDown(ThreadContext context) {
116163
if (isShutdown()) {
117164
execution.logTimings();
118165
}
166+
CpsCallableInvocation.registerMismatchHandler(null);
119167
}
120168

121169
static ThreadLocal<CpsThreadGroup> CURRENT = new ThreadLocal<>();

‎src/main/java/org/jenkinsci/plugins/workflow/cps/DSL.java‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -158,6 +158,7 @@ public Object invokeMethod(String name, Object args) {
158158
}
159159
unreportedAmbiguousFunctions = new HashSet<>(0);
160160
for (StepDescriptor d : StepDescriptor.all()) {
161+
// TODO consider adding metasteps here and in reportAmbiguousStepInvocation
161162
String functionName = d.getFunctionName();
162163
if (functions.containsKey(functionName)) {
163164
unreportedAmbiguousFunctions.add(functionName);
@@ -210,7 +211,7 @@ protected Object invokeStep(StepDescriptor d, Object args) {
210211
/**
211212
* When {@link #invokeMethod(String, Object)} is calling a {@link StepDescriptor}
212213
* @param d The {@link StepDescriptor} being invoked.
213-
* @param name The name used to invoke the step. Will be either {@code d.getFunctionName()} or {@code d.clazz.getName()}.
214+
* @param name The name used to invoke the step. May be {@link StepDescriptor#getFunctionName}, a symbol as in {@link StepDescriptor#metaStepsOf}, or {@code d.clazz.getName()}.
214215
* @param args The arguments passed to the step.
215216
*/
216217
protected Object invokeStep(StepDescriptor d, String name, Object args) {
@@ -296,7 +297,7 @@ protected Object invokeStep(StepDescriptor d, String name, Object args) {
296297
} else {
297298
// if it's in progress, suspend it until we get invoked later.
298299
// when it resumes, the CPS caller behaves as if this method returned with the resume value
299-
Continuable.suspend(new ThreadTaskImpl(context));
300+
Continuable.suspend(name, new ThreadTaskImpl(context));
300301

301302
// the above method throws an exception to unwind the call stack, and
302303
// the control then goes back to CpsFlowExecution.runNextChunk
@@ -392,7 +393,7 @@ protected Object invokeDescribable(String symbol, Object _args) {
392393
ud = new UninstantiatedDescribable(symbol, null, dargs);
393394
margs.put(p.getName(),ud);
394395

395-
return invokeStep(metaStep,new NamedArgsAndClosure(margs,args.body));
396+
return invokeStep(metaStep, symbol, new NamedArgsAndClosure(margs, args.body));
396397
} catch (Exception e) {
397398
throw new IllegalArgumentException("Failed to prepare "+symbol+" step",e);
398399
}

‎src/main/java/org/jenkinsci/plugins/workflow/cps/Safepoint.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@ public class Safepoint extends ThreadTask {
2121
*/
2222
@Whitelisted
2323
public static void safepoint() {
24-
Continuable.suspend(new Safepoint());
24+
Continuable.suspend("safepoint", new Safepoint());
2525
}
2626

2727
@Override

‎src/test/java/org/jenkinsci/plugins/workflow/SerializationTest.java‎

Lines changed: 0 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,6 @@
1616
import org.jvnet.hudson.test.TestExtension;
1717
import org.kohsuke.stapler.DataBoundConstructor;
1818
import static org.junit.Assert.assertTrue;
19-
import org.junit.Ignore;
2019
import org.jvnet.hudson.test.Issue;
2120

2221
/**
@@ -224,23 +223,4 @@ public boolean start() throws Exception {
224223
});
225224
}
226225

227-
@Ignore("TODO JENKINS-31314: calls writeFile just once, echoes null (i.e., return value of writeFile), then succeeds")
228-
@Test public void nonCpsContinuable() {
229-
story.addStep(new Statement() {
230-
@Override public void evaluate() throws Throwable {
231-
p = jenkins().createProject(WorkflowJob.class, "demo");
232-
p.setDefinition(new CpsFlowDefinition(
233-
"@NonCPS def shouldBomb() {\n" +
234-
" def text = ''\n" +
235-
" ['a', 'b', 'c'].each {it -> writeFile file: it, text: it; text += it}\n" +
236-
" text\n" +
237-
"}\n" +
238-
"node {\n" +
239-
" echo shouldBomb()\n" +
240-
"}\n", true));
241-
b = story.j.assertBuildStatus(Result.FAILURE, p.scheduleBuild2(0).get());
242-
}
243-
});
244-
}
245-
246226
}

‎src/test/java/org/jenkinsci/plugins/workflow/cps/CpsVmExecutorServiceTest.java‎

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,22 +24,103 @@
2424

2525
package org.jenkinsci.plugins.workflow.cps;
2626

27+
import hudson.model.Result;
2728
import org.jenkinsci.plugins.workflow.job.WorkflowJob;
29+
import org.jenkinsci.plugins.workflow.job.WorkflowRun;
2830
import org.junit.ClassRule;
2931
import org.junit.Test;
3032
import org.junit.Rule;
33+
import org.junit.rules.ErrorCollector;
3134
import org.jvnet.hudson.test.BuildWatcher;
35+
import org.jvnet.hudson.test.Issue;
3236
import org.jvnet.hudson.test.JenkinsRule;
3337

3438
public class CpsVmExecutorServiceTest {
3539

3640
@ClassRule public static BuildWatcher buildWatcher = new BuildWatcher();
3741
@Rule public JenkinsRule r = new JenkinsRule();
42+
@Rule public ErrorCollector errors = new ErrorCollector();
3843

3944
@Test public void contextClassLoader() throws Exception {
4045
WorkflowJob p = r.jenkins.createProject(WorkflowJob.class, "p");
4146
p.setDefinition(new CpsFlowDefinition("echo(/yes I can load ${Thread.currentThread().contextClassLoader.loadClass(getClass().name)}/)", false));
4247
r.buildAndAssertSuccess(p);
4348
}
4449

50+
@Issue({"JENKINS-31314", "JENKINS-27306", "JENKINS-26313"})
51+
@Test public void wrongCatcher() throws Exception {
52+
boolean origFailOnMismatch = CpsVmExecutorService.FAIL_ON_MISMATCH;
53+
CpsVmExecutorService.FAIL_ON_MISMATCH = false;
54+
try {
55+
WorkflowJob p = r.createProject(WorkflowJob.class, "p");
56+
errors.checkSucceeds(() -> {
57+
p.setDefinition(new CpsFlowDefinition("def ok() {sleep 1}; @NonCPS def bad() {for (int i = 0; i < 10; i++) {sleep 1}; assert false : 'never gets here'}; node {ok(); bad()}", true));
58+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("WorkflowScript", "bad", null, "sleep"), r.buildAndAssertSuccess(p));
59+
return null;
60+
});
61+
errors.checkSucceeds(() -> {
62+
p.setDefinition(new CpsFlowDefinition("def l = [3, 2, 1]; println(/oops got ${l.sort {x, y -> x - y}}/)", true));
63+
WorkflowRun b = r.buildAndAssertSuccess(p);
64+
r.assertLogContains("oops got -1", b);
65+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("java.util.ArrayList", "sort", "org.jenkinsci.plugins.workflow.cps.CpsClosure2", "call"), b);
66+
return null;
67+
});
68+
errors.checkSucceeds(() -> {
69+
p.setDefinition(new CpsFlowDefinition("node {[1, 2, 3].each {x -> sleep 1; echo(/no problem got $x/)}}", true));
70+
WorkflowRun b = r.buildAndAssertSuccess(p);
71+
r.assertLogContains("no problem got 3", b);
72+
r.assertLogNotContains("expected to call", b);
73+
return null;
74+
});
75+
errors.checkSucceeds(() -> {
76+
p.setDefinition(new CpsFlowDefinition("class C {@Override String toString() {'never used'}}; def gstring = /embedding ${new C()}/; echo(/oops got $gstring/)", true));
77+
WorkflowRun b = r.assertBuildStatus(Result.FAILURE, p.scheduleBuild2(0)); // JENKINS-27306: No such constructor found: new org.codehaus.groovy.runtime.GStringImpl java.lang.String java.lang.String[]
78+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("org.codehaus.groovy.runtime.ScriptBytecodeAdapter", "asType", "C", "toString"), b);
79+
return null;
80+
});
81+
errors.checkSucceeds(() -> {
82+
p.setDefinition(new CpsFlowDefinition("echo(/see what ${-> 'this'} does/)", true));
83+
WorkflowRun b = r.buildAndAssertSuccess(p);
84+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("WorkflowScript", "echo", "org.jenkinsci.plugins.workflow.cps.CpsClosure2", "call"), b);
85+
r.assertLogNotContains("see what", b);
86+
return null;
87+
});
88+
errors.checkSucceeds(() -> {
89+
p.setDefinition(new CpsFlowDefinition("node {echo(/see what ${-> 'this'} does/)}", true));
90+
WorkflowRun b = r.buildAndAssertSuccess(p);
91+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("WorkflowScript", "echo", "org.jenkinsci.plugins.workflow.cps.CpsClosure2", "call"), b);
92+
r.assertLogNotContains("see what", b);
93+
return null;
94+
});
95+
errors.checkSucceeds(() -> {
96+
p.setDefinition(new CpsFlowDefinition(
97+
"@NonCPS def shouldBomb() {\n" +
98+
" def text = ''\n" +
99+
" ['a', 'b', 'c'].each {it -> writeFile file: it, text: it; text += it}\n" +
100+
" text\n" +
101+
"}\n" +
102+
"node {\n" +
103+
" echo shouldBomb()\n" +
104+
"}\n", true));
105+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("WorkflowScript", "shouldBomb", null, "writeFile"), r.buildAndAssertSuccess(p));
106+
return null;
107+
});
108+
errors.checkSucceeds(() -> {
109+
p.setDefinition(new CpsFlowDefinition("@NonCPS def bad() {polygon(17) {}}; bad()", true));
110+
WorkflowRun b = r.buildAndAssertSuccess(p);
111+
r.assertLogContains("wrapping in a 17-gon", b);
112+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("WorkflowScript", "bad", null, "polygon"), b);
113+
return null;
114+
});
115+
errors.checkSucceeds(() -> {
116+
p.setDefinition(new CpsFlowDefinition("class C {C(script) {script.sleep(1)}}; new C(this)", true));
117+
WorkflowRun b = r.assertBuildStatus(Result.FAILURE, p.scheduleBuild2(0));
118+
r.assertLogContains(CpsVmExecutorService.mismatchMessage("C", "<init>", null, "sleep"), b);
119+
return null;
120+
});
121+
} finally {
122+
CpsVmExecutorService.FAIL_ON_MISMATCH = origFailOnMismatch;
123+
}
124+
}
125+
45126
}

‎src/test/java/org/jenkinsci/plugins/workflow/cps/steps/RestartingLoadStepTest.java‎

Lines changed: 2 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -134,13 +134,10 @@ public void pauseInsideLoad() throws Exception {
134134
ScriptApproval.get().approveSignature("method groovy.lang.Binding getVariables");
135135
jenkins.getWorkspaceFor(p).child("b.groovy").write("def m(arg) {echo \"${this} binding=${binding.variables}\"; a(\"${arg} from b\")}; this", null);
136136
// Control case:
137-
// TODO if you enable sandbox here, build fails: NoSuchMethodError: No such DSL method 'a' found among […]
138-
// SandboxInterceptor.onMethodCall is given Script2 as the receiver and "a" as the method, when really it should be asked about onGetProperty(Script2.a) followed by onMethodCall(Script1.call).
139-
// Works fine if you use a.call(…) rather than a(…).
140-
p.setDefinition(new CpsFlowDefinition("a = 0; node {a = load 'a.groovy'}; def b; node {b = load 'b.groovy'}; echo \"${this} binding=${binding.variables}\"; b.m('value')", false));
137+
p.setDefinition(new CpsFlowDefinition("a = 0; node {a = load 'a.groovy'}; def b; node {b = load 'b.groovy'}; echo \"${this} binding=${binding.variables}\"; b.m('value')", true));
141138
story.j.assertLogContains("a ran on value from b", story.j.assertBuildStatusSuccess(p.scheduleBuild2(0)));
142139
// Test case:
143-
p.setDefinition(new CpsFlowDefinition("a = 0; node {a = load 'a.groovy'}; semaphore 'wait'; def b; node {b = load 'b.groovy'}; echo \"${this} binding=${binding.variables}\"; b.m('value')", /* TODO ditto */false));
140+
p.setDefinition(new CpsFlowDefinition("a = 0; node {a = load 'a.groovy'}; semaphore 'wait'; def b; node {b = load 'b.groovy'}; echo \"${this} binding=${binding.variables}\"; b.m('value')", true));
144141
WorkflowRun b = p.scheduleBuild2(0).getStartCondition().get();
145142
SemaphoreStep.waitForStart("wait/1", b);
146143
}

0 commit comments

Comments
 (0)