Hello,
VirtualHere USB Server v3.3.7 (Built: Aug 8 2017, 20:15:44)
VirtualHere Client 4.2.1
Device: 28a1:0601 AVEST-SYSTEMS AvBign
Server OS: Red Hat Enterprise Linux Server release 7.4 (Maipo) 3.10.0-693.2.2.el7.x86_64
Client OS: CentOS Linux release 7.4.1708 (Core) 3.10.0-693.2.2.el7.x86_64
Device works without problem when its local connected. But while its connected via virtualhere device has i/o erros when vendor's java application works with it. App works with device via pcscd (pcsc-lite-1.8.8-6.el7.x86_64).
I already emailed to the vendor of the device but maybe its also possible to debug something more with virtualhere?
Syslog/dmesg are empty in the moment of the error, all other logs attached below.
Virtualhere logs:
Tue Oct 17 11:59:52 2017 LOG_WARNING Error 22 discarding urb 0xdc5680 for device /sys/bus/usb/devices/1-1.1, Invalid argument (abort endpoint)
Tue Oct 17 11:59:52 2017 LOG_WARNING Error 22 discarding urb 0xdc5780 for device /sys/bus/usb/devices/1-1.1, Invalid argument (abort endpoint)
Tue Oct 17 11:59:52 2017 LOG_WARNING Error 22 discarding urb 0xdc58e0 for device /sys/bus/usb/devices/1-1.1, Invalid argument (abort endpoint)
Tue Oct 17 11:59:55 2017 LOG_WARNING Error 22 discarding urb 0xdcb9e0 for device /sys/bus/usb/devices/1-1.1, Invalid argument (abort endpoint)
Tue Oct 17 11:59:55 2017 LOG_WARNING Error 22 discarding urb 0xdcc200 for device /sys/bus/usb/devices/1-1.1, Invalid argument (abort endpoint)
Tue Oct 17 11:59:55 2017 LOG_WARNING Error 22 discarding urb 0xdc5640 for device /sys/bus/usb/devices/1-1.1, Invalid argument (abort endpoint)
Dump of the usb bus: usb-bus2 (device 2.10.2, look at the package 54: io error, java app started at the 49 package, before only pcscd was started).
pcscd logs from moment when java app started:
99999999 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival
00000021 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 13
00000005 pcscdaemon.c:93:SVCServiceRunLoop() A new context thread creation is requested: 13
00000451 winscard_svc.c:299:ContextThread() Thread is started: dwClientID=13, threadContext @0x5645e4988f10
00000025 winscard_svc.c:317:ContextThread() Received command: CMD_VERSION from client 13
00000006 winscard_svc.c:329:ContextThread() Client is protocol version 4:2
00000004 winscard_svc.c:349:ContextThread() CMD_VERSION rv=0x0 for client 13
00000074 winscard_svc.c:317:ContextThread() Received command: ESTABLISH_CONTEXT from client 13
00000008 winscard.c:193:SCardEstablishContext() Establishing Context: 0x56490825
00000003 winscard_svc.c:410:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 13
00000057 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000045 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000053 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000049 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000060 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000061 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000111 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000057 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
00000065 winscard_svc.c:317:ContextThread() Received command: CONNECT from client 13
00000009 winscard.c:235:SCardConnect() Attempting Connect to AVEST-SYSTEMS AvBign (AVB1050041021) 00 00 using protocol: 2
00000004 readerfactory.c:739:RFReaderInfo() RefReader() count was: 1
00001329 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:28a1/0601:libudev:0:/dev/bus/usb/002/010 (lun: 0)
00001281 winscard.c:310:SCardConnect() power up complete.
00000009 Card ATR: 3B 8F 01 41 56 42 00 00 00 00 00 00 00 00 01 00 00 00 DA
00000003 winscard.c:330:SCardConnect() powerState: POWER_STATE_INUSE
00000004 prothandler.c:87:PHSetProtocol() Attempting PTS to T=1
00000004 ifdhandler.c:668:IFDHSetProtocolParameters() protocol T=1, usb:28a1/0601:libudev:0:/dev/bus/usb/002/010 (lun: 0)
00000003 winscard.c:409:SCardConnect() Active Protocol: T=1
00000004 winscard.c:429:SCardConnect() hCard Identity: 58515cec
00000003 winscard.c:490:SCardConnect() UnrefReader() count was: 2
00000005 winscard_svc.c:451:ContextThread() CONNECT rv=0x0 for client 13
00000073 winscard_svc.c:317:ContextThread() Received command: GET_ATTRIB from client 13
00000008 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1
00000004 ifdhandler.c:358:IFDHGetCapabilities() tag: 0x7FFF0003, usb:28a1/0601:libudev:0:/dev/bus/usb/002/010 (lun: 0)
00000003 winscard.c:1420:SCardGetAttrib() UnrefReader() count was: 2
00000003 winscard_svc.c:679:ContextThread() GET_ATTRIB rv=0x0 for client 13
00000058 winscard_svc.c:317:ContextThread() Received command: GET_ATTRIB from client 13
00000006 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1
00000003 ifdhandler.c:358:IFDHGetCapabilities() tag: 0x7FFF0003, usb:28a1/0601:libudev:0:/dev/bus/usb/002/010 (lun: 0)
00000003 winscard.c:1420:SCardGetAttrib() UnrefReader() count was: 2
00000002 winscard_svc.c:679:ContextThread() GET_ATTRIB rv=0x0 for client 13
00000070 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13
00000014 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1
00000004 winscard.c:1581:SCardTransmit() Send Protocol: T=1
00000005 APDU: 81 00 00 00 03 01 10 01 00 86 03
00000004 ifdhandler.c:1265:IFDHTransmitToICC() usb:28a1/0601:libudev:0:/dev/bus/usb/002/010 (lun: 0)
03002145 ccid_usb.c:732:ReadUSB() read failed (2/10): -7 Resource temporarily unavailable
00000041 SW:
00000006 ifdwrapper.c:527:IFDTransmit() Card not transacted: 612
00000005 winscard.c:1606:SCardTransmit() Card not transacted: 0x80100016
00000004 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2
00000005 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x80100016 for client 13
00039114 winscard_svc.c:317:ContextThread() Received command: RELEASE_CONTEXT from client 13
00000105 winscard_svc.c:309:ContextThread() Client die: 13
00000014 winscard_svc.c:928:MSGCleanupClient() Thread is stopping: dwClientID=13, threadContext @0x5645e4988f10
00000003 winscard_svc.c:934:MSGCleanupClient() Freeing SCONTEXT @0x5645e4988f10
00376359 eventhandler.c:458:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00403552 ifdhandler.c:1122:IFDHPowerICC() action: PowerDown, usb:28a1/0601:libudev:0:/dev/bus/usb/002/010 (lun: 0)
00001474 eventhandler.c:446:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED