Bug 1301088

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

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.

Created attachment 1129816 [details]
dmesg with trust device

Created attachment 1129818 [details]
dmesg with lifecam device

(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.

(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.

Created attachment 1132793 [details]
from usbview.exe

Created attachment 1132794 [details]
#1 output from UsbDkTraceToFile.bat

Created attachment 1132795 [details]
#2 output from UsbDkTraceToFile.bat

Created attachment 1132796 [details]
#3 output from UsbDkTraceToFile.bat

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

Created attachment 1134420 [details]
Textual UsbDk logs from .etl files provided by Victor

oVirt 4.0 Alpha has been released, moving to oVirt 4.0 Beta target.

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

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

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.

(In reply to ybendito from comment #26)
> 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.

Sounds similar to [0] but it is hard to say without more info

[0] https://cgit.freedesktop.org/spice/spice-gtk/commit/?id=3fb475a9c9eac077c9eebb3623fe14b4cd1e965a

(...)

> 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.

Which hopefuly can be fixed by some QoS - not sure. Still, shouldn't be too hard to test suggestions at [1], just didn't had the time to do it.

[1] https://bugzilla.redhat.com/show_bug.cgi?id=1397522#c1

Moving this to 4.3 for now.

oVirt 4.2.0 has been released on Dec 20th 2017. Please consider re-targeting this bug to next milestone

This bug has not been marked as blocker for oVirt 4.3.0.
Since we are releasing it tomorrow, January 29th, this bug has been re-targeted to 4.3.1.

4.3.1 has been released, please re-target this bug as soon as possible.

After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.

The needinfo request[s] on this closed bug have been removed as they have been unresolved for 1000 days