Bug#908054: pcscd fails to communicate with smartcard after resuming from suspend-to-RAM

[Paride Legovini]

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