LudovicRousseau / pcsc-tools

Some tools to be used with smart cards and PC/SC
https://pcsc-tools.apdu.fr/
GNU General Public License v2.0
185 stars 63 forks source link

ACR122u is visible only after disconnection and reconnection #81

Closed Henry89em closed 7 months ago

Henry89em commented 7 months ago

Hi,

I am having an issue with a reader ACR122u connected to a Raspberry (SO Raspbian).

When I reboot the system with the reader connected, pcsc_scan is not able to find the reader. If I disconnect and reconnect the USB driver, I am able to find and use the reader.

What could be the issue?

Thank you, Enrico

LudovicRousseau commented 7 months ago

Do you see the reader with the command lsusb?

After reboot, generate a pcscd trace as documented at https://pcsclite.apdu.fr/#support

Henry89em commented 7 months ago

Yes, I can find it: Bus 001 Device 004: ID 072f:2200 Advanced Card Systems, Ltd ACR122U Bus 001 Device 005: ID 2575:0001
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

the version of pcscl-lite is: pcsc-lite version 1.8.20.

The log is: log.txt

LudovicRousseau commented 7 months ago

You have 2 different versions of pcsc-lite installed in your system.

00000100 [1983226752] winscard_svc.c:374:ContextThread() Client is protocol version 4:3
00000074 [1983226752] winscard_svc.c:383:ContextThread() Communication protocol mismatch!
00000241 [1983226752] winscard_svc.c:385:ContextThread() Client protocol is 4:3
00000069 [1983226752] winscard_svc.c:387:ContextThread() Server protocol is 4:4

I guess one is in /usr/ and the other one in /usr/local/. You need to fix that first.

Henry89em commented 7 months ago

Ok, thank you, I removed the double installation and now I have only 1.8.20:

This is the log file after doing that 00000000 debuglog.c:289:DebugLogSetLevel() debug level=debug 00000222 debuglog.c:310:DebugLogSetCategory() Debug options: APDU 00000046 pcscdaemon.c:351:main() Force colored logs 00000426 configfile.l:282:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d 00000103 configfile.l:319:DBGetReaderListDir() Skipping non regular file: .. 00000035 configfile.l:319:DBGetReaderListDir() Skipping non regular file: . 00000012 configfile.l:358:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin 00000154 pcscdaemon.c:655:main() pcsc-lite 1.8.20 daemon ready. 00015370 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00001254 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00001184 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 00001243 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0xEC00, path: /dev/bus/usb/001/003 00001115 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 00001218 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x2575, PID: 0x0001, path: /dev/bus/usb/001/005 00001071 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 00001150 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x072F, PID: 0x2200, path: /dev/bus/usb/001/004 00000028 hotplug_libudev.c:433:HPAddDevice() Adding USB device: ACS ACR122U PICC Interface 00000259 readerfactory.c:1079:RFInitializeReader() Attempting startup of ACS ACR122U PICC Interface 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so 00000999 readerfactory.c:954:RFBindFunctions() Loading IFD Handler 3.0 00000143 ifdhandler.c:1961:init_driver() Driver version: 1.4.26 00003305 ifdhandler.c:1978:init_driver() LogLevel: 0x0003 00000029 ifdhandler.c:1989:init_driver() DriverOptions: 0x0000 00000540 ifdhandler.c:2002:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F 00000018 ifdhandler.c:111:CreateChannelByNameOrChannel() Lun: 0, device: usb:072f/2200:libudev:0:/dev/bus/usb/001/004 00000015 ccid_usb.c:237:OpenUSBByName() Reader index: 0, Device: usb:072f/2200:libudev:0:/dev/bus/usb/001/004 00000050 ccid_usb.c:269:OpenUSBByName() interface_number: 0 00000012 ccid_usb.c:270:OpenUSBByName() usb bus/device: 1/4 00000011 ccid_usb.c:287:OpenUSBByName() Using: /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist 00003120 ccid_usb.c:305:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr) 00000035 ccid_usb.c:306:OpenUSBByName() ifdProductString: Generic CCID driver 00000013 ccid_usb.c:307:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version. 00013027 ccid_usb.c:391:OpenUSBByName() Try device: 1/4 00000043 ccid_usb.c:401:OpenUSBByName() vid/pid : 072F/2200 00000010 ccid_usb.c:448:OpenUSBByName() Checking device: 1/4 00000033 ccid_usb.c:519:OpenUSBByName() Trying to open USB bus/device: 1/4 00000442 ccid_usb.c:621:OpenUSBByName() Found Vendor/Product: 072F/2200 (ACS ACR122U PICC Interface) 00000017 ccid_usb.c:623:OpenUSBByName() Using USB bus/device: 1/4 00000012 ccid_usb.c:680:OpenUSBByName() bNumDataRatesSupported is 0 00004204 ccid_usb.c:1244:InterruptRead() before (0) 00100175 ccid_usb.c:1290:InterruptRead() after (0) (2) 00000054 -> 000000 65 00 00 00 00 00 00 00 00 00 00000465 <- 000000 81 00 00 00 00 00 02 02 81 00 00000021 -> 000000 65 00 00 00 00 00 01 00 00 00 00000360 <- 000000 81 00 00 00 00 00 00 02 81 00 00000012 ccid_usb.c:858:ReadUSB() Duplicate frame detected 00100345 ccid_usb.c:836:ReadUSB() read failed (1/4): -7 LIBUSB_ERROR_TIMEOUT 00000054 -> 000000 65 00 00 00 00 00 02 00 00 00 00019250 <- 000000 81 00 00 00 00 00 01 02 81 00 00000037 ccid_usb.c:858:ReadUSB() Duplicate frame detected 00100306 ccid_usb.c:836:ReadUSB() read failed (1/4): -7 LIBUSB_ERROR_TIMEOUT 00000049 ifdhandler.c:195:CreateChannelByNameOrChannel() failed 00000013 ccid_usb.c:879:CloseUSB() Closing USB device: 1/4 00000010 ccid_usb.c:889:CloseUSB() Last slot closed. Release resources 00000139 ccid_usb.c:189:close_libusb_if_needed() libusb_exit 00000404 readerfactory.c:1110:RFInitializeReader() Open Port 0x200000 Failed (usb:072f/2200:libudev:0:/dev/bus/usb/001/004) 00000015 readerfactory.c:375:RFAddReader() ACS ACR122U PICC Interface init failed. 00000012 readerfactory.c:608:RFRemoveReader() UnrefReader() count was: 1 00000010 readerfactory.c:1130:RFUnInitializeReader() Attempting shutdown of ACS ACR122U PICC Interface 00 00. 00000010 readerfactory.c:991:RFUnloadReader() Unloading reader driver. 00000215 hotplug_libudev.c:520:HPAddDevice() Failed adding USB device: ACS ACR122U PICC Interface 00001608 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 ^C30882882 pcscdaemon.c:192:signal_thread() Received signal: 2 00000029 pcscdaemon.c:225:signal_thread() Preparing for suicide 00001454 hotplug_libudev.c:710:HPStopHotPluggables() Hotplug stopped 01000146 readerfactory.c:1363:RFCleanupReaders() entering cleaning function 00000068 winscard_svc.c:152:ContextsDeinitialize() remaining threads: 0 00000013 pcscdaemon.c:781:at_exit() cleaning /var/run/pcscd

LudovicRousseau commented 7 months ago

The problem is that the driver is reading old USB frames (from a previous communication) during init. Try to upgrade the CCID driver from version 1.4.26 (January 2017) to current version 1.5.4.

Henry89em commented 7 months ago

sorry to bother you.

I updated the ccid to 1.5.4 but this is the output of the log:

pcsc-lite version 1.8.18. Copyright (C) 1999-2002 by David Corcoran corcoran@musclecard.com. Copyright (C) 2001-2015 by Ludovic Rousseau ludovic.rousseau@free.fr. Copyright (C) 2003-2004 by Damien Sauveron sauveron@labri.fr. Report bugs to pcsclite-muscle@lists.alioth.debian.org. Enabled features: Linux armv7l-unknown-linux-gnueabihf serial usb libudev usbdropdir=/usr/local/lib/pcsc/drivers ipcdir=/var/run/pcscd configdir=/usr/local/etc/reader.conf.d pi@RevPi52608:~ $ lsusb Bus 001 Device 004: ID 072f:2200 Advanced Card Systems, Ltd ACR122U Bus 001 Device 005: ID 2575:0001 Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub pi@RevPi52608:~ $ pgrep pcscd pi@RevPi52608:~ $ sudo LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color | tee -i log.txt 00000000 debuglog.c:289:DebugLogSetLevel() debug level=debug 00000397 debuglog.c:310:DebugLogSetCategory() Debug options: APDU 00000089 pcscdaemon.c:360:main() Force colored logs 00000630 configfile.l:358:DBGetReaderList() Parsing conf file: /usr/local/etc/reader.conf.d 00000147 pcscdaemon.c:675:main() pcsc-lite 1.8.18 daemon ready. 00017620 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00001136 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00001155 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 00001240 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0xEC00, path: /dev/bus/usb/001/003 00001204 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 00001247 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x2575, PID: 0x0001, path: /dev/bus/usb/001/005 00001110 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 00001198 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x072F, PID: 0x2200, path: /dev/bus/usb/001/004 00000136 hotplug_libudev.c:433:HPAddDevice() Adding USB device: ACS ACR122U PICC Interface 00000365 readerfactory.c:1079:RFInitializeReader() Attempting startup of ACS ACR122U PICC Interface 00 00 using /usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so 00000838 readerfactory.c:954:RFBindFunctions() Loading IFD Handler 3.0 00000188 ifdhandler.c:2111:init_driver() Driver version: 1.5.4 00005152 ifdhandler.c:2133:init_driver() LogLevel: 0x0003 00000183 ifdhandler.c:2144:init_driver() DriverOptions: 0x0000 00001015 ifdhandler.c:2157:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F 00000078 ifdhandler.c:111:CreateChannelByNameOrChannel() Lun: 0, device: usb:072f/2200:libudev:0:/dev/bus/usb/001/004 00000104 ccid_usb.c:257:OpenUSBByName() Reader index: 0, Device: usb:072f/2200:libudev:0:/dev/bus/usb/001/004 00000096 ccid_usb.c:289:OpenUSBByName() interface_number: 0 00000068 ccid_usb.c:290:OpenUSBByName() usb bus/device: 1/4 00000070 ccid_usb.c:327:OpenUSBByName() Using: /usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist 00004623 ccid_usb.c:345:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr) 00000112 ccid_usb.c:346:OpenUSBByName() ifdProductString: Generic CCID driver 00000074 ccid_usb.c:347:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version. 00013700 ccid_usb.c:431:OpenUSBByName() Try device: 1/4 00000205 ccid_usb.c:441:OpenUSBByName() vid/pid : 072F/2200 00000075 ccid_usb.c:523:OpenUSBByName() Checking device: 1/4 00000071 ccid_usb.c:594:OpenUSBByName() Trying to open USB bus/device: 1/4 00000540 ccid_usb.c:700:OpenUSBByName() Found Vendor/Product: 072F/2200 (ACS ACR122U PICC Interface) 00000102 ccid_usb.c:702:OpenUSBByName() Using USB bus/device: 1/4 00000076 ccid_usb.c:774:OpenUSBByName() bNumDataRatesSupported is 0 00004597 ccid_usb.c:1514:InterruptRead() before (0), timeout: 100 ms 00100303 ccid_usb.c:1573:InterruptRead() after (0) (2) 00000255 -> 000000 65 00 00 00 00 00 00 00 00 00 00000627 <- 000000 81 00 00 00 00 00 02 02 81 00 00000130 ccid_usb.c:1050:ReadUSB() Invalid frame detected 03000297 ccid_usb.c:1026:ReadUSB() read failed (1/4): LIBUSB_ERROR_TIMEOUT 00000287 -> 000000 65 00 00 00 00 00 01 00 00 00 00060617 <- 000000 81 00 00 00 00 00 00 02 81 00 00000153 ccid_usb.c:1050:ReadUSB() Invalid frame detected 00100206 ccid_usb.c:1026:ReadUSB() read failed (1/4): LIBUSB_ERROR_TIMEOUT 00000187 -> 000000 65 00 00 00 00 00 02 00 00 00 00000508 <- 000000 81 00 00 00 00 00 01 02 81 00 00000211 ccid_usb.c:1050:ReadUSB() Invalid frame detected 00100350 ccid_usb.c:1026:ReadUSB() read failed (1/4): LIBUSB_ERROR_TIMEOUT 00000206 ifdhandler.c:203:CreateChannelByNameOrChannel() failed 00000073 ccid_usb.c:1071:CloseUSB() Closing USB device: 1/4 00000063 ccid_usb.c:1081:CloseUSB() Last slot closed. Release resources 00000191 ccid_usb.c:208:close_libusb_if_needed() libusb_exit 00000430 readerfactory.c:1110:RFInitializeReader() Open Port 0x200000 Failed (usb:072f/2200:libudev:0:/dev/bus/usb/001/004) 00000110 readerfactory.c:375:RFAddReader() ACS ACR122U PICC Interface init failed. 00000093 readerfactory.c:608:RFRemoveReader() UnrefReader() count was: 1 00000065 readerfactory.c:1130:RFUnInitializeReader() Attempting shutdown of ACS ACR122U PICC Interface 00 00. 00000064 readerfactory.c:991:RFUnloadReader() Unloading reader driver. 00000288 hotplug_libudev.c:520:HPAddDevice() Failed adding USB device: ACS ACR122U PICC Interface 00001597 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0424, PID: 0x9514, path: /dev/bus/usb/001/002 ^C99999999 pcscdaemon.c:192:signal_thread() Received signal: 2 00000029 pcscdaemon.c:225:signal_thread() Preparing for suicide 00001592 hotplug_libudev.c:710:HPStopHotPluggables() Hotplug stopped 01000511 readerfactory.c:1363:RFCleanupReaders() entering cleaning function 00000201 winscard_svc.c:152:ContextsDeinitialize() remaining threads: 0 00000083 pcscdaemon.c:801:at_exit() cleaning /var/run/pcscd

LudovicRousseau commented 7 months ago

It looks like the USB layer is not correct. I suspect a hardware/software problem with the Raspberry Pi.

Maybe https://blog.apdu.fr/posts/2014/04/usb-issues-with-raspberry-pi/ can help

Henry89em commented 7 months ago

Great, thank you, it solved. I configured another Raspberry (3 years ago), and I have just figured out that I used the libacsccid1, I don't know if this could have solved. For now, I am happy! Thank you for your time, I appreciated a lot.