ssh沉思录

作者: 小生境 | 来源:发表于2016-11-13 17:23 被阅读1239次

    我从来没有想过我会在栽倒在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
    

    恩就是这样。

    相关文章

      网友评论

        本文标题:ssh沉思录

        本文链接:https://www.haomeiwen.com/subject/roycpttx.html