Re: usbip port number limits

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Yuyang,

> 
> ----- Mensaje original -----
> De: "Yuyang Du" <yuyang.du@xxxxxxxxxxxxxxx>
> Para: "Juan Zea" <juan.zea@xxxxxxxxxx>
> CC: "Shuah Khan" <shuahkh@xxxxxxxxxxxxxxx>, shuah@xxxxxxxxxx, "Bjørn Mork" <bjorn@xxxxxxx>, linux-usb@xxxxxxxxxxxxxxx, "Valentina Manea" <valentina.manea.m@xxxxxxxxx>
> Enviados: Miércoles, 22 de Noviembre 2017 8:54:03
> Asunto: Re: usbip port number limits
> 
> Hi Juan,
> 
> On Tue, Nov 21, 2017 at 12:24:01PM +0100, Juan Zea wrote:
> >   Please excuse me... I have reported two different problems in this post, and I think things are mixing up a bit. My bad. I've found two different problems:
> > 
> > 1.- When compiling vhci driver with multiple hubs (in latest kernel), usbip tool doesn't seem able to "jump" to the second controller. As far as I understand, it seems to be a problem with high speed devices trying to get connected to super speed ports. I made a patch for avoiding this situation which is almost the same as the one you just sent. Both patches work. I can compile with several hubs of one port, and connect two devices via usbip and the second gets connected to the second controller (skipping the super speed port of first controller).
> > 
> > 2.- The problem is some of these devices don't work, whatsoever controller or hub compiling configuration I do. A fingerprint reader and also recently discovered flash usb sticks don't work either. You can connect them with usbip tool, and they list with lsusb with no problem at all. But when you try to use them, you get this "kernel BUG at drivers/usb/usbip/vhci_hcd.c:669!" (by the way, the line number has changed in the latest pull from master I've just tested, but it's the same line of code). This second problem is the one I bisected in my last message. And I got to the commit 03cd00d538a6feb0492cd153edf256ef7d7bd95e, in which both devices stop working. 
>  
> It'd be good if you can give greater detail of the exact (as much
> info as possible) setting of the fingerprint reader case.
> 

The bug launched in my repository reads:
 669         BUG_ON(!urb->transfer_buffer && urb->transfer_buffer_length);


For my tests, I'm using a kvm machine, with the kernel I want to test. For yesterday's test, I used latest commit: e1d1ea549b57790a3d8cf6300e6ef86118d692a3. I build the kernel with this line:
make x86_64_defconfig; make kvmconfig; cat ../extra.txt >> .config; make -j8
These are the contents of extra.txt:
CONFIG_USBIP_CORE=m
CONFIG_USBIP_VHCI_HCD=m
CONFIG_USBIP_VHCI_HC_PORTS=1
CONFIG_USBIP_VHCI_NR_HCS=4

With this, I get a kvm machine running, in which I load the vhci driver on startup. This driver creates this devices:
root@kernel-tester:~# lsusb
Bus 008 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 007 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

I compile the usbip tools from within this machine on startup too (from the same repository as kernel).


The server is my own laptop, running this kernel: 4.11.0-14-generic, also host to the kvm machine. Network for kvm is a bridge.

In my laptop, the fingerprint reader lists like this:
Bus 002 Device 004: ID 05ba:000a DigitalPersona, Inc. Fingerprint Reader

And this is dmesg when connecting it to my laptop:
[ 3941.459772] usb 2-1.3: new full-speed USB device number 4 using ehci-pci
[ 3941.575718] usb 2-1.3: New USB device found, idVendor=05ba, idProduct=000a
[ 3941.575722] usb 2-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3941.575725] usb 2-1.3: Product: Biokey 200 Fingerprint Scanner
[ 3941.575728] usb 2-1.3: Manufacturer: ZKSoftware Inc.
[ 3941.575730] usb 2-1.3: SerialNumber: {XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX}

Reproduce steps:

1.- Having my laptop with usbip_host module loaded, and 'usbipd -d' running in terminal, bind the reader:
# usbip -d bind -b 2-1.3
usbip: debug: usbip.c:141:[run_command] running command: `bind'
usbip: info: bind device on busid 2-1.3: complete

dmesg reads: 
[ 4092.811059] usbip-host 2-1.3: usbip-host: register new device (bus 2 dev 4)

2.- From kvm machine, with vhci_hcd module loaded, and usbip tools compiled and installed:
# usbip -d attach -r 172.26.8.66 -b 2-1.3
usbip: debug: usbip.c:141:[run_command] running command: `attach'
libusbip: debug: vhci_driver.c:264:[usbip_vhci_driver_open] available ports: 8
libusbip: debug: vhci_driver.c:275:[usbip_vhci_driver_open] available controllers: 4
libusbip: debug: vhci_driver.c:128:[refresh_imported_device_list] controller 0
libusbip: debug: vhci_driver.c:68:[parse_status] hub hs port 0 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:68:[parse_status] hub ss port 1 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:104:[parse_status] exit
libusbip: debug: vhci_driver.c:128:[refresh_imported_device_list] controller 1
libusbip: debug: vhci_driver.c:68:[parse_status] hub hs port 2 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:68:[parse_status] hub ss port 3 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:104:[parse_status] exit
libusbip: debug: vhci_driver.c:128:[refresh_imported_device_list] controller 2
libusbip: debug: vhci_driver.c:68:[parse_status] hub hs port 4 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:68:[parse_status] hub ss port 5 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:104:[parse_status] exit
libusbip: debug: vhci_driver.c:128:[refresh_imported_device_list] controller 3
libusbip: debug: vhci_driver.c:68:[parse_status] hub hs port 6 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:68:[parse_status] hub ss port 7 status 4 speed 0 devid 0
libusbip: debug: vhci_driver.c:69:[parse_status] socket 0 lbusid 0-0
libusbip: debug: vhci_driver.c:104:[parse_status] exit
usbip: debug: usbip_attach.c:112:[import_device] got free port 0
libusbip: debug: vhci_driver.c:362:[usbip_vhci_attach_device2] writing: 0 3 131076 2
libusbip: debug: vhci_driver.c:367:[usbip_vhci_attach_device2] attach attribute path: /sys/devices/platform/vhci_hcd.0/attach
libusbip: debug: vhci_driver.c:375:[usbip_vhci_attach_device2] attached port: 0

kvm dmesg reads:
[  673.438535] vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
[  673.438547] vhci_hcd vhci_hcd.0: devid(131076) speed(2) speed_str(full-speed)
[  673.603515] vhci_hcd: vhci_device speed not set
[  673.603515] vhci_hcd: vhci_device speed not set
[  673.657449] usb 1-1: new full-speed USB device number 2 using vhci_hcd
[  673.720497] vhci_hcd: vhci_device speed not set
[  673.720497] vhci_hcd: vhci_device speed not set
[  673.774416] usb 1-1: SetAddress Request (2) to port 0
[  673.797352] usb 1-1: New USB device found, idVendor=05ba, idProduct=000a
[  673.797357] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  673.797362] usb 1-1: Product: Biokey 200 Fingerprint Scanner
[  673.797368] usb 1-1: Manufacturer: ZKSoftware Inc.
[  673.797370] usb 1-1: SerialNumber: {XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX}

laptop dmesg reads:
[ 4271.104783] usbip-host 2-1.3: stub up
[ 4271.462823] usbip-host 2-1.3: endpoint 0 is stalled
[ 4271.463558] usbip-host 2-1.3: endpoint 0 is stalled
[ 4271.464285] usbip-host 2-1.3: endpoint 0 is stalled

laptop usbipd -d reads:
usbipd: debug: usbipd.c:568:[do_standalone_mode] read event on fd[0]=3
usbipd: info: connection from 192.168.122.127:45942
usbipd: info: received request: 0x8003(5)
usbipd: info: found requested device: 2-1.3
usbip: info: connect: 2-1.3
usbipd: debug: usbipd.c:165:[recv_request_import] import request busid 2-1.3: complete
usbipd: info: request 0x8003(5): complete

3.- lsusb in kvm machine:
# lsusb
Bus 008 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 007 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 002: ID 05ba:000a DigitalPersona, Inc. Fingerprint Reader
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

Everything seems ok.

4.- Run fprint_demo in kvm machine. It says:
Digital Persona U.are.U 4000/4000B/4500
Status: Device ready for use
Driver: uru4000
Imaging device

Up until now, everything is just the same as in previous kernel not impacted by this.

5.- Push any Enroll button in fprint_demo. It will show the appropiate screen, asking you to scan your finger.

When you put your finger in the fingerprint reader, fprint hangs, and you get this in kvm dmesg:
[ 1017.475208] kernel BUG at drivers/usb/usbip/vhci_hcd.c:669!
[ 1017.476830] invalid opcode: 0000 [#1] SMP
[ 1017.477927] Modules linked in: vhci_hcd usbip_core
[ 1017.479632] CPU: 0 PID: 5257 Comm: fprint_demo Not tainted 4.14.0+ #1
[ 1017.483118] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Ubuntu-1.8.2-1ubuntu1 04/01/2014
[ 1017.485901] task: ffff97fe7b29a4c0 task.stack: ffffa701c033c000
[ 1017.487299] RIP: 0010:vhci_urb_enqueue+0x2ee/0x450 [vhci_hcd]
[ 1017.488569] RSP: 0018:ffffa701c033fc90 EFLAGS: 00010002
[ 1017.489647] RAX: 000000000001b340 RBX: 0000000000000001 RCX: 0000000000000003
[ 1017.491174] RDX: 0000000001080020 RSI: ffff97fe7b2c9240 RDI: ffff97fe7fbb0000
[ 1017.493121] RBP: ffff97fe7fbb0000 R08: 000000000001b340 R09: 0000000000000000
[ 1017.494616] R10: 0000000000000001 R11: 0000000000000002 R12: ffff97fe70183e00
[ 1017.496113] R13: 0000000000000000 R14: ffff97fe7faef098 R15: ffff97fe7b2c9240
[ 1017.497540] FS:  00007fe3ff7f9a00(0000) GS:ffff97fe7cc00000(0000) knlGS:0000000000000000
[ 1017.499191] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1017.500385] CR2: 0000556f8de2b010 CR3: 00000000323b1000 CR4: 00000000000006f0
[ 1017.501924] Call Trace:
[ 1017.502446]  usb_hcd_submit_urb+0x83/0x890
[ 1017.503219]  ? __alloc_pages_nodemask+0xe7/0x200
[ 1017.504063]  ? usb_submit_urb+0x3de/0x560
[ 1017.504806]  ? kmalloc_order_trace+0x18/0xa0
[ 1017.505597]  proc_do_submiturb+0xc36/0xcb0
[ 1017.506432]  usbdev_do_ioctl+0xd4e/0x1120
[ 1017.507353]  usbdev_ioctl+0x5/0x10
[ 1017.508104]  do_vfs_ioctl+0x8a/0x5a0
[ 1017.508887]  ? __schedule+0x32f/0x6c0
[ 1017.509704]  SyS_ioctl+0x6f/0x80
[ 1017.510440]  entry_SYSCALL_64_fastpath+0x1a/0x7d
[ 1017.511422] RIP: 0033:0x7fe3faf63ea7
[ 1017.512200] RSP: 002b:00007ffeea09fe58 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 1017.513784] RAX: ffffffffffffffda RBX: 0000556f8dba16b0 RCX: 00007fe3faf63ea7
[ 1017.515278] RDX: 0000556f8dde1010 RSI: 000000008038550a RDI: 000000000000000b
[ 1017.516769] RBP: 0000556f8dba1840 R08: 00007fe3fb234c20 R09: 0000556f8dde1010
[ 1017.518287] R10: 00000000ffffff00 R11: 0000000000000246 R12: 00007fe3fa8fd4d8
[ 1017.519770] R13: 0000000000000000 R14: 00007ffeea0a01f0 R15: 0000000000000000
[ 1017.521301] Code: 4c 89 e7 89 04 24 e8 f2 b6 bd d1 8b 04 24 48 83 c4 20 5b 5d 41 5c 41 5d 41 5e 41 5f c3 8b 86 88 00 00 00 85 c0 0f 84 53 fd ff ff <0f> 0b 0f b7 49 02 48 c7 c6 08 4d 17 c0 4c 89 f7 e8 2d 9c 7d d1 
[ 1017.525613] RIP: vhci_urb_enqueue+0x2ee/0x450 [vhci_hcd] RSP: ffffa701c033fc90
[ 1017.527274] ---[ end trace b4edcee8867b2fdf ]---
[ 1017.475204] ------------[ cut here ]------------
[ 1017.475208] kernel BUG at drivers/usb/usbip/vhci_hcd.c:669!
[ 1017.476830] invalid opcode: 0000 [#1] SMP
[ 1017.477927] Modules linked in: vhci_hcd usbip_core
[ 1017.479632] CPU: 0 PID: 5257 Comm: fprint_demo Not tainted 4.14.0+ #1
[ 1017.483118] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Ubuntu-1.8.2-1ubuntu1 04/01/2014
[ 1017.485901] task: ffff97fe7b29a4c0 task.stack: ffffa701c033c000
[ 1017.487299] RIP: 0010:vhci_urb_enqueue+0x2ee/0x450 [vhci_hcd]
[ 1017.488569] RSP: 0018:ffffa701c033fc90 EFLAGS: 00010002
[ 1017.489647] RAX: 000000000001b340 RBX: 0000000000000001 RCX: 0000000000000003
[ 1017.491174] RDX: 0000000001080020 RSI: ffff97fe7b2c9240 RDI: ffff97fe7fbb0000
[ 1017.493121] RBP: ffff97fe7fbb0000 R08: 000000000001b340 R09: 0000000000000000
[ 1017.494616] R10: 0000000000000001 R11: 0000000000000002 R12: ffff97fe70183e00
[ 1017.496113] R13: 0000000000000000 R14: ffff97fe7faef098 R15: ffff97fe7b2c9240
[ 1017.497540] FS:  00007fe3ff7f9a00(0000) GS:ffff97fe7cc00000(0000) knlGS:0000000000000000
[ 1017.499191] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1017.500385] CR2: 0000556f8de2b010 CR3: 00000000323b1000 CR4: 00000000000006f0
[ 1017.501924] Call Trace:
[ 1017.502446]  usb_hcd_submit_urb+0x83/0x890
[ 1017.503219]  ? __alloc_pages_nodemask+0xe7/0x200
[ 1017.504063]  ? usb_submit_urb+0x3de/0x560
[ 1017.504806]  ? kmalloc_order_trace+0x18/0xa0
[ 1017.505597]  proc_do_submiturb+0xc36/0xcb0
[ 1017.506432]  usbdev_do_ioctl+0xd4e/0x1120
[ 1017.507353]  usbdev_ioctl+0x5/0x10
[ 1017.508104]  do_vfs_ioctl+0x8a/0x5a0
[ 1017.508887]  ? __schedule+0x32f/0x6c0
[ 1017.509704]  SyS_ioctl+0x6f/0x80
[ 1017.510440]  entry_SYSCALL_64_fastpath+0x1a/0x7d
[ 1017.511422] RIP: 0033:0x7fe3faf63ea7
[ 1017.512200] RSP: 002b:00007ffeea09fe58 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 1017.513784] RAX: ffffffffffffffda RBX: 0000556f8dba16b0 RCX: 00007fe3faf63ea7
[ 1017.515278] RDX: 0000556f8dde1010 RSI: 000000008038550a RDI: 000000000000000b
[ 1017.516769] RBP: 0000556f8dba1840 R08: 00007fe3fb234c20 R09: 0000556f8dde1010
[ 1017.518287] R10: 00000000ffffff00 R11: 0000000000000246 R12: 00007fe3fa8fd4d8
[ 1017.519770] R13: 0000000000000000 R14: 00007ffeea0a01f0 R15: 0000000000000000
[ 1017.521301] Code: 4c 89 e7 89 04 24 e8 f2 b6 bd d1 8b 04 24 48 83 c4 20 5b 5d 41 5c 41 5d 41 5e 41 5f c3 8b 86 88 00 00 00 85 c0 0f 84 53 fd ff ff <0f> 0b 0f b7 49 02 48 c7 c6 08 4d 17 c0 4c 89 f7 e8 2d 9c 7d d1 
[ 1017.525613] RIP: vhci_urb_enqueue+0x2ee/0x450 [vhci_hcd] RSP: ffffa701c033fc90
[ 1017.527274] ---[ end trace b4edcee8867b2fdf ]---


Now, lsusb still lists the fingerprint reader. If you try to run fprint_demo again, it will hang immediately, showing a blank screen (I suppose it hangs trying to access the reader). The terminal from within I'm launching it, is also hung.

6.- Try to unload vhci_hcd module:
# rmmod vhci_hcd
rmmod: ERROR: ../libkmod/libkmod.c:514 lookup_builtin_file() could not open builtin file '/lib/modules/4.14.0+/modules.builtin.bin'

Terminal hangs.

dmesg reads:
[ 1319.204615] vhci_hcd vhci_hcd.0: remove, state 4
[ 1319.206679] usb usb2: USB disconnect, device number 1
[ 1319.204615] vhci_hcd vhci_hcd.0: remove, state 4
[ 1319.206679] usb usb2: USB disconnect, device number 1
[ 1319.214494] vhci_hcd: stop threads
[ 1319.215507] vhci_hcd: release socket
[ 1319.216529] vhci_hcd: disconnect device
[ 1319.214494] vhci_hcd: stop threads[ 1319.218734] vhci_hcd vhci_hcd.0: USB bus 2 deregistered

[ 1319.215507] vhci_hcd: release socket
[ 1319.223402] vhci_hcd vhci_hcd.0: remove, state 1
[ 1319.216529] vhci_hcd: disconnect device
[ 1319.218734] vhci_hcd vhci_hcd.0: USB bus 2 deregistered[ 1319.227461] usb usb1: USB disconnect, device number 1

[ 1319.223402] vhci_hcd vhci_hcd.0: remove, state 1[ 1319.229565] usb 1-1: USB disconnect, device number 2

[ 1319.227461] usb usb1: USB disconnect, device number 1
[ 1319.229565] usb 1-1: USB disconnect, device number 2

Everything is still up:
# lsusb
Bus 008 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 007 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 002: ID 05ba:000a DigitalPersona, Inc. Fingerprint Reader
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

# lsmod    
Module                  Size  Used by
vhci_hcd               28672  -1
usbip_core             16384  1 vhci_hcd

vhci driver is not answering:
# usbip port
libusbip: error: udev_device_new_from_subsystem_sysname failed
usbip: error: open vhci_driver
usbip: error: list imported devices

Shutting down kvm machine will hang, as Shuah points out (sorry, I think I never told you about that).


I don't come up with any more detail... anything I'm missing?

Regards,
Juan

Juan Antonio Zea Herranz 
Proyectos y consultoría | Qindel Group 
E: juan.zea@xxxxxxxxxx 
T: +34 91 766 24 21 
M: +34 637 74 63 09 
W: qindel.com 
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux