[Spice-devel] [ usbredir ] usb device (sagem card reader ) not working

Tue May 29 08:01:16 PDT 2012

Hello,
I'm trying to use this usb device :
http://www.ingenico.com/en/products/payment_terminals/healthcare/twin30-plus_fm0cqjcy.html
under windows guest, this usb device is mounting but not recognized
it's seems to be a special usb device , that's using serial port (
create com3  ) under windows.

some debug ( spicy, qemu libspice, linux spicy host )
version : qemu-kvm 1.1 rc3  , libspice from git, spicy 0.12

Regards,
Nicolas Prochazka.

Spicy client on linux

libusb:debug [libusb_get_device_list]
libusb:debug [sysfs_scan_device] scan usb1
libusb:debug [sysfs_scan_device] bus=1 dev=1
libusb:debug [enumerate_device] busnum 1 devaddr 1 session_id 257
libusb:debug [enumerate_device] allocating new device for 1/1 (session 257)
libusb:debug [sysfs_scan_device] scan usb2
libusb:debug [sysfs_scan_device] bus=2 dev=1
libusb:debug [enumerate_device] busnum 2 devaddr 1 session_id 513
libusb:debug [enumerate_device] allocating new device for 2/1 (session 513)
libusb:debug [sysfs_scan_device] scan usb3
libusb:debug [sysfs_scan_device] bus=3 dev=1
libusb:debug [enumerate_device] busnum 3 devaddr 1 session_id 769
libusb:debug [enumerate_device] allocating new device for 3/1 (session 769)
libusb:debug [sysfs_scan_device] scan usb4
libusb:debug [sysfs_scan_device] bus=4 dev=1
libusb:debug [enumerate_device] busnum 4 devaddr 1 session_id 1025
libusb:debug [enumerate_device] allocating new device for 4/1 (session 1025)
libusb:debug [sysfs_scan_device] scan usb5
libusb:debug [sysfs_scan_device] bus=5 dev=1
libusb:debug [enumerate_device] busnum 5 devaddr 1 session_id 1281
libusb:debug [enumerate_device] allocating new device for 5/1 (session 1281)
libusb:debug [sysfs_scan_device] scan usb6
libusb:debug [sysfs_scan_device] bus=6 dev=1
libusb:debug [enumerate_device] busnum 6 devaddr 1 session_id 1537
libusb:debug [enumerate_device] allocating new device for 6/1 (session 1537)
libusb:debug [sysfs_scan_device] scan usb7
libusb:debug [sysfs_scan_device] bus=7 dev=1
libusb:debug [enumerate_device] busnum 7 devaddr 1 session_id 1793
libusb:debug [enumerate_device] allocating new device for 7/1 (session 1793)
libusb:debug [sysfs_scan_device] scan usb8
libusb:debug [sysfs_scan_device] bus=8 dev=1
libusb:debug [enumerate_device] busnum 8 devaddr 1 session_id 2049
libusb:debug [enumerate_device] allocating new device for 8/1 (session 2049)
libusb:debug [sysfs_scan_device] scan 1-2
libusb:debug [sysfs_scan_device] bus=1 dev=2
libusb:debug [enumerate_device] busnum 1 devaddr 2 session_id 258
libusb:debug [enumerate_device] using existing device for 1/2 (session 258)
libusb:debug [discovered_devs_append] need to increase capacity
libusb:debug [sysfs_scan_device] scan 7-1
libusb:debug [sysfs_scan_device] bus=7 dev=9
libusb:debug [enumerate_device] busnum 7 devaddr 9 session_id 1801
libusb:debug [enumerate_device] allocating new device for 7/9 (session 1801)
libusb:debug [sysfs_scan_device] scan 5-2
libusb:debug [sysfs_scan_device] bus=5 dev=2
libusb:debug [enumerate_device] busnum 5 devaddr 2 session_id 1282
libusb:debug [enumerate_device] using existing device for 5/2 (session 1282)
libusb:debug [sysfs_scan_device] scan 6-1
libusb:debug [sysfs_scan_device] bus=6 dev=2
libusb:debug [enumerate_device] busnum 6 devaddr 2 session_id 1538
libusb:debug [enumerate_device] using existing device for 6/2 (session 1538)
libusb:debug [libusb_unref_device] destroy device 1.1
libusb:debug [libusb_unref_device] destroy device 2.1
libusb:debug [libusb_unref_device] destroy device 3.1
libusb:debug [libusb_unref_device] destroy device 4.1
libusb:debug [libusb_unref_device] destroy device 5.1
libusb:debug [libusb_unref_device] destroy device 6.1
libusb:debug [libusb_unref_device] destroy device 7.1
libusb:debug [libusb_unref_device] destroy device 8.1
libusb:debug [libusb_get_device_descriptor]
libusb:debug [libusb_get_active_config_descriptor]
libusb:debug [sysfs_get_active_config_descriptor] active configuration 1
libusb:debug [sysfs_get_active_config_descriptor] active configuration 1
(neo-spice:9548): GSpice-DEBUG: usb-device-manager.c:841 connecting
device 0x8b78b50
(neo-spice:9548): GSpice-DEBUG: channel-usbredir.c:304 connecting usb
channel 0x8a95a80
(neo-spice:9548): GSpice-DEBUG: usb-device-manager.c:596 device added 0x8b78b50
libusb:debug [libusb_open] open 7.9
libusb:debug [usbi_add_pollfd] add fd 22 events 4
libusb:debug [libusb_get_configuration]
libusb:debug [libusb_get_configuration] active config 1
libusb:debug [libusb_get_device_descriptor]
libusb:debug [usbi_get_config_index_by_value] value 1
libusb:debug [libusb_get_config_descriptor] index 0
libusb:debug [libusb_detach_kernel_driver] interface 0
libusb:debug [libusb_claim_interface] interface 0
libusb:debug [libusb_detach_kernel_driver] interface 1
libusb:debug [libusb_claim_interface] interface 1
libusb:debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb:debug [libusb_reset_device]
libusb:debug [libusb_reset_device]
libusb:debug [libusb_submit_transfer] arm timerfd for timeout in
5000ms (first in line)
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=2 status=0 transferred=18
libusb:debug [handle_control_completion] handling completion status 0
libusb:debug [disarm_timerfd]
(neo-spice:9548): GSpice-DEBUG: channel-usbredir.c:460 usbredirhost:
control complete ep 80 status 0 len 18
libusb:debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb:debug [libusb_reset_device]
libusb:debug [libusb_submit_transfer] arm timerfd for timeout in
5000ms (first in line)
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=2 status=0 transferred=18
libusb:debug [handle_control_completion] handling completion status 0
libusb:debug [disarm_timerfd]
(neo-spice:9548): GSpice-DEBUG: channel-usbredir.c:460 usbredirhost:
control complete ep 80 status 0 len 18
libusb:debug [handle_events] poll() 3 fds with timeout in 60000ms
libusb:debug [libusb_submit_transfer] arm timerfd for timeout in
5000ms (first in line)
libusb:debug [handle_events] poll() returned 1
libusb:debug [reap_for_handle] urb type=2 status=0 transferred=48
libusb:debug [handle_control_completion] handling completion status 0
libusb:debug [disarm_timerfd]
(neo-spice:9548): GSpice-DEBUG: channel-usbredir.c:460 usbredirhost:
control complete ep 80 status 0 len 48
libusb:debug [handle_events] poll() 3 fds with timeout in 60000ms
(neo-spice:9548): GSpice-DEBUG: decode-glz.c:372 decode_header: 78x36,
id 311, ref 14
(neo-spice:9548): GSpice-DEBUG: spice-channel-cache.h:92 cache_find:
image dbca82cd2404804e [not found]
(neo-spice:9548): GSpice-DEBUG: spice-channel-cache.h:108 cache_add:
image dbca82cd2404804e (151)
(neo-spice:9548): GSpice-DEBUG: channel-playback.c:409
playback_handle_start: fmt 1 channels 2 freq 44100 time 15826578
(neo-spice:9548): GSpice-DEBUG: channel-playback.c:506 playback set_delay 7 ms
(neo-spice:9548): GSpice-DEBUG: spice-session.c:1702 set mm time: 15826577
(neo-spice:9548): GSpice-DEBUG: channel-playback.c:506 playback set_delay 79 ms
(neo-spice:9548): GSpice-DEBUG: spice-session.c:1702 set mm time: 15827085
(neo-spice:9548): GSpice-DEBUG: spice-session.c:1702 set mm time: 15826798
(neo-spice:9548): GSpice-DEBUG: spice-pulse.c:386 playback_stop

Linux dmesg

[ 2252.750233] hub 7-0:1.0: state 7 ports 2 chg 0000 evt 0002
[ 2252.750245] uhci_hcd 0000:00:1d.1: port 1 portsc 008a,00
[ 2252.750261] hub 7-0:1.0: port 1, status 0100, change 0003, 12 Mb/s
[ 2252.750266] usb 7-1: USB disconnect, device number 7
[ 2252.750270] usb 7-1: unregistering device
[ 2252.750274] usb 7-1: unregistering interface 7-1:1.0
[ 2252.750345] usb 7-1: unregistering interface 7-1:1.1
[ 2252.750424] usb 7-1: usb_disable_device nuking all URBs
[ 2252.854106] hub 7-0:1.0: debounce: port 1: total 100ms stable 100ms
status 0x100
[ 2254.000215] usb usb7: suspend_rh (auto-stop)
[ 2257.766063] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0008
[ 2257.766079] ehci_hcd 0000:00:1d.7: GetStatus port:3 status 001803 0
 ACK POWER sig=j CSC CONNECT
[ 2257.766092] hub 2-0:1.0: port 3, status 0501, change 0001, 480 Mb/s
[ 2257.870055] hub 2-0:1.0: debounce: port 3: total 100ms stable 100ms
status 0x501
[ 2257.921224] ehci_hcd 0000:00:1d.7: port 3 full speed --> companion
[ 2257.921230] ehci_hcd 0000:00:1d.7: GetStatus port:3 status 003801 0
 ACK POWER OWNER sig=j CONNECT
[ 2257.921236] hub 2-0:1.0: port 3 not reset yet, waiting 50ms
[ 2257.972058] ehci_hcd 0000:00:1d.7: GetStatus port:3 status 003002 0
 ACK POWER OWNER sig=se0 CSC
[ 2257.972086] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0008
[ 2258.000085] usb usb7: wakeup_rh (auto-start)
[ 2258.000117] hub 7-0:1.0: state 7 ports 2 chg 0000 evt 0002
[ 2258.000128] uhci_hcd 0000:00:1d.1: port 1 portsc 0093,00
[ 2258.000139] hub 7-0:1.0: port 1, status 0101, change 0001, 12 Mb/s
[ 2258.104086] hub 7-0:1.0: debounce: port 1: total 100ms stable 100ms
status 0x101
[ 2258.206082] usb 7-1: new full-speed USB device number 8 using uhci_hcd
[ 2258.327079] usb 7-1: ep0 maxpacket = 8
[ 2258.347135] usb 7-1: udev 8, busnum 7, minor = 775
[ 2258.347139] usb 7-1: New USB device found, idVendor=079b, idProduct=0028
[ 2258.347144] usb 7-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 2258.347333] usb 7-1: usb_probe_device
[ 2258.347339] usb 7-1: configuration #1 chosen from 1 choice
[ 2258.349135] usb 7-1: adding 7-1:1.0 (config #1, interface 0)
[ 2258.349238] usb 7-1: adding 7-1:1.1 (config #1, interface 1)
[ 2258.349336] drivers/usb/core/inode.c: creating file '008'
[ 2258.349367] hub 7-0:1.0: state 7 ports 2 chg 0000 evt 0002
[ 2258.637084] hub 7-0:1.0: port 1 not reset yet, waiting 50ms
[ 2258.739057] usb 7-1: reset full-speed USB device number 8 using uhci_hcd
[ 2258.750133] hub 7-0:1.0: state 7 ports 2 chg 0000 evt 0002
[ 2258.860081] usb 7-1: ep0 maxpacket = 8
[ 2259.891075] usb 7-1: reset full-speed USB device number 8 using uhci_hcd
[ 2260.013101] usb 7-1: ep0 maxpacket = 8
[ 2260.239083] usb 7-1: reset full-speed USB device number 8 using uhci_hcd
[ 2260.250107] hub 7-0:1.0: state 7 ports 2 chg 0000 evt 0002
[ 2260.361064] usb 7-1: ep0 maxpacket = 8

qemu libspice.

spice_server_add_interface: SPICE_INTERFACE_QXL
red_worker_main: begin
display_channel_create: create display channel
cursor_channel_create: create cursor channel
spice_server_add_interface: SPICE_INTERFACE_PLAYBACK
spice_server_add_interface: SPICE_INTERFACE_RECORD
spice_server_char_device_add_interface: CHAR_DEVICE usbredir
spice_server_char_device_add_interface: CHAR_DEVICE usbredir
spice_server_char_device_add_interface: CHAR_DEVICE usbredir
spice_server_char_device_add_interface: CHAR_DEVICE vdagent
spice_server_add_interface: SPICE_INTERFACE_TABLET
reds_handle_auth_mechanism: Auth method: 1
reds_handle_main_link:
reds_disconnect:
reds_show_new_channel: channel 1:0, connected successfully, over Non Secure link
main_channel_link: add main channel client
reds_handle_main_link: NEW Client 0x7f38697bf530 mcc 0x7f38697ad750
connect-id 1804289383
handle_dev_set_mouse_mode: mouse mode 2
main_channel_handle_parsed: agent start
main_channel_handle_parsed: net test: latency 12.772000 ms, bitrate
785577291 bps (749.184886 Mbps)
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 6:0, connected successfully, over Non Secure link
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 5:0, connected successfully, over Non Secure link
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 9:0, connected successfully, over Non Secure link
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 9:1, connected successfully, over Non Secure link
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 9:2, connected successfully, over Non Secure link
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 3:0, connected successfully, over Non Secure link
inputs_connect: inputs channel client create
reds_handle_auth_mechanism: Auth method: 1
reds_show_new_channel: channel 4:0, connected successfully, over Non Secure link
red_dispatcher_set_cursor_peer:
reds_handle_auth_mechanism: Auth method: 1
handle_dev_cursor_connect: cursor connect
red_connect_cursor: add cursor channel client
reds_show_new_channel: channel 2:0, connected successfully, over Non Secure link
red_dispatcher_set_display_peer:
handle_dev_display_connect: connect
handle_new_display_channel: add display channel client
qemu: usbredirparser info: Peer version: spice-gtk 0.12.6-f84e-dirty
qemu: usbredirparser info: Peer version: spice-gtk 0.12.6-f84e-dirty
qemu: usbredirparser info: Peer version: spice-gtk 0.12.6-f84e-dirty
handle_new_display_channel: New display (client 0x7f38697bf530) dcc
0x7f381017fae0 stream 0x7f386a4c6f10
handle_new_display_channel: jpeg disabled
handle_new_display_channel: zlib-over-glz disabled
display_channel_client_wait_for_init: creating encoder with id == 0
qemu: usb-redir: ep: 00 type: 0 interface: 0

qemu: usb-redir: ep: 02 type: 2 interface: 1

qemu: usb-redir: ep: 80 type: 0 interface: 0

qemu: usb-redir: ep: 81 type: 2 interface: 1

qemu: usb-redir: ep: 83 type: 3 interface: 0

qemu: usb-redir: attaching full speed device 079b:0028 version 0.0 class 02

qemu: usb-redir: reset device

qemu: usb-redir: reset device

qemu: usb-redir: ctrl-out type 0x80 req 0x6 val 0x100 index 0 len 64 id 0

qemu: usb-redir: ctrl-in status 0 len 18 id 0

qemu: usb-redir: reset device

qemu: usb-redir: set address 1

qemu: usb-redir: ctrl-out type 0x80 req 0x6 val 0x100 index 0 len 18 id 1

qemu: usb-redir: ctrl-in status 0 len 18 id 1

qemu: usb-redir: ctrl-out type 0x80 req 0x6 val 0x200 index 0 len 255 id 2

qemu: usb-redir: ctrl-in status 0 len 48 id 2