authentication ssh capistrano capistrano3 sshkit

Capistrano can't deploy to new Ubuntu server because SSHKit / Net::SSH can't authenticate

I'm trying to set up a staging/testing server for a new version of an application I'm working on. So I have set it up so that my local account can authenticate into the deployment server without having to type in a password:

$ ssh [email protected]
Welcome to Ubuntu 16.04 LTS (GNU/Linux 4.4.0-28-generic x86_64)

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

0 packages can be updated.
0 updates are security updates.

Last login: Thu Jul  7 15:53:38 2016 from 10.10.12.50
tester@app-staging:~$ logout

Now I try to get in with Capistrano, but it just rejects me straight away:

$ cap staging deploy:check

$ cap staging deploy:check
(Backtrace restricted to imported tasks)
cap aborted!
Net::SSH::AuthenticationFailed: Authentication failed for user [email protected]

Tasks: TOP => rbenv:validate
(See full trace by running task with --trace)

Investigation so far:

Initially I was doing this with all the hacks required the last time anyone deployed the application, so to remove a lot of things from the equation, I moved all my files aside and had Capistrano generate new deployment configs. So this is all running on the bare minimum config right now, and it still can't authenticate.
I was originally assuming public key authentication would be used by default, because the Capistrano docs say that the user's SSH config file would be used. I now know that this is not the case, and that you have to explicitly put 'publickey' in as a method. So before this, it was asking for a password. I was hoping that getting it not to ask for a password was the hardest thing I was going to have to figure out, but apparently not.
I am not entirely sure whether the "keys" setting is necessary because, again, if Capistrano isn't using the settings from my config, it might not be picking up the key files either. So I tried putting the path to the file in manually, but it doesn't change things anyway.
I used to have a .pub on the end of the key filename, until realising that it probably wanted the private key. But after removing it, I get the exact same result.
Thanks to a suggestion in the comments, I removed the password from the server declaration, since I think getting sudo to work without a password is a cleaner solution anyway. Same result, though.

Now I'm kind of out of ideas for how to diagnose this.

I can't tell whether there is any Capistrano equivalent to ssh -v in order to get more information about what it's trying to do.

Clearly my SSH connection is fine, but Capistrano isn't using the right settings to connect, so maybe I have the syntax wrong or something equally obvious. To that end, here are the files I currently have:

Capfile:

require 'capistrano/setup'
require 'capistrano/deploy'
require 'capistrano/rbenv'
require 'capistrano/bundler'
require 'capistrano/rails/assets'
require 'capistrano/rails/migrations'
require 'capistrano/nginx'

Dir.glob("lib/capistrano/tasks/*.rake").each { |r| import r }

config/deploy.rb:

lock '3.5.0'

set :application, 'app'

set :scm, :svn
set :repo_url, 'https://svn.acme.com/app/trunk'

set :ssh_options, {
  auth_methods: ['publickey'],
  keys: ['~/.ssh/id_ed25519'],
}

config/deploy/staging.rb:

set :rails_env, 'staging'

server 'all-staging.acme.com', user: 'tester', port: 22,
       roles: %w{web app db}

set :deploy_to, '/var/www/app/staging'

Chasing the problem into sshkit:

I noticed that capistrano uses sshkit to do the actual SSH work, so I wrote a test program for that.

#!/usr/bin/env ruby

require 'sshkit'
require 'sshkit/dsl'

include SSHKit::DSL

SSHKit.config.output_verbosity = Logger::DEBUG

on '[email protected]' do
  puts capture(:ls, '-l')
end

This exhibits the same issue, where it asks for the password despite supposedly defaulting to use the same key. Although setting the verbosity to DEBUG hasn't really added any useful diagnostics to go work.

Chasing the problem into Net::SSH:

When installing gems for sshkit, I noticed that it was using yet another SSH library, net-ssh, to do the actual SSH work, so I tried making a new test program which just used that.

$ cat test 
#!/usr/bin/env ruby

require 'net/ssh'

Net::SSH.start('portal-staging.syd.nuix.com', 'tester', verbose: :debug) do |ssh|
  output = ssh.exec!("ls -l")
  puts output
end

This time, the debug output is useful:

$ ./test 
D, [2016-07-08T10:52:56.725877 #56100] DEBUG -- net.ssh.transport.session[3fe8c6916074]: establishing connection to app-staging.acme.com:22
D, [2016-07-08T10:52:56.727988 #56100] DEBUG -- net.ssh.transport.session[3fe8c6916074]: connection established
I, [2016-07-08T10:52:56.728056 #56100]  INFO -- net.ssh.transport.server_version[3fe8c6913414]: negotiating protocol version
D, [2016-07-08T10:52:56.728080 #56100] DEBUG -- net.ssh.transport.server_version[3fe8c6913414]: local is `SSH-2.0-Ruby/Net::SSH_3.1.1 x86_64-darwin13.0'
D, [2016-07-08T10:52:56.749127 #56100] DEBUG -- net.ssh.transport.server_version[3fe8c6913414]: remote is `SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu1'
D, [2016-07-08T10:52:56.750086 #56100] DEBUG -- socket[3fe8c6913ae0]: read 976 bytes
D, [2016-07-08T10:52:56.750166 #56100] DEBUG -- socket[3fe8c6913ae0]: received packet nr 0 type 20 len 972
I, [2016-07-08T10:52:56.750219 #56100]  INFO -- net.ssh.transport.algorithms[3fe8c690fddc]: got KEXINIT from server
I, [2016-07-08T10:52:56.750326 #56100]  INFO -- net.ssh.transport.algorithms[3fe8c690fddc]: sending KEXINIT
D, [2016-07-08T10:52:56.750437 #56100] DEBUG -- socket[3fe8c6913ae0]: queueing packet nr 0 type 20 len 1684
D, [2016-07-08T10:52:56.750504 #56100] DEBUG -- socket[3fe8c6913ae0]: sent 1688 bytes
I, [2016-07-08T10:52:56.750531 #56100]  INFO -- net.ssh.transport.algorithms[3fe8c690fddc]: negotiating algorithms
D, [2016-07-08T10:52:56.750628 #56100] DEBUG -- net.ssh.transport.algorithms[3fe8c690fddc]: negotiated:
* kex: diffie-hellman-group14-sha1
* host_key: ecdsa-sha2-nistp256
* encryption_server: aes128-ctr
* encryption_client: aes128-ctr
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client: 
* language_server: 
D, [2016-07-08T10:52:56.750654 #56100] DEBUG -- net.ssh.transport.algorithms[3fe8c690fddc]: exchanging keys
D, [2016-07-08T10:52:56.752145 #56100] DEBUG -- socket[3fe8c6913ae0]: queueing packet nr 1 type 30 len 268
D, [2016-07-08T10:52:56.752209 #56100] DEBUG -- socket[3fe8c6913ae0]: sent 272 bytes
D, [2016-07-08T10:52:56.753413 #56100] DEBUG -- socket[3fe8c6913ae0]: read 504 bytes
D, [2016-07-08T10:52:56.753475 #56100] DEBUG -- socket[3fe8c6913ae0]: received packet nr 1 type 31 len 484
D, [2016-07-08T10:52:56.754718 #56100] DEBUG -- socket[3fe8c6913ae0]: queueing packet nr 2 type 21 len 20
D, [2016-07-08T10:52:56.754785 #56100] DEBUG -- socket[3fe8c6913ae0]: sent 24 bytes
D, [2016-07-08T10:52:56.754829 #56100] DEBUG -- socket[3fe8c6913ae0]: received packet nr 2 type 21 len 12
D, [2016-07-08T10:52:56.755084 #56100] DEBUG -- net.ssh.authentication.session[3fe8c68d21bc]: beginning authentication of `tester'
D, [2016-07-08T10:52:56.755183 #56100] DEBUG -- socket[3fe8c6913ae0]: queueing packet nr 3 type 5 len 28
D, [2016-07-08T10:52:56.755222 #56100] DEBUG -- socket[3fe8c6913ae0]: sent 52 bytes
D, [2016-07-08T10:52:56.793167 #56100] DEBUG -- socket[3fe8c6913ae0]: read 52 bytes
D, [2016-07-08T10:52:56.793356 #56100] DEBUG -- socket[3fe8c6913ae0]: received packet nr 3 type 6 len 28
D, [2016-07-08T10:52:56.793467 #56100] DEBUG -- net.ssh.authentication.session[3fe8c68d21bc]: trying none
D, [2016-07-08T10:52:56.793589 #56100] DEBUG -- socket[3fe8c6913ae0]: queueing packet nr 4 type 50 len 44
D, [2016-07-08T10:52:56.793640 #56100] DEBUG -- socket[3fe8c6913ae0]: sent 68 bytes
D, [2016-07-08T10:52:56.795136 #56100] DEBUG -- socket[3fe8c6913ae0]: read 68 bytes
D, [2016-07-08T10:52:56.795258 #56100] DEBUG -- socket[3fe8c6913ae0]: received packet nr 4 type 51 len 44
D, [2016-07-08T10:52:56.795319 #56100] DEBUG -- net.ssh.authentication.session[3fe8c68d21bc]: allowed methods: publickey,password
D, [2016-07-08T10:52:56.795361 #56100] DEBUG -- net.ssh.authentication.methods.none[3fe8c68cb18c]: none failed
D, [2016-07-08T10:52:56.795404 #56100] DEBUG -- net.ssh.authentication.session[3fe8c68d21bc]: trying publickey
E, [2016-07-08T10:52:56.795652 #56100] ERROR -- net.ssh.authentication.key_manager[3fe8c68cbad8]: could not load public key file `/Users/tester/.ssh/id_ed25519.pub': Net::SSH::Exception (public key at /Users/tester/.ssh/id_ed25519.pub is not valid)
D, [2016-07-08T10:52:56.795787 #56100] DEBUG -- net.ssh.authentication.agent[3fe8c68c2dfc]: connecting to ssh-agent
D, [2016-07-08T10:52:56.795868 #56100] DEBUG -- net.ssh.authentication.agent[3fe8c68c2dfc]: sending agent request 1 len 49
D, [2016-07-08T10:52:56.795972 #56100] DEBUG -- net.ssh.authentication.agent[3fe8c68c2dfc]: received agent packet 2 len 5
D, [2016-07-08T10:52:56.796016 #56100] DEBUG -- net.ssh.authentication.agent[3fe8c68c2dfc]: sending agent request 11 len 0
D, [2016-07-08T10:52:56.796136 #56100] DEBUG -- net.ssh.authentication.agent[3fe8c68c2dfc]: received agent packet 12 len 550
E, [2016-07-08T10:52:56.796241 #56100] ERROR -- net.ssh.authentication.agent[3fe8c68c2dfc]: ignoring unimplemented key:unsupported key type `ssh-ed25519' [email protected]
D, [2016-07-08T10:52:56.796414 #56100] DEBUG -- net.ssh.authentication.methods.publickey[3fe8c68c3e64]: trying publickey (4b:98:3b:de:13:27:69:2e:75:84:58:0b:4b:43:70:2f)
D, [2016-07-08T10:52:56.796677 #56100] DEBUG -- socket[3fe8c6913ae0]: queueing packet nr 5 type 50 len 508
D, [2016-07-08T10:52:56.796729 #56100] DEBUG -- socket[3fe8c6913ae0]: sent 532 bytes
D, [2016-07-08T10:52:56.797367 #56100] DEBUG -- socket[3fe8c6913ae0]: read 68 bytes
D, [2016-07-08T10:52:56.797440 #56100] DEBUG -- socket[3fe8c6913ae0]: received packet nr 5 type 51 len 44
D, [2016-07-08T10:52:56.797513 #56100] DEBUG -- net.ssh.authentication.session[3fe8c68d21bc]: allowed methods: publickey,password
D, [2016-07-08T10:52:56.797546 #56100] DEBUG -- net.ssh.authentication.session[3fe8c68d21bc]: trying password
[at this point I interrupt the process]

So it kind of seems like it only tries one of my keys, deeming it invalid, and logs that it's unsupported a few lines down. There is another key in my .ssh directory which seemingly isn't even getting tried.

Solution

It looks like ed25519 keys are supported by Net SSH 4.0.0alpha1-4.

https://github.com/net-ssh/net-ssh/issues/214

You probably can use RSA keys, upgrade to net-ssh 4.0.0alpha4, or possibly use SSH Agent to get around this.