Jenkins SCP publisher truncates console log transfers with 1.543

[Peter Portante]

The console log file for http://logs.openstack.org/96/61896/2/gate/gate-grenade-dsvm/5f10eb6/console.html appears cut off.

[Anita Kuno (anteaya)]

The last few lines of console.html

2013-12-14 13:20:26.492 | 2013-12-14 13:20:26 +++ for line in '$(<${fname})'
2013-12-14 13:20:26.494 | 2013-12-14 13:20:26 +++ [[ psmisc =~ NOPRIME ]]
2013-12-14 13:20:26.496 | 2013-12-14 13:20:26 +++ package=psmisc
2013-12-14 13:20:26.499 | 2013-12-14 13:20:26 +++ inst_pkg=1
2013-12-14 13:20:26.501 | 2013-12-14 13:20:26 +++ [[ psmisc =~ (.*)#.*dist:([^ ]*) ]]
2013-12-14 13:20:26.503 | 2013-12-14 13:20:26 +++ [[ psmisc =~ (.*)#.*testonly.* ]]
2013-12-14 13:20:26.506 | 2013-12-14 13:20:26 +++ [[ 1 = 1 ]]
2013-12-14 13:20:26.508 | 2013-12-14 13:20:26 +++ echo psmisc
2013-12-14 13:20:26.510 | 2013-12-14 13:20:26 +++ for line in '$(<${fname})'
2013-12-14 13:20:26.512 | 2013-12-14 13:20:26 +++ [[ git =~ NOPRIME ]]
2013-12-14 13:20:26.514 | 2013-12-14 13:20:26 +++ package=git
2013-12-14 13:20:26.516 | 2013-12-14 13:20:26 +++ inst_pkg=1
2013-12-14 13:20:26.518 | 2013-12-14 13:20:26 +++ [[ git =~ (.*)#.*dist:([^ ]*) ]]
2013-12-14 13:20:26.519 | 2013-12-14 13:20:26 +++ [[ git =~ (.*)#.*testonly.* ]]
2013-12-14 13:20:26.522 | 2013-12-14 13:20:26 +++ [[ 1 = 1 ]]
2013-12-14 13:20:26.524 | 2013-12-14 13:20:26 +++ echo git
2013-12-14 13:20:26.526 | 2013-12-14 13:20:26 +++ for line in '$(<${fname})'
2013-12-14 13:20:26.528 | 2013-12-14 13:20:26 +++ [[ lsof # useful when debugging =~ NOPRIME ]]
2013-12-14 13:20:26.530 | 2013-12-14 13:20:26 +++ package='lsof '
2013-12-14 13:20:26.532 | 2013-12-14 13:20:26 +++ inst_pkg=1
2013-12-14 13:20:26.534 | 2013-12-14 13:20:26 +++ [[ lsof # useful when debugging =~ (.*)#.*dist:([^ ]*) ]]
2013-12-14 13:20:26.536 | 2013-12-14 13:20:26 +++ [[ lsof # useful when debugging =~ (.*)#.*testonly.* ]]
2013-12-14 13:20:26.539 | 2013-12-14 13:20:26 +++ [[ 1 = 1 ]]
2013-12-14 13:20:26.540 | 2013-12-14 13:20:26 +++ echo 'lsof '
2013-12-14 13:20:26.542 | 2013-12-14 13:20:26 +++ for line in '$(<${fname})'
2013

[Jeremy Stanley (fungi)]

All examples brought to our attention seem to be associated with jobs which ran from jenkins01.openstack.org after we upgraded it from 1.525 to 1.543 yesterday (December 13th) around 23:50 UTC. Our best guess is that there is a new race condition introduced whereby the SCP publisher plugin is retrieving an incomplete/truncated versiobn of the console log from the Jenkins master. After downgrading jenkins01 back to 1.525 (to match jenkins02) at 17:25 UTC, spot checks indicate complete console logs from its subsequent jobs are being archived to the logs.openstack.org site once more.

[Jeremy Stanley (fungi)]

Note that this issue does not seem to have actually caused any job failures, but it does of course make them harder to diagnose since you have to go spelunking in jenkins01 for console logs and hope you catch them before the 24-hour expiration.

[Peter Portante (peter-a-portante)]

I agree, this does not cause any job failures, but I was not able to triage the job that did failed. So filed this bug both to cover the truncated logs and as a hook to reverify the failed gate job.

[Khai Do (zaro0508)]

I believe this issue has been fixed upstream: https://github.com/jenkinsci/scp-plugin/pull/8

[Clark Boylan (cboylan)]

The upstream pull request was merged by jeblair and we are running that updated plugin in production on our Jenkins masters. This work is done.