ssh可以登录sftp不能登录

我的服务器一直正常使用，平时使用secureCRT进行管理，使用secureFX进行文件的上传下载，突然有一天secureFX连接的时候出问题了，secureFX的日志如下:

i SecureFX 版本 6.6.1.289 (Official Release - November 4, 2010) 
i 会话 00002 成功建立(为) session mydomain_218.245.0.54_cd.mydomain.com
i SSH2Core version 6.6.0.289
i 正在连接到 cd.mydomain.com:22 ...
i 正在从状态 STATE_NOT_CONNECTED 更改为 STATE_EXPECT_KEX_INIT
i Using protocol SSH2
i RECV : Remote Identifier = 'SSH-2.0-OpenSSH_5.3'
i CAP  : Remote can re-key
i CAP  : Remote sends language in password change requests
i CAP  : Remote sends algorithm name in PK_OK packets
i CAP  : Remote sends algorithm name in public key packets
i CAP  : Remote sends algorithm name in signatures
i CAP  : Remote sends error text in open failure packets
i CAP  : Remote sends name in service accept packets
i CAP  : Remote includes port number in x11 open packets
i CAP  : Remote uses 160 bit keys for SHA1 MAC
i CAP  : Remote supports new diffie-hellman group exchange messages
i CAP  : Remote correctly handles unknown SFTP extensions
i CAP  : Remote correctly encodes OID for gssapi
i CAP  : Remote correctly uses connected addresses in forwarded-tcpip requests
i CAP  : Remote can do SFTP version 4
i CAP  : Remote x.509v3 uses ASN.1 encoding for DSA signatures
i SSPI : Requesting full delegation
i SSPI : [Kerberos] SPN : host@cd.mydomain.com
i SSPI : [Kerberos] InitializeSecurityContext() failed.
i SSPI : [Kerberos] 安全包中没有可用的凭证
i SSPI : [Kerberos] Disabling gss mechanism
i GSS  : Requesting full delegation
i GSS  : [Kerberos] SPN : host@cd.mydomain.com
i GSS  : [Kerberos] InitializeSecurityContext() failed.
i GSS  : [Kerberos] Could not load library 'gssapi32.dll': 找不到指定的模块。
i GSS  : [Kerberos] Disabling gss mechanism
i GSS  : [Kerberos] Disabling gss mechanism
i The following key exchange method has been filtered from the key exchange method list because it is not supported: gss-group1-sha1-toWM5Slw5Ew8Mqkay+al2g==
i SSPI : Requesting full delegation
i SSPI : [Kerberos (Group Exchange)] SPN : host@cd.mydomain.com
i SSPI : [Kerberos (Group Exchange)] InitializeSecurityContext() failed.
i SSPI : [Kerberos (Group Exchange)] 安全包中没有可用的凭证
i SSPI : [Kerberos (Group Exchange)] Disabling gss mechanism
i GSS  : Requesting full delegation
i GSS  : [Kerberos (Group Exchange)] SPN : host@cd.mydomain.com
i GSS  : [Kerberos (Group Exchange)] InitializeSecurityContext() failed.
i GSS  : [Kerberos (Group Exchange)] Could not load library 'gssapi32.dll': 找不到指定的模块。
i GSS  : [Kerberos (Group Exchange)] Disabling gss mechanism
i GSS  : [Kerberos (Group Exchange)] Disabling gss mechanism
i The following key exchange method has been filtered from the key exchange method list because it is not supported: gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==
i SEND : KEXINIT
i RECV : Read kexinit
i Available Remote Kex Methods = diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
i Selected Kex Method = diffie-hellman-group-exchange-sha1
i Available Remote Host Key Algos = ssh-rsa,ssh-dss
i Selected Host Key Algo = ssh-dss
i Available Remote Send Ciphers = 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
i Selected Send Cipher = aes256-ctr
i Available Remote Recv Ciphers = 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
i Selected Recv Cipher = aes256-ctr
i Available Remote Send Macs = hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
i Selected Send Mac = hmac-sha1
i Available Remote Recv Macs = hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
i Selected Recv Mac = hmac-sha1
i Available Remote Compressors = none,zlib@openssh.com
i Selected Compressor = none
i Available Remote Decompressors = none,zlib@openssh.com
i Selected Decompressor = none
i 正在从状态 STATE_EXPECT_KEX_INIT 更改为 STATE_KEY_EXCHANGE
i SEND : KEXDH_GEX_REQUEST
i RECV : KEXDH_GEX_GROUP
i SEND : KEXDH_INIT
i RECV : KEXDH_REPLY
i SEND : NEWKEYS
i 正在从状态 STATE_KEY_EXCHANGE 更改为 STATE_EXPECT_NEWKEYS
i RECV: Remote Hostkey: 0c:f4:cd:fb:c8:1e:00:a2:68:b1:a7:22:57:83:bc:63
i RECV : NEWKEYS
i 正在从状态 STATE_EXPECT_NEWKEYS 更改为 STATE_CONNECTION
i SEND: SERVICE_REQUEST[ssh-userauth]
i RECV: SERVICE_ACCEPT[ssh-userauth] -- OK
i SENT : USERAUTH_REQUEST [none]
i RECV : USERAUTH_FAILURE, continuations [publickey,gssapi-keyex,gssapi-with-mic,password]
i SENT : USERAUTH_REQUEST [password]
i RECV : AUTH_SUCCESS
i Channel Closed.

很是不解，Google了半天也没解决问题。

首先为了确保其他稀奇古怪的问题出现，我将iptables和selinux都关闭，还是不行。

查看/etc/ssh/sshd_config文件中的 Subsystem       sftp    /usr/libexec/openssh/sftp-server  有没有被注释，经查是没有被注释的，而且文件系统里也有

[root@cd ~]# ll /usr/libexec/openssh/sftp-server

----------. 1 root root 63544 2月  22 2013 /usr/libexec/openssh/sftp-server

说明应该是对的。

然后开启了ssh的dubug模式，编辑/etc/ssh/sshd_config文件，将LogLevel INFO改为LogLevel DEBUG，重启了sshd服务

# /etc/init.d/sshd restart

再使用secureFX登录时查看日志信息，

查看# tail -f /var/log/messages 时没有日志输出，

查看# tail -f /var/log/secure 时日志输出如下，未见明显的错误信息输出：

Aug 12 18:21:59 cd sshd[1307]: debug1: Forked child 1870.
Aug 12 18:21:59 cd sshd[1870]: Set /proc/self/oom_score_adj to 0
Aug 12 18:21:59 cd sshd[1870]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Aug 12 18:21:59 cd sshd[1870]: debug1: inetd sockets after dupping: 3, 3
Aug 12 18:21:59 cd sshd[1870]: Connection from 171.214.177.214 port 52174
Aug 12 18:21:59 cd sshd[1870]: debug1: Client protocol version 2.0; client software version SecureFX_6_6_1_289 SecureFX
Aug 12 18:21:59 cd sshd[1870]: debug1: no match: SecureFX_6_6_1_289 SecureFX
Aug 12 18:21:59 cd sshd[1870]: debug1: Enabling compatibility mode for protocol 2.0
Aug 12 18:21:59 cd sshd[1870]: debug1: Local version string SSH-2.0-OpenSSH_5.3
Aug 12 18:21:59 cd sshd[1871]: debug1: permanently_set_uid: 74/74
Aug 12 18:21:59 cd sshd[1871]: debug1: list_hostkey_types: ssh-rsa,ssh-dss
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_KEXINIT sent
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_KEXINIT received
Aug 12 18:21:59 cd sshd[1871]: debug1: kex: client->server aes256-ctr hmac-sha1 none
Aug 12 18:21:59 cd sshd[1871]: debug1: kex: server->client aes256-ctr hmac-sha1 none
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
Aug 12 18:21:59 cd sshd[1871]: debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_NEWKEYS sent
Aug 12 18:21:59 cd sshd[1871]: debug1: expecting SSH2_MSG_NEWKEYS
Aug 12 18:21:59 cd sshd[1871]: debug1: SSH2_MSG_NEWKEYS received
Aug 12 18:21:59 cd sshd[1871]: debug1: KEX done
Aug 12 18:21:59 cd sshd[1871]: debug1: userauth-request for user root service ssh-connection method none
Aug 12 18:21:59 cd sshd[1871]: debug1: attempt 0 failures 0
Aug 12 18:21:59 cd sshd[1870]: debug1: PAM: initializing for "root"
Aug 12 18:21:59 cd sshd[1870]: debug1: PAM: setting PAM_RHOST to "171.214.177.214"
Aug 12 18:21:59 cd sshd[1870]: debug1: PAM: setting PAM_TTY to "ssh"
Aug 12 18:21:59 cd sshd[1871]: debug1: userauth-request for user root service ssh-connection method password
Aug 12 18:21:59 cd sshd[1871]: debug1: attempt 1 failures 0
Aug 12 18:21:59 cd sshd[1870]: debug1: PAM: password authentication accepted for root
Aug 12 18:21:59 cd sshd[1870]: debug1: do_pam_account: called
Aug 12 18:21:59 cd sshd[1870]: Accepted password for root from 171.214.177.214 port 52174 ssh2
Aug 12 18:21:59 cd sshd[1870]: debug1: monitor_child_preauth: root has been authenticated by privileged process
Aug 12 18:21:59 cd sshd[1870]: debug1: temporarily_use_uid: 0/0 (e=0/0)
Aug 12 18:21:59 cd sshd[1870]: debug1: ssh_gssapi_storecreds: Not a GSSAPI mechanism
Aug 12 18:21:59 cd sshd[1870]: debug1: restore_uid: 0/0
Aug 12 18:21:59 cd sshd[1870]: debug1: SELinux support enabled
Aug 12 18:21:59 cd sshd[1870]: debug1: PAM: establishing credentials
Aug 12 18:21:59 cd sshd[1870]: pam_unix(sshd:session): session opened for user root by (uid=0)
Aug 12 18:21:59 cd sshd[1870]: debug1: Entering interactive session for SSH2.
Aug 12 18:21:59 cd sshd[1870]: debug1: server_init_dispatch_20
Aug 12 18:21:59 cd sshd[1870]: debug1: server_input_channel_open: ctype session rchan 0 win 65536 max 16384
Aug 12 18:21:59 cd sshd[1870]: debug1: input_session_request
Aug 12 18:21:59 cd sshd[1870]: debug1: channel 0: new [server-session]
Aug 12 18:21:59 cd sshd[1870]: debug1: session_new: session 0
Aug 12 18:21:59 cd sshd[1870]: debug1: session_open: channel 0
Aug 12 18:21:59 cd sshd[1870]: debug1: session_open: session 0: link with channel 0
Aug 12 18:21:59 cd sshd[1870]: debug1: server_input_channel_open: confirm session
Aug 12 18:21:59 cd sshd[1870]: debug1: server_input_channel_req: channel 0 request subsystem reply 1
Aug 12 18:21:59 cd sshd[1870]: debug1: session_by_channel: session 0 channel 0
Aug 12 18:21:59 cd sshd[1870]: debug1: session_input_channel_req: session 0 req subsystem
Aug 12 18:21:59 cd sshd[1870]: subsystem request for sftp
Aug 12 18:21:59 cd sshd[1870]: debug1: subsystem: exec() /usr/libexec/openssh/sftp-server
Aug 12 18:21:59 cd sshd[1874]: debug1: PAM: reinitializing credentials
Aug 12 18:21:59 cd sshd[1874]: debug1: permanently_set_uid: 0/0
Aug 12 18:22:00 cd sshd[1870]: debug1: Received SIGCHLD.
Aug 12 18:22:00 cd sshd[1870]: debug1: session_by_pid: pid 1874
Aug 12 18:22:00 cd sshd[1870]: debug1: session_exit_message: session 0 channel 0 pid 1874
Aug 12 18:22:00 cd sshd[1870]: debug1: session_exit_message: release channel 0
Aug 12 18:22:00 cd sshd[1870]: debug1: session_by_channel: session 0 channel 0
Aug 12 18:22:00 cd sshd[1870]: debug1: session_close_by_channel: channel 0 child 0
Aug 12 18:22:00 cd sshd[1870]: debug1: session_close: session 0 pid 0
Aug 12 18:22:00 cd sshd[1870]: debug1: channel 0: free: server-session, nchannels 1
Aug 12 18:22:00 cd sshd[1870]: Connection closed by 171.214.177.214
Aug 12 18:22:00 cd sshd[1870]: debug1: do_cleanup
Aug 12 18:22:00 cd sshd[1870]: debug1: PAM: cleanup
Aug 12 18:22:00 cd sshd[1870]: debug1: PAM: closing session
Aug 12 18:22:00 cd sshd[1870]: pam_unix(sshd:session): session closed for user root
Aug 12 18:22:00 cd sshd[1870]: debug1: PAM: deleting credentials
Aug 12 18:22:00 cd sshd[1870]: Transferred: sent 2120, received 1192 bytes
Aug 12 18:22:00 cd sshd[1870]: Closing connection to 171.214.177.214 port 52174

无解，继续Google解决办法 https://www.linuxquestions.org/questions/linux-server-73/can't-get-sftp-logging-to-work-931609/ 收到启发，将 /etc/ssh/sshd_config 中的

Subsystem      sftp    /usr/libexec/openssh/sftp-server 

改为

Subsystem       sftp    internal-sftp

重启sshd后，sftp正常工作了。

但是原因仍然不知为何，回头看看，发现 /usr/libexec/openssh/sftp-server 没有任何权限：

# ll /usr/libexec/openssh/sftp-server

----------. 1 root root 63544 2月  22 2013 /usr/libexec/openssh/sftp-server

正常情况应该是这样：

# ll /usr/libexec/openssh/sftp-server

-rwxr-xr-x. 1 root root 63544 Nov 23  2013 /usr/libexec/openssh/sftp-server

咨询大师说 停止openssh 服务 rm sftp-server文件  正常的scp 过去 再启动openssh

但是我是远程操作，生产系统，不敢停止openssh服务，万一连不上就瓜了，大师建议那就先这样用着。

Note：/usr/libexec/openssh/sftp-server没任何权限，root用户都没法删除修改。