[II] 2012/11/09 21:57:27 WinSwitchServer.start_session(User(Administrator : f629f85ae9424587bea966f155801421),xpra,Command(LXTerminal: lxterminal),,{'read_only': 'False', 'encoding': '""'},None)
[DD] 2012/11/09 21:57:27 WinSwitchServer.real_start_session(User(Administrator : f629f85ae9424587bea966f155801421),xpra,Command(LXTerminal: lxterminal),,{'read_only': 'False', 'encoding': '""'},None)
[DD] 2012/11/09 21:57:27 XpraServerUtil.get_prelaunch_session(f629f85ae9424587bea966f155801421,nathan,,{'read_only': 'False', 'encoding': '""'}) going to test: [ServerSession(:66 - xpra - available)]
[DD] 2012/11/09 21:57:27 XpraServerUtil.is_prelaunched_session_compatible(ServerSession(:66 - xpra - available),,{'read_only': 'False', 'encoding': '""'}) prelaunch session options are not compatible with request: {}
[DD] 2012/11/09 21:57:27 XpraServerUtil.get_prelaunch_session(f629f85ae9424587bea966f155801421,nathan,,{'read_only': 'False', 'encoding': '""'}) session ServerSession(:66 - xpra - available) is not compatible
[DD] 2012/11/09 21:57:27 XpraServerUtil.do_start_session(User(Administrator : f629f85ae9424587bea966f155801421),nathan,Command(LXTerminal: lxterminal),False,,{'read_only': 'False', 'encoding': '""'},None)
[DD] 2012/11/09 21:57:27 XpraServerUtil.initialize_session_from_command(ServerSession(:69 -  - ),Command(LXTerminal: lxterminal)) now set name=LXTerminal, uses_sound_out=False, uses_sound_in=False
[DD] 2012/11/09 21:57:27 XpraServerUtil.initialize_new_session(nathan,Command(LXTerminal: lxterminal),False,,:69,15070)=ServerSession(:69 - xpra - starting)
[DD] 2012/11/09 21:57:27 XpraServerUtil.start_dbus() dbus_command=dbus-daemon --fork --print-address=1 --print-pid=1 --session
[DD] 2012/11/09 21:57:27 XpraServerUtil.start_dbus(ServerSession(:69 - xpra - starting)) output(dbus-daemon --fork --print-address=1 --print-pid=1 --session)=(0,unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4\n14123\n)
[II] 2012/11/09 21:57:27 XpraServerUtil.start_dbus(ServerSession(:69 - xpra - starting)) dbus_pid=14123, dbus_address=unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4
[DD] 2012/11/09 21:57:27 XpraServerUtil.start_sound_server(ServerSession(:69 - xpra - starting)) existing pulse_pid=-1, pulseaudio_command=/usr/bin/pulseaudio
[DD] 2012/11/09 21:57:27 file_io.get_sub_dir(/home/nathan/.winswitch/server/sessions,69,False,511) directory /home/nathan/.winswitch/server/sessions/69 does not exist, creating it
[II] 2012/11/09 21:57:27 virt_server_daemonizer.grab_daemon_pid(['/usr/lib/winswitch/virt_server_daemonizer', '--quiet', '--print-pid', '--daemon', '--log-file', '/home/nathan/.winswitch/server/sessions/69/pulse.log', '--', '/usr/bin/pulseaudio', '--start', '-vvvv', '--disable-shm=true', '--daemonize=false', '--use-pid-file=false', '--system=false', '--exit-idle-time=-1', '-n', '--load=module-suspend-on-idle', '--load=module-null-sink', '--load=module-native-protocol-unix socket=/tmp/pulse-69/native'],None,{'LANG': 'en_GB.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'DBUS_SESSION_BUS_ADDRESS': 'unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4', 'PWD': '/home/nathan', 'USER': 'nathan', 'HOME': '/home/nathan/.winswitch/server/sessions/69', 'PATH': '/home/nathan/bin:/usr/lib/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'DISPLAY': ':69'}) <subprocess.Popen object at 0x3677f10>.returncode=0, stdoutdata=14131\n, stderrdata=, pid=14131
[DD] 2012/11/09 21:57:27 XpraServerUtil.start_sound_server(ServerSession(:69 - xpra - starting)) pulseaudio pid=14131
[DD] 2012/11/09 21:57:27 file_io.save_object_to_properties(ServerSession(:69 - xpra - starting),None,None) /home/nathan/.winswitch/server/sessions/69/config.txt
[DD] 2012/11/09 21:57:27 XpraServerUtil.start_display(ServerSession(:69 - xpra - starting),User(Administrator : f629f85ae9424587bea966f155801421),False,False)
[II] 2012/11/09 21:57:27 XpraServerUtil.start_daemon(ServerSession(:69 - xpra - starting),{'LANG': 'en_GB.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'DBUS_SESSION_BUS_ADDRESS': 'unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4', 'PWD': '/home/nathan', 'PULSE_SERVER': 'unix:/tmp/pulse-69/native', 'USER': 'nathan', 'HOME': '/home/nathan', 'PATH': '/home/nathan/bin:/usr/lib/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'DISPLAY': ':69', 'ALSA_PCM_NAME': 'pulse'},True) starting ['/usr/bin/xpra', '--bind-tcp=127.0.0.1:15070', '--password-file=/home/nathan/.winswitch/server/sessions/69/session.pass', '--no-daemon', '--no-pulseaudio', '--session-name=LXTerminal', 'start', ':69'], logging to /home/nathan/.winswitch/server/sessions/69/xpra.log
[II] 2012/11/09 21:57:28 virt_server_daemonizer.grab_daemon_pid(['/usr/lib/winswitch/virt_server_daemonizer', '--quiet', '--print-pid', '--daemon', '--log-file', '/home/nathan/.winswitch/server/sessions/69/xpra.log', '--', '/usr/bin/xpra', '--bind-tcp=127.0.0.1:15070', '--password-file=/home/nathan/.winswitch/server/sessions/69/session.pass', '--no-daemon', '--no-pulseaudio', '--session-name=LXTerminal', 'start', ':69'],/home/nathan,{'LANG': 'en_GB.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'DBUS_SESSION_BUS_ADDRESS': 'unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4', 'PWD': '/home/nathan', 'PULSE_SERVER': 'unix:/tmp/pulse-69/native', 'USER': 'nathan', 'HOME': '/home/nathan', 'PATH': '/home/nathan/bin:/usr/lib/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'DISPLAY': ':69', 'ALSA_PCM_NAME': 'pulse'}) <subprocess.Popen object at 0x3680090>.returncode=0, stdoutdata=14141\n, stderrdata=, pid=14141
[II] 2012/11/09 21:57:28 XpraServerUtil.session_process_started(14141,ServerSession(:69 - xpra - starting))
[DD] 2012/11/09 21:57:28 XpraServerUtil.watch_session_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - starting))
[DD] 2012/11/09 21:57:28 XpraServerUtil.watch_session_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - starting)) logfile=18
[DD] 2012/11/09 21:57:28 XpraServerUtil.do_watch_session_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) will use gio to monitor for changes
[II] 2012/11/09 21:57:28 XpraServerUtil.do_watch_session_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) watching log with gio: <__main__.GInotifyFileMonitor object at 0x367e640 (GInotifyFileMonitor at 0x2e993c0)>
[DD] 2012/11/09 21:57:28 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting))
[DD] 2012/11/09 21:57:28 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:28 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) read 0 bytes
[DD] 2012/11/09 21:57:28 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - starting)) pid=14141
[DD] 2012/11/09 21:57:28 process_util.kill0(14141) pid is still alive
[DD] 2012/11/09 21:57:28 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - starting)) pid=14141
[DD] 2012/11/09 21:57:28 process_util.kill0(14141) pid is still alive
[DD] 2012/11/09 21:57:28 XpraServerUtil.start_session_object(ServerSession(:69 - xpra - starting),User(Administrator : f629f85ae9424587bea966f155801421),False) started=True
[DD] 2012/11/09 21:57:28 FirewallUtil.call_script(['ADD', '127.0.0.1', '15070']) firewall_script=/usr/lib/winswitch/firewall
[DD] 2012/11/09 21:57:28 FirewallUtil.call_script(['ALLOW', '127.0.0.1', '127.0.0.1', '15070']) firewall_script=/usr/lib/winswitch/firewall
[DD] 2012/11/09 21:57:28 file_io.save_object_to_properties(ServerSession(:69 - xpra - starting),None,None) /home/nathan/.winswitch/server/sessions/69/config.txt
[DD] 2012/11/09 21:57:28 WinSwitchServer.add_new_session(ServerSession(:69 - xpra - starting)) can_capture=True, screen_capture_command=/usr/bin/import -screen -silent -window root -compress JPEG jpeg:
[II] 2012/11/09 21:57:28 WinSwitchServer.send_session_to_all(ServerSession(:69 - xpra - starting)) clients=[WinSwitchClientChannel(User(Administrator : f629f85ae9424587bea966f155801421))]
[II] 2012/11/09 21:57:28 XpraServerUtil.wait_for_session_readyness(ServerSession(:69 - xpra - starting),User(Administrator : f629f85ae9424587bea966f155801421),<function session_started at 0x367f0c8>,<function session_error at 0x367f140>) adding/firing session status update callbacks
[DD] 2012/11/09 21:57:28 ProtocolHandler.send_session_icon(ServerSession(:69 - xpra - starting),True) no icon data available...
[DD] 2012/11/09 21:57:29 XpraServerUtil.watched_directory_changed(<__main__.GInotifyDirectoryMonitor object at 0x7f6dc4241050 (GInotifyDirectoryMonitor at 0x3250b10)>,<__main__.GLocalFile at 0x367e550: file:///home/nathan/.xpra/hostname.net-69>,None,<enum G_FILE_MONITOR_EVENT_CREATED of type GFileMonitorEvent>)
[DD] 2012/11/09 21:57:29 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:29 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) read_pending=False
[DD] 2012/11/09 21:57:29 XpraServerUtil.batch_detect_sessions()
[II] 2012/11/09 21:57:29 XpraServerUtil.detect_sessions() found: [('LIVE', ':66'), ('LIVE', ':69')]
[DD] 2012/11/09 21:57:29 XpraServerUtil.with_version(False) xpra_version=0.6.0
[DD] 2012/11/09 21:57:29 XpraServerUtil.with_version() xpra version is up to date
[DD] 2012/11/09 21:57:29 XpraServerUtil.with_version(False) xpra_version=0.6.0
[DD] 2012/11/09 21:57:29 XpraServerUtil.with_version() xpra version is up to date
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) started thread: 140109536573184
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting))
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) read 829 bytes
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - starting)) read 11 lines
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) reloading=False, lines=['[dix] Could not init font path element /usr/share/fonts/X11/cyrillic, removing from list!\n', '[dix] Could not init font path element /usr/share/fonts/X11/75dpi/:unscaled, removing from list!\n', '[dix] Could not init font path element /usr/share/fonts/X11/75dpi, removing from list!\n', 'Xlib:  extension "RANDR" missing on display ":69".\n', 'Xlib:  extension "RANDR" missing on display ":69".\n', 'Xlib:  extension "RANDR" missing on display ":69".\n', '2012-09-11 21:57:28,253 Randr not supported: X server does not support required extension Randr\n', '2012-09-11 21:57:28,274 using notification forwarder: DBUSNotificationsForwarder(org.freedesktop.Notifications)\n', '2012-09-11 21:57:28,275 xpra server version 0.6.0\n', '2012-09-11 21:57:28,289 xpra is ready.\n', '2012-09-11 21:57:29,175 New connection received: SocketConnection(/home/nathan/.xpra/hostname.net-69 - )\n']
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status([dix] Could not init font path element /usr/share/fonts/X11/cyrillic, removing from list!\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status([dix] Could not init font path element /usr/share/fonts/X11/75dpi/:unscaled, removing from list!\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status([dix] Could not init font path element /usr/share/fonts/X11/75dpi, removing from list!\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status(Xlib:  extension "RANDR" missing on display ":69".\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),[[dix] Could not init font path element /usr/share/fonts/X11/cyrillic, removing from list!, [dix]...) previous line repeated 2 times!
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status(2012-09-11 21:57:28,253 Randr not supported: X server does not support required extension Randr\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status(2012-09-11 21:57:28,274 using notification forwarder: DBUSNotificationsForwarder(org.freedesktop.Notifications)\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status(2012-09-11 21:57:28,275 xpra server version 0.6.0\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status(2012-09-11 21:57:28,289 xpra is ready.\n)=available
[II] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) setting new status=available from line=2012-09-11 21:57:28,289 xpra is ready.\n
[II] 2012/11/09 21:57:29 WinSwitchServer.send_session_status_to_all(ServerSession(:69 - xpra - starting),available) clients=[WinSwitchClientChannel(User(Administrator : f629f85ae9424587bea966f155801421))]
[DD] 2012/11/09 21:57:29 ServerSession.fire_status_callbacks(available) (None, None, <function status_change_schedule_capture at 0x367f050>, False, None): <function status_change_schedule_capture at 0x367f050>()=False
[DD] 2012/11/09 21:57:29 file_io.save_object_to_properties(ServerSession(:69 - xpra - available),None,None) /home/nathan/.winswitch/server/sessions/69/config.txt
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_session_command(ServerSession(:69 - xpra - available)) start_gnome_keyring_daemon=True
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_gnome_keyring_daemon(ServerSession(:69 - xpra - available)) listdir(/home/nathan/.winswitch/server/sessions/69/gnome-keyring)=[]
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - starting),11 lines) new status(2012-09-11 21:57:29,175 New connection received: SocketConnection(/home/nathan/.xpra/hostname.net-69 - )\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - available)) pid=14141
[DD] 2012/11/09 21:57:29 process_util.kill0(14141) pid is still alive
[II] 2012/11/09 21:57:29 XpraServerUtil.start_gnome_keyring_daemon(ServerSession(:69 - xpra - available)) gnome_keyring_env={'GNOME_KEYRING_CONTROL': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring', 'SSH_AUTH_SOCK': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/ssh', 'GPG_AGENT_INFO': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/gpg:0:1', 'GNOME_KEYRING_PID': '14162'}, pid=14162
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_session_wrapper() XDG_OPEN_COMMAND=/usr/bin/xdg-open, WSW_XDG_OPEN=/usr/lib/pymodules/python2.7/winswitch/server/xdg_open.pyc, valid exe=True
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_session_wrapper(ServerSession(:69 - xpra - available)) args=[/usr/lib/winswitch/delayed_start, /home/nathan/.winswitch/server/sessions/69/config.txt, --print-pid, --daemon, --log-file, /home/nathan/.winswitch/server/sessions/69/command.log], env={'_WINSWITCH_SERVER_PID': '13383', 'USER': 'nathan', 'QT_GRAPHICSSYSTEM': 'native', 'HOME': '/home/nathan', 'DISPLAY': ':69', 'GNOME_KEYRING_CONTROL': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring', 'LANG': 'en_GB.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'WINSWITCH_SERVER': '0.12.16', 'WSW_SESSION_ID': '991eebeeba6347ba939dda6b294addf4', 'GPG_AGENT_INFO': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/gpg:0:1', 'SSH_AUTH_SOCK': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/ssh', 'WSW_XDG_OPEN': '/usr/lib/pymodules/python2.7/winswitch/server/xdg_open.pyc', 'PATH': '/usr/lib/winswitch/bin-override:/home/nathan/bin:/usr/lib/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'PULSE_SERVER': 'unix:/tmp/pulse-69/native', 'DBUS_SESSION_BUS_ADDRESS': 'unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4', 'ORBIT_SOCKETDIR': '/home/nathan/.winswitch/server/sessions/69/pulse-69', 'GNOME_KEYRING_PID': '14162', 'PWD': '/home/nathan', 'WSW_ORIGINAL_XDG_OPEN': '/usr/bin/xdg-open', 'ALSA_PCM_NAME': 'pulse'}, session_file=/home/nathan/.winswitch/server/sessions/69/config.txt
[DD] 2012/11/09 21:57:29 file_io.save_object_to_properties(ServerSession(:69 - xpra - available),None,None) /home/nathan/.winswitch/server/sessions/69/config.txt
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_session_wrapper(ServerSession(:69 - xpra - available)) proc=<subprocess.Popen object at 0x3677fd0>
[II] 2012/11/09 21:57:29 XpraServerUtil.start_session_wrapper(ServerSession(:69 - xpra - available)) pid(['/usr/lib/winswitch/delayed_start', '/home/nathan/.winswitch/server/sessions/69/config.txt', '--print-pid', '--daemon', '--log-file', '/home/nathan/.winswitch/server/sessions/69/command.log'])=14219
[DD] 2012/11/09 21:57:29 FirewallUtil.call_script(['ALLOW', '127.0.0.1', '127.0.0.1', '15070']) firewall_script=/usr/lib/winswitch/firewall
[DD] 2012/11/09 21:57:29 WinSwitchServer.prepare_and_send_session_to_user(ServerSession(:69 - xpra - available),User(Administrator : f629f85ae9424587bea966f155801421)) display_util=<winswitch.virt.xpra_server_util.XpraServerUtil instance at 0x7f6dc4225200>, deadline=1347397079.7
[DD] 2012/11/09 21:57:29 FirewallUtil.call_script(['ALLOW', '127.0.0.1', '127.0.0.1', '15070']) firewall_script=/usr/lib/winswitch/firewall
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_prepare_session_for_attach(ServerSession(:69 - xpra - available),User(Administrator : f629f85ae9424587bea966f155801421),<function session_prepared at 0x3676f50>) current status=available
[DD] 2012/11/09 21:57:29 WinSwitchServer.session_prepared()
[II] 2012/11/09 21:57:29 WinSwitchServer.do_send_session_to_user(ServerSession(:69 - xpra - available),f629f85ae9424587bea966f155801421,1347397079.7) found matching channel WinSwitchClientChannel(User(Administrator : f629f85ae9424587bea966f155801421))
[II] 2012/11/09 21:57:29 WinSwitchServer.send_session_status_to_all(ServerSession(:69 - xpra - available),connecting) clients=[WinSwitchClientChannel(User(Administrator : f629f85ae9424587bea966f155801421))]
[DD] 2012/11/09 21:57:29 ServerSession.fire_status_callbacks(connecting) (None, None, <function status_change_schedule_capture at 0x367f050>, False, None): <function status_change_schedule_capture at 0x367f050>()=False
[DD] 2012/11/09 21:57:29 WinSwitchServer.update_session_status(ServerSession(:69 - xpra - connecting),connecting,None) connecting_timeout=20
[II] 2012/11/09 21:57:29 WinSwitchServer.send_session_status_to_all(ServerSession(:69 - xpra - connecting),None) clients=[WinSwitchClientChannel(User(Administrator : f629f85ae9424587bea966f155801421))]
[DD] 2012/11/09 21:57:29 ServerSession.fire_status_callbacks(available) (['starting'], ['available'], <function session_started at 0x367f0c8>, True, 1347397078.06351): <function session_started at 0x367f0c8>()=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:29 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read_pending=False
[DD] 2012/11/09 21:57:29 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) started thread: 140109536573184
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting))
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read 40 bytes
[DD] 2012/11/09 21:57:29 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read 1 lines
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - connecting),1 lines) reloading=False, lines=['2012-09-11 21:57:29,177 Connection lost\n']
[DD] 2012/11/09 21:57:29 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - connecting),1 lines) new status(2012-09-11 21:57:29,177 Connection lost\n)=None
[DD] 2012/11/09 21:57:29 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - connecting)) pid=14141
[DD] 2012/11/09 21:57:29 process_util.kill0(14141) pid is still alive
[DD] 2012/11/09 21:57:30 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:30 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read_pending=False
[DD] 2012/11/09 21:57:30 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:30 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read_pending=False
[DD] 2012/11/09 21:57:30 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) started thread: 140109536573184
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available))
[DD] 2012/11/09 21:57:30 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) started thread: 140109517018880
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting))
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read 145 bytes
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read 2 lines
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read 151 bytes
[DD] 2012/11/09 21:57:30 XpraServerUtil.process_log_data(ServerSession(:66 - xpra - available),2 lines) reloading=False, lines=['2012-09-11 21:57:29,175 New connection received: SocketConnection(/home/nathan/.xpra/hostname.net-66 - )\n', '2012-09-11 21:57:29,177 Connection lost\n']
[DD] 2012/11/09 21:57:30 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read 2 lines
[DD] 2012/11/09 21:57:30 XpraServerUtil.process_log_data(ServerSession(:66 - xpra - available),2 lines) new status(2012-09-11 21:57:29,175 New connection received: SocketConnection(/home/nathan/.xpra/hostname.net-66 - )\n)=None
[DD] 2012/11/09 21:57:30 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - connecting),2 lines) reloading=False, lines=["2012-09-11 21:57:30,128 New connection received: SocketConnection(('127.0.0.1', 15070) - ('127.0.0.1', 52909))\n", '2012-09-11 21:57:30,289 Connection lost\n']
[DD] 2012/11/09 21:57:30 XpraServerUtil.process_log_data(ServerSession(:66 - xpra - available),2 lines) new status(2012-09-11 21:57:29,177 Connection lost\n)=None
[DD] 2012/11/09 21:57:30 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - connecting),2 lines) new status(2012-09-11 21:57:30,128 New connection received: SocketConnection(('127.0.0.1', 15070) - ('127.0.0.1', 52909))\n)=None
[DD] 2012/11/09 21:57:30 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/66/xpra.log,ServerSession(:66 - xpra - available)) pid=13688
[DD] 2012/11/09 21:57:30 XpraServerUtil.process_log_data(ServerSession(:69 - xpra - connecting),2 lines) new status(2012-09-11 21:57:30,289 Connection lost\n)=None
[DD] 2012/11/09 21:57:30 process_util.kill0(13688) pid is still alive
[DD] 2012/11/09 21:57:30 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - connecting)) pid=14141
[DD] 2012/11/09 21:57:30 process_util.kill0(14141) pid is still alive
[DD] 2012/11/09 21:57:31 WinSwitchServer.capture_err(cannot capture ServerSession(:69 - xpra - connecting) at the moment..)
[DD] 2012/11/09 21:57:31 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:31 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read_pending=False
[DD] 2012/11/09 21:57:31 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:31 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read_pending=False
[DD] 2012/11/09 21:57:31 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) started thread: 140109517018880
[DD] 2012/11/09 21:57:31 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available))
[DD] 2012/11/09 21:57:31 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:31 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting))
[DD] 2012/11/09 21:57:31 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) started thread: 140109536573184
[DD] 2012/11/09 21:57:31 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:31 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read 0 bytes
[DD] 2012/11/09 21:57:31 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/66/xpra.log,ServerSession(:66 - xpra - available)) pid=13688
[DD] 2012/11/09 21:57:31 process_util.kill0(13688) pid is still alive
[DD] 2012/11/09 21:57:31 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read 0 bytes
[DD] 2012/11/09 21:57:31 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - connecting)) pid=14141
[DD] 2012/11/09 21:57:31 process_util.kill0(14141) pid is still alive
[DD] 2012/11/09 21:57:32 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:32 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read_pending=False
[DD] 2012/11/09 21:57:32 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:32 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read_pending=False
[DD] 2012/11/09 21:57:32 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) started thread: 140109536573184
[DD] 2012/11/09 21:57:32 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available))
[DD] 2012/11/09 21:57:32 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:32 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/66/xpra.log,16,ServerSession(:66 - xpra - available)) read 0 bytes
[DD] 2012/11/09 21:57:32 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/66/xpra.log,ServerSession(:66 - xpra - available)) pid=13688
[DD] 2012/11/09 21:57:32 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) started thread: 140109517018880
[DD] 2012/11/09 21:57:32 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting))
[DD] 2012/11/09 21:57:32 process_util.kill0(13688) pid is still alive
[DD] 2012/11/09 21:57:32 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:32 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - connecting)) read 0 bytes
[DD] 2012/11/09 21:57:32 XpraServerUtil.poll_server_process(/home/nathan/.winswitch/server/sessions/69/xpra.log,ServerSession(:69 - xpra - connecting)) pid=14141
[DD] 2012/11/09 21:57:32 process_util.kill0(14141) pid is still alive
[DD] 2012/11/09 21:57:37 XpraServerUtil.do_disable_gnome_screensaver(ServerSession(:69 - xpra - connecting))
[II] 2012/11/09 21:57:37 virt_server_daemonizer.grab_daemon_pid(['/usr/lib/winswitch/virt_server_daemonizer', '--quiet', '--print-pid', '--daemon', '--log-file', '/home/nathan/.winswitch/server/sessions/69/dbus-send-disable-gnome-screensaver.log', '--', 'dbus-send', '--session', '--dest=org.gnome.ScreenSaver', '--print-reply', '--type=method_call', '--reply-timeout=20000', '/org/gnome/ScreenSaver', 'org.gnome.ScreenSaver.Inhibit', 'string:"Window Switch"', 'string:"Virtual Session"'],None,{'LANG': 'en_GB.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'GNOME_KEYRING_PID': '14162', 'SSH_AUTH_SOCK': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/ssh', 'ORBIT_SOCKETDIR': '/home/nathan/.winswitch/server/sessions/69/pulse-69', 'DISPLAY': ':69', 'PWD': '/home/nathan', 'PULSE_SERVER': 'unix:/tmp/pulse-69/native', 'USER': 'nathan', 'HOME': '/home/nathan', 'PATH': '/home/nathan/bin:/usr/lib/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'GPG_AGENT_INFO': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/gpg:0:1', 'DBUS_SESSION_BUS_ADDRESS': 'unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4', 'GNOME_KEYRING_CONTROL': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring', 'ALSA_PCM_NAME': 'pulse'}) <subprocess.Popen object at 0x3677f90>.returncode=0, stdoutdata=14317\n, stderrdata=, pid=14317
[DD] 2012/11/09 21:57:37 XpraServerUtil.do_disable_xscreensaver(ServerSession(:69 - xpra - connecting))
[II] 2012/11/09 21:57:37 process_util.exec_nopipe(['/usr/bin/xscreensaver-command', '-exit'],{'LANG': 'en_GB.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'GNOME_KEYRING_PID': '14162', 'SSH_AUTH_SOCK': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/ssh', 'ORBIT_SOCKETDIR': '/home/nathan/.winswitch/server/sessions/69/pulse-69', 'DISPLAY': ':69', 'PWD': '/home/nathan', 'PULSE_SERVER': 'unix:/tmp/pulse-69/native', 'USER': 'nathan', 'HOME': '/home/nathan', 'PATH': '/home/nathan/bin:/usr/lib/ccache:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'GPG_AGENT_INFO': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring/gpg:0:1', 'DBUS_SESSION_BUS_ADDRESS': 'unix:abstract=/tmp/dbus-RbrSHe6MvY,guid=7484208738b0e4ffe5c1985200129ea4', 'GNOME_KEYRING_CONTROL': '/home/nathan/.winswitch/server/sessions/69/gnome-keyring', 'ALSA_PCM_NAME': 'pulse'},None,False,False,None,True)=<subprocess.Popen object at 0x3677fd0>
[II] 2012/11/09 21:57:49 WinSwitchServer.connecting_timeout(ServerSession(:69 - xpra - connecting),2) connection timed out
[DD] 2012/11/09 21:57:49 WinSwitchServer.remove_actor(ServerSession(:69 - xpra - connecting)) actor=f629f85ae9424587bea966f155801421
[DD] 2012/11/09 21:57:49 FirewallUtil.call_script(['REMOVE', '127.0.0.1', '127.0.0.1', '15070']) firewall_script=/usr/lib/winswitch/firewall
[II] 2012/11/09 21:57:49 WinSwitchServer.send_session_status_to_all(ServerSession(:69 - xpra - connecting),available) clients=[WinSwitchClientChannel(User(Administrator : f629f85ae9424587bea966f155801421))]
[DD] 2012/11/09 21:57:49 XpraServerUtil.verify_connected() checking session ServerSession(:69 - xpra - available): previous count=2, current status_update_count=3
[DD] 2012/11/09 21:57:50 XpraServerUtil.session_logfile_changed()
[DD] 2012/11/09 21:57:50 XpraServerUtil.read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - available)) read_pending=False
[DD] 2012/11/09 21:57:50 XpraServerUtil.start_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - available)) started thread: 140109517018880
[DD] 2012/11/09 21:57:50 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - available))
[DD] 2012/11/09 21:57:50 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/69/xpra.log,18,ServerSession(:69 - xpra - available)) about to read, current buffer: 0 bytes
[DD] 2012/11/09 21:57:50 XpraServerUtil.do_read_from_log(/home/nathan/.winswitch/server/sessions/