devopsgroup-io/vagrant-digitalocean

Stuck on "default: Assigned IP address:"

Opened this issue · 13 comments

$ vagrant up --provider=digital_ocean
Bringing machine 'default' up with 'digital_ocean' provider...
==> default: Using existing SSH key: Vagrant
==> default: Creating a new droplet...
==> default: Assigned IP address:

After that, the process hangs and nothing happens. I notice it doesn't actually print out the IP address but I can see that the Ruby process is connected to it over SSH. However, after nothing happening for 2 hours i assumed it was stuck. Any ideas here? Running vagrant on Windows.

I have a few steps for you:
Step 1. What version of this plugin you are using?
Step 2. can you destroy your VM in DigitalOcean first by

vagrant destroy

then try to using debug mode

VAGRANT_LOG=debug vagrant up --provider=digital_ocean

to Give me more print out?

Step 3. compare the result in step 2 to the issue #129, to see if it is the same issue
Step 4. This step 3 is yes, then It should be a issue of DigitalOcean API change, follow #130 closely, this pull request should be merge soon.

I'm getting this same problem. It can't connect via SSH, it's trying to connect using:

 INFO ssh:   - Port: 22
 INFO ssh:   - Username: root
 INFO ssh:   - Password? false

But that's not what I've got set in my config.yml

Cheers,

Ewan

I'm encountering a similar problem.

Running VAGRANT_LOG=debug vagrant up --provider=digital_ocean reveals the following:

DEBUG ssh: == Net-SSH connection debug-level log END ==
 INFO retryable: Retryable exception raised: #<Errno::ECONNREFUSED: Connection refused - connect(2)>
 INFO ssh: Attempting to connect to SSH...
 INFO ssh:   - Host: 104.131.209.189
 INFO ssh:   - Port: 22
 INFO ssh:   - Username: root
 INFO ssh:   - Password? false
 INFO ssh:   - Key Path: ["/Users/Olofguard/.ssh/id_rsa"]
DEBUG ssh: == Net-SSH connection debug-level log START ==
DEBUG ssh: D, [2014-08-02T21:26:56.908846 #64089] DEBUG -- net.ssh.transport.session[808fd524]: establishing connection to 104.131.209.189:22

DEBUG ssh: == Net-SSH connection debug-level log END ==
 INFO ssh: SSH not up: #<Vagrant::Errors::SSHConnectionRefused: SSH connection was refused! This usually happens if the VM failed to
boot properly. Some steps to try to fix this: First, try reloading your
VM with `vagrant reload`, since a simple restart sometimes fixes things.
If that doesn't work, destroy your VM and recreate it with a `vagrant destroy`
followed by a `vagrant up`. If that doesn't work, contact a Vagrant
maintainer (support channels listed on the website) for more assistance.>
 INFO retryable: Retryable exception raised: #<RuntimeError: not ready>
DEBUG ssh: Checking whether SSH is ready...
DEBUG ssh: Checking key permissions: /Users/Olofguard/.ssh/id_rsa
 INFO ssh: Attempting SSH connnection...
 INFO ssh: Attempting to connect to SSH...
 INFO ssh:   - Host: 104.131.209.189
 INFO ssh:   - Port: 22
 INFO ssh:   - Username: root
 INFO ssh:   - Password? false
 INFO ssh:   - Key Path: ["/Users/Olofguard/.ssh/id_rsa"]
DEBUG ssh: == Net-SSH connection debug-level log START ==
DEBUG ssh: D, [2014-08-02T21:27:06.956245 #64089] DEBUG -- net.ssh.transport.session[80990b30]: establishing connection to 104.131.209.189:22
D, [2014-08-02T21:27:08.143754 #64089] DEBUG -- net.ssh.transport.session[80990b30]: connection established
I, [2014-08-02T21:27:08.144005 #64089]  INFO -- net.ssh.transport.server_version[80999dfc]: negotiating protocol version
D, [2014-08-02T21:27:08.193651 #64089] DEBUG -- net.ssh.transport.server_version[80999dfc]: remote is `SSH-2.0-OpenSSH_6.6.1p1 Ubuntu-2ubuntu2'
D, [2014-08-02T21:27:08.193788 #64089] DEBUG -- net.ssh.transport.server_version[80999dfc]: local is `SSH-2.0-Ruby/Net::SSH_2.9.1 universal.x86_64-darwin12.5.0'
D, [2014-08-02T21:27:08.236012 #64089] DEBUG -- tcpsocket[809900a4]: read 1632 bytes
D, [2014-08-02T21:27:08.236199 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 0 type 20 len 1628
I, [2014-08-02T21:27:08.236295 #64089]  INFO -- net.ssh.transport.algorithms[8099d77c]: got KEXINIT from server
I, [2014-08-02T21:27:08.236551 #64089]  INFO -- net.ssh.transport.algorithms[8099d77c]: sending KEXINIT
D, [2014-08-02T21:27:08.236776 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 0 type 20 len 2020
D, [2014-08-02T21:27:08.236864 #64089] DEBUG -- tcpsocket[809900a4]: sent 2024 bytes
I, [2014-08-02T21:27:08.236906 #64089]  INFO -- net.ssh.transport.algorithms[8099d77c]: negotiating algorithms
D, [2014-08-02T21:27:08.237062 #64089] DEBUG -- net.ssh.transport.algorithms[8099d77c]: 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-08-02T21:27:08.237101 #64089] DEBUG -- net.ssh.transport.algorithms[8099d77c]: exchanging keys
D, [2014-08-02T21:27:08.237332 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 1 type 34 len 20
D, [2014-08-02T21:27:08.237392 #64089] DEBUG -- tcpsocket[809900a4]: sent 24 bytes
D, [2014-08-02T21:27:08.314691 #64089] DEBUG -- tcpsocket[809900a4]: read 152 bytes
D, [2014-08-02T21:27:08.314889 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 1 type 31 len 148
D, [2014-08-02T21:27:08.317045 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 2 type 32 len 140
D, [2014-08-02T21:27:08.317152 #64089] DEBUG -- tcpsocket[809900a4]: sent 144 bytes
D, [2014-08-02T21:27:08.359299 #64089] DEBUG -- tcpsocket[809900a4]: read 720 bytes
D, [2014-08-02T21:27:08.359549 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 2 type 33 len 700
D, [2014-08-02T21:27:08.361439 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 3 type 21 len 20
D, [2014-08-02T21:27:08.361593 #64089] DEBUG -- tcpsocket[809900a4]: sent 24 bytes
D, [2014-08-02T21:27:08.361731 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 3 type 21 len 12
D, [2014-08-02T21:27:08.362255 #64089] DEBUG -- net.ssh.authentication.session[80ad18dc]: beginning authentication of `root'
D, [2014-08-02T21:27:08.362443 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 4 type 5 len 28
D, [2014-08-02T21:27:08.362529 #64089] DEBUG -- tcpsocket[809900a4]: sent 52 bytes
D, [2014-08-02T21:27:08.514288 #64089] DEBUG -- tcpsocket[809900a4]: read 52 bytes
D, [2014-08-02T21:27:08.514511 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 4 type 6 len 28
D, [2014-08-02T21:27:08.514690 #64089] DEBUG -- net.ssh.authentication.session[80ad18dc]: trying none
D, [2014-08-02T21:27:08.514936 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 5 type 50 len 44
D, [2014-08-02T21:27:08.515044 #64089] DEBUG -- tcpsocket[809900a4]: sent 68 bytes
D, [2014-08-02T21:27:36.670542 #64089] DEBUG -- tcpsocket[809900a4]: read 68 bytes
D, [2014-08-02T21:27:36.670799 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 5 type 51 len 44
D, [2014-08-02T21:27:36.671014 #64089] DEBUG -- net.ssh.authentication.session[80ad18dc]: allowed methods: publickey,password
D, [2014-08-02T21:27:36.671154 #64089] DEBUG -- net.ssh.authentication.methods.none[80ad43c0]: none failed
D, [2014-08-02T21:27:36.671296 #64089] DEBUG -- net.ssh.authentication.session[80ad18dc]: trying publickey
D, [2014-08-02T21:27:36.671794 #64089] DEBUG -- net.ssh.authentication.agent[80adcc00]: connecting to ssh-agent
D, [2014-08-02T21:27:36.671982 #64089] DEBUG -- net.ssh.authentication.agent[80adcc00]: sending agent request 1 len 61
D, [2014-08-02T21:27:36.672137 #64089] DEBUG -- net.ssh.authentication.agent[80adcc00]: received agent packet 2 len 5
D, [2014-08-02T21:27:36.672213 #64089] DEBUG -- net.ssh.authentication.agent[80adcc00]: sending agent request 11 len 0
D, [2014-08-02T21:27:36.672366 #64089] DEBUG -- net.ssh.authentication.agent[80adcc00]: received agent packet 12 len 5
D, [2014-08-02T21:27:36.672628 #64089] DEBUG -- net.ssh.authentication.methods.publickey[80add330]: trying publickey (5e:16:c5:e8:87:44:f6:a9:17:1e:cd:28:03:ad:8f:cc)
D, [2014-08-02T21:27:36.672881 #64089] DEBUG -- tcpsocket[809900a4]: queueing packet nr 6 type 50 len 348
D, [2014-08-02T21:27:36.673021 #64089] DEBUG -- tcpsocket[809900a4]: sent 372 bytes
D, [2014-08-02T21:27:36.713643 #64089] DEBUG -- tcpsocket[809900a4]: read 68 bytes
D, [2014-08-02T21:27:36.713858 #64089] DEBUG -- tcpsocket[809900a4]: received packet nr 6 type 51 len 44
D, [2014-08-02T21:27:36.714018 #64089] DEBUG -- net.ssh.authentication.session[80ad18dc]: allowed methods: publickey,password
D, [2014-08-02T21:27:36.714106 #64089] DEBUG -- net.ssh.authentication.session[80ad18dc]: trying password
E, [2014-08-02T21:27:36.714208 #64089] ERROR -- net.ssh.authentication.session[80ad18dc]: all authorization methods failed (tried none, publickey, password)

I have been stuck on this for hours, after already fighting for hours to get the digital_ocean vagrant plugin installed, and I'm not sure where to go from here. Any help is greatly appreciated.

Thanks,

Olofguard

@khromov Do you try to set the ssh_key_name property in your Vagrantfile ?

@EwanValentine if you're using a non-default ssh port, you and I may have had the same problem. It appears that the DO plugin must initiate the DO droplet using ssh port 22. If the user has set a non-default port for config.ssh.port in the Vagrantfile, the vagrant up droplet creation hangs forever due to the DO plugin's inability to connect via ssh (and there is no message to the log).

Here is how I adjusted /lib/vagrant-digitalocean/actions/create.rb to accommodate a non-default ssh port for Ubuntu. Maybe it will help.

Hi there, I'm also having this problem. It takes a lot of time in the "assigning IP address", shows the IP assigned but starts giving this connection errors. It's trying to connect as root.

DEBUG ssh: Checking whether SSH is ready...
DEBUG ssh: Checking key permissions: /home/erika/.ssh/id_rsa
 INFO ssh: Attempting SSH connnection...
 INFO ssh: Attempting to connect to SSH...
 INFO ssh:   - Host: 104.131.245.85
 INFO ssh:   - Port: 22
 INFO ssh:   - Username: root
 INFO ssh:   - Password? false
 INFO ssh:   - Key Path: ["/home/erika/.ssh/id_rsa"]
DEBUG ssh: == Net-SSH connection debug-level log START ==
DEBUG ssh: D, [2014-09-23T22:31:21.765461 #21926] DEBUG -- net.ssh.transport.session[e2976c]: establishing connection to 104.131.245.85:22
D, [2014-09-23T22:31:21.870472 #21926] DEBUG -- net.ssh.transport.session[e2976c]: connection established
I, [2014-09-23T22:31:21.871247 #21926]  INFO -- net.ssh.transport.server_version[e28b00]: negotiating protocol version
D, [2014-09-23T22:31:21.975891 #21926] DEBUG -- net.ssh.transport.server_version[e28b00]: remote is `SSH-2.0-OpenSSH_6.6.1p1 Ubuntu-2ubuntu2'
D, [2014-09-23T22:31:21.976210 #21926] DEBUG -- net.ssh.transport.server_version[e28b00]: local is `SSH-2.0-Ruby/Net::SSH_2.9.1 x86_64-linux'
D, [2014-09-23T22:31:22.082595 #21926] DEBUG -- tcpsocket[e29140]: read 1632 bytes
D, [2014-09-23T22:31:22.082804 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 0 type 20 len 1628
I, [2014-09-23T22:31:22.082898 #21926]  INFO -- net.ssh.transport.algorithms[e32a9c]: got KEXINIT from server
I, [2014-09-23T22:31:22.083059 #21926]  INFO -- net.ssh.transport.algorithms[e32a9c]: sending KEXINIT
D, [2014-09-23T22:31:22.083282 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 0 type 20 len 2020
D, [2014-09-23T22:31:22.083361 #21926] DEBUG -- tcpsocket[e29140]: sent 2024 bytes
I, [2014-09-23T22:31:22.083406 #21926]  INFO -- net.ssh.transport.algorithms[e32a9c]: negotiating algorithms
D, [2014-09-23T22:31:22.083554 #21926] DEBUG -- net.ssh.transport.algorithms[e32a9c]: 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-09-23T22:31:22.083590 #21926] DEBUG -- net.ssh.transport.algorithms[e32a9c]: exchanging keys
D, [2014-09-23T22:31:22.083794 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 1 type 34 len 20
D, [2014-09-23T22:31:22.083841 #21926] DEBUG -- tcpsocket[e29140]: sent 24 bytes
D, [2014-09-23T22:31:22.286886 #21926] DEBUG -- tcpsocket[e29140]: read 152 bytes
D, [2014-09-23T22:31:22.287315 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 1 type 31 len 148
D, [2014-09-23T22:31:22.292485 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 2 type 32 len 140
D, [2014-09-23T22:31:22.292633 #21926] DEBUG -- tcpsocket[e29140]: sent 144 bytes
D, [2014-09-23T22:31:22.392802 #21926] DEBUG -- tcpsocket[e29140]: read 720 bytes
D, [2014-09-23T22:31:22.393231 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 2 type 33 len 700
D, [2014-09-23T22:31:22.397600 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 3 type 21 len 20
D, [2014-09-23T22:31:22.397909 #21926] DEBUG -- tcpsocket[e29140]: sent 24 bytes
D, [2014-09-23T22:31:22.398330 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 3 type 21 len 12
D, [2014-09-23T22:31:22.399365 #21926] DEBUG -- net.ssh.authentication.session[dbbe38]: beginning authentication of `root'
D, [2014-09-23T22:31:22.399783 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 4 type 5 len 28
D, [2014-09-23T22:31:22.400048 #21926] DEBUG -- tcpsocket[e29140]: sent 52 bytes
D, [2014-09-23T22:31:22.635246 #21926] DEBUG -- tcpsocket[e29140]: read 52 bytes
D, [2014-09-23T22:31:22.635738 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 4 type 6 len 28
D, [2014-09-23T22:31:22.636170 #21926] DEBUG -- net.ssh.authentication.session[dbbe38]: trying none
D, [2014-09-23T22:31:22.636685 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 5 type 50 len 44
D, [2014-09-23T22:31:22.636940 #21926] DEBUG -- tcpsocket[e29140]: sent 68 bytes
D, [2014-09-23T22:31:22.774939 #21926] DEBUG -- tcpsocket[e29140]: read 68 bytes
D, [2014-09-23T22:31:22.775437 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 5 type 51 len 44
D, [2014-09-23T22:31:22.775754 #21926] DEBUG -- net.ssh.authentication.session[dbbe38]: allowed methods: publickey,password
D, [2014-09-23T22:31:22.776053 #21926] DEBUG -- net.ssh.authentication.methods.none[dbcf40]: none failed
D, [2014-09-23T22:31:22.776291 #21926] DEBUG -- net.ssh.authentication.session[dbbe38]: trying publickey
D, [2014-09-23T22:31:22.777033 #21926] DEBUG -- net.ssh.authentication.agent[dbf2e0]: connecting to ssh-agent
D, [2014-09-23T22:31:22.777388 #21926] DEBUG -- net.ssh.authentication.agent[dbf2e0]: sending agent request 1 len 44
D, [2014-09-23T22:31:22.778501 #21926] DEBUG -- net.ssh.authentication.agent[dbf2e0]: received agent packet 2 len 5
D, [2014-09-23T22:31:22.778721 #21926] DEBUG -- net.ssh.authentication.agent[dbf2e0]: sending agent request 11 len 0
D, [2014-09-23T22:31:22.780832 #21926] DEBUG -- net.ssh.authentication.agent[dbf2e0]: received agent packet 12 len 317
D, [2014-09-23T22:31:22.781839 #21926] DEBUG -- net.ssh.authentication.methods.publickey[dbf920]: trying publickey (7a:3f:1e:0a:f2:b9:17:db:b9:81:63:82:aa:60:55:3d)
D, [2014-09-23T22:31:22.782560 #21926] DEBUG -- tcpsocket[e29140]: queueing packet nr 6 type 50 len 348
D, [2014-09-23T22:31:22.782889 #21926] DEBUG -- tcpsocket[e29140]: sent 372 bytes
D, [2014-09-23T22:31:22.881139 #21926] DEBUG -- tcpsocket[e29140]: read 68 bytes
D, [2014-09-23T22:31:22.881720 #21926] DEBUG -- tcpsocket[e29140]: received packet nr 6 type 51 len 44
D, [2014-09-23T22:31:22.882284 #21926] DEBUG -- net.ssh.authentication.session[dbbe38]: allowed methods: publickey,password
D, [2014-09-23T22:31:22.882492 #21926] DEBUG -- net.ssh.authentication.session[dbbe38]: trying password
E, [2014-09-23T22:31:22.882711 #21926] ERROR -- net.ssh.authentication.session[dbbe38]: 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.>
 INFO retryable: Retryable exception raised: #<RuntimeError: not ready>

Do we need to do anything else than set up the override.ssh.private_key_path ?

I think @qpautrat is right. I had this issue as well.
I got it working by making sure I used both a new SSH key and assigning it a name that does not exist in my account.

@stevemartingale Can you please detail a bit more what you've exactly done so we can fix the problem in our turn :)

Thanks.

This happened to me when my ssh key was in a folder shared with a Windows host and vagrant wasn't able to set the permissions on the key to 0600. I fixed this by copying the key to ~/.ssh/ and updating ssh.private_key_path

This issue seems to only occur now when the end user has an SSH key already specified in their account with the default name "Vagrant". This issue can probably be closed, but it might be wise to add something to the README about it.

Confirming that I solved my previous issue by removing an old "Vagrant" SSH key in my account and using a local dedicated SSH key to Vagrant, since I got errors when trying to use my default SSH keypair - API saying that this key was a duplicate because it was already added in my DO account.

I ran into this problem today myself and specified the provider.ssh_key_name in my Vagrantfile that corresponded to an existing key pair that I had associated with my DO account.

Making it clear in README.md about the behavior of the DO Vagrant plugin attempting to use "Vagrant" by default would be helpful.

Also, does the DO Vagrant plugin attempt to create an SSH key called "Vagrant" if one is not already specified but a successful API call occurs?

Battled with this same issue for hours trying different solutions suggested until I found out that I had config.ssh.username and config.ssh.password set in my VagrantFile.

Apparently, those are used for authentication instead of the ssh key. Removing them solved the issue for me.