search

StanfordSNR / guardian-agent

[beta] Guardian Agent: secure ssh-agent forwarding for Mosh and SSH
BSD 3-Clause "New" or "Revised" License
439 stars 30 forks source link

Support server-initiated rekeying prior to handoff #9

Closed eminence closed 7 years ago

eminence commented 7 years ago

On rtr, I'm running an ssh-agent and have password-less login to bigbox. Running sga-guard:

achin@rtr ~/tmp/09 $ sga-guard achin@bigbox
DISPLAY environment variable is not set. Using terminal for user prompts.
Connecting to achin@bigbox to set up forwarding...
Forwarding to achin@bigbox setup successfully. Waiting for incoming requests...

Now on bigbox I run the following:

achin@bigbox ~ $ sga-ssh achin@bigbox
failed to run command: failed to create session: ssh: unexpected packet in response to channel open: <nil>

Meanwhile on rtr:

Allow achin@bigbox to run '' on achin@bigbox:22?
        1) Disallow
        2) Allow once
        3) Allow forever
        4) Allow achin@bigbox to run any command on achin@bigbox:22 forever
? Answer 2
Request by achin@bigbox to run '' on achin@bigbox:22 APPROVED by user
Can't enforce permission for a single command. Allow achin@bigbox to run ANY COMMAND on achin@bigbox:22?
        1) Disallow
        2) Allow once
        3) Allow forever
? Answer 2
Request by achin@bigbox to run ANY COMMAND on achin@bigbox:22 APPROVED by user

(the error from sga-ssh didn't appear until i selected the "2" option the second time on rtr)

Running v0.7.0-beta on both machines

eminence commented 7 years ago

Here's a little more info:

achin@bigbox ~ $ sga-ssh --debug achin@bigbox
2017/10/26 16:00:35 delegated_client.go:568: KexCallback called
2017/10/26 16:00:35 delegated_client.go:470: Finished copying outgoing SSH data
2017/10/26 16:00:35 client.go:63: error returned from conn wait:  ssh: no common algorithm for host key; client offered: [none], server offered: [ssh-rsa rsa-sha2-512 rsa-sha2-256 ecdsa-sha2-nistp256 ssh-ed25519]
2017/10/26 16:00:35 delegated_client.go:484: Finished copying ssh data from agent: %!s(<nil>)
2017/10/26 16:00:38 delegated_client.go:546: Finished copying transport data from agent
2017/10/26 16:00:38 delegated_client.go:274: Handoff Failed: EOF
2017/10/26 16:00:38 delegated_client.go:531: Finished copying transport data to agent
2017/10/26 16:00:38 delegated_client.go:535: To agent transport forwarding failed: read tcp 10.10.1.102:41864->10.10.1.102:22: use of closed network connection
2017/10/26 16:00:38 sga-ssh.go:146: sga-ssh: Failed to run  on bigbox: failed to run command: failed to create session: ssh: unexpected packet in response to channel open: <nil>
failed to run command: failed to create session: ssh: unexpected packet in response to channel open: <nil>
dimakogan commented 7 years ago

I've created a version that gives a bit more debug information. Could you please run the same commands (including the --debug) again with the modified version?

You can use the prebuilt binaries: sga_linux_amd64.tar.gz

or, if you prefer to build from source, use the kexdebug branch:

git clone -b kexdebug git@github.com:StanfordSNR/guardian-agent
go build ./guardian-agent/cmd/sga-ssh
eminence commented 7 years ago

Thanks for providing the pre-built binaries. Here's the log:

achin@bigbox ~/tmp/19 $ sga-ssh --debug achin@bigbox
2017/10/26 19:55:48 handshake.go:355: kex loop
2017/10/26 19:55:48 handshake.go:360: kex inner loop
2017/10/26 19:55:48 handshake.go:370: select exit: <-requestKex
2017/10/26 19:55:48 handshake.go:393: !sent: sending kexInit
2017/10/26 19:55:48 handshake.go:360: kex inner loop
2017/10/26 19:55:48 handshake.go:368: select exit: <-t.startKex
2017/10/26 19:55:48 handshake.go:416: entering keyexchange
2017/10/26 19:55:48 common.go:139: host key algorithms: server: [none], client: [none]
2017/10/26 19:55:48 delegated_client.go:568: KexCallback called
2017/10/26 19:55:48 handshake.go:355: kex loop
2017/10/26 19:55:48 handshake.go:360: kex inner loop
2017/10/26 19:55:48 handshake.go:368: select exit: <-t.startKex
2017/10/26 19:55:48 handshake.go:393: !sent: sending kexInit
2017/10/26 19:55:48 handshake.go:416: entering keyexchange
2017/10/26 19:55:48 common.go:139: host key algorithms: server: [ssh-rsa rsa-sha2-512 rsa-sha2-256 ecdsa-sha2-nistp256 ssh-ed25519], client: [none]
2017/10/26 19:55:48 delegated_client.go:470: Finished copying outgoing SSH data
2017/10/26 19:55:48 delegated_client.go:484: Finished copying ssh data from agent: %!s(<nil>)
2017/10/26 19:55:48 client.go:63: error returned from conn wait:  ssh: no common algorithm for host key; client offered: [none], server offered: [ssh-rsa rsa-sha2-512 rsa-sha2-256 ecdsa-sha2-nistp256 ssh-ed25519]
2017/10/26 19:55:48 mux.go:332: ssh: unexpected packet in response to channel open: <nil>
2017/10/26 19:55:48 delegated_client.go:274: Handoff Failed: EOF
2017/10/26 19:55:48 delegated_client.go:546: Finished copying transport data from agent
2017/10/26 19:55:48 delegated_client.go:531: Finished copying transport data to agent
2017/10/26 19:55:48 delegated_client.go:535: To agent transport forwarding failed: read tcp 10.10.1.102:57864->10.10.1.102:22: use of closed network connection
2017/10/26 19:55:48 sga-ssh.go:146: sga-ssh: Failed to run  on bigbox: failed to run command: failed to create session: ssh: unexpected packet in response to channel open: <nil>
failed to run command: failed to create session: ssh: unexpected packet in response to channel open: <nil>
dimakogan commented 7 years ago

Thank you for the information and for your time helping to diagnose this in general! May I ask what version of SSH server is running on bigbox?

dimakogan commented 7 years ago

Also, could you please run sga-guard (on rtr) with --debug as well (and repeat the same flow) and attach the output?

eminence commented 7 years ago

bigbox is running OpenSSH_7.5p1-hpn14v12, OpenSSL 1.0.2l 25 May 2017

Debug traces from rtr:

achin@rtr ~/tmp/10/sga_linux_amd64 $ sga-guard achin@bigbox --debug
DISPLAY environment variable is not set. Using terminal for user prompts.
Connecting to achin@bigbox to set up forwarding...
2017/10/26 21:55:54 sshfwd.go:90: Listening on: /run/user/1000/.guard.7275
Forwarding to achin@bigbox setup successfully. Waiting for incoming requests...
2017/10/26 21:55:57 agent.go:98: New incoming connection
Allow achin@bigbox to run '' on achin@bigbox:22?
        1) Disallow
        2) Allow once
        3) Allow forever
        4) Allow achin@bigbox to run any command on achin@bigbox:22 forever
? Answer 2
Request by achin@bigbox to run '' on achin@bigbox:22 APPROVED by user
2017/10/26 21:55:58 proxy.go:43: Read version: "SSH-2.0-OpenSSH_7.5p1-hpn14v12" from server
2017/10/26 21:55:58 proxy.go:51: Read version: "SSH-2.0-Go" from client
2017/10/26 21:55:58 handshake.go:355: kex loop
2017/10/26 21:55:58 handshake.go:355: kex loop
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:370: select exit: <-requestKex
2017/10/26 21:55:58 handshake.go:393: !sent: sending kexInit
2017/10/26 21:55:58 handshake.go:370: select exit: <-requestKex
2017/10/26 21:55:58 handshake.go:393: !sent: sending kexInit
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:368: select exit: <-t.startKex
2017/10/26 21:55:58 handshake.go:416: entering keyexchange
2017/10/26 21:55:58 common.go:139: host key algorithms: server: [none], client: [none]
2017/10/26 21:55:58 handshake.go:368: select exit: <-t.startKex
2017/10/26 21:55:58 handshake.go:416: entering keyexchange
2017/10/26 21:55:58 common.go:139: host key algorithms: server: [ssh-rsa rsa-sha2-512 rsa-sha2-256 ecdsa-sha2-nistp256 ssh-ed25519], client: [ssh-ed25519]
2017/10/26 21:55:58 handshake.go:355: kex loop
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:355: kex loop
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 proxy.go:84: Connected to server successfully
2017/10/26 21:55:58 handshake.go:373: select exit: <-t.stopOutKex
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:365: select exit: <-t.startKex NOT OK
2017/10/26 21:55:58 proxy.go:119: Stopping Kex
2017/10/26 21:55:58 handshake.go:373: select exit: <-t.stopOutKex
2017/10/26 21:55:58 handshake.go:360: kex inner loop
2017/10/26 21:55:58 handshake.go:365: select exit: <-t.startKex NOT OK
2017/10/26 21:55:58 proxy.go:124: Done with Kex
2017/10/26 21:55:58 proxy.go:138: UpdateClientSessionParams begin
2017/10/26 21:55:58 proxy.go:150: UpdateClientSessionParams Complete
2017/10/26 21:55:58 proxy.go:172: Got message 90 from client: *ssh.channelOpenMsg
2017/10/26 21:55:58 proxy.go:198: Forwarded seqNum: 5 from client to server as: 7
2017/10/26 21:55:58 proxy.go:172: Got message 2 from client: *ssh.ignoreMsg
2017/10/26 21:55:58 proxy.go:198: Forwarded seqNum: 8 from client to server as: 8
2017/10/26 21:55:58 proxy.go:223: Got message 80 from server: *ssh.globalRequestMsg
2017/10/26 21:55:58 proxy.go:247: Forwarded seqNum: 7 from server to client as: 7
2017/10/26 21:55:58 proxy.go:223: Got message 20 from server: *ssh.kexInitMsg
2017/10/26 21:55:58 proxy.go:247: Forwarded seqNum: 8 from server to client as: 8
2017/10/26 21:55:58 proxy.go:172: Got message 20 from client: *ssh.kexInitMsg
2017/10/26 21:55:58 filter.go:99: Attempting handoff without successful no-more-sessions.
Can't enforce permission for a single command. Allow achin@bigbox to run ANY COMMAND on achin@bigbox:22?
        1) Disallow
        2) Allow once
        3) Allow forever
? Answer 2
Request by achin@bigbox to run ANY COMMAND on achin@bigbox:22 APPROVED by user
2017/10/26 21:56:00 proxy.go:198: Forwarded seqNum: 9 from client to server as: 9
2017/10/26 21:56:00 sshfwd.go:167: Finished copying from client to real agent.
dimakogan commented 7 years ago

The bug seems to be of guardian agent not handling a server-initiated rekeying of the connection before guardian agent's handoff procedure. Making the assumption that such a rekeying would not happen in this narrow time-window turned out to be a bad idea :/ I will fix this.

Just to confirm that I'm not missing anything else, could you please run sshd -T on bigbox (this should print out the effective sshd_config it uses). I expect to see a very short rekeying limit that would explain why we're seeing the server initiating a rekeying so early on.

Thanks again for all the help!

eminence commented 7 years ago

I see this (on both bigbox and rtr -- maybe this is a gentoo default?):

achin@bigbox ~/tmp/19 $ sudo sshd -T |grep -i rekey
rekeylimit 0 0

achin@bigbox ~/tmp/19 $ sudo grep -i rekey /etc/ssh/sshd_config
#RekeyLimit default none

(I didn't paste the entire output since it's rather long, but if you want too see more of it, let me know)

dimakogan commented 7 years ago

I managed to reproduce it. The root cause is indeed the bug in my code which does not properly handle an early server-initiated rekeying. This early rekeying is a behaviour specific to the hpn variant of OpenSSH, which rekeys immediately after authentication.

As I said above, I will change our code to handle this case.

Thanks for the help debugging this @eminence !

dimakogan commented 7 years ago

Fixed in StanfordSNR/crypto@fadb455. Latest release should work 🤞

eminence commented 7 years ago

i confirm the issue is fixed!