PCSCD: Smart card readers stop responding after being plugged and unplugged multiple times...
Gavin Williams <[email protected]>
| Newsgroups | gmane.comp.lib.muscle |
|---|---|
| Message-ID | <[email protected]> |
Afternoon all
I'm having some issues with getting PCSCD to work reliably.
Setup is:
Gigabyte XM12-3227 Core i3 Mini-PC
Cambrionix 49 port USB device
Enumerates as follows:
# lsusb |grep 'Bus 003'
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 002: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 003: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 004: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 005: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 006: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 007: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 008: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 009: ID 0424:2507 Standard Microsystems Corp. hub
Bus 003 Device 037: ID 076b:3021 OmniKey AG CardMan 3121
Omnikey 3121 USB readers, with ifdokccid_linux_x86_64-4.0.5.1.bundle drivers from HID Global
Centos 6.5 x86-64
Libudev: libudev-147-2.51.el6.x86_64 & libudev-devel-147-2.51.el6.x86_64
Libusb1: libusb1-1.0.9-0.6.rc1.el6.x86_64 & libusb1-devel-1.0.9-0.6.rc1.el6.x86_64
I'm building pcsc-lite 1.8.11 from source:
pcsc-lite-1.8.11]$ ./configure --build=x86_64-redhat-linux-gnu --host=x86_64-redhat-linux-gnu --target=x86_64-redhat-linux-gnu --program-prefix= --prefix=/usr --exec-prefix=/usr --bindir=/usr/bin --sbindir=/usr/sbin --sysconfdir=/etc --datadir=/usr/share --includedir=/usr/include --libdir=/usr/lib64 --libexecdir=/usr/libexec --localstatedir=/var --sharedstatedir=/var/lib --mandir=/usr/share/man --infodir=/usr/share/info --disable-dependency-tracking --disable-static --enable-confdir=/etc --enable-ipcdir=/var/run --enable-usbdropdir=/usr/lib64/pcsc/drivers --disable-serial
...
PC/SC lite has been configured with following options:
Version: 1.8.11
System binaries: /usr/sbin
Configuration dir: /etc
Host: x86_64-redhat-linux-gnu
Compiler: gcc
Preprocessor flags: -I${top_srcdir}/src
Compiler flags: -Wall -fno-common -g -O2
Preprocessor flags: -I${top_srcdir}/src
Linker flags:
Libraries: -ldl -lrt
PTHREAD_CFLAGS: -pthread
PTHREAD_LIBS:
PCSC_ARCH: Linux
pcscd binary /usr/sbin/pcscd
polkit support: no
polkit policy dir:
libudev support: yes
libusb support: no
USB drop directory: /usr/lib64/pcsc/drivers
ATR parsing messages: false
ipcdir: /var/run
use serial: no
use usb: yes
systemd unit directory:
serial config dir.: /etc
PCSCLITE_FEATURES: Linux x86_64-redhat-linux-gnu usb libudev usbdropdir=/usr/lib64/pcsc/drivers ipcdir=/var/run configdir=/etc
I can provide a full compile log if required.
Without pcscd running, I can plug and un-plug the Omnikey reader dozens of times without issue.
E.g.:
Mar 21 16:42:59 netisam kernel: usb 3-2.2.5: USB disconnect, device number 25
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: new full speed USB device number 26 using xhci_hcd
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: New USB device found, idVendor=076b, idProduct=3021
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: Product: Smart Card Reader USB
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: Manufacturer: OMNIKEY AG
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: configuration #1 chosen from 1 choice
Mar 21 16:43:02 netisam kernel: usb 3-2.2.5: ep 0x83 - rounding interval to 128 microframes, ep desc says 192 microframes
Mar 21 16:43:04 netisam kernel: usb 3-2.2.5: USB disconnect, device number 26
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: new full speed USB device number 27 using xhci_hcd
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: New USB device found, idVendor=076b, idProduct=3021
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: Product: Smart Card Reader USB
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: Manufacturer: OMNIKEY AG
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: configuration #1 chosen from 1 choice
Mar 21 16:43:06 netisam kernel: usb 3-2.2.5: ep 0x83 - rounding interval to 128 microframes, ep desc says 192 microframes
However when I start running pcscd, I start getting failures after a handful of plug-unplug instances:
Running pcscd in foreground and debug with the card reader plugged in gives the following on startup:
00000000 debuglog.c:295:DebugLogSetLevel() debug level=debug
00000123 pcscdaemon.c:571:main() pcsc-lite 1.8.11 daemon ready.
00007422 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001
00000126 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001
00000122 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000124 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/003
00000116 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000127 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/004
00000137 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x076B, PID: 0x3021, path: /dev/bus/usb/003/027
00000022 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x076B, PID: 0x3021, path: /dev/bus/usb/003/027
00000006 hotplug_libudev.c:347:HPAddDevice() Adding USB device: OMNIKEY CardMan (076B:3021) 3021
00000030 readerfactory.c:1015:RFInitializeReader() Attempting startup of OMNIKEY CardMan (076B:3021) 3021 00 00 using /usr/lib64/pcsc/drivers/ifdokccid_linux_x86_64-4.0.5.1.bundle/Contents/Linux/ifdokccid.so
00003009 readerfactory.c:900:RFBindFunctions() Loading IFD Handler 3.0
HID HID Global OMNIKEY CCID driver x86_64 v4.0.5.1
00093248 readerfactory.c:358:RFAddReader() Using the reader polling thread
00000796 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/004
00000182 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000209 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/005
00000133 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000126 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/006
00000164 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000135 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/007
00000117 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000186 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/008
00000168 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000129 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/009
00000117 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000201 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/004/001
00000158 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000170 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000172 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/001/002
00000156 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000116 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000121 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/002/002
00000036 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010146 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010168 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010159 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010159 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010163 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010158 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00010166 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: OMNIKEY CardMan (076B:3021) 3021 00 00
00001242 eventhandler.c:292:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000032 Card ATR: 3B DF 18 00 81 B1 FE 45 1F 02 00 00 00 00 00 63 35 97 81 90 00 50 04 70 04 A1
00402520 eventhandler.c:481:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
This provided the following output in /var/log/messages:
Mar 21 16:51:46 netisam kernel: usb 3-2.2.5: reset full speed USB device number 27 using xhci_hcd
Mar 21 16:51:46 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880413616780
Mar 21 16:51:46 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8804136167c8
Mar 21 16:51:46 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880413616810
Mar 21 16:51:46 netisam kernel: usb 3-2.2.5: ep 0x83 - rounding interval to 128 microframes, ep desc says 192 microframes
After a variable number of plug in and out, typically between 6 and 12, I get the following in /var/log/messages:
Mar 21 17:00:06 netisam kernel: usb 3-2.2.5: USB disconnect, device number 35
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: new full speed USB device number 36 using xhci_hcd
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: New USB device found, idVendor=076b, idProduct=3021
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: Product: Smart Card Reader USB
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: Manufacturer: OMNIKEY AG
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: configuration #1 chosen from 1 choice
Mar 21 17:00:08 netisam kernel: usb 3-2.2.5: ep 0x83 - rounding interval to 128 microframes, ep desc says 192 microframes
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: reset full speed USB device number 36 using xhci_hcd
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880413616680
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8804136166c8
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880413616710
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: ep 0x83 - rounding interval to 128 microframes, ep desc says 192 microframes
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: Not enough bandwidth on HS bus for newly activated TT.
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: Not enough bandwidth
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: Busted HC? Not enough HCD resources for old configuration.
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: USB disconnect, device number 36
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880413616680
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8804136166c8
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880413616710
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: new full speed USB device number 37 using xhci_hcd
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: New USB device found, idVendor=076b, idProduct=3021
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: Product: Smart Card Reader USB
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: Manufacturer: OMNIKEY AG
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: configuration #1 chosen from 1 choice
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: ep 0x83 - rounding interval to 128 microframes, ep desc says 192 microframes
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: Not enough bandwidth on HS bus for newly activated TT.
Mar 21 17:00:09 netisam kernel: xhci_hcd 0000:00:14.0: Not enough bandwidth
Mar 21 17:00:09 netisam kernel: usb 3-2.2.5: can't set config #1, error -12
And then no further card reader events are registered by pcscd.
Prior to the last unplug, pcscd logs:
00000012 hotplug_libudev.c:546:HPRescanUsbBus() Removing USB device[0]: OMNIKEY CardMan (076B:3021) 3021 at /dev/bus/usb/003/035
00000006 readerfactory.c:561:RFRemoveReader() UnrefReader() count was: 1
00000005 eventhandler.c:182:EHDestroyEventHandler() Stomping thread.
00000005 eventhandler.c:211:EHDestroyEventHandler() Waiting polling thread
00883705 eventhandler.c:339:EHStatusHandlerThread() Error communicating to: OMNIKEY CardMan (076B:3021) 3021 00 00
00400215 eventhandler.c:504:EHStatusHandlerThread() Die
00000081 eventhandler.c:222:EHDestroyEventHandler() Thread stomped.
00000021 readerfactory.c:1066:RFUnInitializeReader() Attempting shutdown of OMNIKEY CardMan (076B:3021) 3021 00 00.
00000069 readerfactory.c:937:RFUnloadReader() Unloading reader driver.
01478498 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x076B, PID: 0x3021, path: /dev/bus/usb/003/036
00000013 hotplug_libudev.c:347:HPAddDevice() Adding USB device: OMNIKEY CardMan (076B:3021) 3021
00000037 readerfactory.c:1015:RFInitializeReader() Attempting startup of OMNIKEY CardMan (076B:3021) 3021 00 00 using /usr/lib64/pcsc/drivers/ifdokccid_linux_x86_64-4.0.5.1.bundle/Contents/Linux/ifdokccid.so
00000248 readerfactory.c:900:RFBindFunctions() Loading IFD Handler 3.0
HID HID Global OMNIKEY CCID driver x86_64 v4.0.5.1
00090227 readerfactory.c:1046:RFInitializeReader() Open Port 0x200000 Failed (usb:076b/3021:libudev:0:/dev/bus/usb/003/036)
00000022 readerfactory.c:338:RFAddReader() OMNIKEY CardMan (076B:3021) 3021 init failed.
00000012 readerfactory.c:561:RFRemoveReader() UnrefReader() count was: 1
00000011 readerfactory.c:1066:RFUnInitializeReader() Attempting shutdown of OMNIKEY CardMan (076B:3021) 3021 00 00.
00000010 readerfactory.c:937:RFUnloadReader() Unloading reader driver.
00000098 hotplug_libudev.c:417:HPAddDevice() Failed adding USB device: OMNIKEY CardMan (076B:3021) 3021
00001008 hotplug_libudev.c:620:HPEstablishUSBNotifications() Device removed
00000668 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001
00000126 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001
00000126 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000126 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/003
00000128 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000126 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/004
00000151 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000166 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/005
00000127 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000124 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/006
00000118 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000122 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/007
00000125 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000122 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/008
00000171 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000145 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/009
00000121 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0424, PID: 0x2507, path: /dev/bus/usb/003/002
00000147 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/004/001
00000147 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000124 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000130 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/001/002
00000205 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000131 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000127 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/002/002
00000011 hotplug_libudev.c:546:HPRescanUsbBus() Removing USB device[0]: OMNIKEY CardMan (076B:3021) 3021 at /dev/bus/usb/003/036
Any ideas on what the cause might be?
Cheers
Gavin
_______________________________________________
Muscle mailing list
[email protected]
http://lists.musclecard.com/mailman/listinfo/muscle_lists.musclecard.com