You are not logged in.

#1 2013-01-02 18:26:27

8472
Member
From: Slovakia
Registered: 2010-05-15
Posts: 83

ssh X11 forwarding takes too long to start any app. remotely

Hi,

I have a bizzare problem with %subject% for some time already.
Affected are all my Arch linux installations (all with: systemd, openbox (without Display Manager), and latest updates):
1. home desktop (core 2 duo, 2.4GHz, 3GB RAM).
2. one testing desktop in virtualbox on the desktop from prev. point.
3. work laptop (Intel Core i5, 4GB RAM).

All of these are connected via cable to the same home network 100MB router (using openwrt on asus wl-500g).

Normal ssh transmissions, like entering commands, or transfer of data via scp (even large amount of data for testing purposes because of this) works quick like expected.

The problem is, that if I try to start app. remotely via ssh X forwarding from and to any of these (affected also bidirectional), it takes always aprox. 2 minutes to start the app.
Afterwards, it works fast and fine.
Doesn't change anything, whether the X server is running on the server's side or not.
Have been testing it with some lightweight apps too, but makes no difference if it's e.g. mousepad, gedit, thunderbird, always the same 2 min. delay at their start.

Also, some time ago, I had an older (more than 10 years) laptop, also with Arch installed, using LXDE, and connected via wifi to this same router, which worked perfectly without any delay. Also the same time ago, I was yet running Ubuntu on the home desktop, when I installed Arch to the virtualbox mentioned in point 2, and the problem was already present on the virtual pc, but not on the Ubuntu or the older laptop with Arch I had before.
Later, when I switched home desktop to Arch (or I got new laptop in the work), the issue appeared instantly on the new Arch installations.
The sshd configuration is the basic from the package, with X forwarding enabled of course, thus no strange changes of mine.


I monitored the ssh communications with tcpdump, not to read the encrypted data itself wink , but to see whether the data is flowing, and there are flow outages (absolute quiet except of below mentioned exceptions) in the mentioned 2 minutes duration till app. startup:
- after ssh authentication, there is about 1 minute silence, when after this 1st minute some few data is flowing
- next, there is another 1 minute silence, after which the app. finally starts

I've also gathered ssh debugging informations, from both, server (where I'm connecting and trying to start app. remotely) and client, with description when waiting has been detected.
server:

/usr/sbin/sshd -ddd

debug2: load_server_config: filename /etc/ssh/sshd_config
debug2: load_server_config: done config len = 501
debug2: parse_server_config: config /etc/ssh/sshd_config len 501
debug3: /etc/ssh/sshd_config:15 setting ListenAddress 0.0.0.0
debug3: /etc/ssh/sshd_config:16 setting ListenAddress ::
debug3: /etc/ssh/sshd_config:35 setting LogLevel INFO
debug3: /etc/ssh/sshd_config:42 setting PermitRootLogin no
debug3: /etc/ssh/sshd_config:52 setting AuthorizedKeysFile .ssh/authorized_keys
debug3: /etc/ssh/sshd_config:68 setting PermitEmptyPasswords no
debug3: /etc/ssh/sshd_config:71 setting ChallengeResponseAuthentication no
debug3: /etc/ssh/sshd_config:92 setting UsePAM yes
debug3: /etc/ssh/sshd_config:94 setting AllowAgentForwarding yes
debug3: /etc/ssh/sshd_config:95 setting AllowTcpForwarding yes
debug3: /etc/ssh/sshd_config:97 setting X11Forwarding yes
debug3: /etc/ssh/sshd_config:98 setting X11DisplayOffset 10
debug3: /etc/ssh/sshd_config:99 setting X11UseLocalhost yes
debug3: /etc/ssh/sshd_config:104 setting UsePrivilegeSeparation sandbox 
debug3: /etc/ssh/sshd_config:106 setting Compression delayed
debug3: /etc/ssh/sshd_config:109 setting UseDNS no
debug3: /etc/ssh/sshd_config:120 setting Subsystem sftp /usr/lib/ssh/sftp-server
debug1: sshd version OpenSSH_6.1p1
debug3: Incorrect RSA1 identifier
debug1: read PEM private key done: type RSA
debug1: private host key: #0 type 1 RSA
debug3: Incorrect RSA1 identifier
debug1: read PEM private key done: type DSA
debug1: private host key: #1 type 2 DSA
debug3: Incorrect RSA1 identifier
debug1: read PEM private key done: type ECDSA
debug1: private host key: #2 type 3 ECDSA
debug1: rexec_argv[0]='/usr/sbin/sshd'
debug1: rexec_argv[1]='-ddd'
debug3: oom_adjust_setup
Set /proc/self/oom_score_adj from 0 to -1000
debug2: fd 3 setting O_NONBLOCK
debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
debug2: fd 4 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug3: fd 5 is not O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
debug3: send_rexec_state: entering fd = 8 config len 501
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
debug1: inetd sockets after dupping: 3, 3
Connection from CLIENT_IP port 43333
debug1: Client protocol version 2.0; client software version OpenSSH_6.1
debug1: match: OpenSSH_6.1 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.1
debug2: fd 3 setting O_NONBLOCK
debug3: ssh_sandbox_init: preparing seccomp filter sandbox
debug2: Network child is on pid 6379
debug3: preauth child monitor started
debug3: privsep user:group 99:99 [preauth]
debug1: permanently_set_uid: 99/99 [preauth]
debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth]
debug3: ssh_sandbox_child: attaching seccomp filter program [preauth]
debug1: list_hostkey_types: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
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 [preauth]
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256 [preauth]
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 [preauth]
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 [preauth]
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 [preauth]
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 [preauth]
debug2: kex_parse_kexinit: none,zlib@openssh.com [preauth]
debug2: kex_parse_kexinit: none,zlib@openssh.com [preauth]
debug2: kex_parse_kexinit:  [preauth]
debug2: kex_parse_kexinit:  [preauth]
debug2: kex_parse_kexinit: first_kex_follows 0  [preauth]
debug2: kex_parse_kexinit: reserved 0  [preauth]
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 [preauth]
debug2: kex_parse_kexinit: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,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 [preauth]
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 [preauth]
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 [preauth]
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 [preauth]
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 [preauth]
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib [preauth]
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib [preauth]
debug2: kex_parse_kexinit:  [preauth]
debug2: kex_parse_kexinit:  [preauth]
debug2: kex_parse_kexinit: first_kex_follows 0  [preauth]
debug2: kex_parse_kexinit: reserved 0  [preauth]
debug2: mac_setup: found hmac-md5 [preauth]
debug1: kex: client->server aes128-ctr hmac-md5 none [preauth]
debug2: mac_setup: found hmac-md5 [preauth]
debug1: kex: server->client aes128-ctr hmac-md5 none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug3: mm_key_sign entering [preauth]
debug3: mm_request_send entering: type 4 [preauth]
debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth]
debug3: mm_request_receive_expect entering: type 5 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 4
debug3: mm_answer_sign
debug3: mm_answer_sign: signature 0x13e3f80(100)
debug3: mm_request_send entering: type 5
debug2: monitor_read: 4 used once, disabling now
debug2: kex_derive_keys [preauth]
debug2: set_newkeys: mode 1 [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug2: set_newkeys: mode 0 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug1: KEX done [preauth]
debug1: userauth-request for user USERNAME service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug3: mm_getpwnamallow entering [preauth]
debug3: mm_request_send entering: type 6 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 6
debug3: mm_answer_pwnamallow
debug2: parse_server_config: config reprocess config len 501
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send entering: type 7
debug2: monitor_read: 6 used once, disabling now
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
debug3: mm_request_receive_expect entering: type 7 [preauth]
debug3: mm_request_receive entering [preauth]
debug2: input_userauth_request: setting up authctxt for USERNAME [preauth]
debug3: mm_start_pam entering [preauth]
debug3: mm_request_send entering: type 45 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 45
debug1: PAM: initializing for "USERNAME"
debug1: PAM: setting PAM_RHOST to "CLIENT_IP"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 45 used once, disabling now
debug3: mm_inform_authserv entering [preauth]
debug3: mm_request_send entering: type 3 [preauth]
debug2: input_userauth_request: try method none [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 3
debug3: mm_answer_authserv: service=ssh-connection, style=
debug2: monitor_read: 3 used once, disabling now
debug1: userauth-request for user USERNAME service ssh-connection method publickey [preauth]
debug1: attempt 1 failures 0 [preauth]
debug2: input_userauth_request: try method publickey [preauth]
debug1: test whether pkalg/pkblob are acceptable [preauth]
debug3: mm_key_allowed entering [preauth]
debug3: mm_request_send entering: type 20 [preauth]
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect entering: type 21 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 20
debug3: mm_answer_keyallowed entering
debug3: mm_answer_keyallowed: key_from_blob: 0x13e1e20
debug1: temporarily_use_uid: 1000/100 (e=0/0)
debug1: trying public key file /home/USERNAME/.ssh/authorized_keys
debug1: Could not open authorized keys '/home/USERNAME/.ssh/authorized_keys': No such file or directory
debug1: restore_uid: 0/0
Failed publickey for USERNAME from CLIENT_IP port 43333 ssh2
debug3: mm_answer_keyallowed: key 0x13e1e20 is not allowed
debug3: mm_request_send entering: type 21
debug2: userauth_pubkey: authenticated 0 pkalg ssh-dss [preauth]
debug1: userauth-request for user USERNAME service ssh-connection method password [preauth]
debug1: attempt 2 failures 1 [preauth]
debug2: input_userauth_request: try method password [preauth]
debug3: mm_auth_password entering [preauth]
debug3: mm_request_send entering: type 10 [preauth]
debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth]
debug3: mm_request_receive_expect entering: type 11 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 10
debug3: PAM: sshpam_passwd_conv called with 1 messages
debug1: PAM: password authentication accepted for USERNAME
debug3: mm_answer_authpassword: sending result 1
debug3: mm_request_send entering: type 11
debug3: mm_request_receive_expect entering: type 46
debug3: mm_request_receive entering
debug1: do_pam_account: called
debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
debug3: mm_request_send entering: type 47
Accepted password for USERNAME from CLIENT_IP port 43333 ssh2
debug3: mm_auth_password: user authenticated [preauth]
debug3: mm_do_pam_account entering [preauth]
debug3: mm_request_send entering: type 46 [preauth]
debug3: mm_request_receive_expect entering: type 47 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_do_pam_account returning 1 [preauth]
debug3: mm_send_keystate: Sending new keys: 0x13e1c40 0x13e34c0 [preauth]
debug3: mm_newkeys_to_blob: converting 0x13e1c40 [preauth]
debug3: mm_newkeys_to_blob: converting 0x13e34c0 [preauth]
debug3: mm_send_keystate: New keys have been sent [preauth]
debug3: mm_send_keystate: Sending compression state [preauth]
debug3: mm_request_send entering: type 24 [preauth]
debug3: mm_send_keystate: Finished sending state [preauth]
debug1: monitor_read_log: child log fd closed
debug1: monitor_child_preauth: USERNAME has been authenticated by privileged process
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect entering: type 24
debug3: mm_request_receive entering
debug3: mm_newkeys_from_blob: 0x13f3b20(122)
debug2: mac_setup: found hmac-md5
debug3: mm_get_keystate: Waiting for second key
debug3: mm_newkeys_from_blob: 0x13f3b20(122)
debug2: mac_setup: found hmac-md5
debug3: mm_get_keystate: Getting compression state
debug3: mm_get_keystate: Getting Network I/O buffers
debug3: mm_share_sync: Share sync
debug3: mm_share_sync: Share sync end
debug3: ssh_sandbox_parent_finish: finished
debug1: PAM: establishing credentials
debug3: PAM: opening session
User child is on pid 6387
debug1: PAM: establishing credentials
debug1: permanently_set_uid: 1000/100
debug2: set_newkeys: mode 0
debug2: set_newkeys: mode 1
debug1: Entering interactive session for SSH2.
debug2: fd 7 setting O_NONBLOCK
debug2: fd 9 setting O_NONBLOCK
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
debug1: input_session_request
debug1: channel 0: new [server-session]
debug2: session_new: allocate (allocated 0 max 10)
debug3: session_unused: session id 0 unused
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
debug1: server_input_channel_req: channel 0 request x11-req reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req x11-req
debug3: sock_set_v6only: set socket 10 IPV6_V6ONLY
debug2: fd 10 setting O_NONBLOCK
debug3: fd 10 is O_NONBLOCK
debug1: channel 1: new [X11 inet listener]
debug2: fd 11 setting O_NONBLOCK
debug3: fd 11 is O_NONBLOCK
debug1: channel 2: new [X11 inet listener]
debug1: server_input_channel_req: channel 0 request exec reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req exec
debug2: fd 3 setting TCP_NODELAY
debug3: packet_set_tos: set IP_TOS 0x10
debug2: fd 14 setting O_NONBLOCK
debug2: fd 13 setting O_NONBLOCK
debug2: fd 16 setting O_NONBLOCK
debug2: channel 0: read 210 from efd 16
debug2: channel 0: rwin 2097152 elen 210 euse 1
debug2: channel 0: sent ext data 210
debug2: channel 0: read 380 from efd 16
debug2: channel 0: rwin 2096942 elen 380 euse 1
debug2: channel 0: sent ext data 380
debug2: channel 0: read 121 from efd 16
debug2: channel 0: rwin 2096562 elen 121 euse 1
debug2: channel 0: sent ext data 121

### Here started the waiting on the server's side, and continued later till the start of app.:

debug1: X11 connection requested.
debug2: fd 12 setting TCP_NODELAY
debug2: fd 12 setting O_NONBLOCK
debug3: fd 12 is O_NONBLOCK
debug1: channel 3: new [X11 connection from 127.0.0.1 port 46968]
debug2: channel 3: open confirm rwindow 2097152 rmax 16384
debug2: channel 0: read 62 from efd 16
debug2: channel 0: rwin 2096441 elen 62 euse 1
debug2: channel 0: sent ext data 62
debug1: X11 connection requested.
debug2: fd 15 setting TCP_NODELAY
debug2: fd 15 setting O_NONBLOCK
debug3: fd 15 is O_NONBLOCK
debug1: channel 4: new [X11 connection from 127.0.0.1 port 46972]
debug2: channel 4: open confirm rwindow 2097152 rmax 16384
debug2: channel 3: rcvd adjust 51268
debug2: channel 3: rcvd adjust 65536
debug2: channel 3: rcvd adjust 65536
debug2: channel 3: rcvd adjust 65536
debug2: channel 3: rcvd adjust 65536
debug2: channel 3: rcvd adjust 32768
debug2: channel 3: rcvd adjust 147456
debug2: channel 3: rcvd adjust 55788
debug2: channel 3: window 32740 sent adjust 32796

client:

ssh -Xvvv USERNAME@SERVER_IP mousepad

OpenSSH_6.1p1, OpenSSL 1.0.1c 10 May 2012
debug1: Reading configuration data /etc/ssh/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to SERVER_IP [SERVER_IP] port 22.
debug1: Connection established.
debug1: identity file /home/USERNAME/.ssh/id_rsa type -1
debug1: identity file /home/USERNAME/.ssh/id_rsa-cert type -1
debug1: identity file /home/USERNAME/.ssh/id_dsa type 2
debug1: identity file /home/USERNAME/.ssh/id_dsa-cert type -1
debug1: identity file /home/USERNAME/.ssh/id_ecdsa type -1
debug1: identity file /home/USERNAME/.ssh/id_ecdsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.1
debug1: match: OpenSSH_6.1 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.1
debug2: fd 3 setting O_NONBLOCK
debug3: load_hostkeys: loading entries for host "SERVER_IP" from file "/home/USERNAME/.ssh/known_hosts"
debug3: load_hostkeys: found key type ECDSA in file /home/USERNAME/.ssh/known_hosts:4
debug3: load_hostkeys: loaded 1 keys
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,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
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
debug2: kex_parse_kexinit: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,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: 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
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256
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: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA ABC123...
debug3: load_hostkeys: loading entries for host "SERVER_IP" from file "/home/USERNAME/.ssh/known_hosts"
debug3: load_hostkeys: found key type ECDSA in file /home/USERNAME/.ssh/known_hosts:4
debug3: load_hostkeys: loaded 1 keys
debug1: Host 'SERVER_IP' is known and matches the ECDSA host key.
debug1: Found key in /home/USERNAME/.ssh/known_hosts:4
debug1: ssh_ecdsa_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: /home/USERNAME/.ssh/id_rsa ((nil))
debug2: key: /home/USERNAME/.ssh/id_dsa (0x)
debug2: key: /home/USERNAME/.ssh/id_ecdsa ((nil))
debug1: Authentications that can continue: publickey,password
debug3: start over, passed a different list publickey,password
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: Trying private key: /home/USERNAME/.ssh/id_rsa
debug3: no such identity: /home/USERNAME/.ssh/id_rsa
debug1: Offering DSA public key: /home/USERNAME/.ssh/id_dsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Authentications that can continue: publickey,password
debug1: Trying private key: /home/USERNAME/.ssh/id_ecdsa
debug3: no such identity: /home/USERNAME/.ssh/id_ecdsa
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred: ,password
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
USERNAME@SERVER_IP's password: 
debug3: packet_send2: adding 48 (len 68 padlen 12 extra_pad 64)
debug2: we sent a password packet, wait for reply
debug1: Authentication succeeded (password).
Authenticated to SERVER_IP ([SERVER_IP]: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.
debug2: callback start
debug2: x11_get_proto: /usr/bin/xauth -f /tmp/ssh-mHE6faU7YJF2/xauthfile generate :0 MIT-MAGIC-COOKIE-1 untrusted timeout 1200 2>/dev/null
debug2: x11_get_proto: /usr/bin/xauth -f /tmp/ssh-mHE6faU7YJF2/xauthfile list :0 2>/dev/null
debug1: Requesting X11 forwarding with authentication spoofing.
debug2: channel 0: request x11-req confirm 1
debug2: fd 3 setting TCP_NODELAY
debug3: packet_set_tos: set IP_TOS 0x10
debug2: client_session2_setup: id 0
debug1: Sending command: mousepad
debug2: channel 0: request exec confirm 1
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel_input_status_confirm: type 99 id 0
debug2: X11 forwarding request accepted on channel 0
debug2: channel 0: rcvd adjust 2097152
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0

### After successful authentication, here above started the first waiting, where after first 1 min. continued with:

debug2: channel 0: rcvd ext data 210
debug2: channel 0: rcvd ext data 380
debug2: channel 0: rcvd ext data 121
debug3: Copy environment: XDG_SESSION_COOKIE=0d937ee20c7e42bdbf828421a30eaa2f-1357144247.348263-1841400888
debug3: Copy environment: XDG_SESSION_ID=5
debug3: Copy environment: XDG_RUNTIME_DIR=/run/user/1000
debug2: channel 0: written 711 to efd 6

### After another 1 min. continued with + started the app.

debug1: client_input_channel_open: ctype x11 rchan 3 win 65536 max 16384
debug1: client_request_x11: request from 127.0.0.1 46968
debug2: fd 7 setting O_NONBLOCK
debug3: fd 7 is O_NONBLOCK
debug1: channel 1: new [x11]
debug1: confirm x11
debug2: channel 0: rcvd ext data 62
Xlib:  extension "RANDR" missing on display "localhost:10.0".
debug2: channel 0: written 62 to efd 6
debug1: client_input_channel_open: ctype x11 rchan 4 win 65536 max 16384
debug1: client_request_x11: request from 127.0.0.1 46972
debug2: fd 8 setting O_NONBLOCK
debug3: fd 8 is O_NONBLOCK
debug1: channel 2: new [x11]
debug1: confirm x11
debug2: channel 1: window 2045884 sent adjust 51268
debug2: channel 1: window 2031616 sent adjust 65536
debug2: channel 1: window 2031616 sent adjust 65536
debug2: channel 1: window 2031616 sent adjust 65536
debug2: channel 1: window 2031616 sent adjust 65536
debug2: channel 1: window 2031616 sent adjust 32768
debug2: channel 1: window 1949696 sent adjust 147456
debug2: channel 1: window 2041364 sent adjust 55788
debug2: channel 1: rcvd adjust 32796
debug1: client_input_channel_open: ctype x11 rchan 5 win 65536 max 16384
debug1: client_request_x11: request from 127.0.0.1 46974
debug2: fd 9 setting O_NONBLOCK
debug3: fd 9 is O_NONBLOCK
debug1: channel 3: new [x11]
debug1: confirm x11
debug2: channel 1: rcvd adjust 32800

It's quite strange, as I have no more ideas what to check next.
Any ideas pls?
thx in advance.


Logic clearly dictates that the needs of the many outweigh the needs of the few.

Offline

#2 2013-03-25 20:25:11

8472
Member
From: Slovakia
Registered: 2010-05-15
Posts: 83

Re: ssh X11 forwarding takes too long to start any app. remotely

Have finally found a solution for this problem: http://serverfault.com/questions/490352 … w-to-start
Now the applications do start immediately via SSH X11 forwarding as expected.
The following three lines helped:

ip6tables -A INPUT -i lo -j ACCEPT
ip6tables -A OUTPUT -o lo -j ACCEPT
ip6tables -A FORWARD -i lo -o lo -j ACCEPT

While until now, all ip6 traffic has been forbidden (to drop all ip6 traffic) at the start of the system of course.
Nevertheless, I don't understand it, why the ip6 localhost has to be granted this way even if the /etc/ssh/sshd_config is configured for ip4 only "AddressFamily inet"?
I thought, that this way the sshd will be using ip4 protocol only (including for the X11 forwarding), then why does it still need the ip6?


Logic clearly dictates that the needs of the many outweigh the needs of the few.

Offline

#3 2015-01-28 22:13:43

kevdog
Member
Registered: 2013-01-26
Posts: 102

Re: ssh X11 forwarding takes too long to start any app. remotely

It would be great if this info would be added to the official sshd Arch wiki page.  Information very valuable for Arch SSHd setup, interestingly I didn't have to do this for my firewall configuration within my other Ubuntu server.

Offline

Board footer

Powered by FluxBB