xpra icon
Bug tracker and wiki

This bug tracker and wiki are being discontinued
please use https://github.com/Xpra-org/xpra instead.


Opened 8 years ago

Last modified 5 months ago

#329 closed defect

Sound sink underruns seem to lead to spinners and eventual ping timeouts (for win32 clients) — at Version 1

Reported by: alas Owned by: Antoine Martin
Priority: major Milestone: 0.10
Component: client Version:
Keywords: Cc:

Description (last modified by Antoine Martin)

Using win client 0.9.0 r3152 and fedora server 0.9.0 r3163 over an internet connection, with several tabs open and video playing... the client starts experiencing sound sink queue underruns, which create choppiness for the whole client and eventually start to lead to paint_spinners and a connection crash.

I'm not sure if this is just a matter of connection issues or if there's something else going on. Below are the -d all logs from the time of one of the crashes (from the client side)

2013-05-07 20:00:13,361 mask_to_names(<flags 0 of type GdkModifierType>)=['mod2']
2013-05-07 20:00:13,377 mask_to_names(<flags 0 of type GdkModifierType>) GetKeyState(VK_NUMLOCK)=1
2013-05-07 20:00:13,378 mask_to_names(<flags 0 of type GdkModifierType>)=['mod2']
2013-05-07 20:00:13,392 mask_to_names(<flags 0 of type GdkModifierType>) GetKeyState(VK_NUMLOCK)=1
2013-05-07 20:00:13,394 mask_to_names(<flags 0 of type GdkModifierType>)=['mod2']
2013-05-07 20:00:13,552 check_echo_timeout(1367981953553) last_ping_echoed_time=1367981953553
2013-05-07 20:00:13,563 average server latency=1752.4, using max wait 4.50s
2013-05-07 20:00:18,071 check_server_echo: server is not responding, redrawing spinners over the windows
2013-05-07 20:00:18,076 paint_spinner(<gtk.gdk.CairoContext object at 0x02B00360>, gtk.gdk.Rectangle(0, 0, 834, 716))
2013-05-07 20:00:18,177 paint_spinner(<gtk.gdk.CairoContext object at 0x02B00360>, gtk.gdk.Rectangle(0, 0, 834, 716))
2013-05-07 20:00:18,276 paint_spinner(<gtk.gdk.CairoContext object at 0x02B00360>, gtk.gdk.Rectangle(0, 0, 834, 716))
2013-05-07 20:00:18,377 paint_spinner(<gtk.gdk.CairoContext object at 0x02B00360>, gtk.gdk.Rectangle(0, 0, 834, 716))
2013-05-07 20:00:18,480 sound sink: adding 104 bytes, {}
2013-05-07 20:00:18,483 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-05-07 20:00:18,483 sound sink queue underrun
2013-05-07 20:00:18,572 check_server_echo: server is OK again, stopping redraw2013-05-07 20:00:23,553 check_echo_timeout(1367981963553) last_ping_echoed_time=1367981953553
2013-05-07 20:00:23,555 server ping timeout - waited 60 seconds without a response
2013-05-07 20:00:23,555 XpraClient.quit(2) current exit_code=None
2013-05-07 20:00:23,555 XpraClient.cleanup() client_extras=<xpra.win32.gui.ClientExtras object at 0x02B637D0>
2013-05-07 20:00:23,556 ClientExtras.cleanup() tray=<xpra.win32.win32_tray.Win32Tray instance at 0x04B4A8F0>
2013-05-07 20:00:23,558 ClientExtrasBase.cleanup() session_info_window=None, gtk.main_level()=1
2013-05-07 20:00:23,558 ClientExtrasBase.cleanup() done
2013-05-07 20:00:23,559 ClientExtras.cleanup() calling tray.close=<bound methodWin32Tray.close of <xpra.win32.win32_tray.Win32Tray instance at 0x04B4A8F0>>
2013-05-07 20:00:23,559 Win32Tray.close() tray_widget=<xpra.win32.win32_NotifyIcon.win32NotifyIcon instance at 0x04B558A0>
2013-05-07 20:00:23,561 win32NotifyIcon.close() exit_callback=<function tray_exit at 0x04B4B730>
2013-05-07 20:00:23,563 OnDestroy(0,None,None,None) closed=False, exit_callback=None
2013-05-07 20:00:23,565 OnDestroy(..) calling Shell_NotifyIcon(NIM_DELETE, (525884, 0))
2013-05-07 20:00:23,595 OnDestroy(..) calling exit_callback=None
2013-05-07 20:00:23,596 detect_win32_session_events(None) missing handle!
2013-05-07 20:00:23,598 Win32Tray.close() ended
2013-05-07 20:00:23,598 ClientExtras.cleanup() ended
2013-05-07 20:00:23,599 XpraClient.stop_receiving_sound()
2013-05-07 20:00:23,601 SoundPipeline.cleanup()
2013-05-07 20:00:23,601 SoundPipeline.stop()
2013-05-07 20:00:23,628 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-05-07 20:00:23,653 SoundPipeline.stop() done
2013-05-07 20:00:23,654 SoundPipeline.cleanup() done
2013-05-07 20:00:23,655 sound: client_signalled_change(<XpraClient object at 0x290e6c0 (xpra+client+XpraClient at 0x238db30)>) is_on=False
2013-05-07 20:00:23,657 spk_off(())
2013-05-07 20:00:23,657 XpraClient.stop_receiving_sound()
2013-05-07 20:00:23,658 stop_receiving_sound: sound not started!
2013-05-07 20:00:23,660 XpraClient.stop_receiving_sound() done
2013-05-07 20:00:23,661 XpraClientBase.cleanup() protocol=Protocol(SocketConnection(('10.0.11.67', 52994) - ('107.6.90.194', 1201)))
2013-05-07 20:00:23,661 connection closed after 140854 packets received (164730258 bytes) and 19349 packets sent (638945 bytes)
2013-05-07 20:00:23,663 XpraClient.clean_mmap() mmap_file=None
2013-05-07 20:00:23,664 write thread: empty marker, exiting
2013-05-07 20:00:23,664 read thread: empty marker, exiting
2013-05-07 20:00:23,665 update_focus(2,False) _focused=2
2013-05-07 20:00:23,667 mask_to_names(<flags 0 of type GdkModifierType>) GetKeyState(VK_NUMLOCK)=1
2013-05-07 20:00:23,668 mask_to_names(<flags 0 of type GdkModifierType>)=['mod2']
2013-05-07 20:00:23,670 <class 'xpra.window_backing.PixmapBacking'>.close() video_decoder=<xpra.x264.codec.Decoder object at 0x02BD4D70>
2013-05-07 20:00:23,677 unknown win32 message: 28 / 0 / 2452
2013-05-07 20:00:23,688 XpraClient.cleanup() done
2013-05-07 20:00:23,690 XpraClient.quit(2) main loop at level 1, calling gtk quit via timeout
2013-05-07 20:00:23,690 average server latency=1752.4, using max wait 4.50s
2013-05-07 20:00:23,693 Connection lost
2013-05-07 20:00:23,694 XpraClient.quit(1) current exit_code=2
2013-05-07 20:00:23,694 XpraClient.cleanup() client_extras=<xpra.win32.gui.ClientExtras object at 0x02B637D0>
2013-05-07 20:00:23,696 ClientExtras.cleanup() tray=None
2013-05-07 20:00:23,698 ClientExtrasBase.cleanup() session_info_window=None, gtk.main_level()=1
2013-05-07 20:00:23,700 ClientExtrasBase.cleanup() done
2013-05-07 20:00:23,701 ClientExtras.cleanup() ended
2013-05-07 20:00:23,703 XpraClientBase.cleanup() protocol=None
2013-05-07 20:00:23,704 XpraClient.clean_mmap() mmap_file=None
2013-05-07 20:00:23,706 XpraClient.cleanup() done
2013-05-07 20:00:23,707 XpraClient.quit(1) main loop at level 1, calling gtk quit via timeout
2013-05-07 20:00:24,190 XpraClient.run() main loop ended, returning exit_code=2
2013-05-07 20:00:24,191 XpraClient.cleanup() client_extras=<xpra.win32.gui.ClientExtras object at 0x02B637D0>
2013-05-07 20:00:24,193 ClientExtras.cleanup() tray=None
2013-05-07 20:00:24,193 ClientExtrasBase.cleanup() session_info_window=None, gtk.main_level()=0
2013-05-07 20:00:24,194 ClientExtrasBase.cleanup() done
2013-05-07 20:00:24,194 ClientExtras.cleanup() ended
2013-05-07 20:00:24,194 XpraClientBase.cleanup() protocol=None
2013-05-07 20:00:24,196 XpraClient.clean_mmap() mmap_file=None
2013-05-07 20:00:24,196 XpraClient.cleanup() done

C:\Program Files (x86)\Xpra>

Change History (2)

comment:1 Changed 8 years ago by Antoine Martin

Description: modified (diff)
Milestone: 0.10
Status: newassigned

Which codec was this?
What sort of internet connection is this?
What was the bandwidth usage at the time?

average server latency=1752.4

A latency of over a second is going to be problematic! (maybe sound data is overloading the connection?)

PS: please use shell redirection to capture log files so I don't have to edit the log to remove the idiotic carriage returns added by the obnoxious windows dos window.

Changed 8 years ago by alas

Attachment: testxpra-5-8-13.txt added

xpra client logs for internet-cloud session crash

Note: See TracTickets for help on using tickets.