Hoje mesmo, meu servidor começou a ficar lento no login do ssh quando um terminal não é solicitado. O atraso parece ser aleatório entre 0 e 40 segundos e é reproduzível a cada vez. A parte surpreendente é que, se eu pedir um tty ( -t ), a velocidade é normal.
Aqui está a saída de ssh -tt -vvv user@server echo com registro de data e hora em ms:
0.000 OpenSSH_6.6.1, OpenSSL 1.0.1f 6 Jan 2014
0.000 debug1: Reading configuration data /home/tange/.ssh/config
0.000 debug1: /home/tange/.ssh/config line 1: Applying options for *
0.000 debug1: /home/tange/.ssh/config line 12: Applying options for *.pi
0.000 debug1: /home/tange/.ssh/config line 160: Applying options for *
0.000 debug1: Reading configuration data /etc/ssh/ssh_config
0.000 debug1: /etc/ssh/ssh_config line 19: Applying options for *
0.000 debug2: ssh_connect: needpriv 0
0.000 debug1: Connecting to xxx.pi [7.2.5.7] port 22.
0.027 debug1: Connection established.
0.027 debug3: Incorrect RSA1 identifier
0.027 debug3: Could not load "/home/tange/.ssh/id_rsa" as a RSA1 public key
0.027 debug1: identity file /home/tange/.ssh/id_rsa type 1
0.027 debug1: identity file /home/tange/.ssh/id_rsa-cert type -1
0.027 debug1: identity file /home/tange/.ssh/id_dsa type -1
0.027 debug1: identity file /home/tange/.ssh/id_dsa-cert type -1
0.027 debug1: identity file /home/tange/.ssh/id_ecdsa type -1
0.027 debug1: identity file /home/tange/.ssh/id_ecdsa-cert type -1
0.027 debug1: identity file /home/tange/.ssh/id_ed25519 type -1
0.027 debug1: identity file /home/tange/.ssh/id_ed25519-cert type -1
0.027 debug1: Enabling compatibility mode for protocol 2.0
0.027 debug1: Local version string SSH-2.0-OpenSSH_6.6.1p1 Ubuntu-2ubuntu2
0.066 debug1: Remote protocol version 2.0, remote software version OpenSSH_6.0p1 Debian-4+deb7u2
0.066 debug1: match: OpenSSH_6.0p1 Debian-4+deb7u2 pat OpenSSH* compat 0x04000000
0.066 debug2: fd 3 setting O_NONBLOCK
0.066 debug3: load_hostkeys: loading entries for host "xxx.pi" from file "/home/tange/.ssh/known_hosts"
0.067 debug3: load_hostkeys: found key type ECDSA in file /home/tange/.ssh/known_hosts:150
0.067 debug3: load_hostkeys: loaded 1 keys
0.068 debug3: order_hostkeyalgs: prefer hostkeyalgs: [email protected],[email protected],[email protected],ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
0.068 debug1: SSH2_MSG_KEXINIT sent
0.094 debug1: SSH2_MSG_KEXINIT received
0.094 debug2: kex_parse_kexinit: [email protected],ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
0.094 debug2: kex_parse_kexinit: [email protected],[email protected],[email protected],ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,[email protected],[email protected],[email protected],[email protected],[email protected],ssh-ed25519,ssh-rsa,ssh-dss
0.094 debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,[email protected],[email protected],[email protected],aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,[email protected]
0.095 debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,[email protected],[email protected],[email protected],aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,[email protected]
0.095 debug2: kex_parse_kexinit: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-md5,hmac-sha1,[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,[email protected],hmac-sha1-96,hmac-md5-96
0.095 debug2: kex_parse_kexinit: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-md5,hmac-sha1,[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,[email protected],hmac-sha1-96,hmac-md5-96
0.095 debug2: kex_parse_kexinit: [email protected],zlib,none
0.095 debug2: kex_parse_kexinit: [email protected],zlib,none
0.095 debug2: kex_parse_kexinit:
0.095 debug2: kex_parse_kexinit:
0.095 debug2: kex_parse_kexinit: first_kex_follows 0
0.095 debug2: kex_parse_kexinit: reserved 0
0.095 debug2: kex_parse_kexinit: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
0.095 debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256
0.095 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,[email protected]
0.095 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,[email protected]
0.095 debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,[email protected],hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,[email protected],hmac-sha1-96,hmac-md5-96
0.095 debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,[email protected],hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,[email protected],hmac-sha1-96,hmac-md5-96
0.095 debug2: kex_parse_kexinit: none,[email protected]
0.095 debug2: kex_parse_kexinit: none,[email protected]
0.095 debug2: kex_parse_kexinit:
0.095 debug2: kex_parse_kexinit:
0.095 debug2: kex_parse_kexinit: first_kex_follows 0
0.095 debug2: kex_parse_kexinit: reserved 0
0.095 debug2: mac_setup: setup hmac-md5
0.095 debug1: kex: server->client aes128-ctr hmac-md5 [email protected]
0.095 debug2: mac_setup: setup hmac-md5
0.095 debug1: kex: client->server aes128-ctr hmac-md5 [email protected]
0.095 debug1: sending SSH2_MSG_KEX_ECDH_INIT
0.095 debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
0.153 debug1: Server host key: ECDSA 0c:17:b3:93:f6:47:73:de:33:24:6e:db:bf:67:44:1b
0.153 debug3: load_hostkeys: loading entries for host "xxx.pi" from file "/home/tange/.ssh/known_hosts"
0.153 debug3: load_hostkeys: found key type ECDSA in file /home/tange/.ssh/known_hosts:150
0.153 debug3: load_hostkeys: loaded 1 keys
0.153 debug3: load_hostkeys: loading entries for host "7.2.5.7" from file "/home/tange/.ssh/known_hosts"
0.154 debug3: load_hostkeys: found key type ECDSA in file /home/tange/.ssh/known_hosts:151
0.155 debug3: load_hostkeys: loaded 1 keys
0.155 debug1: Host 'xxx.pi' is known and matches the ECDSA host key.
0.155 debug1: Found key in /home/tange/.ssh/known_hosts:150
0.156 debug1: ssh_ecdsa_verify: signature correct
0.156 debug2: kex_derive_keys
0.156 debug2: set_newkeys: mode 1
0.156 debug1: SSH2_MSG_NEWKEYS sent
0.156 debug1: expecting SSH2_MSG_NEWKEYS
0.156 debug2: set_newkeys: mode 0
0.156 debug1: SSH2_MSG_NEWKEYS received
0.156 debug1: Roaming not allowed by server
0.156 debug1: SSH2_MSG_SERVICE_REQUEST sent
0.306 debug2: service_accept: ssh-userauth
0.306 debug1: SSH2_MSG_SERVICE_ACCEPT received
0.765 debug2: key: /home/tange/.ssh/id_rsa (0x7f9b662d4bb0),
0.765 debug2: key: /home/tange/.ssh/id_rsa_openindiana (0x7f9b662d6a70),
0.765 debug2: key: /home/tange/.ssh/id_tym (0x7f9b662d6540),
0.765 debug2: key: /home/tange/.ssh/id_dsa ((nil)),
0.765 debug2: key: /home/tange/.ssh/id_ecdsa ((nil)),
0.765 debug2: key: /home/tange/.ssh/id_ed25519 ((nil)),
0.924 debug1: Authentications that can continue: publickey,password
0.924 debug3: start over, passed a different list publickey,password
0.924 debug3: preferred publickey,keyboard-interactive,password
0.924 debug3: authmethod_lookup publickey
0.924 debug3: remaining preferred: keyboard-interactive,password
0.924 debug3: authmethod_is_enabled publickey
0.924 debug1: Next authentication method: publickey
0.924 debug1: Offering RSA public key: /home/tange/.ssh/id_rsa
0.924 debug3: send_pubkey_test
0.924 debug2: we sent a publickey packet, wait for reply
0.983 debug1: Server accepts key: pkalg ssh-rsa blen 1047
0.983 debug2: input_userauth_pk_ok: fp e1:95:e3:ff:99:a6:3a:b5:53:5a:54:59:d0:72:94:7f
0.983 debug3: sign_and_send_pubkey: RSA e1:95:e3:ff:99:a6:3a:b5:53:5a:54:59:d0:72:94:7f
1.196 debug1: Enabling compression at level 6.
1.196 debug1: Authentication succeeded (publickey).
1.196 Authenticated to xxx.pi ([7.2.5.7]:22).
1.196 debug2: fd 5 setting O_NONBLOCK
1.196 debug3: fd 6 is O_NONBLOCK
1.197 debug1: channel 0: new [client-session]
1.197 debug3: ssh_session2_open: channel_new: 0
1.197 debug2: channel 0: send open
1.197 debug1: Requesting [email protected]
1.197 debug1: Entering interactive session.
1.230 debug2: callback start
1.230 debug2: fd 3 setting TCP_NODELAY
1.230 debug3: packet_set_tos: set IP_TOS 0x08
1.230 debug2: client_session2_setup: id 0
1.230 debug1: Sending environment.
1.230 debug3: Ignored env XDG_VTNR
1.230 debug3: Ignored env XDG_SESSION_ID
1.230 debug3: Ignored env SSH_AGENT_PID
1.230 debug3: Ignored env CLUTTER_IM_MODULE
1.230 debug3: Ignored env SELINUX_INIT
1.230 debug3: Ignored env DM_CONTROL
1.230 debug3: Ignored env SESSION
1.230 debug3: Ignored env GPG_AGENT_INFO
1.230 debug3: Ignored env GLADE_PIXMAP_PATH
1.230 debug3: Ignored env XDG_MENU_PREFIX
1.230 debug3: Ignored env SHELL
1.230 debug3: Ignored env TERM
1.231 debug3: Ignored env XDM_MANAGED
1.231 debug3: Ignored env SSH_AGENT_LAUNCHER
1.231 debug3: Ignored env KONSOLE_DBUS_SERVICE
1.231 debug3: Ignored env KONSOLE_PROFILE_NAME
1.231 debug3: Ignored env MOZ_NO_REMOTE
1.231 debug3: Ignored env WINDOWID
1.231 debug3: Ignored env UPSTART_SESSION
1.231 debug3: Ignored env PERL_MB_OPT
1.231 debug3: Ignored env SHELL_SESSION_ID
1.231 debug3: Ignored env XTERM_SHELL
1.231 debug3: Ignored env USER
1.231 debug3: Ignored env LS_COLORS
1.231 debug3: Ignored env ORACLE_SID
1.231 debug3: Ignored env DEBEMAIL
1.231 debug3: Ignored env GLADE_MODULE_PATH
1.231 debug3: Ignored env SSH_AUTH_SOCK
1.231 debug3: Ignored env DEFAULTS_PATH
1.231 debug3: Ignored env SESSION_MANAGER
1.231 debug3: Ignored env XDG_CONFIG_DIRS
1.231 debug3: Ignored env PATH
1.231 debug3: Ignored env DESKTOP_SESSION
1.231 debug3: Ignored env _
1.231 debug3: Ignored env QT_IM_MODULE
1.231 debug3: Ignored env PWD
1.231 debug3: Ignored env JOB
1.231 debug3: Ignored env JAVA_HOME
1.231 debug3: Ignored env XMODIFIERS
1.231 debug3: Ignored env KONSOLE_DBUS_WINDOW
1.231 debug1: Sending env LANG = en_US.UTF-8
1.231 debug2: channel 0: request env confirm 0
1.231 debug3: Ignored env MANDATORY_PATH
1.231 debug3: Ignored env IM_CONFIG_PHASE
1.232 debug3: Ignored env KONSOLE_DBUS_SESSION
1.232 debug3: Ignored env XTERM_VERSION
1.232 debug3: Ignored env XTERM_LOCALE
1.232 debug3: Ignored env HISTCONTROL
1.232 debug3: Ignored env SESSIONTYPE
1.232 debug3: Ignored env HOME
1.232 debug3: Ignored env XDG_SEAT
1.232 debug3: Ignored env SHLVL
1.232 debug3: Ignored env COLORFGBG
1.232 debug3: Ignored env JDK_HOME
1.232 debug3: Ignored env LANGUAGE
1.232 debug3: Ignored env UPSTART_INSTANCE
1.232 debug3: Ignored env LOGNAME
1.232 debug3: Ignored env LESS
1.232 debug3: Ignored env UPSTART_EVENTS
1.232 debug3: Ignored env VISUAL
1.232 debug3: Ignored env XDG_DATA_DIRS
1.232 debug3: Ignored env DBUS_SESSION_BUS_ADDRESS
1.232 debug3: Ignored env QT4_IM_MODULE
1.232 debug3: Ignored env DEBFULLNAME
1.232 debug3: Ignored env LESSOPEN
1.232 debug3: Ignored env TEXTDOMAIN
1.232 debug3: Ignored env WINDOWPATH
1.232 debug3: Ignored env UPSTART_JOB
1.232 debug3: Ignored env INSTANCE
1.232 debug3: Ignored env DISPLAY
1.232 debug3: Ignored env XDG_RUNTIME_DIR
1.232 debug3: Ignored env PROFILEHOME
1.232 debug3: Ignored env GLADE_CATALOG_PATH
1.232 debug3: Ignored env ORACLE_HOME
1.232 debug3: Ignored env GTK_IM_MODULE
1.232 debug3: Ignored env XDG_CURRENT_DESKTOP
1.233 debug3: Ignored env LESSCLOSE
1.233 debug3: Ignored env PERL_MM_OPT
1.233 debug3: Ignored env TEXTDOMAINDIR
1.233 debug3: Ignored env BASH_FUNC_myfunc%%
1.233 debug1: Sending command: echo
1.233 debug2: channel 0: request exec confirm 1
1.233 debug2: callback done
1.233 debug2: channel 0: open confirm rwindow 0 rmax 32768
11.076 debug2: channel 0: rcvd adjust 2097152
11.076 debug2: channel_input_status_confirm: type 99 id 0
11.076 debug2: exec request accepted on channel 0
11.076 debug2: channel 0: rcvd eof
11.076 debug2: channel 0: output open -> drain
11.076 debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
11.076 debug1: client_input_channel_req: channel 0 rtype [email protected] reply 0
11.076 debug2: channel 0: rcvd eow
11.076 debug2: channel 0: close_read
11.076 debug2: channel 0: input open -> closed
11.076 debug2: channel 0: rcvd close
11.076 debug3: channel 0: will not send data after close
11.077
11.077 debug3: channel 0: will not send data after close
11.077 debug2: channel 0: obuf empty
11.077 debug2: channel 0: close_write
11.077 debug2: channel 0: output drain -> closed
11.077 debug2: channel 0: almost dead
11.077 debug2: channel 0: gc: notify user
11.077 debug2: channel 0: gc: user detached
11.077 debug2: channel 0: send close
11.077 debug2: channel 0: is dead
11.077 debug2: channel 0: garbage collecting
11.077 debug1: channel 0: free: client-session, nchannels 1
11.077 debug3: channel 0: status: The following connections are open:
11.077 #0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)
11.077
11.077 debug1: fd 1 clearing O_NONBLOCK
11.077 debug3: fd 2 is not O_NONBLOCK
11.077 Transferred: sent 5648, received 2656 bytes, in 9.9 seconds
11.077 Bytes per second: sent 571.7, received 268.8
11.077 debug1: Exit status 0
11.077 debug1: compress outgoing: raw data 154, compressed 134, factor 0.87
11.077 debug1: compress incoming: raw data 101, compressed 81, factor 0.80
Alguma idéia de por que isso acontece de repente? E por que -t não é afetado?
Tags ssh