Jira (PUP-5389) PID race condition allows two puppet instances, which can result in failure to request certificate

[Ioannis (JIRA)]

Title: Message Title

Ioannis created an issue   Puppet / PUP-5389 PID race condition allows two puppet instances, which can result in failure to request certificate Issue Type: Bug Affects Versions: PUP 3.3.2 Assignee: Unassigned Components: Puppet Server Created: 2015/10/16 10:37 AM Environment: OS: RHEL6.6 Puppet: 3.3.2 mcollective-puppet-agent: 1.10.0 [root@node1 ~]# lscpu Architecture: x86_64 CPU op-mode(s): 32-bit, 64-bit Byte Order: Little Endian CPU(s): 2 On-line CPU(s) list: 0,1 Thread(s) per core: 1 Core(s) per socket: 1 Socket(s): 2 NUMA node(s): 1 Vendor ID: GenuineIntel CPU family: 6 Model: 26 Stepping: 4 CPU MHz: 2600.000 BogoMIPS: 5200.00 Virtualization: VT-x Hypervisor vendor: VMware Virtualization type: full L1d cache: 32K L1i cache: 32K L2 cache: 256K L3 cache: 20480K NUMA node0 CPU(s): 0,1 [root@node1 ~]# free -m total used free shared buffers cached Mem: 1742 1020 721 0 90 316 -/+ buffers/cache: 613 1129 Swap: 2047 0 2047 Priority: Normal Reporter: Ioannis By using mcollective's puppet agent, we're triggering puppet to retrieve and apply the new catalog (mco puppet runonce) while the puppet daemon is idle. This has been automated and sometimes can happen while a node is rebooting. During the start-up, mcollective starts first (S24) and can receive and execute the mco puppet call about the same time the daemon is starting (S98). If agent.pid file is not detected by the mcollective agent, it proceeds executing puppet agent --onetime. There's a time window from the moment puppet starts until it creates the pid file, which the mcollective agent could miss the fact that a puppet process is already running and start another instance of the puppet agent. Normally this doesn't result in a bad state, since a second lock is acquired before applying the catalog. But if the certificates aren't generated yet, both instances are attempting a certificate request, which result in failure to sign them. Oct 16 18:17:19 node1 puppet-agent[52032]: Reopening log files Oct 16 18:17:20 node1 puppet-agent[52032]: Creating a new SSL key for node1.p.com Oct 16 18:17:20 node1 puppet-agent[52026]: Creating a new SSL key for node1.p.com Oct 16 18:17:20 node1 puppet-agent[52032]: Creating a new SSL certificate request for node1.p.com Oct 16 18:17:20 node1 puppet-agent[52032]: Certificate Request fingerprint (SHA256): 29:7D:9B:17:88:03:F0:DA:B1:86:CC:21:0A:C0:D0:9F:4A:92:03:1C:F1:19:0E:6A:B7:7C:7E:F1:66:02:EA:4B Oct 16 18:17:20 node1 puppet-agent[52032]: Caching certificate for node1.p.com Oct 16 18:17:20 node1 puppet-agent[52032]: Starting Puppet client version 3.3.2 Oct 16 18:17:20 node1 puppet-agent[52047]: Retrieving plugin Oct 16 18:17:22 node1 puppet-agent[52026]: Could not request certificate: The certificate retrieved from the master does not match the agent's private key. Oct 16 18:17:22 node1 puppet-agent[52026]: Certificate fingerprint: 2E:BC:7A:5F:D8:FB:33:03:CD:BC:CB:68:59:B5:BD:75:86:37:A9:62:2C:84:53:7F:D9:90:10:50:62:B1:32:59 Oct 16 18:17:22 node1 puppet-agent[52026]: To fix this, remove the certificate from both the master and the agent and then start a puppet run, which will automatically regenerate a certficate. Oct 16 18:17:22 node1 puppet-agent[52026]: On the master: Oct 16 18:17:22 node1 puppet-agent[52026]: puppet cert clean node1.p.com Oct 16 18:17:22 node1 puppet-agent[52026]: On the agent: Oct 16 18:17:22 node1 puppet-agent[52026]: rm -f /var/lib/puppet/ssl/certs/node1.p.com.pem Oct 16 18:17:22 node1 puppet-agent[52026]: puppet agent -t This is surprisingly easy to reproduce manually, as it seems that it takes more than 1 second from the moment puppet starts until a pid file is created. Here's a normal startup with a bit of additional log messages Oct 16 15:59:42 node1 puppet-agent: About to run puppet. Time: 1445007582.080518313 Oct 16 15:59:43 node1 puppet-agent[30750]: daemonizing Oct 16 15:59:43 node1 puppet-agent[30755]: Time: 1445007583.30188 About to create PID file /var/run/puppet/agent.pid Oct 16 15:59:43 node1 puppet-agent[30755]: Reopening log files Oct 16 15:59:43 node1 puppet-agent[30755]: Starting Puppet client version 3.3.2 Oct 16 15:59:43 node1 puppet-agent[30755]: Setting signal traps Oct 16 15:59:43 node1 puppet-agent[30755]: Time: 1445007583.58079 About to create PID file /var/run/puppet/agent.pid Oct 16 15:59:43 node1 puppet-agent[30764]: Retrieving plugin ... Add Comment   This message was sent by Atlassian JIRA (v6.4.11#64026-sha1:78f6ec4) -- You received this message because you are subscribed to the Google Groups "Puppet Bugs" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-bugs+unsubscr...@googlegroups.com. To post to this group, send email to puppet-bugs@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-bugs. For more options, visit https://groups.google.com/d/optout.