0

I have a CentOS 7 server with OpenSSH installed which it's primary purpose is to be an SFTP server. I have several clients who connect to this server using either Private/Public Key authentication or Passwords and they all connect fine.

I have one particular client who is connecting to our server using GlobalScape EFT 5.1 with a combination of Password and Private/Public Key.

The public key they provided us with starts with the comment below and is over multiple lines.

---- BEGIN SSH2 PUBLIC KEY ----

I converted the public key using SSH-KEYGEN -i -f and placed it inside the authorized_keys file. It is now on one line and starts with ssh-rsa.

On looking at the logs (which I have pasted below) it does not seem to be recognising that they are using a key.

Sep 30 15:49:37 server14 sshd[11107]: debug3: oom_adjust_restore
Sep 30 15:49:37 server14 sshd[11107]: Set /proc/self/oom_score_adj to 0
Sep 30 15:49:37 server14 sshd[11107]: debug1: rexec start in 5 out 5 newsock 5 pipe 8 sock 9
Sep 30 15:49:37 server14 sshd[11107]: debug1: inetd sockets after dupping: 3, 3
Sep 30 15:49:37 server14 sshd[11107]: Connection from XXX.XXX.XXX.XXX port 4387
Sep 30 15:49:37 server14 sshd[11107]: debug1: Client protocol version 2.0; client software version GSSFTP1.0
Sep 30 15:49:37 server14 sshd[11107]: debug1: no match: GSSFTP1.0
Sep 30 15:49:37 server14 sshd[11107]: debug1: Enabling compatibility mode for protocol 2.0
Sep 30 15:49:37 server14 sshd[11107]: debug1: Local version string SSH-2.0-OpenSSH_5.3
Sep 30 15:49:37 server14 sshd[11107]: debug2: fd 3 setting O_NONBLOCK
Sep 30 15:49:37 server14 sshd[11107]: debug2: Network child is on pid 11108
Sep 30 15:49:37 server14 sshd[11107]: debug3: preauth child monitor started
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: privsep user:group 74:74
Sep 30 15:49:37 server14 sshd[11108]: debug1: permanently_set_uid: 74/74
Sep 30 15:49:37 server14 sshd[11108]: debug1: list_hostkey_types: ssh-rsa,ssh-dss
Sep 30 15:49:37 server14 sshd[11108]: debug1: SSH2_MSG_KEXINIT sent
Sep 30 15:49:37 server14 sshd[11108]: debug3: Wrote 840 bytes for a total of 861
Sep 30 15:49:37 server14 sshd[11108]: debug1: SSH2_MSG_KEXINIT received
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: none,zlib@openssh.com
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: none,zlib@openssh.com
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: first_kex_follows 0 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: reserved 0 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: diffie-hellman-group1-sha1
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: 3des-cbc,arcfour,cast128-cbc,twofish-cbc,blowfish-cbc
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: 3des-cbc,arcfour,cast128-cbc,twofish-cbc,blowfish-cbc
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: zlib,none
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: zlib,none
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: first_kex_follows 0 
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_parse_kexinit: reserved 0 
Sep 30 15:49:37 server14 sshd[11108]: debug2: mac_setup: found hmac-md5
Sep 30 15:49:37 server14 sshd[11108]: debug1: kex: client->server 3des-cbc hmac-md5 none
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 78
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 79
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 78
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 79
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug2: mac_setup: found hmac-md5
Sep 30 15:49:37 server14 sshd[11108]: debug1: kex: server->client 3des-cbc hmac-md5 none
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 78
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 79
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 78
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 79
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug2: dh_gen_key: priv key bits set: 208/384
Sep 30 15:49:37 server14 sshd[11108]: debug2: bits set: 502/1024
Sep 30 15:49:37 server14 sshd[11108]: debug1: expecting SSH2_MSG_KEXDH_INIT
Sep 30 15:49:37 server14 sshd[11108]: debug2: bits set: 539/1024
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_key_sign entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 5
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 6
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 5
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_sign
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_sign: signature 0x7fe361d8dbf0(271)
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 6
Sep 30 15:49:37 server14 sshd[11108]: debug2: kex_derive_keys
Sep 30 15:49:37 server14 sshd[11108]: debug2: set_newkeys: mode 1
Sep 30 15:49:37 server14 sshd[11108]: debug1: SSH2_MSG_NEWKEYS sent
Sep 30 15:49:37 server14 sshd[11108]: debug1: expecting SSH2_MSG_NEWKEYS
Sep 30 15:49:37 server14 sshd[11108]: debug3: Wrote 720 bytes for a total of 1581
Sep 30 15:49:37 server14 sshd[11107]: debug2: monitor_read: 5 used once, disabling now
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug2: set_newkeys: mode 0
Sep 30 15:49:37 server14 sshd[11108]: debug1: SSH2_MSG_NEWKEYS received
Sep 30 15:49:37 server14 sshd[11108]: debug1: KEX done
Sep 30 15:49:37 server14 sshd[11108]: debug3: Wrote 48 bytes for a total of 1629
Sep 30 15:49:37 server14 sshd[11108]: debug3: Received SSH2_MSG_IGNORE
Sep 30 15:49:37 server14 sshd[11108]: debug1: userauth-request for user SFTPUserName service ssh-connection method none
Sep 30 15:49:37 server14 sshd[11108]: debug1: attempt 0 failures 0
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_getpwnamallow entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 7
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 8
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 7
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_pwnamallow
Sep 30 15:49:37 server14 sshd[11107]: debug3: Trying to reverse map address XXX.XXX.XXX.XXX.
Sep 30 15:49:37 server14 sshd[11107]: debug2: parse_server_config: config reprocess config len 901
Sep 30 15:49:37 server14 sshd[11107]: debug3: checking match for 'User SFTPUserName' user SFTPUserName host XXX.XXX.XXX.XXX addr XXX.XXX.XXX.XXX
Sep 30 15:49:37 server14 sshd[11107]: debug1: user ScotPower matched 'User SFTPUserName' at line 147
Sep 30 15:49:37 server14 sshd[11107]: debug3: match found
Sep 30 15:49:37 server14 sshd[11107]: debug3: reprocess config:148 setting ForceCommand internal-sftp
Sep 30 15:49:37 server14 sshd[11107]: debug3: reprocess config:149 setting AllowTCPForwarding no
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 8
Sep 30 15:49:37 server14 sshd[11108]: debug2: input_userauth_request: setting up authctxt for SFTPUserName
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_start_pam entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 50
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_inform_authserv entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 3
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_inform_authrole entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 4
Sep 30 15:49:37 server14 sshd[11108]: debug2: input_userauth_request: try method none
Sep 30 15:49:37 server14 sshd[11108]: debug3: Wrote 80 bytes for a total of 1709
Sep 30 15:49:37 server14 sshd[11107]: debug2: monitor_read: 7 used once, disabling now
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 50
Sep 30 15:49:37 server14 sshd[11107]: debug1: PAM: initializing for "SFTPUserName"
Sep 30 15:49:37 server14 sshd[11107]: debug1: PAM: setting PAM_RHOST to "XXX.XXX.XXX.XXX"
Sep 30 15:49:37 server14 sshd[11107]: debug1: PAM: setting PAM_TTY to "ssh"
Sep 30 15:49:37 server14 sshd[11107]: debug2: monitor_read: 50 used once, disabling now
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 3
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_authserv: service=ssh-connection, style=
Sep 30 15:49:37 server14 sshd[11107]: debug2: monitor_read: 3 used once, disabling now
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 4
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_authrole: role=
Sep 30 15:49:37 server14 sshd[11107]: debug2: monitor_read: 4 used once, disabling now
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: Received SSH2_MSG_IGNORE
Sep 30 15:49:37 server14 sshd[11108]: debug1: userauth-request for user SFTPUserName service ssh-connection method password
Sep 30 15:49:37 server14 sshd[11108]: debug1: attempt 1 failures 0
Sep 30 15:49:37 server14 sshd[11108]: debug2: input_userauth_request: try method password
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_auth_password entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 11
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 12
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 11
Sep 30 15:49:37 server14 sshd[11107]: debug3: PAM: sshpam_passwd_conv called with 1 messages
Sep 30 15:49:37 server14 sshd[11107]: debug1: PAM: password authentication accepted for SFTPUserName
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_authpassword: sending result 1
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 12
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive_expect entering: type 51
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_auth_password: user authenticated
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_do_pam_account entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 51
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 52
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug1: do_pam_account: called
Sep 30 15:49:37 server14 sshd[11107]: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 52
Sep 30 15:49:37 server14 sshd[11107]: Accepted password for SFTPUserName from XXX.XXX.XXX.XXX port 4387 ssh2
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_do_pam_account returning 1
Sep 30 15:49:37 server14 sshd[11107]: debug1: monitor_child_preauth: SFTPUserName has been authenticated by privileged process
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_get_keystate: Waiting for new keys
Sep 30 15:49:37 server14 sshd[11108]: debug3: Wrote 32 bytes for a total of 1741
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive_expect entering: type 25
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_send_keystate: Sending new keys: 0x7fe361d8d950 0x7fe361d8ebf0
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_newkeys_to_blob: converting 0x7fe361d8d950
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_newkeys_to_blob: converting 0x7fe361d8ebf0
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_send_keystate: New keys have been sent
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_send_keystate: Sending compression state
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 25
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_send_keystate: Finished sending state
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_send entering: type 80
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive_expect entering: type 81
Sep 30 15:49:37 server14 sshd[11108]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_newkeys_from_blob: 0x7fe361da19f0(120)
Sep 30 15:49:37 server14 sshd[11107]: debug2: mac_setup: found hmac-md5
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_get_keystate: Waiting for second key
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_newkeys_from_blob: 0x7fe361da19f0(120)
Sep 30 15:49:37 server14 sshd[11107]: debug2: mac_setup: found hmac-md5
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_get_keystate: Getting compression state
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_get_keystate: Getting Network I/O buffers
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive_expect entering: type 80
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 81
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_share_sync: Share sync
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_share_sync: Share sync end
Sep 30 15:49:37 server14 sshd[11107]: debug1: temporarily_use_uid: 504/504 (e=0/0)
Sep 30 15:49:37 server14 sshd[11107]: debug1: ssh_gssapi_storecreds: Not a GSSAPI mechanism
Sep 30 15:49:37 server14 sshd[11107]: debug1: restore_uid: 0/0
Sep 30 15:49:37 server14 sshd[11107]: debug1: SELinux support disabled
Sep 30 15:49:37 server14 sshd[11107]: debug1: PAM: establishing credentials
Sep 30 15:49:37 server14 sshd[11107]: debug3: PAM: opening session
Sep 30 15:49:37 server14 sshd[11107]: debug1: temporarily_use_uid: 504/504 (e=0/0)
Sep 30 15:49:37 server14 sshd[11107]: debug1: ssh_gssapi_storecreds: Not a GSSAPI mechanism
Sep 30 15:49:37 server14 sshd[11107]: debug1: restore_uid: 0/0
Sep 30 15:49:37 server14 sshd[11107]: User child is on pid 11109
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11109]: debug1: PAM: establishing credentials
Sep 30 15:49:37 server14 sshd[11109]: debug1: permanently_set_uid: 504/504
Sep 30 15:49:37 server14 sshd[11109]: debug2: set_newkeys: mode 0
Sep 30 15:49:37 server14 sshd[11109]: debug2: set_newkeys: mode 1
Sep 30 15:49:37 server14 sshd[11109]: debug1: Entering interactive session for SSH2.
Sep 30 15:49:37 server14 sshd[11109]: debug2: fd 5 setting O_NONBLOCK
Sep 30 15:49:37 server14 sshd[11109]: debug2: fd 6 setting O_NONBLOCK
Sep 30 15:49:37 server14 sshd[11109]: debug1: server_init_dispatch_20
Sep 30 15:49:37 server14 sshd[11109]: debug1: server_input_channel_open: ctype session rchan 0 win 100000 max 8192
Sep 30 15:49:37 server14 sshd[11109]: debug1: input_session_request
Sep 30 15:49:37 server14 sshd[11109]: debug1: channel 0: new [server-session]
Sep 30 15:49:37 server14 sshd[11109]: debug2: session_new: allocate (allocated 0 max 10)
Sep 30 15:49:37 server14 sshd[11109]: debug3: session_unused: session id 0 unused
Sep 30 15:49:37 server14 sshd[11109]: debug1: session_new: session 0
Sep 30 15:49:37 server14 sshd[11109]: debug1: session_open: channel 0
Sep 30 15:49:37 server14 sshd[11109]: debug1: session_open: session 0: link with channel 0
Sep 30 15:49:37 server14 sshd[11109]: debug1: server_input_channel_open: confirm session
Sep 30 15:49:37 server14 sshd[11109]: debug3: Wrote 48 bytes for a total of 1789
Sep 30 15:49:37 server14 sshd[11109]: debug1: server_input_channel_req: channel 0 request subsystem reply 1
Sep 30 15:49:37 server14 sshd[11109]: debug1: session_by_channel: session 0 channel 0
Sep 30 15:49:37 server14 sshd[11109]: debug1: session_input_channel_req: session 0 req subsystem
Sep 30 15:49:37 server14 sshd[11109]: subsystem request for sftp
Sep 30 15:49:37 server14 sshd[11109]: debug1: subsystem: exec() internal-sftp -l DEBUG3 -f AUTH
Sep 30 15:49:37 server14 sshd[11109]: debug1: Forced command (config) 'internal-sftp'
Sep 30 15:49:37 server14 sshd[11109]: debug3: mm_audit_run_command entering command internal-sftp
Sep 30 15:49:37 server14 sshd[11109]: debug3: mm_request_send entering: type 62
Sep 30 15:49:37 server14 sshd[11109]: debug3: mm_request_receive_expect entering: type 63
Sep 30 15:49:37 server14 sshd[11109]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11107]: debug3: monitor_read: checking request 62
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_answer_audit_command entering
Sep 30 15:49:37 server14 sshd[11107]: debug2: session_new: allocate (allocated 0 max 10)
Sep 30 15:49:37 server14 sshd[11107]: debug3: session_unused: session id 0 unused
Sep 30 15:49:37 server14 sshd[11107]: debug1: session_new: session 0
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_send entering: type 63
Sep 30 15:49:37 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:37 server14 sshd[11109]: debug2: fd 3 setting TCP_NODELAY
Sep 30 15:49:37 server14 sshd[11109]: debug2: fd 9 setting O_NONBLOCK
Sep 30 15:49:37 server14 sshd[11109]: debug2: fd 8 setting O_NONBLOCK
Sep 30 15:49:37 server14 sshd[11109]: debug2: fd 11 setting O_NONBLOCK
Sep 30 15:49:37 server14 sshd[11109]: debug3: Wrote 72 bytes for a total of 1861
Sep 30 15:49:37 server14 sshd[11109]: debug3: Wrote 136 bytes for a total of 1997
Sep 30 15:49:47 server14 sshd[11109]: Connection closed by XXX.XXX.XXX.XXX
Sep 30 15:49:47 server14 sshd[11109]: debug1: channel 0: free: server-session, nchannels 1
Sep 30 15:49:47 server14 sshd[11109]: debug3: channel 0: status: The following connections are open:\r\n  #0 server-session (t4 r0 i0/0 o0/0 fd 9/8 cc -1)\r\n
Sep 30 15:49:47 server14 sshd[11109]: debug3: channel 0: close_fds r 9 w 8 e 11
Sep 30 15:49:47 server14 sshd[11109]: debug1: session_close: session 0 pid 11110
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_audit_end_command entering command internal-sftp
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_request_send entering: type 64
Sep 30 15:49:47 server14 sshd[11109]: debug3: session_unused: session id 0 unused
Sep 30 15:49:47 server14 sshd[11109]: debug1: do_cleanup
Sep 30 15:49:47 server14 sshd[11109]: debug3: PAM: sshpam_thread_cleanup entering
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_request_send entering: type 80
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_request_receive_expect entering: type 81
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_request_receive entering
Sep 30 15:49:47 server14 sshd[11107]: debug3: monitor_read: checking request 64
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_answer_audit_end_command entering
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_session_close: session 0 pid 0
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_session_close: command 0
Sep 30 15:49:47 server14 sshd[11107]: debug3: session_unused: session id 0 unused
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:47 server14 sshd[11107]: debug3: monitor_read: checking request 80
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_request_send entering: type 81
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:47 server14 sshd[11109]: Transferred: sent 1864, received 2744 bytes
Sep 30 15:49:47 server14 sshd[11109]: Closing connection to XXX.XXX.XXX.XXX port 4387
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_audit_event entering
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_request_send entering: type 61
Sep 30 15:49:47 server14 sshd[11107]: debug3: monitor_read: checking request 61
Sep 30 15:49:47 server14 sshd[11109]: debug3: mm_request_send entering: type 65
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_answer_audit_event entering
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_request_receive entering
Sep 30 15:49:47 server14 sshd[11107]: debug3: monitor_read: checking request 65
Sep 30 15:49:47 server14 sshd[11107]: debug3: mm_answer_term: tearing down sessions
Sep 30 15:49:47 server14 sshd[11107]: debug1: PAM: cleanup
Sep 30 15:49:47 server14 sshd[11107]: debug1: PAM: closing session
Sep 30 15:49:47 server14 sshd[11107]: debug1: PAM: deleting credentials

I must add that we recently upgraded the server from CentOS6 to 7 and the connection used to work on CentOS6. As far as I can tell the configuration is identical.

Below is the current sshd_config file that we are using.

#   $OpenBSD: sshd_config,v 1.80 2008/07/02 02:24:18 djm Exp $

# This is the sshd server system-wide configuration file.  See
# sshd_config(5) for more information.

# This sshd was compiled with PATH=/usr/local/bin:/bin:/usr/bin

# The strategy used for options in the default sshd_config shipped with
# OpenSSH is to specify options with their default value where
# possible, but leave them commented.  Uncommented options change a
# default value.

#Port 22
#AddressFamily any
#ListenAddress 0.0.0.0
#ListenAddress ::

# Disable legacy (protocol version 1) support in the server for new
# installations. In future the default will change to require explicit
# activation of protocol 1
Protocol 2

# HostKey for protocol version 1
#HostKey /etc/ssh/ssh_host_key
# HostKeys for protocol version 2
#HostKey /etc/ssh/ssh_host_rsa_key
#HostKey /etc/ssh/ssh_host_dsa_key

# Lifetime and size of ephemeral version 1 server key
#KeyRegenerationInterval 1h
#ServerKeyBits 1024

# Logging
# obsoletes QuietMode and FascistLogging
SyslogFacility AUTH
SyslogFacility AUTHPRIV
LogLevel DEBUG3

# Authentication:

#LoginGraceTime 2m
#PermitRootLogin yes
#StrictModes yes
#MaxAuthTries 6
#MaxSessions 10

RSAAuthentication yes
PubkeyAuthentication yes
AuthorizedKeysFile  %h/.ssh/authorized_keys
#AuthorizedKeysCommand none
#AuthorizedKeysCommandRunAs nobody

# For this to work you will also need host keys in /etc/ssh/ssh_known_hosts
#RhostsRSAAuthentication no
# similar for protocol version 2
#HostbasedAuthentication no
# Change to yes if you don't trust ~/.ssh/known_hosts for
# RhostsRSAAuthentication and HostbasedAuthentication
#IgnoreUserKnownHosts no
# Don't read the user's ~/.rhosts and ~/.shosts files
#IgnoreRhosts yes

# To disable tunneled clear text passwords, change to no here!
PasswordAuthentication yes
#PermitEmptyPasswords no

# Change to no to disable s/key passwords
ChallengeResponseAuthentication no

# Kerberos options
#KerberosAuthentication no
#KerberosOrLocalPasswd yes
#KerberosTicketCleanup yes
#KerberosGetAFSToken no
#KerberosUseKuserok yes

# GSSAPI options
#GSSAPIAuthentication no
GSSAPIAuthentication yes
#GSSAPICleanupCredentials yes
GSSAPICleanupCredentials yes
#GSSAPIStrictAcceptorCheck yes
#GSSAPIKeyExchange no

# Set this to 'yes' to enable PAM authentication, account processing, 
# and session processing. If this is enabled, PAM authentication will 
# be allowed through the ChallengeResponseAuthentication and
# PasswordAuthentication.  Depending on your PAM configuration,
# PAM authentication via ChallengeResponseAuthentication may bypass
# the setting of "PermitRootLogin without-password".
# If you just want the PAM account and session checks to run without
# PAM authentication, then enable this but set PasswordAuthentication
# and ChallengeResponseAuthentication to 'no'.
#UsePAM no
UsePAM yes

# Accept locale-related environment variables
AcceptEnv LANG LC_CTYPE LC_NUMERIC LC_TIME LC_COLLATE LC_MONETARY LC_MESSAGES
AcceptEnv LC_PAPER LC_NAME LC_ADDRESS LC_TELEPHONE LC_MEASUREMENT
AcceptEnv LC_IDENTIFICATION LC_ALL LANGUAGE
AcceptEnv XMODIFIERS

#AllowAgentForwarding yes
#AllowTcpForwarding yes
#GatewayPorts no
#X11Forwarding no
X11Forwarding yes
#X11DisplayOffset 10
#X11UseLocalhost yes
#PrintMotd yes
#PrintLastLog yes
#TCPKeepAlive yes
#UseLogin no
#UsePrivilegeSeparation yes
#PermitUserEnvironment no
#Compression delayed
#ClientAliveInterval 0
ClientAliveCountMax 10
#ShowPatchLevel no
#UseDNS yes
#PidFile /var/run/sshd.pid
#MaxStartups 10:30:100
PermitTunnel yes
#ChrootDirectory none

# no default banner path
#Banner none

# override default of no subsystems
Subsystem   sftp    internal-sftp -l VERBOSE -f AUTH

# Example of overriding settings on a per-user basis
#Match User anoncvs
#   X11Forwarding no
#   AllowTcpForwarding no
#   ForceCommand cvs server

# tail /etc/ssh/sshd_config

Match User SFTPUserName
    ForceCommand internal-sftp
    AllowTCPForwarding no
0

In server log, there is not used pubkey authentication method, so I would rather blame client that he is not sending the key.

Since the client is using some non-standard software (that I have never heard of before) it is possible there appeared some incompatibility during the time since centos6 release on one or the other side.

Updating the client to current version should help: EFT 5.1 is 8 years old!

  • At present the client is saying that it used to work and the only change has been our server. I don't think updating from EFT 5.1 is an option :( – JammoD Oct 2 '15 at 12:31
  • yes, but it is not excuse to use such outdated software. I don't believe it is even supported after so many years – Jakuje Oct 2 '15 at 12:33

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.