Мои сессии SSH занимают очень много времени, чтобы начать. Это относится к входам в систему с паролями и без них, интерактивным и неинтерактивным. Я попытался установить «GSSAPIAuthentication no» и «IPQoS 0x00» на стороне клиента, а также «UseDNS no» на стороне сервера, но без кубиков. Я действительно озадачен и расстроен. Хуже всего то, что SFTP тоже требует вечности для установления соединений, что делает передачу файлов намного дольше, чем это было бы в противном случае.
Я подумал, что проблема может быть связана с PAM, из-за того, что зависание находится в журнале sshd ниже, поэтому я попытался закомментировать каждую строку по одной в файле /etc/pam.d/sshd. Некоторые из них вызывали невозможность входа в систему, некоторые не имели видимого эффекта. Я не могу точно сказать, останавливается ли PAM для других служб, но я могу сказать, что зачисление на мою учетную запись с другой учетной записи с «su -l» не имеет явной задержки. Я попытался создать новую учетную запись пользователя, просто чтобы увидеть, не было ли что-то не так с моей существующей учетной записью, и та же проблема сохранилась. Есть идеи о том, что происходит?
На стороне клиента выводится наиболее подробный режим (отредактированный там, где это целесообразно):
OpenSSH_5.9p1, OpenSSL 0.9.8r 8 Feb 2011
debug1: Reading configuration data ...
debug1: ... line 1: Applying options for ...
debug1: Reading configuration data /etc/ssh_config
debug1: /etc/ssh_config line 20: Applying options for *
debug1: /etc/ssh_config line 53: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to ... [x.x.x.x] port 22.
debug1: Connection established.
debug1: identity file /.../.ssh/id_rsa type -1
debug1: identity file /.../.ssh/id_rsa-cert type -1
debug3: Incorrect RSA1 identifier
debug3: Could not load "/.../.ssh/id_dsa" as a RSA1 public key
debug1: identity file /.../.ssh/id_dsa type 2
debug1: identity file /.../.ssh/id_dsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.2
debug1: match: OpenSSH_5.2 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.9
debug2: fd 3 setting O_NONBLOCK
debug3: load_hostkeys: loading entries for host "..." from file "/.../.ssh/known_hosts"
debug3: load_hostkeys: found key type RSA in file /.../.ssh/known_hosts:9
debug3: load_hostkeys: loaded 1 keys
debug3: order_hostkeyalgs: prefer hostkeyalgs: ssh-rsa-cert-v01@openssh.com,ssh-rsa-cert-v00@openssh.com,ssh-rsa
debug1: SSH2_MSG_KEXINIT sent
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-rsa-cert-v00@openssh.com,ssh-rsa,ssh-dss-cert-v01@openssh.com,ssh-dss-cert-v00@openssh.com,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-256-96,hmac-sha2-512,hmac-sha2-512-96,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-256-96,hmac-sha2-512,hmac-sha2-512-96,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-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,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
debug2: dh_gen_key: priv key bits set: 136/256
debug2: bits set: 523/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Server host key: RSA ...
debug3: load_hostkeys: loading entries for host "..." from file "/.../.ssh/known_hosts"
debug3: load_hostkeys: found key type RSA in file /.../.ssh/known_hosts:9
debug3: load_hostkeys: loaded 1 keys
debug3: load_hostkeys: loading entries for host "x.x.x.x" from file "/.../.ssh/known_hosts"
debug3: load_hostkeys: found key type RSA in file /.../.ssh/known_hosts:9
debug3: load_hostkeys: loaded 1 keys
debug1: Host '...' is known and matches the RSA host key.
debug1: Found key in /.../.ssh/known_hosts:9
debug2: bits set: 492/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
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /.../.ssh/id_dsa (0x7f8b7b41d6c0)
debug2: key: /.../.ssh/id_rsa (0x0)
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug3: start over, passed a different list publickey,password,keyboard-interactive
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering DSA public key: /.../.ssh/id_dsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-dss blen 434
debug2: input_userauth_pk_ok: fp ...
debug3: sign_and_send_pubkey: DSA ...
debug1: Authentication succeeded (publickey).
Authenticated to ... ([x.x.x.x]:22).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
****** Hangs here ******
debug2: callback start
debug2: client_session2_setup: id 0
debug2: fd 3 setting TCP_NODELAY
debug2: channel 0: request pty-req confirm 1
debug1: Sending environment.
debug3: Ignored env TERM_PROGRAM
debug3: Ignored env SHELL
debug3: Ignored env TERM
debug3: Ignored env TMPDIR
debug3: Ignored env Apple_PubSub_Socket_Render
debug3: Ignored env TERM_PROGRAM_VERSION
debug3: Ignored env TERM_SESSION_ID
debug3: Ignored env USER
debug3: Ignored env COMMAND_MODE
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env Apple_Ubiquity_Message
debug3: Ignored env __CF_USER_TEXT_ENCODING
debug3: Ignored env PATH
debug3: Ignored env MKL_NUM_THREADS
debug3: Ignored env PWD
debug1: Sending env LANG = en_US.UTF-8
debug2: channel 0: request env confirm 0
debug3: Ignored env HOME
debug3: Ignored env SHLVL
debug3: Ignored env DYLD_LIBRARY_PATH
debug3: Ignored env PYTHONPATH
debug3: Ignored env LOGNAME
debug3: Ignored env DISPLAY
debug3: Ignored env SECURITYSESSIONID
debug3: Ignored env _
debug2: channel 0: request shell confirm 1
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel_input_status_confirm: type 99 id 0
debug2: PTY allocation request accepted on channel 0
debug2: channel 0: rcvd adjust 2097152
debug2: channel_input_status_confirm: type 99 id 0
debug2: shell request accepted on channel 0
На стороне сервера выходные данные отладки выглядят так:
Sep 16 18:46:40 ... sshd[31435]: debug1: inetd sockets after dupping: 3, 4
Sep 16 18:46:40 ... sshd[31435]: Connection from x.x.x.x port 52758
Sep 16 18:46:40 ... sshd[31435]: debug1: Current Session ID is 56AC0FB0 / Session Attributes are 00008000
Sep 16 18:46:40 ... sshd[31435]: debug1: Running in inetd mode in a non-root session... assuming inetd created the session for us.
Sep 16 18:46:40 ... sshd[31435]: debug1: Client protocol version 2.0; client software version OpenSSH_5.9
Sep 16 18:46:40 ... sshd[31435]: debug1: match: OpenSSH_5.9 pat OpenSSH*
Sep 16 18:46:40 ... sshd[31435]: debug1: Enabling compatibility mode for protocol 2.0
Sep 16 18:46:40 ... sshd[31435]: debug1: Local version string SSH-2.0-OpenSSH_5.2
Sep 16 18:46:40 ... sshd[31435]: debug1: Checking with Service ACLs for ssh login restrictions
Sep 16 18:46:40 ... sshd[31435]: debug1: call to mbr_user_name_to_uuid with <...> suceeded to retrieve user_uuid
Sep 16 18:46:40 ... sshd[31435]: debug1: Call to mbr_check_service_membership failed with status <0>
Sep 16 18:46:40 ... sshd[31435]: debug1: PAM: initializing for "..."
Sep 16 18:46:40 ... sshd[31435]: debug1: PAM: setting PAM_RHOST to "x.x.x.x"
Sep 16 18:46:40 ... sshd[31435]: Failed none for ... from x.x.x.x port 52758 ssh2
Sep 16 18:46:40 ... sshd[31435]: debug1: temporarily_use_uid: 509/20 (e=0/0)
Sep 16 18:46:40 ... sshd[31435]: debug1: trying public key file /.../.ssh/authorized_keys
Sep 16 18:46:40 ... sshd[31435]: debug1: restore_uid: 0/0
Sep 16 18:46:40 ... sshd[31435]: debug1: temporarily_use_uid: 509/20 (e=0/0)
Sep 16 18:46:40 ... sshd[31435]: debug1: trying public key file /.../.ssh/authorized_keys2
Sep 16 18:46:40 ... sshd[31435]: debug1: fd 5 clearing O_NONBLOCK
Sep 16 18:46:40 ... sshd[31435]: debug1: matching key found: file /.../.ssh/authorized_keys2, line 1
Sep 16 18:46:40 ... sshd[31435]: Found matching DSA key: ...
Sep 16 18:46:40 ... sshd[31435]: debug1: restore_uid: 0/0
Sep 16 18:46:40 ... sshd[31435]: debug1: temporarily_use_uid: 509/20 (e=0/0)
Sep 16 18:46:40 ... sshd[31435]: debug1: trying public key file /.../.ssh/authorized_keys
Sep 16 18:46:40 ... sshd[31435]: debug1: restore_uid: 0/0
Sep 16 18:46:40 ... sshd[31435]: debug1: temporarily_use_uid: 509/20 (e=0/0)
Sep 16 18:46:40 ... sshd[31435]: debug1: trying public key file /.../.ssh/authorized_keys2
Sep 16 18:46:40 ... sshd[31435]: debug1: fd 5 clearing O_NONBLOCK
Sep 16 18:46:40 ... sshd[31435]: debug1: matching key found: file /.../.ssh/authorized_keys2, line 1
Sep 16 18:46:40 ... sshd[31435]: Found matching DSA key: ...
Sep 16 18:46:40 ... sshd[31435]: debug1: restore_uid: 0/0
Sep 16 18:46:40 ... sshd[31435]: debug1: ssh_dss_verify: signature correct
Sep 16 18:46:40 ... sshd[31435]: debug1: do_pam_account: called
Sep 16 18:46:40 ... sshd[31435]: Accepted publickey for ... from x.x.x.x port 52758 ssh2
Sep 16 18:46:40 ... sshd[31435]: debug1: monitor_child_preauth: ... has been authenticated by privileged process
Sep 16 18:46:40 ... sshd[31435]: debug1: PAM: establishing credentials
***** Hangs here *****
Sep 16 18:46:54 ... sshd[31435]: User child is on pid 31654
Sep 16 18:46:54 ... sshd[31654]: debug1: PAM: establishing credentials
Sep 16 18:46:54 ... sshd[31654]: debug1: permanently_set_uid: 509/20
Sep 16 18:46:54 ... sshd[31654]: debug1: Entering interactive session for SSH2.
Sep 16 18:46:54 ... sshd[31654]: debug1: server_init_dispatch_20
Sep 16 18:46:54 ... sshd[31654]: debug1: server_input_channel_open: ctype session rchan 0 win 1048576 max 16384
Sep 16 18:46:54 ... sshd[31654]: debug1: input_session_request
Sep 16 18:46:54 ... sshd[31654]: debug1: channel 0: new [server-session]
Sep 16 18:46:54 ... sshd[31654]: debug1: session_new: session 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_open: channel 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_open: session 0: link with channel 0
Sep 16 18:46:54 ... sshd[31654]: debug1: server_input_channel_open: confirm session
Sep 16 18:46:54 ... sshd[31654]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
Sep 16 18:46:54 ... sshd[31654]: debug1: server_input_channel_req: channel 0 request pty-req reply 1
Sep 16 18:46:54 ... sshd[31654]: debug1: session_by_channel: session 0 channel 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_input_channel_req: session 0 req pty-req
Sep 16 18:46:54 ... sshd[31654]: debug1: Allocating pty.
Sep 16 18:46:54 ... sshd[31435]: debug1: session_new: session 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_pty_req: session 0 alloc /dev/ttys008
Sep 16 18:46:54 ... sshd[31654]: debug1: server_input_channel_req: channel 0 request env reply 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_by_channel: session 0 channel 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_input_channel_req: session 0 req env
Sep 16 18:46:54 ... sshd[31654]: debug1: server_input_channel_req: channel 0 request shell reply 1
Sep 16 18:46:54 ... sshd[31654]: debug1: session_by_channel: session 0 channel 0
Sep 16 18:46:54 ... sshd[31654]: debug1: session_input_channel_req: session 0 req shell
Sep 16 18:46:54 ... sshd[31655]: debug1: Setting controlling tty using TIOCSCTTY.