I hope somebody here can help. I've been setting up OpenSSH under Debian
using the current unstable packages and I cannot connect to the server
using PuTTY from Windows.
This setup uses an ADSL router port forwarding to the server and it is
an external connection over the internet that is failing. I have
searched everywhere I could think of for a solution to this, but it is
not a simple failure that I can see so it might be interesting enough
for somebody here to suggest something.
When I connect I get the usual username and password prompts. If I put
in the wrong password it carries on as it should and tells me access is
denied then asks for the password again. This leads me to think that the
SSH server is getting my connection, and sure enough, running sshd on
port 222 in debug mode shows this (full ddd debug log to follow).
When I get the correct password the debug output stops at Setting
controlling tty using TIOCSCTTY. The server hangs and eventually PuTTY
will say a software error closed the connection.
If I kill PuTTY before this happens then the server detects this and
closes the debug mode appropriately.
The long and short of it is that I don't get a shell after I have
authenticated. It looks to me like it a failing to allocate a TTY after
is decides I am allowed one. I have got round this by using lshd for
now, but there are a lot of strange problems with key authentication
when using that so I would very much like to use sshd again.
This may be a proper error, and I can report it, but I thought I had
best exhaust all my options before hand.
Sorry for the long log and thanks in advance.
Martin D Fraser
-----------------------------
debug2: read_server_config: filename /etc/ssh/sshd_config
debug1: sshd version OpenSSH_3.8.1p1 Debian-8.sarge.4
debug3: Not a RSA1 key file /etc/ssh/ssh_host_rsa_key.
debug1: read PEM private key done: type RSA
debug1: private host key: #0 type 1 RSA
debug3: Not a RSA1 key file /etc/ssh/ssh_host_dsa_key.
debug1: read PEM private key done: type DSA
debug1: private host key: #1 type 2 DSA
socket: Address family not supported by protocol
debug1: Bind to port 222 on 0.0.0.0.
Server listening on 0.0.0.0 port 222.
debug1: Server will not fork when running in debugging mode.
Connection from xxx.xxx.xxx.xxx port 1655
debug1: Client protocol version 2.0; client software version
PuTTY-Release-0.54
debug1: no match: PuTTY-Release-0.54
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_3.8.1p1 Debian-8.sarge.4
debug2: Network child is on pid 2007
debug3: preauth child monitor started
debug3: mm_request_receive entering
debug3: privsep user:group 100:65534
debug1: permanently_set_uid: 100/65534
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes256-cbc,rijndael256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,rijndael192-cbc,aes128-cbc,rijndael128-cbc,blowfish-cbc,3des-cbc
debug2: kex_parse_kexinit:
aes256-cbc,rijndael256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,rijndael192-cbc,aes128-cbc,rijndael128-cbc,blowfish-cbc,3des-cbc
debug2: kex_parse_kexinit: hmac-sha1,hmac-md5,none
debug2: kex_parse_kexinit: hmac-sha1,hmac-md5,none
debug2: kex_parse_kexinit: none,zlib,none
debug2: kex_parse_kexinit: none,zlib,none
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_init: found hmac-sha1
debug1: kex: client->server aes256-cbc hmac-sha1 none
debug2: mac_init: found hmac-sha1
debug1: kex: server->client aes256-cbc hmac-sha1 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST_OLD received
debug3: mm_request_send entering: type 0
debug3: mm_choose_dh: waiting for MONITOR_ANS_MODULI
debug3: mm_request_receive_expect entering: type 1
debug3: monitor_read: checking request 0
debug3: mm_request_receive entering
debug3: mm_answer_moduli: got parameters: 1024 2048 8192
debug3: mm_request_send entering: type 1
debug2: monitor_read: 0 used once, disabling now
debug3: mm_request_receive entering
debug3: mm_choose_dh: remaining 0
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug2: dh_gen_key: priv key bits set: 245/512
debug2: bits set: 1058/2048
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug2: bits set: 1069/2048
debug3: mm_key_sign entering
debug3: mm_request_send entering: type 4
debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN
debug3: mm_request_receive_expect entering: type 5
debug3: monitor_read: checking request 4
debug3: mm_request_receive entering
debug3: mm_answer_sign
debug3: mm_answer_sign: signature 0x809ddd0(143)
debug3: mm_request_send entering: type 5
debug2: monitor_read: 4 used once, disabling now
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
debug3: mm_request_receive entering
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user username service ssh-connection method
none
debug1: attempt 0 failures 0
debug3: mm_getpwnamallow entering
debug3: mm_request_send entering: type 6
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM
debug3: mm_request_receive_expect entering: type 7
debug3: monitor_read: checking request 6
debug3: mm_request_receive entering
debug3: mm_answer_pwnamallow
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send entering: type 7
debug2: monitor_read: 6 used once, disabling now
debug3: mm_request_receive entering
debug2: input_userauth_request: setting up authctxt for username
debug3: mm_start_pam entering
debug3: mm_request_send entering: type 45
debug3: mm_inform_authserv entering
debug3: monitor_read: checking request 45
debug3: mm_request_send entering: type 3
debug1: PAM: initializing for "username"
debug2: input_userauth_request: try method none
debug3: mm_auth_password entering
debug3: mm_request_send entering: type 10
debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD
debug3: mm_request_receive_expect entering: type 11
debug3: mm_request_receive entering
debug3: Trying to reverse map address xxx.xxx.xxx.xxx.
reverse mapping checking getaddrinfo for hostname.host.domain failed -
POSSIBLE BREAKIN ATTEMPT!
debug1: PAM: setting PAM_RHOST to "xxx.xxx.xxx.xxx"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 45 used once, disabling now
debug3: mm_request_receive entering
debug3: monitor_read: checking request 3
debug3: mm_answer_authserv: service=ssh-connection, style=
debug2: monitor_read: 3 used once, disabling now
debug3: mm_request_receive entering
debug3: monitor_read: checking request 10
debug3: mm_answer_authpassword: sending result 0
debug3: mm_request_send entering: type 11
Failed none for username from xxx.xxx.xxx.xxx port 1655 ssh2
debug3: mm_auth_password: user not authenticated
debug3: mm_request_receive entering
Failed none for username from xxx.xxx.xxx.xxx port 1655 ssh2
debug1: userauth-request for user username service ssh-connection method
publickey
debug1: attempt 1 failures 1
debug2: input_userauth_request: try method publickey
debug1: test whether pkalg/pkblob are acceptable
debug3: mm_key_allowed entering
debug3: mm_request_send entering: type 20
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED
debug3: mm_request_receive_expect entering: type 21
debug3: monitor_read: checking request 20
debug3: mm_request_receive entering
debug3: mm_answer_keyallowed entering
debug3: mm_answer_keyallowed: key_from_blob: 0x80a3138
debug1: temporarily_use_uid: 1000/1000 (e=0/0)
debug1: trying public key file /home/username/.ssh/authorized_keys
debug1: restore_uid: 0/0
debug1: temporarily_use_uid: 1000/1000 (e=0/0)
debug1: trying public key file /home/username/.ssh/authorized_keys2
debug1: restore_uid: 0/0
debug3: mm_answer_keyallowed: key 0x80a3138 is disallowed
debug3: mm_request_send entering: type 21
debug3: mm_request_receive entering
debug2: userauth_pubkey: authenticated 0 pkalg ssh-rsa
Failed publickey for username from xxx.xxx.xxx.xxx port 1655 ssh2
debug1: userauth-request for user username service ssh-connection method
password
debug1: attempt 2 failures 2
debug2: input_userauth_request: try method password
debug3: mm_auth_password entering
debug3: mm_request_send entering: type 10
debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD
debug3: mm_request_receive_expect entering: type 11
debug3: monitor_read: checking request 10
debug3: mm_request_receive entering
debug3: auth_shadow_pwexpired: today 12816 sp_lstchg 12714 sp_max 99999
debug3: mm_answer_authpassword: sending result 1
debug3: mm_request_send entering: type 11
debug3: mm_request_receive_expect entering: type 46
debug3: mm_auth_password: user authenticated
debug3: mm_request_receive entering
debug3: mm_do_pam_account entering
debug3: mm_request_send entering: type 46
debug3: mm_request_receive_expect entering: type 47
debug3: mm_request_receive entering
debug3: PAM: do_pam_account pam_acct_mgmt = 0
debug3: mm_request_send entering: type 47
debug3: mm_do_pam_account returning 1
Accepted password for username from xxx.xxx.xxx.xxx port 1655 ssh2
Accepted password for username from xxx.xxx.xxx.xxx port 1655 ssh2
debug1: monitor_child_preauth: username has been authenticated by
privileged process
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect entering: type 24
debug3: mm_request_receive entering
debug3: mm_send_keystate: Sending new keys: 0x809e048 0x809dfc8
debug3: mm_newkeys_to_blob: converting 0x809e048
debug3: mm_newkeys_to_blob: converting 0x809dfc8
debug3: mm_send_keystate: New keys have been sent
debug3: mm_send_keystate: Sending compression state
debug3: mm_request_send entering: type 24
debug3: mm_send_keystate: Finished sending state
debug3: mm_newkeys_from_blob: 0x80a41f0(139)
debug2: mac_init: found hmac-sha1
debug3: mm_get_keystate: Waiting for second key
debug3: mm_newkeys_from_blob: 0x80a41f0(139)
debug2: mac_init: found hmac-sha1
debug3: mm_get_keystate: Getting compression state
debug3: mm_get_keystate: Getting Network I/O buffers
debug3: mm_share_sync: Share sync
debug3: mm_share_sync: Share sync end
debug2: User child is on pid 2008
debug3: mm_request_receive entering
debug3: PAM: opening session
debug3: PAM: pam_store_conv called with 1 messages
debug3: PAM: pam_store_conv called with 1 messages
debug1: PAM: reinitializing credentials
debug1: permanently_set_uid: 1000/1000
debug2: set_newkeys: mode 0
debug2: set_newkeys: mode 1
debug1: Entering interactive session for SSH2.
debug2: fd 9 setting O_NONBLOCK
debug2: fd 10 setting O_NONBLOCK
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 256 win 16384 max
16384
debug1: input_session_request
debug1: channel 0: new [server-session]
debug1: session_new: init
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
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 25
debug3: mm_pty_allocate: waiting for MONITOR_ANS_PTY
debug3: mm_request_receive_expect entering: type 26
debug3: mm_request_receive entering
debug3: monitor_read: checking request 25
debug3: mm_answer_pty entering
debug1: session_new: init
debug1: session_new: session 0
debug3: mm_request_send entering: type 26
debug1: session_pty_req: session 0 alloc /dev/pts/1
debug3: tty_parse_modes: SSH2 n_bytes 1
debug3: mm_answer_pty: tty /dev/pts/1 ptyfd 7
debug3: mm_request_receive entering
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
debug1: PAM: setting PAM_TTY to "/dev/pts/1"
debug2: fd 4 setting TCP_NODELAY
debug1: Setting controlling tty using TIOCSCTTY.
debug2: channel 0: rfd 12 isatty
debug2: fd 12 setting O_NONBLOCK
debug2: fd 11 is O_NONBLOCK
Connection closed by xxx.xxx.xxx.xxx
debug1: channel 0: free: server-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 server-session (t4 r256 i0/0 o0/0 fd 12/11)
debug3: channel 0: close_fds r 12 w 11 e -1
debug1: session_close: session 0 pid 2009
debug3: mm_request_send entering: type 27
debug1: do_cleanup
debug1: PAM: cleanup
debug3: monitor_read: checking request 27
debug3: mm_answer_pty_cleanup entering
debug1: session_by_tty: session 0 tty /dev/pts/1
debug3: mm_session_close: session 0 pid 2008
debug3: mm_session_close: tty /dev/pts/1 ptyfd 7
debug1: session_pty_cleanup: session 0 release /dev/pts/1
debug3: PAM: sshpam_thread_cleanup entering
Closing connection to xxx.xxx.xxx.xxx
debug1: PAM: cleanup
debug3: mm_request_receive entering
debug1: Received SIGCHLD.
debug3: mm_request_send entering: type 56
debug3: monitor_read: checking request 56
debug3: mm_answer_term: tearing down sessions
