[Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36

qemu-devel.nongnu.org archive mirror
 help / color / mirror / Atom feed

* [Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
@ 2015-02-09 21:09 Dennis Ostermann
  2015-02-10  8:09 ` Hans de Goede
  0 siblings, 1 reply; 4+ messages in thread
From: Dennis Ostermann @ 2015-02-09 21:09 UTC (permalink / raw)
  To: qemu-devel; +Cc: hdegoede, kraxel

Hi there,

please revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - 
"usb-host-libusb: Fix reset handling"

This breaks usb pass through of FTDI based usb devices:

On the host:

lsusb | grep FT2232
Bus 003 Device 008: ID 0403:6010 Future Technology Devices 
International, Ltd FT2232C Dual USB-UART/FIFO IC


~/qemu-install/bin$ sudo ./qemu-system-x86_64 -monitor 
telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 
--enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device 
usb-ehci,id=ehci -device 
usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
WARNING: Image format was not specified for '/dev/sdd2' and probing 
guessed raw.
          Automatically detecting the format is dangerous for raw 
images, write operations on block 0 will be restricted.
          Specify the 'raw' format explicitly to remove the restrictions.
libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device 
/dev/bus/usb/003/005: No such file or directory
libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device 
/dev/bus/usb/003/006: No such file or directory
libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device 
/dev/bus/usb/003/007: No such device

The device gets reset again and again and is re-enumerated every time 
and finally not passed through.



After reverting the commit:

~/qemu-patched-install/bin$ sudo ./qemu-system-x86_64 -monitor 
telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 
--enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device 
usb-ehci,id=ehci -device 
usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
WARNING: Image format was not specified for '/dev/sdd2' and probing 
guessed raw.
          Automatically detecting the format is dangerous for raw 
images, write operations on block 0 will be restricted.
          Specify the 'raw' format explicitly to remove the restrictions.


The device appears in the guest OS and can be used.

Tested with HEAD and several libusb versions. Affects at least FTDI 
FT2232H and FTDI FT232R.

Thanks and best regards,
Dennis Ostermann

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
  2015-02-09 21:09 [Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling" Dennis Ostermann
@ 2015-02-10  8:09 ` Hans de Goede
  2015-02-10 21:02   ` Dennis Ostermann
  0 siblings, 1 reply; 4+ messages in thread
From: Hans de Goede @ 2015-02-10  8:09 UTC (permalink / raw)
  To: Dennis Ostermann, qemu-devel; +Cc: kraxel

Hi,

On 09-02-15 22:09, Dennis Ostermann wrote:
> Hi there,
>
> please revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
>
> This breaks usb pass through of FTDI based usb devices:
>
> On the host:
>
> lsusb | grep FT2232
> Bus 003 Device 008: ID 0403:6010 Future Technology Devices International, Ltd FT2232C Dual USB-UART/FIFO IC
>
>
> ~/qemu-install/bin$ sudo ./qemu-system-x86_64 -monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device usb-ehci,id=ehci -device usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
> WARNING: Image format was not specified for '/dev/sdd2' and probing guessed raw.
>           Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.
>           Specify the 'raw' format explicitly to remove the restrictions.
> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/005: No such file or directory
> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/006: No such file or directory
> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/007: No such device
>
> The device gets reset again and again and is re-enumerated every time and finally not passed through.

This looks like the device drops of the bus when it is reset, that is not normal behavior,
there seems to be something unique to your setup causing this. Have you tried this on
multiple machines / different usb ports on your pc ? This may be something weird with the usb
controller in your machine.

>
>
>
> After reverting the commit:
>
> ~/qemu-patched-install/bin$ sudo ./qemu-system-x86_64 -monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device usb-ehci,id=ehci -device usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
> WARNING: Image format was not specified for '/dev/sdd2' and probing guessed raw.
>           Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.
>           Specify the 'raw' format explicitly to remove the restrictions.
>
>
> The device appears in the guest OS and can be used.
>
> Tested with HEAD and several libusb versions. Affects at least FTDI FT2232H and FTDI FT232R.

Which versions of libusb have you tested exactly ?

Regards,

Hans

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
  2015-02-10  8:09 ` Hans de Goede
@ 2015-02-10 21:02   ` Dennis Ostermann
  2015-02-11  7:29     ` Hans de Goede
  0 siblings, 1 reply; 4+ messages in thread
From: Dennis Ostermann @ 2015-02-10 21:02 UTC (permalink / raw)
  To: qemu-devel; +Cc: Hans de Goede, kraxel

Hello Hans,

thanks for taking care.


09-02-15 09:09, Hans de Goede wrote:
> Hi,
>
> On 09-02-15 22:09, Dennis Ostermann wrote:
>> Hi there,
>>
>> please revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
>>
>> This breaks usb pass through of FTDI based usb devices:
>>
>> On the host:
>>
>> lsusb | grep FT2232
>> Bus 003 Device 008: ID 0403:6010 Future Technology Devices International, Ltd FT2232C Dual USB-UART/FIFO IC
>>
>>
>> ~/qemu-install/bin$ sudo ./qemu-system-x86_64 -monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device usb-ehci,id=ehci -device usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
>> WARNING: Image format was not specified for '/dev/sdd2' and probing guessed raw.
>>            Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.
>>            Specify the 'raw' format explicitly to remove the restrictions.
>> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/005: No such file or directory
>> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/006: No such file or directory
>> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/007: No such device
>>
>> The device gets reset again and again and is re-enumerated every time and finally not passed through.
> This looks like the device drops of the bus when it is reset, that is not normal behavior,
> there seems to be something unique to your setup causing this. Have you tried this on
> multiple machines / different usb ports on your pc ? This may be something weird with the usb
> controller in your machine.
The machine uses Intel H97 chipset, so not that unique. I tried every 
port, every USB BIOS, with and without hub, it doesn't make any 
difference. But you're right, I also tried it on a T61 with Intel 900 
series chipset and it worked alright. But this is an 'old' USB 2.0 
chipset. I'll try on another box with USB 3.0 chipset tomorrow, if I can 
get one.
With the commit reverted, it even works behind a no-name china USB 3.0 hub.

>>
>> After reverting the commit:
>>
>> ~/qemu-patched-install/bin$ sudo ./qemu-system-x86_64 -monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device usb-ehci,id=ehci -device usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
>> WARNING: Image format was not specified for '/dev/sdd2' and probing guessed raw.
>>            Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.
>>            Specify the 'raw' format explicitly to remove the restrictions.
>>
>>
>> The device appears in the guest OS and can be used.
>>
>> Tested with HEAD and several libusb versions. Affects at least FTDI FT2232H and FTDI FT232R.
> Which versions of libusb have you tested exactly ?
Latest HEAD, 1.0.16. and 1.0.17. Should I try any other? Couldn't find 
anything in the commit logs that might have s.th. to do with my issue.
I compiled 1.0.16 with debug enabled. Here is what it shows with the 
original qemu:

~/qemu-install/bin$ sudo 
LD_LIBRARY_PATH=~/Devel/libusb-1.0.16-install/lib ./qemu-system-x86_64 
-monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir 
tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 
8192  -usb -device usb-ehci,id=ehci -device 
usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
WARNING: Image format was not specified for '/dev/sdd2' and probing 
guessed raw.
          Automatically detecting the format is dangerous for raw 
images, write operations on block 0 will be restricted.
          Specify the 'raw' format explicitly to remove the restrictions.
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000003] [0000081c] libusbx: debug [libusb_init] created default context
[ 0.000037] [0000081c] libusbx: debug [libusb_init] libusbx v1.0.16.10774
[ 0.000057] [0000081c] libusbx: debug [find_usbfs_path] found usbfs at 
/dev/bus/usb
[ 0.000067] [0000081c] libusbx: debug [op_init] bulk continuation flag 
supported
[ 0.000070] [0000081c] libusbx: debug [op_init] zero length packet flag 
supported
[ 0.000080] [0000081c] libusbx: debug [op_init] sysfs can relate devices
[ 0.000085] [0000081c] libusbx: debug [op_init] sysfs has complete 
descriptors
[ 0.000310] [00000824] libusbx: debug [linux_udev_event_thread_main] 
udev event thread entering.
[ 0.000469] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: usb1 detached: 0
[ 0.000477] [0000081c] libusbx: debug [linux_get_device_address] scan usb1
[ 0.000509] [0000081c] libusbx: debug [linux_get_device_address] bus=1 dev=1
[ 0.000514] [0000081c] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 1 session_id 257
[ 0.000518] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/1 (session 257)
[ 0.000576] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: 1-10 detached: 0
[ 0.000581] [0000081c] libusbx: debug [linux_get_device_address] scan 1-10
[ 0.000608] [0000081c] libusbx: debug [linux_get_device_address] bus=1 
dev=19
[ 0.000612] [0000081c] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 19 session_id 275
[ 0.000616] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/19 (session 275)
[ 0.000646] [0000081c] libusbx: debug [linux_get_parent_info] Dev 
0x7f6fad6fdd20 (1-10) has parent 0x7f6fad6fdc20 (usb1) port 10
[ 0.000704] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: 1-12 detached: 0
[ 0.000708] [0000081c] libusbx: debug [linux_get_device_address] scan 1-12
[ 0.000733] [0000081c] libusbx: debug [linux_get_device_address] bus=1 
dev=13
[ 0.000738] [0000081c] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 13 session_id 269
[ 0.000742] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/13 (session 269)
[ 0.000757] [0000081c] libusbx: debug [linux_get_parent_info] Dev 
0x7f6fad6fd4b0 (1-12) has parent 0x7f6fad6fdc20 (usb1) port 12
[ 0.000812] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: 1-4 detached: 0
[ 0.000817] [0000081c] libusbx: debug [linux_get_device_address] scan 1-4
[ 0.000851] [0000081c] libusbx: debug [linux_get_device_address] bus=1 
dev=11
[ 0.000855] [0000081c] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 11 session_id 267
[ 0.000858] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/11 (session 267)
[ 0.000872] [0000081c] libusbx: debug [linux_get_parent_info] Dev 
0x7f6fad6fd550 (1-4) has parent 0x7f6fad6fdc20 (usb1) port 4
[ 0.000900] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: 1-6 detached: 0
[ 0.000905] [0000081c] libusbx: debug [linux_get_device_address] scan 1-6
[ 0.000921] [0000081c] libusbx: debug [linux_get_device_address] bus=1 dev=2
[ 0.000925] [0000081c] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 2 session_id 258
[ 0.000929] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/2 (session 258)
[ 0.000944] [0000081c] libusbx: debug [linux_get_parent_info] Dev 
0x7f6fad6fd5f0 (1-6) has parent 0x7f6fad6fdc20 (usb1) port 6
[ 0.000971] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: usb2 detached: 0
[ 0.000976] [0000081c] libusbx: debug [linux_get_device_address] scan usb2
[ 0.000991] [0000081c] libusbx: debug [linux_get_device_address] bus=2 dev=1
[ 0.000995] [0000081c] libusbx: debug [linux_enumerate_device] busnum 2 
devaddr 1 session_id 513
[ 0.000999] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 2/1 (session 513)
[ 0.001035] [0000081c] libusbx: debug [linux_get_device_address] getting 
address for device: 2-4 detached: 0
[ 0.001040] [0000081c] libusbx: debug [linux_get_device_address] scan 2-4
[ 0.001056] [0000081c] libusbx: debug [linux_get_device_address] bus=2 dev=2
[ 0.001061] [0000081c] libusbx: debug [linux_enumerate_device] busnum 2 
devaddr 2 session_id 514
[ 0.001064] [0000081c] libusbx: debug [linux_enumerate_device] 
allocating new device for 2/2 (session 514)
[ 0.001079] [0000081c] libusbx: debug [linux_get_parent_info] Dev 
0x7f6fad6fd690 (2-4) has parent 0x7f6fad650db0 (usb2) port 4
[ 0.001105] [0000081c] libusbx: debug [usbi_add_pollfd] add fd 16 events 1
[ 0.001111] [0000081c] libusbx: debug [usbi_add_pollfd] add fd 18 events 1
[ 0.001117] [0000081c] libusbx: debug [usbi_io_init] using timerfd for 
timeouts
[ 0.001121] [0000081c] libusbx: debug [usbi_add_pollfd] add fd 20 events 1
[ 0.079545] [0000081c] libusbx: debug [libusb_get_device_list]
[ 0.079674] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.079695] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.079709] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.079722] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.079736] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.079749] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.079765] [0000081c] libusbx: debug [libusb_open] open 1.19
[ 0.079821] [0000081c] libusbx: debug [usbi_add_pollfd] add fd 22 events 4
[ 0.079961] [0000081c] libusbx: debug [libusb_kernel_driver_active] 
interface 0
[ 0.079986] [0000081c] libusbx: error [op_kernel_driver_active] Get 
driver: ftdi_sio
[ 0.080001] [0000081c] libusbx: debug [libusb_detach_kernel_driver] 
interface 0
[ 0.080279] [0000081c] libusbx: debug [libusb_kernel_driver_active] 
interface 1
[ 0.080326] [0000081c] libusbx: error [op_kernel_driver_active] Get 
driver: ftdi_sio
[ 0.080342] [0000081c] libusbx: debug [libusb_detach_kernel_driver] 
interface 1
[ 0.080608] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.080738] [0000081c] libusbx: debug [libusb_get_config_descriptor] index 0
[ 0.080772] [0000081c] libusbx: debug [libusb_get_config_descriptor] index 1
[ 0.080796] [0000081c] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 1000ms (first in line)
[ 0.080850] [0000081c] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.080870] [0000081c] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 60000ms
[ 0.080891] [0000081c] libusbx: debug [handle_events] poll() returned 1
[ 0.080910] [0000081c] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=4
[ 0.080926] [0000081c] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.080941] [0000081c] libusbx: debug [disarm_timerfd]
[ 0.080957] [0000081c] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7f6fad7002e8 has callback 0x7f6fa9540bd0
[ 0.080984] [0000081c] libusbx: debug [sync_transfer_cb] actual_length=4
[ 0.081010] [0000081c] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 1000ms (first in line)
[ 0.081035] [0000081c] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.081050] [0000081c] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 60000ms
[ 0.082213] [0000081c] libusbx: debug [handle_events] poll() returned 1
[ 0.082261] [0000081c] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=24
[ 0.082278] [0000081c] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.082294] [0000081c] libusbx: debug [disarm_timerfd]
[ 0.082310] [0000081c] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7f6fad7002e8 has callback 0x7f6fa9540bd0
[ 0.082326] [0000081c] libusbx: debug [sync_transfer_cb] actual_length=24
[ 0.082359] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.141951] [0000081f] libusbx: debug [libusb_reset_device]
[ 0.323290] [0000081c] libusbx: debug [libusb_reset_device]
[ 0.323396] [0000081c] libusbx: debug [sysfs_get_active_config] device 
unconfigured
[ 0.323402] [0000081c] libusbx: debug [libusb_close]
[ 0.323408] [0000081c] libusbx: debug [usbi_remove_pollfd] remove fd 22
[ 0.323415] [0000081c] libusbx: debug [libusb_get_device_list]
[ 0.323436] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323439] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323442] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323445] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323448] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323451] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323454] [0000081c] libusbx: debug [libusb_open] open 1.19
[ 0.323479] [0000081c] libusbx: error [_get_usbfs_fd] libusbx couldn't 
open USB device /dev/bus/usb/001/019: No such file or directory
[ 0.323483] [0000081c] libusbx: debug [libusb_open] open 1.19 returns -4
[ 0.323486] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 0.323786] [00000824] libusbx: debug [linux_get_device_address] getting 
address for device: 1-10 detached: 1
[ 0.323798] [00000824] libusbx: debug [udev_hotplug_event] udev hotplug 
event. action: remove.
[ 0.327153] [0000081c] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.327167] [0000081c] libusbx: debug [handle_events] poll() 3 fds with 
timeout in 0ms
[ 0.327173] [0000081c] libusbx: debug [handle_events] poll() returned 1
[ 0.327176] [0000081c] libusbx: debug [handle_events] caught a fish on 
the hotplug pipe
[ 0.327183] [0000081c] libusbx: debug [libusb_unref_device] destroy 
device 1.19
[ 0.458307] [00000824] libusbx: debug [linux_get_device_address] getting 
address for device: 1-10 detached: 0
[ 0.458370] [00000824] libusbx: debug [linux_get_device_address] scan 1-10
[ 0.458430] [00000824] libusbx: debug [linux_get_device_address] bus=1 
dev=20
[ 0.458453] [00000824] libusbx: debug [udev_hotplug_event] udev hotplug 
event. action: add.
[ 0.458470] [00000824] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 20 session_id 276
[ 0.458487] [00000824] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/20 (session 276)
[ 0.458526] [00000824] libusbx: debug [linux_get_parent_info] Dev 
0x7f6d88001ae0 (1-10) has parent 0x7f6fad6fdc20 (usb1) port 10
[ 0.458565] [0000081c] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.458572] [0000081c] libusbx: debug [handle_events] poll() 3 fds with 
timeout in 0ms
[ 0.458576] [0000081c] libusbx: debug [handle_events] poll() returned 1
[ 0.458579] [0000081c] libusbx: debug [handle_events] caught a fish on 
the hotplug pipe
[ 2.323468] [0000081c] libusbx: debug [libusb_get_device_list]
[ 2.323479] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.323482] [0000081c] libusbx: debug [libusb_open] open 1.20
[ 2.323492] [0000081c] libusbx: debug [usbi_add_pollfd] add fd 22 events 4
[ 2.323534] [0000081c] libusbx: debug [libusb_kernel_driver_active] 
interface 0
[ 2.323536] [0000081c] libusbx: error [op_kernel_driver_active] Get 
driver: ftdi_sio
[ 2.323538] [0000081c] libusbx: debug [libusb_detach_kernel_driver] 
interface 0
[ 2.323695] [0000081c] libusbx: debug [libusb_kernel_driver_active] 
interface 1
[ 2.323709] [0000081c] libusbx: error [op_kernel_driver_active] Get 
driver: ftdi_sio
[ 2.323710] [0000081c] libusbx: debug [libusb_detach_kernel_driver] 
interface 1
[ 2.323922] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.323946] [0000081c] libusbx: debug [libusb_get_config_descriptor] index 0
[ 2.323948] [0000081c] libusbx: debug [libusb_get_config_descriptor] index 1
[ 2.323951] [0000081c] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 1000ms (first in line)
[ 2.323957] [0000081c] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 2.323959] [0000081c] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 60000ms
[ 2.324454] [0000081c] libusbx: debug [handle_events] poll() returned 1
[ 2.324460] [0000081c] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=4
[ 2.324462] [0000081c] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 2.324464] [0000081c] libusbx: debug [disarm_timerfd]
[ 2.324465] [0000081c] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7f6fad67a3f8 has callback 0x7f6fa9540bd0
[ 2.324467] [0000081c] libusbx: debug [sync_transfer_cb] actual_length=4
[ 2.324470] [0000081c] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 1000ms (first in line)
[ 2.324474] [0000081c] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 2.324475] [0000081c] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 60000ms
[ 2.325679] [0000081c] libusbx: debug [handle_events] poll() returned 1
[ 2.325685] [0000081c] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=24
[ 2.325687] [0000081c] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 2.325689] [0000081c] libusbx: debug [disarm_timerfd]
[ 2.325690] [0000081c] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7f6fad5ef7b8 has callback 0x7f6fa9540bd0
[ 2.325691] [0000081c] libusbx: debug [sync_transfer_cb] actual_length=24
[ 2.325696] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.325697] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.325698] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.325699] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.325700] [0000081c] libusbx: debug [libusb_get_device_descriptor]
[ 2.325701] [0000081c] libusbx: debug [libusb_get_device_descriptor]

And this is the latest qemu with the commit reverted (That doesn't reset 
unconfigured devices):

~/qemu-patched-install/bin$ sudo 
LD_LIBRARY_PATH=~/Devel/libusb-1.0.16-install/lib ./qemu-system-x86_64 
-monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir 
tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 
8192  -usb -device usb-ehci,id=ehci -device 
usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
WARNING: Image format was not specified for '/dev/sdd2' and probing 
guessed raw.
          Automatically detecting the format is dangerous for raw 
images, write operations on block 0 will be restricted.
          Specify the 'raw' format explicitly to remove the restrictions.
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000002] [00000838] libusbx: debug [libusb_init] created default context
[ 0.000037] [00000838] libusbx: debug [libusb_init] libusbx v1.0.16.10774
[ 0.000059] [00000838] libusbx: debug [find_usbfs_path] found usbfs at 
/dev/bus/usb
[ 0.000070] [00000838] libusbx: debug [op_init] bulk continuation flag 
supported
[ 0.000073] [00000838] libusbx: debug [op_init] zero length packet flag 
supported
[ 0.000082] [00000838] libusbx: debug [op_init] sysfs can relate devices
[ 0.000086] [00000838] libusbx: debug [op_init] sysfs has complete 
descriptors
[ 0.000326] [00000840] libusbx: debug [linux_udev_event_thread_main] 
udev event thread entering.
[ 0.000468] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: usb1 detached: 0
[ 0.000476] [00000838] libusbx: debug [linux_get_device_address] scan usb1
[ 0.000500] [00000838] libusbx: debug [linux_get_device_address] bus=1 dev=1
[ 0.000528] [00000838] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 1 session_id 257
[ 0.000531] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/1 (session 257)
[ 0.000593] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: 1-10 detached: 0
[ 0.000598] [00000838] libusbx: debug [linux_get_device_address] scan 1-10
[ 0.000625] [00000838] libusbx: debug [linux_get_device_address] bus=1 
dev=20
[ 0.000630] [00000838] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 20 session_id 276
[ 0.000634] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/20 (session 276)
[ 0.000663] [00000838] libusbx: debug [linux_get_parent_info] Dev 
0x7fcb2532ebd0 (1-10) has parent 0x7fcb2532eb10 (usb1) port 10
[ 0.000728] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: 1-12 detached: 0
[ 0.000733] [00000838] libusbx: debug [linux_get_device_address] scan 1-12
[ 0.000760] [00000838] libusbx: debug [linux_get_device_address] bus=1 
dev=13
[ 0.000765] [00000838] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 13 session_id 269
[ 0.000768] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/13 (session 269)
[ 0.000784] [00000838] libusbx: debug [linux_get_parent_info] Dev 
0x7fcb2532ecb0 (1-12) has parent 0x7fcb2532eb10 (usb1) port 12
[ 0.000842] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: 1-4 detached: 0
[ 0.000847] [00000838] libusbx: debug [linux_get_device_address] scan 1-4
[ 0.000864] [00000838] libusbx: debug [linux_get_device_address] bus=1 
dev=11
[ 0.000869] [00000838] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 11 session_id 267
[ 0.000872] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/11 (session 267)
[ 0.000889] [00000838] libusbx: debug [linux_get_parent_info] Dev 
0x7fcb2532f6b0 (1-4) has parent 0x7fcb2532eb10 (usb1) port 4
[ 0.000918] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: 1-6 detached: 0
[ 0.000923] [00000838] libusbx: debug [linux_get_device_address] scan 1-6
[ 0.000940] [00000838] libusbx: debug [linux_get_device_address] bus=1 dev=2
[ 0.000944] [00000838] libusbx: debug [linux_enumerate_device] busnum 1 
devaddr 2 session_id 258
[ 0.000948] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 1/2 (session 258)
[ 0.000963] [00000838] libusbx: debug [linux_get_parent_info] Dev 
0x7fcb2532f770 (1-6) has parent 0x7fcb2532eb10 (usb1) port 6
[ 0.000992] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: usb2 detached: 0
[ 0.000997] [00000838] libusbx: debug [linux_get_device_address] scan usb2
[ 0.001014] [00000838] libusbx: debug [linux_get_device_address] bus=2 dev=1
[ 0.001019] [00000838] libusbx: debug [linux_enumerate_device] busnum 2 
devaddr 1 session_id 513
[ 0.001022] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 2/1 (session 513)
[ 0.001060] [00000838] libusbx: debug [linux_get_device_address] getting 
address for device: 2-4 detached: 0
[ 0.001065] [00000838] libusbx: debug [linux_get_device_address] scan 2-4
[ 0.001082] [00000838] libusbx: debug [linux_get_device_address] bus=2 dev=2
[ 0.001087] [00000838] libusbx: debug [linux_enumerate_device] busnum 2 
devaddr 2 session_id 514
[ 0.001090] [00000838] libusbx: debug [linux_enumerate_device] 
allocating new device for 2/2 (session 514)
[ 0.001107] [00000838] libusbx: debug [linux_get_parent_info] Dev 
0x7fcb252d02d0 (2-4) has parent 0x7fcb252d0230 (usb2) port 4
[ 0.001133] [00000838] libusbx: debug [usbi_add_pollfd] add fd 16 events 1
[ 0.001140] [00000838] libusbx: debug [usbi_add_pollfd] add fd 18 events 1
[ 0.001147] [00000838] libusbx: debug [usbi_io_init] using timerfd for 
timeouts
[ 0.001150] [00000838] libusbx: debug [usbi_add_pollfd] add fd 20 events 1
[ 0.074566] [00000838] libusbx: debug [libusb_get_device_list]
[ 0.074647] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.074669] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.074687] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.074705] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.074720] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.074734] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.074748] [00000838] libusbx: debug [libusb_open] open 1.20
[ 0.074804] [00000838] libusbx: debug [usbi_add_pollfd] add fd 22 events 4
[ 0.074962] [00000838] libusbx: debug [libusb_kernel_driver_active] 
interface 0
[ 0.074989] [00000838] libusbx: error [op_kernel_driver_active] Get 
driver: ftdi_sio
[ 0.075006] [00000838] libusbx: debug [libusb_detach_kernel_driver] 
interface 0
[ 0.075311] [00000838] libusbx: debug [libusb_kernel_driver_active] 
interface 1
[ 0.075359] [00000838] libusbx: error [op_kernel_driver_active] Get 
driver: ftdi_sio
[ 0.075375] [00000838] libusbx: debug [libusb_detach_kernel_driver] 
interface 1
[ 0.075641] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.075749] [00000838] libusbx: debug [libusb_get_config_descriptor] index 0
[ 0.075761] [00000838] libusbx: debug [libusb_get_config_descriptor] index 1
[ 0.075775] [00000838] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 1000ms (first in line)
[ 0.075819] [00000838] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.075827] [00000838] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 60000ms
[ 0.075839] [00000838] libusbx: debug [handle_events] poll() returned 1
[ 0.075847] [00000838] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=4
[ 0.075854] [00000838] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.075860] [00000838] libusbx: debug [disarm_timerfd]
[ 0.075866] [00000838] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7fcb25328998 has callback 0x7fcb22b21bd0
[ 0.075872] [00000838] libusbx: debug [sync_transfer_cb] actual_length=4
[ 0.075889] [00000838] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 1000ms (first in line)
[ 0.075900] [00000838] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.075906] [00000838] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 60000ms
[ 0.077092] [00000838] libusbx: debug [handle_events] poll() returned 1
[ 0.077144] [00000838] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=24
[ 0.077161] [00000838] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.077177] [00000838] libusbx: debug [disarm_timerfd]
[ 0.077192] [00000838] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7fcb25328998 has callback 0x7fcb22b21bd0
[ 0.077208] [00000838] libusbx: debug [sync_transfer_cb] actual_length=24
[ 0.077244] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 0.234815] [00000838] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 10000ms (first in line)
[ 0.234924] [00000838] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.234933] [00000838] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 0ms
[ 0.234947] [00000838] libusbx: debug [handle_events] poll() returned 1
[ 0.234952] [00000838] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=8
[ 0.234955] [00000838] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.234959] [00000838] libusbx: debug [disarm_timerfd]
[ 0.234962] [00000838] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7fcb252b5d98 has callback 0x7fcb24229710
[ 0.236001] [00000838] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 10000ms (first in line)
[ 0.236133] [00000838] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.236143] [00000838] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 0ms
[ 0.236156] [00000838] libusbx: debug [handle_events] poll() returned 1
[ 0.236160] [00000838] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=9
[ 0.236164] [00000838] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.236167] [00000838] libusbx: debug [disarm_timerfd]
[ 0.236170] [00000838] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7fcb2529f568 has callback 0x7fcb24229710
[ 0.237209] [00000838] libusbx: debug [add_to_flying_list] arm timerfd 
for timeout in 10000ms (first in line)
[ 0.237362] [00000838] libusbx: debug 
[libusb_handle_events_timeout_completed] doing our own event handling
[ 0.237372] [00000838] libusbx: debug [handle_events] poll() 4 fds with 
timeout in 0ms
[ 0.237385] [00000838] libusbx: debug [handle_events] poll() returned 1
[ 0.237389] [00000838] libusbx: debug [reap_for_handle] urb type=2 
status=0 transferred=55
[ 0.237392] [00000838] libusbx: debug [handle_control_completion] 
handling completion status 0
[ 0.237395] [00000838] libusbx: debug [disarm_timerfd]
[ 0.237408] [00000838] libusbx: debug [usbi_handle_transfer_completion] 
transfer 0x7fcb2527b358 has callback 0x7fcb24229710
[ 2.077254] [00000838] libusbx: debug [libusb_get_device_list]
[ 2.077267] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 2.077268] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 2.077269] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 2.077271] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 2.077272] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 2.077272] [00000838] libusbx: debug [libusb_get_device_descriptor]
[ 2.077273] [00000838] libusbx: debug [libusb_get_device_descriptor]

> Regards,
>
> Hans
Best regards,
Dennis

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
  2015-02-10 21:02   ` Dennis Ostermann
@ 2015-02-11  7:29     ` Hans de Goede
  0 siblings, 0 replies; 4+ messages in thread
From: Hans de Goede @ 2015-02-11  7:29 UTC (permalink / raw)
  To: Dennis Ostermann, qemu-devel; +Cc: kraxel

Hi,

On 10-02-15 22:02, Dennis Ostermann wrote:
> Hello Hans,
>
> thanks for taking care.
>
>
> 09-02-15 09:09, Hans de Goede wrote:
>> Hi,
>>
>> On 09-02-15 22:09, Dennis Ostermann wrote:
>>> Hi there,
>>>
>>> please revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling"
>>>
>>> This breaks usb pass through of FTDI based usb devices:
>>>
>>> On the host:
>>>
>>> lsusb | grep FT2232
>>> Bus 003 Device 008: ID 0403:6010 Future Technology Devices International, Ltd FT2232C Dual USB-UART/FIFO IC
>>>
>>>
>>> ~/qemu-install/bin$ sudo ./qemu-system-x86_64 -monitor telnet:127.0.0.1:1234,server,nowait -hda /dev/sdd2 -redir tcp:20022::22 --enable-kvm -cpu host -smp 4 -vga vmware --vnc :0 -m 8192  -usb -device usb-ehci,id=ehci -device usb-host,bus=ehci.0,vendorid=0x0403,productid=0x6010
>>> WARNING: Image format was not specified for '/dev/sdd2' and probing guessed raw.
>>>            Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.
>>>            Specify the 'raw' format explicitly to remove the restrictions.
>>> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/005: No such file or directory
>>> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/006: No such file or directory
>>> libusbx: error [_get_usbfs_fd] libusbx couldn't open USB device /dev/bus/usb/003/007: No such device
>>>
>>> The device gets reset again and again and is re-enumerated every time and finally not passed through.
>> This looks like the device drops of the bus when it is reset, that is not normal behavior,
>> there seems to be something unique to your setup causing this. Have you tried this on
>> multiple machines / different usb ports on your pc ? This may be something weird with the usb
>> controller in your machine.
> The machine uses Intel H97 chipset, so not that unique. I tried every port, every USB BIOS, with and without hub, it doesn't make any difference. But you're right, I also tried it on a T61 with Intel 900 series chipset and it worked alright. But this is an 'old' USB 2.0 chipset. I'll try on another box with USB 3.0 chipset tomorrow, if I can get one.

Ok, lets wait and see what results another model usb-3 capable pc / laptop gets us, I've
the feeling that this is a machine specific issue. Normally a usb-reset should not cause
a device disconnect as you're seeing here.

Regards,

Hans

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2015-02-11  7:30 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2015-02-09 21:09 [Qemu-devel] Revert commit 5af35d7feccaa7d26b72c6c3d14116421d736b36 - "usb-host-libusb: Fix reset handling" Dennis Ostermann
2015-02-10  8:09 ` Hans de Goede
2015-02-10 21:02   ` Dennis Ostermann
2015-02-11  7:29     ` Hans de Goede

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).