Bug #759: x2goclient 4.0.5.0 (and 4.0.5.1 preview) frequent ssh commands don't free resources
I've run in to this problem as well, with these x2go versions:
Client (Mac)
- x2goclient 4.0.5.0 (OS X 10.9+ build) or 4.0.5.1 preview (December 2015 build)
- OS X 10.11.3
- XQuartz 2.7.8
Server (Linux)
- x2goagent: 3.5.0.32
- x2goserver: 4.0.1.19
- x2goserver-extensions: 4.0.1.19
- Fedora 23 (with updates as of 2016-02-17)
Steps to reproduce:
- Run 'x2goclient --debug' and open a session
- Observe frequent xmodmap commands while session is active
- Quit session to see a large number of SshProcess objects freed
This came to my attention because the default SELinux/audit settings on Fedora 23 log five events for each xmodmap ssh command executed on the server by the client. That's 1800 events per hour when an x2go session is active.
Judging from ONMainWindow::slotSetModMap() in onmainwindow.cpp, it looks like the intent is to only run the xmodmap command if kbMap is empty (maybe there's an expected way for kbMap to get cleared so it has to be periodically checked?). However, slotSetModMap() runs every 10 seconds and executes a command every time. It's not clear to me how kbMap becomes empty.
Furthermore, the SshProcess objects are not cleaned up until the session is exited. The 'processes' QList in SshMasterConnection grows without bound.
Logs from x2goclient --debug:
""" x2go-DEBUG-../src/sshprocess.cpp:199> Executing remote command via SshProcess object 6: "export DISPLAY=":50"; echo "keycode 8 = a A aring Aring <snip>" x2go-DEBUG-../src/sshprocess.cpp:204> Running masterCon->addChannelConnection(this, '"d93c9f1a-2d4d-42fb-92a9-5373621768f6"', '"bash -c 'echo "X2GODATABEGIN:d93c9f1a-2d4d-42fb-92a9-5373621768f6"; export PATH="/usr/local/bin:/usr/bin:/bin"; export DISPLAY=":50"; echo "keycode 8 = a A aring Aring keycode 9 = s S ssharp Iacut"'); x2go-DEBUG-../src/sshmasterconnection.cpp:1284> Locking SSH channel connection MUTEX. x2go-DEBUG-../src/sshmasterconnection.cpp:1286> Passing new channel conenction object to channelConnections. x2go-DEBUG-../src/sshmasterconnection.cpp:1288> Unlocking SSH channel connection MUTEX. x2go-DEBUG-../src/sshmasterconnection.cpp:1476> Creating new channel.
x2go-DEBUG-../src/sshmasterconnection.cpp:1480> New channel:0x7fcb9a7af450
x2go-DEBUG-../src/sshmasterconnection.cpp:1511> Executing remote: "bash -c 'echo "X2GODATABEGIN:d93c9f1a-2d4d-42fb-92a9-5373621768f6"; export PATH="/usr/local/bin:/usr/bin:/bin"; export DISPLAY=":50"; echo "keycode 8 = a A aring Aring <snip>" x2go-DEBUG-../src/sshmasterconnection.cpp:1534> New exec channel created.
x2go-DEBUG-../src/sshmasterconnection.cpp:1638> EOF on channel 0x7fcb9a7af450; SshProcess object: 6 x2go-DEBUG-../src/sshmasterconnection.cpp:1706> EOF sent. x2go-DEBUG-../src/sshmasterconnection.cpp:1710> Channel closed. x2go-DEBUG-../src/sshprocess.cpp:517> SSH finished: raw output (stdout): "X2GODATABEGIN:d93c9f1a-2d4d-42fb-92a9-5373621768f6 X2GODATAEND:d93c9f1a-2d4d-42fb-92a9-5373621768f6 " x2go-DEBUG-../src/sshprocess.cpp:528> SSH finished: true - "" (6). <repeat every 10 seconds> """
And the log of SshProcess cleanup when the session is disconnected after a little over one minute:
""" x2go-DEBUG-../src/sshmasterconnection.cpp:715> SshMasterConnection, instance SshMasterConnection(0x7fcb9cc51a90) thread finished. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshmasterconnection.cpp:722> SshMasterConnection, instance SshMasterConnection(0x7fcb9cc51a90) finished destructor. """
-- Mat Martineau Intel OTC
Given that the Mac client is leaking 6 SshProcess objects per minute, is there a chance bug 759 will get a look before 4.0.5.1?
Thanks, Mat
On Thu, 18 Feb 2016, Mat Martineau wrote:
I've run in to this problem as well, with these x2go versions:
Client (Mac)
- x2goclient 4.0.5.0 (OS X 10.9+ build) or 4.0.5.1 preview (December 2015 build)
- OS X 10.11.3
- XQuartz 2.7.8
Server (Linux)
- x2goagent: 3.5.0.32
- x2goserver: 4.0.1.19
- x2goserver-extensions: 4.0.1.19
- Fedora 23 (with updates as of 2016-02-17)
Steps to reproduce:
- Run 'x2goclient --debug' and open a session
- Observe frequent xmodmap commands while session is active
- Quit session to see a large number of SshProcess objects freed
This came to my attention because the default SELinux/audit settings on Fedora 23 log five events for each xmodmap ssh command executed on the server by the client. That's 1800 events per hour when an x2go session is active.
Judging from ONMainWindow::slotSetModMap() in onmainwindow.cpp, it looks like the intent is to only run the xmodmap command if kbMap is empty (maybe there's an expected way for kbMap to get cleared so it has to be periodically checked?). However, slotSetModMap() runs every 10 seconds and executes a command every time. It's not clear to me how kbMap becomes empty.
Furthermore, the SshProcess objects are not cleaned up until the session is exited. The 'processes' QList in SshMasterConnection grows without bound.
Logs from x2goclient --debug:
""" x2go-DEBUG-../src/sshprocess.cpp:199> Executing remote command via SshProcess object 6: "export DISPLAY=":50"; echo "keycode 8 = a A aring Aring <snip>" x2go-DEBUG-../src/sshprocess.cpp:204> Running masterCon->addChannelConnection(this, '"d93c9f1a-2d4d-42fb-92a9-5373621768f6"', '"bash -c 'echo "X2GODATABEGIN:d93c9f1a-2d4d-42fb-92a9-5373621768f6"; export PATH="/usr/local/bin:/usr/bin:/bin"; export DISPLAY=":50"; echo "keycode 8 = a A aring Aring keycode 9 = s S ssharp Iacut"'); x2go-DEBUG-../src/sshmasterconnection.cpp:1284> Locking SSH channel connection MUTEX. x2go-DEBUG-../src/sshmasterconnection.cpp:1286> Passing new channel conenction object to channelConnections. x2go-DEBUG-../src/sshmasterconnection.cpp:1288> Unlocking SSH channel connection MUTEX. x2go-DEBUG-../src/sshmasterconnection.cpp:1476> Creating new channel.
x2go-DEBUG-../src/sshmasterconnection.cpp:1480> New channel:0x7fcb9a7af450
x2go-DEBUG-../src/sshmasterconnection.cpp:1511> Executing remote: "bash -c 'echo "X2GODATABEGIN:d93c9f1a-2d4d-42fb-92a9-5373621768f6"; export PATH="/usr/local/bin:/usr/bin:/bin"; export DISPLAY=":50"; echo "keycode 8 = a A aring Aring <snip>" x2go-DEBUG-../src/sshmasterconnection.cpp:1534> New exec channel created.
x2go-DEBUG-../src/sshmasterconnection.cpp:1638> EOF on channel 0x7fcb9a7af450; SshProcess object: 6 x2go-DEBUG-../src/sshmasterconnection.cpp:1706> EOF sent. x2go-DEBUG-../src/sshmasterconnection.cpp:1710> Channel closed. x2go-DEBUG-../src/sshprocess.cpp:517> SSH finished: raw output (stdout): "X2GODATABEGIN:d93c9f1a-2d4d-42fb-92a9-5373621768f6 X2GODATAEND:d93c9f1a-2d4d-42fb-92a9-5373621768f6 " x2go-DEBUG-../src/sshprocess.cpp:528> SSH finished: true - "" (6). <repeat every 10 seconds> """
And the log of SshProcess cleanup when the session is disconnected after a little over one minute:
""" x2go-DEBUG-../src/sshmasterconnection.cpp:715> SshMasterConnection, instance SshMasterConnection(0x7fcb9cc51a90) thread finished. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshmasterconnection.cpp:722> SshMasterConnection, instance SshMasterConnection(0x7fcb9cc51a90) finished destructor. """
-- Mat Martineau Intel OTC
x2go-dev mailing list x2go-dev@lists.x2go.org http://lists.x2go.org/listinfo/x2go-dev
On 14.03.2016 05:47 PM, Mat Martineau wrote:
Given that the Mac client is leaking 6 SshProcess objects per minute, is there a chance bug 759 will get a look before 4.0.5.1?
Sorry, I didn't have the time to look at that yet. Hopefully for the next release.
Mihai
On 03/14/2016 05:47 PM, Mat Martineau wrote:
Given that the Mac client is leaking 6 SshProcess objects per minute, is there a chance bug 759 will get a look before 4.0.5.1?
Obviously not, but something definitely sounds fishy there.
In general, running xmodmap every 10 seconds is fine. That's how we synchronize the keyboard map on OS X. I understand this may seem weird, but keyboard handling on OS X is difficult. The keyboard settings that is reported by the local X server on OS X is just "bogus" and the mapping is done differently. I don't know how exactly, but I figure it's going through the OS X system at some point.
A problem arises if these values are taken at face value - they keyboard mapping would completely messed up. This also holds, for example, if the keyboard parameters is changed in x2goagent/nxagent (e.g., via the desktop environment) itself.
The second issue - ssh processes stacking up, is NOT intentional and must be fixed.
Can you reproduce this with current versions?
Mihai
On Wed, 15 Nov 2017, Mihai Moldovan wrote:
On 03/14/2016 05:47 PM, Mat Martineau wrote:
Given that the Mac client is leaking 6 SshProcess objects per minute, is there a chance bug 759 will get a look before 4.0.5.1?
Obviously not, but something definitely sounds fishy there.
...
The second issue - ssh processes stacking up, is NOT intentional and must be fixed.
Can you reproduce this with current versions?
Running with x2goserver 4.0.1.20 (Fedora 26) and x2goclient 4.1.1.0 (MacOS 10.12.6), I still see the cleanup at exit:
""" x2go-DEBUG-../src/sshmasterconnection.cpp:1985> All channels closed and session disconnected. Quitting session loop.
x2go-DEBUG-../src/sshmasterconnection.cpp:797> SshMasterConnection, instance SshMasterConnection(0x7fc54fdf1b40) thread finished. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshprocess.cpp:52> SshProcess destructor called. x2go-DEBUG-../src/sshmasterconnection.cpp:804> SshMasterConnection, instance SshMasterConnection(0x7fc54fdf1b40) finished destructor. x2go-DEBUG-../src/onmainwindow.cpp:6532> Setting focus. """
-- Mat Martineau Intel OTC
-
Mat Martineau -
Mihai Moldovan