Puppet: System Administration Automated

Support

Ticket #1199 (new defect)

Opened 8 months ago

Last modified 6 months ago

puppetd dies after connection to puppetmaster fails

Reported by: immerda Assigned to: andrew
Priority: normal Milestone: 0.24.5
Component: executables Version: 0.24.4
Severity: normal Keywords: daemon, die, no connection
Cc: Triage Stage: Needs more info
Attached Patches: None Complexity: Unknown

Description

We had now several times the problem that when our puppetmaster died (due to some memory problems) all our clients daemons just stopped running and exited. We then had to manually restart all daemons.

Sample log entry from a client: 

Sun Apr 20 06:24:32 +0200 2008 Puppet (notice): Finished catalog run in 45.93 seconds
Sun Apr 20 06:56:32 +0200 2008 Puppet (err): Could not retrieve plugins: execution expired
Sun Apr 20 06:58:32 +0200 2008 Puppet (err): Configuration retrieval timed out
Sun Apr 20 06:58:33 +0200 2008 Puppet (notice): Starting catalog run

this is the last entry after that puppetd isn't running anymore. It seems that puppetd is failling after sending the message benchmark in lib/puppet/network/client/master.rb on line 234. I tried to nail this problem down to propose a patch for it, however my puppet internal knowledge isn't yet that fine to really see where the problem actually raises. It might be due to some (unlogged) failure in benchmark or even later.

Change History

04/24/08 01:38:37 changed by jamtur01

  • stage changed from Unreviewed to Needs more info.

Can you provide a --trace?

04/24/08 01:44:06 changed by jamtur01

Also plays into #1190.

04/24/08 07:27:08 changed by luke

  • component changed from library to executables.

04/25/08 13:01:27 changed by immerda

So what actually I didn't get it that puppetd was crashing in trace and nodaemonize mode. However the behaviour I found out is in my opinion as well not the expected one.

Test Setup: puppetd 0.24.4 run in no-daemon and trace mode. After It got one correct run, I added my puppetmaster's address to 127.0.0.1 in /etc/hosts, in my opinion this should be the same as if the puppetmaster goes away. After that in the next run it spit some traces, and then I removed the /etc/hosts entry. puppetd never exited, however in the next run it still didn't get back to the normal behaviour (connecting to the puppetmaster) it just sit there and did nothing. Running it for around a day in a screen spit out a second trace message, but still not connecting to the puppetmaster. after relaunching the puppetd, it is connecting again fine to the master.

here are the traces: 

[root@host ~]# /usr/sbin/puppetd --server=puppet.domain.ch --logdest=/var/log/puppet/puppet.log --report --trace --no-daemonize
/usr/lib/ruby/site_ruby/1.8/puppet/network/xmlrpc/client.rb:59:in `list'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/proxy.rb:15:in `send'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/proxy.rb:15:in `list'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:862:in `sourcerecurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:853:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:853:in `sourcerecurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:719:in `recurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:340:in `eval_generate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:192:in `eval_generate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:227:in `eval_resource'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:309:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:445:in `thinmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:444:in `thinmark'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:308:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:302:in `collect'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:302:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/node/catalog.rb:118:in `apply'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:339:in `download'
/usr/lib/ruby/1.8/timeout.rb:56:in `timeout'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:338:in `download'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:394:in `getplugins'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:201:in `getplugins'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:149:in `getconfig'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:253:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:445:in `thinmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:444:in `thinmark'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:252:in `run'
/usr/lib/ruby/1.8/sync.rb:229:in `synchronize'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:245:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client.rb:136:in `runnow'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client.rb:179:in `start'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `call'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `__signal__'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `__signal__'
(eval):2:in `signal'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:321:in `sound_alarm'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `select'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `select'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:116:in `iterate'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:107:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet.rb:363:in `start'
/usr/sbin/puppetd:459

--- second trace (many hours later, but with correct /etc/hosts entry) ----

/usr/lib/ruby/site_ruby/1.8/puppet/network/xmlrpc/client.rb:59:in `list'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/proxy.rb:15:in `send'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/proxy.rb:15:in `list'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:862:in `sourcerecurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:853:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:853:in `sourcerecurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:719:in `recurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:340:in `eval_generate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:192:in `eval_generate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:227:in `eval_resource'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:309:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:445:in `thinmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:444:in `thinmark'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:308:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:302:in `collect'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:302:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/node/catalog.rb:118:in `apply'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:264:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:212:in `benchmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:211:in `benchmark'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:263:in `run'
/usr/lib/ruby/1.8/sync.rb:229:in `synchronize'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:245:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client.rb:136:in `runnow'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client.rb:179:in `start'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `call'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `__signal__'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `__signal__'
(eval):2:in `signal'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:321:in `sound_alarm'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `select'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `select'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:116:in `iterate'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:107:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet.rb:363:in `start'
/usr/sbin/puppetd:459
/usr/lib/ruby/site_ruby/1.8/puppet/network/xmlrpc/client.rb:59:in `list'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/proxy.rb:15:in `send'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/proxy.rb:15:in `list'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:862:in `sourcerecurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:853:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:853:in `sourcerecurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:719:in `recurse'
/usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:340:in `eval_generate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:192:in `eval_generate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:227:in `eval_resource'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:309:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:445:in `thinmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:444:in `thinmark'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:308:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:302:in `collect'
/usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:302:in `evaluate'
/usr/lib/ruby/site_ruby/1.8/puppet/node/catalog.rb:118:in `apply'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:264:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:212:in `benchmark'
/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/usr/lib/ruby/site_ruby/1.8/puppet/util.rb:211:in `benchmark'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:263:in `run'
/usr/lib/ruby/1.8/sync.rb:229:in `synchronize'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:245:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client.rb:136:in `runnow'
/usr/lib/ruby/site_ruby/1.8/puppet/network/client.rb:179:in `start'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `call'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `__signal__'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in `__signal__'
(eval):2:in `signal'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:321:in `sound_alarm'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `select'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `each'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:130:in `select'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:116:in `iterate'
/usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:107:in `run'
/usr/lib/ruby/site_ruby/1.8/puppet.rb:363:in `start'
/usr/sbin/puppetd:459

---- end ----

actually it looks like there are 2 traces the second time. When shutting down the no-daemonized run I saw the following logmessage: 

Fri Apr 25 12:47:21 +0200 2008 Puppet (notice): Finished catalog run in 73057.11 seconds

the rest of the log is wasted by errors that it couldn't find sources for files. If you need additional infos, please letme know.

05/08/08 16:28:06 changed by luke

  • milestone set to 0.24.5.

05/26/08 07:36:08 changed by andrew

  • owner changed from community to andrew.