[JENKINS-58878] Add test that reproduces the issue

[dwnusbaum]

See JENKINS-58878.

Update: fix is in jenkinsci/workflow-cps-plugin#335, I'll update this PR once I have an incremental build.

---

Just adding an ignored test for now while I try to figure out the right way to fix the problem. Here's a bad fix:

--- a/src/main/java/org/jenkinsci/plugins/workflow/steps/GeneralNonBlockingStepExecution.java
+++ b/src/main/java/org/jenkinsci/plugins/workflow/steps/GeneralNonBlockingStepExecution.java
@@ -74,6 +74,7 @@ public abstract class GeneralNonBlockingStepExecution extends StepExecution {
             threadName = Thread.currentThread().getName();
             try {
                 try (ACLContext acl = ACL.as(auth)) {
+                    Thread.sleep(10L);
                     block.run();
                 }
             } catch (Throwable x) {

From playing with that fix, the sleep only seems to matter for starting the step. If you disable the sleep when run is called from TailCall.onSuccess, the test still passes. The test usually blocks for me pretty quickly (within 5 iterations of the loop), but I have seen it run as many as 40 iterations successfully.

One strange thing to me is that based on the log output, the completion callbacks appear to be running before the body executes. Here is the output of one of the hung tests:

   6.733 [test0 #1] Started
   7.930 [test0 #1] [Pipeline] slowBlock
   7.984 [test0 #1] starting step
   7.984 [test0 #1] starting background part of step
   7.984 [test0 #1] starting body
   7.985 [test0 #1] [Pipeline] {
   8.145 [test0 #1] body completed, starting background end part of step
   8.145 [test0 #1] ending step
   8.146 [test0 #1] [Pipeline] echo
   8.146 [test0 #1] At 0
   8.147 [test0 #1] [Pipeline] }
   8.199 [test0 #1] [Pipeline] // slowBlock
   8.254 [test0 #1] [Pipeline] slowBlock
   8.254 [test0 #1] starting step
   8.254 [test0 #1] starting background part of step
   8.254 [test0 #1] starting body
   8.255 [test0 #1] [Pipeline] {
   8.309 [test0 #1] body completed, starting background end part of step
   8.309 [test0 #1] ending step
   8.310 [test0 #1] [Pipeline] echo
   8.310 [test0 #1] At 1
   8.310 [test0 #1] [Pipeline] }
   8.311 [test0 #1] [Pipeline] // slowBlock
   8.311 [test0 #1] [Pipeline] slowBlock
   8.311 [test0 #1] starting step
   8.312 [test0 #1] starting background part of step
   8.312 [test0 #1] starting body
   8.364 [test0 #1] [Pipeline] {
   8.364 [test0 #1] body completed, starting background end part of step
   8.364 [test0 #1] ending step
   8.365 [test0 #1] [Pipeline] echo
   8.365 [test0 #1] At 2
   8.365 [test0 #1] [Pipeline] }
   8.417 [test0 #1] [Pipeline] // slowBlock
   8.418 [test0 #1] [Pipeline] slowBlock
   8.418 [test0 #1] starting step
   8.418 [test0 #1] starting background part of step
   8.418 [test0 #1] starting body
   8.419 [test0 #1] [Pipeline] {
   8.470 [test0 #1] body completed, starting background end part of step
   8.471 [test0 #1] ending step
   8.471 [test0 #1] [Pipeline] echo
   8.471 [test0 #1] At 3
   8.471 [test0 #1] [Pipeline] }
   8.472 [test0 #1] [Pipeline] // slowBlock
   8.523 [test0 #1] [Pipeline] slowBlock
   8.523 [test0 #1] starting step
   8.524 [test0 #1] starting background part of step
   8.524 [test0 #1] starting body
   8.525 [test0 #1] [Pipeline] {
   8.525 [test0 #1] body completed, starting background end part of step
   8.526 [test0 #1] ending step
   8.581 [test0 #1] [Pipeline] echo
   8.581 [test0 #1] At 4
   8.581 [test0 #1] [Pipeline] }
   8.582 [test0 #1] [Pipeline] // slowBlock
   8.582 [test0 #1] [Pipeline] slowBlock
   9.433 [test0 #1] starting step
   9.434 [test0 #1] starting background part of step
   9.435 [test0 #1] starting body

[jglick]

Means you can use the BOM if you like.