This service will be undergoing maintenance at 00:00 UTC, 2017-10-23 It is expected to last about 30 minutes
Bug 1301088 - virt-viewer fails to redirect webcam and sometimes hangs - for remote VM only
virt-viewer fails to redirect webcam and sometimes hangs - for remote VM only
Status: NEW
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: mingw-virt-viewer (Show other bugs)
3.6.2
Unspecified Unspecified
unspecified Severity medium
: ovirt-4.2.0
: 4.0.0
Assigned To: Default Assignee for SPICE Bugs
SPICE QE bug list
:
Depends On: 1397522 1487917 1487918
Blocks:
  Show dependency treegraph
 
Reported: 2016-01-22 09:51 EST by Victor Toso
Modified: 2017-09-28 05:08 EDT (History)
10 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Spice
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
dmesg with trust device (693 bytes, text/plain)
2016-02-23 10:19 EST, Victor Toso
no flags Details
dmesg with lifecam device (2.46 KB, text/plain)
2016-02-23 10:21 EST, Victor Toso
no flags Details
from usbview.exe (117.75 KB, text/plain)
2016-03-03 08:52 EST, Victor Toso
no flags Details
#1 output from UsbDkTraceToFile.bat (832.00 KB, image/vnd.microsoft.icon)
2016-03-03 08:53 EST, Victor Toso
no flags Details
#2 output from UsbDkTraceToFile.bat (704.00 KB, image/vnd.microsoft.icon)
2016-03-03 08:54 EST, Victor Toso
no flags Details
#3 output from UsbDkTraceToFile.bat (2.25 MB, image/vnd.microsoft.icon)
2016-03-03 08:55 EST, Victor Toso
no flags Details
Textual UsbDk logs from .etl files provided by Victor (8.10 KB, application/zip)
2016-03-09 03:45 EST, Dmitry Fleytman
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
FreeDesktop.org 96598 None None None 2016-06-28 10:10 EDT

  None (edit)
Description Victor Toso 2016-01-22 09:51:10 EST
Description of problem:
* This problem is specifically for remote VM's. I wasn't able to trigger this issue for VM's under the same network. VM's under the same network behaves as expected.

* I'm also having trouble to redirect stdout/stderr from remote-viewer.exe in cmd.exe/powershell/cygwin so, I'm trying to attach here the logs that seems more promising regarding this issue

Trying to redirect two different webcams (one at the time). The following error happen with both:

> (remote-viewer.exe:8872): GSpice-WARNING **: Warning no automount-inhibiting 
> implementation available                                                                                                    
> libusb: error [win_transfer_callback] detected I/O error 1627: [1627] Function 
> failed during execution.

(...)

> Driver file operation error. Failed to open device symlink \\.\UsbDk (Access 
> is denied.  Error code = 5)
> (remote-viewer.exe:8872): GSpice-WARNING **: handle_dev_change: 
> libusb_get_device_list failed
> (remote-viewer.exe:8872): GSpice-CRITICAL **: handle_dev_change: assertion 
> 'dev_count >= 0' failed

I'm connecting to a Fedora 22 guest and It might or might not show a single frame on Cheese before the device fails on the Guest.
When I disconnect the device it often happens to hang and freeze the remote-viewer UI with the following error

> libusb: debug [libusb_get_next_timeout] no URB with timeout or all handled by 
> OS; no timeout!
> libusb: debug [libusb_handle_events_timeout_completed] doing our own event 
> handling
> libusb: debug [handle_events] poll() 2 fds with timeout in 3ms
> libusb: debug [handle_events] poll() returned 0


Version-Release number of selected component (if applicable):
Tried with usbdk 1.0.11, 1.0.10 and 1.0.8
virt-viewer-2.0-8 x64
windows 7 x64

How reproducible:
Always

Steps to Reproduce:
1. Connect to a remote VM
2. Share a webcam
3. see the errors happen

Actual results:
Fail to redirect the webcam


Expected results:
Being able to redirect the webcam


Additional info:
I suspect that this is related to usbdk integration on libusb and spice-gtk for the windows client.
Comment 2 Dmitry Fleytman 2016-01-24 02:10:55 EST
Hi Victor,

From logs it looks like a transfer failure:
                                                                                     
> libusb: error [win_transfer_callback] detected I/O error 1627: [1627] Function 
> failed during execution.

Most probably this failure comes from UsbDk, not from user mode.

> Driver file operation error. Failed to open device symlink \\.\UsbDk (Access 
> is denied.  Error code = 5)
> (remote-viewer.exe:8872): GSpice-WARNING **: handle_dev_change: 
> libusb_get_device_list failed
> (remote-viewer.exe:8872): GSpice-CRITICAL **: handle_dev_change: assertion 
> 'dev_count >= 0' failed

This part of log is a consequence of the original error.

In order to understand what exactly happened we need more information:

1. UsbTree dump on the host: http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/UsbInfo.txt
2. UsbDk traces of the failure (host):
http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/Tracing.txt#n52
3. WDF traces if the failure (host):
http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/WdfLogDumping.txt

Please collect this information.

Thanks,
Dmitry
Comment 8 Victor Toso 2016-02-23 10:18:40 EST
Hi,

Have you tested this procedures on Windows 10 x64? I'm failing again. I plan to wipe everything that I've installed so I could try again with a 'fresh' install for this environment.

(In reply to Dmitry Fleytman from comment #2)
> In order to understand what exactly happened we need more information:
> 
> 1. UsbTree dump on the host:
> http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/UsbInfo.txt

The command below does Segmentation Faults:

usbview /q /f /savexml:MyUsbTree.xml

> 2. UsbDk traces of the failure (host):
> http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/Tracing.
> txt#n52

No UsbDkTrace.etl is generated...

> 3. WDF traces if the failure (host):
> http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/
> WdfLogDumping.txt
> 
> Please collect this information.

I'll be attaching the dmesg of Fedora 21 guest connected with latest UsbDK 1.0.12 when connecting two different webcams.
Comment 9 Victor Toso 2016-02-23 10:19 EST
Created attachment 1129816 [details]
dmesg with trust device
Comment 10 Victor Toso 2016-02-23 10:21 EST
Created attachment 1129818 [details]
dmesg with lifecam device
Comment 11 Victor Toso 2016-02-24 10:49:35 EST
(In reply to Victor Toso from comment #8)
> Have you tested this procedures on Windows 10 x64? I

Sorry, I really meant Windows 7 x64. Bare-metal.
Comment 12 Dmitry Fleytman 2016-02-28 05:10:01 EST
(In reply to Victor Toso from comment #8)
> Hi,
> 
> Have you tested this procedures on Windows 10 x64? I'm failing again. I plan
> to wipe everything that I've installed so I could try again with a 'fresh'
> install for this environment.
> 
> (In reply to Dmitry Fleytman from comment #2)
> > In order to understand what exactly happened we need more information:
> > 
> > 1. UsbTree dump on the host:
> > http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/UsbInfo.txt
> 
> The command below does Segmentation Faults:
> 
> usbview /q /f /savexml:MyUsbTree.xml
> 
> > 2. UsbDk traces of the failure (host):
> > http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/Tracing.
> > txt#n52
> 
> No UsbDkTrace.etl is generated...

Hi Victor,

This log is critical to understand what is happening in UsbDk. Could you please clarify what is going on when you run the tracer? Are there error messages or some other suspicious behaviour. This manual is tested by many users and and it was working for everyone...

Thanks, Dmitry

> 
> > 3. WDF traces if the failure (host):
> > http://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/
> > WdfLogDumping.txt
> > 
> > Please collect this information.
> 
> I'll be attaching the dmesg of Fedora 21 guest connected with latest UsbDK
> 1.0.12 when connecting two different webcams.
Comment 13 Victor Toso 2016-03-03 08:52 EST
Created attachment 1132793 [details]
from usbview.exe
Comment 14 Victor Toso 2016-03-03 08:53 EST
Created attachment 1132794 [details]
#1 output from UsbDkTraceToFile.bat
Comment 15 Victor Toso 2016-03-03 08:54 EST
Created attachment 1132795 [details]
#2 output from UsbDkTraceToFile.bat
Comment 16 Victor Toso 2016-03-03 08:55 EST
Created attachment 1132796 [details]
#3 output from UsbDkTraceToFile.bat
Comment 17 Victor Toso 2016-03-03 08:57:09 EST
My notes related to the attachments from comment #13 to comment #16
--

* Running always as admin

1-) install usbdk 1.0.12 from: http://www.spice-space.org/download.html
2-) reboot
3-) install mingw64-virt-viewer-2.0-8.el7ev.noarch (from brew)
4-) install WDK from: https://msdn.microsoft.com/en-us/windows/hardware/hh852365
- based on https://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/Tracing.txt#n52
- based on https://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/UsbInfo.txt
5-) reboot
6-) tested usbview.exe -- works
7-) following https://cgit.freedesktop.org/spice/win32/usbdk/tree/Documentation/Tracing.txt#n52
 7.1) copied traceview to Trace folder
 7.2) Run UsbDkTraceToFile.bat

Tests:

A) LifeCam
- Connect to remote Fedora 21
- redirect Microsoft LifeCam
- small freeze/delay in the UI (2 maybe 3 seconds)
- open cheese -> "No device was found"
- disable redirect of Microsoft LifeCam
 > first test: Ui freezes.. remote-viwer might get "Not Responding"
 > second test: does not freeze but webcam light is not turned off,
   then when I click on File in remote-viewer it does freeze and get "Not Responding"

-- dmesg on guest from test A
[759648.490399] usb 1-2: new high-speed USB device number 6 using ehci-pci
[759648.874951] usb 1-2: New USB device found, idVendor=045e, idProduct=075d
[759648.874958] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[759648.874961] usb 1-2: Product: Microsoft® LifeCam Cinema(TM)
[759648.874965] usb 1-2: Manufacturer: Microsoft
[759648.947556] uvcvideo: Found UVC 1.00 device Microsoft® LifeCam Cinema(TM) (045e:075d)
[759649.093542] input: Microsoft® LifeCam Cinema(TM) as /devices/pci0000:00/0000:00:08.7/usb1/1-2/1-2:1.0/input/input10
[759654.732242] usb 1-2: 3:1: cannot get freq at ep 0x82
[759660.533088] usb 1-2: 5:2: cannot get min/max values for control 2 (id 5)
[759660.539668] usb 1-2: USB disconnect, device number 6



B) TrustDevice
- Connect to remote Fedora 21
- redirect Trust Device
- dmesg seems okay
- enable cheese
- guest freezes
- I disconnect and connect again, cheese says "There was an error playing video from the webcam"
- Same issue when trying again

-- dmesg on guest from test B
[759036.175379] usb 1-2: new high-speed USB device number 4 using ehci-pci
[759036.562456] usb 1-2: New USB device found, idVendor=145f, idProduct=019f
[759036.562462] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[759036.562466] usb 1-2: Product: Trust Webcam
[759036.562469] usb 1-2: Manufacturer: Novatek
[759036.633132] uvcvideo: Found UVC 1.00 device Trust Webcam (145f:019f)
[759036.778387] input: Trust Webcam as /devices/pci0000:00/0000:00:08.7/usb1/1-2/1-2:1.0/input/input8
[759306.782240] usb 1-2: USB disconnect, device number 4
[759306.786486] uvcvideo: Failed to resubmit video URB (-19).


* path for usbview: C:\Program Files (x86)\Windows Kits\10\Tools\x64\usbview.exe
Comment 18 Dmitry Fleytman 2016-03-09 03:45 EST
Created attachment 1134420 [details]
Textual UsbDk logs from .etl files provided by Victor
Comment 19 Yaniv Lavi (Dary) 2016-05-09 06:57:39 EDT
oVirt 4.0 Alpha has been released, moving to oVirt 4.0 Beta target.
Comment 23 Victor Toso 2016-06-28 10:10:18 EDT
Let's move this one to rhevm-4.1 as it will some time to develop a proper solution upstream. Upstream bug to track is:

https://bugs.freedesktop.org/show_bug.cgi?id=96598
Comment 25 Victor Toso 2016-11-22 12:38:40 EST
Solution is not upstream yet.
It should be addressed in RHEL7 first.
RFE open at: https://bugzilla.redhat.com/show_bug.cgi?id=1397522

Moving to rhevm-4.2
Comment 26 ybendito 2017-08-23 13:14:20 EDT
One of scenarios when the problem happens:
Redirect USB 2.0 camera device to VM - redirected OK (sometimes redirection fails as the device disappears during redirection, which is different problem)
The client machine is connected to network of qemu via wireless, the bandwidth consumption of the working camera is significant and close or higher than available bandwidth of wireless networking. The problem can happen also if the network is wired but due to some reason there is significant latency and as a result the effective bandwidth is low.
In this case upon activation of the camera on VM, the viewer enters busy loop and does not leave it anymore. The display of remote viewer is frozen, mouse also does not function in VM window. It is possible to connect to the machine via RDP if enabled and try to deactivate the camera, but this does not produce any effect as the viewer does not receive commands anymore. Only recovery is to kill the viewer's process. Possible root cause is the bug in libusb.

Note You need to log in before you can comment on or make changes to this bug.