Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 23 Nov 2012 12:43:58 -0500
From:      Paul Kraus <paul@kraus-haus.org>
To:        FreeBSD Mailing List <freebsd-questions@freebsd.org>
Cc:        Carl Zwanzig <cpz@tuunq.com>
Subject:   Odd X11 over SSH issue
Message-ID:  <CALhcXPDSZ8Qgj4tG1UQdO7c4tB3cSJbW%2Bj0DDbpJFct2VZXs4g@mail.gmail.com>

next in thread | raw e-mail | index | archive | help
I am seeing very poor response time running the VitrualBox GUI via X11
tunneled over SSH via the Internet. The issue _appears_ to be limited
to the VBox GUI as Firefox is reasonable. I am well aware of the
latency issues tunneling X11 over SSH across the Internet, but that is
what we are stuck with for the moment. The server is running FreeBSD 9
and is patched as of about 4 weeks ago.

Observations:

1. When I first SSH into the box I see a long delay after the SSH
tunnel is setup before being prompted for a password, and I do not
know if this delay is related to the VBox issue. Details below.

2. When I fire up VirtualBox it takes _minutes_ before the window
opens and each action (drawing contents, mouse clicks) takes
additional _minutes_. Looking at the VirtualBox process with truss I
see many, many errors of the form:

read(7,0x80193a02c,4096)			 ERR#35 'Resource temporarily unavailable'

where fd 7 is a socket. I would chock it up to network slowness, but I
do not see the same behavior with Firefox, xload, or xclock. An xterm
is even pretty snappy. Timing firefox, it takes under 10 seconds to
draw the window and fill it. It takes about 2 to 3 seconds to draw the
menu after clicking on the menu widget. With VirtualBox is takes
_minutes_ for every action, so it is clearly a call that VirtualBox is
making, but I can't figure it out from the truss output. The
VirtualBox GUI works fine when run on the console or on the local
network (not via SSH). I have a local system that I think is
configured the same way (but much slower hardware) and the VirtualBox
GUI is reasonable via SSH about 10-20 seconds to open the window and
5-10 second response time to mouse clicks). It is only when it is
tunneled over SSH via the Internet that the problem appears.

Details below.

Any suggestions where to look ? Or am I barking up the wrong tree ?

{--------1---------2---------3---------4---------5---------6---------7---------}
SSH details:

Mini1:~ user$ ssh -X -C -v root@a.b.c.d
OpenSSH_5.2p1, OpenSSL 0.9.8r 8 Feb 2011
debug1: Reading configuration data /etc/ssh_config
debug1: Connecting to a.b.c.d [a.b.c.d] port 22.
debug1: Connection established.
debug1: identity file /Users/user/.ssh/identity type -1
debug1: identity file /Users/user/.ssh/id_rsa type -1
debug1: identity file /Users/user/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version
OpenSSH_5.8p2_hpn13v11 FreeBSD-20110503
debug1: match: OpenSSH_5.8p2_hpn13v11 FreeBSD-20110503 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.2
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr hmac-md5 zlib@openssh.com
debug1: kex: client->server aes128-ctr hmac-md5 zlib@openssh.com
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host 'a.b.c.d' is known and matches the RSA host key.
debug1: Found key in /Users/user/.ssh/known_hosts:9
debug1: ssh_rsa_verify: signature correct
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,keyboard-interactive
debug1: Next authentication method: publickey
debug1: Trying private key: /Users/user/.ssh/identity
debug1: Trying private key: /Users/user/.ssh/id_rsa
debug1: Trying private key: /Users/user/.ssh/id_dsa
debug1: Next authentication method: keyboard-interactive

<here there is a pause of 30 to 60 seconds>

Password:
debug1: Enabling compression at level 6.
debug1: Authentication succeeded (keyboard-interactive).
debug1: channel 0: new [client-session]
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
Warning: untrusted X11 forwarding setup failed: xauth key data not generated
Warning: No xauth data; using fake authentication data for X11 forwarding.
debug1: Requesting X11 forwarding with authentication spoofing.
Last login: Fri Nov 23 11:20:26 2012 from e.f.g.h
FreeBSD 9.0-RELEASE-p3 (GENERIC) #0: Tue Jun 12 02:52:29 UTC 2012

{--------1---------2---------3---------4---------5---------6---------7---------}

VBox Details (from truss):

10709: socket(PF_INET,SOCK_STREAM,6)             = 7 (0x7)
10709: fcntl(7,F_SETFD,FD_CLOEXEC)               = 0 (0x0)
10709: setsockopt(0x7,0x6,0x1,0x7fffffffc578,0x4,0x2) = 0 (0x0)
10709: setsockopt(0x7,0xffff,0x8,0x7fffffffc578,0x4,0x2) = 0 (0x0)
10709: connect(7,{ AF_INET 127.0.0.1:6010 },16)  = 0 (0x0)
10709: getpeername(7,{ AF_INET 127.0.0.1:6010 },0x7fffffffc2d4) = 0 (0x0)
10709: __sysctl(0x7fffffffc2f0,0x2,0x7fffffffc340,0x7fffffffc2e8,0x0,0x0)
= 0 (0x0)
10709: access("/root/.Xauthority",4)             = 0 (0x0)
10709: open("/root/.Xauthority",O_RDONLY,0666)   = 8 (0x8)
10709: fstat(8,{ mode=-rw------- ,inode=131090,size=199,blksize=4096
}) = 0 (0x0)
10709: read(8,"\^A\0\0\^Dsrv1\0\^A0\0\^RMIT-MAG"...,4096) = 199 (0xc7)
10709: read(8,0x801848000,4096)                  = 0 (0x0)
10709: close(8)                                  = 0 (0x0)
10709: getsockname(7,{ AF_INET 127.0.0.1:52920 },0x7fffffffc2d4) = 0 (0x0)
10709: fcntl(7,F_GETFL,)                         = 2 (0x2)
10709: fcntl(7,F_SETFL,O_NONBLOCK|0x2)           = 0 (0x0)
10709: fcntl(7,F_SETFD,FD_CLOEXEC)               = 0 (0x0)
10709: poll({7/POLLIN|POLLOUT},1,-1)             = 1 (0x1)
10709: writev(0x7,0x7fffffffc420,0x6,0x0,0x50,0x0) = 48 (0x30)
10709: read(7,0x80181a138,8)                     ERR#35 'Resource
temporarily unavailable'
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\^A\0\v\0\0\0\M-3\^S",8)          = 8 (0x8)
10709: read(7,"\M-P\M-8\M^^\0\0\0\M-@\0\M^?\M^?"...,20172) = 8184 (0x1ff8)
10709: read(7,0x80198e000,11988)                 ERR#35 'Resource
temporarily unavailable'
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\0\M^?\0\0\M^?\0\0\0\^A\0\0\0s"...,11988) = 11988 (0x2ed4)
10709: poll({7/POLLIN|POLLOUT},1,-1)             = 1 (0x1)
10709: writev(0x7,0x7fffffffc4d0,0x1,0x0,0x0,0x0) = 20 (0x14)
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\^AM\^A\0\0\0\0\0\^A\M^G\0\0\^A"...,4096) = 32 (0x20)
10709: poll({7/POLLIN|POLLOUT},1,-1)             = 1 (0x1)
10709: writev(0x7,0x7fffffffc510,0x1,0x0,0x0,0x0) = 4 (0x4)
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\^AM\^B\0\0\0\0\0\M^?\M^??\0\^A"...,4096) = 32 (0x20)
10709: read(7,0x80193a02c,4096)                  ERR#35 'Resource
temporarily unavailable'
10709: poll({7/POLLIN|POLLOUT},1,-1)             = 1 (0x1)
10709: writev(0x7,0x7fffffffc520,0x3,0x0,0x0,0x0) = 44 (0x2c)
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\^A\0\^D\0\0\0\0\0\0\0\0\0\0\0\0"...,4096) = 32 (0x20)
10709: read(7,0x80193a02c,4096)                  ERR#35 'Resource
temporarily unavailable'
10709: poll({7/POLLIN|POLLOUT},1,-1)             = 1 (0x1)
10709: writev(0x7,0x7fffffffc490,0x3,0x0,0x0,0x0) = 20 (0x14)
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\^AM\^E\0\0\0\0\0\^A\M^L_\M^O\^A"...,4096) = 32 (0x20)
10709: read(7,0x80193a02c,4096)                  ERR#35 'Resource
temporarily unavailable'
10709: read(7,0x80193a02c,4096)                  ERR#35 'Resource
temporarily unavailable'
10709: poll({7/POLLIN|POLLOUT},1,-1)             = 1 (0x1)
10709: writev(0x7,0x7fffffffc4c0,0x3,0x0,0x0,0x0) = 8 (0x8)
10709: poll({7/POLLIN},1,-1)                     = 1 (0x1)
10709: read(7,"\^A\^A\^F\0\0\0\0\0\^A\0\0\0\^A"...,4096) = 32 (0x20)
10709: read(7,0x80193a02c,4096)                  ERR#35 'Resource
temporarily unavailable'
10709: read(7,0x80193a02c,4096)                  ERR#35 'Resource
temporarily unavailable'
...

-- 
{--------1---------2---------3---------4---------5---------6---------7---------}
Paul Kraus
-> Principal Consultant, Business Information Technology Systems
-> Deputy Technical Director, LoneStarCon 3 (http://lonestarcon3.org/)
-> Sound Coordinator, Schenectady Light Opera Company (
http://www.sloctheater.org/ )
-> Technical Advisor, Troy Civic Theatre Company
-> Technical Advisor, RPI Players



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CALhcXPDSZ8Qgj4tG1UQdO7c4tB3cSJbW%2Bj0DDbpJFct2VZXs4g>