[JIRA] [workflow-plugin] (JENKINS-31769) sh steps on slaves randomly hang when complete

44 перегляди
Перейти до першого непрочитаного повідомлення

barthelemy@crans.org (JIRA)

не прочитано,
27 лист. 2015 р., 05:16:0227.11.15
Кому: jenkinsc...@googlegroups.com
Sébastien Barthélémy created an issue
 
Jenkins / Bug JENKINS-31769
sh steps on slaves randomly hang when complete
Issue Type: Bug Bug
Assignee: Jesse Glick
Components: workflow-plugin
Created: 27/Nov/15 10:15 AM
Environment: jenkins master & slaves inside docker containers all on the same linux server
Workflow 1.10.1
Jenkins ver. 1.625.1
Priority: Major Major
Reporter: Sébastien Barthélémy

sh steps that succeed are sometimes hanging

on http://agility-test.local/job/team_romeo_dev/4/console I see

...
Running: Allocate node : Body : End                                             
Running: Allocate node : End                                                    
Running: Allocate node : Start                                                  
Running on qibuild-linux64 in /home/jenkins/jenkins/workspace/team_romeo_dev    
Running: Allocate node : Body : Start                                           
Running: Determine Current Directory                                            
Running: Shell Script                                                           
[team_romeo_dev] Running shell script                                           
+ qibuild add-config linux64_debug -t linux64                                   

and it hangs there forever. Here is the corresponding part of the workflow

  ...
  node("qibuild-linux64") {
    configs = []
    if (params.run_linux64_debug) {
      configs << 'linux64_debug'
    }
    if (params.run_linux64_release) {
      configs << 'linux64_release'
    }
    workspace = pwd()
    for (int i = 0; i < configs.size(); ++i) {
      String config = configs[i]
      sh "qibuild add-config ${config} -t linux64"
      def p = projects.all()
      configure(c, config, p)
      make(c, config, p)
      String test_dir = "test-${config}"
      String test_dir_full = "${workspace}/${test_dir}"
      test(c, config, p, test_dir_full)
      step([$class: 'JUnitResultArchiver', testResults: "${test_dir}/*/test-results/*.xml"])
      String test_archive = "${test_dir}.tgz"
      sh "tar -czf ${test_archive} ${test_dir}"
      step([$class: 'ArtifactArchiver', artifacts: test_archive])
    }
    ...

I does seem similar to https://issues.jenkins-ci.org/browse/JENKINS-28759

I'm not sure how to help nailing this issue.

I got thread dumps in case it helps:

I then added a org.jenkinsci.plugins.workflow.steps.durable_task and will hopefully have more information next time it occurs.

Add Comment Add Comment
 
This message was sent by Atlassian JIRA (v6.4.2#64017-sha1:e244265)
Atlassian logo

jglick@cloudbees.com (JIRA)

не прочитано,
30 лист. 2015 р., 16:07:0230.11.15
Кому: jenkinsc...@googlegroups.com
Jesse Glick commented on Bug JENKINS-31769
 
Re: sh steps on slaves randomly hang when complete

Rather sounds like JENKINS-28821: perhaps your slave workspace is not writable, and the wrapper script launch is just failing. Look in your workspace for a directory like .abcdef123456 and see if it contains a PID file, a log file, and a wrapper script file. I suspect something is wrong with how your Docker containers are set up. The durable-task plugin needs to do a better job of detecting and diagnosing this kind of environmental problem.

barthelemy@crans.org (JIRA)

не прочитано,
1 груд. 2015 р., 04:20:0101.12.15
Кому: jenkinsc...@googlegroups.com

Hi Jesse, thank you for answering.
I'd be surprised by a docker problem : I guess it would not work at all in that case, no?

Anyway, I got a new hang, on
http://agility-test.local/job/team_romeo_dev/12/console
I get

Started by upstream project "nightly" build number 8
originally caused by:
 Started by timer
Running: Print Message
runme
Running: run_stage
Entering stage run_stage
Proceeding
Running: Allocate node : Start
Running on qisrc in /home/jenkins/jenkins/workspace/team_romeo_dev
Running: Allocate node : Body : Start
Running: Shell Script
[team_romeo_dev] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory
...hanging forever...

On the slave itself, there are the files you mention

$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`

$ cd jenkins/workspace/team_romeo_dev/.d10a2fc7/

$ ls
jenkins-log.txt  jenkins-result.txt  pid  script.sh

$ cat jenkins-log.txt 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 

$ cat jenkins-result.txt
0

$ cat pid               
31285

$ cat script.sh 
#!/bin/sh -xe
file /home/jenkins/w/team_romeo_dev/.qijenkins@339a8fe7a101:~/jenkins/workspace/team_romeo_dev/.d10a2fc7$

$ mount
none on / type aufs (rw,relatime,si=1abb4f0b5dbc66b3,dio)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev type tmpfs (rw,nosuid,mode=755)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=666)
sysfs on /sys type sysfs (ro,nosuid,nodev,noexec,relatime)
tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,relatime,mode=755)
cgroup on /sys/fs/cgroup/cpuset type cgroup (ro,nosuid,nodev,noexec,relatime,cpuset)
cgroup on /sys/fs/cgroup/cpu type cgroup (ro,nosuid,nodev,noexec,relatime,cpu)
cgroup on /sys/fs/cgroup/cpuacct type cgroup (ro,nosuid,nodev,noexec,relatime,cpuacct)
cgroup on /sys/fs/cgroup/memory type cgroup (ro,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/devices type cgroup (ro,nosuid,nodev,noexec,relatime,devices)
cgroup on /sys/fs/cgroup/freezer type cgroup (ro,nosuid,nodev,noexec,relatime,freezer)
cgroup on /sys/fs/cgroup/blkio type cgroup (ro,nosuid,nodev,noexec,relatime,blkio)
cgroup on /sys/fs/cgroup/perf_event type cgroup (ro,nosuid,nodev,noexec,relatime,perf_event)
cgroup on /sys/fs/cgroup/hugetlb type cgroup (ro,nosuid,nodev,noexec,relatime,hugetlb)
systemd on /sys/fs/cgroup/systemd type cgroup (ro,nosuid,nodev,noexec,relatime,name=systemd)
/dev/mapper/agility--test--vg-root on /home/jenkins/w type ext4 (rw,relatime,errors=remount-ro,data=ordered)
/dev/mapper/agility--test--vg-root on /etc/resolv.conf type ext4 (rw,relatime,errors=remount-ro,data=ordered)
/dev/mapper/agility--test--vg-root on /etc/hostname type ext4 (rw,relatime,errors=remount-ro,data=ordered)
/dev/mapper/agility--test--vg-root on /etc/hosts type ext4 (rw,relatime,errors=remount-ro,data=ordered)
shm on /dev/shm type tmpfs (rw,nosuid,nodev,noexec,relatime,size=65536k)
mqueue on /dev/mqueue type mqueue (rw,nosuid,nodev,noexec,relatime)
proc on /proc/asound type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/bus type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/fs type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/irq type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/sys type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/sysrq-trigger type proc (ro,nosuid,nodev,noexec,relatime)
tmpfs on /proc/kcore type tmpfs (rw,nosuid,mode=755)
tmpfs on /proc/latency_stats type tmpfs (rw,nosuid,mode=755)
tmpfs on /proc/timer_stats type tmpfs (rw,nosuid,mode=755)

I found nothing useful in http://agility-test.local/log/org.jenkinsci.plugins.workflow.steps.durable_task/, its ring buffer seems too small.

Here is the jenkins thread dump
http://pastebin.com/V5bJrJxn

jglick@cloudbees.com (JIRA)

не прочитано,
1 груд. 2015 р., 14:32:0101.12.15
Кому: jenkinsc...@googlegroups.com

Jenkins thread dumps are generally useless. 1.12-beta-2 adds a Workflow-specific virtual thread dump, though in this case it would not tell you anything you did not already know: that the build is inside a sh step.

If jenkins-result.txt exists, and the step still does not exit, it usually means that the Jenkins slave agent is failing to read this file—check file permissions. This is why I suspect Docker: there might be a UID mapping issue.

The ring buffer for log messages shown in the UI only holds 100 items IIRC. Install the Support Core plugin and your existing custom logs will be streamed to disk, rotated every 10000 items to a series of up to 10 backup files.

barthelemy@crans.org (JIRA)

не прочитано,
2 груд. 2015 р., 04:04:0202.12.15
Кому: jenkinsc...@googlegroups.com

Hi Jesse, thank you again for help and tips.

> If jenkins-result.txt exists, and the step still does not exit,
> it usually means that the Jenkins slave agent is failing to read this file—
> check file permissions.

Here they are:

$ ls -l jenkins/workspace/team_romeo_dev/.d10a2fc7/
total 16
-rw-rw-r-- 1 jenkins jenkins 89 Nov 29 02:26 jenkins-log.txt
-rw-rw-r-- 1 jenkins jenkins  2 Nov 29 02:26 jenkins-result.txt
-rw-rw-r-- 1 jenkins jenkins  6 Nov 29 02:25 pid
-rwxr-xr-x 1 jenkins jenkins 53 Nov 29 02:25 script.sh

> This is why I suspect Docker: there might be a UID mapping issue.

I doubt it, for several reasons:
1/ my docker setup did not change and is quite straightforward I think
2/ that would not explain why it sometimes hangs but usually works
3/ in this case, you can see that the permissions are ok. In particular, the master did succeed to read the log file (since it displayed it in the web interface, see my previous comment), and the result file has the exact same permissions.

jglick@cloudbees.com (JIRA)

не прочитано,
2 груд. 2015 р., 17:25:0402.12.15
Кому: jenkinsc...@googlegroups.com

Well enable a fine logger. If you see

still running in … on …

you can use /script to check something like

Jenkins.instance.getNode('slavename').createPath('/that/path/.abcd1234/jenkins-result.txt').exists()

One odd thing I notice in your logs is the mismatch between /home/jenkins/w/team_romeo_dev and /home/jenkins/workspace/team_romeo_dev. Are you using symbolic links? Custom workspace locations?

barthelemy@crans.org (JIRA)

не прочитано,
3 груд. 2015 р., 05:25:0203.12.15
Кому: jenkinsc...@googlegroups.com

Hello Jesse,

Well enable a fine logger

I enabled the fine logger and installed the support-core plugin (no hang since ) .
I can see the logs on the master. There are 10 of them, each one holding 2 minutes of history, that will not be enough I fear.

$ cd jenkins_home
$ wc -l logs/custom/*
    4727 logs/custom/durable_task.log
   10027 logs/custom/durable_task.log.1
    9989 logs/custom/durable_task.log.2
   10044 logs/custom/durable_task.log.4
   10008 logs/custom/durable_task.log.5
    9993 logs/custom/durable_task.log.6
   10004 logs/custom/durable_task.log.7
   10025 logs/custom/durable_task.log.8
    9976 logs/custom/durable_task.log.9
   84793 total
$ head -n 1 logs/custom/durable_task.log.1
2015-12-03 09:38:55.137+0000 [id=95]       FINE    hudson.remoting.Channel$1#handle: Received hudson.remoting.UnexportCommand@571a0764
$ tail -n 1 logs/custom/durable_task.log.1
2015-12-03 09:40:03.616+0000 [id=95]    FINE    hudson.remoting.Channel$1#handle: Received 

One odd thing I notice in your logs is the mismatch between

home/jenkins/w/team_romeo_dev and
/home/jenkins/workspace/team_romeo_dev.

/home/jenkins/workspace is jenkins' workspace.

team_romeo_dev is the name of the job, so /home/jenkins/workspace/team_romeo_dev is this job's workspace. I think there is nothing custom there.

The purpose of the job is to build C++ software using qibuild.

The /home/jenkins/w directory is where I store qibuild worktrees (checkouts of C++ sources) and build directories.
This directory is a docker volume shared among slaves (which are docker containers, all running on the same host), so that all slaves have access to the sources to build.
I have one worktree directory per job (here /home/jenkins/w/team_romeo_dev), named like the job, which is itself named like the git branch it follows.

So, there is no symlink involved, and jenkins should not be aware of this /home/jenkins/w/team_romeo_dev directory (but the scripts it runs are).

Are you using symbolic links?

no

Custom workspace locations?

no

jglick@cloudbees.com (JIRA)

не прочитано,
4 груд. 2015 р., 15:22:0204.12.15
Кому: jenkinsc...@googlegroups.com
Jesse Glick edited a comment on Bug JENKINS-31769
bq. each one holding 2 minutes of history

The log is supposed
 to be  rotated after it has accumulated 10k lines. But it looks like most of yours is junk. Perhaps I needed to clarify that the {{FINE}} logger should be logging only {{org.jenkinsci.plugins.workflow.steps.durable_task}} and {{org.jenkinsci.plugins.durabletask}}.

jglick@cloudbees.com (JIRA)

не прочитано,
4 груд. 2015 р., 15:22:0404.12.15
Кому: jenkinsc...@googlegroups.com

each one holding 2 minutes of history

The log is supposed rotated after it has accumulated 10k lines. But it looks like most of yours is junk. Perhaps I needed to clarify that the FINE logger should be logging only org.jenkinsci.plugins.workflow.steps.durable_task and org.jenkinsci.plugins.durabletask.

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 04:13:0207.12.15
Кому: jenkinsc...@googlegroups.com

This week-end I had another hang, on a toy workflow I created for the occasion.

Here is is code:

class Config implements Serializable {
  String branch
  String source
  String build
}

def runme(Config c)
{
  echo "runme"
  stage name: 'run_stage', concurrency: 1
  node("qisrc") {
    for (int i = 0; i < 1000; ++i) {
      echo("i: ${i}");
      try {
        sh "file ${c.source}/.qi" // will throw if .qi is missing
      } catch (all) {
        sh "ls ${c.source}"
      }
    }
  }
}

def c = new Config(
  branch: "team/romeo/dev",
  source: "/home/jenkins/w/team_romeo_dev",
  build: "/home/jenkins/w/team_romeo_dev-build")
runme(c)
class Config implements Serializable {
  String branch
  String source
  String build
}

def runme(Config c)
{
  echo "runme"
  stage name: 'run_stage', concurrency: 1
  node("qisrc") {
    for (int i = 0; i < 1000; ++i) {
      echo("i: ${i}");
      try {
        sh "file ${c.source}/.qi" // will throw if .qi is missing
      } catch (all) {
        sh "ls ${c.source}"
      }
    }
  }
}

def c = new Config(
  branch: "team/romeo/dev",
  source: "/home/jenkins/w/team_romeo_dev",
  build: "/home/jenkins/w/team_romeo_dev-build")
runme(c)

I found it hung at iteration 530
http://agility-test.local/job/test_workflow/19/console

Started by upstream project "nightly" build number 6
originally caused by:
 Started by timer
Running: Print Message
runme
Running: run_stage
Entering stage run_stage
Proceeding
Running: Allocate node : Start
Running on qisrc in /home/jenkins/jenkins/workspace/test_workflow
Running: Allocate node : Body : Start
Running: Print Message
i: 0
Running: Shell Script
[test_workflow] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
Running: Print Message
i: 1
Running: Shell Script
...
Running: Shell Script
[test_workflow] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
Running: Print Message
i: 530
Running: Shell Script
[test_workflow] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 

Nothing unexpected in the control directory seems

$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`
$ ls -la jenkins/workspace/test_workflow/
total 24
drwxrwxr-x 3 jenkins jenkins  4096 Dec  6 02:39 .
drwxrwxr-x 4 jenkins jenkins  4096 Dec  2 13:20 ..
drwxrwxr-x 2 jenkins jenkins  4096 Dec  6 02:39 .ac553e58
-rw-rw-r-- 1 jenkins jenkins 10130 Dec  4 02:14 snapshot.json
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-log.txt 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/                
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt 
0
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/                   
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/pid 
17882
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/script.sh 
#!/bin/sh -xe
file /home/jenkins/w/team_romeo_dev/.qijenkins@036123a0bf25:~$

The jobs usually runs for 5 minutes and started Dec 6, 2015 2:35 AM.
Sadly, my older log is 2015-12-06 21:31:54.875+0000.

I tried this in http://agility-test.local/script

Jenkins.instance.getNode('qisrc').createPath('/home/jenkins/jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt').exists()

I got

 
                                                

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 04:14:0107.12.15
Кому: jenkinsc...@googlegroups.com
This week-end I had another hang, on a toy workflow I created for the occasion.

Here is is code:
{code}
{code}



I found it hung at iteration 530
http://agility-test.local/job/test_workflow/19/console
{noformat}
{noformat}


Nothing unexpected in the control directory seems 
{code}

$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`
$ ls -la jenkins/workspace/test_workflow/
total 24
drwxrwxr-x 3 jenkins jenkins  4096 Dec  6 02:39 .
drwxrwxr-x 4 jenkins jenkins  4096 Dec  2 13:20 ..
drwxrwxr-x 2 jenkins jenkins  4096 Dec  6 02:39 .ac553e58
-rw-rw-r-- 1 jenkins jenkins 10130 Dec  4 02:14 snapshot.json
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-log.txt 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/                
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt 
0
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/                   
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/pid 
17882
jenkins@036123a0bf25:~$ cat jenkins/workspace/test_workflow/.ac553e58/script.sh 
#!/bin/sh -xe
file /home/jenkins/w/team_romeo_dev/.qijenkins@036123a0bf25:~$
{code}


The jobs usually runs for 5 minutes and started Dec 6, 2015 2:35 AM.
Sadly, my older log is 2015-12-06 21:31:54.875+0000.

I tried this in http://agility-test.local/script
{code}

Jenkins.instance.getNode('qisrc').createPath('/home/jenkins/jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt').exists()
{code}
I got 
{noformat}

Result: true
{noformat}
But nothing happened. The job is still hanged.

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 04:14:0207.12.15
Кому: jenkinsc...@googlegroups.com

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 04:16:0407.12.15
Кому: jenkinsc...@googlegroups.com
{code}
$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`
$ ls -la jenkins/workspace/test_workflow/
total 24
drwxrwxr-x 3 jenkins jenkins  4096 Dec  6 02:39 .
drwxrwxr-x 4 jenkins jenkins  4096 Dec  2 13:20 ..
drwxrwxr-x 2 jenkins jenkins  4096 Dec  6 02:39 .ac553e58
-rw-rw-r-- 1 jenkins jenkins 10130 Dec  4 02:14 snapshot.json
jenkins@036123a0bf25:~ $ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-log.txt 

+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
jenkins@036123a0bf25:~ $ cat jenkins/workspace/test_workflow/.ac553e58/                
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
jenkins@036123a0bf25:~ $ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt 
0
jenkins@036123a0bf25:~ $ cat jenkins/workspace/test_workflow/.ac553e58/                   
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
jenkins@036123a0bf25:~ $ cat jenkins/workspace/test_workflow/.ac553e58/pid 
17882
jenkins@036123a0bf25:~ $ cat jenkins/workspace/test_workflow/.ac553e58/script.sh 
#!/bin/sh -xe
file /home/jenkins/w/team_romeo_dev/.
qijenkins@036123a0bf25:~$ qi
{code}

The jobs usually runs for 5 minutes and started Dec 6, 2015 2:35 AM.
Sadly, my older log is 2015-12-06 21:31:54.875+0000.

I tried this in http://agility-test.local/script
{code}
Jenkins.instance.getNode('qisrc').createPath('/home/jenkins/jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt').exists()
{code}
I got 
{noformat}
Result: true
{noformat}
But nothing happened. The job is still hanged.

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 05:07:0507.12.15
Кому: jenkinsc...@googlegroups.com
 code:
$ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-log.txt 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
$ cat jenkins/workspace/test_workflow/.ac553e58/                
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
$ cat jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt 
0

$ cat jenkins/workspace/test_workflow/.ac553e58/                   
jenkins-log.txt     jenkins-result.txt  pid                 script.sh           
$ cat jenkins/workspace/test_workflow/.ac553e58/pid 
17882

$ cat jenkins/workspace/test_workflow/.ac553e58/script.sh 
#!/bin/sh -xe
file /home/jenkins/w/team_romeo_dev/.qi
{code}

The jobs usually runs for 5 minutes and started Dec 6, 2015 2:35 AM.
Sadly, my older log is 2015-12-06 21:31:54.875+0000.

I tried this in http://agility-test.local/script
{code}
Jenkins.instance.getNode('qisrc').createPath('/home/jenkins/jenkins/workspace/test_workflow/.ac553e58/jenkins-result.txt').exists()
{code}
I got 
{noformat}
Result: true
{noformat}
But nothing happened. The job is still hanged.

jglick@cloudbees.com (JIRA)

не прочитано,
7 груд. 2015 р., 09:52:0107.12.15
Кому: jenkinsc...@googlegroups.com

No working hypothesis. Still need to either get logs from the time of the hang, or a way to reproduce from scratch.

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 10:21:0207.12.15
Кому: jenkinsc...@googlegroups.com

No working hypothesis. Still need to either get logs from the time of the hang, or a way to reproduce from scratch.

ok.

The good news is that my logger was mis-configured, my logs now cover a longer timespan:
I see 3 to 4 logs per seconds:
either

2015-12-07 15:10:30.671+0000 [id=52]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 89 bytes from /home/jenkins/jenkins/workspace/test_workflow/.a7304ceb/jenkins-log.txt
2015-12-07 15:10:30.962+0000 [id=53]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 89 bytes from /home/jenkins/jenkins/workspace/test_workflow/.3bb38477/jenkins-log.txt

or

2015-12-07 10:12:26.691+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_romeo_dev on qisrc
2015-12-07 10:12:27.003+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_romeo_dev on qisrc

which means a file (10000 lines) covers 40 to 55 minutes.

However, with only 10 of them I cannot cover the whole week-end.

jglick@cloudbees.com (JIRA)

не прочитано,
7 груд. 2015 р., 10:25:0107.12.15
Кому: jenkinsc...@googlegroups.com

And this does not reproduce consistently enough to inspect logs during a workday I suppose?

You could either create a custom build of support-core that makes this and/or this larger (or determined by configurable system property—if so, please submit a PR), or configure your servlet container to capture logs if that is possible (depends on the container I think).

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 13:27:0107.12.15
Кому: jenkinsc...@googlegroups.com

And this does not reproduce consistently enough to inspect logs during a workday I suppose?

The normal jobs take hours, which make the probabilty to see a hang quite low. I'm trying to reproduce the issue on smaller purpose-less jobs.

I'm making progress: I got a new hang, with logs!

I'm not sure it is the exact same problem since this is the first time that 1/ I notice unexpected console logs and 2/ the control directory is not there.

The setup is:
a workflow job called test_nightly is run every 4 minutes. It starts another workflow job called test_workflow, two times is a row. I expect at least half of the test_nightly jobs will get superseded. The sources are at the end.

It worked as expected until test_nightly #91, which started at Dec 7, 2015 4:04 PM

Started by timer
Running: run_stage
Entering stage run_stage
Canceling older #90
Waiting for builds [89]
Unblocked since #89 finished
Running: Building test_workflow
Starting building project: test_workflow

which started test_workflow #75 at Dec 7, 2015 4:06 PM, which never returned
The console logs below are quite surprising, the line + file /home/jenkins/w/team_romeo_dev/.qi appears too many times, as if several threads fetched the log in parallel.

started by upstream project "test_nightly" build number 91
originally caused by:
 Started by timer
Running: Print Message
runme
Running: run_stage
Entering stage run_stage
Proceeding
Running: Allocate node : Start
Running on qisrc in /home/jenkins/jenkins/workspace/test_workflow
Running: Allocate node : Body : Start
Running: Print Message
i: 0
Running: Shell Script
[test_workflow] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
Running: Print Message
i: 1
...

i: 648
Running: Shell Script
[test_workflow] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
Running: Print Message
i: 649
Running: Shell Script
[test_workflow] Running shell script
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory 
+ file /home/jenkins/w/team_romeo_dev/.qi
/home/jenkins/w/team_romeo_dev/.qi: directory

full console log here: http://pastebin.com/6cWTbNF4
durable task log: http://pastebin.com/DKZCNEna
default log: http://pastebin.com/LUXUYERM

On the slave, there is no control directory (contrary to others occurrences of the hang)

$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`
$ ls -la jenkins/workspace/test_workflow/
total 8
drwxrwxr-x 2 jenkins jenkins 4096 Dec  7 16:13 .
drwxrwxr-x 4 jenkins jenkins 4096 Dec  7 10:12 ..

test_workflow source

class Config implements Serializable {
  String branch
  String source
  String build
}

def runme(Config c)
{
  echo "runme"
  stage name: 'run_stage', concurrency: 1
  node("qisrc") {
    for (int i = 0; i < 1000; ++i) {
      echo("i: ${i}");
      try {
        sh "file ${c.source}/.qi" // will throw if .qi is missing
      } catch (all) {
        sh "ls ${c.source}"
      }
    }
  }
}

def c = new Config(
  branch: "team/romeo/dev",
  source: "/home/jenkins/w/team_romeo_dev",
  build: "/home/jenkins/w/team_romeo_dev-build")
runme(c)

test_nightly source

stage name: 'run_stage', concurrency: 1
build job: "test_workflow", propagate: false
build job: "test_workflow", propagate: false

jglick@cloudbees.com (JIRA)

не прочитано,
7 груд. 2015 р., 14:40:0207.12.15
Кому: jenkinsc...@googlegroups.com

My suspicion falls on

…	FINE	o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/test_workflow
java.lang.InterruptedException
	at java.lang.Object.wait(Native Method)
	at hudson.remoting.Request.call(Request.java:147)
	at hudson.remoting.Channel.call(Channel.java:777)
	at hudson.FilePath.act(FilePath.java:980)
	at hudson.FilePath.act(FilePath.java:969)
	at hudson.FilePath.deleteRecursive(FilePath.java:1171)
	at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.cleanup(FileMonitoringTask.java:155)
	at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:199)
	at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
	at …

There is a three-second timeout on rounds of checking, to prevent hung slave connections from stalling everything. So in the latest case it sounds like if the slave is heavily enough loaded that about three seconds elapse between the start of the first check round after the process has exited and when cleanup is called, there could be a race condition whereby the control directory is actually deleted but the step does not exit. I think the sequence of operations needs to be reordered a bit.

That does not explain the original hangs, in which case the control dir was there.

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 15:26:0607.12.15
Кому: jenkinsc...@googlegroups.com

Got a new one, with the control directory

job team_agility_dev #1, started Dec 7, 2015 6:00 PM

Started by upstream project "nightly" build number 1
originally caused by:
 Started by timer
Running: Print Message
runme
Running: run_stage
Entering stage run_stage
...
 (146/148) Setup dialog                        
* (147/148) Setup gui/qigui                     
* (148/148) Setup life/usersession              
                                                 
New qisrc worktree initialized in /home/jenkins/w/team_agility_dev
Running: Shell Script
[team_agility_dev] Running shell script
+ rm -f snapshot.json

on the qisrc slave

$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`
$ ls -ld jenkins/workspace/team_agility_dev/.e7972254/
drwxrwxr-x 2 jenkins jenkins 4096 Dec  7 19:12 jenkins/workspace/team_agility_dev/.e7972254/
$ ls -l jenkins/workspace/team_agility_dev/.e7972254/
total 16
-rw-rw-r-- 1 jenkins jenkins 22 Dec  7 19:12 jenkins-log.txt
-rw-rw-r-- 1 jenkins jenkins  2 Dec  7 19:12 jenkins-result.txt
-rw-rw-r-- 1 jenkins jenkins  6 Dec  7 19:12 pid
-rwxr-xr-x 1 jenkins jenkins 33 Dec  7 19:12 script.sh
$ cat jenkins/workspace/team_agility_dev/.e7972254/jenkins-log.txt
+ rm -f snapshot.json
$ cat jenkins/workspace/team_agility_dev/.e7972254/jenkins-result.txt 
0
$ cat jenkins/workspace/team_agility_dev/.e7972254/pid                
26868
$ cat jenkins/workspace/team_agility_dev/.e7972254/script.sh 
#!/bin/sh -xe
rm -f snapshot.json

Also
Jenkins.instance.getNode('qisrc').createPath('/home/jenkins/jenkins/workspace/team_agility_dev/.e7972254/jenkins-result.txt').exists() return true

Here is the durable task log, it starts from the previous test_workflow" hang at
16:13:47.220+0000 then jumps to the new job a 18:58:58.789+0000 when I cancelled the hung one (which was blocking team_agility_dev since they compete for the same executor).

I skipped some parts with ellipsis.
At the very you'll see that it reads from .e7972254/jenkins-log.txt

2015-12-07 16:13:47.220+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/test_workflow
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at hudson.FilePath.deleteRecursive(FilePath.java:1171)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.cleanup(FileMonitoringTask.java:155)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:199)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 18:58:58.789+0000 [id=51]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 170 bytes from /home/jenkins/jenkins/workspace/test_workflow/.3bdc0065/jenkins-log.txt
2015-12-07 18:59:00.277+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/test_workflow
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at hudson.FilePath.deleteRecursive(FilePath.java:1171)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.cleanup(FileMonitoringTask.java:155)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:199)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:01:19.958+0000 [id=42]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 168 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.708dc0db/jenkins-log.txt
2015-12-07 19:01:24.510+0000 [id=42]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 42 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.d2f92a64/jenkins-log.txt
2015-12-07 19:01:30.996+0000 [id=52]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 430 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:01:32.645+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:33.832+0000 [id=42]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 4,149 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:01:34.369+0000 [id=42]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:35.722+0000 [id=42]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:37.366+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:38.905+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:40.515+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:41.959+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:44.132+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:45.920+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:48.670+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:50.756+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:52.572+0000 [id=59]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 306 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:01:53.082+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:54.338+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:55.376+0000 [id=51]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 232 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:01:55.962+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:57.105+0000 [id=42]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:01:57.972+0000 [id=42]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 217 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:01:58.630+0000 [id=42]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc

...



2015-12-07 19:07:41.454+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:43.284+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:44.103+0000 [id=53]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 248 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:07:44.450+0000 [id=53]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:45.469+0000 [id=64]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 254 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:07:45.993+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:46.764+0000 [id=64]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 227 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:07:47.117+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:48.542+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:49.856+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:07:57.730+0000 [id=54]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 941 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:07:58.700+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at org.jenkinsci.plugins.durabletask.ProcessLiveness.isAlive(ProcessLiveness.java:49)
        at org.jenkinsci.plugins.durabletask.BourneShellScript$ShellController.exitStatus(BourneShellScript.java:146)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:191)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:08:00.526+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:02.705+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:04.432+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:06.238+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:08.304+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:11.371+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:13.685+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:16.113+0000 [id=53]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:19.356+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:22.174+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:08:24.411+0000 [id=54]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 233 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt

...

2015-12-07 19:09:41.968+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:42.680+0000 [id=55]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 231 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:43.205+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:43.810+0000 [id=55]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 237 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:44.181+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:44.793+0000 [id=59]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 237 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:45.137+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:46.266+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:46.954+0000 [id=59]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 225 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:47.334+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:48.089+0000 [id=59]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 237 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:48.478+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:49.406+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:50.062+0000 [id=51]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 84 bytes from /home/jenkins/jenkins/workspace/team_agility
_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:50.551+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:51.199+0000 [id=54]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 153 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:51.688+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:52.289+0000 [id=59]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 228 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:52.729+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:53.934+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:54.571+0000 [id=52]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 225 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:54.920+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:55.613+0000 [id=59]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 237 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:55.955+0000 [id=59]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:56.712+0000 [id=55]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 229 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:57.053+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:58.193+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:58.857+0000 [id=23]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 240 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:09:59.202+0000 [id=23]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:09:59.825+0000 [id=55]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 257 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:00.167+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:01.124+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:02.521+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:03.851+0000 [id=23]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:04.976+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:05.964+0000 [id=52]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 256 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:06.359+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:07.473+0000 [id=42]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:08.122+0000 [id=23]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 237 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:08.507+0000 [id=23]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:09.309+0000 [id=54]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 222 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:09.653+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:10.256+0000 [id=51]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 84 bytes from /home/jenkins/jenkins/workspace/team_agility
_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:10.733+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:11.339+0000 [id=52]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 148 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:11.708+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:12.302+0000 [id=64]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 226 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:12.646+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:13.576+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:14.567+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:15.750+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:17.018+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:18.517+0000 [id=55]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:20.920+0000 [id=63]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 470 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:21.709+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:23.032+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:24.222+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: still running in /home/jenkins/jenkins/workspace/team_agility_dev on qisrc
2015-12-07 19:10:25.529+0000 [id=63]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 226 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:27.888+0000 [id=63]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at org.jenkinsci.plugins.durabletask.ProcessLiveness.isAlive(ProcessLiveness.java:49)
        at org.jenkinsci.plugins.durabletask.BourneShellScript$ShellController.exitStatus(BourneShellScript.java:146)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:191)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:10:33.658+0000 [id=64]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 605 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:33.872+0000 [id=64]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at hudson.FilePath.exists(FilePath.java:1437)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.exitStatus(FileMonitoringTask.java:139)
        at org.jenkinsci.plugins.durabletask.BourneShellScript$ShellController.exitStatus(BourneShellScript.java:141)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:191)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:10:37.303+0000 [id=54]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 308 bytes from /home/jenkins/jenkins/workspace/team_agilit
y_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:10:38.075+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at hudson.FilePath.exists(FilePath.java:1437)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.exitStatus(FileMonitoringTask.java:139)
        at org.jenkinsci.plugins.durabletask.BourneShellScript$ShellController.exitStatus(BourneShellScript.java:141)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:191)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:10:55.434+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.writeLog(FileMonitoringTask.java:96)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:185)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:12:01.074+0000 [id=54]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 8,663 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.dcbaaa31/jenkins-log.txt
2015-12-07 19:12:21.960+0000 [id=51]    FINE    o.j.p.d.FileMonitoringTask$FileMonitoringController#writeLog: copied 22 bytes from /home/jenkins/jenkins/workspace/team_agility_dev/.e7972254/jenkins-log.txt
2015-12-07 19:12:23.093+0000 [id=51]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at hudson.FilePath.exists(FilePath.java:1437)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.exitStatus(FileMonitoringTask.java:139)
        at org.jenkinsci.plugins.durabletask.BourneShellScript$ShellController.exitStatus(BourneShellScript.java:141)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:191)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:12:41.742+0000 [id=52]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.writeLog(FileMonitoringTask.java:96)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:185)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
2015-12-07 19:12:51.418+0000 [id=54]    FINE    o.j.p.w.s.d.DurableTaskStep$Execution#check: could not check /home/jenkins/jenkins/workspace/team_agility_dev
java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at hudson.remoting.Request.call(Request.java:147)
        at hudson.remoting.Channel.call(Channel.java:777)
        at hudson.FilePath.act(FilePath.java:980)
        at hudson.FilePath.act(FilePath.java:969)
        at org.jenkinsci.plugins.durabletask.FileMonitoringTask$FileMonitoringController.writeLog(FileMonitoringTask.java:96)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.check(DurableTaskStep.java:196)
        at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.run(DurableTaskStep.java:154)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

The "default" log is there: http://pastebin.com/jyiw33fL

barthelemy@crans.org (JIRA)

не прочитано,
7 груд. 2015 р., 15:29:0607.12.15
Кому: jenkinsc...@googlegroups.com
Got a new  one  hang ,  this time  with the control directory

It's job team_agility_dev #1, started Dec 7, 2015 6:00 PM  which hangs aftre running a simple shell script (calling "rm").
{noformat}

Started by upstream project "nightly" build number 1
originally caused by:
 Started by timer
Running: Print Message
runme
Running: run_stage
Entering stage run_stage
...
 (146/148) Setup dialog                        
* (147/148) Setup gui/qigui                     
* (148/148) Setup life/usersession              
                                                 
New qisrc worktree initialized in /home/jenkins/w/team_agility_dev
Running: Shell Script
[team_agility_dev] Running shell script
+ rm -f snapshot.json
{noformat}
on the qisrc slave
{noformat}

$ ssh jenkins@`sudo docker inspect --format '{{.NetworkSettings.IPAddress}}' qisrc`
$ ls -ld jenkins/workspace/team_agility_dev/.e7972254/
drwxrwxr-x 2 jenkins jenkins 4096 Dec  7 19:12 jenkins/workspace/team_agility_dev/.e7972254/
$ ls -l jenkins/workspace/team_agility_dev/.e7972254/
total 16
-rw-rw-r-- 1 jenkins jenkins 22 Dec  7 19:12 jenkins-log.txt
-rw-rw-r-- 1 jenkins jenkins  2 Dec  7 19:12 jenkins-result.txt
-rw-rw-r-- 1 jenkins jenkins  6 Dec  7 19:12 pid
-rwxr-xr-x 1 jenkins jenkins 33 Dec  7 19:12 script.sh
$ cat jenkins/workspace/team_agility_dev/.e7972254/jenkins-log.txt
+ rm -f snapshot.json
$ cat jenkins/workspace/team_agility_dev/.e7972254/jenkins-result.txt 
0
$ cat jenkins/workspace/team_agility_dev/.e7972254/pid                
26868
$ cat jenkins/workspace/team_agility_dev/.e7972254/script.sh 
#!/bin/sh -xe
rm -f snapshot.json
{noformat}

Also 
{{Jenkins.instance.getNode('qisrc').createPath('/home/jenkins/jenkins/workspace/team_agility_dev/.e7972254/jenkins-result.txt').exists()}} return true


Here is the durable task log, it starts from the previous test_workflow" hang at 
16:13:47.220+0000 then jumps to the new job a 18:58:58.789+0000 when I cancelled the hung one (which was blocking team_agility_dev since they compete for the same executor).

I skipped some parts with ellipsis.
At the very  end  you'll see that it reads from {{.e7972254/jenkins-log.txt}}
{noformat}
{noformat}


The "default" log is there: http://pastebin.com/jyiw33fL

jglick@cloudbees.com (JIRA)

не прочитано,
7 груд. 2015 р., 16:16:0207.12.15
Кому: jenkinsc...@googlegroups.com
Jesse Glick started work on Bug JENKINS-31769
 
Change By: Jesse Glick
Status: Open In Progress

scm_issue_link@java.net (JIRA)

не прочитано,
8 груд. 2015 р., 12:21:0108.12.15
Кому: jenkinsc...@googlegroups.com

Code changed in jenkins
User: Jesse Glick
Path:
durable-task-step/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java
http://jenkins-ci.org/commit/workflow-plugin/72e31bb07080d3a9d3e80ead616894ca95a526d9
Log:
JENKINS-31769 Prevent some problems with hanging sh steps.
Do not clear recurrentPeriod until the step has exited.
Do not call cleanup until the step has exited, and do not try to interrupt it.

scm_issue_link@java.net (JIRA)

не прочитано,
8 груд. 2015 р., 12:22:0308.12.15
Кому: jenkinsc...@googlegroups.com

Code changed in jenkins
User: Jesse Glick
Path:

CHANGES.md
durable-task-step/src/main/java/org/jenkinsci/plugins/workflow/steps/durable_task/DurableTaskStep.java
http://jenkins-ci.org/commit/workflow-plugin/7976e54ef63d3abbb43f615e72e87986ce36c4db
Log:
JENKINS-31769 Merging #268.

Compare: https://github.com/jenkinsci/workflow-plugin/compare/68e4b324f616...7976e54ef63d

barthelemy@crans.org (JIRA)

не прочитано,
8 груд. 2015 р., 17:25:0308.12.15
Кому: jenkinsc...@googlegroups.com

Hello Jesse, thank you for the quick fix.

Can you tell me which versions of jenkins and workflow I could use to test it before an official release?

Thank you again

jglick@cloudbees.com (JIRA)

не прочитано,
12 груд. 2015 р., 06:26:0112.12.15
Кому: jenkinsc...@googlegroups.com

WF 1.12-beta-3, as noted in WF changelog. Again, this fix is for one diagnosed root cause and may not address similar symptoms with dustinct root causes reported here or in other issues.

jglick@cloudbees.com (JIRA)

не прочитано,
1 лют. 2016 р., 03:25:0501.02.16
Кому: jenkinsc...@googlegroups.com
Jesse Glick resolved as Cannot Reproduce
 

I fixed a number of potentially related issues in 1.13.

Jenkins / Bug JENKINS-31769
Change By: Jesse Glick
Status: In Progress Resolved
Resolution: Cannot Reproduce
Відповісти всім
Відповісти автору
Переслати
0 нових повідомлень