regression: juju ssh dies with (publickey)

[Aaron Bentley]

$ juju --version
1.24.2-vivid-amd64
$ juju ssh -e juju-ci4 juju-reports/0 -v
OpenSSH_6.7p1 Ubuntu-5ubuntu1, OpenSSL 1.0.1f 6 Jan 2014
debug1: Reading configuration data /home/abentley/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug1: Executing proxy command: exec /usr/bin/juju ssh --proxy=false --pty=false 52.0.56.106 nc 172.31.22.130 22
debug1: permanently_drop_suid: 1000
debug1: identity file /home/abentley/.juju/ssh/juju_id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/abentley/.juju/ssh/juju_id_rsa-cert type -1
debug1: identity file /home/abentley/.ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/abentley/.ssh/id_rsa-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.7p1 Ubuntu-5ubuntu1
Warning: Permanently added '52.0.56.106' (ECDSA) to the list of known hosts.
Permission denied (publickey).
ERROR subprocess encountered error code 255
ssh_exchange_identification: Connection closed by remote host
ERROR subprocess encountered error code 255
$ ~/canonical/juju-versions/1.23.2/usr/lib/juju-1.23.2/bin/juju --version
1.23.2-vivid-amd64
$ ~/canonical/juju-versions/1.23.2/usr/lib/juju-1.23.2/bin/juju ssh -e juju-ci4 juju-reports/0 -v
OpenSSH_6.7p1 Ubuntu-5ubuntu1, OpenSSL 1.0.1f 6 Jan 2014
debug1: Reading configuration data /home/abentley/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug1: Executing proxy command: exec /home/abentley/canonical/juju-versions/1.23.2/usr/lib/juju-1.23.2/bin/juju ssh --proxy=false --pty=false 52.0.56.106 nc -q0 172.31.22.130 22
debug1: permanently_drop_suid: 1000
debug1: identity file /home/abentley/.juju/ssh/juju_id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/abentley/.juju/ssh/juju_id_rsa-cert type -1
debug1: identity file /home/abentley/.ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/abentley/.ssh/id_rsa-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.7p1 Ubuntu-5ubuntu1
Warning: Permanently added '52.0.56.106' (ECDSA) to the list of known hosts.
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.6.1p1 Ubuntu-2ubuntu2
debug1: match: OpenSSH_6.6.1p1 Ubuntu-2ubuntu2 pat OpenSSH_6.6.1* compat 0x04000000
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr <email address hidden> none
debug1: kex: client->server aes128-ctr <email address hidden> none
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA c8:60:4e:66:e3:bf:a8:59:c8:77:20:6b:c1:cb:96:d0
Warning: Permanently added '172.31.22.130' (ECDSA) to the list of known hosts.
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering RSA public key: /home/abentley/.ssh/id_rsa
debug1: Authentications that can continue: publickey
debug1: Offering RSA public key: juju-rsa
debug1: Server accepts key: pkalg ssh-rsa blen 279
debug1: Authentication succeeded (publickey).
Authenticated to 172.31.22.130 (via proxy).
debug1: channel 0: new [client-session]
debug1: Requesting <email address hidden>
debug1: Entering interactive session.
debug1: Sending environment.
debug1: Sending env LANG = en_CA.UTF-8
Welcome to Ubuntu 14.04.1 LTS (GNU/Linux 3.13.0-44-generic x86_64)

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

  System information as of Wed Jul 8 13:54:56 UTC 2015

  System load: 0.06 Processes: 82
  Usage of /: 64.7% of 7.75GB Users logged in: 0
  Memory usage: 21% IP address for eth0: 172.31.22.130
  Swap usage: 0%

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

  Get cloud support with Ubuntu Advantage Cloud Guest:
    http://www.ubuntu.com/business/services/cloud

166 packages can be updated.
75 updates are security updates.

*** System restart required ***
Last login: Wed Jul 8 13:54:59 2015 from ip-172-31-15-136.ec2.internal

$ ~/canonical/juju-versions/1.25-2864/usr/lib/juju-1.25-alpha1/bin/juju --version
1.25-alpha1-vivid-amd64
$ ~/canonical/juju-versions/1.25-2864/usr/lib/juju-1.25-alpha1/bin/juju ssh -e juju-ci4 juju-reports/0 -v
OpenSSH_6.7p1 Ubuntu-5ubuntu1, OpenSSL 1.0.1f 6 Jan 2014
debug1: Reading configuration data /home/abentley/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug1: Executing proxy command: exec /home/abentley/canonical/juju-versions/1.25-2864/usr/lib/juju-1.25-alpha1/bin/juju ssh --proxy=false --pty=false 52.0.56.106 nc 172.31.22.130 22
debug1: permanently_drop_suid: 1000
debug1: identity file /home/abentley/.juju/ssh/juju_id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/abentley/.juju/ssh/juju_id_rsa-cert type -1
debug1: identity file /home/abentley/.ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/abentley/.ssh/id_rsa-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.7p1 Ubuntu-5ubuntu1
Warning: Permanently added '52.0.56.106' (ECDSA) to the list of known hosts.
Permission denied (publickey).
ERROR subprocess encountered error code 255
ssh_exchange_identification: Connection closed by remote host
ERROR subprocess encountered error code 255

[Aaron Bentley (abentley)]

Note that the rsa key that succeeded is named juju-rsa, not id_rsa. AFAICT, 1.24 and 1.25 are not even attempting to use it.

[Curtis Hovey (sinzui)]

I see this
menn0, we discussed that one earlier today
[7:00pm] <thumper>
menn0: I think abentley's analysis is wrong
[7:00pm] <thumper>
menn0: if you look at the logs, it was his personal id_rsa that worked
[7:00pm] <thumper>
but 1.24 and master did not appear to be trying

[Curtis Hovey (sinzui)]

Eric Snow observed that ssh can fail because of the number of the keys. 5 is the magic number for more configurations. I have 6 which might explain why ssh failed for me when juju switched to the ssh lib. I found I could fix the issue by adding the test key as my second or my changing renaming the test key to id_rsa to force it to be the first.

[Eric Snow (ericsnowcurrently)]

One thought: each key that SSH tries counts as an attempt. So if the server is configured to allow only 5 attempts and you have 6 keys and the machine is set up with that 6th key, it will always fail. I ran into this with the sky critsit and ended up having to work around it with SSH options. However, note that I fixed this in commit 0b2cc4a2 (mid-May).

* https://github.com/juju/juju/commit/0b2cc4a2

[Aaron Bentley (abentley)]

@thumper: Here are the lines that I believe indicate that juju-rsa was used in the successful attempt:
debug1: Offering RSA public key: juju-rsa
debug1: Server accepts key: pkalg ssh-rsa blen 279
debug1: Authentication succeeded (publickey).

@ericsnowcurrently
I don't think the issue is caused by an excessive number of attempts. In the failed attempts, I see no "Offering RSA public key" lines, leading me to think that 0 attempts were made. In the successful attempt, I see 2 "Offering RSA public key" lines, with the second suceeding.

[Aaron Bentley (abentley)]

This even applies to machines not managed by juju:

$ $HOME/canonical/juju-versions/1.25-2864/usr/lib/juju-1.25-alpha1/bin/juju ssh vivid-slave.vapour.ws
Warning: Permanently added 'vivid-slave.vapour.ws,15.125.67.100' (ECDSA) to the list of known hosts.
Permission denied (publickey).
ERROR subprocess encountered error code 255

$ $HOME/canonical/juju-versions/1.23.2/usr/lib/juju-1.23.2/bin/juju ssh vivid-slave.vapour.ws
Warning: Permanently added 'vivid-slave.vapour.ws,15.125.67.100' (ECDSA) to the list of known hosts.
Welcome to Ubuntu 15.04 (GNU/Linux 3.19.0-22-generic x86_64)

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

  System information as of Thu Jul 23 14:09:28 UTC 2015

  System load: 0.0 Users logged in: 0
  Usage of /: 15.1% of 29.00GB IP address for eth0: 10.0.0.53
  Memory usage: 2% IP address for virbr0: 192.168.122.1
  Swap usage: 0% IP address for lxcbr0: 10.0.1.1
  Processes: 107

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

  Get cloud support with Ubuntu Advantage Cloud Guest:
    http://www.ubuntu.com/business/services/cloud

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

Last login: Thu Jul 23 13:25:54 2015 from 75-119-255-188.dsl.teksavvy.com
ubuntu@vivid-slave:~$

[Aaron Bentley (abentley)]

This bug appears to be caused by juju respecting fewer names as potential keys, compared to ssh itself.

I created a new user with only one private key, named staging-juju-rsa. SSH itself worked, but "juju ssh" errored. Then I renamed staging-juju-rsa to id_rsa. "juju ssh" then worked.

$ ls -l .ssh
total 12
-rw-r--r-- 1 juju-user juju-user 444 Jul 23 13:57 known_hosts
-rw------- 1 juju-user juju-user 1679 Jul 23 13:48 staging-juju-rsa
-rw------- 1 juju-user juju-user 396 Jul 23 13:48 staging-juju-rsa.pub
$ ssh <email address hidden> -v
OpenSSH_6.7p1 Ubuntu-5ubuntu1, OpenSSL 1.0.1f 6 Jan 2014
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug1: Connecting to vivid-slave.vapour.ws [15.125.67.100] port 22.
debug1: Connection established.
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_rsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_rsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_dsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_dsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_ecdsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_ecdsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_ed25519 type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/juju-user/.ssh/id_ed25519-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.7p1 Ubuntu-5ubuntu1
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.7p1 Ubuntu-5ubuntu1
debug1: match: OpenSSH_6.7p1 Ubuntu-5ubuntu1 pat OpenSSH* compat 0x04000000
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr <email address hidden> none
debug1: kex: client->server aes128-ctr <email address hidden> none
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA f0:e9:e2:0d:d3:ad:4a:fa:bb:b1:62:82:c3:0e:0d:c7
debug1: Host 'vivid-slave.vapour.ws' is known and matches the ECDSA host key.
debug1: Found key in /home/juju-user/.ssh/known_hosts:1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering RSA public key: abentley@speedy
debug1: Server accepts key: pkalg ssh-rsa blen 279
debug1: Authentication succeeded (publickey).
Authenticated to vivid-slave.vapour.ws ([15.125.67.100]:22).
debug1: channel 0: new [client-session]
debug1: Requesting <email address hidden>
debug1: Entering interactive session.
debug1: Sending environment.
debug1: Sen...

[Eric Snow (ericsnowcurrently)]

Possibly related: https://github.com/juju/juju/issues/2920

[Katherine Cox-Buday (cox-katherine-e)]

We think it's possible that this (http://reviews.vapour.ws/r/1716) change may have caused the regression. I've submitted a patch to back this out and then I'd appreciate it if you could tests again.

[Aaron Bentley (abentley)]

I've confirmed that it is fixed in a build of 5e0b332.

[Aaron Bentley (abentley)]

Specifically, http://reports.vapour.ws/releases/2986/job/build-binary-vivid-amd64/attempt/274

[Curtis Hovey (sinzui)]

Is this issue really in 1.22? I had no ssh problems when releasing 1.22. Only 1.24 an 1.25 required me to change my ssh setup.