ACR122u is visible only after disconnection and reconnection

[Henry89em]

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]

Do you see the reader with the command lsusb?

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

[Henry89em]

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]

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]

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 ([email protected])
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]

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]

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 [email protected].
Copyright (C) 2001-2015 by Ludovic Rousseau [email protected].
Copyright (C) 2003-2004 by Damien Sauveron [email protected].
Report bugs to [email protected].
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 ([email protected])
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]

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]

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.