我从来没有想过我会在栽倒在ssh上。
在CentOS6.5上部署Hadoop集群,居然用了一下午都没建立起ssh互通。
我扭过头对旁边实施的同事说,最可怕的就是这种从来没有出过问题的步骤以一种不可思议的角度树了一面高墙在我面前,颠覆你所学习的所有知识储备。
不管怎么说,通过一晚上的功课,恶补了很多知识,最后还是解决了问题。
那么我们从日志开始:
(P.S. 以下代码皆运行在macOS的VirtualBox上的CentOS6.8 Minimal上)
1. ssh日志
总之重点就是以下这句代码了:
ssh username@host -vvv
v的数量可以理解为调试日志信息的详细程序,最多为Debug3(-vvv)。
当然既然我们在调试ssh免密登录,不妨再增加一个选项:
ssh username@host -vvv -oPreferredAuthentications=publickey
-oPreferredAuthentications=publickey会让ssh只使用publickey方式去验证,若失败就直接跳过密码登录。
比如我们尝试通过以太网自己登录自己:
ssh 192.168.1.117 -oPreferredAuthentications=publickey -vvv
终端打印出以下信息:
OpenSSH_5.3p1, OpenSSL 1.0.1e-fips 11 Feb 2013
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to 192.168.1.117 [192.168.1.117] port 22.
debug1: Connection established.
debug1: permanently_set_uid: 0/0
debug1: identity file /root/.ssh/identity type -1
debug1: identity file /root/.ssh/identity-cert type -1
debug1: identity file /root/.ssh/id_rsa type -1
debug1: identity file /root/.ssh/id_rsa-cert type -1
debug1: identity file /root/.ssh/id_dsa type -1
debug1: identity file /root/.ssh/id_dsa-cert type -1
debug1: identity file /root/.ssh/id_ecdsa type -1
debug1: identity file /root/.ssh/id_ecdsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.3
debug1: match: OpenSSH_5.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug3: Wrote 960 bytes for a total of 981
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa-cert-v01@openssh.com,ssh-dss-cert-v01@openssh.com,ssh-rsa-cert-v00@openssh.com,ssh-dss-cert-v00@openssh.com,ssh-rsa,ssh-dss
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
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
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
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
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,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-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
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
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
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
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
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug3: Wrote 24 bytes for a total of 1005
debug2: dh_gen_key: priv key bits set: 115/256
debug2: bits set: 495/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: Wrote 144 bytes for a total of 1149
debug3: check_host_in_hostfile: host 192.168.1.117 filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: host 192.168.1.117 filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 1
debug1: Host '192.168.1.117' is known and matches the RSA host key.
debug1: Found key in /root/.ssh/known_hosts:1
debug2: bits set: 527/1024
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: Wrote 16 bytes for a total of 1165
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug3: Wrote 48 bytes for a total of 1213
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /root/.ssh/identity ((nil))
debug2: key: /root/.ssh/id_rsa ((nil))
debug2: key: /root/.ssh/id_dsa ((nil))
debug2: key: /root/.ssh/id_ecdsa ((nil))
debug3: Wrote 64 bytes for a total of 1277
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
debug3: start over, passed a different list publickey,gssapi-keyex,gssapi-with-mic,password
debug3: preferred publickey
debug3: authmethod_lookup publickey
debug3: remaining preferred:
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /root/.ssh/identity
debug3: no such identity: /root/.ssh/identity
debug1: Trying private key: /root/.ssh/id_rsa
debug3: no such identity: /root/.ssh/id_rsa
debug1: Trying private key: /root/.ssh/id_dsa
debug3: no such identity: /root/.ssh/id_dsa
debug1: Trying private key: /root/.ssh/id_ecdsa
debug3: no such identity: /root/.ssh/id_ecdsa
debug2: we did not send a packet, disable method
debug1: No more authentication methods to try.
Permission denied (publickey,gssapi-keyex,gssapi-with-mic,password).
不要怕,ssh调试信息直接倒着读,从Next authentication method: publickey这一行开始就是使用publickey方法来验证,调试信息说得还是比较清楚的:
debug1: Trying private key: /root/.ssh/id_rsa
debug3: no such identity: /root/.ssh/id_rsa
因为使用publickey登录,需要客户端将自己的id_rsa发送过去,而现在找不到这个文件,肯定过不了啊。
不过很多时候建立互通的时候,问题不是出在客户端而是在服务端,这时候肯定就要检查sshd的日志了。
2. sshd日志
sshd的日志放在/var/log/secure里,不过其调试信息是非常简陋的,先修改其LogLevel再说:把/etc/ssh/sshd_config里的
#LogLevel INFO
改成
LogLevel Debug3
再重启sshd服务就可以了:
service sshd restart
比如说,假如我有把本机的id_rsa.pub塞到自己的~/.ssh/authorized_keys里了,但是我把authorized_keys的权限设置为777了:
ssh-keygen -t rsa -P ''
cd ~/.ssh
cat id_rsa.pub >> authorized_keys
chmod 777 authorized_keys
结果无法免密登录了,从ssh的调试信息来看只是说了一句:
debug2: we did not send a packet, disable method
这时候就只有看/var/log/secure了:
Nov 13 02:59:59 localhost sshd[1542]: debug3: fd 5 is not O_NONBLOCK
Nov 13 02:59:59 localhost sshd[1542]: debug1: Forked child 1575.
Nov 13 02:59:59 localhost sshd[1542]: debug3: send_rexec_state: entering fd = 8 config len 578
Nov 13 02:59:59 localhost sshd[1542]: debug3: ssh_msg_send: type 0
Nov 13 02:59:59 localhost sshd[1542]: debug3: send_rexec_state: done
Nov 13 02:59:59 localhost sshd[1575]: debug3: oom_adjust_restore
Nov 13 02:59:59 localhost sshd[1575]: Set /proc/self/oom_score_adj to 0
Nov 13 02:59:59 localhost sshd[1575]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 632 bytes for a total of 52213
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 52333
Nov 13 02:59:59 localhost sshd[1575]: debug1: inetd sockets after dupping: 3, 3
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 200 bytes for a total of 52533
Nov 13 02:59:59 localhost sshd[1575]: Connection from 192.168.1.117 port 45342
Nov 13 02:59:59 localhost sshd[1575]: debug1: Client protocol version 2.0; client software version OpenSSH_5.3
Nov 13 02:59:59 localhost sshd[1575]: debug1: match: OpenSSH_5.3 pat OpenSSH*
Nov 13 02:59:59 localhost sshd[1575]: debug1: Enabling compatibility mode for protocol 2.0
Nov 13 02:59:59 localhost sshd[1575]: debug1: Local version string SSH-2.0-OpenSSH_5.3
Nov 13 02:59:59 localhost sshd[1575]: debug2: fd 3 setting O_NONBLOCK
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 632 bytes for a total of 53165
Nov 13 02:59:59 localhost sshd[1575]: debug2: Network child is on pid 1576
Nov 13 02:59:59 localhost sshd[1575]: debug3: preauth child monitor started
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 344 bytes for a total of 53509
Nov 13 02:59:59 localhost sshd[1576]: debug3: privsep user:group 74:74
Nov 13 02:59:59 localhost sshd[1576]: debug1: permanently_set_uid: 74/74
Nov 13 02:59:59 localhost sshd[1576]: debug1: list_hostkey_types: ssh-rsa,ssh-dss
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_KEXINIT sent
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 408 bytes for a total of 53917
Nov 13 02:59:59 localhost sshd[1576]: debug3: Wrote 840 bytes for a total of 861
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_KEXINIT received
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 1192 bytes for a total of 55109
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55229
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55349
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55469
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55589
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55709
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55829
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 55949
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 56069
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 56189
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: none,zlib@openssh.com
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: none,zlib@openssh.com
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit:
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit:
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: first_kex_follows 0
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: reserved 0
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: ssh-rsa-cert-v01@openssh.com,ssh-dss-cert-v01@openssh.com,ssh-rsa-cert-v00@openssh.com,ssh-dss-cert-v00@openssh.com,ssh-rsa,ssh-dss
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: 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
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit:
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 2024 bytes for a total of 58213
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit:
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: first_kex_follows 0
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_parse_kexinit: reserved 0
Nov 13 02:59:59 localhost sshd[1576]: debug2: mac_setup: found hmac-md5
Nov 13 02:59:59 localhost sshd[1576]: debug1: kex: client->server aes128-ctr hmac-md5 none
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 78
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 78
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 79
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 79
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug2: mac_setup: found hmac-md5
Nov 13 02:59:59 localhost sshd[1576]: debug1: kex: server->client aes128-ctr hmac-md5 none
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 78
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 78
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 79
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 79
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 0
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 0
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_moduli: got parameters: 1024 1024 8192
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 1
Nov 13 02:59:59 localhost sshd[1575]: debug2: monitor_read: 0 used once, disabling now
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_choose_dh: waiting for MONITOR_ANS_MODULI
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 1
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_choose_dh: remaining 0
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
Nov 13 02:59:59 localhost sshd[1576]: debug3: Wrote 152 bytes for a total of 1013
Nov 13 02:59:59 localhost sshd[1576]: debug2: dh_gen_key: priv key bits set: 137/256
Nov 13 02:59:59 localhost sshd[1576]: debug2: bits set: 492/1024
Nov 13 02:59:59 localhost sshd[1576]: debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
Nov 13 02:59:59 localhost sshd[1576]: debug2: bits set: 500/1024
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_key_sign entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 5
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 5
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_sign
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_sign: signature 0x7fa5c9c3afd0(271)
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 6
Nov 13 02:59:59 localhost sshd[1575]: debug2: monitor_read: 5 used once, disabling now
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 6
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
Nov 13 02:59:59 localhost sshd[1576]: debug2: kex_derive_keys
Nov 13 02:59:59 localhost sshd[1576]: debug2: set_newkeys: mode 1
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_NEWKEYS sent
Nov 13 02:59:59 localhost sshd[1576]: debug1: expecting SSH2_MSG_NEWKEYS
Nov 13 02:59:59 localhost sshd[1576]: debug3: Wrote 720 bytes for a total of 1733
Nov 13 02:59:59 localhost sshd[1576]: debug2: set_newkeys: mode 0
Nov 13 02:59:59 localhost sshd[1576]: debug1: SSH2_MSG_NEWKEYS received
Nov 13 02:59:59 localhost sshd[1576]: debug1: KEX done
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 280 bytes for a total of 58493
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 4104 bytes for a total of 62597
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 536 bytes for a total of 63133
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63253
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63373
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63493
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63613
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63733
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63853
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 63973
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64093
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64213
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64333
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64453
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64573
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64693
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64813
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 64933
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65053
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65173
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65293
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65413
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65533
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65653
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65773
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 65893
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66013
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66133
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66253
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66373
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66493
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66613
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66733
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66853
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 66973
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67093
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67213
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67333
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67453
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67573
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67693
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67813
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 67933
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68053
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68173
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68293
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68413
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68533
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68653
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68773
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 68893
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69013
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69133
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69253
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69373
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69493
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69613
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69733
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69853
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 69973
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70093
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70213
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70333
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70453
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70573
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70693
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70813
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 70933
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71053
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71173
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71293
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71413
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71533
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71653
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71773
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 71893
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72013
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72133
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72253
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72373
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72493
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72613
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72733
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72853
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 72973
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73093
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73213
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73333
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73453
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73573
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73693
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73813
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 73933
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74053
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74173
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74293
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74413
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74533
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74653
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74773
Nov 13 02:59:59 localhost sshd[1558]: debug2: channel 0: rcvd adjust 49391
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 74893
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 200 bytes for a total of 75093
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75213
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75333
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75453
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75573
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75693
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75813
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 75933
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76053
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76173
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76293
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76413
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76533
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76653
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76773
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 76893
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77013
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77133
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77253
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77373
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77493
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77613
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77733
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77853
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 77973
Nov 13 02:59:59 localhost sshd[1576]: debug3: Wrote 48 bytes for a total of 1781
Nov 13 02:59:59 localhost sshd[1576]: debug1: userauth-request for user root service ssh-connection method none
Nov 13 02:59:59 localhost sshd[1576]: debug1: attempt 0 failures 0
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_getpwnamallow entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 7
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 8
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 7
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_pwnamallow
Nov 13 02:59:59 localhost sshd[1575]: debug3: Trying to reverse map address 192.168.1.117.
Nov 13 02:59:59 localhost sshd[1575]: debug2: parse_server_config: config reprocess config len 578
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 8
Nov 13 02:59:59 localhost sshd[1576]: debug2: input_userauth_request: setting up authctxt for root
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_start_pam entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 50
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_inform_authserv entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 3
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_inform_authrole entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 4
Nov 13 02:59:59 localhost sshd[1576]: debug2: input_userauth_request: try method none
Nov 13 02:59:59 localhost sshd[1576]: debug3: Wrote 80 bytes for a total of 1861
Nov 13 02:59:59 localhost sshd[1576]: debug1: userauth-request for user root service ssh-connection method publickey
Nov 13 02:59:59 localhost sshd[1576]: debug1: attempt 1 failures 0
Nov 13 02:59:59 localhost sshd[1576]: debug2: input_userauth_request: try method publickey
Nov 13 02:59:59 localhost sshd[1576]: debug1: test whether pkalg/pkblob are acceptable
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_key_allowed entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 21
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 22
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 78093
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 78213
Nov 13 02:59:59 localhost sshd[1575]: debug2: monitor_read: 7 used once, disabling now
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 50
Nov 13 02:59:59 localhost sshd[1575]: debug1: PAM: initializing for "root"
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 2824 bytes for a total of 81037
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 440 bytes for a total of 81477
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 81597
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 81717
Nov 13 02:59:59 localhost sshd[1575]: debug1: PAM: setting PAM_RHOST to "192.168.1.117"
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 81837
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 200 bytes for a total of 82037
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 82157
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 82277
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 82397
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 82517
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 82637
Nov 13 02:59:59 localhost sshd[1575]: debug1: PAM: setting PAM_TTY to "ssh"
Nov 13 02:59:59 localhost sshd[1575]: debug2: monitor_read: 50 used once, disabling now
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 3
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_authserv: service=ssh-connection, style=
Nov 13 02:59:59 localhost sshd[1575]: debug2: monitor_read: 3 used once, disabling now
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 4
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_authrole: role=
Nov 13 02:59:59 localhost sshd[1575]: debug2: monitor_read: 4 used once, disabling now
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 21
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_keyallowed entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_keyallowed: key_from_blob: 0x7fa5c9c4cc70
Nov 13 02:59:59 localhost sshd[1575]: debug1: temporarily_use_uid: 0/0 (e=0/0)
Nov 13 02:59:59 localhost sshd[1575]: debug1: trying public key file /root/.ssh/authorized_keys
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 82757
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 1016 bytes for a total of 83773
Nov 13 02:59:59 localhost sshd[1575]: debug1: fd 4 clearing O_NONBLOCK
Nov 13 02:59:59 localhost sshd[1575]: Authentication refused: bad ownership or modes for file /root/.ssh/authorized_keys
Nov 13 02:59:59 localhost sshd[1575]: debug1: restore_uid: 0/0
Nov 13 02:59:59 localhost sshd[1575]: debug1: temporarily_use_uid: 0/0 (e=0/0)
Nov 13 02:59:59 localhost sshd[1575]: debug1: trying public key file /root/.ssh/authorized_keys2
Nov 13 02:59:59 localhost sshd[1575]: debug1: Could not open authorized keys '/root/.ssh/authorized_keys2': No such file or directory
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 552 bytes for a total of 84325
Nov 13 02:59:59 localhost sshd[1575]: debug1: restore_uid: 0/0
Nov 13 02:59:59 localhost sshd[1575]: Failed publickey for root from 192.168.1.117 port 45342 ssh2
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_answer_keyallowed: key 0x7fa5c9c4cc70 is not allowed
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 22
Nov 13 02:59:59 localhost sshd[1576]: debug2: userauth_pubkey: authenticated 0 pkalg ssh-rsa
Nov 13 02:59:59 localhost sshd[1576]: debug3: Wrote 80 bytes for a total of 1941
Nov 13 02:59:59 localhost sshd[1576]: Connection closed by 192.168.1.117
Nov 13 02:59:59 localhost sshd[1576]: debug1: do_cleanup
Nov 13 02:59:59 localhost sshd[1576]: debug3: PAM: sshpam_thread_cleanup entering
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_send entering: type 80
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive_expect entering: type 81
Nov 13 02:59:59 localhost sshd[1576]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 696 bytes for a total of 85021
Nov 13 02:59:59 localhost sshd[1575]: debug3: monitor_read: checking request 80
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_send entering: type 81
Nov 13 02:59:59 localhost sshd[1575]: debug3: mm_request_receive entering
Nov 13 02:59:59 localhost sshd[1575]: debug1: do_cleanup
Nov 13 02:59:59 localhost sshd[1575]: debug1: PAM: cleanup
Nov 13 02:59:59 localhost sshd[1558]: debug3: Wrote 1176 bytes for a total of 86197
Nov 13 02:59:59 localhost sshd[1575]: debug3: PAM: sshpam_thread_cleanup entering
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 472 bytes for a total of 86669
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 200 bytes for a total of 86869
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 86989
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87109
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87229
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87349
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87469
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87589
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87709
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87829
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 87949
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88069
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88189
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88309
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88429
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88549
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88669
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88789
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 88909
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89029
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89149
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89269
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89389
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89509
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89629
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89749
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89869
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 89989
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90109
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90229
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90349
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90469
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90589
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90709
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90829
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 90949
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 91069
Nov 13 03:00:00 localhost sshd[1558]: debug3: Wrote 120 bytes for a total of 91189
不要慌,只要搜一下关键词authorized_keys,马上就能定位到这句话:
Authentication refused: bad ownership or modes for file /root/.ssh/authorized_keys
嘛,所以说这是权限给的太过的原因了,只要把authorized_keys和~/.ssh分别设为600和700权限就可以了。
或者把/etc/ssh/sshd_config里的StrictModes设为no也可以work:
sed -i -e '/StrictModes/s/yes/no/' -e '/StrictModes/s/^#//' /etc/ssh/sshd_config
3. SELinux日志
通常来说,我们通过sshd在Debug3级别下的调试信息能够得到足够多的信息来make correction,但是也有匪夷所思的报错,如:
Could not open authorized keys '/root/.ssh/authorized_keys': Permission denied
但是我回头看.ssh目录和其下的文件权限,都是不多不少的,owner和group也是没有任何问题,sshd进程也是root启动的。
这时候就要开始怀疑是SELinux大法在装怪了,先去看看其日志,在/var/log/audit/audit.log里:
type=CRYPTO_SESSION msg=audit(1479024700.380:216): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from-client cipher=aes128-ctr ksize=128 spid=1648 suid=74 rport=45345 laddr=192.168.1.117 lport=22 exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=? res=success'
type=CRYPTO_SESSION msg=audit(1479024700.380:217): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from-server cipher=aes128-ctr ksize=128 spid=1648 suid=74 rport=45345 laddr=192.168.1.117 lport=22 exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=? res=success'
type=AVC msg=audit(1479024700.435:218): avc: denied { read } for pid=1647 comm="sshd" name="authorized_keys" dev=dm-0 ino=136979 scontext=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:admin_home_t:s0 tclass=file
type=SYSCALL msg=audit(1479024700.435:218): arch=c000003e syscall=2 success=no exit=-13 a0=7fb235b68280 a1=800 a2=1 a3=4000 items=0 ppid=1641 pid=1647 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4 comm="sshd" exe="/usr/sbin/sshd" subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 key=(null)
type=USER_AUTH msg=audit(1479024700.435:219): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=pubkey acct="root" exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=ssh res=failed'
type=CRYPTO_KEY_USER msg=audit(1479024700.439:220): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=session fp=? direction=both spid=1648 suid=74 rport=45345 laddr=192.168.1.117 lport=22 exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=? res=success'
type=USER_ERR msg=audit(1479024700.440:221): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=PAM:bad_ident acct="?" exe="/usr/sbin/sshd" hostname=192.168.1.117 addr=192.168.1.117 terminal=ssh res=failed'
type=CRYPTO_KEY_USER msg=audit(1479024700.440:222): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=eb:a4:b2:14:58:6a:b7:87:64:67:45:7f:a2:e4:5a:24 direction=? spid=1647 suid=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=? res=success'
type=CRYPTO_KEY_USER msg=audit(1479024700.440:223): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=87:ba:f7:65:c4:fa:63:de:c4:88:2a:6f:be:85:3e:f7 direction=? spid=1647 suid=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=? res=success'
type=USER_LOGIN msg=audit(1479024700.440:224): user pid=1647 uid=0 auid=0 ses=4 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login acct="root" exe="/usr/sbin/sshd" hostname=? addr=192.168.1.117 terminal=ssh res=failed'
不要慌,还是搜关键词authorized_keys,马上就能定位到:
type=AVC msg=audit(1479024700.435:218): avc: denied { read } for pid=1647 comm="sshd" name="authorized_keys" dev=dm-0 ino=136979 scontext=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:admin_home_t:s0 tclass=file
噫,authorized_keys文件的context居然是unconfined_u:object_r:admin_home_t:s0,难道type不应该是ssh_home_t吗,先restorecon试试:
restorecon ~/.ssh ~/.ssh/authorized_keys
在看看context:
ll -Za ~/.ssh/
嗯这次的type都是ssh_home_t了。
再ssh试试,卧槽,可以了。
4. 大规模集群的ssh互通
嘛,如果是三四台机器建立ssh互通,可能我手写几个循环,相互scp一下id_rsa.pub还是可以忍受的。不过如果有10台,20台机器呢?
答案当然是用ansible啊,只要编写好host文件,剩下的都是很简单的:
# hosts
hostname1 ansible_ssh_host=192.168.0.1 ansible_ssh_user=root ansible_ssh_pass=my_password1
hostname2 ansible_ssh_host=192.168.0.2 ansible_ssh_user=root ansible_ssh_pass=my_password2
hostname3 ansible_ssh_host=192.168.0.3 ansible_ssh_user=root ansible_ssh_pass=my_password3
然后是task脚本:
# task.yml
- name: build connections between each host
hosts: all
tasks:
- name: generate root id_rsa in each
user: >
name=root
generate_ssh_key=yes
- name: fetch id_rsa.pub from all to local
fetch: >
src=/root/.ssh/id_rsa.pub
dest=/tmp/ssh_files
- name: concat authorized_keys in local
shell: >
cat {{ item }}
>> /tmp/ssh_files/authorized_keys
with_fileglob:
- /tmp/ssh_files/*/root/.ssh/id_rsa.pub
delegate_to: 127.0.0.1
run_once: true
- name: distribute authorized_keys to all
lineinfile: >
dest=/root/.ssh/authorized_keys
line={{ lookup('file', '/tmp/ssh_files/authorized_keys') }}
create=yes
- name: chmod authorized_keys
file: >
path=/root/.ssh/authorized_keys
mode=0600
- name: chmod .ssh
file: >
path=/root/.ssh
mode=0755
with_items
- name: delete tempfiles
file: >
path=/tmp/ssh_files
state=absent
run_once: true
- name: update known_hosts
shell: ssh-keyscan -H {{ item[0] }} >> {{ item[1] }}/.ssh/known_hosts
with_nested:
- "{{ groups.all }}"
- '/root'
- name: restorecon context
shell: restorecon {{ item }}
with_items:
- "/root/.ssh"
- "/root/.ssh/authorized_keys"
使用的时候也很简单,直接指定hosts文件运行task.yml就可以了:
ansible -i host task.yml
恩就是这样。
网友评论