nsidc / vagrant-vsphere

VMware vSphere provider for Vagrant
Other
607 stars 166 forks source link

Unable to 'vagrant ssh', can ssh from CLI just fine #48

Open rcarrillocruz opened 10 years ago

rcarrillocruz commented 10 years ago

Hi guys

After using the workaround for issue https://github.com/nsidc/vagrant-vsphere/issues/28 to force the use of nokogiri 1.5.5, I can successfully create VMs on my VCenter. However, upon creation, the ssh connection is never made as apparently no hostname value is passed. This is the debug log:

vagrant@vagrant-jumpbox:~/bug1226155$ VAGRANT_LOG=DEBUG vagrant up
 INFO global: Vagrant version: 1.2.2
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/suspend/plugin.rb
 INFO manager: Registered plugin: suspend command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/resume/plugin.rb
 INFO manager: Registered plugin: resume command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/ssh/plugin.rb
 INFO manager: Registered plugin: ssh command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/plugin/plugin.rb
 INFO manager: Registered plugin: plugin command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/halt/plugin.rb
 INFO manager: Registered plugin: halt command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/provision/plugin.rb
 INFO manager: Registered plugin: provision command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/package/plugin.rb
 INFO manager: Registered plugin: package command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/box/plugin.rb
 INFO manager: Registered plugin: box command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/reload/plugin.rb
 INFO manager: Registered plugin: reload command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/destroy/plugin.rb
 INFO manager: Registered plugin: destroy command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/status/plugin.rb
 INFO manager: Registered plugin: status command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/up/plugin.rb
 INFO manager: Registered plugin: up command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/ssh_config/plugin.rb
 INFO manager: Registered plugin: ssh-config command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/commands/init/plugin.rb
 INFO manager: Registered plugin: init command
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/kernel_v2/plugin.rb
 INFO manager: Registered plugin: kernel
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/communicators/ssh/plugin.rb
 INFO manager: Registered plugin: ssh communicator
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/freebsd/plugin.rb
 INFO manager: Registered plugin: FreeBSD host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/opensuse/plugin.rb
 INFO manager: Registered plugin: OpenSUSE host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/bsd/plugin.rb
 INFO manager: Registered plugin: BSD host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/linux/plugin.rb
 INFO manager: Registered plugin: Linux host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/gentoo/plugin.rb
 INFO manager: Registered plugin: Gentoo host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/arch/plugin.rb
 INFO manager: Registered plugin: Arch host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/windows/plugin.rb
 INFO manager: Registered plugin: Windows host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/hosts/fedora/plugin.rb
 INFO manager: Registered plugin: Fedora host
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/providers/virtualbox/plugin.rb
 INFO manager: Registered plugin: VirtualBox provider
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/kernel_v1/plugin.rb
 INFO manager: Registered plugin: kernel
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/suse/plugin.rb
 INFO manager: Registered plugin: SUSE guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/freebsd/plugin.rb
 INFO manager: Registered plugin: FreeBSD guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/solaris/plugin.rb
 INFO manager: Registered plugin: Solaris guest.
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/debian/plugin.rb
 INFO manager: Registered plugin: Debian guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/pld/plugin.rb
 INFO manager: Registered plugin: PLD Linux guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/redhat/plugin.rb
 INFO manager: Registered plugin: RedHat guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/linux/plugin.rb
 INFO manager: Registered plugin: Linux guest.
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/openbsd/plugin.rb
 INFO manager: Registered plugin: OpenBSD guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/gentoo/plugin.rb
 INFO manager: Registered plugin: Gentoo guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/arch/plugin.rb
 INFO manager: Registered plugin: Arch guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/ubuntu/plugin.rb
 INFO manager: Registered plugin: Ubuntu guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/guests/fedora/plugin.rb
 INFO manager: Registered plugin: Fedora guest
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/provisioners/puppet/plugin.rb
 INFO manager: Registered plugin: puppet
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/provisioners/cfengine/plugin.rb
 INFO manager: Registered plugin: CFEngine Provisioner
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/provisioners/ansible/plugin.rb
 INFO manager: Registered plugin: ansible
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/provisioners/shell/plugin.rb
 INFO manager: Registered plugin: shell
DEBUG global: Loading core plugin: /usr/share/vagrant/plugins/provisioners/chef/plugin.rb
 INFO manager: Registered plugin: chef
 INFO vagrant: `vagrant` invoked: ["up"]
DEBUG vagrant: Creating Vagrant environment
 INFO environment: Environment initialized (#<Vagrant::Environment:0x000000024240a8>)
 INFO environment:   - cwd: /home/vagrant/bug1226155
 INFO environment: Home path: /home/vagrant/.vagrant.d
 INFO environment: Local data path: /home/vagrant/bug1226155/.vagrant
DEBUG environment: Creating: /home/vagrant/bug1226155/.vagrant
DEBUG environment: Loading plugins from: /home/vagrant/.vagrant.d/plugins.json
 INFO environment: Loading plugin from JSON: vagrant-vsphere
 INFO manager: Registered plugin: vsphere
 INFO environment: Running hook: environment_load
 INFO environment: Initializing config...
 INFO loader: Set :default = "/usr/share/vagrant/config/default.rb"
DEBUG loader: Populating proc cache for "/usr/share/vagrant/config/default.rb"
DEBUG loader: Load procs for pathname: /usr/share/vagrant/config/default.rb
 INFO loader: Set :root = #<Pathname:/home/vagrant/bug1226155/Vagrantfile>
DEBUG loader: Populating proc cache for #<Pathname:/home/vagrant/bug1226155/Vagrantfile>
DEBUG loader: Load procs for pathname: /home/vagrant/bug1226155/Vagrantfile
 INFO loader: Loading configuration in order: [:default, :home, :root]
DEBUG loader: Loading from: default (evaluating)
DEBUG loader: Loading from: root (evaluating)
DEBUG loader: Configuration loaded successfully, finalizing and returning
DEBUG hosts: Host path search classes: [VagrantPlugins::HostFedora::Host, VagrantPlugins::HostWindows::Host, VagrantPlugins::HostArch::Host, VagrantPlugins::HostFreeBSD::Host, VagrantPlugins::HostOpenSUSE::Host, VagrantPlugins::HostGentoo::Host, VagrantPlugins::HostLinux::Host, VagrantPlugins::HostBSD::Host]
 INFO hosts: Host class: VagrantPlugins::HostLinux::Host
 INFO runner: Running action: #<Vagrant::Action::Builder:0x000000024f55e0>
 INFO cli: CLI: [] "up" []
DEBUG cli: Invoking command class: VagrantPlugins::CommandUp::Command []
DEBUG command: 'Up' each target VM...
DEBUG command: Getting target VMs for command. Arguments:
DEBUG command:  -- names: []
DEBUG command:  -- options: {:provider=>nil}
DEBUG command: Loading all machines...
 INFO environment: Getting machine: default (vsphere)
 INFO environment: Uncached load of machine.
 INFO loader: Set :vm_default = []
 INFO loader: Loading configuration in order: [:default, :home, :root, :vm_default]
DEBUG loader: Loading from: default (cache)
DEBUG loader: Loading from: root (cache)
DEBUG loader: Configuration loaded successfully, finalizing and returning
 INFO environment: Provider-supported box formats: [:vsphere]
 INFO box_collection: Searching for box: ubuntu1310 (vsphere) in /home/vagrant/.vagrant.d/boxes/ubuntu1310/vsphere/metadata.json
 INFO box_collection: Box not found: ubuntu1310 (vsphere)
 INFO machine: Initializing machine: default
 INFO machine:   - Provider: VagrantPlugins::VSphere::Provider
 INFO machine:   - Box:
 INFO machine:   - Data dir: /home/vagrant/bug1226155/.vagrant/machines/default/vsphere
 INFO command: With machine: default (vSphere (new))
 INFO interface: info: Bringing machine 'default' up with 'vsphere' provider...
Bringing machine 'default' up with 'vsphere' provider...
 INFO batch_action: Enabling parallelization by default.
 INFO batch_action: Disabling parallelization because provider doesn't support it: vsphere
 INFO batch_action: Batch action will parallelize: false
 INFO batch_action: Starting action: #<Vagrant::Machine:0x00000002be1340> up {:parallel=>true, :provision_enabled=>true, :provision_types=>nil}
 INFO machine: Calling action: up on provider vSphere (new)
 INFO runner: Running action: #<Vagrant::Action::Builder:0x00000002a53f78>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x007ff034f39e00>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::ConnectVSphere:0x007ff034f39dd8>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::Call:0x007ff034f39db0>
 INFO runner: Running action: #<Vagrant::Action::Builder:0x007ff03408d1b8>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::IsCreated:0x007ff034091bc8>
 INFO machine: Calling action: get_state on provider vSphere (new)
 INFO runner: Running action: #<Vagrant::Action::Builder:0x007ff0344532c0>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x007ff03449ea68>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::ConnectVSphere:0x007ff03449ea18>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::GetState:0x007ff03449e9c8>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::CloseVSphere:0x007ff03449e978>
 INFO runner: Running action: #<Vagrant::Action::Warden:0x007ff0346a7ad0>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::Clone:0x007ff0346a79b8>
 INFO interface: info: Calling vSphere CloneVM with the following settings:
[default] Calling vSphere CloneVM with the following settings:
 INFO interface: info:  -- Source VM: ubuntu1310
[default]  -- Source VM: ubuntu1310
 INFO interface: info:  -- Name: bug1226155
[default]  -- Name: bug1226155
 INFO interface: info: Waiting for SSH to become available...
[default] Waiting for SSH to become available...
DEBUG ssh: Checking whether SSH is ready...
 INFO machine: Calling action: get_ssh_info on provider vSphere (4225307e-7ec4-e2c0-948e-b7def220653d)
 INFO runner: Running action: #<Vagrant::Action::Builder:0x007ff0344b6118>
 INFO warden: Calling action: #<Vagrant::Action::Builtin::ConfigValidate:0x007ff034517eb8>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::ConnectVSphere:0x007ff034517e68>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::GetSshInfo:0x007ff034517da0>
 INFO warden: Calling action: #<VagrantPlugins::VSphere::Action::CloseVSphere:0x007ff034517cd8>
DEBUG ssh: Checking key permissions: /home/vagrant/.vagrant.d/insecure_private_key
 INFO ssh: Attempting SSH. Retries: 100. Timeout: 30
 INFO ssh: Attempting to connect to SSH...
 INFO ssh:   - Host:
 INFO ssh:   - Port: 22
 INFO ssh:   - Username: vagrant
 INFO ssh:   - Key Path: /home/vagrant/.vagrant.d/insecure_private_key
DEBUG ssh: == Net-SSH connection debug-level log START ==
DEBUG ssh: D, [2014-03-21T12:21:26.086182 #13039] DEBUG -- net.ssh.transport.session[3ff81a1cbe28]: establishing connection to :22
D, [2014-03-21T12:21:26.087878 #13039] DEBUG -- net.ssh.transport.session[3ff81a1cbe28]: connection established
I, [2014-03-21T12:21:26.088026 #13039]  INFO -- net.ssh.transport.server_version[3ff81a1ccff8]: negotiating protocol version
D, [2014-03-21T12:21:26.094173 #13039] DEBUG -- net.ssh.transport.server_version[3ff81a1ccff8]: remote is `SSH-2.0-OpenSSH_6.2p2 Ubuntu-6'
D, [2014-03-21T12:21:26.094279 #13039] DEBUG -- net.ssh.transport.server_version[3ff81a1ccff8]: local is `SSH-2.0-Ruby/Net::SSH_2.6.7 x86_64-linux'
D, [2014-03-21T12:21:26.095910 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: read 1544 bytes
D, [2014-03-21T12:21:26.096069 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: received packet nr 0 type 20 len 1540
I, [2014-03-21T12:21:26.096187 #13039]  INFO -- net.ssh.transport.algorithms[3ff81a756014]: got KEXINIT from server
I, [2014-03-21T12:21:26.096394 #13039]  INFO -- net.ssh.transport.algorithms[3ff81a756014]: sending KEXINIT
D, [2014-03-21T12:21:26.096615 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: queueing packet nr 0 type 20 len 1620
D, [2014-03-21T12:21:26.096735 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: sent 1624 bytes
I, [2014-03-21T12:21:26.096798 #13039]  INFO -- net.ssh.transport.algorithms[3ff81a756014]: negotiating algorithms
D, [2014-03-21T12:21:26.097051 #13039] DEBUG -- net.ssh.transport.algorithms[3ff81a756014]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: aes128-cbc
* encryption_client: aes128-cbc
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2014-03-21T12:21:26.097118 #13039] DEBUG -- net.ssh.transport.algorithms[3ff81a756014]: exchanging keys
D, [2014-03-21T12:21:26.097422 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: queueing packet nr 1 type 34 len 20
D, [2014-03-21T12:21:26.097526 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: sent 24 bytes
D, [2014-03-21T12:21:26.100563 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: read 152 bytes
D, [2014-03-21T12:21:26.100683 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: received packet nr 1 type 31 len 148
D, [2014-03-21T12:21:26.103387 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: queueing packet nr 2 type 32 len 140
D, [2014-03-21T12:21:26.103489 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: sent 144 bytes
D, [2014-03-21T12:21:26.107071 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: read 720 bytes
D, [2014-03-21T12:21:26.107169 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: received packet nr 2 type 33 len 700
D, [2014-03-21T12:21:26.109056 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: queueing packet nr 3 type 21 len 20
D, [2014-03-21T12:21:26.109157 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: sent 24 bytes
D, [2014-03-21T12:21:26.109252 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: received packet nr 3 type 21 len 12
D, [2014-03-21T12:21:26.109577 #13039] DEBUG -- net.ssh.authentication.session[3ff81a77adec]: beginning authentication of `vagrant'
D, [2014-03-21T12:21:26.109723 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: queueing packet nr 4 type 5 len 28
D, [2014-03-21T12:21:26.109792 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: sent 52 bytes
D, [2014-03-21T12:21:26.147166 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: read 52 bytes
D, [2014-03-21T12:21:26.147315 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: received packet nr 4 type 6 len 28
D, [2014-03-21T12:21:26.147462 #13039] DEBUG -- net.ssh.authentication.session[3ff81a77adec]: trying none
D, [2014-03-21T12:21:26.147620 #13039] DEBUG -- net.ssh.authentication.session[3ff81a77adec]: Mechanism none was requested, but isn't a known type.  Ignoring it.
D, [2014-03-21T12:21:26.147683 #13039] DEBUG -- net.ssh.authentication.session[3ff81a77adec]: trying publickey
D, [2014-03-21T12:21:26.148074 #13039] DEBUG -- net.ssh.authentication.agent[3ff81a77c5e8]: connecting to ssh-agent
E, [2014-03-21T12:21:26.148236 #13039] ERROR -- net.ssh.authentication.agent[3ff81a77c5e8]: could not connect to ssh-agent
D, [2014-03-21T12:21:26.148500 #13039] DEBUG -- net.ssh.authentication.methods.publickey[3ff81a77c7a0]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6)
D, [2014-03-21T12:21:26.148701 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: queueing packet nr 5 type 50 len 348
D, [2014-03-21T12:21:26.151102 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: sent 372 bytes
D, [2014-03-21T12:21:26.152239 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: read 68 bytes
D, [2014-03-21T12:21:26.152402 #13039] DEBUG -- tcpsocket[3ff81a1ce3a8]: received packet nr 5 type 51 len 44
D, [2014-03-21T12:21:26.152529 #13039] DEBUG -- net.ssh.authentication.session[3ff81a77adec]: allowed methods: publickey,password
D, [2014-03-21T12:21:26.152602 #13039] DEBUG -- net.ssh.authentication.session[3ff81a77adec]: trying password
E, [2014-03-21T12:21:26.152684 #13039] ERROR -- net.ssh.authentication.session[3ff81a77adec]: all authorization methods failed (tried none, publickey, password)

DEBUG ssh: == Net-SSH connection debug-level log END ==
 INFO ssh: SSH not up: #<Vagrant::Errors::SSHAuthenticationFailed: SSH authentication failed! This is typically caused by the public/private
keypair for the SSH user not being properly set on the guest VM. Please
verify that the guest VM is setup with the proper public key, and that
the private key path for Vagrant is setup properly as well.>

However, if I ssh to the box just created with the vagrant private key I can ssh just fine:

vagrant@vagrant-jumpbox:~$ ssh -i ~/.vagrant.d/insecure_private_key 192.168.1.146
The authenticity of host '192.168.1.146 (192.168.1.146)' can't be established.
ECDSA key fingerprint is ea:83:c3:d3:46:16:49:01:8f:20:f8:4e:b3:50:83:0c.
Are you sure you want to continue connecting (yes/no)? yes
Warning: Permanently added '192.168.1.146' (ECDSA) to the list of known hosts.
Welcome to Ubuntu 13.10 (GNU/Linux 3.11.0-12-generic x86_64)

 * Documentation:  https://help.ubuntu.com/

  System information as of Fri Mar 21 12:26:53 CET 2014

  System load:  0.0               Processes:           83
  Usage of /:   2.9% of 35.07GB   Users logged in:     0
  Memory usage: 1%                IP address for eth0: 192.168.1.146
  Swap usage:   0%

  Graph this data and manage this system at:
    https://landscape.canonical.com/

90 packages can be updated.
43 updates are security updates.

Last login: Fri Mar 21 12:26:53 2014
vagrant@ubuntu1310:~$

One thing I noted is that 'vagrant ssh-config' won't show any value for HostName:

vagrant@vagrant-jumpbox:~/bug1226155$ vagrant ssh-config
Host default
  HostName
  User vagrant
  Port 22
  UserKnownHostsFile /dev/null
  StrictHostKeyChecking no
  PasswordAuthentication no
  IdentityFile "/home/vagrant/.vagrant.d/insecure_private_key"
  IdentitiesOnly yes
  LogLevel FATAL

I was expecting HostName to be 127.0.0.1 and Port 2222 as with VirtualBox vms?

This is the Vagrantfile, just in case it's also relevant:

vagrant@vagrant-jumpbox:~/bug1226155$ cat Vagrantfile
Vagrant.configure("2") do |config|
  config.vm.box = 'ubuntu1310'
  config.vm.box_url = './ubuntu1310.box'

  config.vm.provider :vsphere do |vsphere|
    vsphere.host = '192.168.1.23'
    vsphere.name = 'bug1226155'
    vsphere.clone_from_vm = true
    vsphere.template_name = 'ubuntu1310'
    #vsphere.compute_resource_name = '192.168.1.22'
    #vsphere.resource_pool_name = ''
    vsphere.user = 'root'
    vsphere.password = 'vmware'
    vsphere.insecure = true
  end

end
asmaier commented 10 years ago

Is this problem related to this one: https://github.com/nsidc/vagrant-vsphere/issues/50 ?