Confused about unexpected path through Jenkinsfile

[David Karr]

Using Jenkins 2.19.2 on Linux.

I'm perplexed by the behavior of my Jenkinsfile, or at least what it's reporting to me.  I had it basically working, but then I added some simple additional lines to gather some additional information, and now it somehow just stops executing the script at some point, without any explanation or stack trace.

The following is the method called from a catch block in a stage where I first start to see a problem:

@NonCPS
def notifyFailure(String stageName) {
    println "result[${currentBuild.rawBuild.getPreviousBuild()?.getResult()}]"
    println "SUCCESS[${hudson.model.Result.SUCCESS}]"
    println "was.SUCCESS[${hudson.model.Result.SUCCESS == currentBuild.rawBuild.getPreviousBuild()?.getResult()}]"
    try {
        println "About to call bFNMT."
        String    body    = buildFailureNotificationMessageText(stageName)
        println "Returned from bFNMT."
        println "body[${body}]"
    }
    catch (err) {
        err.printStackTrace()
    }
    try {
        String emailAddressesStr = getLastCommitsEmails()
        println "emailAddressesStr[${emailAddressesStr}]"
    }
    catch (err) {
        err.printStackTrace
    }
    def emailAddressesList = emailAddressesStr.split(",")
    println "emailAddressesList[${emailAddressesList}]"
    emailAddressesList.each { address -> println "address[${address}]" }
    def uidsList = emailAddressesList.collect { address -> address.split("@")[0] }
    println "uidsList[${uidsList}]"
    sendQMessageToUsers(["dk068x"], body)
    emailext body:body.replaceAll('\\n', '<br>'),
             mimeType:'text/html',
             subject: 'BUILD FAILURE - ' + env.JOB_NAME,
             to: 'dk0...@att.com'
}

The following is the tail of the console output, starting at the first println in this method:

result[FAILURE]
[Pipeline] echo
SUCCESS[SUCCESS]
[Pipeline] echo
was.SUCCESS[false]
[Pipeline] echo
About to call bFNMT.
[Pipeline] echo
In bFNMT.
[Pipeline] echo
job[unified-service-layer-build-pipeline] stageName[DEPLOY] bu[http:...]
[Pipeline] echo
In gLCT.
[Pipeline] sh
[workspace] Running shell script
+ git log -5 --date=short '--pretty=format:%cN: %cd : %s'
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // node
[Pipeline] End of Pipeline
[DOSSIER] Response Code: 0
[DOSSIER] Backup file created: /home/jenkins/...
[DOSSIER] Seconds to input data: 0
ERROR: script returned exit code 1
Finished: FAILURE

Here are the two other relevant methods that are called in this sequence:

@NonCPS
def buildFailureNotificationMessageText(String stageName) {
    println "In bFNMT."
    println "job[${env.JOB_NAME}] stageName[${stageName}] bu[${env.BUILD_URL}]"
    def result = "${env.JOB_NAME} <b><font color=\"red\">FAILED</font></b> (stage ${stageName}).\n" +
                 "\n" +
                 "Last commits:\n" +
                 getLastCommitsText() + "\n" +
                 "\n" +
                 env.BUILD_URL
           
    println "At end of bFNMT."
    return result
}

@NonCPS
def getLastCommitsText() {
    println "In gLCT."
    def result    = sh(returnStdout:true, script:'git log -5 --date=short --pretty=format:"%cN: %cd : %s"')
    println "At end of gLCT."
    return result
}

If you look at the console output, you'll see it printed "In gLCT" and then it shows the "git log" command line. Then, it just seems to skip the rest of the flow and jump to the end of the stage and node.

Also note that this is the "DEPLOY" stage. There was a "BUILD" stage before this, that executed similar methods.  It also executed a method that executed a "git log" command line, and in the console output I saw the first "In ..." message, then the "Running shell script" message followed by the "+ git log ..." line, and then just like in the "DEPLOY" stage, it just skipped to the end of the stage.  In this case, it went onto the "DEPLOY" stage, so this "skipping" behavior didn't cause a failure.

I'm at a loss to understand what this is doing here.

[David Karr]

I've determined that this behavior is caused by the "@NonCPS" annotation.  Once I removed them, this went back to behaving normally. I've read explanations of what @NonCPS is for, and I still don't fully understand it.  I believe I read somewhere that "collection.each {}" doesn't work properly without it, which is why I first started using it (although that code is commented out right now). I guess I'll backtrack now and see if I can get "each" working.  If not, I'll use an old loop.

[Daniel Beck]

> On 16.11.2016, at 22:20, David Karr <davidmic...@gmail.com> wrote:
>
> I've determined that this behavior is caused by the "@NonCPS" annotation.

You can't call Pipeline steps from @NonCPS annotated methods.

Basically:
Outside @NonCPS -- fancy Groovy features don't work
Inside @NonCPS -- Pipeline steps don't work

[David Karr]

Yes, I've heard that.  What I am unable to find any information on is what exactly a "pipeline step" actually means.

I also have a feeling that the "@NonCPS"-state doesn't apply "lexically", but "dynamically".  In other words, if I'm in a @NonCPS method, and I call a non-@NonCPS method, that method is still effectively @NonCPS.  This is another thing that I haven't found stated anywhere.

In my test case, when I change my method to @NonCPS, it aborts on very innocuous statements.

For instance, this is an excerpt of my @NonCPS-annotated method:

        println "JP_AlwaysNotifyTheseUsers[${JP_AlwaysNotifyTheseUsers}]"
        def alwaysNotifyEmailAddressesList = JP_AlwaysNotifyTheseUsers.split(/[,]/)
        println "alwaysNotifyEmailAddressesList[${alwaysNotifyEmailAddressesList}]"
        println "alwaysNotifyEmailAddressesList.size[${alwaysNotifyEmailAddressesList.size()}]"
//        String[] alwaysNotifyEmailAddresses = alwaysNotifyEmailAddressesList.toArray(new String[0]);
//        println "alwaysNotifyEmailAddresses[" + alwaysNotifyEmailAddresses + "]"
//        println "alwaysNotifyEmailAddresses0[" + alwaysNotifyEmailAddresses[0] + "]"
//        if (alwaysNotifyEmailAddressesList.size() > 0) {
//            println "alwaysNotifyEmailAddressesList0[${alwaysNotifyEmailAddressesList.get(0)}]"
//        }
//        else {
//            println "alwaysNotifyEmailAddressesList is size 0."
//        }
        println "About to start loop."
        for (int ctr = 0; ctr < alwaysNotifyEmailAddressesList.size(); ++ ctr) {
            println "ctr[" + ctr + "]" // last line
            def emailAddress = alwaysNotifyEmailAddressesList.get(ctr)
            println "emailAddress[" + emailAddress + "]"
            println "emailAddress[${emailAddress}]"
            emailAddressesList.add(emailAddress)
        }
        println "emailAddressesList[${emailAddressesList}]"

Here is the output that I see in the Jenkins console:

JP_AlwaysNotifyTheseUsers[...]
[Pipeline] echo
alwaysNotifyEmailAddressesList[[...]]
[Pipeline] echo
alwaysNotifyEmailAddressesList.size[1]
[Pipeline] echo
About to start loop.
[Pipeline] echo
ctr[0]

[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // node
[Pipeline] End of Pipeline

As you can see, the line marked with "last line" is the last line that appears to execute.  Either the "get()" call or the next println call makes it abort.  How are either of those a "pipeline step"?

[Daniel Beck]

> On 17.11.2016, at 17:19, David Karr <davidmic...@gmail.com> wrote:
>
> What I am unable to find any information on is what exactly a "pipeline step" actually means.

Everything you'll find in the snippet generator.

> I also have a feeling that the "@NonCPS"-state doesn't apply "lexically", but "dynamically". In other words, if I'm in a @NonCPS method, and I call a non-@NonCPS method, that method is still effectively @NonCPS.

Yes. (Otherwise what I wrote would be trivial to work around and wouldn't matter at all…)

[David Karr]

On Thursday, November 17, 2016 at 12:39:26 PM UTC-8, Daniel Beck wrote:

> On 17.11.2016, at 17:19, David Karr <davidmic...@gmail.com> wrote:
>
> What I am unable to find any information on is what exactly a "pipeline step" actually means.

Everything you'll find in the snippet generator.

Ok.  I don't think I saw that clearly stated in the other sources I found.

As "echo" is one of the pipeline steps, I would guess that "println" does exactly the same thing, but that doesn't appear to be a pipeline step.  Is that true?
 
Although I now understand what the limitation is, this still doesn't help my current problem.  As can be seen from my example, it is aborting on something that doesn't appear to be a pipeline step (unless "println" is a pipeline step).  The line before that "println" that it's not hitting is a "collection.get()" expression, which I'm pretty sure is not a pipeline step.

[David Karr]

On Thursday, November 17, 2016 at 2:13:40 PM UTC-8, David Karr wrote:

On Thursday, November 17, 2016 at 12:39:26 PM UTC-8, Daniel Beck wrote:

> On 17.11.2016, at 17:19, David Karr <davidmic...@gmail.com> wrote:
>
> What I am unable to find any information on is what exactly a "pipeline step" actually means.

Everything you'll find in the snippet generator.

Ok.  I don't think I saw that clearly stated in the other sources I found.

As "echo" is one of the pipeline steps, I would guess that "println" does exactly the same thing, but that doesn't appear to be a pipeline step.  Is that true?
 
Although I now understand what the limitation is, this still doesn't help my current problem.  As can be seen from my example, it is aborting on something that doesn't appear to be a pipeline step (unless "println" is a pipeline step).  The line before that "println" that it's not hitting is a "collection.get()" expression, which I'm pretty sure is not a pipeline step.

I've now verified that changing the reference from "collection.get(ctr)" to "collection[ctr]" makes it NOT abort at that point. Let me make this clear. If in the previous example, in the "ctr" loop, if I access the entry with "alwaysNotifyEmailAddressesList.get(ctr)", that aborts the pipeline. If I instead access it with "alwaysNotifyEmailAddressesList[ctr]", it does NOT abort the loop.

Unfortunately, that only gets me past that particular point. At the end of the loop iteration, I've tried every variation I can think of to add the string to the end of the "emailAddressesList" list, but no matter what, the pipeline exits at that line.