Created attachment 881722 [details] Spice logs both on client and host sides (debug mode NOT activated) Description of problem: After upgrading the viewer on windows machines to the latest version we started experiencing random session freezes. The viewer needs then to be killed. After that the session can be re-established by re-launching the client (guest is NOT affected). Also we noticed that when the viewer freezes, the connection is in CLOSE_WAIT on the client and it's not listed anymore on the host. This is not reproducible on a predictable basis so it's difficult to collect relevant debug data. In the spicex.log file we see: 1396361383 INFO [5916:4436] COSpiceX::Connect: spicec pid 3904 1396424606 INFO [5916:2812] COSpiceX::event_thread: exit_code=1 error_code=1032 There is not a repetitive usage pattern to reproduce it: this happens both with idle and active sessions. Version-Release number of selected component (if applicable): rhevm-spice-client-x86-cab-3.3-11.el6_5 Additional note: We have asked to collect spice logs both from client and host after this happened (attached). However happening in an unpredictable fashion they have been unable to set the debug mode so far. - what could we set up to collect useful debugging information to troubleshoot this? - any possible way to work this around comes to your mind?
Please try to provide indication on how to reproduce. If not, please provide SPICE_DEBUG log from debug-helper.
(remote-viewer.exe:2560): Gdk-CRITICAL **: gdk_property_delete: assertion `window != NULL' failed (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:465 clipboard_get_targets: (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "DataObject" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Object Descriptor" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "RichText Format" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "HTMLFormat" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "UTF8_STRING" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Embed Source" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Native" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "OwnerLink" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "OlePrivate Data" (remote-viewer.exe:2560): Gdk-CRITICAL **: gdk_property_delete: assertion `window != NULL' failed (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:465 clipboard_get_targets: (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "DataObject" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Object Descriptor" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "RichText Format" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "HTMLFormat" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "UTF8_STRING" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Embed Source" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Native" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "OwnerLink" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "OlePrivate Data" (remote-viewer.exe:2560): Gdk-CRITICAL **: gdk_property_delete: assertion `window != NULL' failed [New Thread 2560.0x2390](remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:465 clipboard_get_targets: (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "DataObject" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Object Descriptor" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "RichText Format" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "HTMLFormat" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "UTF8_STRING" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Embed Source" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "Native" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "OwnerLink" (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-gtk-session.c:469 "OlePrivate Data" (remote-viewer.exe:2560): Gdk-CRITICAL **: gdk_property_delete: assertion `window != NULL' failed [New Thread 2560.0x1ba0] [New Thread 2560.0x1960] [New Thread 2560.0x1b90] [New Thread 2560.0x1190] [New Thread 2560.0x1dc0] [New Thread 2560.0x1418] (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1440 focus_in_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1243 release_keys (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1463 focus_out_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1243 release_keys (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1440 focus_in_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1243 release_keys (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1463 focus_out_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1243 release_keys (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1410 enter_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1440 focus_in_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1243 release_keys (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:734 grab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event press: button 1, state 0x0 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1624 button_event release: button 1, state 0x100 (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1424 leave_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:762 ungrab keyboard (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1463 focus_out_event (remote-viewer.exe:2560): GSpice-DEBUG: ../../gtk/spice-widget.c:1243 release_keys
Maybe this will help also, from the windows event viewer: Faulting application name: iexplore.exe, version: 9.0.8112.16540, time stamp: 0x5309896b Faulting module name: SpiceX.dll_unloaded, version: 0.0.0.0, time stamp: 0x531883fa Exception code: 0xc0000005 Fault offset: 0x0ffc42d0 Faulting process id: 0xe78 Faulting application start time: 0x01cf4e60e54fb871 Faulting application path: C:\Program Files (x86)\Internet Explorer\iexplore.exe Faulting module path: SpiceX.dll Report Id: c207a326-ba67-11e3-84f2-402cf486b1ac Also current indication is that all tests performed using native mode didn't show the issue. Not sure how cogent this is as fro now but I wanted you to know. In parallel they are seeing also the issue described in BZ#1081533 which may or may not be related, but I'll leave it to you to decide.
(In reply to Luca Villa from comment #7) > Maybe this will help also, from the windows event viewer: > > Faulting application name: iexplore.exe, version: 9.0.8112.16540, time > stamp: 0x5309896b > Faulting module name: SpiceX.dll_unloaded, version: 0.0.0.0, time stamp: > 0x531883fa > Exception code: 0xc0000005 > Fault offset: 0x0ffc42d0 > Faulting process id: 0xe78 > Faulting application start time: 0x01cf4e60e54fb871 > Faulting application path: C:\Program Files (x86)\Internet > Explorer\iexplore.exe > Faulting module path: SpiceX.dll > Report Id: c207a326-ba67-11e3-84f2-402cf486b1ac Does this appear in the event log every time a session starts freezing?
(In reply to Christophe Fergeau from comment #8) > (In reply to Luca Villa from comment #7) > > Maybe this will help also, from the windows event viewer: > > > > Faulting application name: iexplore.exe, version: 9.0.8112.16540, time > > stamp: 0x5309896b > > Faulting module name: SpiceX.dll_unloaded, version: 0.0.0.0, time stamp: > > 0x531883fa > > Exception code: 0xc0000005 > > Fault offset: 0x0ffc42d0 > > Faulting process id: 0xe78 > > Faulting application start time: 0x01cf4e60e54fb871 > > Faulting application path: C:\Program Files (x86)\Internet > > Explorer\iexplore.exe > > Faulting module path: SpiceX.dll > > Report Id: c207a326-ba67-11e3-84f2-402cf486b1ac > > Does this appear in the event log every time a session starts freezing? Customer's answer follows: I have seen some cases in which this occured, I am asking all people who have the problem to check the event log for the error. So far a 100% hit.
The SpiceX crash is probably not causing the hang. But perhaps it could be helpful to try without SpiceX, using the native vv / mime connection method. From Comment 6, it seems there are some clipboard related errors. How did they trigger those? Are they doing copy&paste in the client, using which application? Can they try to reproduce when using "only" remote-viewer? (no other app running, no copy&paste) thanks
also, when the hang happen, please try to get the "thread apply all bt" from the gdb prompt.
(In reply to Marc-Andre Lureau from comment #10) > The SpiceX crash is probably not causing the hang. But perhaps it could be > helpful to try without SpiceX, using the native vv / mime connection method. > As pointed out in c#7: current indication is that all tests performed using native mode didn't show the issue. I don't know how extensively they tested but this seems to me a good indication already. > > From Comment 6, it seems there are some clipboard related errors. How did > they trigger those? Are they doing copy&paste in the client, using which > application? Can they try to reproduce when using "only" remote-viewer? (no > other app running, no copy&paste) > I can ask. Just a note however: this appeared in very different usage conditions such as: an idle session with screen locked while the user was at lunch vs actively used session. At least in the first case I doubt they were doing any copy&paste activity. (In reply to Marc-Andre Lureau from comment #11) > also, when the hang happen, please try to get the "thread apply all bt" from > the gdb prompt. Ok, my bad that I didn't explicitly ask to do this already. Since this appears to be difficult to reproduce at will, is there anything else useful that they need to collected that comes to your mind? It's of course better if they can just collect everything in one shot. Thanks.
Created attachment 883940 [details] segfault screenshot Not sure if this can be relevant but in doubt I'm posting it anyway. I received only the screenshot as sadly the user closed the window without collecting the text. I also asked them to increase the CMD window buffer size. Unfortunately it seems we have missed the right time as the issue is not appearing today on the client of the IT guy working on this.
(In reply to Luca Villa from comment #31) > Created attachment 883940 [details] > segfault screenshot > > Not sure if this can be relevant but in doubt I'm posting it anyway. > I received only the screenshot as sadly the user closed the window without > collecting the text. that could be related, it's also a clipboard issue. > I also asked them to increase the CMD window buffer size. > Unfortunately it seems we have missed the right time as the issue is not > appearing today on the client of the IT guy working on this. ok, waiting for next log then
I could reproduce only on rhel6, when the client receives SIGHUP, the cause seems to be on server side: Breakpoint 1, red_channel_client_disconnect (rcc=0x7febe61c5f30) at red_channel.c:1830 1830 { (gdb) bt #0 red_channel_client_disconnect (rcc=0x7febe61c5f30) at red_channel.c:1830 #1 0x00007febe363268a in qemu_run_timers (timeout=1000) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:1339 #2 main_loop_wait (timeout=1000) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:4088 #3 0x00007febe365556a in kvm_main_loop () at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2245 #4 0x00007febe3635379 in main_loop (argc=80, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:4266 #5 main (argc=80, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:6644 (
Now that I use a debug version of spice-server, I can't reproduce the SIGHUP (for >3 hours..) However, I just got a grip on something interesting that is effectively a bug in spice-gtk and freezes the main channel (no more clipboard, or monitor reconfiguration etc). This could perhaps later trigger some auto-disconnect of the server? Here is the issue: While the client is Thread 1 (Thread 3932.0xc90): #0 0x76fd015d in ntdll!ZwWaitForMultipleObjects () from C:\Windows\system32\ntd #1 0x76fd015d in ntdll!ZwWaitForMultipleObjects () from C:\Windows\system32\ntd #2 0x75f415e9 in WaitForMultipleObjectsEx () from C:\Windows\syswow64\KernelBas #3 0x00000008 in ?? () #4 0x0028d710 in ?? () #5 0x768819f8 in WaitForMultipleObjectsEx () from C:\Windows\syswow64\kernel32. #6 0x74c1086a in USER32!PeekMessageW () from C:\Windows\syswow64\user32.dll #7 0x03de6d3a in poll_rest (poll_msgs=1, handles=0x28d87c, nhandles=7, fds=0x10 timeout=4994) at ../../glib/gpoll.c:159 #8 0x03de72df in g_poll (fds=0x101c8968, nfds=8, timeout=4994) at ../../glib/gp #9 0x03dd9335 in g_main_context_poll (context=0x100e4930, timeout=4994, priorit fds=0x101c8968, n_fds=8) at ../../glib/gmain.c:3440 #10 0x03dd8cec in g_main_context_iterate (context=0x100e4930, block=1, dispatch= self=0x10128b40) at ../../glib/gmain.c:3141 #11 0x03dd9116 in g_main_loop_run (loop=0x1142bd10) at ../../glib/gmain.c:3340 #12 0x0d8a2b15 in clipboard_get (clipboard=0x10120108, selection_data=0x28df60, user_data=0x100dc958) at ../../gtk/spice-gtk-session.c:659 4. The clipboard is still hold by guest, so send a request there and wait for data Now because clipboard is synchronous with gtk+ this function will not return until the data is received. However, we need to return so that main channel can keep running, and actually send/receive the data. Here we can see we are in a freeze moment, due to gtk synchronous API, and spice-gtk coroutine usage... Adding a pre-condition on main coroutine being !active is the least, it should be enough to avoid this. There should be a check to avoid this kind of clipboard dependency loop between guest and client. #13 0x058250d1 in selection_get_cb (widget=0x100d8440, selection_data=0x28df60, time=10589129) at gtkclipboard.c:338 #14 0x0569f08a in _gtk_marshal_VOID__BOXED_UINT_UINT (closure=0x11437168, return n_param_values=4, param_values=0x28dcc0, invocation_hint=0x28dc2c, marshal_d at gtkmarshalers.c:1540 #15 0x63a462cc in g_closure_invoke (closure=0x11437168, return_value=0x0, n_para param_values=0x28dcc0, invocation_hint=0x28dc2c) at ../../gobject/gclosure.c #16 0x63a5d5ca in signal_emit_unlocked_R (node=0x100e7138, detail=0, instance=0x emission_return=0x0, instance_and_params=0x28dcc0) at ../../gobject/gsignal. #17 0x63a5cce8 in g_signal_emit_valist (instance=0x100d8440, signal_id=57, detai var_args=0x28df14 "`~M\016\001") at ../../gobject/gsignal.c:3300 #18 0x63a5d0a2 in g_signal_emit_by_name (instance=0x100d8440, detailed_signal=0x59412a5 <gtk_selection_handler_key+869> "selection-get") at ../../gobject/gsignal.c:3393 #19 0x05723f8a in gtk_selection_invoke_handler (widget=0x100d8440, data=0x28df60 at gtkselection.c:2986 #20 0x05721658 in gtk_selection_convert (widget=0x100d8440, selection=0x45, targ time_=10589129) at gtkselection.c:1085 #21 0x05825e2d in gtk_clipboard_request_contents (clipboard=clipboard@entry=0x10 target=target@entry=0xc064, callback=callback@entry=0xd8a3b30 <clipboard_rec user_data=0x1544daf8) at gtkclipboard.c:917 #22 0x0d8a3ad5 in clipboard_request (main=0x10168978, selection=0, type=1, user_ at ../../gtk/spice-gtk-session.c:836 3. got a clipboard request from guest: the coroutine main channel is running, waiting for this function to return #23 0x0ae453a9 in g_cclosure_user_marshal_BOOLEAN__UINT_UINT (closure=0x101688f8 return_value=0x28e270, n_param_values=3, param_values=0x28e1b0, invocation_h marshal_data=0x0) at spice-marshal.c:531 #24 0x63a462cc in g_closure_invoke (closure=0x101688f8, return_value=0x28e270, n param_values=0x28e1b0, invocation_hint=0x28e11c) at ../../gobject/gclosure.c #25 0x63a5d5ca in signal_emit_unlocked_R (node=0x1013ab68, detail=0, instance=0x emission_return=0x28e270, instance_and_params=0x28e1b0) at ../../gobject/gsi #26 0x63a5cd77 in g_signal_emit_valist (instance=0x10168978, signal_id=206, deta var_args=0x28e3e4 "Oû\021\022Hä(") at ../../gobject/gsignal.c:3310 #27 0x63a5cfd0 in g_signal_emit (instance=0x10168978, signal_id=206, detail=0) at ../../gobject/gsignal.c:3356 #28 0x0ae1a7ca in do_emit_main_context (object=0x10168978, signum=8, params=0x12 at ../../gtk/channel-main.c:896 #29 0x0ae0f990 in emit_main_context (opaque=0x1211fb30) at ../../gtk/gio-corouti #30 0x03dda20f in g_idle_dispatch (source=0x15448958, callback=0xae0f95f <emit_m user_data=0x1211fb30) at ../../glib/gmain.c:4657 #31 0x03dd8019 in g_main_dispatch (context=0x100e4930) at ../../glib/gmain.c:253 #32 0x03dd8b45 in g_main_context_dispatch (context=0x100e4930) at ../../glib/gma #33 0x03dd8d20 in g_main_context_iterate (context=0x100e4930, block=1, dispatch= self=0x10128b40) at ../../glib/gmain.c:3146 #34 0x03dd9116 in g_main_loop_run (loop=0x101cd4d8) at ../../glib/gmain.c:3340 #35 0x0d8a2b15 in clipboard_get (clipboard=0x10120108, selection_data=0x28eaa8, user_data=0x100dc958) at ../../gtk/spice-gtk-session.c:659 2. got a second clipboard request from client first one isn't finished, we should probably prevent this or queue requests, as it will reply out of order (first reply will get to last request..). not a big issue but still.. #36 0x058250d1 in selection_get_cb (widget=0x100d8440, selection_data=0x28eaa8, time=10589129) at gtkclipboard.c:338 #37 0x0569f08a in _gtk_marshal_VOID__BOXED_UINT_UINT (closure=0x11437168, return n_param_values=4, param_values=0x28e7d0, invocation_hint=0x28e73c, marshal_d at gtkmarshalers.c:1540 #38 0x63a462cc in g_closure_invoke (closure=0x11437168, return_value=0x0, n_para param_values=0x28e7d0, invocation_hint=0x28e73c) at ../../gobject/gclosure.c #39 0x63a5d5ca in signal_emit_unlocked_R (node=0x100e7138, detail=0, instance=0x emission_return=0x0, instance_and_params=0x28e7d0) at ../../gobject/gsignal. #40 0x63a5cce8 in g_signal_emit_valist (instance=0x100d8440, signal_id=57, detai var_args=0x28ea24 "`~M\016Hê(") at ../../gobject/gsignal.c:3300 #41 0x63a5d0a2 in g_signal_emit_by_name (instance=0x100d8440, detailed_signal=0x59412a5 <gtk_selection_handler_key+869> "selection-get") at ../../gobject/gsignal.c:3393 #42 0x05723f8a in gtk_selection_invoke_handler (widget=0x100d8440, data=0x28eaa8 at gtkselection.c:2986 #43 0x0572314f in _gtk_selection_request (widget=0x100d8440, event=0x100f0530) at gtkselection.c:2391 #44 0x0569d080 in _gtk_marshal_BOOLEAN__BOXED (closure=0x100e70c8, return_value= n_param_values=2, param_values=0x28ecf0, invocation_hint=0x28ec5c, marshal_data=0x5722e3a <_gtk_selection_request>) at gtkmarshalers.c:86 #45 0x63a4685b in g_type_class_meta_marshal (closure=0x100e70c8, return_value=0x n_param_values=2, param_values=0x28ecf0, invocation_hint=0x28ec5c, marshal_d at ../../gobject/gclosure.c:970 #46 0x63a462cc in g_closure_invoke (closure=0x100e70c8, return_value=0x28ec38, n param_values=0x28ecf0, invocation_hint=0x28ec5c) at ../../gobject/gclosure.c #47 0x63a5d713 in signal_emit_unlocked_R (node=0x100e70f0, detail=0, instance=0x emission_return=0x28ed90, instance_and_params=0x28ecf0) at ../../gobject/gsi #48 0x63a5cd77 in g_signal_emit_valist (instance=0x100d8440, signal_id=54, detai var_args=0x28ef00 "\030ï(") at ../../gobject/gsignal.c:3310 #49 0x63a5cfd0 in g_signal_emit (instance=0x100d8440, signal_id=54, detail=0) at ../../gobject/gsignal.c:3356 #50 0x0580a01c in gtk_widget_event_internal (widget=0x100d8440, event=0x100f0530 at gtkwidget.c:5010 #51 0x05809bae in gtk_widget_event (widget=0x100d8440, event=0x100f0530) at gtkw #52 0x0569a2d6 in gtk_main_do_event (event=0x100f0530) at gtkmain.c:1639 #53 0x6c38d3e6 in gdk_event_dispatch (source=0x100e48b0, callback=0x0, user_data at gdkevents-win32.c:3673 #54 0x03dd8019 in g_main_dispatch (context=0x100e4930) at ../../glib/gmain.c:253 #55 0x03dd8b45 in g_main_context_dispatch (context=0x100e4930) at ../../glib/gma #56 0x03dd8d20 in g_main_context_iterate (context=0x100e4930, block=1, dispatch= self=0x10128b40) at ../../glib/gmain.c:3146 #57 0x03dd9116 in g_main_loop_run (loop=0x15049310) at ../../glib/gmain.c:3340 #58 0x0d8a2b15 in clipboard_get (clipboard=0x10120108, selection_data=0x28f638, user_data=0x100dc958) at ../../gtk/spice-gtk-session.c:659 1. got clipboard request from client #59 0x058250d1 in selection_get_cb (widget=0x100d8440, selection_data=0x28f638, time=10589129) at gtkclipboard.c:338 #60 0x0569f08a in _gtk_marshal_VOID__BOXED_UINT_UINT (closure=0x11437168, return n_param_values=4, param_values=0x28f360, invocation_hint=0x28f2cc, marshal_d at gtkmarshalers.c:1540 #61 0x63a462cc in g_closure_invoke (closure=0x11437168, return_value=0x0, n_para param_values=0x28f360, invocation_hint=0x28f2cc) at ../../gobject/gclosure.c #62 0x63a5d5ca in signal_emit_unlocked_R (node=0x100e7138, detail=0, instance=0x emission_return=0x0, instance_and_params=0x28f360) at ../../gobject/gsignal. #63 0x63a5cce8 in g_signal_emit_valist (instance=0x100d8440, signal_id=57, detai var_args=0x28f5b4 "`~M\016Oo(") at ../../gobject/gsignal.c:3300 #64 0x63a5d0a2 in g_signal_emit_by_name (instance=0x100d8440, detailed_signal=0x59412a5 <gtk_selection_handler_key+869> "selection-get") at ../../gobject/gsignal.c:3393 #65 0x05723f8a in gtk_selection_invoke_handler (widget=0x100d8440, data=0x28f638 at gtkselection.c:2986 #66 0x0572314f in _gtk_selection_request (widget=0x100d8440, event=0x100f0168) at gtkselection.c:2391 #67 0x0569d080 in _gtk_marshal_BOOLEAN__BOXED (closure=0x100e70c8, return_value= n_param_values=2, param_values=0x28f880, invocation_hint=0x28f7ec, marshal_data=0x5722e3a <_gtk_selection_request>) at gtkmarshalers.c:86 #68 0x63a4685b in g_type_class_meta_marshal (closure=0x100e70c8, return_value=0x n_param_values=2, param_values=0x28f880, invocation_hint=0x28f7ec, marshal_d at ../../gobject/gclosure.c:970 #69 0x63a462cc in g_closure_invoke (closure=0x100e70c8, return_value=0x28f7c8, n param_values=0x28f880, invocation_hint=0x28f7ec) at ../../gobject/gclosure.c #70 0x63a5d713 in signal_emit_unlocked_R (node=0x100e70f0, detail=0, instance=0x emission_return=0x28f920, instance_and_params=0x28f880) at ../../gobject/gsi #71 0x63a5cd77 in g_signal_emit_valist (instance=0x100d8440, signal_id=54, detai var_args=0x28fa90 ""ú(") at ../../gobject/gsignal.c:3310 #72 0x63a5cfd0 in g_signal_emit (instance=0x100d8440, signal_id=54, detail=0) at ../../gobject/gsignal.c:3356 #73 0x0580a01c in gtk_widget_event_internal (widget=0x100d8440, event=0x100f0168 at gtkwidget.c:5010 #74 0x05809bae in gtk_widget_event (widget=0x100d8440, event=0x100f0168) at gtkw #75 0x0569a2d6 in gtk_main_do_event (event=0x100f0168) at gtkmain.c:1639 #76 0x6c38d3e6 in gdk_event_dispatch (source=0x100e48b0, callback=0x0, user_data at gdkevents-win32.c:3673 #77 0x03dd8019 in g_main_dispatch (context=0x100e4930) at ../../glib/gmain.c:253 #78 0x03dd8b45 in g_main_context_dispatch (context=0x100e4930) at ../../glib/gma #79 0x03dd8d20 in g_main_context_iterate (context=0x100e4930, block=1, dispatch= self=0x10128b40) at ../../glib/gmain.c:3146 #80 0x03dd9116 in g_main_loop_run (loop=0x113a81c0) at ../../glib/gmain.c:3340 #81 0x05699b4a in gtk_main () at gtkmain.c:1257 #82 0x0041c696 in main (argc=1, argv=0xe4d5fe8) at ../../src/remote-viewer-main.
(remote-viewer.exe:4352): Gdk-CRITICAL **: gdk_property_delete: assertion `window != NULL' failed is a gtk+ bug and can be ignored for now. It is happening when there are >1 ongoing clipboard request, and the >1 reply will destroy the associated (unvisible) window, before gdk_property_delete() is called. This seems harmless, although it points to an interesting time, usually of deep clipboard operation like comment #79.
sent 2 patches to avoid the remote request cycle and reentering loop while main channel is busy: http://lists.freedesktop.org/archives/spice-devel/2014-May/016856.html and a little gtk+ patch to remove the harmless critical: https://bugzilla.gnome.org/show_bug.cgi?id=730183 I am still wondering what causes the server disconnection from Comment 76, that caused the unsolicited SIGHUP and further client black screen.
(In reply to Marc-Andre Lureau from comment #85) > I am still wondering what causes the server disconnection from Comment 76, > that caused the unsolicited SIGHUP and further client black screen. Hmm, it seems there is a connectivity test. The server sends a regular ping, and expects a reply on main channel. If it's not received within the timer, red_channel_client_connectivity_timer() will disconnect the client. So that would corroborate the main channel freeze. sad none of us managed to see that in the server debug.. it should surely be a warning visible by default, so I send a patch for that too: http://lists.freedesktop.org/archives/spice-devel/2014-May/016859.html
(In reply to Marc-Andre Lureau from comment #86) > (In reply to Marc-Andre Lureau from comment #85) > > I am still wondering what causes the server disconnection from Comment 76, > > that caused the unsolicited SIGHUP and further client black screen. > > Hmm, it seems there is a connectivity test. The server sends a regular ping, > and expects a reply on main channel. If it's not received within the timer, > red_channel_client_connectivity_timer() will disconnect the client. So that > would corroborate the main channel freeze. This was done to fix bug 994175
I wrote a simpler clipboard synchronizer (as proof of concept) that works better with spice and doesn't generate a lot of traffic or fight too much with other managers, feel free to give it a try: http://elmarco.fedorapeople.org/clipsync.py
After further testing I have seen the following: - I get mixed results wrt copy&paste operations. ** with version 0.5.620 (in use by the customer) a buffer size reasonably large fails to be copied client --> guest. spice-vdagent.log reports May 19 15:24:19.561779 spice-vdagent[3122]: err: clipboard: unexpected selection type GTK_TEXT_BUFFER_CONTENTS ** with version 0.5.622 c&p works better even with larger buffers apparently. However the test DLL seems not compatible with this newer version (application error at startup). Marc-Andre: can you please also provide a test DLL compiled against 622? Thanks, Luca
(In reply to Luca Villa from comment #94) > After further testing I have seen the following: > > - I get mixed results wrt copy&paste operations. > > ** with version 0.5.620 (in use by the customer) a buffer size reasonably > large fails to be copied client --> guest. > spice-vdagent.log reports > May 19 15:24:19.561779 spice-vdagent[3122]: err: clipboard: unexpected > selection type GTK_TEXT_BUFFER_CONTENTS I would need more details about application used, content of the buffer, whether any clipboard manager is running, network condition etc.. this could be harmless race, or a vdagent bug. probably a seperate issue anyway > ** with version 0.5.622 c&p works better even with larger buffers > apparently. > However the test DLL seems not compatible with this newer version > (application error at startup). > Marc-Andre: can you please also provide a test DLL compiled against 622? my bad, this one should work: http://elmarco.fedorapeople.org/libspice-client-gtk-2.0-4.dll
(In reply to Marc-Andre Lureau from comment #95) > > Marc-Andre: can you please also provide a test DLL compiled against 622? > > my bad, this one should work: > http://elmarco.fedorapeople.org/libspice-client-gtk-2.0-4.dll Unfortunately this still fails for me: remote-viewer.exe refuses to start.
(In reply to Luca Villa from comment #96) > (In reply to Marc-Andre Lureau from comment #95) > > > > Marc-Andre: can you please also provide a test DLL compiled against 622? > > > > my bad, this one should work: > > http://elmarco.fedorapeople.org/libspice-client-gtk-2.0-4.dll > > Unfortunately this still fails for me: remote-viewer.exe refuses to start. Can you provide you $prefix/deps.txt file? Make sure you run 32bit version.
Created attachment 897329 [details] deps.txt from version 0.5.622 (In reply to Marc-Andre Lureau from comment #97) > > Can you provide you $prefix/deps.txt file? Make sure you run 32bit version. Please see attached. The only dependency changed from 620 is openssl. $ diff deps.txt-620 deps.txt-622 46c46 < mingw32-openssl-1.0.1c-1.1.el6.noarch --- > mingw32-openssl-1.0.1e-6.1.el6_5.noarch Also I'm quite confident I'm running 32bit version (from SpiceX.cab)
(In reply to Luca Villa from comment #98) > Also I'm quite confident I'm running 32bit version (from SpiceX.cab) I just tried with 6-23 (the last build), it works fine: https://brewweb.devel.redhat.com/buildinfo?buildID=353665 what error do you get?
(In reply to Marc-Andre Lureau from comment #99) > (In reply to Luca Villa from comment #98) > > Also I'm quite confident I'm running 32bit version (from SpiceX.cab) > > I just tried with 6-23 (the last build), it works fine: > https://brewweb.devel.redhat.com/buildinfo?buildID=353665 > > what error do you get? If I run it from the CMD a dialog appears: ---------------------------------------------- Title: remote-viewer.exe - Application error Text: The application was unable to start correctly (0xc000007b). Click OK to close the application. ---------------------------------------------- I copied the same test DLL over version 620 and 621 and it works for both, but not 622.
(In reply to Luca Villa from comment #100) > I copied the same test DLL over version 620 and 621 and it works for both, > but not 622. no idea what's going on then, use 6-23, it is working too and is the last candidate.
(In reply to Marc-Andre Lureau from comment #101) > (In reply to Luca Villa from comment #100) > > > I copied the same test DLL over version 620 and 621 and it works for both, > > but not 622. > > no idea what's going on then, use 6-23, it is working too and is the last > candidate. Looks like 6-23 is not working while copying from guest (RHEL6) to client (Windows7) while the vice-versa works. I tried it with both a 3.3.0 infra and with a 3.4 pre. No clipboard manager in action at all on the guests. Can you please check this? I cannot proceed with the tests... Thanks, Luca
(In reply to Luca Villa from comment #102) > (In reply to Marc-Andre Lureau from comment #101) > > (In reply to Luca Villa from comment #100) > > > > > I copied the same test DLL over version 620 and 621 and it works for both, > > > but not 622. > > > > no idea what's going on then, use 6-23, it is working too and is the last > > candidate. > > Looks like 6-23 is not working while copying from guest (RHEL6) to client > (Windows7) while the vice-versa works. > I tried it with both a 3.3.0 infra and with a 3.4 pre. > No clipboard manager in action at all on the guests. > > Can you please check this? I cannot proceed with the tests... Whoo, I wonder how I missed that from testing last week. The proposed solution isn't sooo good, I'll probably need to dig deeper in gtk+ clipboard, perhaps proposing a new api.. but for now please try with: http://elmarco.fedorapeople.org/libspice-client-gtk-2.0-4.dll
I tested the new dll (win7, virt-viewer 0.5.623) and now it works as expected. Also, with no clipboard manager, with the clipsync, and with klipper, results are as expected. Klipper sometimes fails to sync large buffers though.
the bug should be for 3.5, add to be cloned to the corresponding ( proposed z-stream )
ok, let's get this patch released
added temporary 3.4.0 in order to clone to 3.3.z
*** Bug 1103288 has been marked as a duplicate of this bug. ***
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHSA-2015-0197.html