Issue #1963 has been updated by Todd Zullinger.
The read_mounts call in question here is from puppet (in lib/puppet/util/selinux.rb). I don't know what the best way to determine how many files this puppet configuration is managing, but here's a rough idea: <pre> # grep -c 'type: file$' /var/lib/puppet/localconfig.yaml 82 </pre> It doesn't take any real noticeable amount of time for most of these calls, aside from the one that runs inside the download_plugins function and hangs, of course. But surely they do add up to something more than is really needed. To paraphrase an old statesman¹, "A few milliseconds here and a few milliseconds there, and pretty soon you're talking about real time." If it's possible to refactor things to avoid many of these calls, it might kill several birds with one elegant stone. ¹ I'm reminded also of a quote of unknown origin that says, "A statesman is a dead politician. Lord knows, we need more statesmen." ;) ---------------------------------------- Bug #1963: Failing to read /proc/mounts for selinux kills file downloads http://projects.reductivelabs.com/issues/1963 Author: Marc Fournier Status: Accepted Priority: High Assigned to: Category: plumbing Target version: 0.25.0 Complexity: Unknown Affected version: 0.25.0 Keywords: selinux plugin timeout With selinux enabled (on fedora10, libselinux-ruby RPM installed, git checkout of 0.24.7) and "pluginsync=true" in puppet.conf, puppet timeouts on plugin retrieval. Curiously, the problem occurs before puppet starts to connect to the puppetmaster. tcpdump shows no network access before/while the timeout. It seems to me puppet tries to access a file in /proc, which causes the timeout. Same problem occurs with latest commit on branch 0.24.x Same problem occurs with redhat5 and Tom Payne's libselinux-ruby-puppet. This renders puppet unusable if you rely on plugins and you have an selinux-enabled system. Here is the backtrace I obtain when running puppet with --debug: <pre> [r...@fedora10test puppet]# git checkout 0.24.7 HEAD is now at 8befc18... Updated to version 0.24.7 [r...@fedora10test puppet]# RUBYLIB=/root/puppet/lib/ bin/puppetd -t --debug --environment marc debug: /File[/var/puppet/facts]/seluser: Found seluser default 'system_u' for /var/puppet/facts debug: /File[/var/puppet/facts]/selrole: Found selrole default 'object_r' for /var/puppet/facts debug: /File[/var/puppet/facts]/seltype: Found seltype default 'var_t' for /var/puppet/facts [...] debug: Finishing transaction 70197300339920 with 0 changes debug: Loaded state in 0.00 seconds debug: Puppet::Network::Client::File: defining fileserver.describe debug: Puppet::Network::Client::File: defining fileserver.list debug: Puppet::Network::Client::File: defining fileserver.retrieve debug: /File[/var/lib/puppet/lib]/seluser: Found seluser default 'system_u' for /var/lib/puppet/lib debug: /File[/var/lib/puppet/lib]/selrole: Found selrole default 'object_r' for /var/lib/puppet/lib debug: /File[/var/lib/puppet/lib]/seltype: Found seltype default 'var_lib_t' for /var/lib/puppet/lib debug: /File[/var/lib/puppet/lib]/selrange: Found selrange default 's0' for /var/lib/puppet/lib info: Retrieving plugins /usr/lib/ruby/1.8/timeout.rb:60:in `read_mounts' /root/puppet/lib/puppet/util/selinux.rb:177:in `find_fs' /root/puppet/lib/puppet/util/selinux.rb:203:in `selinux_label_support?' /root/puppet/lib/puppet/util/selinux.rb:49:in `get_selinux_default_context' /root/puppet/lib/puppet/type/file/selcontext.rb:37:in `retrieve_default_context' /root/puppet/lib/puppet/type/file/selcontext.rb:61:in `default' /root/puppet/lib/puppet/type.rb:651:in `setdefaults' /root/puppet/lib/puppet/type.rb:138:in `eachattr' /root/puppet/lib/puppet/type.rb:135:in `each' /root/puppet/lib/puppet/type.rb:135:in `eachattr' /root/puppet/lib/puppet/type.rb:641:in `setdefaults' /root/puppet/lib/puppet/type.rb:2362:in `initialize' /root/puppet/lib/puppet/type/file.rb:460:in `initialize' /root/puppet/lib/puppet/type.rb:1131:in `new' /root/puppet/lib/puppet/type.rb:1131:in `create' /root/puppet/lib/puppet/node/catalog.rb:200:in `create_resource' /root/puppet/lib/puppet/node/catalog.rb:186:in `create_implicit_resource' /root/puppet/lib/puppet/type/file.rb:643:in `newchild' /root/puppet/lib/puppet/type/file.rb:563:in `localrecurse' /root/puppet/lib/puppet/type/file.rb:558:in `each' /root/puppet/lib/puppet/type/file.rb:558:in `localrecurse' /root/puppet/lib/puppet/type/file.rb:712:in `recurse' /root/puppet/lib/puppet/type/file.rb:340:in `eval_generate' /root/puppet/lib/puppet/transaction.rb:193:in `eval_generate' /root/puppet/lib/puppet/transaction.rb:228:in `eval_resource' /root/puppet/lib/puppet/transaction.rb:310:in `evaluate' /root/puppet/lib/puppet/util.rb:425:in `thinmark' /usr/lib/ruby/1.8/benchmark.rb:308:in `realtime' /root/puppet/lib/puppet/util.rb:424:in `thinmark' /root/puppet/lib/puppet/transaction.rb:309:in `evaluate' /root/puppet/lib/puppet/transaction.rb:303:in `collect' /root/puppet/lib/puppet/transaction.rb:303:in `evaluate' /root/puppet/lib/puppet/node/catalog.rb:124:in `apply' /root/puppet/lib/puppet/network/client/master.rb:331:in `download' /root/puppet/lib/puppet/network/client/master.rb:330:in `download' /root/puppet/lib/puppet/network/client/master.rb:369:in `getplugins' /root/puppet/lib/puppet/network/client/master.rb:192:in `getplugins' /root/puppet/lib/puppet/network/client/master.rb:133:in `getconfig' /root/puppet/lib/puppet/network/client/master.rb:245:in `run' /root/puppet/lib/puppet/util.rb:425:in `thinmark' /usr/lib/ruby/1.8/benchmark.rb:308:in `realtime' /root/puppet/lib/puppet/util.rb:424:in `thinmark' /root/puppet/lib/puppet/network/client/master.rb:244:in `run' /usr/lib/ruby/1.8/sync.rb:229:in `synchronize' /root/puppet/lib/puppet/network/client/master.rb:237:in `run' bin/puppetd:417 err: Could not retrieve plugins: execution expired debug: /File[/var/puppet/facts]/seluser: Found seluser default 'system_u' for /var/puppet/facts debug: /File[/var/puppet/facts]/selrole: Found selrole default 'object_r' for /var/puppet/facts debug: /File[/var/puppet/facts]/seltype: Found seltype default 'var_t' for /var/puppet/facts debug: /File[/var/puppet/facts]/selrange: Found selrange default 's0' for /var/puppet/facts info: Retrieving facts debug: Calling fileserver.list [...] </pre> The same, but under supervision of "strace -e open": <pre> open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 open("/proc/mounts", O_RDONLY) = 6 open("/selinux/context", O_RDWR) = 6 debug: /File[/var/lib/puppet/lib]/seluser: Found seluser default 'system_u' for /var/lib/puppet/lib open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 open("/proc/mounts", O_RDONLY) = 6 open("/selinux/context", O_RDWR) = 6 debug: /File[/var/lib/puppet/lib]/selrole: Found selrole default 'object_r' for /var/lib/puppet/lib open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 open("/proc/mounts", O_RDONLY) = 6 open("/selinux/context", O_RDWR) = 6 debug: /File[/var/lib/puppet/lib]/seltype: Found seltype default 'var_lib_t' for /var/lib/puppet/lib open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 open("/proc/mounts", O_RDONLY) = 6 open("/selinux/context", O_RDWR) = 6 debug: /File[/var/lib/puppet/lib]/selrange: Found selrange default 's0' for /var/lib/puppet/lib info: Retrieving plugins Process 10089 attached (waiting for parent) Process 10089 resumed (parent 10066 ready) [pid 10066] open("/var/lib/puppet/lib", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 6 [pid 10066] open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 [pid 10066] open("/proc/mounts", O_RDONLY) = 6 /usr/lib/ruby/1.8/timeout.rb:60:in `read_mounts' /root/puppet/lib/puppet/util/selinux.rb:177:in `find_fs' /root/puppet/lib/puppet/util/selinux.rb:177:in `find_fs' /root/puppet/lib/puppet/util/selinux.rb:203:in `selinux_label_support?' /root/puppet/lib/puppet/util/selinux.rb:49:in `get_selinux_default_context' [...] bin/puppetd:417 err: Could not retrieve plugins: execution expired [pid 10066] open("/usr/lib/ruby/1.8/net/https.rb", O_RDONLY) = 6 [pid 10066] open("/var/lib/puppet/ssl/certs/ca.pem", O_RDONLY) = 6 [pid 10066] open("/var/lib/puppet/ssl/certs/fedora10test.pem", O_RDONLY) = 6 [pid 10066] open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 [pid 10066] open("/proc/mounts", O_RDONLY) = 6 [pid 10066] open("/selinux/context", O_RDWR) = 6 debug: /File[/var/puppet/facts]/seluser: Found seluser default 'system_u' for /var/puppet/facts [pid 10066] open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 [pid 10066] open("/proc/mounts", O_RDONLY) = 6 [pid 10066] open("/selinux/context", O_RDWR) = 6 debug: /File[/var/puppet/facts]/selrole: Found selrole default 'object_r' for /var/puppet/facts [pid 10066] open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 [pid 10066] open("/proc/mounts", O_RDONLY) = 6 [pid 10066] open("/selinux/context", O_RDWR) = 6 debug: /File[/var/puppet/facts]/seltype: Found seltype default 'var_t' for /var/puppet/facts [pid 10066] open("/proc/self/task/10066/attr/current", O_RDONLY) = 6 [pid 10066] open("/proc/mounts", O_RDONLY) = 6 [pid 10066] open("/selinux/context", O_RDWR) = 6 debug: /File[/var/puppet/facts]/selrange: Found selrange default 's0' for /var/puppet/facts info: Retrieving facts </pre> -- You have received this notification because you have either subscribed to it, or are involved in it. To change your notification preferences, please click here: http://reductivelabs.com/redmine/my/account --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Puppet Bugs" group. To post to this group, send email to [email protected] To unsubscribe from this group, send email to [email protected] For more options, visit this group at http://groups.google.com/group/puppet-bugs?hl=en -~----------~----~----~----~------~----~------~--~---
