Puppet

May be related to [[http://projects.reductivelabs.com/issues/3029]]

What platform?

CentOS 5.2 and 5.4 x86_64 and i386 have all been shown to have the same issue.

ruby 1.8.5 (2006-08-25) [x86_64-linux] facter 1.5.6

Interestingly enough, this trace which is a bit different also showed up in the logs:

/usr/lib/ruby/site_ruby/1.8/puppet/util/suidmanager.rb:29:in asuser' /usr/lib/ruby/site_ruby/1.8/puppet/util/settings.rb:731:inwritesub' /usr/lib/ruby/site_ruby/1.8/puppet/util/settings.rb:717:in write' /usr/lib/ruby/site_ruby/1.8/puppet/indirector/ssl_file.rb:158:inwrite' /usr/lib/ruby/site_ruby/1.8/puppet/indirector/ssl_file.rb:98:in save' /usr/lib/ruby/site_ruby/1.8/puppet/indirector/indirection.rb:199:infind' /usr/lib/ruby/site_ruby/1.8/puppet/indirector.rb:51:in find' /usr/lib/ruby/site_ruby/1.8/puppet/ssl/host.rb:208:inssl_store' /usr/lib/ruby/site_ruby/1.8/puppet/network/http_pool.rb:56:in cert_setup' /usr/lib/ruby/site_ruby/1.8/puppet/network/http_pool.rb:100:inhttp_instance' /usr/lib/ruby/site_ruby/1.8/puppet/indirector/rest.rb:65:in network' /usr/lib/ruby/site_ruby/1.8/puppet/indirector/rest.rb:73:insearch' /usr/lib/ruby/site_ruby/1.8/puppet/indirector/indirection.rb:240:in search' /usr/lib/ruby/site_ruby/1.8/puppet/indirector.rb:59:insearch' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:595:in perform_recursion' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:562:inrecurse_remote' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:561:in collect' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:561:inrecurse_remote' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:483:in recurse' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:385:ineval_generate' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:349:in send' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:349:ingenerate_additional_resources' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:193:in eval_generate' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:240:ineval_children_and_apply_resource' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:207:in eval_resource' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:296:inevaluate' /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:418:in thinmark' /usr/lib/ruby/1.8/benchmark.rb:293:inmeasure' /usr/lib/ruby/1.8/benchmark.rb:307:in realtime' /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:417:inthinmark' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:295:in evaluate' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:289:incollect' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:289:in evaluate' /usr/lib/ruby/site_ruby/1.8/puppet/resource/catalog.rb:142:inapply' /usr/lib/ruby/site_ruby/1.8/puppet/configurer/downloader.rb:32:in evaluate' /usr/lib/ruby/1.8/timeout.rb:56:intimeout' /usr/lib/ruby/site_ruby/1.8/puppet/configurer/downloader.rb:31:in evaluate' /usr/lib/ruby/site_ruby/1.8/puppet/configurer/plugin_handler.rb:12:indownload_plugins' /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:75:in prepare' /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:138:inrun' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:53:in run' /usr/lib/ruby/site_ruby/1.8/puppet/agent/locker.rb:21:inlock' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:53:in run' /usr/lib/ruby/1.8/sync.rb:229:insynchronize' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:53:in run' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:130:inwith_client' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:51:in run' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:104:instart' /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:insignal‘ /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:insignal’ (eval):2:in signal' /usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/event-loop.rb:321:insound_alarm' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:108:in start' /usr/lib/ruby/site_ruby/1.8/puppet/daemon.rb:127:instart' /usr/lib/ruby/site_ruby/1.8/puppet/application/puppetd.rb:116:in main' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:226:insend' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:226:in run_command' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:217:inrun' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:306:in exit_on_fail' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:217:inrun' /usr/sbin/puppetd:159 err: /File[/var/lib/puppet/lib]: Failed to generate additional resources using ‘eval_generate’: Invalid argument debug: file_metadata supports formats: b64_zlib_yaml marshal pson raw yaml; using pson /usr/lib/ruby/site_ruby/1.8/puppet/parameter.rb:401:in fail' /usr/lib/ruby/site_ruby/1.8/puppet/type/file/source.rb:160:ininit_metadata' /usr/lib/ruby/site_ruby/1.8/puppet/util/cacher.rb:106:in send' /usr/lib/ruby/site_ruby/1.8/puppet/util/cacher.rb:106:incached_value' /usr/lib/ruby/site_ruby/1.8/puppet/util/cacher.rb:46:in metadata' /usr/lib/ruby/site_ruby/1.8/puppet/type/file/source.rb:111:incopy_source_values' /usr/lib/ruby/site_ruby/1.8/puppet/type/file.rb:630:in retrieve' /usr/lib/ruby/site_ruby/1.8/puppet/type.rb:726:inevaluate' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:62:in apply' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:251:ineval_children_and_apply_resource' /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:418:in thinmark' /usr/lib/ruby/1.8/benchmark.rb:293:inmeasure' /usr/lib/ruby/1.8/benchmark.rb:307:in realtime' /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:417:inthinmark' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:250:in eval_children_and_apply_resource' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:207:ineval_resource' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:296:in evaluate' /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:418:inthinmark' /usr/lib/ruby/1.8/benchmark.rb:293:in measure' /usr/lib/ruby/1.8/benchmark.rb:307:inrealtime' /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:417:in thinmark' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:295:inevaluate' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:289:in collect' /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:289:inevaluate' /usr/lib/ruby/site_ruby/1.8/puppet/resource/catalog.rb:142:in apply' /usr/lib/ruby/site_ruby/1.8/puppet/configurer/downloader.rb:32:inevaluate' /usr/lib/ruby/1.8/timeout.rb:56:in timeout' /usr/lib/ruby/site_ruby/1.8/puppet/configurer/downloader.rb:31:inevaluate' /usr/lib/ruby/site_ruby/1.8/puppet/configurer/plugin_handler.rb:12:in download_plugins' /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:75:inprepare' /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:138:in run' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:53:inrun' /usr/lib/ruby/site_ruby/1.8/puppet/agent/locker.rb:21:in lock' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:53:inrun' /usr/lib/ruby/1.8/sync.rb:229:in synchronize' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:53:inrun' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:130:in with_client' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:51:inrun' /usr/lib/ruby/site_ruby/1.8/puppet/agent.rb:104:in start' /usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:incall' /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:ineach' /usr/lib/ruby/site_ruby/1.8/puppet/external/event-loop/signal-system.rb:97:in __signal__' (eval):2:insignal' /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/agent.rb:108:instart' /usr/lib/ruby/site_ruby/1.8/puppet/daemon.rb:127:in start' /usr/lib/ruby/site_ruby/1.8/puppet/application/puppetd.rb:116:inmain' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:226:in send' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:226:inrun_command' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:217:in run' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:306:inexit_on_fail' /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:217:in `run' /usr/sbin/puppetd:159

Jason —

What happens if you go into irb on the client and type “Process.groups”? You should see something like this:

(markus) ~ > irb
irb(main):001:0> Process.groups
=> [20, 98, 101, 81, 79, 102, 80]
irb(main):002:0> RUBY_VERSION
=> "1.8.5"
irb(main):003:0> 

— Markus

# irb
irb(main):001:0> RUBY_VERSION
=> "1.8.5"
irb(main):002:0> Process.groups
Errno::EINVAL: Invalid argument
    from (irb):2:in `groups'
    from (irb):2
irb(main):003:0> Process.gid
=> 0
irb(main):004:0> Process.uid
=> 0
irb(main):005:0>

Very odd.

For good measure I upgraded ruby to 1.8.6 on a machine that was showing issue. Still didn’t resolve the issue. It seems that this issue only exists for the root user.

I’ve just tested this (running Process.groups directly) with ruby 1.8.5 on Centos 5.3 as root, and was unable to reproduce the error. However, playing around (and taking a peek at the process.c in the ruby source tree) did suggest a possible explanation.

Could you try (in irb again):

Process.maxgroups = 1024
Process.groups

and see if that generates the same error? If not, could you report the results of:

Process.groups.length

— Markus

# irb
irb(main):001:0> Process.groups.length
Errno::EINVAL: Invalid argument
    from (irb):1:in `groups'
    from (irb):1
irb(main):002:0> exit
[root@shared-xen-008 ~]# irb
irb(main):001:0> Process.groups
Errno::EINVAL: Invalid argument
    from (irb):1:in `groups'
    from (irb):1
irb(main):002:0> Process.maxgroups=1024
=> 1024
irb(main):003:0> Process.groups
=> [0, 1, 2, 3, 4, 6, 10, 99, 500, 1011, 2531, 2532, 2533, 2534, 2535, 2540, 2546, 2547, 2557, 2562, 2563, 2564, 2565, 2567, 2576, 2581, 2583, 2588, 2592, 2596, 10001, 10027, 10028, 10040, 10047, 10048, 10049, 10050, 10055, 10068, 10069, 10072, 10073, 10077, 10080, 10086, 10088, 10089, 10099, 10101, 10115, 10131, 10143, 10144, 10148, 10149, 10150]
irb(main):004:0> Process.groups.length
=> 57
irb(main):005:0> 

I have used this as a fix for some of my clients last night, adding it to configurer.rb in class << self (Process.maxgroups=256). It seems to work OK, but I wasn’t sure if it was the proper solution. However, 3 clients still “exited” last night without error.

However, 3 clients still “exited” last night without error.

Related, do you think, or something else?

As for the main issue, we should probably just set maxgroups to some arbitrary high in Puppet::Util; so far as I can tell there is minimal / no downside to this.

— Markus

Don’t think it was related. I agree that there shouldn’t be a downside to setting this number unless someone has a user with more than 1024 groups. (doubtful) Any chance this can go into 0.25.4? this is the only thing holding me up from upgrading all my puppet clients to 0.25.x

If there is another rc necessitated by a bug in rc3, yes. Elsewise, 0.25.5.

Here is the patch I just applied to 10 hosts, so far so good.

Removed patch, doesn’t work. Here is a snipped strace output from the puppet daemon as it crashes:

stat(“/var/lib/puppet/ssl”, {st_mode=S_IFDIR|0771, st_size=4096, …}) = 0 stat(“/var/lib/puppet/ssl”, {st_mode=S_IFDIR|0771, st_size=4096, …}) = 0 geteuid() = 0 getegid() = 0 getuid() = 0 getgid() = 0 access(“/var/lib/puppet/ssl”, W_OK) = 0 getuid() = 0 getuid() = 0 getuid() = 0 getgid() = 0 geteuid() = 0 getegid() = 0 getgroups(32, 0x7fffea35f050) = -1 EINVAL (Invalid argument) write(2, “/usr/lib/ruby/site_ruby/1.8/pupp”…, 69) = 69 write(2, “: ”, 2) = 2 write(2, “Invalid argument”, 16) = 16 write(2, “ (”, 2) = 2 write(2, “Errno::EINVAL”, 13) = 13 write(2, “)\n”, 2) = 2 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 76) = 76 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 73) = 73 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 79) = 79 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 77) = 77 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 81) = 81 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 68) = 68 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 72) = 72 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 84) = 84 write(2, “\t … 7 levels…\n”, 18) = 18 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 69) = 69 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 78) = 78 write(2, “\tfrom /usr/lib/ruby/site_ruby/1.”…, 69) = 69 write(2, “\tfrom /usr/sbin/puppetd:159\n”, 28) = 28 munmap(0x2aaaab808000, 372736) = 0 close(4) = 0 munmap(0x2ba8c59e6000, 4096) = 0 close(3) = 0 munmap(0x2ba8c59e5000, 4096) = 0 close(6) = 0 exit_group(1) = ? Process 5918 detached

Just out of curiosity, what was the patch? Flag it as non-working, but if you just remove it from the thread it makes it hard to diagnose its consequences.

Sorry about that James, Here is a new version of the patch that seems to be working better based on Marcus' suggestion.

--- a/lib/puppet/util/monkey_patches.rb
+++ b/lib/puppet/util/monkey_patches.rb
@@ -1,3 +1,4 @@
+Process.maxgroups=1024
 module RDoc 
     def self.caller(skip=nil)
         in_gem_wrapper = false

The prior patch was adding the same line to lib/puppet/util/suidmanager.rb inside of the initgroups method.

There’s a branch up with the above patch applied, if anyone else is experiencing the problem and would like to test it.

Pushed in commit:“1f086c28118075aa8cccc2edcdd44ae64b3a5750” in branch 0.25.x