Tips to Debug Jenkins v2.x Pipeline Script(s), Part 2

In the first article, I shared few tips to debug Groovy-DSL scripts as part of the iterative development process. Improving the skills to analyze these scripts that constitute a crucial framework, and are integral to your CI environment's functionality, is very important.

Now, let's dive little deeper, to try and understand what's happening under the hood. Hang tight and get ready for the ride!

Code Inside the 'sh' Step

Let us start with this basic code that emits the current date and time in the timezone that I work.

For this demonstration, I created a simple pipeline build job in my private Jenkins, and the name of the job is 'testbuild-result'.

node('test-agent') {
    stage("Xecute Shell Script") {
        sh """
            sleep 35 && \
            date '+DATE:%d/%m/%Y %h:%m %Z' && \
            sleep 15
            """
    }
}

It is important to note that the Unix commands in the pipeline script, date and time are executed using the 'sh' step and enclosed within "triple double quotes," enabling string interpolation and the accommodation of multiline strings.

See this blog post for a detailed explanation on such Groovy strings.

What Happens to This Code Enclosed Within 'Sh' Step?

Now, let's examine how Jenkins Pipeline plugin suite treats this multiline code.

Here is the snippet of the build console output (attachment as image failed!) produced by Jenkins as the above pipeline code is executed.

[Pipeline] {
[Pipeline] stage
[Pipeline] { (Xecute Shell Script)
[Pipeline] sh
[testbuild-result] Running shell script
+ sleep 35
+ date '+DATE:%d/%m/%Y %h:%m %Z'
DATE:08/07/2019 Jul:07 PDT
+ sleep 15
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // node
[Pipeline] End of Pipeline
Finished: SUCCESS

From the build console output, it's quite obvious that the command has been executed, and as per line 8, in the trimmed output above, date and time output is shown on the standard out.

Code Execution Demystified

In Jenkins v2.x, it is possible that the pipeline builds can survive interruptions to the Jenkins service. So, how does Jenkins handles this code execution?

With a little bit of instrumentation, by adding the sleep command, the longevity of the code execution allows us to examine and understand what's happening here.

With the SSH access to the build agent, test-agent , I check the process table in the agent. From the trimmed output (of the process table), we find a set of processes running as generic user, build .

It's time for some in-depth analysis.

Build Workspace

From the process output, it can be inferred that the build workspace is, '/Users/jenkins/workspace/testbuild-result'; however, there are several other interesting things that are worth further discussion.

$ ps -eaf | grep -i build
build     5356 14355  0 23:28 ?        00:00:00 sh -c echo $$ 
> '/Users/jenkins/workspace/testbuild-result@tmp/durable-17912088/pid'
build     5359  5356  0 23:28 ?        00:00:00 /bin/sh -xe 
/Users/jenkins/workspace/testbuild-result@tmp/durable-17912088/script.sh
build     5360  5359  0 23:28 ?        00:00:00 sleep 35
root     14111  5767  0 May29 ?        00:00:00 sshd: build [priv]
build    14113 14111  0 May29 ?        00:01:56 sshd: build@notty
build    14293 14113  0 May29 ?        00:00:00 bash -c cd "/Users/jenkins" && java  -jar slave.jar
build    14355 14293  0 May29 ?        05:21:36 java -jar slave.jar

Parent and Child Processes

It is interesting to observe how the three lines of code are handled here.

The main Java process, 14355, has kicked off the execution of the code, via 5356; let's call this the main process. This "main" has spawned off another one, 5359, which owns the "script.sh" and this has created a child process, 5360, to execute the sleep command. This chain of processes isn't anything unusual but Jenkins ensures this is recorded as the process id of the "main" process, 5356.

Build Durability

At the global level, depending on the needs of the organization or the hosted projects, the durability setting can be configured globally in Jenkins. Check out Jenkins doc on pipeline durability.

Within <workspace@tmp>, durable folder is created and suffixed with a unique 8-digit ID.

What's Inside the "tmp"?

Code that was within the "sh" step is munged as script.sh and this script finds storage in a temporary directory, named, "testbuild-result@tmp" — ephemeral in nature. Within this temporary folder, there are few files, named "pid," "script.sh," and "jenkins-log.txt."

$ ls /Users/jenkins/workspace/testbuild-result@tmp/durable*/
jenkins-log.txt  pid  script.sh

Examine the pid

This is the main build process that started the code execution.

$ cat /Users/jenkins/workspace/testbuild-result@tmp/durable*/pid
5356

Contents of script

Three lines of shell script enclosed within triple double quotes are part of this shell script.

$ ls /Users/jenkins/workspace/testbuild-result@tmp/durable-*/*.sh
/Users/jenkins/workspace/testbuild-result@tmp/durable-17912088/script.sh

$ cat /Users/jenkins/workspace/testbuild-result@tmp/durable-*/*.sh
#!/bin/sh -xe

            sleep 35 &&             date '+DATE:%d/%m/%Y %h:%m %Z' &&             sleep 15