Ubuntu Maverick 100% CPU-Usage and no functionality

[Thomas Käfer]

Hi! I installed winswitch on 3 systems of mine in the last days:

1.) Linux Mint Debian Editon (based on Debian Wheezy)
2.) Ubuntu 11.04 Natty Narwhal
3.) Ubuntu 10.10 Maverick Meerkat

On 1.) and 2.) It worked well locally, although I was not able to use 1.) from 2.) - see ​https://winswitch.org/forum/topic/15/ for details

This issue is about the 3rd machine, the Ubuntu 10.10.

I did install winswitch like this:

curl https://winswitch.org/gpg.asc | apt-key add -
echo "deb http://winswitch.org/ maverick main" > /etc/apt/sources.list.d/winswitch.list;
apt-get update
apt-get install winswitch

When starting the applet, it appeared in the statusbar, but reacted very sluggish (which did not get better even after 15 minutes) I could not open a session locally neither remote on the 1.) machine, although the second issue seems to stem from version incompatibilities of xpra.

I'll attach the logfile.

[Antoine Martin]

• I believe that the problem with the sluggishness is due to a long standing bug in Maverick that Ubuntu does not seem to care about (despite the totally trivial fix they have applied to Lucid and later releases), see here for details: #90

Maverick is soon to be end-of-lifed anyway so this is not a supported configuration. Sorry but I have enough work my own bugs!

• I've looked at the log extracts you posted and everything looks fine:

  ServerLink.add_port_forward(None,127.0.0.1,15064) adding new port forward
  ConchConnection.forward_port(12463,127.0.0.1,15064)
  (...)
  SimpleLineProcess.start() process(['/usr/bin/xpra', (...), 'attach', 'tcp:127.0.0.1:12463'])=<Process pid=3467 status=-1>
  

It looks like it knows which port the session is on (15064 on the server), creates a tunnel to it from 12463 (local port) then tries to attach to this local port.
If this problem occurs only on one machine, is it possible that the ssh or user environment is different? Is Xpra at the correct/latest version? Does ssh allow port forwarding (I believe there would have been an error if not, but still worth checking)

Hah I think I see a problem here:

process_util.kill0(2553) error polling pid: [Errno 3] Kein passender Prozess gefunden

I believe it does not find the process it just started (gnome-terminal), for whatever reason...

Can you try running the same xpra server command directly on that server system to try to see why it failed:

/usr/bin/xpra "--xvfb=/usr/bin/Xvfb +extension Composite \
    -screen 0 3840x2560x24+32 -noreset -auth /var/run/gdm/auth-for-kaefert-fuKIoX/database" \
    "--bind-tcp=127.0.0.1:15062" \
    "--password-file=/home/kaefert/.winswitch/server/sessions/61/session.pass" \
    "--no-daemon" "--no-pulseaudio" "--session-name=Terminal" "start" ":61

You can safely drop "--password-file" and "-auth xxxx" (or replace it with the $XAUTHORITY of your new user session).

If that works when you run it but not when winswitch does it, you will need to

look at ​session-debugging and in particular the --no-delete-session-files switch so that you can look at the xpra server logfile after the session failed to start. In your log sample, the log file was:

XpraServerUtil.do_watch_session_log(/home/kaefert/.winswitch/server/sessions/61/xpra.log,43,ServerSession(:61 - xpra - starting)) ...

Hope this helps...

[Thomas Käfer]

What should this command do? It did not open any new window or something. Here is the output:

kaefert@blechmobil:~$ /usr/bin/xpra "--xvfb=/usr/bin/Xvfb +extension Composite -screen 0 3840x2560x24+32 -noreset" "--bind-tcp=127.0.0.1:15062" "--no-daemon" "--no-pulseaudio" "--session-name=Terminal" "start" ":61"
[dix] Could not init font path element /usr/share/fonts/X11/cyrillic, removing from list!
[dix] Could not init font path element /usr/share/fonts/X11/100dpi/:unscaled, removing from list!
[dix] Could not init font path element /usr/share/fonts/X11/75dpi/:unscaled, removing from list!
[dix] Could not init font path element /usr/share/fonts/X11/100dpi, removing from list!
[dix] Could not init font path element /usr/share/fonts/X11/75dpi, removing from list!
Xlib:  extension "RANDR" missing on display ":61".
Xlib:  extension "RANDR" missing on display ":61".
Xlib:  extension "RANDR" missing on display ":61".
Randr not supported: X server does not support required extension Randr
cannot register our notification forwarder: the name 'org.freedesktop.Notifications' is already claimed on the session bus

xpra is ready.


^Cgot signal 2, exiting
xpra: Fatal IO error 2 (Datei oder Verzeichnis nicht gefunden) on X server :61.
kaefert@blechmobil:~$ 

I pressed Enter -> Enter -> Control+C after a minute or so..

[Antoine Martin]

OK, that's fine then, it means xpra can start ok with the given command line.
(You're not seeing anything because you have not started any applications on DISPLAY=:61 and you are not attached to this xpra session anyway - it's only started and ready)

So the next thing is that we call kill -0 $PID to check that the process really is started (this just polls it, this is where we get the "Kein passender Prozess gefunden"). Can you try that too? (from another terminal since the one you will be launching xpra from will be blocked - you can find the pid with a simple "ps -ef | grep xpra")

Are there any special security restrictions on this box which would cause the kill to fail? SELinux or apparmor or something?
Another way to check is to simply disable the call to kill0 in the poll_server_process of winswitch/virt/server_util_base.py.
If that works, then we know that something is preventing our code from polling the process with kill -0.

[Thomas Käfer]

what should this kill command output?

kaefert@blechmobil:~$ ps -ef | grep xpra
kaefert   3974  3931  0 08:57 pts/1    00:00:00 /usr/bin/python /usr/bin/xpra --xvfb=/usr/bin/Xvfb +extension Composite -screen 0 3840x2560x24+32 -noreset --bind-tcp=127.0.0.1:15062 --no-daemon --no-pulseaudio --session-name=Terminal start :61
kaefert   4122  4077  0 08:58 pts/2    00:00:00 grep --colour=auto xpra
kaefert@blechmobil:~$ kill -0 3974
kaefert@blechmobil:~$ KILL -0 3974
KILL: command not found

I didn't setup anything like SELinux, but maybe there is something here out of the box in this Linux Mint Debian Edition distribution that I'm running on this machine.

[Antoine Martin]

That looks fine: it finds the pid via kill... (otherwise kill would have complained)

Just to confirm: judging by the logs, it should not make any difference whether you are connecting from another machine to this session or not, does it? What I mean is that the session fails to start, so where you are connecting from should not really matter..
*Unless*:

• this is a race issue and the kill -0 happens at the wrong time (when the session is not ready yet - somehow)
• it is the connection from the client which causes the server to crash. This you should be able to find out by looking at the ​session-debugging info I posted above: the xpra server log might have a crash in it, if we see a connection attempt in the log then this is likely the case.

What exact versions have you got installed? (both xpra and winswitch on all systems involved)

Apart from that, the only thing left for me to do is to install Linux Mint Debian Edition in a virtual machine and try to reproduce it there...

Can you profile full details, exact download links/version, packages list, etc.. Anything that might be relevant.

[Thomas Käfer]

The latest image for LMDE you can find here: ​http://blog.linuxmint.com/?p=1967
It does not really matter form what release you start, since "Linux Mint Debian Edition (LMDE) is a rolling distribution based on Debian Testing."
If you tell me of what packages you want to know the versions I can look them up.

With your "race issue" I wonder shouldn't I then be able to connect to an existing session? I tried both creating a new and reconnecting to an existing session.

The Ubuntu 11.04 machine that I used as the client is my PC at work, where I will only be again on wednesday.

[Thomas Käfer]

On the LMDE machine I have these versions installed:
winswitch 0.12.12-1
xpra 0.1.0-1

[Antoine Martin]

With your "race issue" I wonder shouldn't I then be able to connect to an existing session? I tried both creating a new and reconnecting to an existing session.

Hang on, so you were able to start sessions from somewhere else, right?
And when you try to connect from the problematic client, the session disappears? (ie: after the connection fails, can you still connect from other clients? I would think not?)

It does sound like a crash triggered by this specific client, see above for getting the debug info. You may also be able to trigger the crash by connecting with xpra directly (no need for winswitch).

[Thomas Käfer]

hmm, okey I now modified the config files in a way that the applet does not autostart a server, started the server manually with the session no delete and connected with my applet through an ssh tunnel to the same machine, hoping to reproduce the same problem, but that worked like a charm.

Endless logfiles also with a few error messages like:

[EE] 2012/23/04 10:05:58 XpraServerUtil.watch_existing_log(ServerSession(:61 - xpra - starting)) log_watcher already present: <__main__.GInotifyFileMonitor object at 0x3be1910 (GInotifyFileMonitor at 0x2d17a10)>

But as long as it does what it should everyting is fine I guess.

One other thing (should I open a new bug for this?)
I could not modify the client property start_local_server from true to false with the applet configuration GUI, I had to do it manually in the config file. It gave me this error:

[EE] 2012/23/04 10:15:03 ConfigureAppletWindow.commit_changes()
[ee] 2012/23/04 10:15:03 Traceback (most recent call last):
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/ui/config_common.py", line 630, in commit_changes
[ee] 2012/23/04 10:15:03     self.do_apply_changes()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/ui/config_applet.py", line 1022, in do_apply_changes
[ee] 2012/23/04 10:15:03     self.applet.settings_modified()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/client/applet.py", line 766, in settings_modified
[ee] 2012/23/04 10:15:03     self.init_client_utils()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/client/client_base.py", line 356, in init_client_utils
[ee] 2012/23/04 10:15:03     self.client_utils[session_type] = constructor()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/client/client_base.py", line 338, in rdp_common
[ee] 2012/23/04 10:15:03     return	RDPClientUtil(self.update_session_status, self.notify)
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/virt/rdp_client_util.py", line 18, in __init__
[ee] 2012/23/04 10:15:03     RDPClientBase.__init__(self, update_session_status, notify_callback)
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/virt/rdp_client_base.py", line 38, in __init__
[ee] 2012/23/04 10:15:03     ClientUtilBase.__init__(self, WINDOWS_TYPE, update_session_status, notify_callback)
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/virt/client_util_base.py", line 48, in __init__
[ee] 2012/23/04 10:15:03     self.options_defaults = self.load_options_defaults()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/virt/client_util_base.py", line 58, in load_options_defaults
[ee] 2012/23/04 10:15:03     props = self.get_options_defaults()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/virt/rdp_client_base.py", line 373, in get_options_defaults
[ee] 2012/23/04 10:15:03     d[KEYMAP] = self.get_default_keymap()
[ee] 2012/23/04 10:15:03   File "/usr/lib/pymodules/python2.7/winswitch/virt/rdp_client_base.py", line 85, in get_default_keymap
[ee] 2012/23/04 10:15:03     if k in self.keymaps.keys():
[ee] 2012/23/04 10:15:03 AttributeError: RDPClientUtil instance has no attribute 'keymaps'

For the other problem, thats much more interesting I can only continue to debug this the day after tomorrow, since I'm not at work today and tomorrow, and I don't have another machine at hand here.

[Antoine Martin]

The issue with the keymaps error is fixed in r4882 and was in ticket #186

r4893 prevents the XpraServerUtil.watch_existing_log error message you reported, thanks!

Are you saying that you cannot reproduce the problem anymore??
(Whether the server is embedded in the applet or not should not make any difference when it comes to polling the server processes - but maybe it does)

[Thomas Käfer]

No thats not what I was trying to say. What I meant was that I need the Ubuntu 11.04 box to reproduce it, which I will only have access to again the day after tomorrow.

[Thomas Käfer]

Okey, now I'm here. So I saw that for both my machines there are upgrades for xpra, I did not install them yet, so that I can document the problem before upgrading.

The versions installed on my Ubuntu 11.04 now are:
xpra 0.0.7.34-1
winswitch 0.12.12-1

My Ubuntu 11.04 prompts me to update to:
xpra 0.2.0-2
winswitch 0.12.13-1

My Linux Mint Debian Edition prompst me to update to:
xpra 0.2.0-2
winswitch 0.12.13-2

I now did the following (with still the old versions):
-) Start winswitch_server on LMDE
-) Start winswitch_applet on Ubuntu 11.04
-) Connect from Ubuntu 11.04 to LMDE through SSH-Tunnel
-) Start a gnome-terminal on the LMDE through winswitch
--> connection failed just like previous
-) Connecting through locally running client on the LMDE to the gnome-terminal --> works, unlike you suspected, the session survives the failed connection attempt.
-) trying to reconnect to the gnome-terminal session from Ubuntu 11.04 again.
--> failes again
I'll attach the logs, I also used the --no-delete-session-files, and will attach the xpra.log

Next I'm gonna try updating both sides and try again.

[Antoine Martin]

Hmmm, support for xpra versions older than 0.0.7.35 has been dropped, so this is not going to work, sorry. And I can't fix the buggy "Maverick" distro: packages won't build on it - then there's the 100% cpu bug and many many others.
Fortunately, the disaster distribution known as Maverick has already reached end-of-life. Please upgrade.

[Antoine Martin]

The suspicious lines from those log files are:

• in 2012-04-25_1030_winswitch_failure_client_log.txt:

  SimpleLineProcess.start() process(['/usr/bin/xpra', (...), 'attach', 'tcp:127.0.0.1:12461'])=<Process pid=4956 status=-1>
  ClientSession.fire_status_callbacks(available) (['connecting'], ['available'], <function connect_failed at 0x376a668>, True, 1335342492.761654)()=None
  process_util.subprocess_terminate(<winswitch.util.process_util.SimpleLineProcess instance at 0x3522368>,True)
  

Why it fires the available transition is not clear from this log extract. Did you run with --debug-mode?
Everything else looks correct, tunnels, etc.

• in 2012-04-25_1045_winswitch_failure_client_log.txt:

  process_util.subprocess_terminate(<winswitch.util.process_util.SimpleLineProcess instance at 0x3522830>,True)
  

Again, with nothing to indicate why it decided to terminate the client.

• nothing suspicious at all in 2012-04-25_1045_winswitch_failure_server_log.txt - apart from the connection timeout
• 2012-04-25_1045_xpra.log shows error related to older unsupported versions. Please upgrade.

[Thomas Käfer]

Yes, I ran with those options: --debug-mode --no-delete-session-files

Ok, so I'll upgrade. Sadly I am so stupid, that I forgot that my LMDE-machine at home has a bios password and will not boot automatically after issuing an reboot command... So I cannot test further today, sorry. Probably I won't be able to test until Monday the 30th April 2012.

[Thomas Käfer]

sorry I forgot to report the results here, Only wrote about my success in the IRC channel.
So for documentational purposes: Upgrading did solve the issues