alcc@gmx.de
2013-Jan-02 13:55 UTC
[Puppet Users] puppet master keeps spawning new child processes
Hi, running a puppet master managing 15-20 agents. When I start the puppetmaster service system load will stay around 2 for a couple of minutes (sometimes hours). Then after a while (sometimes sooner, sometimes later) system load increases and puppetmaster process keeps spawning child processes - biggest number I''ve seen so far: ~ 20. Since each spawned puppetmaster process causes 100% load on a core, system performance will immensely get affected sooner or later. Is this child process spawning normal behavior? Assuming catalog compiling (or whatever) really is so CPU consuming - why does it work after service restart at the beginning sometimes even for a couple of hours before new puppetmaster child processes appear and system load increases? Thanks in advance, Christian. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/zN_sDAFKntMJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-02 14:19 UTC
[Puppet Users] Re: puppet master keeps spawning new child processes
> rpm -qa | egrep "puppet|ruby"rubygem-rake-0.8.7-2.1.el6.noarch ruby-mysql-2.8.2-1.el6.x86_64 libselinux-ruby-2.0.94-5.3.el6.x86_64 puppet-3.0.2-1.el6.noarch puppet-dashboard-1.2.16-1.el6.noarch ruby-1.8.7.352-7.el6_2.x86_64 ruby-irb-1.8.7.352-7.el6_2.x86_64 rubygems-1.3.7-1.el6.noarch ruby-augeas-0.4.1-1.el6.x86_64 ruby-shadow-1.4.1-13.el6.x86_64 puppet-server-3.0.2-1.el6.noarch puppetlabs-release-6-6.noarch ruby-libs-1.8.7.352-7.el6_2.x86_64 ruby-rdoc-1.8.7.352-7.el6_2.x86_64 rubygem-json-1.4.6-1.el6.x86_64> cat /etc/redhat-releaseCentOS release 6.3 (Final) -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/Y3E2a3F1O6EJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-03 10:36 UTC
[Puppet Users] Re: puppet master keeps spawning new child processes
When having more than one process...> ps faux | grep "puppet master" | grep -v greppuppet 5100 92.0 2.7 427180 329728 ? Rsl 09:22 119:27 /usr/bin/ruby /usr/bin/puppet master puppet 11957 99.9 1.6 300168 200224 ? R 10:07 83:53 \_ /usr/bin/ruby /usr/bin/puppet master ... strace-ing first process shows lot of system calls going on> strace -v -p 5100 2>&1 | head -n100Process 5100 attached - interrupt to quit ioctl(8, FIONREAD, [89]) = 0 recvfrom(8, "\30\244\205\200\0\1\0\1\0\0\0\0\003224\003150\00220\003172\7in-a"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.20.60.12")}, [16]) = 89 close(8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 getsockname(6, {sa_family=AF_INET, sin_port=htons(8140), sin_addr=inet_addr("172.20.150.201")}, [16]) = 0 open("/etc/hosts", O_RDONLY|O_CLOEXEC) = 8 fstat(8, {st_dev=makedev(253, 0), st_ino=2490395, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=158, st_atime=2013/01/03-11:06:35, st_mtime=2010/01/12-14:28:22, st_ctime=2012/10/24-12:05:48}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd177a16000 read(8, "127.0.0.1 localhost localhost."..., 4096) = 158 read(8, "", 4096) = 0 close(8) = 0 munmap(0x7fd177a16000, 4096) = 0 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 8 connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.20.60.12")}, 16) = 0 poll([{fd=8, events=POLLOUT}], 1, 0) = 1 ([{fd=8, revents=POLLOUT}]) sendto(8, "\364\266\1\0\0\1\0\0\0\0\0\0\003201\003150\00220\003172\7in-a"..., 45, MSG_NOSIGNAL, NULL, 0) = 45 poll([{fd=8, events=POLLIN}], 1, 5000) = 1 ([{fd=8, revents=POLLIN}]) ioctl(8, FIONREAD, [90]) = 0 recvfrom(8, "\364\266\205\200\0\1\0\1\0\0\0\0\003201\003150\00220\003172\7in-a"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.20.60.12")}, [16]) = 90 close(8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 select(6, [5], [], [], {0, 0}) = 1 (in [5], left {0, 0}) rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 select(6, [5], [], [], {0, 0}) = 1 (in [5], left {0, 0}) rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 select(6, [5], [], [], {0, 0}) = 1 (in [5], left {0, 0}) rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 accept(5, {sa_family=AF_INET, sin_port=htons(58015), sin_addr=inet_addr("172.20.150.232")}, [16]) = 8 fcntl(8, F_GETFL) = 0x2 (flags O_RDWR) fstat(8, {st_dev=makedev(0, 6), st_ino=81435612, st_mode=S_IFSOCK|0777, st_nlink=1, st_uid=52, st_gid=52, st_blksize=4096, st_blocks=0, st_size=0, st_atime=0, st_mtime=0, st_ctime=0}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd177a16000 lseek(8, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) fcntl(8, F_GETFL) = 0x2 (flags O_RDWR) fstat(8, {st_dev=makedev(0, 6), st_ino=81435612, st_mode=S_IFSOCK|0777, st_nlink=1, st_uid=52, st_gid=52, st_blksize=4096, st_blocks=0, st_size=0, st_atime=0, st_mtime=0, st_ctime=0}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd177a15000 lseek(8, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 fcntl(8, F_GETFL) = 0x2 (flags O_RDWR) fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 fcntl(8, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 fcntl(8, F_GETFD) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 getpeername(8, {sa_family=AF_INET, sin_port=htons(58015), sin_addr=inet_addr("172.20.150.232")}, [16]) = 0 open("/etc/hosts", O_RDONLY|O_CLOEXEC) = 9 fstat(9, {st_dev=makedev(253, 0), st_ino=2490395, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=158, st_atime=2013/01/03-11:06:35, st_mtime=2010/01/12-14:28:22, st_ctime=2012/10/24-12:05:48}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd177a14000 read(9, "127.0.0.1 localhost localhost."..., 4096) = 158 read(9, "", 4096) = 0 close(9) = 0 ... strace-ing child process shows nothing... strace -v -p 11957 Process 11957 attached - interrupt to quit Will watch this for some time now - but so far (~30 minutes) didn''t see anything going on. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/uXAQOYwbIdkJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-03 10:39 UTC
[Puppet Users] Re: puppet master keeps spawning new child processes
> ... strace-ing child process shows nothing... > > strace -v -p 11957 > Process 11957 attached - interrupt to quit > > > Will watch this for some time now - but so far (~30 minutes) didn''t see > anything going on. > > Any other idea about how to find out what process 11957 actually isdoing? -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/3uMC9DVv6loJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
R.I.Pienaar
2013-Jan-03 10:41 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
----- Original Message -----> From: alcc@gmx.de > To: puppet-users@googlegroups.com > Sent: Thursday, January 3, 2013 10:36:35 AM > Subject: [Puppet Users] Re: puppet master keeps spawning new child processes > > When having more than one process... > > > ps faux | grep "puppet master" | grep -v grep > puppet 5100 92.0 2.7 427180 329728 ? Rsl 09:22 119:27 > /usr/bin/ruby /usr/bin/puppet master > puppet 11957 99.9 1.6 300168 200224 ? R 10:07 83:53 \_ > /usr/bin/ruby /usr/bin/puppet master > > > ... strace-ing first process shows lot of system calls going onyou''d probably have to strace it around the time it does the fork to get useful information. Do you have any custom parser functions perhaps that might be running external commands? or use the generate() function much? I am not sure if the generate function actually forks like this but it''s worth seeing if you use it. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-03 10:59 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
Am Donnerstag, 3. Januar 2013 11:41:21 UTC+1 schrieb R.I. Pienaar:> > > > ----- Original Message ----- > > From: al...@gmx.de <javascript:> > > To: puppet...@googlegroups.com <javascript:> > > Sent: Thursday, January 3, 2013 10:36:35 AM > > Subject: [Puppet Users] Re: puppet master keeps spawning new child > processes > > > > When having more than one process... > > > > > ps faux | grep "puppet master" | grep -v grep > > puppet 5100 92.0 2.7 427180 329728 ? Rsl 09:22 119:27 > > /usr/bin/ruby /usr/bin/puppet master > > puppet 11957 99.9 1.6 300168 200224 ? R 10:07 83:53 \_ > > /usr/bin/ruby /usr/bin/puppet master > > > > > > ... strace-ing first process shows lot of system calls going on > > you''d probably have to strace it around the time it does the fork to get > useful > information. >I''ll try to do that... somehow...> Do you have any custom parser functions perhaps that might be running > external > commands? or use the generate() function much? I am not sure if the > generate > function actually forks like this but it''s worth seeing if you use it. >Not that I know of... AFAIK I don''t have any custom parser functions and I must admit that I don''t even know what the generate() function is or does. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/9oHHYLDYCuMJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-03 11:22 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
After monitoring the "Father" process a bit more I realized that it often happens that new processes are created - usually they don''t live long.> strace -f -v -p 5100 -o /tmp/strace.5100.logProcess 5100 attached with 2 threads - interrupt to quit Process 18702 detached Process 19996 attached Process 19997 attached Process 19998 attached Process 19998 detached Process 20160 attached (waiting for parent) Process 20160 resumed (parent 19996 ready) Process 20160 detached Process 19996 detached Process 19997 detached Process 20636 attached Process 20637 attached Process 20638 attached Process 20638 detached Process 20814 attached Process 20814 detached Process 20636 detached Process 20637 detached Process 20925 attached (waiting for parent) Process 20925 resumed (parent 5100 ready) Process 20926 attached Process 20927 attached Process 20927 detached Process 21119 attached (waiting for parent) Process 21119 resumed (parent 20925 ready) Process 21119 detached Process 21125 attached (waiting for parent) Process 21125 resumed (parent 20925 ready) Process 21125 detached Process 20925 detached [... and so on... ] I just killed this Child-Process using kill -9 - Puppetmaster still runs... no complains in the log. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/Orxl9SeNKlMJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
Brian Lalor
2013-Jan-03 11:25 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
On Jan 3, 2013, at 5:39 AM, alcc@gmx.de wrote:> Any other idea about how to find out what process 11957 actually is doing?There''s another flag to strace, -f, if I recall correctly, that will follow forks of children. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-03 12:47 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
> There''s another flag to strace, -f, if I recall correctly, that will > follow forks of children. >straced father process (pid 14850) using -f, caught the moment when a process was spawned that didn''t go away and stayed at 100% cpu load (pid 18915). It''s a lot output so I grep''ed for child process pid 18915 and piped it to | sort -u for a first look. Sorted/uniqued output: http://pkqs.net/~cf/strace_14850_child-18915_sort-u.log Whole output just grep''ed for child process pid: http://pkqs.net/~cf/strace_14850_child-18915.log -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/nSRz8zeVVP4J. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-04 12:17 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
Disabling puppet dashboard helped - 12 hours without any "frozen" 100% child process. Now investigating if it''s dashboard''s external node command.>-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/okUymmaneZQJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
alcc@gmx.de
2013-Jan-07 10:03 UTC
Re: [Puppet Users] Re: puppet master keeps spawning new child processes
Am Freitag, 4. Januar 2013 13:17:46 UTC+1 schrieb al...@gmx.de:> Disabling puppet dashboard helped - 12 hours without any "frozen" 100% > child process. Now investigating if it''s dashboard''s external node command.Commenting out ENC-related lines in puppet.conf fixed this. Calling the external command was the cause for spawned child processes in the first place. Don''t need ENC anyway. It''s all peachy now. Thx! -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To view this discussion on the web visit https://groups.google.com/d/msg/puppet-users/-/XytwkISaZusJ. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.