Регулярно тормозит ssh (вопрос к залу)
Dec. 15th, 2019 01:40 am![[personal profile]](https://www.dreamwidth.org/img/silk/identity/user.png){kind=small}
phd_ruКоллеги. Тормозит
Тормозит не всегда; это случается раз в несколько дней, продолжается час-полтора, потом работает нормально. В разное время; бывает в 7 вечера, а сегодня около полуночи началось. Тормозит
Трасса от меня до сервера:
Сервер не загружен работой (и тормозят одновременно два независимых сервера в разных частях мира):
Что это? Где искать проблему? Я перевесил
ssh:$ time ssh oper.med.ru echo test test real 7m32.477s user 0m0.016s sys 0m0.008s
Тормозит не всегда; это случается раз в несколько дней, продолжается час-полтора, потом работает нормально. В разное время; бывает в 7 вечера, а сегодня около полуночи началось. Тормозит
ssh на 2 моих внешних сервера (а у меня их 2 и есть); внутри квартиры всё работает нормально. Тормозит только ssh, остальные протоколы работают без проблем. Торможение возникает в середине протокола: $ ssh -vvv oper.med.ru echo test OpenSSH_7.4p1 Debian-10+deb9u7, OpenSSL 1.0.2t 10 Sep 2019 debug1: Reading configuration data /home/phd/.ssh/config debug3: kex names ok: [diffie-hellman-group1-sha1] debug3: kex names ok: [diffie-hellman-group1-sha1] debug1: /home/phd/.ssh/config line 65: Applying options for * debug1: Reading configuration data /etc/ssh/ssh_config debug1: /etc/ssh/ssh_config line 19: Applying options for * debug1: Control socket "/home/phd/.ssh/controls/phd@oper.med.ru:22" does not exist debug2: resolving "oper.med.ru" port 22 debug2: ssh_connect_direct: needpriv 0 debug1: Connecting to oper.med.ru [62.231.1.75] port 22. debug1: Connection established. debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_rsa type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_rsa-cert type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_dsa type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_dsa-cert type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_ecdsa type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_ecdsa-cert type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_ed25519 type -1 debug1: key_load_public: No such file or directory debug1: identity file /home/phd/.ssh/id_ed25519-cert type -1 debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_7.4p1 Debian-10+deb9u7 debug1: Remote protocol version 2.0, remote software version OpenSSH_7.9p1 Debian-10+deb10u1 debug1: match: OpenSSH_7.9p1 Debian-10+deb10u1 pat OpenSSH* compat 0x04000000 debug2: fd 3 setting O_NONBLOCK debug1: Authenticating to oper.med.ru:22 as 'phd' debug3: hostkeys_foreach: reading file "/home/phd/.ssh/known_hosts" debug3: record_hostkey: found key type RSA in file /home/phd/.ssh/known_hosts:53 debug3: record_hostkey: found key type ECDSA in file /home/phd/.ssh/known_hosts:55 debug3: record_hostkey: found key type ED25519 in file /home/phd/.ssh/known_hosts:57 debug3: load_hostkeys: loaded 3 keys from oper.med.ru debug3: order_hostkeyalgs: prefer hostkeyalgs: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa debug3: send packet: type 20 debug1: SSH2_MSG_KEXINIT sent debug3: receive packet: type 20 debug1: SSH2_MSG_KEXINIT received debug2: local client KEXINIT proposal debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,ext-info-c debug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa debug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc debug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc debug2: MACs ctos: hmac-sha1,umac-64@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1-96 debug2: MACs stoc: hmac-sha1,umac-64@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1-96 debug2: compression ctos: none,zlib@openssh.com,zlib debug2: compression stoc: none,zlib@openssh.com,zlib debug2: languages ctos: debug2: languages stoc: debug2: first_kex_follows 0 debug2: reserved 0 debug2: peer server KEXINIT proposal debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1 debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 debug2: ciphers ctos: aes128-ctr,aes256-ctr,aes128-cbc,aes256-cbc debug2: ciphers stoc: aes128-ctr,aes256-ctr,aes128-cbc,aes256-cbc debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 debug2: compression ctos: none,zlib@openssh.com debug2: compression stoc: none,zlib@openssh.com debug2: languages ctos: debug2: languages stoc: debug2: first_kex_follows 0 debug2: reserved 0 debug1: kex: algorithm: curve25519-sha256 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha1 compression: none debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha1 compression: none debug3: send packet: type 30 debug1: expecting SSH2_MSG_KEX_ECDH_REPLY debug3: receive packet: type 31 debug1: Server host key: ecdsa-sha2-nistp256 SHA256:8hBLooqO3bRdB8B5qdKHS/KOfEId2ysF2KM/q97QkeI debug3: hostkeys_foreach: reading file "/home/phd/.ssh/known_hosts" debug3: record_hostkey: found key type RSA in file /home/phd/.ssh/known_hosts:53 debug3: record_hostkey: found key type ECDSA in file /home/phd/.ssh/known_hosts:55 debug3: record_hostkey: found key type ED25519 in file /home/phd/.ssh/known_hosts:57 debug3: load_hostkeys: loaded 3 keys from oper.med.ru debug3: hostkeys_foreach: reading file "/home/phd/.ssh/known_hosts" debug3: record_hostkey: found key type RSA in file /home/phd/.ssh/known_hosts:54 debug3: record_hostkey: found key type ECDSA in file /home/phd/.ssh/known_hosts:56 debug3: record_hostkey: found key type ED25519 in file /home/phd/.ssh/known_hosts:58 debug3: load_hostkeys: loaded 3 keys from 62.231.1.75 debug1: Host 'oper.med.ru' is known and matches the ECDSA host key. debug1: Found key in /home/phd/.ssh/known_hosts:55 debug3: send packet: type 21 debug2: set_newkeys: mode 1 debug1: rekey after 4294967296 blocks debug1: SSH2_MSG_NEWKEYS sent debug1: expecting SSH2_MSG_NEWKEYS debug3: receive packet: type 21 debug1: SSH2_MSG_NEWKEYS received debug2: set_newkeys: mode 0 debug1: rekey after 4294967296 blocks debug2: key: .ssh/phd@nb3 (0x12dd220), agent debug2: key: /home/phd/.ssh/id_rsa ((nil)) debug2: key: /home/phd/.ssh/id_dsa ((nil)) debug2: key: /home/phd/.ssh/id_ecdsa ((nil)) debug2: key: /home/phd/.ssh/id_ed25519 ((nil)) debug3: send packet: type 5 debug3: receive packet: type 7 debug1: SSH2_MSG_EXT_INFO received debug1: kex_input_ext_info: server-sig-algs= debug3: receive packet: type 6 debug2: service_accept: ssh-userauth debug1: SSH2_MSG_SERVICE_ACCEPT received debug3: send packet: type 50 debug3: receive packet: type 51 debug1: Authentications that can continue: publickey,password debug3: start over, passed a different list publickey,password debug3: preferred public-key,publickey,password,keyboard-interactive debug3: authmethod_lookup publickey debug3: remaining preferred: password,keyboard-interactive debug3: authmethod_is_enabled publickey debug1: Next authentication method: publickey debug1: Offering RSA public key: .ssh/phd@nb3 debug3: send_pubkey_test debug3: send packet: type 50 debug2: we sent a publickey packet, wait for reply debug3: receive packet: type 60 debug1: Server accepts key: pkalg rsa-sha2-512 blen 279 debug2: input_userauth_pk_ok: fp SHA256:9Z/tUUOmc85sVIwhyfP1F7PVqnsf7ZjvQIk2D/tUas4 debug3: sign_and_send_pubkey: RSA SHA256:9Z/tUUOmc85sVIwhyfP1F7PVqnsf7ZjvQIk2D/tUas4 debug3: send packet: type 50 debug3: receive packet: type 52 debug1: Authentication succeeded (publickey). Authenticated to oper.med.ru ([62.231.1.75]:22). debug1: channel 0: new [client-session] debug3: ssh_session2_open: channel_new: 0 debug2: channel 0: send open debug3: send packet: type 90 debug1: Requesting no-more-sessions@openssh.com debug3: send packet: type 80 debug1: Entering interactive session. debug1: pledge: network debug3: receive packet: type 80 debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0 debug3: receive packet: type 4 debug1: Remote: /home/phd/.ssh/authorized_keys:2: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding debug3: receive packet: type 4 debug1: Remote: /home/phd/.ssh/authorized_keys:2: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding debug3: receive packet: type 91 debug2: callback start debug2: fd 3 setting TCP_NODELAY debug3: ssh_packet_set_tos: set IP_TOS 0x08 debug2: client_session2_setup: id 0 debug1: Sending environment. debug3: Ignored env GIT_COMMITTER_NAME debug3: Ignored env LESS_TERMCAP_se debug3: Ignored env HISTFILESIZE debug3: Ignored env MAIL debug3: Ignored env USER debug3: Ignored env crt debug3: Ignored env no_proxy debug3: Ignored env LESS_TERMCAP_ue debug3: Ignored env GIT_AUTHOR_EMAIL debug3: Ignored env HOSTFILE debug3: Ignored env HISTIGNORE debug3: Ignored env BROWSER debug3: Ignored env SHLVL debug3: Ignored env LESS debug3: Ignored env HOME debug3: Ignored env LESS_TERMCAP_mr debug3: Ignored env HUSHLOGIN debug3: Ignored env WINDOW_MANAGER debug3: Ignored env PAGER debug3: Ignored env GIT_AUTHOR_NAME debug3: Ignored env LESS_TERMCAP_so debug1: Sending env LC_CTYPE = ru_RU.KOI8-R debug2: channel 0: request env confirm 0 debug3: send packet: type 98 debug3: Ignored env FVWM_USERDIR debug3: Ignored env ENV debug3: Ignored env VISUAL debug3: Ignored env DBUS_SESSION_BUS_ADDRESS debug3: Ignored env FVWM_DATADIR debug3: Ignored env COLORTERM debug3: Ignored env gnupg_SSH_AUTH_SOCK_by debug3: Ignored env auto_proxy debug3: Ignored env HOSTDISPLAY debug3: Ignored env HGUSER debug3: Ignored env LOGNAME debug3: Ignored env GTK_IM_MODULE debug3: Ignored env WINDOWID debug3: Ignored env LESS_TERMCAP_us debug3: Ignored env _ debug3: Ignored env COLORFGBG debug3: Ignored env TERM debug3: Ignored env BLOCKSIZE debug3: Ignored env HISTCONTROL debug3: Ignored env _VIRTUALENVWRAPPER_API debug1: Sending env LC_COLLATE = ru_RU.KOI8-R debug2: channel 0: request env confirm 0 debug3: send packet: type 98 debug3: Ignored env WINDOWPATH debug3: Ignored env PATH debug3: Ignored env LESSCHARSET debug3: Ignored env G_FILENAME_ENCODING debug3: Ignored env DISPLAY debug1: Sending env LANG = C debug2: channel 0: request env confirm 0 debug3: send packet: type 98 debug3: Ignored env PYTHONSTARTUP debug3: Ignored env HISTSIZE debug3: Ignored env LS_COLORS debug3: Ignored env XAUTHORITY debug3: Ignored env SSH_AUTH_SOCK debug3: Ignored env LESSEDIT debug3: Ignored env SHELL debug3: Ignored env FVWM_MODULEDIR debug3: Ignored env MAILPATH debug3: Ignored env FCEDIT debug3: Ignored env LESS_TERMCAP_mb debug3: Ignored env GDK_USE_XFT debug3: Ignored env GIT_COMMITTER_EMAIL debug3: Ignored env LESS_TERMCAP_md debug3: Ignored env VIRTUALENVWRAPPER_SCRIPT debug3: Ignored env QT_IM_MODULE debug3: Ignored env PWD debug3: Ignored env LESS_TERMCAP_me debug3: Ignored env OPS1 debug3: Ignored env HISTFILE debug3: Ignored env LESS_TERMCAP_mh debug3: Ignored env ORGANIZATION debug3: Ignored env BACKGROUND debug3: Ignored env MANPATH debug3: Ignored env EDITOR debug1: Sending command: echo test debug2: channel 0: request exec confirm 1 debug3: send packet: type 98 debug2: callback done debug2: channel 0: open confirm rwindow 0 rmax 32768 ---------- вот здесь происходит затык ---------- debug3: receive packet: type 98 debug1: client_input_channel_req: channel 0 rtype keepalive@openssh.com reply 1 debug3: send packet: type 100 debug3: receive packet: type 98 debug1: client_input_channel_req: channel 0 rtype keepalive@openssh.com reply 1 debug3: send packet: type 100 ---------- 2 keepalive успело пройти, т.е. 2 минуты таймаута ---------- debug2: channel 0: rcvd adjust 2097152 debug3: receive packet: type 99 debug2: channel_input_status_confirm: type 99 id 0 debug2: exec request accepted on channel 0 test debug3: receive packet: type 96 debug2: channel 0: rcvd eof debug2: channel 0: output open -> drain debug2: channel 0: obuf empty debug2: channel 0: close_write debug2: channel 0: output drain -> closed debug3: receive packet: type 98 debug1: client_input_channel_req: channel 0 rtype exit-status reply 0 debug3: receive packet: type 98 debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0 debug2: channel 0: rcvd eow debug2: channel 0: close_read debug2: channel 0: input open -> closed debug3: receive packet: type 97 debug2: channel 0: rcvd close debug3: channel 0: will not send data after close debug2: channel 0: almost dead debug2: channel 0: gc: notify user debug2: channel 0: gc: user detached debug2: channel 0: send close debug3: send packet: type 97 debug2: channel 0: is dead debug2: channel 0: garbage collecting debug1: channel 0: free: client-session, nchannels 1 debug3: channel 0: status: The following connections are open: #0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1) debug3: send packet: type 1 Transferred: sent 2512, received 2896 bytes, in 92.2 seconds Bytes per second: sent 27.3, received 31.4 debug1: Exit status 0
Трасса от меня до сервера:
$ tcptraceroute oper.med.ru 22 Running: traceroute -T -O info -p 22 oper.med.ru traceroute to oper.med.ru (62.231.1.75), 30 hops max, 52 byte packets 1 10.110.23.1 (10.110.23.1) 107.227 ms 107.193 ms 107.168 ms 2 * * * 3 * * * 4 10.110.2.57 (10.110.2.57) 108.614 ms 108.636 ms 108.611 ms 5 10.110.2.62 (10.110.2.62) 108.742 ms 109.224 ms 109.270 ms 6 31.28.19.100 (31.28.19.100) 110.191 ms 107.579 ms 107.559 ms 7 Filanco-lgw.Moscow.gldn.net (194.186.0.249) 108.359 ms 108.423 ms 108.367 ms 8 pe02.Les.Moscow.gldn.net (79.104.235.229) 108.952 ms 109.026 ms 108.925 ms 9 62.231.1.75 (62.231.1.75) 109.394 ms 109.566 ms 114.770 ms
Сервер не загружен работой (и тормозят одновременно два независимых сервера в разных частях мира):
$ ssh oper.med.ru uptime 22:02:27 up 4 days, 4:00, 0 users, load average: 0.19, 0.07, 0.02
Что это? Где искать проблему? Я перевесил
sshd на другой порт — не помогло. Где-то между мной и серверами стоит DPI специально против ssh?
no subject
Date: 2019-12-15 06:39 am (UTC)Это точно не DNS-таймауты на той стороне при попытке разрезолвить твою машину на этой?
В принципе, все мои случаи торможения ssh сводились либо к настройкам DNS на сервере, либо к попыткам авторизации по GSSAPO там где его близко не стояло, либо еще к чему-нибудь подобному, но уже в недрах systemd.
no subject
Date: 2019-12-15 10:27 am (UTC)Я, правда, сомневаюсь. У меня на эти сервера окна с
sshоткрыты целыми днями. Я не уверен, чтоsshрегулярно переспрашивает DNS. И если, как я думаю, не переспрашивает, а торможение возникает после многих часов открытых окон, то дело всё же не в DNS.no subject
Date: 2019-12-15 12:44 pm (UTC)no subject
Date: 2019-12-15 01:39 pm (UTC)sshоткрыты целыми днями. Т.е. ре-коннекта нет по много часов. Т.ч. вряд ли дело в DNS. И вдруг вечером либо я вижу это торможение и закрываю окошки, или они сами отваливаются по таймауту. А примерssh oper.med.ru echo testвыше — это когда я уже споткнулся и закрыл окошки сssh.no subject
Date: 2019-12-15 02:01 pm (UTC)no subject
Date: 2019-12-15 03:06 pm (UTC)tcpdump -wи потомtcpdump -rя уже делал. Видно, что в какой-то момент возникает пауза в пакетах от клиента к серверу.Надо будет синхронизировать время и точно посмотреть, возникает ли эта пауза после того, как пакет ушёл от клиента.
wiresharkможет больше показать, чемtcpdump -r?no subject
Date: 2019-12-15 04:36 pm (UTC)no subject
Date: 2019-12-15 04:45 pm (UTC)