Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

File provisioner on macOS Mojave 10.14.3 fails to properly copy folders #10662

Closed
angoras opened this issue Feb 11, 2019 · 13 comments
Closed

File provisioner on macOS Mojave 10.14.3 fails to properly copy folders #10662

angoras opened this issue Feb 11, 2019 · 13 comments

Comments

@angoras
Copy link

angoras commented Feb 11, 2019

Vagrant version

2.2.3
vagrant-hostsupdater (1.1.1.160, global)
vagrant-share (1.1.9, global)
vagrant-vbguest (0.17.2, global)

Host operating system

MacOS 10.14.3

Guest operating system

ubuntu/xenial64 (virtualbox, 20190208.0.0)

Vagrantfile

Vagrant.configure("2") do |config|
  config.vm.box = "ubuntu/xenial64"
  config.vm.network "forwarded_port", host: 8888, guest: 80, host_ip: "localhost"
  config.vm.network "private_network", ip: "192.168.42.10"
  config.vm.hostname = "dev.example.com"
  config.vm.provider "virtualbox" do |vb|
    vb.memory = "2048"
  end
  config.vm.provision "file", source: "conf/vagrant", destination: "/home/vagrant"
end

Debug output

https://gist.github.com/angoras/e1138fc79b1b56da892298ff1ca39274

Expected behavior

The directory (including some files) should be copied into the guest, as described here:
https://www.vagrantup.com/docs/provisioning/file.html

Actual behavior

The script terminates with the above error.
The problem is this line:
config.vm.provision "file", source: "conf/vagrant", destination: "/home/vagrant"
It used to work, but with the latest update, 2.2.3, it stopped working. If every file is copied separately it still works, but not when defined on the directory level. Maybe it has got something to do with [GH-10570]?

Steps to reproduce

  1. Run vagrantfile above

@briancain
Copy link
Member

Hello @angoras - I don't think that issue is related. It's taking already existing variables and just printing information.

What does your folder config/vagrant look like? What files are inside? If you pick a different folder to sync with say a simple text file, does it work like expected? Thanks!

@briancain
Copy link
Member

Oh, okay. I just noticed you are using a file provisioner. I have to ask, is conf/vagrant a file, or a folder? The debug output makes me think it's a folder.

@angoras
Copy link
Author

angoras commented Feb 12, 2019

@briancain Yes, it's a folder with some text files and a subfolder with additional text files.

@briancain
Copy link
Member

@angoras - if you want to sync a folder, you need to use the synced_folders config option:

config.vm.synced_folder "conf/vagrant", "home/vagrant"

The file provisioner is only for files, not folders. That would explain the odd behavior. Thanks!

@angoras
Copy link
Author

angoras commented Feb 13, 2019

@briancain But this is not a synced folder, it's just copied during the provision. Like the last example here:
https://www.vagrantup.com/docs/provisioning/file.html

@briancain
Copy link
Member

@angoras - you can use rsync for that if you just one a one time copy to the guest:

The rsync synced folder does a one-time one-way sync from the machine running to the machine being started by Vagrant.

https://www.vagrantup.com/docs/synced-folders/rsync.html

config.vm.synced_folder "conf/vagrant", "home/vagrant, type: "rsync"

@dgollub
Copy link

dgollub commented Feb 13, 2019

@briancain The "file" provisioner is used to copy folders into the VM, and it works with my configuration, but not with my coworkers, who gets the same error messages as @angoras.

Also the documentation clearly says this

The Vagrant file provisioner allows you to upload a file or directory from the host machine to the guest machine.

You can see that for yourself here: https://www.vagrantup.com/docs/provisioning/file.html

So, you saying to use the synced folders instead is not helping my coworker or @angoras getting their "used-to-be-working-previously" configuration working again with a new version, that apparently has a regression.

I will try and get the debug output and version numbers for ruby, gem, vagrant etc. once my coworker gets to the office.

EDIT: sorry for the harsh tone. But this is really something driving me up the wall very easily, completely ignoring the original issue and instead just offering a replacement, when clearly the original approach is a regression that used to be working before.

@briancain
Copy link
Member

@dgollub - Okay, it does look like the file provisioner for whatever reason does support folders.

@angoras - I've also tried to reproduce the error, and it doesn't happen with the latest version:

config.vm.define "bork" do |b|
    b.vm.box = "bento/ubuntu-18.04"
    b.vm.provision "Sandbox", type: "file",
      source: "linux-sandbox/Vagrantfile",
      destination: "/home/vagrant/test/Vagrantfile"

    b.vm.provision "file",
      source: "conf/vagrant",
      destination: "/home/vagrant"
    b.vm.provider :virtualbox
end
brian@localghost:vagrant-sandbox % tree conf                                                            ±[●●][master]
conf
└── vagrant
    └── scripts
        ├── linux
        │   ├── a folder
        │   │   └── test.sh
        │   ├── folder
        │   │   └── hello.sh
        │   ├── hello.sh
        │   ├── install-docker.sh
        │   ├── install-vagrant.sh
        │   ├── install-vbox.sh
        │   ├── setup-debug-env.sh
        │   └── test.sh
        └── windows
            ├── admin.ps1
            ├── hello.ps1
            ├── info.ps1
            ├── setuphyperv.ps1
            └── setup.ps1

6 directories, 13 files
brian@localghost:vagrant-sandbox % be vagrant up bork                                                   ±[●●][master]
Bringing machine 'bork' up with 'virtualbox' provider...
==> bork: Importing base box 'bento/ubuntu-18.04'...
==> bork: Matching MAC address for NAT networking...
==> bork: Checking if box 'bento/ubuntu-18.04' version '201812.27.0' is up to date...
==> bork: Setting the name of the VM: vagrant-sandbox_bork_1550098092413_82183
==> bork: Fixed port collision for 22 => 2222. Now on port 2200.
==> bork: Clearing any previously set network interfaces...
==> bork: Preparing network interfaces based on configuration...
    bork: Adapter 1: nat
==> bork: Forwarding ports...
    bork: 22 (guest) => 2200 (host) (adapter 1)
==> bork: Booting VM...
==> bork: Waiting for machine to boot. This may take a few minutes...
    bork: SSH address: 127.0.0.1:2200
    bork: SSH username: vagrant
    bork: SSH auth method: private key
    bork:
    bork: Vagrant insecure key detected. Vagrant will automatically replace
    bork: this with a newly generated keypair for better security.
    bork:
    bork: Inserting generated public key within guest...
    bork: Removing insecure key from the guest if it's present...
    bork: Key inserted! Disconnecting and reconnecting using new SSH key...
==> bork: Machine booted and ready!
==> bork: Checking for guest additions in VM...
    bork: The guest additions on this VM do not match the installed version of
    bork: VirtualBox! In most cases this is fine, but in rare cases it can
    bork: prevent things such as shared folders from working properly. If you see
    bork: shared folder errors, please make sure the guest additions within the
    bork: virtual machine match the version of VirtualBox you have installed on
    bork: your host and reload your VM.
    bork:
    bork: Guest Additions Version: 5.2.22
    bork: VirtualBox Version: 6.0
==> bork: Mounting shared folders...
    bork: /vagrant => /home/brian/code/vagrant-sandbox
==> bork: Running provisioner: Sandbox (file)...
    bork: /home/brian/code/vagrant-sandbox/linux-sandbox/Vagrantfile => /home/vagrant/test/Vagrantfile
==> bork: Running provisioner: file...
    bork: /home/brian/code/vagrant-sandbox/conf/vagrant/. => /home/vagrant
brian@localghost:vagrant-sandbox % be vagrant ssh bork                                                  ±[●●][master]
Welcome to Ubuntu 18.04.1 LTS (GNU/Linux 4.15.0-29-generic x86_64)

 * Documentation:  https://help.ubuntu.com
 * Management:     https://landscape.canonical.com
 * Support:        https://ubuntu.com/advantage

  System information as of Wed Feb 13 22:48:41 UTC 2019

  System load:  0.32              Processes:           91
  Usage of /:   2.4% of 61.80GB   Users logged in:     0
  Memory usage: 12%               IP address for eth0: 10.0.2.15
  Swap usage:   0%


0 packages can be updated.
0 updates are security updates.
vagrant@vagrant:~$ tree scripts/
scripts/
├── linux
│   ├── a folder
│   │   └── test.sh
│   ├── folder
│   │   └── hello.sh
│   ├── hello.sh
│   ├── install-docker.sh
│   ├── install-vagrant.sh
│   ├── install-vbox.sh
│   ├── setup-debug-env.sh
│   └── test.sh
└── windows
    ├── admin.ps1
    ├── hello.ps1
    ├── info.ps1
    ├── setuphyperv.ps1
    └── setup.ps1

4 directories, 13 files
vagrant@vagrant:~$ exit
logout
Connection to 127.0.0.1 closed.

I've used the same path names as the original issue, and Vagrant is able to copy everything just fine as expected. It would be helpful to know what is exactly in your folder that you are expecting to copy over to the guest. My guess is maybe there's an issue with the name of a file you have in that folder.

Still, I will still stand by my original suggestion and say that the synced_folder option (with rsync if you must only sync once) is still a much more sane option for something like this. The file provisioner uses scp to copy files, and there are differences across platforms that make this difficult and very bug prone with something like copying folders. The synced_folder option is much more reliable in this case for what you are trying to do.

@dgollub
Copy link

dgollub commented Feb 14, 2019

@briancain Thanks for your reply. I have gathered additional information, and this all - to me at least - points to a combination of the Vagrant source itself in tandem with the new macOS 10.14.x as source for the issue.

Unfortunately I do not have a Linux nor a Windows host machine to verify whether or not this is purely a Vagrant issue or purely a macOS 10.14.x issue.

Anyway, here is more information, and I did this all on my MacBook Pro with macOS 10.14.2 (18C54).

Vagrantfile part

config.vm.provision "file", source: "scripts/vagrant/docker-build-postgres", destination: "docker-build-postgres"

docker-build-postgres is a folder with two files in it, Dockerfile and docker-postgres-setup.sql.

Starting point is Vagrant version 2.2.0, installed when I was still on macOS 10.13.x, and back then using the file provisioner with a directory still worked as described in the documentation.

However my coworker got a new MacBook Pro with macOS: 10.14.3 (18D109) and installed Vagrant 2.2.3, and the provisioning using the file provisioner with a directory fails with this error message:

==> default: Running provisioner: file...
    default: /<redacted>/scripts/vagrant/docker-build-postgres/. => docker-build-postgres
/opt/vagrant/embedded/gems/2.2.3/gems/net-scp-1.2.1/lib/net/scp.rb:398:in `await_response_state': scp: error: unexpected filename: . (RuntimeError)

Debug output says basically the same the one @angoras posted.

I then went ahead and upgrade my Vagrant to 2.2.3 as well, and tried vagrant halt followed by vagrant up --provision --debug &> vagrant.log. And low and behold, same error.

So I tried downgrading to the following versions:

  • 2.2.0: the same version I had before, but now it doesn't work, same error
  • 2.1.5: same error
  • 2.0.4: same error
  • 1.9.8: can not test, since I am using VirtualBox Version 5.2.26 r128414 (Qt5.6.3) which is not supported by 1.9.8.

Also, the 2.1.5 log had this extra debug output, that the 2.2.0 and 2.2.3 one did not have (I am referring to the DEBUG guest/ssh statements):

DEBUG guest: Searching for cap: shell_expand_guest_path
DEBUG guest: Checking in: ubuntu
DEBUG guest: Checking in: debian
DEBUG guest: Checking in: linux
DEBUG guest: Found cap: shell_expand_guest_path in linux
 INFO guest: Execute capability: shell_expand_guest_path [#<Vagrant::Machine: default (VagrantPlugins::ProviderVirtualBox::Provider)>, "docker-build-postgres"] (ubuntu)
DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: echo; printf docker-build-postgres (sudo=false)
DEBUG ssh: stderr: 41e57d38-b4f7-4e46-9c38-13873d338b86-vagrant-ssh
DEBUG ssh: Exit status: 0
DEBUG ssh: Re-using SSH connection.
 INFO ssh: Execute: mkdir -p "docker-build-postgres" (sudo=false)
DEBUG ssh: stderr: 41e57d38-b4f7-4e46-9c38-13873d338b86-vagrant-ssh
DEBUG ssh: Exit status: 0
DEBUG ssh: Uploading: /<redacted>/scripts/vagrant/docker-build-postgres/. to docker-build-postgres
DEBUG ssh: Re-using SSH connection.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x00000001025eece8>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x00000001026cf1a8>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x00000001026a66e0>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x0000000102c1f338>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Calling recover: #<Vagrant::Action::Builtin::Call:0x0000000102c1f3b0>
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
ERROR warden: Error occurred: �scp: error: unexpected filename: .

 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO warden: Beginning recovery process...
 INFO warden: Recovery complete.
 INFO environment: Released process lock: machine-action-dad4bf7d416570a9657e2e4aa872778f
 INFO environment: Running hook: environment_unload
 INFO runner: Preparing hooks for middleware sequence...
 INFO runner: 1 hooks defined.
 INFO runner: Running action: environment_unload #<Vagrant::Action::Builder:0x00000001026df990>
/opt/vagrant/embedded/gems/2.1.5/gems/net-scp-1.2.1/lib/net/scp.rb:398:in `await_response_state': �scp: error: unexpected filename: . (RuntimeError)
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-scp-1.2.1/lib/net/scp.rb:365:in `block (3 levels) in start_command'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/channel.rb:610:in `do_close'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:573:in `channel_closed'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:682:in `channel_close'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:549:in `dispatch_incoming_packets'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:249:in `ev_preprocess'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/event_loop.rb:101:in `each'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/event_loop.rb:101:in `ev_preprocess'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/event_loop.rb:29:in `process'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:228:in `process'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:181:in `block in loop'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:181:in `loop'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/session.rb:181:in `loop'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-ssh-5.0.2/lib/net/ssh/connection/channel.rb:272:in `wait'
	from /opt/vagrant/embedded/gems/2.1.5/gems/net-scp-1.2.1/lib/net/scp.rb:284:in `upload!'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/communicators/ssh/communicator.rb:295:in `block in upload'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/communicators/ssh/communicator.rb:691:in `block in scp_connect'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/communicators/ssh/communicator.rb:339:in `connect'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/communicators/ssh/communicator.rb:689:in `scp_connect'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/communicators/ssh/communicator.rb:292:in `upload'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/provisioners/file/provisioner.rb:42:in `block in provision'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/provisioners/file/provisioner.rb:5:in `tap'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/provisioners/file/provisioner.rb:5:in `provision'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/provision.rb:138:in `run_provisioner'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/environment.rb:526:in `hook'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/provision.rb:126:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/provision.rb:126:in `block in call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/provision.rb:103:in `each'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/provision.rb:103:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/providers/virtualbox/action/check_accessible.rb:18:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/call.rb:53:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/call.rb:53:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/providers/virtualbox/action/check_virtualbox.rb:26:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/call.rb:53:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/box_check_outdated.rb:82:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/providers/virtualbox/action/check_virtualbox.rb:26:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/call.rb:53:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/config_validate.rb:25:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:95:in `block in finalize_action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builtin/call.rb:53:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/plugins/providers/virtualbox/action/check_virtualbox.rb:26:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/warden.rb:34:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/builder.rb:116:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `block in run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/util/busy.rb:19:in `busy'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/action/runner.rb:66:in `run'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/machine.rb:239:in `action_raw'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/machine.rb:208:in `block in action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/environment.rb:614:in `lock'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/machine.rb:194:in `call'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/machine.rb:194:in `action'
	from /opt/vagrant/embedded/gems/2.1.5/gems/vagrant-2.1.5/lib/vagrant/batch_action.rb:82:in `block (2 levels) in run'

This line here looks suspicious DEBUG ssh: Uploading: /<redacted>/scripts/vagrant/docker-build-postgres/. to docker-build-postgres. Why does the path end with docker-build-postgres/. and not simply docker-build-postgres/ or docker-build-postgres? That . should not be there I'd think. Or maybe it should, but whatever macOS 10.14 changed under the hood doesn't like it any longer?! This is just a guess of course.

More details.

My environment is as follows

macOS: 10.14.2 (18C54)


$ vagrant --version
Vagrant 2.2.3

$ which gem
/usr/local/bin/gem

$ gem --version
3.0.1

$ which ruby
/usr/local/bin/ruby

$ ruby --version
ruby 2.6.0p0 (2018-12-25 revision 66547) [x86_64-darwin18]

$ which scp
/usr/bin/scp

$ ls -la /usr/bin/scp
-rwxr-xr-x  1 root  wheel  80896 Nov 30 16:38 /usr/bin/scp

Coworker:

macOS: 10.14.3 (18D109)


$ vagrant --version
Vagrant 2.2.3


$ which gem
/usr/bin/gem

$ gem --version
2.5.2.3

$ which ruby
/usr/bin/ruby

$ ruby --version
ruby 2.3.7p456 (2018-03-28 revision 63024) [universal.x86_64-darwin18]

For now we decided to list all files separately in the Vagrantfile instead of using the folder directly with the file provisioner. That works for us. But maybe this analysis helps someone else figure out what is going on.

Also, since this is a real regression, this issue should be re-opened in my opinion (or create a new one with a better title maybe).

@angoras
Copy link
Author

angoras commented Feb 14, 2019

@briancain

I've used the same path names as the original issue, and Vagrant is able to copy everything just fine as expected. It would be helpful to know what is exactly in your folder that you are expecting to copy over to the guest. My guess is maybe there's an issue with the name of a file you have in that folder.

Thanks for investigating. I really don't think the filenames has got anything to do with it. They have been the same for almost a year, and worked across many versions of both vagrant and MacOS. I'm sorry to say that I upgraded both vagrant from 2.2.2 to 2.2.3 and MacOS from 10.14.2 to 10.14.3 at the same time, so I don't know where the problem originated.

Still, I will still stand by my original suggestion and say that the synced_folder option (with rsync if you must only sync once) is still a much more sane option for something like this. The file provisioner uses scp to copy files, and there are differences across platforms that make this difficult and very bug prone with something like copying folders. The synced_folder option is much more reliable in this case for what you are trying to do.

Thanks, I will try that instead. Maybe this should be mentioned in the documentation then? :-)

@briancain briancain changed the title File provisioner can't find files File provisioner on macOS Mojave 10.14.3 fails to properly copy folders Feb 14, 2019
@briancain briancain reopened this Feb 14, 2019
@ladar
Copy link
Contributor

ladar commented Feb 16, 2019

The problem is with a recent OpenSSH patch. See my analysis here: lavabit/robox#40.

@briancain
Copy link
Member

Hey all. I'm going to go ahead and close this one in favor of #10675 as it seems to have more information as to the actual bug here with net-scp. Thanks!

@ghost
Copy link

ghost commented Mar 28, 2020

I'm going to lock this issue because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active issues.

If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

@ghost ghost locked and limited conversation to collaborators Mar 28, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants