[Twisted-Python] conch problem with ecdsa-sha2-nistp256 host key?

Craig Rodrigues rodrigc at crodrigues.org
Tue Dec 20 20:56:06 MST 2016


On Tue, Dec 20, 2016 at 7:32 PM, Craig Rodrigues <rodrigc at crodrigues.org>
wrote:

> On Tue, Dec 20, 2016 at 6:24 PM, Glyph Lefkowitz <glyph at twistedmatrix.com>
> wrote:
>
>>
>>
>
>>
>> So... is this because buildbot.twistedmatrix.com has an RSA key as well,
>> and when it offers it, our checking isn't correctly comparing the type
>> before deciding that it doesn't match, or allowing for multiple keys?  I
>> notice that if I manually add the RSA key and delete the ECDSA key it seems
>> to work.
>>
>> -g
>>
>>
>
> Yes, that is part of it.
> What is happening is that the conch client sends a MSG_KEXINIT
> packet to the server to negotatiate what the host key should be.
> If I use an OpenSSH ssh client to connect to OpenSSH sshd server,
> the negotiated host key algorithm is ecdsa-sha2-nistp256.
>
> If I use a conch client to connect to the OpenSSH sshd server,
> the negotiated host key algorithm is ssh-rsa.
>
> I started a test instance of the sshd server with:
>
> /usr/sbin/sshd -p 9000 -d -d -d
>
> and captured the logs (see attached).
>
> I think some problems are:
>   (1)  conch proposes a list of *host key algorithms* in a different
> order than
>          OpenSSH.  It shouldn't matter, but conch proposes ssh-rsa first,
>          while OpenSSH proposes it last.
>   (2)  OpenSSH client seems to be able to receive multiple host keys back
>          from the server, and can match the one it has.
>
> --
> Craig
>
>
Here are the proper logs.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: </pipermail/twisted-python/attachments/20161220/cf5edc71/attachment-0002.html>
-------------- next part --------------
Script started on Tue Dec 20 18:50:57 2016
Command: /usr/sbin/sshd -p 9000 -d -d -d
debug2: load_server_config: filename /etc/ssh/sshd_config

debug2: load_server_config: done config len = 197

debug2: parse_server_config: config /etc/ssh/sshd_config len 197

debug3: /etc/ssh/sshd_config:49 setting PermitRootLogin yes

debug3: /etc/ssh/sshd_config:131 setting Subsystem sftp	/usr/libexec/sftp-server

debug1: sshd version OpenSSH_7.2, OpenSSL 1.0.2j-freebsd  26 Sep 2016

debug1: private host key #0: ssh-rsa SHA256:73H4OcFhNGdHY2sVsbBOVVOudub2EkvfYNlwpxWM1Xw

debug1: private host key #1: ssh-dss SHA256:6BQ11F0ejGONS1+d4O63t7fyyGKaEyW33a73x5G/3ic

debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:jkq3WG/EU+yyyg8xemPshcErRvPYmSbU202opbYgzHU

debug1: private host key #3: ssh-ed25519 SHA256:59NbS+jIUH9ADjLpk5nQLKq229hrx89QpAd3Z3Ts6j4

debug1: rexec_argv[0]='/usr/sbin/sshd'

debug1: rexec_argv[1]='-p'

debug1: rexec_argv[2]='9000'

debug1: rexec_argv[3]='-d'

debug1: rexec_argv[4]='-d'

debug1: rexec_argv[5]='-d'

debug2: fd 3 setting O_NONBLOCK

debug3: Fssh_sock_set_v6only: set socket 3 IPV6_V6ONLY

debug1: Bind to port 9000 on ::.

debug1: Server TCP RWIN socket size: 65536

Server listening on :: port 9000.

debug2: fd 4 setting O_NONBLOCK

debug1: Bind to port 9000 on 0.0.0.0.

debug1: Server TCP RWIN socket size: 65536

Server listening on 0.0.0.0 port 9000.

debug1: fd 5 clearing O_NONBLOCK

debug1: Server will not fork when running in debugging mode.

debug3: send_rexec_state: entering fd = 8 config len 197

debug3: ssh_msg_send: type 0

debug3: send_rexec_state: done

debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8

debug1: inetd sockets after dupping: 3, 3

debug1: res_init()

Connection from 192.168.1.5 port 58547 on 192.168.1.2 port 9000

debug1: Client protocol version 2.0; client software version Twisted

debug1: no match: Twisted

debug1: Enabling compatibility mode for protocol 2.0

debug1: Local version string SSH-2.0-OpenSSH_7.2 FreeBSD-20160310

debug2: fd 3 setting O_NONBLOCK

debug3: ssh_sandbox_init: preparing capsicum sandbox

debug2: Network child is on pid 69006

debug3: preauth child monitor started

debug3: privsep user:group 22:22 [preauth]

debug1: permanently_set_uid: 22/22 [preauth]

debug3: list_hostkey_types: ssh-dss key not permitted by HostkeyAlgorithms [preauth]

debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]

debug3: send packet: type 20 [preauth]

debug1: SSH2_MSG_KEXINIT sent [preauth]

debug3: receive packet: type 20 [preauth]

debug1: SSH2_MSG_KEXINIT received [preauth]

debug2: local server KEXINIT proposal [preauth]

debug2: KEX algorithms: curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1 [preauth]

debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]

debug2: ciphers ctos: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth]

debug2: ciphers stoc: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth]

debug2: MACs ctos: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]

debug2: MACs stoc: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]

debug2: compression ctos: none,zlib at openssh.com [preauth]

debug2: compression stoc: none,zlib at openssh.com [preauth]

debug2: languages ctos:  [preauth]

debug2: languages stoc:  [preauth]

debug2: first_kex_follows 0  [preauth]

debug2: reserved 0  [preauth]

debug2: peer client KEXINIT proposal [preauth]

debug2: KEX algorithms: ecdh-sha2-nistp224,ecdh-sha2-nistp256,ecdh-sha2-nistk233,ecdh-sha2-nistb233,ecdh-sha2-nistk163,ecdh-sha2-nistp384,ecdh-sha2-nistk409,ecdh-sha2-nistk283,ecdh-sha2-nistb409,ecdh-sha2-nistt571,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1,diffie-hellman-group14-sha1 [preauth]

debug2: host key algorithms: ssh-rsa,ssh-dss,ecdsa-sha2-nistp224,ecdsa-sha2-nistp256,ecdsa-sha2-nistk233,ecdsa-sha2-nistb233,ecdsa-sha2-nistk163,ecdsa-sha2-nistp384,ecdsa-sha2-nistk409,ecdsa-sha2-nistk283,ecdsa-sha2-nistb409,ecdsa-sha2-nistt571,ecdsa-sha2-nistp521 [preauth]

debug2: ciphers ctos: aes256-ctr,aes256-cbc,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,cast128-ctr,cast128-cbc,blowfish-cbc,3des-cbc [preauth]

debug2: ciphers stoc: aes256-ctr,aes256-cbc,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,cast128-ctr,cast128-cbc,blowfish-cbc,3des-cbc [preauth]

debug2: MACs ctos: hmac-sha2-512,hmac-sha2-384,hmac-sha2-256,hmac-sha1,hmac-md5 [preauth]

debug2: MACs stoc: hmac-sha2-512,hmac-sha2-384,hmac-sha2-256,hmac-sha1,hmac-md5 [preauth]

debug2: compression ctos: none,zlib [preauth]

debug2: compression stoc: none,zlib [preauth]

debug2: languages ctos:  [preauth]

debug2: languages stoc:  [preauth]

debug2: first_kex_follows 0  [preauth]

debug2: reserved 0  [preauth]

debug1: kex: algorithm: ecdh-sha2-nistp256 [preauth]

debug1: kex: host key algorithm: ssh-rsa [preauth]

debug1: kex: client->server cipher: aes256-ctr MAC: hmac-sha2-512 compression: none [preauth]

debug1: kex: server->client cipher: aes256-ctr MAC: hmac-sha2-512 compression: none [preauth]

debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]

debug3: receive packet: type 30 [preauth]

debug3: mm_key_sign entering [preauth]

debug3: mm_request_send entering: type 6 [preauth]

debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth]

debug3: mm_request_receive_expect entering: type 7 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 6

debug3: mm_answer_sign

debug3: mm_answer_sign: hostkey proof signature 0x804079b40(271)

debug3: mm_request_send entering: type 7

debug2: monitor_read: 6 used once, disabling now

debug3: send packet: type 31 [preauth]

debug3: send packet: type 21 [preauth]

debug2: set_newkeys: mode 1 [preauth]

debug1: rekey after 4294967296 blocks [preauth]

debug1: SSH2_MSG_NEWKEYS sent [preauth]

debug1: expecting SSH2_MSG_NEWKEYS [preauth]

debug3: receive packet: type 1 [preauth]

Received disconnect from 192.168.1.5 port 58547:9: bbbad host key [preauth]

Disconnected from 192.168.1.5 port 58547 [preauth]

debug1: do_cleanup [preauth]

debug3: PAM: sshpam_thread_cleanup entering [preauth]

debug1: monitor_read_log: child log fd closed

debug3: mm_request_receive entering

debug1: do_cleanup

debug3: PAM: sshpam_thread_cleanup entering

debug1: Killing privsep child 69006


Command exit status: 255
Script done on Tue Dec 20 18:51:03 2016
-------------- next part --------------
Script started on Tue Dec 20 18:50:42 2016
Command: /usr/sbin/sshd -p 9000 -d -d -d
debug2: load_server_config: filename /etc/ssh/sshd_config

debug2: load_server_config: done config len = 197

debug2: parse_server_config: config /etc/ssh/sshd_config len 197

debug3: /etc/ssh/sshd_config:49 setting PermitRootLogin yes

debug3: /etc/ssh/sshd_config:131 setting Subsystem sftp	/usr/libexec/sftp-server

debug1: sshd version OpenSSH_7.2, OpenSSL 1.0.2j-freebsd  26 Sep 2016

debug1: private host key #0: ssh-rsa SHA256:73H4OcFhNGdHY2sVsbBOVVOudub2EkvfYNlwpxWM1Xw

debug1: private host key #1: ssh-dss SHA256:6BQ11F0ejGONS1+d4O63t7fyyGKaEyW33a73x5G/3ic

debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:jkq3WG/EU+yyyg8xemPshcErRvPYmSbU202opbYgzHU

debug1: private host key #3: ssh-ed25519 SHA256:59NbS+jIUH9ADjLpk5nQLKq229hrx89QpAd3Z3Ts6j4

debug1: rexec_argv[0]='/usr/sbin/sshd'

debug1: rexec_argv[1]='-p'

debug1: rexec_argv[2]='9000'

debug1: rexec_argv[3]='-d'

debug1: rexec_argv[4]='-d'

debug1: rexec_argv[5]='-d'

debug2: fd 3 setting O_NONBLOCK

debug3: Fssh_sock_set_v6only: set socket 3 IPV6_V6ONLY

debug1: Bind to port 9000 on ::.

debug1: Server TCP RWIN socket size: 65536

Server listening on :: port 9000.

debug2: fd 4 setting O_NONBLOCK

debug1: Bind to port 9000 on 0.0.0.0.

debug1: Server TCP RWIN socket size: 65536

Server listening on 0.0.0.0 port 9000.

debug1: fd 5 clearing O_NONBLOCK

debug1: Server will not fork when running in debugging mode.

debug3: send_rexec_state: entering fd = 8 config len 197

debug3: ssh_msg_send: type 0

debug3: send_rexec_state: done

debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8

debug1: inetd sockets after dupping: 3, 3

debug1: res_init()

Connection from 192.168.1.5 port 58546 on 192.168.1.2 port 9000

debug1: Client protocol version 2.0; client software version OpenSSH_7.2

debug1: match: OpenSSH_7.2 pat OpenSSH* compat 0x04000000

debug1: Enabling compatibility mode for protocol 2.0

debug1: Local version string SSH-2.0-OpenSSH_7.2 FreeBSD-20160310

debug2: fd 3 setting O_NONBLOCK

debug3: ssh_sandbox_init: preparing capsicum sandbox

debug2: Network child is on pid 68979

debug3: preauth child monitor started

debug3: privsep user:group 22:22 [preauth]

debug1: permanently_set_uid: 22/22 [preauth]

debug3: list_hostkey_types: ssh-dss key not permitted by HostkeyAlgorithms [preauth]

debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]

debug3: send packet: type 20 [preauth]

debug1: SSH2_MSG_KEXINIT sent [preauth]

debug3: receive packet: type 20 [preauth]

debug1: SSH2_MSG_KEXINIT received [preauth]

debug2: local server KEXINIT proposal [preauth]

debug2: KEX algorithms: curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1 [preauth]

debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]

debug2: ciphers ctos: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth]

debug2: ciphers stoc: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth]

debug2: MACs ctos: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]

debug2: MACs stoc: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]

debug2: compression ctos: none,zlib at openssh.com [preauth]

debug2: compression stoc: none,zlib at openssh.com [preauth]

debug2: languages ctos:  [preauth]

debug2: languages stoc:  [preauth]

debug2: first_kex_follows 0  [preauth]

debug2: reserved 0  [preauth]

debug2: peer client KEXINIT proposal [preauth]

debug2: KEX algorithms: curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,ext-info-c [preauth]

debug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01 at openssh.com,ecdsa-sha2-nistp384-cert-v01 at openssh.com,ecdsa-sha2-nistp521-cert-v01 at openssh.com,ssh-ed25519-cert-v01 at openssh.com,ssh-rsa-cert-v01 at openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]

debug2: ciphers ctos: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc [preauth]

debug2: ciphers stoc: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc [preauth]

debug2: MACs ctos: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]

debug2: MACs stoc: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]

debug2: compression ctos: none,zlib at openssh.com,zlib [preauth]

debug2: compression stoc: none,zlib at openssh.com,zlib [preauth]

debug2: languages ctos:  [preauth]

debug2: languages stoc:  [preauth]

debug2: first_kex_follows 0  [preauth]

debug2: reserved 0  [preauth]

debug1: kex: algorithm: curve25519-sha256 at libssh.org [preauth]

debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]

debug1: kex: client->server cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none [preauth]

debug1: kex: server->client cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none [preauth]

debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]

debug3: receive packet: type 30 [preauth]

debug3: mm_key_sign entering [preauth]

debug3: mm_request_send entering: type 6 [preauth]

debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth]

debug3: mm_request_receive_expect entering: type 7 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 6

debug3: mm_answer_sign

debug3: mm_answer_sign: hostkey proof signature 0x8040411c0(99)

debug3: mm_request_send entering: type 7

debug2: monitor_read: 6 used once, disabling now

debug3: send packet: type 31 [preauth]

debug3: send packet: type 21 [preauth]

debug2: set_newkeys: mode 1 [preauth]

debug1: rekey after 134217728 blocks [preauth]

debug1: SSH2_MSG_NEWKEYS sent [preauth]

debug1: expecting SSH2_MSG_NEWKEYS [preauth]

debug3: send packet: type 7 [preauth]

debug3: receive packet: type 21 [preauth]

debug2: set_newkeys: mode 0 [preauth]

debug1: rekey after 134217728 blocks [preauth]

debug1: SSH2_MSG_NEWKEYS received [preauth]

debug1: KEX done [preauth]

debug3: receive packet: type 5 [preauth]

debug3: send packet: type 6 [preauth]

debug3: receive packet: type 50 [preauth]

debug3: Trying to reverse map address 192.168.1.5. [preauth]

debug1: userauth-request for user rodrigc service ssh-connection method none [preauth]

debug1: attempt 0 failures 0 [preauth]

debug3: mm_getpwnamallow entering [preauth]

debug3: mm_request_send entering: type 8 [preauth]

debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]

debug3: mm_request_receive_expect entering: type 9 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 8

debug3: mm_answer_pwnamallow

debug3: Trying to reverse map address 192.168.1.5.

debug2: parse_server_config: config reprocess config len 197

debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1

debug3: mm_request_send entering: type 9

debug2: monitor_read: 8 used once, disabling now

debug2: input_userauth_request: setting up authctxt for rodrigc [preauth]

debug3: mm_start_pam entering [preauth]

debug3: mm_request_send entering: type 100 [preauth]

debug3: mm_inform_authserv entering [preauth]

debug3: mm_request_send entering: type 4 [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 100

debug1: PAM: initializing for "rodrigc"

debug1: PAM: setting PAM_RHOST to "192.168.1.5"

debug2: monitor_read: 100 used once, disabling now

debug2: input_userauth_request: try method none [preauth]

debug3: userauth_finish: failure partial=0 next methods="publickey,keyboard-interactive" [preauth]

debug3: send packet: type 51 [preauth]

debug3: receive packet: type 50 [preauth]

debug1: userauth-request for user rodrigc service ssh-connection method publickey [preauth]

debug1: attempt 1 failures 0 [preauth]

debug2: input_userauth_request: try method publickey [preauth]

debug1: userauth_pubkey: test whether pkalg/pkblob are acceptable for RSA SHA256:m2nfEMZA8SWbLCwY40QzK5CSxEAuW0H+aUC4g8jOWFo [preauth]

debug3: mm_key_allowed entering [preauth]

debug3: mm_request_send entering: type 22 [preauth]

debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]

debug3: mm_request_receive_expect entering: type 23 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 4

debug3: mm_answer_authserv: service=ssh-connection, style=

debug2: monitor_read: 4 used once, disabling now

debug3: mm_request_receive entering

debug3: monitor_read: checking request 22

debug3: mm_answer_keyallowed entering

debug3: mm_answer_keyallowed: key_from_blob: 0x80401b540

debug1: trying public key file /opt2/home/rodrigc/.ssh/authorized_keys

debug1: fd 4 clearing O_NONBLOCK

debug2: user_key_allowed: check options: 'ssh-dss AAAAB3NzaC1kc3MAAACBAO00EJjM71Kbjn+PUMQIvLi9OSVqlhwrKuFLTimAfDiRRXrGuTzOuzaYFb5SXQvJDdzGl1B1nSuzJLbTROfqIL/Mc3TxLBo1LeZjeTyNlYgXO+Me/keDygqcacHWDy+a2zXIYBqmwLnACF4B3lw5FUpySxwwwzJwdz8AaIfeMWhdAAAAFQChfRlm8UUrKI00Xtg/FfA+ajEfPQAAAIB2vKNP6T8QCsA6Hx82CQRP3Q1O/VsBOKqgQdgOf3a/1/rnxDFQHFtKMrCVgQu+M8SPOMOAub+Q3T07YEKhhFrONcRojARwzfYp6AJ35tZ70m8/5QrVXzhDM3HnCtyLv+aTatuFoHzOl8n9VxgTEieWQ6IekVPRtaMoSXKAgeX3eAAAAIBpjpXQH+mLK6a6xYwWxjjpemnG2I2luTR/NFWzdS4A0m5+qBEaKZmSwDKA/6jd3yG9MonRO5kmQhaS/bnXRp+vIH4i9E69XsCKsC53hGgGKS+V82rsrASO0snncRrtwiXljF/E5+4ZDSI2lPZeSbhnJdLnaOO86C62CfZN+Hocqw== rodrigc_android
'

debug2: user_key_allowed: advance: 'AAAAB3NzaC1kc3MAAACBAO00EJjM71Kbjn+PUMQIvLi9OSVqlhwrKuFLTimAfDiRRXrGuTzOuzaYFb5SXQvJDdzGl1B1nSuzJLbTROfqIL/Mc3TxLBo1LeZjeTyNlYgXO+Me/keDygqcacHWDy+a2zXIYBqmwLnACF4B3lw5FUpySxwwwzJwdz8AaIfeMWhdAAAAFQChfRlm8UUrKI00Xtg/FfA+ajEfPQAAAIB2vKNP6T8QCsA6Hx82CQRP3Q1O/VsBOKqgQdgOf3a/1/rnxDFQHFtKMrCVgQu+M8SPOMOAub+Q3T07YEKhhFrONcRojARwzfYp6AJ35tZ70m8/5QrVXzhDM3HnCtyLv+aTatuFoHzOl8n9VxgTEieWQ6IekVPRtaMoSXKAgeX3eAAAAIBpjpXQH+mLK6a6xYwWxjjpemnG2I2luTR/NFWzdS4A0m5+qBEaKZmSwDKA/6jd3yG9MonRO5kmQhaS/bnXRp+vIH4i9E69XsCKsC53hGgGKS+V82rsrASO0snncRrtwiXljF/E5+4ZDSI2lPZeSbhnJdLnaOO86C62CfZN+Hocqw== rodrigc_android
'

debug2: key not found

debug1: trying public key file /opt2/home/rodrigc/.ssh/authorized_keys2

debug1: Could not open authorized keys '/opt2/home/rodrigc/.ssh/authorized_keys2': No such file or directory

Failed publickey for rodrigc from 192.168.1.5 port 58546 ssh2: RSA SHA256:m2nfEMZA8SWbLCwY40QzK5CSxEAuW0H+aUC4g8jOWFo

debug3: mm_answer_keyallowed: key 0x80401b540 is not allowed

debug3: mm_request_send entering: type 23

debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]

debug3: userauth_finish: failure partial=0 next methods="publickey,keyboard-interactive" [preauth]

debug3: send packet: type 51 [preauth]

debug3: receive packet: type 50 [preauth]

debug1: userauth-request for user rodrigc service ssh-connection method publickey [preauth]

debug1: attempt 2 failures 1 [preauth]

debug2: input_userauth_request: try method publickey [preauth]

debug1: userauth_pubkey: test whether pkalg/pkblob are acceptable for RSA SHA256:a3jm5HIWdUdTsXuwT4LVYwLzViTu08OdGircV2/wDPc [preauth]

debug3: mm_key_allowed entering [preauth]

debug3: mm_request_send entering: type 22 [preauth]

debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]

debug3: mm_request_receive_expect entering: type 23 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 22

debug3: mm_answer_keyallowed entering

debug3: mm_answer_keyallowed: key_from_blob: 0x80401b540

debug1: trying public key file /opt2/home/rodrigc/.ssh/authorized_keys

debug1: fd 4 clearing O_NONBLOCK

debug2: user_key_allowed: check options: 'ssh-dss AAAAB3NzaC1kc3MAAACBAO00EJjM71Kbjn+PUMQIvLi9OSVqlhwrKuFLTimAfDiRRXrGuTzOuzaYFb5SXQvJDdzGl1B1nSuzJLbTROfqIL/Mc3TxLBo1LeZjeTyNlYgXO+Me/keDygqcacHWDy+a2zXIYBqmwLnACF4B3lw5FUpySxwwwzJwdz8AaIfeMWhdAAAAFQChfRlm8UUrKI00Xtg/FfA+ajEfPQAAAIB2vKNP6T8QCsA6Hx82CQRP3Q1O/VsBOKqgQdgOf3a/1/rnxDFQHFtKMrCVgQu+M8SPOMOAub+Q3T07YEKhhFrONcRojARwzfYp6AJ35tZ70m8/5QrVXzhDM3HnCtyLv+aTatuFoHzOl8n9VxgTEieWQ6IekVPRtaMoSXKAgeX3eAAAAIBpjpXQH+mLK6a6xYwWxjjpemnG2I2luTR/NFWzdS4A0m5+qBEaKZmSwDKA/6jd3yG9MonRO5kmQhaS/bnXRp+vIH4i9E69XsCKsC53hGgGKS+V82rsrASO0snncRrtwiXljF/E5+4ZDSI2lPZeSbhnJdLnaOO86C62CfZN+Hocqw== rodrigc_android
'

debug2: user_key_allowed: advance: 'AAAAB3NzaC1kc3MAAACBAO00EJjM71Kbjn+PUMQIvLi9OSVqlhwrKuFLTimAfDiRRXrGuTzOuzaYFb5SXQvJDdzGl1B1nSuzJLbTROfqIL/Mc3TxLBo1LeZjeTyNlYgXO+Me/keDygqcacHWDy+a2zXIYBqmwLnACF4B3lw5FUpySxwwwzJwdz8AaIfeMWhdAAAAFQChfRlm8UUrKI00Xtg/FfA+ajEfPQAAAIB2vKNP6T8QCsA6Hx82CQRP3Q1O/VsBOKqgQdgOf3a/1/rnxDFQHFtKMrCVgQu+M8SPOMOAub+Q3T07YEKhhFrONcRojARwzfYp6AJ35tZ70m8/5QrVXzhDM3HnCtyLv+aTatuFoHzOl8n9VxgTEieWQ6IekVPRtaMoSXKAgeX3eAAAAIBpjpXQH+mLK6a6xYwWxjjpemnG2I2luTR/NFWzdS4A0m5+qBEaKZmSwDKA/6jd3yG9MonRO5kmQhaS/bnXRp+vIH4i9E69XsCKsC53hGgGKS+V82rsrASO0snncRrtwiXljF/E5+4ZDSI2lPZeSbhnJdLnaOO86C62CfZN+Hocqw== rodrigc_android
'

debug1: matching key found: file /opt2/home/rodrigc/.ssh/authorized_keys, line 2 RSA SHA256:a3jm5HIWdUdTsXuwT4LVYwLzViTu08OdGircV2/wDPc

debug3: mm_answer_keyallowed: key 0x80401b540 is allowed

debug3: mm_request_send entering: type 23

debug3: send packet: type 60 [preauth]

debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]

Postponed publickey for rodrigc from 192.168.1.5 port 58546 ssh2 [preauth]

debug3: receive packet: type 50 [preauth]

debug1: userauth-request for user rodrigc service ssh-connection method publickey [preauth]

debug1: attempt 3 failures 1 [preauth]

debug2: input_userauth_request: try method publickey [preauth]

debug3: userauth_pubkey: have signature for RSA SHA256:a3jm5HIWdUdTsXuwT4LVYwLzViTu08OdGircV2/wDPc [preauth]

debug3: mm_key_allowed entering [preauth]

debug3: mm_request_send entering: type 22 [preauth]

debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]

debug3: mm_request_receive_expect entering: type 23 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 22

debug3: mm_answer_keyallowed entering

debug3: mm_answer_keyallowed: key_from_blob: 0x80401b540

debug1: trying public key file /opt2/home/rodrigc/.ssh/authorized_keys

debug1: fd 4 clearing O_NONBLOCK

debug2: user_key_allowed: check options: 'ssh-dss AAAAB3NzaC1kc3MAAACBAO00EJjM71Kbjn+PUMQIvLi9OSVqlhwrKuFLTimAfDiRRXrGuTzOuzaYFb5SXQvJDdzGl1B1nSuzJLbTROfqIL/Mc3TxLBo1LeZjeTyNlYgXO+Me/keDygqcacHWDy+a2zXIYBqmwLnACF4B3lw5FUpySxwwwzJwdz8AaIfeMWhdAAAAFQChfRlm8UUrKI00Xtg/FfA+ajEfPQAAAIB2vKNP6T8QCsA6Hx82CQRP3Q1O/VsBOKqgQdgOf3a/1/rnxDFQHFtKMrCVgQu+M8SPOMOAub+Q3T07YEKhhFrONcRojARwzfYp6AJ35tZ70m8/5QrVXzhDM3HnCtyLv+aTatuFoHzOl8n9VxgTEieWQ6IekVPRtaMoSXKAgeX3eAAAAIBpjpXQH+mLK6a6xYwWxjjpemnG2I2luTR/NFWzdS4A0m5+qBEaKZmSwDKA/6jd3yG9MonRO5kmQhaS/bnXRp+vIH4i9E69XsCKsC53hGgGKS+V82rsrASO0snncRrtwiXljF/E5+4ZDSI2lPZeSbhnJdLnaOO86C62CfZN+Hocqw== rodrigc_android
'

debug2: user_key_allowed: advance: 'AAAAB3NzaC1kc3MAAACBAO00EJjM71Kbjn+PUMQIvLi9OSVqlhwrKuFLTimAfDiRRXrGuTzOuzaYFb5SXQvJDdzGl1B1nSuzJLbTROfqIL/Mc3TxLBo1LeZjeTyNlYgXO+Me/keDygqcacHWDy+a2zXIYBqmwLnACF4B3lw5FUpySxwwwzJwdz8AaIfeMWhdAAAAFQChfRlm8UUrKI00Xtg/FfA+ajEfPQAAAIB2vKNP6T8QCsA6Hx82CQRP3Q1O/VsBOKqgQdgOf3a/1/rnxDFQHFtKMrCVgQu+M8SPOMOAub+Q3T07YEKhhFrONcRojARwzfYp6AJ35tZ70m8/5QrVXzhDM3HnCtyLv+aTatuFoHzOl8n9VxgTEieWQ6IekVPRtaMoSXKAgeX3eAAAAIBpjpXQH+mLK6a6xYwWxjjpemnG2I2luTR/NFWzdS4A0m5+qBEaKZmSwDKA/6jd3yG9MonRO5kmQhaS/bnXRp+vIH4i9E69XsCKsC53hGgGKS+V82rsrASO0snncRrtwiXljF/E5+4ZDSI2lPZeSbhnJdLnaOO86C62CfZN+Hocqw== rodrigc_android
'

debug1: matching key found: file /opt2/home/rodrigc/.ssh/authorized_keys, line 2 RSA SHA256:a3jm5HIWdUdTsXuwT4LVYwLzViTu08OdGircV2/wDPc

debug3: mm_answer_keyallowed: key 0x80401b540 is allowed

debug3: mm_request_send entering: type 23

debug3: mm_key_verify entering [preauth]

debug3: mm_request_send entering: type 24 [preauth]

debug3: mm_key_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]

debug3: mm_request_receive_expect entering: type 25 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_request_receive entering

debug3: monitor_read: checking request 24

debug3: mm_answer_keyverify: key 0x80401b540 signature verified

debug3: mm_request_send entering: type 25

debug3: mm_request_receive_expect entering: type 102

debug3: mm_request_receive entering

debug1: do_pam_account: called

debug3: PAM: do_pam_account pam_acct_mgmt = 0 (success)

debug3: mm_request_send entering: type 103

Accepted publickey for rodrigc from 192.168.1.5 port 58546 ssh2: RSA SHA256:a3jm5HIWdUdTsXuwT4LVYwLzViTu08OdGircV2/wDPc

debug1: monitor_child_preauth: rodrigc has been authenticated by privileged process

debug3: mm_get_keystate: Waiting for new keys

debug3: mm_request_receive_expect entering: type 26

debug3: mm_request_receive entering

debug3: mm_get_keystate: GOT new keys

debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth]

debug3: mm_do_pam_account entering [preauth]

debug3: mm_request_send entering: type 102 [preauth]

debug3: mm_request_receive_expect entering: type 103 [preauth]

debug3: mm_request_receive entering [preauth]

debug3: mm_do_pam_account returning 1 [preauth]

debug3: send packet: type 52 [preauth]

debug3: mm_request_send entering: type 26 [preauth]

debug3: mm_send_keystate: Finished sending state [preauth]

debug1: monitor_read_log: child log fd closed

debug3: mm_share_sync: Share sync

debug3: mm_share_sync: Share sync end

debug3: ssh_sandbox_parent_finish: finished

debug1: PAM: establishing credentials

debug3: PAM: opening session

User child is on pid 68980

debug1: PAM: establishing credentials

debug3: monitor_apply_keystate: packet_set_state

debug2: set_newkeys: mode 0

debug1: rekey after 134217728 blocks

debug2: set_newkeys: mode 1

debug1: rekey after 134217728 blocks

debug1: ssh_packet_set_postauth: called

debug3: Fssh_ssh_packet_set_state: done

debug3: notify_hostkeys: key 0: ssh-rsa SHA256:73H4OcFhNGdHY2sVsbBOVVOudub2EkvfYNlwpxWM1Xw

debug3: notify_hostkeys: key 1: ssh-dss SHA256:6BQ11F0ejGONS1+d4O63t7fyyGKaEyW33a73x5G/3ic

debug3: notify_hostkeys: key 2: ecdsa-sha2-nistp256 SHA256:jkq3WG/EU+yyyg8xemPshcErRvPYmSbU202opbYgzHU

debug3: notify_hostkeys: key 3: ssh-ed25519 SHA256:59NbS+jIUH9ADjLpk5nQLKq229hrx89QpAd3Z3Ts6j4

debug3: notify_hostkeys: sent 4 hostkeys

debug3: send packet: type 80

debug1: Entering interactive session for SSH2.

debug2: fd 6 setting O_NONBLOCK

debug2: fd 7 setting O_NONBLOCK

debug1: server_init_dispatch_20

debug3: receive packet: type 90

debug1: server_input_channel_open: ctype session rchan 0 win 1048576 max 16384

debug1: input_session_request

debug1: channel 0: new [server-session]

debug2: session_new: allocate (allocated 0 max 10)

debug3: session_unused: session id 0 unused

debug1: session_new: session 0

debug1: session_open: channel 0

debug1: session_open: session 0: link with channel 0

debug1: server_input_channel_open: confirm session

debug3: send packet: type 91

debug3: receive packet: type 80

debug1: server_input_global_request: rtype no-more-sessions at openssh.com want_reply 0

debug3: receive packet: type 98

debug1: server_input_channel_req: channel 0 request pty-req reply 1

debug1: session_by_channel: session 0 channel 0

debug1: session_input_channel_req: session 0 req pty-req

debug1: Allocating pty.

debug3: mm_request_send entering: type 28

debug3: mm_pty_allocate: waiting for MONITOR_ANS_PTY

debug3: mm_request_receive_expect entering: type 29

debug3: mm_request_receive entering

debug3: mm_request_receive entering

debug3: monitor_read: checking request 28

debug3: mm_answer_pty entering

debug2: session_new: allocate (allocated 0 max 10)

debug3: session_unused: session id 0 unused

debug1: session_new: session 0

debug3: mm_request_send entering: type 29

debug3: mm_answer_pty: tty /dev/pts/4 ptyfd 5

debug1: session_pty_req: session 0 alloc /dev/pts/4

debug3: send packet: type 99

debug3: receive packet: type 98

debug1: server_input_channel_req: channel 0 request env reply 0

debug1: session_by_channel: session 0 channel 0

debug1: session_input_channel_req: session 0 req env

debug2: Ignoring env request LANG: disallowed name

debug3: receive packet: type 98

debug1: server_input_channel_req: channel 0 request shell reply 1

debug1: session_by_channel: session 0 channel 0

debug1: session_input_channel_req: session 0 req shell

Starting session: shell on pts/4 for rodrigc from 192.168.1.5 port 58546 id 0

debug2: fd 3 setting TCP_NODELAY

debug3: Fssh_ssh_packet_set_tos: set IP_TOS 0x10

debug2: channel 0: rfd 10 isatty

debug2: fd 10 setting O_NONBLOCK

debug3: fd 8 is O_NONBLOCK

debug3: send packet: type 99

debug1: Setting controlling tty using TIOCSCTTY.

debug2: channel 0: read<=0 rfd 10 len 0

debug2: channel 0: read failed

debug2: channel 0: close_read

debug2: channel 0: input open -> drain

debug2: channel 0: ibuf empty

debug2: channel 0: send eof

debug3: send packet: type 96

debug2: channel 0: input drain -> closed

debug1: Received SIGCHLD.

debug1: session_by_pid: pid 68981

debug1: session_exit_message: session 0 channel 0 pid 68981

debug2: channel 0: request exit-status confirm 0

debug3: send packet: type 98

debug1: session_exit_message: release channel 0

debug2: channel 0: write failed

debug2: channel 0: close_write

debug2: channel 0: send eow

debug3: send packet: type 98

debug2: channel 0: output open -> closed

debug3: mm_request_send entering: type 30

debug2: channel 0: send close

debug3: send packet: type 97

debug3: channel 0: will not send data after close

debug2: notify_done: reading

debug3: mm_request_receive entering

debug3: channel 0: will not send data after close

debug3: monitor_read: checking request 30

debug3: mm_answer_pty_cleanup entering

debug1: session_by_tty: session 0 tty /dev/pts/4

debug3: mm_session_close: session 0 pid 68980

debug3: mm_session_close: tty /dev/pts/4 ptyfd 5

debug1: session_pty_cleanup: session 0 release /dev/pts/4

debug3: session_unused: session id 0 unused

debug3: receive packet: type 97

debug2: channel 0: rcvd close

debug3: channel 0: will not send data after close

debug2: channel 0: is dead

debug2: channel 0: gc: notify user

debug1: session_by_channel: session 0 channel 0

debug1: session_close_by_channel: channel 0 child 0

Close session: user rodrigc from 192.168.1.5 port 58546 id 0

debug3: session_unused: session id 0 unused

debug2: channel 0: gc: user detached

debug2: channel 0: is dead

debug2: channel 0: garbage collecting

debug1: channel 0: free: server-session, nchannels 1

debug3: channel 0: status: The following connections are open:

  #0 server-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)



debug3: receive packet: type 1

Received disconnect from 192.168.1.5 port 58546:11: disconnected by user

Disconnected from 192.168.1.5 port 58546

debug1: do_cleanup

debug3: PAM: sshpam_thread_cleanup entering

debug3: mm_request_receive entering

debug1: do_cleanup

debug1: PAM: cleanup

debug1: PAM: closing session

debug1: PAM: deleting credentials

debug3: PAM: sshpam_thread_cleanup entering


Command exit status: 255
Script done on Tue Dec 20 18:50:47 2016


More information about the Twisted-Python mailing list