[PUP-8180] puppet agent -t fails from within sshfs working directory Created: 2017/11/15  Updated: 2019/10/01

Status: Accepted
Project: Puppet
Component/s: None
Affects Version/s: PUP 4.10.9
Fix Version/s: None

Type: Bug Priority: Trivial
Reporter: Tylar Murray Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: agent
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu 16.04.3 LTS

~$ sshfs --version
SSHFS version 2.5
FUSE library version: 2.9.4
fusermount version: 2.9.4
using FUSE kernel interface version 7.19


Issue Links:
Relates
relates to PUP-9997 Puppet must not call Dir.chdir() exce... Accepted
Template:
Acceptance Criteria:

`sudo mkdir /mnt/test && sudo sshfs /mnt/test $testserver && cd /mnt/test && sudo puppet agent -t`

Team: Coremunity
Method Found: Needs Assessment
QA Risk Assessment: Needs Assessment

 Description   

This is trivial to work around, but it threw me off when I first saw it and figured I would write it up really quick in case someone else comes across the same.

Some resources will fail when running `puppet agent --test` if your current working directory is within an sshfs mount.

Here are relevant error messages from two resources failing in this way, vcsrepo and nfs:

Error: /Stage[main]/Nfs::Client::Service/Service[rpcbind]/enable: change from false to true failed: Could not enable rpcbind: 
Notice: /Stage[main]/Nfs::Client/Anchor[nfs::client::end]: Dependency Service[rpcbind] has failures: true
 
Error: /Stage[main]/Backdat::Install/Vcsrepo[/opt/backdat]: Could not evaluate: Permission denied @ dir_chdir - /mnt/puppetenv

Could be related to PUP-5915, but I'm not certain.

Here is the detailed trace:

tylar@mycomputer:/mnt/my-sshfs-mount$ sudo puppet agent --test --trace
Info: Using configured environment 'test'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Info: Loading facts
Info: Caching catalog for mycomputer.mydomain.edu
Info: Applying configuration version '1511820289'
Error: Could not enable rpcbind: 
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/execution.rb:235:in `execute'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider/command.rb:23:in `execute'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider.rb:221:in `block in has_command'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider.rb:422:in `block in create_class_and_instance_method'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider/service/systemd.rb:47:in `systemctl_change_enable'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider/service/systemd.rb:125:in `enable'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/service.rb:55:in `block (3 levels) in <module:Puppet>'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:487:in `set'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:561:in `sync'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:236:in `sync'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:134:in `sync_if_needed'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:88:in `block in perform_changes'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:87:in `each'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:87:in `perform_changes'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:21:in `evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:230:in `apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:246:in `eval_resource'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `call'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block (2 levels) in evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:507:in `block in thinmark'
/opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:506:in `thinmark'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block in evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:154:in `evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:222:in `block in apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:155:in `with_destination'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:142:in `as_logging_destination'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:221:in `apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:171:in `block in apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:224:in `block in benchmark'
/opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:223:in `benchmark'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:170:in `apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:343:in `run_internal'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:221:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:195:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:45:in `block (4 levels) in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent/locker.rb:21:in `lock'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:45:in `block (3 levels) in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:98:in `with_client'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:42:in `block (2 levels) in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:65:in `run_in_fork'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:41:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:179:in `call'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:179:in `controlled_run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:39:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/agent.rb:353:in `onetime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/agent.rb:331:in `run_command'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:358:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:662:in `exit_on_fail'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:358:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:132:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:72:in `execute'
/opt/puppetlabs/puppet/bin/puppet:5:in `<main>'
Error: /Stage[main]/Nfs::Client::Service/Service[rpcbind]/enable: change from false to true failed: Could not enable rpcbind: 
Notice: /Stage[main]/Nfs::Client/Anchor[nfs::client::end]: Dependency Service[rpcbind] has failures: true
Warning: /Stage[main]/Nfs::Client/Anchor[nfs::client::end]: Skipping because of failed dependencies
Error: /Stage[main]/Backdat::Install/Vcsrepo[/opt/backdat]: Could not evaluate: Permission denied @ dir_chdir - /mnt/my-sshfs-mount
/opt/puppetlabs/puppet/cache/lib/puppet/provider/vcsrepo.rb:43:in `chdir'
/opt/puppetlabs/puppet/cache/lib/puppet/provider/vcsrepo.rb:43:in `at_path'
/opt/puppetlabs/puppet/cache/lib/puppet/provider/vcsrepo/git.rb:132:in `working_copy_exists?'
/opt/puppetlabs/puppet/cache/lib/puppet/type/vcsrepo.rb:138:in `retrieve'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type.rb:1070:in `retrieve'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type.rb:1098:in `retrieve_resource'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:300:in `from_resource'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:20:in `evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:230:in `apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:246:in `eval_resource'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `call'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block (2 levels) in evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:507:in `block in thinmark'
/opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:506:in `thinmark'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block in evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:154:in `evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:222:in `block in apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:155:in `with_destination'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:142:in `as_logging_destination'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:221:in `apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:171:in `block in apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:224:in `block in benchmark'
/opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:223:in `benchmark'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:170:in `apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:343:in `run_internal'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:221:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:195:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:45:in `block (4 levels) in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent/locker.rb:21:in `lock'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:45:in `block (3 levels) in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:98:in `with_client'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:42:in `block (2 levels) in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:65:in `run_in_fork'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:41:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:179:in `call'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:179:in `controlled_run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:39:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/agent.rb:353:in `onetime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/agent.rb:331:in `run_command'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:358:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:662:in `exit_on_fail'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:358:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:132:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:72:in `execute'
/opt/puppetlabs/puppet/bin/puppet:5:in `<main>'
Info: Stage[main]: Unscheduling all events on Stage[main]
Notice: Applied catalog in 3.31 seconds



 Comments   
Comment by Josh Cooper [ 2017/11/27 ]

Can you rerun with --trace and include the backtrace in the description?

Comment by Tylar Murray [ 2017/11/27 ]

added. Sorry I'm not familiar with the formatting or workflow here.

Comment by Josh Cooper [ 2017/11/27 ]

Thanks [~tylar] for the quick response. One of the provider errors is definitely a dup of the other issue:

Error: /Stage[main]/Backdat::Install/Vcsrepo[/opt/backdat]: Could not evaluate: Permission denied @ dir_chdir - /mnt/my-sshfs-mount
/opt/puppetlabs/puppet/cache/lib/puppet/provider/vcsrepo.rb:43:in `chdir'

I'm not sure what is causing the first error with rpcbind. For some reason it's returning a non-zero exit code, see https://github.com/puppetlabs/puppet/blob/4.10.9/lib/puppet/util/execution.rb#L235. Can you also run with --debug and see what command the provider is trying to execute?

Comment by Josh Cooper [ 2017/11/27 ]

Oh wait, it's in the stack trace: https://github.com/puppetlabs/puppet/blob/4.10.9/lib/puppet/provider/service/systemd.rb#L47. Can you execute systemctl enable rpcbind via sudo from within the sshfs directory?

Comment by Tylar Murray [ 2017/11/28 ]

Josh Cooper I Think you're on to something. systemctl enable rpcbind gives me a password prompt that doesn't take my local password.

I guess it's trying to authenticate as tylar@my-sshfs-host.

Comment by Josh Cooper [ 2019/10/01 ]

I think this is related to PUP-9997, but it's being triggered by the vcsrepo's use of Dir.chdir, and it occurs when the puppet process tries to change the current working directory back to the sshfs home directory. What was the workaround you used?

Generated at Sat Dec 14 19:32:57 PST 2019 using JIRA 7.7.1#77002-sha1:e75ca93d5574d9409c0630b81c894d9065296414.