[Sysadmins] Почему ssh не работает сразу после загрузки?

[Eugene Prokopiev]

Здравствуйте!

Сразу после загрузки машины пытаюсь подключиться к ней по ssh, получаю:

Connection to 192.168.101.181 closed by remote host.
Connection to 192.168.101.181 closed.

В логах ssh:

Mar  5 19:22:28 bercut sshd[2839]: debug1: Forked child 4614.
Mar  5 19:22:28 bercut sshd[4614]: Connection from 192.168.101.104 port 
32778
Mar  5 19:22:28 bercut sshd[4614]: debug1: Client protocol version 2.0; 
client software version OpenSSH_3.6.1p2
Mar  5 19:22:28 bercut sshd[4614]: debug1: match: OpenSSH_3.6.1p2 pat 
OpenSSH*
Mar  5 19:22:28 bercut sshd[4614]: debug1: Enabling compatibility mode 
for protocol 2.0
Mar  5 19:22:28 bercut sshd[4614]: debug1: Local version string 
SSH-1.99-OpenSSH_3.6.1p2
Mar  5 19:22:28 bercut sshd[4615]: debug1: permanently_set_uid: 105/108
Mar  5 19:22:28 bercut sshd[4615]: debug1: list_hostkey_types: 
ssh-rsa,ssh-dss
Mar  5 19:22:28 bercut sshd[4615]: debug1: SSH2_MSG_KEXINIT sent
Mar  5 19:22:28 bercut sshd[4615]: debug1: SSH2_MSG_KEXINIT received
Mar  5 19:22:28 bercut sshd[4615]: debug1: kex: client->server 
blowfish-cbc hmac-md5 none
Mar  5 19:22:28 bercut sshd[4615]: debug1: kex: server->client 
blowfish-cbc hmac-md5 none
Mar  5 19:22:28 bercut sshd[4615]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST 
received
Mar  5 19:22:28 bercut sshd[4615]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
Mar  5 19:22:28 bercut sshd[4615]: debug1: expecting 
SSH2_MSG_KEX_DH_GEX_INIT
Mar  5 19:22:28 bercut sshd[4615]: debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
Mar  5 19:22:28 bercut sshd[4615]: debug1: SSH2_MSG_NEWKEYS sent
Mar  5 19:22:28 bercut sshd[4615]: debug1: expecting SSH2_MSG_NEWKEYS
Mar  5 19:22:35 bercut sshd[4615]: debug1: SSH2_MSG_NEWKEYS received
Mar  5 19:22:36 bercut sshd[4615]: debug1: KEX done
Mar  5 19:22:36 bercut sshd[4615]: debug1: userauth-request for user 
john service ssh-connection method none
Mar  5 19:22:36 bercut sshd[4615]: debug1: attempt 0 failures 0
Mar  5 19:22:36 bercut sshd[4614]: debug1: Starting up PAM with username 
"john"
Mar  5 19:22:36 bercut sshd[4614]: debug1: PAM setting rhost to 
"192.168.101.104"
Mar  5 19:22:36 bercut sshd[4614]: pam_tcb(sshd:auth): Authentication 
failed for john from (uid=0)
Mar  5 19:22:36 bercut sshd[4614]: debug1: PAM password authentication 
failed for john: Authentication failure
Mar  5 19:22:36 bercut sshd[4615]: Failed none for john from 
192.168.101.104 port 32778 ssh2
Mar  5 19:22:38 bercut sshd[4615]: debug1: userauth-request for user 
john service ssh-connection method password
Mar  5 19:22:38 bercut sshd[4615]: debug1: attempt 1 failures 1
Mar  5 19:22:39 bercut sshd[4614]: pam_tcb(sshd:auth): Authentication 
passed for john from (uid=0)
Mar  5 19:22:39 bercut sshd[4614]: debug1: PAM password authentication 
accepted for john
Mar  5 19:22:39 bercut sshd[4615]: Accepted password for john from 
192.168.101.104 port 32778 ssh2
Mar  5 19:22:39 bercut sshd[4614]: debug1: monitor_child_preauth: john 
has been authenticated by privileged process
Mar  5 19:22:39 bercut sshd[4621]: debug1: PAM establishing creds
Mar  5 19:22:39 bercut sshd[4621]: debug1: permanently_set_uid: 500/500
Mar  5 19:22:39 bercut sshd[4621]: debug1: Entering interactive session 
for SSH2.
Mar  5 19:22:39 bercut sshd[4621]: debug1: fd 6 setting O_NONBLOCK
Mar  5 19:22:39 bercut sshd[4621]: debug1: fd 7 setting O_NONBLOCK
Mar  5 19:22:39 bercut sshd[4621]: debug1: server_init_dispatch_20
Mar  5 19:22:39 bercut sshd[4621]: debug1: server_input_channel_open: 
ctype session rchan 0 win 65536 max 16384
Mar  5 19:22:39 bercut sshd[4621]: debug1: input_session_request
Mar  5 19:22:39 bercut sshd[4621]: debug1: channel 0: new [server-session]
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_new: init
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_new: session 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_open: channel 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_open: session 0: link 
with channel 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: server_input_channel_open: 
confirm session
Mar  5 19:22:39 bercut sshd[4621]: debug1: server_input_channel_req: 
channel 0 request pty-req reply 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_by_channel: session 0 
channel 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_input_channel_req: 
session 0 req pty-req
Mar  5 19:22:39 bercut sshd[4621]: debug1: Allocating pty.
Mar  5 19:22:39 bercut sshd[4614]: debug1: session_new: init
Mar  5 19:22:39 bercut sshd[4614]: debug1: session_new: session 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_pty_req: session 0 
alloc /dev/pts/0
Mar  5 19:22:39 bercut sshd[4621]: debug1: server_input_channel_req: 
channel 0 request shell reply 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_by_channel: session 0 
channel 0
Mar  5 19:22:39 bercut sshd[4621]: debug1: session_input_channel_req: 
session 0 req shell
Mar  5 19:22:39 bercut sshd[4621]: debug1: PAM setting tty to "/dev/pts/0"
Mar  5 19:22:39 bercut sshd[4621]: pam_tcb(sshd:session): Session opened 
for john by (uid=500)
Mar  5 19:22:39 bercut sshd[4621]: fatal: PAM session setup failed[6]: 
Permission denied
Mar  5 19:22:39 bercut sshd[4621]: debug1: Calling cleanup 0x806ef20(0x0)
Mar  5 19:22:39 bercut sshd[4621]: debug1: Calling cleanup 
0x8058ed0(0x808c080)
Mar  5 19:22:39 bercut sshd[4621]: debug1: Calling cleanup 0x80673e0(0x0)
Mar  5 19:22:39 bercut sshd[4614]: debug1: session_by_tty: session 0 tty 
/dev/pts/0
Mar  5 19:22:39 bercut sshd[4621]: debug1: channel_free: channel 0: 
server-session, nchannels 1
Mar  5 19:22:39 bercut sshd[4614]: debug1: session_pty_cleanup: session 
0 release /dev/pts/0
Mar  5 19:22:39 bercut sshd[4621]: debug1: Calling cleanup 0x8063610(0x0)
Mar  5 19:22:39 bercut sshd[4614]: debug1: Calling cleanup 0x8063610(0x0)

После рестарта ssh подключаюсь нормально.

В чем может быть дело? Особенно интересует fatal: PAM session setup 
failed[6]: Permission denied, к чему именно denied и отчего он перестает 
быть таковым после рестарта sshd?

Система - не самый свежий Сизиф

-- 
С уважением, Прокопьев Евгений