Fuel for OpenStack

Orchestrator loses working puppet agent and declares it dead

Bug #1261276 reported by Vladimir Kuklin
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Fuel for OpenStack
Fix Released
High
Vladimir Sharshov
Fuel for OpenStack 4.0

Bug Description

CentOS HA Flat. Node-3 (compute) deployment fails.

Examining puppet and orchestrator logs shows that puppet was ran only once and the whole environment in system tests was snapshotted with puppet applying interfaces configuration. Anyway, naily.log shows that puppet hung, even though it was not hanging at all. Moreover, logs say that puppet failed on the node at the moment when it has not yet started.:

2013-12-16T01:49:21 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'uploadfile', method 'upload', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:msg=>"File was uploaded!"}}
2013-12-16T01:49:21 info: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: Required attrs/metadata passed via facts extension. Starting deployment.
2013-12-16T01:49:21 debug: [8972] Waiting for puppet to finish deployment on all
                           nodes (timeout = 3600 sec)...
2013-12-16T01:49:21 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"stopped", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158561, :enabled=>1, :idling=>0, :version=>nil, :output=>"Currently stopped; last completed run 1387158561 seconds ago", :changes=>nil, :stopped=>1}}
2013-12-16T01:49:21 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"stopped", :changes=>nil, :stopped=>1, :time=>{"last_run"=>0}, :resources=>{"changed"=>0, "out_of_sync"=>0, "failed"=>1, "restarted"=>0, "total"=>0}, :events=>nil, :lastrun=>0, :running=>0, :runtime=>1387158561, :version=>nil, :enabled=>1, :output=>"Currently stopped; last completed run 1387158561 seconds ago"}}
2013-12-16T01:49:21 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"stopped", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158561, :enabled=>1, :idling=>0, :version=>nil, :output=>"Currently stopped; last completed run 1387158561 seconds ago", :changes=>nil, :stopped=>1}}
2013-12-16T01:49:21 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"stopped", :changes=>nil, :stopped=>1, :time=>{"last_run"=>0}, :resources=>{"changed"=>0, "out_of_sync"=>0, "failed"=>1, "restarted"=>0, "total"=>0}, :events=>nil, :lastrun=>0, :running=>0, :runtime=>1387158561, :version=>nil, :enabled=>1, :output=>"Currently stopped; last completed run 1387158561 seconds ago"}}
2013-12-16T01:49:22 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'runonce', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"stopped", :stopped=>1, :lastrun=>0, :running=>0, :runtime=>1387158561, :enabled=>1, :output=>"Called /usr/sbin/daemonize -a -e /var/log/puppet/puppet.err -o /var/log/puppet/puppet.log -l /tmp/puppetd.lock -p /tmp/puppetd.lock /usr/bin/puppet apply /etc/puppet/manifests/site.pp --logdest syslog --trace --debug, Currently stopped; last completed run 1387158561 seconds ago"}}
2013-12-16T01:49:22 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'runonce', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"stopped", :lastrun=>0, :running=>0, :runtime=>1387158561, :enabled=>1, :idling=>0, :output=>"Called /usr/sbin/daemonize -a -e /var/log/puppet/puppet.err -o /var/log/puppet/puppet.log -l /tmp/puppetd.lock -p /tmp/puppetd.lock /usr/bin/puppet apply /etc/puppet/manifests/site.pp --logdest syslog --trace --debug, Currently stopped; last completed run 1387158561 seconds ago", :stopped=>1}}
2013-12-16T01:49:22 debug: [8972] puppetd_runonce completed within 1 seconds.
2013-12-16T01:49:22 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"running", :changes=>nil, :stopped=>0, :time=>{"last_run"=>0}, :resources=>{"changed"=>0, "out_of_sync"=>0, "failed"=>1, "restarted"=>0, "total"=>0}, :events=>nil, :lastrun=>0, :running=>1, :runtime=>1387158562, :version=>nil, :enabled=>1, :output=>"Currently running; last completed run 1387158562 seconds ago"}}
2013-12-16T01:49:22 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"stopped", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :err_msg=>"Process not running but not empty lockfile is present. Trying to remove lockfile...ok.", :runtime=>1387158562, :enabled=>1, :idling=>0, :version=>nil, :output=>"Currently stopped; last completed run 1387158562 seconds ago", :changes=>nil, :stopped=>1}}
2013-12-16T01:49:22 debug: [8972] Nodes statuses: {"succeed"=>[], "error"=>["3"], "running"=>["5"]}
2013-12-16T01:49:22 debug: [8972] Puppet on node "3" will be restarted. 1 retries remained.
2013-12-16T01:49:22 debug: [8972] Can't read file with logs: /var/log/remote/node-5.test.domain.local/puppet-apply.log
2013-12-16T01:49:22 debug: [8972] Got progress for nodes: [{"uid"=>"5", "progress"=>0}]
2013-12-16T01:49:22 debug: [8972] Data received by DeploymentProxyReporter to report it up: {"nodes"=>[{"uid"=>"5", "progress"=>0, "status"=>"deploying", "role"=>"compute"}]}
2013-12-16T01:49:22 info: [8972] Retrying to run puppet for following error nodes: 3
2013-12-16T01:49:22 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158562, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158562 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:28 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158568, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158568 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:33 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158573, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158573 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:38 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158578, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158578 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:43 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158583, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158583 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:48 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158588, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158588 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:54 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158594, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158594 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:49:59 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158599, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158599 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:04 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158604, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158604 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:09 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158609, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158609 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:14 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158614, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158614 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:19 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158619, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158619 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:24 debug: [8972] puppetd_runonce completed within 62 seconds.
2013-12-16T01:50:24 warning: [8972] Following nodes have puppet hung: '3'
2013-12-16T01:50:26 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158626, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158626 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:26 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"running", :changes=>nil, :stopped=>0, :time=>{"last_run"=>0}, :resources=>{"changed"=>0, "out_of_sync"=>0, "failed"=>1, "restarted"=>0, "total"=>0}, :events=>nil, :lastrun=>0, :running=>1, :runtime=>1387158626, :version=>nil, :enabled=>1, :output=>"Currently running; last completed run 1387158626 seconds ago"}}
2013-12-16T01:50:26 debug: [8972] Nodes statuses: {"succeed"=>[], "error"=>["3"], "running"=>["5"]}
2013-12-16T01:50:26 debug: [8972] Puppet on node "3" will be restarted. 0 retries remained.
2013-12-16T01:50:26 debug: [8972] Got progress for nodes: [{"uid"=>"5", "progress"=>0}]
2013-12-16T01:50:26 debug: [8972] Data received by DeploymentProxyReporter to report it up: {"nodes"=>[{"uid"=>"5", "progress"=>0, "status"=>"deploying", "role"=>"compute"}]}
2013-12-16T01:50:26 info: [8972] Retrying to run puppet for following error nodes: 3
2013-12-16T01:50:27 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158627, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158627 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:32 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158632, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158632 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:37 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158637, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158637 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:42 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158642, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158642 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:47 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158647, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158647 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:52 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158652, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158652 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:50:57 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158657, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158657 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:02 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158662, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158662 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:08 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158668, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158668 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:13 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158673, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158673 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:19 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158679, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158679 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:24 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158684, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158684 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:29 debug: [8972] puppetd_runonce completed within 63 seconds.
2013-12-16T01:51:29 warning: [8972] Following nodes have puppet hung: '3'
2013-12-16T01:51:31 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"3", :statuscode=>0, :statusmsg=>"OK", :data=>{:status=>"idling", :resources=>{"failed"=>1, "total"=>0, "restarted"=>0, "out_of_sync"=>0, "changed"=>0}, :events=>nil, :lastrun=>0, :time=>{"last_run"=>0}, :running=>0, :runtime=>1387158691, :enabled=>1, :idling=>1, :version=>nil, :output=>"Currently idling; last completed run 1387158691 seconds ago", :changes=>nil, :stopped=>0}}
2013-12-16T01:51:31 debug: [8972] 65e92a76-7a6d-46ec-98a7-75ef45cd4972: MC agent 'puppetd', method 'last_run_summary', results: {:sender=>"5", :statuscode=>0, :statusmsg=>"OK", :data=>{:idling=>0, :status=>"running", :changes=>nil, :stopped=>0, :time=>{"last_run"=>0}, :resources=>{"changed"=>0, "out_of_sync"=>0, "failed"=>1, "restarted"=>0, "total"=>0}, :events=>nil, :lastrun=>0, :running=>1, :runtime=>1387158691, :version=>nil, :enabled=>1, :output=>"Currently running; last completed run 1387158691 seconds ago"}}
2013-12-16T01:51:31 debug: [8972] Nodes statuses: {"succeed"=>[], "error"=>["3"], "running"=>["5"]}

Morevoer, naily says it restarted puppet, that is not true.

Tags: orchestrator
Vladimir Kuklin (vkuklin)
Changed in fuel:
assignee: nobody → Vladimir Sharshov (vsharshov)
Revision history for this message
Vladimir Kuklin (vkuklin) wrote :
Revision history for this message
Vladimir Kuklin (vkuklin) wrote :

looks like the problem is that naily treats node as hang during networking configuration phase

Revision history for this message
Vladimir Sharshov (vsharshov) wrote :

Vladimir, thanks!

Now this is expected behavior (error) instead of success for such situations: #1256244.

Now we should try to find reason why astute think what puppet is dead when its live and run.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to fuel-astute (master)

Fix proposed to branch: master
Review: https://review.openstack.org/62343

Changed in fuel:
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to fuel-astute (master)

Reviewed: https://review.openstack.org/62343
Committed: https://git.openstack.org/cgit/stackforge/fuel-astute/commit/?id=f6551811846c9e21d9bee04562e4eef4347b22c0
Submitter: Jenkins
Branch: master

commit f6551811846c9e21d9bee04562e4eef4347b22c0
Author: Vladimir <email address hidden>
Date: Mon Dec 16 16:25:45 2013 +0400

    New behavior for idealing puppet state

    * Kill process instead of send USR1 signal;
    * Increase time to examine running process from 60 to 120 sec;
    * Increase time between last_run request from 5 to 10 sec.

    Change-Id: I3fce9ac162a0201f7dc7062dead3350f55e350fc
    Closes-Bug: #1261276

Changed in fuel:
status: In Progress → Fix Committed
Dmitry Pyzhov (dpyzhov)
Changed in fuel:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.