release: "5.1"
api: "1.0"
build_number: "369"
build_id: "2014-07-29_02-01-14"
astute_sha: "aa5aed61035a8dc4035ab1619a8bb540a7430a95"
fuellib_sha: "851b29ac6434c1671078ef293bb25a04dc492f49"
ostf_sha: "9c0454b2197756051fc9cee3cfd856cf2a4f0875"
nailgun_sha: "98ea1ce54f4d084e2533c7ea23aa98551f955ec5"
fuelmain_sha: "2379783517e4830868f66b5fbab512eec4695679"
With enabled patch https://review.openstack.org/#/c/104267/6 , which makes parallel run of 2nd and 3rd controllers, BVT test failed: http://jenkins-product.srt.mirantis.net:8080/job/fuel_master.ubuntu.bvt_2/208/.
less 10.108.0.2/var/log/docker-logs/astute/astute.log:
2014-07-29T00:47:40 debug: [372] f738b612-c864-425a-a99f-f70d01cebcdb: MC agent 'puppetd', method 'last_run_
summary', results: {:sender=>"2", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"running", :changes=>ni
l, :runtime=>1406591259, :enabled=>1, :events=>nil, :idling=>0, :version=>nil, :stopped=>0, :time=>{"last_ru
n"=>0}, :resources=>{"failed"=>1, "changed"=>0, "total"=>0, "out_of_sync"=>0, "restarted"=>0}, :lastrun=>0,
:running=>1, :output=>"Currently running; last completed run 1406591259 seconds ago"}}
2014-07-29T00:47:40 debug: [372] f738b612-c864-425a-a99f-f70d01cebcdb: MC agent 'puppetd', method 'last_run_
summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"running",
:runtime=>1406591260, :stopped=>0, :resources=>{"changed"=>0, "failed"=>1, "total"=>0, "restarted"=>0, "out_
of_sync"=>0}, :lastrun=>0, :version=>nil, :time=>{"last_run"=>0}, :changes=>nil, :running=>1, :enabled=>1, :
events=>nil, :output=>"Currently running; last completed run 1406591260 seconds ago"}}
2014-07-29T00:47:40 debug: [372] Nodes statuses: {"succeed"=>[], "error"=>[], "running"=>["2", "3"]}
2014-07-29T00:47:41 debug: [372] Got progress for nodes: [{"uid"=>"2", "progress"=>4}, {"uid"=>"3", "progres
s"=>4}]
2014-07-29T00:47:41 debug: [372] Data received by DeploymentProxyReporter to report it up: {"nodes"=>[{"uid"
=>"2", "progress"=>4, "status"=>"deploying", "role"=>"controller"}, {"uid"=>"3", "progress"=>4, "status"=>"d
eploying", "role"=>"controller"}]}
2014-07-29T00:48:25 debug: [372] f738b612-c864-425a-a99f-f70d01cebcdb: MC agent 'puppetd', method 'last_run_
summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"running",
:runtime=>1406591263, :stopped=>0, :resources=>{"changed"=>0, "failed"=>1, "total"=>0, "restarted"=>0, "out_
of_sync"=>0}, :lastrun=>0, :version=>nil, :time=>{"last_run"=>0}, :changes=>nil, :running=>1, :enabled=>1, :
events=>nil, :output=>"Currently running; last completed run 1406591263 seconds ago"}}
2014-07-29T00:48:25 debug: [372] f738b612-c864-425a-a99f-f70d01cebcdb: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"2", :statuscode=>5, :statusmsg=>"execution expired", :data=>{:changes=>nil, :events=>nil, :version=>nil, :time=>{"last_run"=>0}, :resources=>{"failed"=>1, "changed"=>0, "total"=>0, "out_of_sync"=>0, "restarted"=>0}}}
2014-07-29T00:48:25 err: [372] MCollective call failed in agent 'puppetd', method 'last_run_summary', failed nodes:
ID: 2 - Reason: execution expired
2014-07-29T00:48:25 err: [372] Timeout of deployment is exceeded.
It is unclear:
1) why execution expired
2) why astute gave up with timeout error?
According to logs, puppet continued to run:
less node-2.
"stop"
Mon Jul 28 23:49:15 +0000 2014 Service[
Mon Jul 28 23:49:15 +0000 2014 Service[
grep puppet node-2.
root 3789 8.7 11.5 443104 236652 ? Rs 23:40 0:46 /usr/bin/ruby /usr/bin/puppet apply /etc/puppet/
I could not find syslog for node-2, wondering where it is in snapshot...