On Sat, 8 Sep 2018 17:21:31 +0200 Ludovic Rousseau <ludovic.rouss...@gmail.com> wrote: > Le 05/09/2018 à 16:34, Nicolas Braud-Santoni a écrit : > > Package: pcscd > > Version: 1.8.23-3 > > Severity: normal > > > > Hi, > > > > pcscd fails to detect my Yubikey 4 Nano when resuming from suspend-to-disk, > > resulting in GnuPG prompting me to insert the device; the problem persists > > even if I unplug and replug the device, and until I restart pcscd. > > I tried to reproduce the problem but without success. > > Can you generate a pcscd trace as described in > https://pcsclite.apdu.fr/#support
Hi, I'm also hitting this issue, but after trying a few things I'm not convinced it is strictly a "resume after suspend" problem. But let's proceed with order. I normally keep a OpenPGP smartcard in my laptop's smartcard reader and I use it via scdaemon with disable-ccid. Sometimes when I suspend and resume my laptop I lose access to the smartcard: gnupg/scdaemon can't find it anymore. Restarting pcscd helps (systemctl restart pcscd) often but *not always* helps. I tried to collect logs running pcscd in foreground in a shell, but guess what, it *never* happens if I run it like this. The problem seems to happen only when pcscd is started by systemd, and I found out that I can reproduce it by restarting pcscd several time with systemctl. So I modified pcscd.service like this: [Service] Environment=LIBCCID_ifdLogLevel=0x000F ExecStart=/usr/sbin/pcscd --foreground --debug --apdu #ExecStart=/usr/sbin/pcscd --foreground --auto-exit #ExecReload=/usr/sbin/pcscd --hotplug in order to collect the relevant logs. Here they are. Here I restart pcscd with `systemctl restart pcscd`: Apr 03 12:51:52 stramonio pcscd[97491]: 08882959 pcscdaemon.c:193:signal_thread() Received signal: 15 Apr 03 12:51:52 stramonio pcscd[97491]: 00000020 pcscdaemon.c:213:signal_thread() Direct suicide Apr 03 12:51:52 stramonio pcscd[97491]: 00000004 pcscdaemon.c:787:at_exit() cleaning /run/pcscd Apr 03 12:51:52 stramonio systemd[1]: Stopping PC/SC Smart Card Daemon... Apr 03 12:51:52 stramonio systemd[1]: pcscd.service: Succeeded. Apr 03 12:51:52 stramonio systemd[1]: Stopped PC/SC Smart Card Daemon. Apr 03 12:51:52 stramonio systemd[1]: Started PC/SC Smart Card Daemon. Apr 03 12:51:52 stramonio pcscd[98472]: 00000000 debuglog.c:299:DebugLogSetLevel() debug level=debug Apr 03 12:51:52 stramonio pcscd[98472]: 00000020 debuglog.c:320:DebugLogSetCategory() Debug options: APDU Apr 03 12:51:52 stramonio pcscd[98472]: 00000032 pcscdaemon.c:451:main() Started by systemd Apr 03 12:51:52 stramonio pcscd[98472]: 00000130 configfile.l:293:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d Apr 03 12:51:52 stramonio pcscd[98472]: 00000020 configfile.l:369:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin Apr 03 12:51:52 stramonio pcscd[98472]: 00000040 configfile.l:329:DBGetReaderListDir() Skipping non regular file: .. Apr 03 12:51:52 stramonio pcscd[98472]: 00000006 configfile.l:329:DBGetReaderListDir() Skipping non regular file: . Apr 03 12:51:52 stramonio pcscd[98472]: 00000009 pcscdaemon.c:663:main() pcsc-lite 1.8.26 daemon ready. Apr 03 12:51:52 stramonio pcscd[98472]: 00008288 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:51:52 stramonio pcscd[98472]: 00000169 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:51:52 stramonio pcscd[98472]: 00000178 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/001/002 Apr 03 12:51:52 stramonio pcscd[98472]: 00000115 hotplug_libudev.c:440:HPAddDevice() Adding USB device: Alcor Micro AU9560 Apr 03 12:51:52 stramonio pcscd[98472]: 00000152 readerfactory.c:1074:RFInitializeReader() Attempting startup of Alcor Micro AU9560 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so Apr 03 12:51:52 stramonio pcscd[98472]: 00000295 readerfactory.c:950:RFBindFunctions() Loading IFD Handler 3.0 Apr 03 12:51:52 stramonio pcscd[98472]: 00000029 ifdhandler.c:1961:init_driver() Driver version: 1.4.31 Apr 03 12:51:52 stramonio pcscd[98472]: 00000781 ifdhandler.c:1978:init_driver() LogLevel: 0x0003 Apr 03 12:51:52 stramonio pcscd[98472]: 00000016 ifdhandler.c:1989:init_driver() DriverOptions: 0x0000 Apr 03 12:51:52 stramonio pcscd[98472]: 00000202 ifdhandler.c:2002:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F Apr 03 12:51:52 stramonio pcscd[98472]: 00000012 ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 0, device: usb:058f/9540:libudev:0:/dev/bus/usb/001/002 Apr 03 12:51:52 stramonio pcscd[98472]: 00000005 ccid_usb.c:237:OpenUSBByName() Reader index: 0, Device: usb:058f/9540:libudev:0:/dev/bus/usb/001/002 Apr 03 12:51:52 stramonio pcscd[98472]: 00000014 ccid_usb.c:269:OpenUSBByName() interface_number: 0 Apr 03 12:51:52 stramonio pcscd[98472]: 00000003 ccid_usb.c:270:OpenUSBByName() usb bus/device: 1/2 Apr 03 12:51:52 stramonio pcscd[98472]: 00000006 ccid_usb.c:302:OpenUSBByName() Using: /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist Apr 03 12:51:52 stramonio pcscd[98472]: 00000776 ccid_usb.c:320:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rouss...@free.fr) Apr 03 12:51:52 stramonio pcscd[98472]: 00000012 ccid_usb.c:321:OpenUSBByName() ifdProductString: Generic CCID driver Apr 03 12:51:52 stramonio pcscd[98472]: 00000005 ccid_usb.c:322: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. Apr 03 12:51:52 stramonio pcscd[98472]: 00013831 ccid_usb.c:406:OpenUSBByName() Try device: 1/2 Apr 03 12:51:52 stramonio pcscd[98472]: 00000013 ccid_usb.c:416:OpenUSBByName() vid/pid : 058F/9540 Apr 03 12:51:52 stramonio pcscd[98472]: 00000003 ccid_usb.c:482:OpenUSBByName() Checking device: 1/2 Apr 03 12:51:52 stramonio pcscd[98472]: 00000002 ccid_usb.c:553:OpenUSBByName() Trying to open USB bus/device: 1/2 Apr 03 12:51:52 stramonio pcscd[98472]: 00000070 ccid_usb.c:659:OpenUSBByName() Found Vendor/Product: 058F/9540 (Alcor Micro AU9560) Apr 03 12:51:52 stramonio pcscd[98472]: 00000003 ccid_usb.c:661:OpenUSBByName() Using USB bus/device: 1/2 Apr 03 12:51:52 stramonio pcscd[98472]: 00000002 ccid_usb.c:1253:ControlUSB() request: 0x03 Apr 03 12:51:55 stramonio pcscd[98472]: 03000359 ccid_usb.c:1264:ControlUSB() control failed (1/2): -7 LIBUSB_ERROR_TIMEOUT Apr 03 12:51:55 stramonio pcscd[98472]: 00000040 ccid_usb.c:1197:get_data_rates() IFD does not support GET_DATA_RATES request: -7 Apr 03 12:51:55 stramonio pcscd[98472]: 00001498 ccid_usb.c:1306:InterruptRead() before (0), timeout: 100 ms Apr 03 12:51:55 stramonio pcscd[98472]: 00100435 ccid_usb.c:1352:InterruptRead() after (0) (2) Apr 03 12:51:55 stramonio pcscd[98472]: 00000046 -> 000000 65 00 00 00 00 00 00 00 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00000877 <- 000000 81 00 00 00 00 00 00 01 00 01 Apr 03 12:51:55 stramonio pcscd[98472]: 00000035 -> 000000 65 00 00 00 00 00 01 00 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00000981 <- 000000 81 00 00 00 00 00 01 01 00 01 Apr 03 12:51:55 stramonio pcscd[98472]: 00000048 ifdhandler.c:380:IFDHGetCapabilities() tag: 0xFB3, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:55 stramonio pcscd[98472]: 00000009 readerfactory.c:396:RFAddReader() Using the reader polling thread Apr 03 12:51:55 stramonio pcscd[98472]: 00000008 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:55 stramonio pcscd[98472]: 00000012 -> 000000 65 00 00 00 00 00 02 00 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00000826 <- 000000 81 00 00 00 00 00 02 01 00 01 Apr 03 12:51:55 stramonio pcscd[98472]: 00000040 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:51:55 stramonio pcscd[98472]: 00000164 ifdhandler.c:380:IFDHGetCapabilities() tag: 0xFAE, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:55 stramonio pcscd[98472]: 00000013 ifdhandler.c:476:IFDHGetCapabilities() Reader supports 1 slot(s) Apr 03 12:51:55 stramonio pcscd[98472]: 00000085 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:55 stramonio pcscd[98472]: 00000053 -> 000000 65 00 00 00 00 00 03 00 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00000565 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:51:55 stramonio pcscd[98472]: 00000285 <- 000000 81 00 00 00 00 00 03 01 00 01 Apr 03 12:51:55 stramonio pcscd[98472]: 00000030 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:51:55 stramonio pcscd[98472]: 00000010 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:55 stramonio pcscd[98472]: 00000044 -> 000000 65 00 00 00 00 00 04 00 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00000089 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:51:55 stramonio pcscd[98472]: 00000424 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC069, path: /dev/bus/usb/001/006 Apr 03 12:51:55 stramonio pcscd[98472]: 00000322 <- 000000 81 00 00 00 00 00 04 01 00 01 Apr 03 12:51:55 stramonio pcscd[98472]: 00000031 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:51:55 stramonio pcscd[98472]: 00000011 ifdhandler.c:1153:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:55 stramonio pcscd[98472]: 00000011 -> 000000 62 00 00 00 00 00 05 00 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00000003 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:51:55 stramonio pcscd[98472]: 00000391 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x17EF, PID: 0xA360, path: /dev/bus/usb/001/010 Apr 03 12:51:55 stramonio pcscd[98472]: 00000398 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:51:55 stramonio pcscd[98472]: 00000421 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 Apr 03 12:51:55 stramonio pcscd[98472]: 00000459 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 Apr 03 12:51:55 stramonio pcscd[98472]: 00000420 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 Apr 03 12:51:55 stramonio pcscd[98472]: 00000405 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 Apr 03 12:51:55 stramonio pcscd[98472]: 00000382 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 Apr 03 12:51:55 stramonio pcscd[98472]: 00000428 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:51:55 stramonio pcscd[98472]: 00000124 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:51:55 stramonio pcscd[98472]: 00000135 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:51:55 stramonio pcscd[98472]: 00000126 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:51:55 stramonio pcscd[98472]: 00000126 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 Apr 03 12:51:55 stramonio pcscd[98472]: 00000109 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:51:55 stramonio pcscd[98472]: 00000112 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:51:55 stramonio pcscd[98472]: 00000109 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0A2B, path: /dev/bus/usb/001/003 Apr 03 12:51:55 stramonio pcscd[98472]: 00000116 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0A2B, path: /dev/bus/usb/001/003 Apr 03 12:51:55 stramonio pcscd[98472]: 00000110 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:51:55 stramonio pcscd[98472]: 00000114 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04F2, PID: 0xB604, path: /dev/bus/usb/001/004 Apr 03 12:51:55 stramonio pcscd[98472]: 00000113 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04F2, PID: 0xB604, path: /dev/bus/usb/001/004 Apr 03 12:51:55 stramonio pcscd[98472]: 00000185 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 Apr 03 12:51:55 stramonio pcscd[98472]: 00000109 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 Apr 03 12:51:55 stramonio pcscd[98472]: 00000115 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0316, path: /dev/bus/usb/002/002 Apr 03 12:51:55 stramonio pcscd[98472]: 00000107 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 Apr 03 12:51:55 stramonio pcscd[98472]: 00000118 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/003 Apr 03 12:51:55 stramonio pcscd[98472]: 00000126 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/004 Apr 03 12:51:55 stramonio pcscd[98472]: 00000113 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/003 Apr 03 12:51:55 stramonio pcscd[98472]: 00000163 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010146 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010354 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010325 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010417 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010138 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010417 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:55 stramonio pcscd[98472]: 00010411 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010307 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010434 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010214 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010464 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010428 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010240 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010444 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010376 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00010194 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00002529 <- 000000 80 15 00 00 00 00 05 00 00 00 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C Apr 03 12:51:56 stramonio pcscd[98472]: 00000060 eventhandler.c:289:EHStatusHandlerThread() powerState: POWER_STATE_POWERED Apr 03 12:51:56 stramonio pcscd[98472]: 00000023 Card ATR: 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C Apr 03 12:51:56 stramonio pcscd[98472]: 00000014 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:51:56 stramonio pcscd[98472]: 00000016 -> 000000 65 00 00 00 00 00 06 00 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00000853 <- 000000 81 00 00 00 00 00 06 00 00 00 Apr 03 12:51:56 stramonio pcscd[98472]: 00000031 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:51:56 stramonio pcscd[98472]: 00000015 ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 5000 ms Apr 03 12:51:56 stramonio pcscd[98472]: 00000010 ccid_usb.c:1306:InterruptRead() before (0), timeout: 5000 ms Apr 03 12:52:01 stramonio pcscd[98472]: 05000495 ccid_usb.c:1352:InterruptRead() after (0) (2) Apr 03 12:52:01 stramonio pcscd[98472]: 00000052 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:01 stramonio pcscd[98472]: 00000016 -> 000000 65 00 00 00 00 00 07 00 00 00 Apr 03 12:52:01 stramonio pcscd[98472]: 00000856 <- 000000 81 00 00 00 00 00 07 00 00 00 Apr 03 12:52:01 stramonio pcscd[98472]: 00000026 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:52:01 stramonio pcscd[98472]: 00000011 ifdhandler.c:1153:IFDHPowerICC() action: PowerDown, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:01 stramonio pcscd[98472]: 00000012 -> 000000 63 00 00 00 00 00 08 00 00 00 Apr 03 12:52:01 stramonio pcscd[98472]: 00040885 <- 000000 81 00 00 00 00 00 08 01 00 01 Apr 03 12:52:01 stramonio pcscd[98472]: 00000027 eventhandler.c:482:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED Apr 03 12:52:01 stramonio pcscd[98472]: 00000005 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:01 stramonio pcscd[98472]: 00000005 -> 000000 65 00 00 00 00 00 09 00 00 00 Apr 03 12:52:01 stramonio pcscd[98472]: 00000756 <- 000000 81 00 00 00 00 00 09 01 00 01 Apr 03 12:52:01 stramonio pcscd[98472]: 00000011 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:52:01 stramonio pcscd[98472]: 00000004 ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 600000 ms Apr 03 12:52:01 stramonio pcscd[98472]: 00000003 ccid_usb.c:1306:InterruptRead() before (0), timeout: 600000 ms Now pcscd seems to be idling. If I try to access the smartcard nothing is logged. Now I do a `systemctl stop pcscd` followed by a `systemctl start pcscd`. The following is logged: pr 03 12:52:52 stramonio pcscd[98472]: 51238774 pcscdaemon.c:193:signal_thread() Received signal: 15 Apr 03 12:52:52 stramonio pcscd[98472]: 00000015 pcscdaemon.c:213:signal_thread() Direct suicide Apr 03 12:52:52 stramonio pcscd[98472]: 00000008 pcscdaemon.c:787:at_exit() cleaning /run/pcscd Apr 03 12:52:52 stramonio systemd[1]: Stopping PC/SC Smart Card Daemon... Apr 03 12:52:52 stramonio systemd[1]: pcscd.service: Succeeded. Apr 03 12:52:52 stramonio systemd[1]: Stopped PC/SC Smart Card Daemon. Apr 03 12:52:56 stramonio systemd[1]: Started PC/SC Smart Card Daemon. Apr 03 12:52:56 stramonio pcscd[99237]: 00000000 debuglog.c:299:DebugLogSetLevel() debug level=debug Apr 03 12:52:56 stramonio pcscd[99237]: 00000036 debuglog.c:320:DebugLogSetCategory() Debug options: APDU Apr 03 12:52:56 stramonio pcscd[99237]: 00000033 pcscdaemon.c:451:main() Started by systemd Apr 03 12:52:56 stramonio pcscd[99237]: 00000141 configfile.l:293:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d Apr 03 12:52:56 stramonio pcscd[99237]: 00000020 configfile.l:369:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin Apr 03 12:52:56 stramonio pcscd[99237]: 00000056 configfile.l:329:DBGetReaderListDir() Skipping non regular file: .. Apr 03 12:52:56 stramonio pcscd[99237]: 00000005 configfile.l:329:DBGetReaderListDir() Skipping non regular file: . Apr 03 12:52:56 stramonio pcscd[99237]: 00000011 pcscdaemon.c:663:main() pcsc-lite 1.8.26 daemon ready. Apr 03 12:52:56 stramonio pcscd[99237]: 00009477 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:52:56 stramonio pcscd[99237]: 00000153 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:52:56 stramonio pcscd[99237]: 00000168 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/001/002 Apr 03 12:52:56 stramonio pcscd[99237]: 00000013 hotplug_libudev.c:440:HPAddDevice() Adding USB device: Alcor Micro AU9560 Apr 03 12:52:56 stramonio pcscd[99237]: 00000046 readerfactory.c:1074:RFInitializeReader() Attempting startup of Alcor Micro AU9560 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so Apr 03 12:52:56 stramonio pcscd[99237]: 00000252 readerfactory.c:950:RFBindFunctions() Loading IFD Handler 3.0 Apr 03 12:52:56 stramonio pcscd[99237]: 00000025 ifdhandler.c:1961:init_driver() Driver version: 1.4.31 Apr 03 12:52:56 stramonio pcscd[99237]: 00000767 ifdhandler.c:1978:init_driver() LogLevel: 0x0003 Apr 03 12:52:56 stramonio pcscd[99237]: 00000012 ifdhandler.c:1989:init_driver() DriverOptions: 0x0000 Apr 03 12:52:56 stramonio pcscd[99237]: 00000206 ifdhandler.c:2002:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F Apr 03 12:52:56 stramonio pcscd[99237]: 00000009 ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 0, device: usb:058f/9540:libudev:0:/dev/bus/usb/001/002 Apr 03 12:52:56 stramonio pcscd[99237]: 00000006 ccid_usb.c:237:OpenUSBByName() Reader index: 0, Device: usb:058f/9540:libudev:0:/dev/bus/usb/001/002 Apr 03 12:52:56 stramonio pcscd[99237]: 00000008 ccid_usb.c:269:OpenUSBByName() interface_number: 0 Apr 03 12:52:56 stramonio pcscd[99237]: 00000003 ccid_usb.c:270:OpenUSBByName() usb bus/device: 1/2 Apr 03 12:52:56 stramonio pcscd[99237]: 00000003 ccid_usb.c:302:OpenUSBByName() Using: /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist Apr 03 12:52:56 stramonio pcscd[99237]: 00000722 ccid_usb.c:320:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rouss...@free.fr) Apr 03 12:52:56 stramonio pcscd[99237]: 00000008 ccid_usb.c:321:OpenUSBByName() ifdProductString: Generic CCID driver Apr 03 12:52:56 stramonio pcscd[99237]: 00000003 ccid_usb.c:322: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. Apr 03 12:52:56 stramonio pcscd[99237]: 00010550 ccid_usb.c:406:OpenUSBByName() Try device: 1/2 Apr 03 12:52:56 stramonio pcscd[99237]: 00000018 ccid_usb.c:416:OpenUSBByName() vid/pid : 058F/9540 Apr 03 12:52:56 stramonio pcscd[99237]: 00000003 ccid_usb.c:482:OpenUSBByName() Checking device: 1/2 Apr 03 12:52:56 stramonio pcscd[99237]: 00000003 ccid_usb.c:553:OpenUSBByName() Trying to open USB bus/device: 1/2 Apr 03 12:52:56 stramonio pcscd[99237]: 00114272 ccid_usb.c:659:OpenUSBByName() Found Vendor/Product: 058F/9540 (Alcor Micro AU9560) Apr 03 12:52:56 stramonio pcscd[99237]: 00000049 ccid_usb.c:661:OpenUSBByName() Using USB bus/device: 1/2 Apr 03 12:52:56 stramonio pcscd[99237]: 00000012 ccid_usb.c:1253:ControlUSB() request: 0x03 Apr 03 12:52:59 stramonio pcscd[99237]: 03000428 ccid_usb.c:1264:ControlUSB() control failed (1/2): -7 LIBUSB_ERROR_TIMEOUT Apr 03 12:52:59 stramonio pcscd[99237]: 00000045 ccid_usb.c:1197:get_data_rates() IFD does not support GET_DATA_RATES request: -7 Apr 03 12:52:59 stramonio pcscd[99237]: 00001424 ccid_usb.c:1306:InterruptRead() before (0), timeout: 100 ms Apr 03 12:52:59 stramonio pcscd[99237]: 00000550 ccid_usb.c:1352:InterruptRead() after (0) (0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000030 NotifySlotChange: 50 03 Apr 03 12:52:59 stramonio pcscd[99237]: 00000012 -> 000000 65 00 00 00 00 00 00 00 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00000878 <- 000000 81 00 00 00 00 00 00 01 00 01 Apr 03 12:52:59 stramonio pcscd[99237]: 00000032 -> 000000 65 00 00 00 00 00 01 00 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00000780 <- 000000 81 00 00 00 00 00 01 01 00 01 Apr 03 12:52:59 stramonio pcscd[99237]: 00000036 ifdhandler.c:380:IFDHGetCapabilities() tag: 0xFB3, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000009 readerfactory.c:396:RFAddReader() Using the reader polling thread Apr 03 12:52:59 stramonio pcscd[99237]: 00000008 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000010 -> 000000 65 00 00 00 00 00 02 00 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00000781 <- 000000 81 00 00 00 00 00 02 01 00 01 Apr 03 12:52:59 stramonio pcscd[99237]: 00000029 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:52:59 stramonio pcscd[99237]: 00000164 ifdhandler.c:380:IFDHGetCapabilities() tag: 0xFAE, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000012 ifdhandler.c:476:IFDHGetCapabilities() Reader supports 1 slot(s) Apr 03 12:52:59 stramonio pcscd[99237]: 00000065 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000034 -> 000000 65 00 00 00 00 00 03 00 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00000608 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:52:59 stramonio pcscd[99237]: 00000303 <- 000000 81 00 00 00 00 00 03 01 00 01 Apr 03 12:52:59 stramonio pcscd[99237]: 00000022 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:52:59 stramonio pcscd[99237]: 00000009 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000012 -> 000000 65 00 00 00 00 00 04 00 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00000103 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:52:59 stramonio pcscd[99237]: 00000437 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC069, path: /dev/bus/usb/001/006 Apr 03 12:52:59 stramonio pcscd[99237]: 00000277 <- 000000 81 00 00 00 00 00 04 01 00 01 Apr 03 12:52:59 stramonio pcscd[99237]: 00000022 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:52:59 stramonio pcscd[99237]: 00000009 ifdhandler.c:1153:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:52:59 stramonio pcscd[99237]: 00000011 -> 000000 62 00 00 00 00 00 05 00 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00000133 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:52:59 stramonio pcscd[99237]: 00000558 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x17EF, PID: 0xA360, path: /dev/bus/usb/001/010 Apr 03 12:52:59 stramonio pcscd[99237]: 00000487 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:52:59 stramonio pcscd[99237]: 00000507 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 Apr 03 12:52:59 stramonio pcscd[99237]: 00000557 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 Apr 03 12:52:59 stramonio pcscd[99237]: 00000487 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 Apr 03 12:52:59 stramonio pcscd[99237]: 00000346 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 Apr 03 12:52:59 stramonio pcscd[99237]: 00000142 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 Apr 03 12:52:59 stramonio pcscd[99237]: 00000165 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:52:59 stramonio pcscd[99237]: 00000157 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:52:59 stramonio pcscd[99237]: 00000158 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:52:59 stramonio pcscd[99237]: 00000154 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 Apr 03 12:52:59 stramonio pcscd[99237]: 00000136 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 Apr 03 12:52:59 stramonio pcscd[99237]: 00000153 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 Apr 03 12:52:59 stramonio pcscd[99237]: 00000120 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:52:59 stramonio pcscd[99237]: 00000139 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0A2B, path: /dev/bus/usb/001/003 Apr 03 12:52:59 stramonio pcscd[99237]: 00000131 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0A2B, path: /dev/bus/usb/001/003 Apr 03 12:52:59 stramonio pcscd[99237]: 00000131 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 Apr 03 12:52:59 stramonio pcscd[99237]: 00000126 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04F2, PID: 0xB604, path: /dev/bus/usb/001/004 Apr 03 12:52:59 stramonio pcscd[99237]: 00000135 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04F2, PID: 0xB604, path: /dev/bus/usb/001/004 Apr 03 12:52:59 stramonio pcscd[99237]: 00000215 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 Apr 03 12:52:59 stramonio pcscd[99237]: 00000119 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 Apr 03 12:52:59 stramonio pcscd[99237]: 00000136 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0316, path: /dev/bus/usb/002/002 Apr 03 12:52:59 stramonio pcscd[99237]: 00000119 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 Apr 03 12:52:59 stramonio pcscd[99237]: 00000143 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/003 Apr 03 12:52:59 stramonio pcscd[99237]: 00000137 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/004 Apr 03 12:52:59 stramonio pcscd[99237]: 00000132 hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/003 Apr 03 12:52:59 stramonio pcscd[99237]: 00000215 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010095 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010415 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010207 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010168 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010217 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010417 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010204 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010453 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:52:59 stramonio pcscd[99237]: 00010206 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010198 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010204 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010175 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010385 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010302 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010428 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00010410 readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00002993 <- 000000 80 15 00 00 00 00 05 00 00 00 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C Apr 03 12:53:00 stramonio pcscd[99237]: 00000064 eventhandler.c:289:EHStatusHandlerThread() powerState: POWER_STATE_POWERED Apr 03 12:53:00 stramonio pcscd[99237]: 00000014 Card ATR: 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C Apr 03 12:53:00 stramonio pcscd[99237]: 00000010 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:53:00 stramonio pcscd[99237]: 00000010 -> 000000 65 00 00 00 00 00 06 00 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00000817 <- 000000 81 00 00 00 00 00 06 00 00 00 Apr 03 12:53:00 stramonio pcscd[99237]: 00000031 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:53:00 stramonio pcscd[99237]: 00000011 ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 5000 ms Apr 03 12:53:00 stramonio pcscd[99237]: 00000010 ccid_usb.c:1306:InterruptRead() before (0), timeout: 5000 ms Apr 03 12:53:05 stramonio pcscd[99237]: 05000578 ccid_usb.c:1352:InterruptRead() after (0) (2) Apr 03 12:53:05 stramonio pcscd[99237]: 00000060 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:53:05 stramonio pcscd[99237]: 00000016 -> 000000 65 00 00 00 00 00 07 00 00 00 Apr 03 12:53:05 stramonio pcscd[99237]: 00000915 <- 000000 81 00 00 00 00 00 07 00 00 00 Apr 03 12:53:05 stramonio pcscd[99237]: 00000026 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:53:05 stramonio pcscd[99237]: 00000011 ifdhandler.c:1153:IFDHPowerICC() action: PowerDown, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:53:05 stramonio pcscd[99237]: 00000012 -> 000000 63 00 00 00 00 00 08 00 00 00 Apr 03 12:53:05 stramonio pcscd[99237]: 00040939 <- 000000 81 00 00 00 00 00 08 01 00 01 Apr 03 12:53:05 stramonio pcscd[99237]: 00000053 eventhandler.c:482:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED Apr 03 12:53:05 stramonio pcscd[99237]: 00000012 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 12:53:05 stramonio pcscd[99237]: 00000013 -> 000000 65 00 00 00 00 00 09 00 00 00 Apr 03 12:53:05 stramonio pcscd[99237]: 00000915 <- 000000 81 00 00 00 00 00 09 01 00 01 Apr 03 12:53:05 stramonio pcscd[99237]: 00000037 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 12:53:05 stramonio pcscd[99237]: 00000012 ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 600000 ms Apr 03 12:53:05 stramonio pcscd[99237]: 00000009 ccid_usb.c:1306:InterruptRead() before (0), timeout: 600000 ms Again trying to access the smartcard doesn't work. In both cases removing and re-inserting the smartcard doesn't make it work, but events like these are logged: [card removed] Apr 03 13:15:20 stramonio pcscd[114133]: 03379492 ccid_usb.c:1352:InterruptRead() after (0) (0) Apr 03 13:15:20 stramonio pcscd[114133]: 00000063 NotifySlotChange: 50 02 Apr 03 13:15:20 stramonio pcscd[114133]: 00000014 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 13:15:20 stramonio pcscd[114133]: 00000012 -> 000000 65 00 00 00 00 00 1E 00 00 00 Apr 03 13:15:20 stramonio pcscd[114133]: 00001631 <- 000000 81 00 00 00 00 00 1E 42 FE 01 Apr 03 13:15:20 stramonio pcscd[114133]: 00000027 ifdhandler.c:1941:IFDHICCPresence() Card absent Apr 03 13:15:20 stramonio pcscd[114133]: 00000009 eventhandler.c:358:EHStatusHandlerThread() Card Removed From Alcor Micro AU9560 00 00 Apr 03 13:15:20 stramonio pcscd[114133]: 00000013 ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 600000 ms Apr 03 13:15:20 stramonio pcscd[114133]: 00000008 ccid_usb.c:1306:InterruptRead() before (0), timeout: 600000 ms [card inserted] Apr 03 13:15:27 stramonio pcscd[114133]: 07215346 ccid_usb.c:1352:InterruptRead() after (0) (0) Apr 03 13:15:27 stramonio pcscd[114133]: 00000052 NotifySlotChange: 50 03 Apr 03 13:15:27 stramonio pcscd[114133]: 00000020 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 13:15:27 stramonio pcscd[114133]: 00000013 -> 000000 65 00 00 00 00 00 1F 00 00 00 Apr 03 13:15:27 stramonio pcscd[114133]: 00010122 <- 000000 81 00 00 00 00 00 1F 01 00 01 Apr 03 13:15:27 stramonio pcscd[114133]: 00000043 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 13:15:27 stramonio pcscd[114133]: 00000011 ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 13:15:27 stramonio pcscd[114133]: 00000011 -> 000000 65 00 00 00 00 00 20 00 00 00 Apr 03 13:15:27 stramonio pcscd[114133]: 00000834 <- 000000 81 00 00 00 00 00 20 01 00 01 Apr 03 13:15:27 stramonio pcscd[114133]: 00000070 ifdhandler.c:1941:IFDHICCPresence() Card present Apr 03 13:15:27 stramonio pcscd[114133]: 00000018 ifdhandler.c:1153:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) Apr 03 13:15:27 stramonio pcscd[114133]: 00000016 -> 000000 62 00 00 00 00 00 21 00 00 00 Apr 03 13:15:27 stramonio pcscd[114133]: 00173616 <- 000000 80 15 00 00 00 00 21 00 00 00 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C Apr 03 13:15:27 stramonio pcscd[114133]: 00000049 eventhandler.c:406:EHStatusHandlerThread() powerState: POWER_STATE_POWERED Apr 03 13:15:27 stramonio pcscd[114133]: 00000009 eventhandler.c:423:EHStatusHandlerThread() Card inserted into Alcor Micro AU9560 00 00 Apr 03 13:15:27 stramonio pcscd[114133]: 00000015 Card ATR: 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C Apr 03 13:15:27 stramonio pcscd[114133]: 00000011 ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 5000 ms Apr 03 13:15:27 stramonio pcscd[114133]: 00000009 ccid_usb.c:1306:InterruptRead() before (0), timeout: 5000 ms Now I shut down pcscd with `systemctl stop pcscd`: Apr 03 12:53:33 stramonio pcscd[99237]: 28370996 pcscdaemon.c:193:signal_thread() Received signal: 15 Apr 03 12:53:33 stramonio pcscd[99237]: 00000026 pcscdaemon.c:213:signal_thread() Direct suicide Apr 03 12:53:33 stramonio pcscd[99237]: 00000004 pcscdaemon.c:787:at_exit() cleaning /run/pcscd Apr 03 12:53:33 stramonio systemd[1]: Stopping PC/SC Smart Card Daemon... Apr 03 12:53:33 stramonio systemd[1]: pcscd.service: Succeeded. Apr 03 12:53:33 stramonio systemd[1]: Stopped PC/SC Smart Card Daemon. and start it manually from a shell, then trying to access the smartcard. It immediately works: $ sudo LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color 00000000 [140323360282560] debuglog.c:299:DebugLogSetLevel() debug level=debug 00000014 [140323360282560] debuglog.c:320:DebugLogSetCategory() Debug options: APDU 00000009 [140323360282560] pcscdaemon.c:353:main() Force colored logs 00000094 [140323360282560] configfile.l:293:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d 00000015 [140323360282560] configfile.l:369:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin 00000032 [140323360282560] configfile.l:329:DBGetReaderListDir() Skipping non regular file: .. 00000005 [140323360282560] configfile.l:329:DBGetReaderListDir() Skipping non regular file: . 00000006 [140323360282560] pcscdaemon.c:663:main() pcsc-lite 1.8.26 daemon ready. 00006132 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000138 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000143 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/001/002 00000009 [140323360282560] hotplug_libudev.c:440:HPAddDevice() Adding USB device: Alcor Micro AU9560 00000037 [140323360282560] readerfactory.c:1074:RFInitializeReader() Attempting startup of Alcor Micro AU9560 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so 00000212 [140323360282560] readerfactory.c:950:RFBindFunctions() Loading IFD Handler 3.0 00000022 [140323360282560] ifdhandler.c:1961:init_driver() Driver version: 1.4.31 00000583 [140323360282560] ifdhandler.c:1978:init_driver() LogLevel: 0x0003 00000008 [140323360282560] ifdhandler.c:1989:init_driver() DriverOptions: 0x0000 00000178 [140323360282560] ifdhandler.c:2002:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F 00000006 [140323360282560] ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 0, device: usb:058f/9540:libudev:0:/dev/bus/usb/001/002 00000007 [140323360282560] ccid_usb.c:237:OpenUSBByName() Reader index: 0, Device: usb:058f/9540:libudev:0:/dev/bus/usb/001/002 00000010 [140323360282560] ccid_usb.c:269:OpenUSBByName() interface_number: 0 00000004 [140323360282560] ccid_usb.c:270:OpenUSBByName() usb bus/device: 1/2 00000006 [140323360282560] ccid_usb.c:302:OpenUSBByName() Using: /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist 00000561 [140323360282560] ccid_usb.c:320:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rouss...@free.fr) 00000007 [140323360282560] ccid_usb.c:321:OpenUSBByName() ifdProductString: Generic CCID driver 00000006 [140323360282560] ccid_usb.c:322: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. 00006013 [140323360282560] ccid_usb.c:406:OpenUSBByName() Try device: 1/2 00000011 [140323360282560] ccid_usb.c:416:OpenUSBByName() vid/pid : 058F/9540 00000006 [140323360282560] ccid_usb.c:482:OpenUSBByName() Checking device: 1/2 00000006 [140323360282560] ccid_usb.c:553:OpenUSBByName() Trying to open USB bus/device: 1/2 00113878 [140323360282560] ccid_usb.c:659:OpenUSBByName() Found Vendor/Product: 058F/9540 (Alcor Micro AU9560) 00000029 [140323360282560] ccid_usb.c:661:OpenUSBByName() Using USB bus/device: 1/2 00000011 [140323360282560] ccid_usb.c:1253:ControlUSB() request: 0x03 03000357 [140323360282560] ccid_usb.c:1264:ControlUSB() control failed (1/2): -7 LIBUSB_ERROR_TIMEOUT 00000043 [140323360282560] ccid_usb.c:1197:get_data_rates() IFD does not support GET_DATA_RATES request: -7 00001551 [140323360282560] ccid_usb.c:1306:InterruptRead() before (0), timeout: 100 ms 00000418 [140323360282560] ccid_usb.c:1352:InterruptRead() after (0) (0) 00000033 [140323360282560] NotifySlotChange: 50 03 00000016 [140323360282560] -> 000000 65 00 00 00 00 00 00 00 00 00 00000879 [140323360282560] <- 000000 81 00 00 00 00 00 00 01 00 01 00000070 [140323360282560] -> 000000 65 00 00 00 00 00 01 00 00 00 00001013 [140323360282560] <- 000000 81 00 00 00 00 00 01 01 00 01 00000049 [140323360282560] ifdhandler.c:380:IFDHGetCapabilities() tag: 0xFB3, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000013 [140323360282560] readerfactory.c:396:RFAddReader() Using the reader polling thread 00000011 [140323360282560] ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000015 [140323360282560] -> 000000 65 00 00 00 00 00 02 00 00 00 00000997 [140323360282560] <- 000000 81 00 00 00 00 00 02 01 00 01 00000044 [140323360282560] ifdhandler.c:1941:IFDHICCPresence() Card present 00000178 [140323360282560] ifdhandler.c:380:IFDHGetCapabilities() tag: 0xFAE, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000019 [140323360282560] ifdhandler.c:476:IFDHGetCapabilities() Reader supports 1 slot(s) 00000054 [140323343255296] ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000050 [140323343255296] -> 000000 65 00 00 00 00 00 03 00 00 00 00000616 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000324 [140323343255296] <- 000000 81 00 00 00 00 00 03 01 00 01 00000034 [140323343255296] ifdhandler.c:1941:IFDHICCPresence() Card present 00000016 [140323343255296] ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000014 [140323343255296] -> 000000 65 00 00 00 00 00 04 00 00 00 00000011 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 00000407 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC069, path: /dev/bus/usb/001/006 00000432 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 00000013 [140323343255296] <- 000000 81 00 00 00 00 00 04 01 00 01 00000057 [140323343255296] ifdhandler.c:1941:IFDHICCPresence() Card present 00000029 [140323343255296] ifdhandler.c:1153:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000026 [140323343255296] -> 000000 62 00 00 00 00 00 05 00 00 00 00000293 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x17EF, PID: 0xA360, path: /dev/bus/usb/001/010 00000362 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 00000388 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 00000416 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 00000416 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 00000537 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04D9, PID: 0xA0CD, path: /dev/bus/usb/001/008 00000529 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 00000606 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 00000576 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 00000489 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 00000484 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x046D, PID: 0x082D, path: /dev/bus/usb/001/009 00000445 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/007 00000432 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x5411, path: /dev/bus/usb/001/005 00000340 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000363 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0A2B, path: /dev/bus/usb/001/003 00000487 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0A2B, path: /dev/bus/usb/001/003 00000538 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000625 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04F2, PID: 0xB604, path: /dev/bus/usb/001/004 00000593 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x04F2, PID: 0xB604, path: /dev/bus/usb/001/004 00000903 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 00000443 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 00000460 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0316, path: /dev/bus/usb/002/002 00000420 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 00000469 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/003 00000545 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/004 00000513 [140323360282560] hotplug_libudev.c:299:get_driver() Looking for a driver for VID: 0x0BDA, PID: 0x0411, path: /dev/bus/usb/002/003 00000642 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010124 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010390 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010185 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010195 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010190 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010134 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010340 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010380 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010437 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010429 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010212 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010423 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010432 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010213 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00010424 [140323360282560] readerfactory.c:1409:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9560 00 00 00005769 [140323343255296] <- 000000 80 15 00 00 00 00 05 00 00 00 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C 00000067 [140323343255296] eventhandler.c:289:EHStatusHandlerThread() powerState: POWER_STATE_POWERED 00000018 [140323343255296] Card ATR: 3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C 00000019 [140323343255296] ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000015 [140323343255296] -> 000000 65 00 00 00 00 00 06 00 00 00 00000921 [140323343255296] <- 000000 81 00 00 00 00 00 06 00 00 00 00000034 [140323343255296] ifdhandler.c:1941:IFDHICCPresence() Card present 00000032 [140323343255296] ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 5000 ms 00000062 [140323343255296] ccid_usb.c:1306:InterruptRead() before (0), timeout: 5000 ms 00863889 [140323360282560] winscard_msg_srv.c:256:ProcessEventsServer() Common channel packet arrival 00000020 [140323360282560] winscard_msg_srv.c:267:ProcessEventsServer() ProcessCommonChannelRequest detects: 14 00000007 [140323360282560] pcscdaemon.c:133:SVCServiceRunLoop() A new context thread creation is requested: 14 00000201 [140323326469888] winscard_svc.c:340:ContextThread() Authorized PC/SC client 00000011 [140323326469888] winscard_svc.c:343:ContextThread() Thread is started: dwClientID=14, threadContext @0x564fbc6893d0 00000016 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_VERSION from client 14 00000010 [140323326469888] winscard_svc.c:373:ContextThread() Client is protocol version 4:4 00000007 [140323326469888] winscard_svc.c:396:ContextThread() CMD_VERSION rv=0x0 for client 14 00000085 [140323326469888] winscard_svc.c:361:ContextThread() Received command: ESTABLISH_CONTEXT from client 14 00000017 [140323326469888] winscard.c:215:SCardEstablishContext() Establishing Context: 0x32626CBB 00000008 [140323326469888] winscard_svc.c:461:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 14 00000070 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000041 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000066 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CONNECT from client 14 00000013 [140323326469888] winscard_svc.c:499:ContextThread() Authorized client for 'Alcor Micro AU9560 00 00' 00000007 [140323326469888] winscard.c:258:SCardConnect() Attempting Connect to Alcor Micro AU9560 00 00 using protocol: 3 00000010 [140323326469888] readerfactory.c:821:RFReaderInfo() RefReader() count was: 1 00000007 [140323326469888] winscard.c:352:SCardConnect() powerState: POWER_STATE_IN_USE 00000007 [140323326469888] prothandler.c:107:PHSetProtocol() Attempting PTS to T=1 00000010 [140323326469888] ifdhandler.c:694:IFDHSetProtocolParameters() protocol T=1, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000008 [140323326469888] ifdhandler.c:818:IFDHSetProtocolParameters() Set speed to 119354 bauds 00000007 [140323326469888] ifdhandler.c:978:IFDHSetProtocolParameters() BWI/CWI (TB3) present: 0x75 00000007 [140323326469888] ifdhandler.c:1013:IFDHSetProtocolParameters() IFSC (TA3) present: 254 00000007 [140323326469888] ifdhandler.c:1017:IFDHSetProtocolParameters() Timeout: 14029 ms 00000007 [140323326469888] commands.c:2254:SetParameters() length: 7 bytes 00000012 [140323326469888] -> 000000 61 07 00 00 00 00 07 01 00 00 18 10 FF 75 00 FE 00 00001980 [140323326469888] <- 000000 82 07 00 00 00 00 07 00 00 01 18 10 FF 75 00 FE 00 00000010 [140323326469888] ifdhandler.c:1074:IFDHSetProtocolParameters() IFSC (TA3) present: 254 00000006 [140323326469888] ifdhandler.c:1087:IFDHSetProtocolParameters() T=1: IFSC=254, IFSD=254 00000008 [140323326469888] winscard.c:430:SCardConnect() Active Protocol: T=1 00000008 [140323326469888] winscard.c:456:SCardConnect() hCard Identity: 79f5890a 00000008 [140323326469888] winscard.c:518:SCardConnect() UnrefReader() count was: 2 00000010 [140323326469888] winscard_svc.c:513:ContextThread() CONNECT rv=0x0 for client 14 00000049 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CONTROL from client 14 00000013 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000005 [140323326469888] ifdhandler.c:1410:IFDHControl() ControlCode: 0x42000D48, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000004 [140323326469888] Control TxBuffer: 00000004 [140323326469888] Control RxBuffer: 12 04 42 33 00 12 00000003 [140323326469888] winscard.c:1359:SCardControl() UnrefReader() count was: 2 00000004 [140323326469888] winscard_svc.c:735:ContextThread() CONTROL rv=0x0 for client 14 00000063 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CONTROL from client 14 00000010 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000004 [140323326469888] ifdhandler.c:1410:IFDHControl() ControlCode: 0x42330012, usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000003 [140323326469888] Control TxBuffer: 00000006 [140323326469888] Control RxBuffer: 01 02 00 00 03 01 00 09 01 00 0B 02 8F 05 0C 02 40 95 0A 04 00 00 01 00 00000004 [140323326469888] winscard.c:1359:SCardControl() UnrefReader() count was: 2 00000003 [140323326469888] winscard_svc.c:735:ContextThread() CONTROL rv=0x0 for client 14 00000030 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000035 [140323326469888] winscard_svc.c:361:ContextThread() Received command: STATUS from client 14 00000013 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000009 [140323326469888] winscard.c:1300:SCardStatus() UnrefReader() count was: 2 00000007 [140323326469888] winscard_svc.c:632:ContextThread() STATUS rv=0x0 for client 14 00000033 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000009 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000029 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000009 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000030 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000015 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000006 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000008 [140323326469888] APDU: 00 A4 00 0C 02 3F 00 00000007 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000007 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 7 bytes 00000010 [140323326469888] -> 000000 6F 07 00 00 00 00 08 00 00 00 00 A4 00 0C 02 3F 00 00008779 [140323326469888] <- 000000 80 02 00 00 00 00 08 00 00 00 6B 00 00000033 [140323326469888] SW: 6B 00 00000010 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000011 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000184 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000032 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000009 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000018 [140323326469888] APDU: 00 A4 04 00 06 D2 76 00 01 24 01 00000016 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000013 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 11 bytes 00000034 [140323326469888] -> 000000 6F 0B 00 00 00 00 09 00 00 00 00 A4 04 00 06 D2 76 00 01 24 01 00013045 [140323326469888] <- 000000 80 02 00 00 00 00 09 00 00 00 90 00 00000045 [140323326469888] SW: 90 00 00000013 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000012 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000232 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000049 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000011 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000011 [140323326469888] APDU: 00 CA 00 4F 00 00000015 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000019 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000027 [140323326469888] -> 000000 6F 05 00 00 00 00 0A 00 00 00 00 CA 00 4F 00 00007754 [140323326469888] <- 000000 80 12 00 00 00 00 0A 00 00 00 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 90 00 00000057 [140323326469888] SW: D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 90 00 00000017 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000015 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000210 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000041 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000013 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000014 [140323326469888] APDU: 00 CA 5F 52 00 00000024 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000017 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000026 [140323326469888] -> 000000 6F 05 00 00 00 00 0B 00 00 00 00 CA 5F 52 00 00006773 [140323326469888] <- 000000 80 0C 00 00 00 00 0B 00 00 00 00 31 F5 73 C0 01 60 05 90 00 90 00 00000043 [140323326469888] SW: 00 31 F5 73 C0 01 60 05 90 00 90 00 00000012 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000011 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000244 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000036 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000010 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000009 [140323326469888] APDU: 00 CA 00 C4 00 00000010 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000013 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000019 [140323326469888] -> 000000 6F 05 00 00 00 00 0C 00 00 00 00 CA 00 C4 00 00009031 [140323326469888] <- 000000 80 09 00 00 00 00 0C 00 00 00 00 40 40 40 03 00 03 90 00 00000043 [140323326469888] SW: 00 40 40 40 03 00 03 90 00 00000014 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000016 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000193 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000043 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000011 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000010 [140323326469888] APDU: 00 CA 00 6E 00 00000011 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000012 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000021 [140323326469888] -> 000000 6F 05 00 00 00 00 0D 00 00 00 00 CA 00 6E 00 00069889 [140323326469888] <- 000000 80 E6 00 00 00 00 0D 00 00 00 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000139 [140323326469888] SW: 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000034 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000021 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000254 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000099 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000027 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000017 [140323326469888] APDU: 00 CA 7F 74 00 00000018 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000014 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000020 [140323326469888] -> 000000 6F 05 00 00 00 00 0E 00 00 00 00 CA 7F 74 00 00005479 [140323326469888] <- 000000 80 02 00 00 00 00 0E 00 00 00 6A 88 00000036 [140323326469888] SW: 6A 88 00000012 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000012 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000208 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000050 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000012 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000017 [140323326469888] APDU: 00 CA 00 5E 00 08 00 00000012 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000014 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 7 bytes 00000019 [140323326469888] -> 000000 6F 07 00 00 00 00 0F 00 00 00 00 CA 00 5E 00 08 00 00005834 [140323326469888] <- 000000 80 02 00 00 00 00 0F 00 00 00 90 00 00000051 [140323326469888] SW: 90 00 00000013 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000012 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000245 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000049 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000013 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000012 [140323326469888] APDU: 00 CA 00 6E 00 00000017 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000017 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000022 [140323326469888] -> 000000 6F 05 00 00 00 00 10 00 00 00 00 CA 00 6E 00 00070114 [140323326469888] <- 000000 80 E6 00 00 00 00 10 00 00 00 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000138 [140323326469888] SW: 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000031 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000016 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000215 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000058 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000017 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000015 [140323326469888] APDU: 00 CA 00 6E 00 00000025 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000025 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000020 [140323326469888] -> 000000 6F 05 00 00 00 00 11 00 00 00 00 CA 00 6E 00 00069951 [140323326469888] <- 000000 80 E6 00 00 00 00 11 00 00 00 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000131 [140323326469888] SW: 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000024 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000018 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000239 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000050 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000012 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000012 [140323326469888] APDU: 00 CA 00 6E 00 00000012 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000014 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000024 [140323326469888] -> 000000 6F 05 00 00 00 00 12 00 00 00 00 CA 00 6E 00 00069651 [140323326469888] <- 000000 80 E6 00 00 00 00 12 00 00 00 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000130 [140323326469888] SW: 4F 10 D2 76 00 01 24 01 03 03 00 05 00 00 72 E8 00 00 5F 52 0A 00 31 F5 73 C0 01 60 05 90 00 7F 66 08 02 02 08 00 02 02 08 00 73 81 B7 C0 0A 7F 00 08 00 08 00 08 00 00 01 C1 06 01 08 00 00 20 00 C2 06 01 08 00 00 20 00 C3 06 01 08 00 00 20 00 C4 07 00 40 40 40 03 00 03 C5 3C 56 1A D5 85 EE D7 66 92 1B A8 DD 96 D6 58 61 88 3E 01 4D B9 AA 69 28 B0 CE CE F8 A4 05 C5 37 4D C7 DF 04 8F 3B BB 7E 04 D5 99 F7 19 09 0D 89 11 7C BE F1 91 0D 3F 9A BB FC 32 D6 D4 C6 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 CD 0C 5B 31 5F 7F 5C 79 0A 9B 5C 78 69 77 90 00 00000025 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000020 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000338 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000036 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001209 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000036 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000204 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000040 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000196 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00001105 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000050 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000013 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000012 [140323326469888] APDU: 00 CA 00 C4 00 00000020 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000023 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000023 [140323326469888] -> 000000 6F 05 00 00 00 00 13 00 00 00 00 CA 00 C4 00 00008982 [140323326469888] <- 000000 80 09 00 00 00 00 13 00 00 00 00 40 40 40 03 00 03 90 00 00000039 [140323326469888] SW: 00 40 40 40 03 00 03 90 00 00000012 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000012 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000288 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000096 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000017 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000016 [140323326469888] APDU: 00 CA 00 65 00 00000015 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000011 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000019 [140323326469888] -> 000000 6F 05 00 00 00 00 14 00 00 00 00 CA 00 65 00 00015477 [140323326469888] <- 000000 80 1D 00 00 00 00 14 00 00 00 5B 10 4C 65 67 6F 76 69 6E 69 3C 3C 50 61 72 69 64 65 5F 2D 02 65 6E 5F 35 01 39 90 00 00000054 [140323326469888] SW: 5B 10 4C 65 67 6F 76 69 6E 69 3C 3C 50 61 72 69 64 65 5F 2D 02 65 6E 5F 35 01 39 90 00 00000013 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000013 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 02116710 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000027 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000023 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000015 [140323326469888] APDU: 00 CA 00 F9 00 00000008 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000008 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 5 bytes 00000010 [140323326469888] -> 000000 6F 05 00 00 00 00 15 00 00 00 00 CA 00 F9 00 00006489 [140323326469888] <- 000000 80 05 00 00 00 00 15 00 00 00 81 01 00 90 00 00000030 [140323326469888] SW: 81 01 00 90 00 00000006 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000006 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000107 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000018 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000006 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000009 [140323326469888] APDU: 00 20 00 82 09 63 61 74 6F 62 6C 65 70 61 00000008 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000007 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 14 bytes 00000012 [140323326469888] -> 000000 6F 0E 00 00 00 00 16 00 00 00 00 20 00 82 09 63 61 74 6F 62 6C 65 70 61 00073459 [140323326469888] <- 000000 80 02 00 00 00 00 16 00 00 00 90 00 00000056 [140323326469888] SW: 90 00 00000012 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000013 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000259 [140323326469888] winscard_svc.c:361:ContextThread() Received command: TRANSMIT from client 14 00000060 [140323326469888] readerfactory.c:848:RFReaderInfoById() RefReader() count was: 1 00000012 [140323326469888] winscard.c:1595:SCardTransmit() Send Protocol: T=1 00000143 [140323326469888] APDU: 00 2A 80 86 00 01 01 00 07 B9 88 FB E9 87 9D FE D4 31 99 03 9C EB B4 4E 7C C3 BC C2 D3 13 B5 B9 3D D7 0B 90 60 96 98 E4 C3 61 AB E0 B4 FD 24 B9 5A 7F FB AA 00 E0 9F 83 E5 99 15 6A E7 DD A4 86 C3 50 89 FA FE 1A B7 48 E7 76 5A BC E8 B5 6E 38 77 8C 6F 6C 34 43 0C 9C 2D 7B 3F 44 B7 D3 D2 D8 23 F7 D0 25 F6 94 E0 C6 75 CB 63 19 A0 B4 BC 42 91 4A 86 13 1C 53 B3 46 89 4C B5 A0 2A 39 58 A4 10 7E B4 A2 F9 73 5D 95 21 A2 F0 F4 2E 30 C3 8F D3 8D E1 F3 D2 3A 39 72 C4 F5 A1 AA 60 9E 78 F1 89 E1 91 DB 54 7B 5B 51 33 E3 9E 09 C0 1A 43 6A 27 AE 8F B9 85 EF C8 51 E1 86 51 CC 58 B2 3D 1B E4 C0 8C 25 19 DB 00 BD 93 A1 8B 61 C6 1F 96 C4 89 09 A3 9A 25 15 7D 1D CA AE 73 3E 79 6B B1 B4 50 ED 94 78 A0 CE B7 F7 CE E8 77 47 A9 65 30 A6 00 8F A7 00 40 BF F9 4F E6 D3 74 8B DE 72 03 D3 FD 57 D6 84 F9 F9 31 69 01 00 00000041 [140323326469888] ifdhandler.c:1302:IFDHTransmitToICC() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000011 [140323326469888] commands.c:1623:CmdXfrBlockAPDU_extended() T=0 (extended): 266 bytes 00000123 [140323326469888] -> 000000 6F 06 01 00 00 00 17 00 01 00 00 2A 80 86 00 01 01 00 07 B9 88 FB E9 87 9D FE D4 31 99 03 9C EB B4 4E 7C C3 BC C2 D3 13 B5 B9 3D D7 0B 90 60 96 98 E4 C3 61 AB E0 B4 FD 24 B9 5A 7F FB AA 00 E0 9F 83 E5 99 15 6A E7 DD A4 86 C3 50 89 FA FE 1A B7 48 E7 76 5A BC E8 B5 6E 38 77 8C 6F 6C 34 43 0C 9C 2D 7B 3F 44 B7 D3 D2 D8 23 F7 D0 25 F6 94 E0 C6 75 CB 63 19 A0 B4 BC 42 91 4A 86 13 1C 53 B3 46 89 4C B5 A0 2A 39 58 A4 10 7E B4 A2 F9 73 5D 95 21 A2 F0 F4 2E 30 C3 8F D3 8D E1 F3 D2 3A 39 72 C4 F5 A1 AA 60 9E 78 F1 89 E1 91 DB 54 7B 5B 51 33 E3 9E 09 C0 1A 43 6A 27 AE 8F B9 85 EF C8 51 E1 86 51 CC 58 B2 3D 1B E4 C0 8C 25 19 DB 00 BD 93 A1 8B 61 C6 1F 96 C4 89 09 A3 9A 25 15 7D 1D CA AE 73 3E 79 6B B1 B4 50 ED 94 78 A0 CE B7 F7 CE E8 77 47 A9 65 30 A6 00 8F A7 00 40 BF F9 4F E6 D3 74 8B DE 72 03 D3 FD 57 D6 84 F9 F9 00035950 [140323326469888] <- 000000 80 00 00 00 00 00 17 00 00 10 00000047 [140323326469888] -> 000000 6F 04 00 00 00 00 18 00 02 00 31 69 01 00 00515072 [140323326469888] <- 000000 80 25 00 00 00 00 18 00 00 00 09 2B 46 41 A8 31 AE 01 AE 72 94 F7 D0 92 AE 54 02 3C BE 79 8F 4A B1 54 AA 5C 47 34 32 F2 65 5F 16 0E 1B 90 00 00000059 [140323326469888] SW: 09 2B 46 41 A8 31 AE 01 AE 72 94 F7 D0 92 AE 54 02 3C BE 79 8F 4A B1 54 AA 5C 47 34 32 F2 65 5F 16 0E 1B 90 00 00000014 [140323326469888] winscard.c:1640:SCardTransmit() UnrefReader() count was: 2 00000014 [140323326469888] winscard_svc.c:685:ContextThread() TRANSMIT rv=0x0 for client 14 00000356 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000044 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001222 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000046 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000206 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000033 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000207 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000026 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00500836 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000051 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001219 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000037 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000199 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000200 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00500857 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000045 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001228 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000037 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000213 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000160 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000026 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00007646 [140323343255296] ccid_usb.c:1352:InterruptRead() after (0) (2) 00000042 [140323343255296] ifdhandler.c:1821:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 00000018 [140323343255296] -> 000000 65 00 00 00 00 00 19 00 00 00 00000847 [140323343255296] <- 000000 81 00 00 00 00 00 19 00 00 00 00000029 [140323343255296] ifdhandler.c:1941:IFDHICCPresence() Card present 00000015 [140323343255296] ifdhandler.c:309:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/002 (lun: 0) 600000 ms 00000011 [140323343255296] ccid_usb.c:1306:InterruptRead() before (0), timeout: 600000 ms 00492433 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000054 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001234 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000037 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000219 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000225 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000036 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00501095 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000046 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001242 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000224 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000228 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00501094 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000047 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001270 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000037 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000224 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000031 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000194 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00501072 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000058 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001237 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000041 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000143 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000031 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000210 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000043 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00500693 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000048 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001212 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000039 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000182 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000178 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00500925 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000046 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001218 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000238 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000033 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000222 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00501019 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000046 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001235 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000221 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000221 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00501119 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000045 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001229 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000223 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000226 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000036 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00501106 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000045 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00001225 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000035 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000225 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000032 [140323326469888] winscard_svc.c:834:MSGSendReaderStates() Send reader states: 14 00000223 [140323326469888] winscard_svc.c:361:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000034 [140323326469888] winscard_svc.c:442:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 [these 3 lines keep getting printer foverer]. I hope this helps. Paride