Re: Failed to Allocate Memory When Connected to LDAP
James Lee
> Hello,
>
> I have a Solaris 10 system running Puppet 2.6.8 that is experiencing a
> very unusual problem. It has been running fine up until I configured
> the system to use LDAP for users and groups. The problem is easily
> reproducible. Take "ldap" out of /etc/nsswitch.conf and it runs fine,
> once it's added back in, Puppet crashes:
I've narrowed down what is triggering this problem, but I still do not
know how to fix it.
I created a barebones node configuration:
> node 'acad.es.gwu.edu'
> {
> package { "SUNWzsh":
> ensure => "installed",
> provider => "sun",
> }
>
> notify { "SUNWzsh is installed":
> require => Package["SUNWzsh"],
> }
> }
The 'package' resource will cause Puppet to crash with:
> acad ~ # puppet agent --test --environment=jameslee --no-report --noop
> /opt/csw/lib/ruby/gems/1.8/gems/puppet-2.6.12/lib/puppet/provider/package/apt.rb:15:in `[]=': failed to allocate memory (NoMemoryError)
> from /opt/csw/lib/ruby/gems/1.8/gems/puppet-2.6.12/lib/puppet/provider/package/apt.rb:15
> ...
Any other resource in the node configuration and Puppet runs without
complaint. For example, I can manage users and everything. The weird
thing is, once I disable 'ldap' in /etc/nsswitch.conf, Puppet will run
with the packages resource too:
> acad ~ # puppet agent --test --environment=jameslee --no-report --noop
> info: Caching catalog for acad.es.gwu.edu
> info: Applying configuration version '1327080824'
> notice: /Stage[main]//Node[acad.es.gwu.edu]/Notify[SUNWzsh is installed]/message: current_value absent, should be SUNWzsh is installed (noop)
> notice: Finished catalog run in 4.66 seconds
WEIRD! So I took a look at the 'apt.rb' file from the stack trace above
and see that it is failing trying to set an environmental variable. To
see whether it was that line or something else, I added:
> ENV["TEST"] = "foo"
to the very first line of the file. Should be harmless, but lo and behold:
> acad ~ # puppet agent --test --environment=jameslee --no-report --noop
> /opt/csw/lib/ruby/gems/1.8/gems/puppet-2.6.12/lib/puppet/provider/package/apt.rb:1:in `[]=': failed to allocate memory (NoMemoryError)
Just trying to set the environmental variable crashed Puppet. Next, to
see if 'ENV' was really growing out of control, I added 'p ENV' to the
top of 'apt.rb' and the result wasn't anything out of the ordinary:
> acad ~ # puppet agent --test --environment=jameslee --no-report --noop
> {"_"=>"/usr/local/bin/puppet", "PAGER"=>"less", "EDITOR"=>"vim",
> "OLDPWD"=>"/opt/csw/lib/ruby/gems/1.8/gems/puppet-2.6.12/lib",
> "PWD"=>"/export/home/jameslee", "SHLVL"=>"1",
> "HOME"=>"/export/home/jameslee",
> "PATH"=>"/usr/local/sbin:/usr/local/bin:/opt/csw/sbin:/opt/csw/bin:/usr/sfw/bin:/usr/sbin:/usr/bin:/sbin:/bin",
> "MAIL"=>"/var/mail//jameslee", "TZ"=>"US/Eastern", "LANG"=>"C",
> "TERM"=>"xterm", "DISPLAY"=>"localhost:13.0", "SHELL"=>"/bin/zsh",
> "LOGNAME"=>"root", "USER"=>"root", "SUDO_COMMAND"=>"/bin/zsh",
> "SUDO_USER"=>"jameslee", "SUDO_UID"=>"19374", "SUDO_GID"=>"14"}
> /opt/csw/lib/ruby/gems/1.8/gems/puppet-2.6.12/lib/puppet/provider/package/apt.rb:2:in `[]=': failed to allocate memory (NoMemoryError)
I don't understand how setting ENV variables is fine without LDAP and
crashes Puppet/Ruby with LDAP. At this point I suspect I am looking at
a weird consequence of another problem, but I have no idea. I've been
able to replicate this problem with Puppet 2.6.8, 2.6.12 running on Ruby
1.8.4 (from Sun Freeware) and 1.8.7 (from OpenCSW).
If anyone has any ideas, I'd love to hear them. I really just need a
fresh set of eyes at this point.
Thanks,
James
James Lee
I have a Solaris 10 system running Puppet 2.6.8 that is experiencing a
very unusual problem. It has been running fine up until I configured
the system to use LDAP for users and groups. The problem is easily
reproducible. Take "ldap" out of /etc/nsswitch.conf and it runs fine,
once it's added back in, Puppet crashes:
> acad ~ # puppet agent --test --environment=jameslee --no-report
> info: Caching catalog for acad.es.gwu.edu
> info: Applying configuration version '1327003919'
> --- /etc/nsswitch.conf Thu Jan 19 15:11:54 2012
> +++ /tmp/puppet-file5186.0 Thu Jan 19 15:13:04 2012
> @@ -13,8 +13,8 @@
> # "hosts:" and "services:" in this file are used only if the
> # /etc/netconfig file has a "-" for nametoaddr_libs of "inet" transports.
>
> -passwd: files
> -group: files
> +passwd: files ldap
> +group: files ldap
> hosts: files dns
> ipnodes: files
> networks: files
> info: FileBucket got a duplicate file {md5}4dc29d1e26abeda92f07cbf7ea8c8184
> info: /Stage[main]/Solaris/File[/etc/nsswitch.conf]: Filebucketed /etc/nsswitch.conf to puppet with sum 4dc29d1e26abeda92f07cbf7ea8c8184
> notice: /Stage[main]/Solaris/File[/etc/nsswitch.conf]/content: content changed '{md5}4dc29d1e26abeda92f07cbf7ea8c8184' to '{md5}42577aabe4178912e5f5c030a7d72634'
> notice: Finished catalog run in 59.61 seconds
> acad ~ # puppet agent --test --environment=jameslee --no-report
> /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/provider/package/apt.rb:15:in `[]=': failed to allocate memory (NoMemoryError)
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/provider/package/apt.rb:15
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/classgen.rb:117:in `genthing'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/classgen.rb:28:in `genclass'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/type.rb:1446:in `provide'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/provider/package/apt.rb:1
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/autoload.rb:113:in `loadall'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/autoload.rb:109:in `loadall'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/autoload.rb:108:in `loadall'
> ... 51 levels...
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/application.rb:305:in `run'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/command_line.rb:62:in `execute'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/bin/puppet:4
> from /usr/local/bin/puppet:19
This system has 6 GB of memory of which only 168 MB are being used. It
does not appear that the puppet process running under the LDAP
configuration balloons out of control either, so I can't imagine it's
actually running out of memory.
I tested Puppet 2.6.12 and it has the same problem. Unfortunately
trying 2.7 is not possible at the moment.
For what it's worth, I can reduce the node's configuration down to
basically nothing and the problem goes away, so there is something in
one of our modules that is triggering the problem, but I have no idea
what. The stack trace above gives me no real clues (it's a Solaris
system, there is no APT system, and removing the apt provider just
pushes the crash to another file, same message). I don't have any LDAP
related resources in the Puppet configuration (like LDAP user
resources). What is it about LDAP that simply enabling it could cause
Puppet to crash? How might I go about debugging this?
The full debug output is shown below.
Thanks,
James
> acad ~ # puppet agent --test --environment=jameslee --no-report --debug
> debug: Failed to load library 'shadow' for feature 'libshadow'
> debug: Puppet::Type::User::ProviderPw: file pw does not exist
> debug: Failed to load library 'ldap' for feature 'ldap'
> debug: Puppet::Type::User::ProviderLdap: feature ldap is missing
> debug: Puppet::Type::User::ProviderUseradd: file chage does not exist
> debug: Puppet::Type::User::ProviderDirectoryservice: file /usr/bin/dscl does not exist
> debug: Failed to load library 'selinux' for feature 'selinux'
> debug: Puppet::Type::File::ProviderMicrosoft_windows: feature microsoft_windows is missing
> debug: /File[/var/lib/puppet/state/last_run_report.yaml]: Autorequiring File[/var/lib/puppet/state]
> debug: /File[/var/lib/puppet/state/classes.txt]: Autorequiring File[/var/lib/puppet/state]
> debug: /File[/var/lib/puppet/client_yaml]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/certs]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/etc/puppet/ssl/certs/ca.pem]: Autorequiring File[/etc/puppet/ssl/certs]
> debug: /File[/etc/puppet/ssl/public_keys]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/var/lib/puppet/state/last_run_summary.yaml]: Autorequiring File[/var/lib/puppet/state]
> debug: /File[/var/lib/puppet/state/state.yaml]: Autorequiring File[/var/lib/puppet/state]
> debug: /File[/etc/puppet/ssl/private_keys]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/etc/puppet/ssl/private]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/etc/puppet/ssl/private_keys/acad.es.gwu.edu.pem]: Autorequiring File[/etc/puppet/ssl/private_keys]
> debug: /File[/etc/puppet/ssl/public_keys/acad.es.gwu.edu.pem]: Autorequiring File[/etc/puppet/ssl/public_keys]
> debug: /File[/var/lib/puppet/clientbucket]: Autorequiring File[/var/lib/puppet]
> debug: /File[/var/lib/puppet/log]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/certificate_requests]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/var/lib/puppet/facts]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/crl.pem]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/var/lib/puppet/run]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/certs/acad.es.gwu.edu.pem]: Autorequiring File[/etc/puppet/ssl/certs]
> debug: /File[/etc/puppet/ssl]: Autorequiring File[/etc/puppet]
> debug: /File[/var/lib/puppet/state/graphs]: Autorequiring File[/var/lib/puppet/state]
> debug: /File[/etc/puppet/puppet.conf]: Autorequiring File[/etc/puppet]
> debug: /File[/var/lib/puppet/state]: Autorequiring File[/var/lib/puppet]
> debug: /File[/var/lib/puppet/client_data]: Autorequiring File[/var/lib/puppet]
> debug: /File[/var/lib/puppet/lib]: Autorequiring File[/var/lib/puppet]
> debug: Finishing transaction 76347634
> debug: /File[/etc/puppet/ssl/private]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/var/lib/puppet/state]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/certs/acad.es.gwu.edu.pem]: Autorequiring File[/etc/puppet/ssl/certs]
> debug: /File[/var/lib/puppet/run]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/private_keys]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/etc/puppet/ssl/certificate_requests]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/var/lib/puppet/log]: Autorequiring File[/var/lib/puppet]
> debug: /File[/var/lib/puppet/facts]: Autorequiring File[/var/lib/puppet]
> debug: /File[/var/lib/puppet/lib]: Autorequiring File[/var/lib/puppet]
> debug: /File[/etc/puppet/ssl/public_keys/acad.es.gwu.edu.pem]: Autorequiring File[/etc/puppet/ssl/public_keys]
> debug: /File[/etc/puppet/ssl]: Autorequiring File[/etc/puppet]
> debug: /File[/etc/puppet/ssl/private_keys/acad.es.gwu.edu.pem]: Autorequiring File[/etc/puppet/ssl/private_keys]
> debug: /File[/etc/puppet/ssl/certs/ca.pem]: Autorequiring File[/etc/puppet/ssl/certs]
> debug: /File[/etc/puppet/ssl/public_keys]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/etc/puppet/ssl/certs]: Autorequiring File[/etc/puppet/ssl]
> debug: /File[/etc/puppet/ssl/crl.pem]: Autorequiring File[/etc/puppet/ssl]
> debug: Finishing transaction 75890314
> debug: Using cached certificate for ca
> debug: Using cached certificate for acad.es.gwu.edu
> debug: Finishing transaction 75662514
> debug: Loaded state in 0.04 seconds
> debug: Using cached certificate for ca
> debug: Using cached certificate for acad.es.gwu.edu
> debug: Using cached certificate_revocation_list for ca
> debug: catalog supports formats: b64_zlib_yaml dot marshal pson raw yaml; using pson
> /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/provider/package/apt.rb:15:in `[]=': failed to allocate memory (NoMemoryError)
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/provider/package/apt.rb:15
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/classgen.rb:117:in `genthing'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/classgen.rb:28:in `genclass'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/type.rb:1446:in `provide'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/provider/package/apt.rb:1
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/autoload.rb:113:in `loadall'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/autoload.rb:109:in `loadall'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/autoload.rb:108:in `loadall'
> ... 51 levels...
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/application.rb:305:in `run'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/lib/puppet/util/command_line.rb:62:in `execute'
> from /usr/local/lib/ruby/gems/1.8/gems/puppet-2.6.8/bin/puppet:4
> from /usr/local/bin/puppet:19
James Lee
> I've narrowed down what is triggering this problem, but I still do not
> know how to fix it.
>> acad ~ # puppet agent --test --environment=jameslee --no-report --noop
>> /opt/csw/lib/ruby/gems/1.8/gems/puppet-2.6.12/lib/puppet/provider/package/apt.rb:1:in `[]=': failed to allocate memory (NoMemoryError)
>
> Just trying to set the environmental variable crashed Puppet.
> I don't understand how setting ENV variables is fine without LDAP and
> crashes Puppet/Ruby with LDAP. At this point I suspect I am looking at
> a weird consequence of another problem, but I have no idea. I've been
> able to replicate this problem with Puppet 2.6.8, 2.6.12 running on Ruby
> 1.8.4 (from Sun Freeware) and 1.8.7 (from OpenCSW).
Just to close the loop on this issue, I finally managed to get a good
core dump from the crash which told me where the problem was happening:
> --- called from signal handler with signal 11 (SIGSEGV) ---
> fecd6129 realfree (a175944) + 43
> fecd6747 cleanfree (0) + 44
> fecd5c63 _malloc_unlocked (20, fef55638, 1d, fef42f9c, 7fc0fb8, feeab4ff) + ad
> fecd5b8c malloc (1d, 8, 0, feeab4aa) + 34
> feeab4ff ruby_xmalloc (1d, 8, 0, feeb0e7a) + 63
> feeb10d3 ruby_setenv (988b5b0, a151998) + 267
Something about the way the 'ruby_setenv' was allocating memory was
failing. Some googling led me to this bug report:
http://bugs.ruby-lang.org/issues/2353
which included a patch that solved my problem. I (manually) applied
Nobuyoshi Nakada's fix to the very old version of Ruby I'm running and
Puppet no longer crashes!
With this behind me I can plan an upgrade to Puppet 2.7 and Ruby 1.9,
which includes this fix.
Thanks!
James