00000000 debuglog.c:295:DebugLogSetLevel() debug level=debug
00000014 debuglog.c:324:DebugLogSetCategory() Debug options: APDU
00000063 configfile.l:286:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d
00000009 configfile.l:298:DBGetReaderListDir() Skipping non regular file: ..
00000002 configfile.l:298:DBGetReaderListDir() Skipping non regular file: .
00000002 configfile.l:339:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin
00000034 pcscdaemon.c:571:main() pcsc-lite 1.8.11 daemon ready.
00000831 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000036 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000038 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x07DC, path: /dev/bus/usb/002/002
00000033 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x07DC, path: /dev/bus/usb/002/002
00000033 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000035 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x138A, PID: 0x003F, path: /dev/bus/usb/002/003
00000031 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000033 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x05C8, PID: 0x035D, path: /dev/bus/usb/002/004
00000033 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x05C8, PID: 0x035D, path: /dev/bus/usb/002/004
00000040 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000062 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/002/005
00000010 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/002/005
00000001 hotplug_libudev.c:347:HPAddDevice() Adding USB device: Alcor Micro AU9540
00000013 readerfactory.c:1015:RFInitializeReader() Attempting startup of Alcor Micro AU9540 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
00000111 readerfactory.c:900:RFBindFunctions() Loading IFD Handler 3.0
00000021 ifdhandler.c:1910:init_driver() Driver version: 1.4.16
00000295 ifdhandler.c:1927:init_driver() LogLevel: 0x0003
00000005 ifdhandler.c:1938:init_driver() DriverOptions: 0x0000
00000068 ifdhandler.c:1951:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F
00000004 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 0, device: usb:058f/9540:libudev:0:/dev/bus/usb/002/005
00000005 ccid_usb.c:233:OpenUSBByName() Reader index: 0, Device: usb:058f/9540:libudev:0:/dev/bus/usb/002/005
00000016 ccid_usb.c:265:OpenUSBByName() interface_number: 0
00000004 ccid_usb.c:281:OpenUSBByName() Using: /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist
00000263 ccid_usb.c:299:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr)
00000003 ccid_usb.c:300:OpenUSBByName() ifdProductString: Generic CCID driver
00000002 ccid_usb.c:301: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.
00000915 ccid_usb.c:426:OpenUSBByName() Checking device: 2/5
00000004 ccid_usb.c:488:OpenUSBByName() Trying to open USB bus/device: 2/5
00070797 ccid_usb.c:589:OpenUSBByName() Found Vendor/Product: 058F/9540 (Alcor Micro AU9540)
00000010 ccid_usb.c:591:OpenUSBByName() Using USB bus/device: 2/5
00000004 ccid_usb.c:1149:ControlUSB() request: 0x03
03000176 ccid_usb.c:1162:ControlUSB() control failed (2/5): -7 Resource temporarily unavailable
00000013 ccid_usb.c:1093:get_data_rates() IFD does not support GET_DATA_RATES request: -7
00000982 ccid_usb.c:1202:InterruptRead() before (0)
00000487 ccid_usb.c:1246:InterruptRead() after (0) (0)
00000013 NotifySlotChange: 50 03 
00000005 -> 000000 65 00 00 00 00 00 00 00 00 00 
00000776 <- 000000 81 00 00 00 00 00 00 01 00 01 
00000013 -> 000000 65 00 00 00 00 00 01 00 00 00 
00000799 <- 000000 81 00 00 00 00 00 01 01 00 01 
00000018 ifdhandler.c:362:IFDHGetCapabilities() tag: 0xFB3, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 readerfactory.c:358:RFAddReader() Using the reader polling thread
00000004 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 02 00 00 00 
00000777 <- 000000 81 00 00 00 00 00 02 01 00 01 
00000015 ifdhandler.c:1891:IFDHICCPresence() Card present
00000059 ifdhandler.c:362:IFDHGetCapabilities() tag: 0xFAE, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000007 ifdhandler.c:450:IFDHGetCapabilities() Reader supports 1 slot(s)
00000023 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000008 -> 000000 65 00 00 00 00 00 03 00 00 00 
00000201 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/003/001
00000084 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/003/001
00000108 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x0951, PID: 0x162B, path: /dev/bus/usb/003/002
00000094 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000073 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000074 hotplug_libudev.c:295:get_driver() Looking for a driver for VID: 0x8087, PID: 0x8000, path: /dev/bus/usb/001/002
00000038 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00000046 <- 000000 81 00 00 00 00 00 03 01 00 01 
00000006 ifdhandler.c:1891:IFDHICCPresence() Card present
00000005 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 04 00 00 00 
00000713 <- 000000 81 00 00 00 00 00 04 01 00 01 
00000006 ifdhandler.c:1891:IFDHICCPresence() Card present
00000004 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000005 -> 000000 62 00 00 00 00 00 05 00 00 00 
00009324 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010147 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010121 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010144 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010099 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010108 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010148 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010152 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010119 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010146 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010152 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010120 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010145 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010149 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010118 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010147 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010147 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010115 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010146 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010148 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010114 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010144 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010148 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010115 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010148 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010122 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010113 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010147 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010152 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010116 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010146 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010150 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010116 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00010145 readerfactory.c:1356:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 00 00
00005161 <- 000000 80 17 00 00 00 00 05 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000023 eventhandler.c:292:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000010 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000008 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000010 -> 000000 65 00 00 00 00 00 06 00 00 00 
00000790 <- 000000 81 00 00 00 00 00 06 01 00 01 
00000014 ifdhandler.c:1891:IFDHICCPresence() Card absent
00000007 eventhandler.c:361:EHStatusHandlerThread() Card Removed From Alcor Micro AU9540 00 00
00000008 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 5000 ms
00000005 ccid_usb.c:1202:InterruptRead() before (0)
05000152 ccid_usb.c:1246:InterruptRead() after (0) (2)
00000015 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 07 00 00 00 
00000793 <- 000000 81 00 00 00 00 00 07 01 00 01 
00000014 ifdhandler.c:1891:IFDHICCPresence() Card present
00000005 ifdhandler.c:1122:IFDHPowerICC() action: PowerDown, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 63 00 00 00 00 00 08 00 00 00 
00040829 <- 000000 81 00 00 00 00 00 08 01 00 01 
00000013 eventhandler.c:481:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
00000004 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 09 00 00 00 
00000727 <- 000000 81 00 00 00 00 00 09 01 00 01 
00000007 ifdhandler.c:1891:IFDHICCPresence() Card present
00000003 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 0A 00 00 00 
00000727 <- 000000 81 00 00 00 00 00 0A 01 00 01 
00000007 ifdhandler.c:1891:IFDHICCPresence() Card present
00000003 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 62 00 00 00 00 00 0B 00 00 00 
00348881 <- 000000 80 17 00 00 00 00 0B 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000015 eventhandler.c:407:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000003 eventhandler.c:422:EHStatusHandlerThread() Card inserted into Alcor Micro AU9540 00 00
00000006 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000004 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 5000 ms
00000003 ccid_usb.c:1202:InterruptRead() before (0)
05000148 ccid_usb.c:1246:InterruptRead() after (0) (2)
00000015 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 0C 00 00 00 
00000804 <- 000000 81 00 00 00 00 00 0C 01 00 01 
00000012 ifdhandler.c:1891:IFDHICCPresence() Card absent
00000004 eventhandler.c:481:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
00000003 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 0D 00 00 00 
00000783 <- 000000 81 00 00 00 00 00 0D 01 00 01 
00000013 ifdhandler.c:1891:IFDHICCPresence() Card present
00000005 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 600000 ms
00000003 ccid_usb.c:1202:InterruptRead() before (0)
43008821 winscard_msg_srv.c:256:ProcessEventsServer() Common channel packet arrival
00000020 winscard_msg_srv.c:268:ProcessEventsServer() ProcessCommonChannelRequest detects: 14
00000003 pcscdaemon.c:137:SVCServiceRunLoop() A new context thread creation is requested: 14
00000212 winscard_svc.c:334:ContextThread() Authorized PC/SC client
00000008 winscard_svc.c:338:ContextThread() Thread is started: dwClientID=14, threadContext @0x17cc520
00000009 winscard_svc.c:356:ContextThread() Received command: CMD_VERSION from client 14
00000005 winscard_svc.c:368:ContextThread() Client is protocol version 4:3
00000003 winscard_svc.c:388:ContextThread() CMD_VERSION rv=0x0 for client 14
00000053 winscard_svc.c:356:ContextThread() Received command: ESTABLISH_CONTEXT from client 14
00000020 winscard.c:219:SCardEstablishContext() Establishing Context: 0x13106420
00000008 winscard_svc.c:449:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 14
00000036 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000032 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000047 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000036 winscard_svc.c:356:ContextThread() Received command: CONNECT from client 14
00000010 winscard_svc.c:487:ContextThread() Authorized client for 'Alcor Micro AU9540 00 00'
00000004 winscard.c:261:SCardConnect() Attempting Connect to Alcor Micro AU9540 00 00 using protocol: 3
00000004 readerfactory.c:771:RFReaderInfo() RefReader() count was: 1
00000006 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000008 -> 000000 65 00 00 00 00 00 0E 00 00 00 
00000725 <- 000000 81 00 00 00 00 00 0E 01 00 01 
00000007 ifdhandler.c:1891:IFDHICCPresence() Card present
00000003 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 62 00 00 00 00 00 0F 00 00 00 
00349068 <- 000000 80 17 00 00 00 00 0F 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000017 winscard.c:336:SCardConnect() power up complete.
00000006 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000002 winscard.c:356:SCardConnect() powerState: POWER_STATE_INUSE
00000003 prothandler.c:113:PHSetProtocol() Attempting PTS to T=1
00000003 ifdhandler.c:668:IFDHSetProtocolParameters() protocol T=1, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000005 ifdhandler.c:792:IFDHSetProtocolParameters() Set speed to 115625 bauds
00000002 ifdhandler.c:949:IFDHSetProtocolParameters() BWI/CWI (TB3) present: 0x9F
00000006 ifdhandler.c:983:IFDHSetProtocolParameters() IFSC (TA3) present: 254
00000002 ifdhandler.c:987:IFDHSetProtocolParameters() Timeout: 124152 ms
00000003 commands.c:2207:SetParameters() length: 7 bytes
00000004 -> 000000 61 07 00 00 00 00 10 01 00 00 95 10 00 9F 00 FE 00 
00348576 <- 000000 82 00 00 00 00 00 10 01 00 00 
00000015 ifdhandler.c:1044:IFDHSetProtocolParameters() IFSC (TA3) present: 254
00000003 ifdhandler.c:1057:IFDHSetProtocolParameters() T=1: IFSC=254, IFSD=254
00000003 winscard.c:435:SCardConnect() Active Protocol: T=1
00000004 winscard.c:455:SCardConnect() hCard Identity: 306e8bb9
00000004 winscard.c:516:SCardConnect() UnrefReader() count was: 2
00000004 winscard_svc.c:501:ContextThread() CONNECT rv=0x0 for client 14
00000073 winscard_svc.c:356:ContextThread() Received command: CONTROL from client 14
00000014 readerfactory.c:798:RFReaderInfoById() RefReader() count was: 1
00000005 ifdhandler.c:1360:IFDHControl() ControlCode: 0x42000D48, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000002 Control TxBuffer: 
00000004 Control RxBuffer: 12 04 42 33 00 12 
00000003 winscard.c:1376:SCardControl() UnrefReader() count was: 2
00000003 winscard_svc.c:700:ContextThread() CONTROL rv=0x0 for client 14
00000041 winscard_svc.c:356:ContextThread() Received command: DISCONNECT from client 14
00000013 readerfactory.c:798:RFReaderInfoById() RefReader() count was: 1
00000004 winscard.c:876:SCardDisconnect() Active Contexts: 1
00000003 winscard.c:877:SCardDisconnect() dwDisposition: 0
00000003 winscard.c:1042:SCardDisconnect() powerState: POWER_STATE_GRACE_PERIOD
00000005 ifdhandler.c:362:IFDHGetCapabilities() tag: 0xFB2, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000003 winscard.c:1056:SCardDisconnect() Stopping polling thread
00000003 ifdhandler.c:327:IFDHStopPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000037 winscard.c:1069:SCardDisconnect() UnrefReader() count was: 2
00000008 winscard_svc.c:538:ContextThread() DISCONNECT rv=0x0 for client 14
00000004 ccid_usb.c:1246:InterruptRead() after (0) (3)
00000008 ccid_usb.c:1261:InterruptRead() InterruptRead (2/5): Resource temporarily unavailable
00000074 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000047 winscard_svc.c:356:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14
00000014 winscard_svc.c:356:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14
00000007 winscard_svc.c:430:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14
00000049 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000074 winscard_svc.c:356:ContextThread() Received command: RELEASE_CONTEXT from client 14
00000011 winscard.c:230:SCardReleaseContext() Releasing Context: 0x13106420
00000005 winscard_svc.c:464:ContextThread() RELEASE_CONTEXT rv=0x0 for client 14
00000028 winscard_svc.c:348:ContextThread() Client die: 14
00000017 winscard_svc.c:981:MSGCleanupClient() Thread is stopping: dwClientID=14, threadContext @0x17cc520
00000004 winscard_svc.c:987:MSGCleanupClient() Freeing SCONTEXT @0x17cc520
00399835 eventhandler.c:493:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000017 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 11 00 00 00 
00000784 <- 000000 81 00 00 00 00 00 11 01 00 01 
00000012 ifdhandler.c:1891:IFDHICCPresence() Card absent
00000004 eventhandler.c:361:EHStatusHandlerThread() Card Removed From Alcor Micro AU9540 00 00
00000005 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 5000 ms
00000002 ccid_usb.c:1202:InterruptRead() before (0)
05000148 ccid_usb.c:1246:InterruptRead() after (0) (2)
00000015 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 12 00 00 00 
00000763 <- 000000 81 00 00 00 00 00 12 01 00 01 
00000012 ifdhandler.c:1891:IFDHICCPresence() Card present
00000004 ifdhandler.c:1122:IFDHPowerICC() action: PowerDown, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 63 00 00 00 00 00 13 00 00 00 
00040876 <- 000000 81 00 00 00 00 00 13 01 00 01 
00000015 eventhandler.c:481:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
00000005 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 14 00 00 00 
00000774 <- 000000 81 00 00 00 00 00 14 01 00 01 
00000012 ifdhandler.c:1891:IFDHICCPresence() Card present
00000004 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 15 00 00 00 
00000725 <- 000000 81 00 00 00 00 00 15 01 00 01 
00000007 ifdhandler.c:1891:IFDHICCPresence() Card present
00000003 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 62 00 00 00 00 00 16 00 00 00 
00348959 <- 000000 80 17 00 00 00 00 16 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000016 eventhandler.c:407:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000003 eventhandler.c:422:EHStatusHandlerThread() Card inserted into Alcor Micro AU9540 00 00
00000005 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000005 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 5000 ms
00000003 ccid_usb.c:1202:InterruptRead() before (0)
05000134 ccid_usb.c:1246:InterruptRead() after (0) (2)
00000015 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000009 -> 000000 65 00 00 00 00 00 17 00 00 00 
00000742 <- 000000 81 00 00 00 00 00 17 01 00 01 
00000008 ifdhandler.c:1891:IFDHICCPresence() Card absent
00000004 eventhandler.c:481:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
00000003 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 18 00 00 00 
00000758 <- 000000 81 00 00 00 00 00 18 01 00 01 
00000007 ifdhandler.c:1891:IFDHICCPresence() Card present
00000005 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 600000 ms
00000004 ccid_usb.c:1202:InterruptRead() before (0)
03521765 winscard_msg_srv.c:256:ProcessEventsServer() Common channel packet arrival
00000024 winscard_msg_srv.c:268:ProcessEventsServer() ProcessCommonChannelRequest detects: 14
00000002 pcscdaemon.c:137:SVCServiceRunLoop() A new context thread creation is requested: 14
00000189 winscard_svc.c:334:ContextThread() Authorized PC/SC client
00000006 winscard_svc.c:338:ContextThread() Thread is started: dwClientID=14, threadContext @0x17cc520
00000017 winscard_svc.c:356:ContextThread() Received command: CMD_VERSION from client 14
00000003 winscard_svc.c:368:ContextThread() Client is protocol version 4:3
00000002 winscard_svc.c:388:ContextThread() CMD_VERSION rv=0x0 for client 14
00000028 winscard_svc.c:356:ContextThread() Received command: ESTABLISH_CONTEXT from client 14
00000007 winscard.c:219:SCardEstablishContext() Establishing Context: 0x43DC6D26
00000002 winscard_svc.c:449:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 14
00000020 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000019 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000019 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000024 winscard_svc.c:356:ContextThread() Received command: CONNECT from client 14
00000005 winscard_svc.c:487:ContextThread() Authorized client for 'Alcor Micro AU9540 00 00'
00000002 winscard.c:261:SCardConnect() Attempting Connect to Alcor Micro AU9540 00 00 using protocol: 3
00000002 readerfactory.c:771:RFReaderInfo() RefReader() count was: 1
00000003 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 19 00 00 00 
00000688 <- 000000 81 00 00 00 00 00 19 01 00 01 
00000004 ifdhandler.c:1891:IFDHICCPresence() Card present
00000003 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000003 -> 000000 62 00 00 00 00 00 1A 00 00 00 
00349060 <- 000000 80 17 00 00 00 00 1A 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000016 winscard.c:336:SCardConnect() power up complete.
00000005 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000003 winscard.c:356:SCardConnect() powerState: POWER_STATE_INUSE
00000003 prothandler.c:113:PHSetProtocol() Attempting PTS to T=1
00000003 ifdhandler.c:668:IFDHSetProtocolParameters() protocol T=1, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 ifdhandler.c:792:IFDHSetProtocolParameters() Set speed to 115625 bauds
00000003 ifdhandler.c:949:IFDHSetProtocolParameters() BWI/CWI (TB3) present: 0x9F
00000003 ifdhandler.c:983:IFDHSetProtocolParameters() IFSC (TA3) present: 254
00000002 ifdhandler.c:987:IFDHSetProtocolParameters() Timeout: 124152 ms
00000003 commands.c:2207:SetParameters() length: 7 bytes
00000004 -> 000000 61 07 00 00 00 00 1B 01 00 00 95 10 00 9F 00 FE 00 
00348556 <- 000000 82 00 00 00 00 00 1B 01 00 00 
00000015 ifdhandler.c:1044:IFDHSetProtocolParameters() IFSC (TA3) present: 254
00000003 ifdhandler.c:1057:IFDHSetProtocolParameters() T=1: IFSC=254, IFSD=254
00000003 winscard.c:435:SCardConnect() Active Protocol: T=1
00000004 winscard.c:455:SCardConnect() hCard Identity: 27b21154
00000003 winscard.c:516:SCardConnect() UnrefReader() count was: 2
00000004 winscard_svc.c:501:ContextThread() CONNECT rv=0x0 for client 14
00000059 winscard_svc.c:356:ContextThread() Received command: CONTROL from client 14
00000012 readerfactory.c:798:RFReaderInfoById() RefReader() count was: 1
00000005 ifdhandler.c:1360:IFDHControl() ControlCode: 0x42000D48, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000003 Control TxBuffer: 
00000004 Control RxBuffer: 12 04 42 33 00 12 
00000003 winscard.c:1376:SCardControl() UnrefReader() count was: 2
00000003 winscard_svc.c:700:ContextThread() CONTROL rv=0x0 for client 14
00000034 winscard_svc.c:356:ContextThread() Received command: DISCONNECT from client 14
00000010 readerfactory.c:798:RFReaderInfoById() RefReader() count was: 1
00000003 winscard.c:876:SCardDisconnect() Active Contexts: 1
00000002 winscard.c:877:SCardDisconnect() dwDisposition: 0
00000002 winscard.c:1042:SCardDisconnect() powerState: POWER_STATE_GRACE_PERIOD
00000003 ifdhandler.c:362:IFDHGetCapabilities() tag: 0xFB2, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000002 winscard.c:1056:SCardDisconnect() Stopping polling thread
00000002 ifdhandler.c:327:IFDHStopPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000060 winscard.c:1069:SCardDisconnect() UnrefReader() count was: 2
00000010 winscard_svc.c:538:ContextThread() DISCONNECT rv=0x0 for client 14
00000000 ccid_usb.c:1246:InterruptRead() after (0) (3)
00000019 ccid_usb.c:1261:InterruptRead() InterruptRead (2/5): Resource temporarily unavailable
00000067 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000052 winscard_svc.c:356:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14
00000033 winscard_svc.c:356:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14
00000013 winscard_svc.c:430:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14
00000031 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000046 winscard_svc.c:356:ContextThread() Received command: RELEASE_CONTEXT from client 14
00000010 winscard.c:230:SCardReleaseContext() Releasing Context: 0x43DC6D26
00000004 winscard_svc.c:464:ContextThread() RELEASE_CONTEXT rv=0x0 for client 14
00000029 winscard_svc.c:348:ContextThread() Client die: 14
00000017 winscard_svc.c:981:MSGCleanupClient() Thread is stopping: dwClientID=14, threadContext @0x17cc520
00000003 winscard_svc.c:987:MSGCleanupClient() Freeing SCONTEXT @0x17cc520
00399859 eventhandler.c:493:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000018 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000005 -> 000000 65 00 00 00 00 00 1C 00 00 00 
00000810 <- 000000 81 00 00 00 00 00 1C 01 00 01 
00000012 ifdhandler.c:1891:IFDHICCPresence() Card absent
00000005 eventhandler.c:361:EHStatusHandlerThread() Card Removed From Alcor Micro AU9540 00 00
00000004 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 5000 ms
00000003 ccid_usb.c:1202:InterruptRead() before (0)
00903450 winscard_msg_srv.c:256:ProcessEventsServer() Common channel packet arrival
00000016 winscard_msg_srv.c:268:ProcessEventsServer() ProcessCommonChannelRequest detects: 14
00000003 pcscdaemon.c:137:SVCServiceRunLoop() A new context thread creation is requested: 14
00000165 winscard_svc.c:334:ContextThread() Authorized PC/SC client
00000006 winscard_svc.c:338:ContextThread() Thread is started: dwClientID=14, threadContext @0x17cc520
00000007 winscard_svc.c:356:ContextThread() Received command: CMD_VERSION from client 14
00000003 winscard_svc.c:368:ContextThread() Client is protocol version 4:3
00000002 winscard_svc.c:388:ContextThread() CMD_VERSION rv=0x0 for client 14
00000076 winscard_svc.c:356:ContextThread() Received command: ESTABLISH_CONTEXT from client 14
00000010 winscard.c:219:SCardEstablishContext() Establishing Context: 0x1B6B461F
00000003 winscard_svc.c:449:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 14
00000033 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000028 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000030 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000024 winscard_svc.c:356:ContextThread() Received command: CONNECT from client 14
00000007 winscard_svc.c:487:ContextThread() Authorized client for 'Alcor Micro AU9540 00 00'
00000003 winscard.c:261:SCardConnect() Attempting Connect to Alcor Micro AU9540 00 00 using protocol: 3
00000004 readerfactory.c:771:RFReaderInfo() RefReader() count was: 1
00000002 winscard.c:448:SCardConnect() Direct access: no protocol selected
00000003 winscard.c:455:SCardConnect() hCard Identity: 25c47f1c
00000003 winscard.c:516:SCardConnect() UnrefReader() count was: 2
00000003 winscard_svc.c:501:ContextThread() CONNECT rv=0x0 for client 14
00000024 winscard_svc.c:356:ContextThread() Received command: CONTROL from client 14
00000007 readerfactory.c:798:RFReaderInfoById() RefReader() count was: 1
00000005 ifdhandler.c:1360:IFDHControl() ControlCode: 0x42000D48, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000002 Control TxBuffer: 
00000004 Control RxBuffer: 12 04 42 33 00 12 
00000002 winscard.c:1376:SCardControl() UnrefReader() count was: 2
00000003 winscard_svc.c:700:ContextThread() CONTROL rv=0x0 for client 14
00000021 winscard_svc.c:356:ContextThread() Received command: DISCONNECT from client 14
00000007 readerfactory.c:798:RFReaderInfoById() RefReader() count was: 1
00000003 winscard.c:876:SCardDisconnect() Active Contexts: 1
00000002 winscard.c:877:SCardDisconnect() dwDisposition: 0
00000003 winscard.c:1042:SCardDisconnect() powerState: POWER_STATE_GRACE_PERIOD
00000003 ifdhandler.c:362:IFDHGetCapabilities() tag: 0xFB2, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000003 winscard.c:1056:SCardDisconnect() Stopping polling thread
00000002 ifdhandler.c:327:IFDHStopPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000027 winscard.c:1069:SCardDisconnect() UnrefReader() count was: 2
00000007 winscard_svc.c:538:ContextThread() DISCONNECT rv=0x0 for client 14
00000006 ccid_usb.c:1246:InterruptRead() after (0) (3)
00000006 ccid_usb.c:1261:InterruptRead() InterruptRead (2/5): Resource temporarily unavailable
00000033 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000029 winscard_svc.c:356:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14
00000010 winscard_svc.c:356:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14
00000006 winscard_svc.c:430:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14
00000015 winscard_svc.c:356:ContextThread() Received command: CMD_GET_READERS_STATE from client 14
00000024 winscard_svc.c:356:ContextThread() Received command: RELEASE_CONTEXT from client 14
00000006 winscard.c:230:SCardReleaseContext() Releasing Context: 0x1B6B461F
00000002 winscard_svc.c:464:ContextThread() RELEASE_CONTEXT rv=0x0 for client 14
00000014 winscard_svc.c:348:ContextThread() Client die: 14
00000008 winscard_svc.c:981:MSGCleanupClient() Thread is stopping: dwClientID=14, threadContext @0x17cc520
00000005 winscard_svc.c:987:MSGCleanupClient() Freeing SCONTEXT @0x17cc520
00400014 eventhandler.c:493:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000015 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 1D 00 00 00 
00000776 <- 000000 81 00 00 00 00 00 1D 01 00 01 
00000012 ifdhandler.c:1891:IFDHICCPresence() Card present
00000005 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 1E 00 00 00 
00000771 <- 000000 81 00 00 00 00 00 1E 01 00 01 
00000014 ifdhandler.c:1891:IFDHICCPresence() Card present
00000005 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 62 00 00 00 00 00 1F 00 00 00 
00349072 <- 000000 80 17 00 00 00 00 1F 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000015 eventhandler.c:407:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00000004 eventhandler.c:422:EHStatusHandlerThread() Card inserted into Alcor Micro AU9540 00 00
00000005 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 12 C4 
00000004 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 5000 ms
00000003 ccid_usb.c:1202:InterruptRead() before (0)
05000274 ccid_usb.c:1246:InterruptRead() after (0) (2)
00000015 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000006 -> 000000 65 00 00 00 00 00 20 00 00 00 
00000714 <- 000000 81 00 00 00 00 00 20 01 00 01 
00000007 ifdhandler.c:1891:IFDHICCPresence() Card absent
00000003 eventhandler.c:481:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
00000002 ifdhandler.c:1770:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0)
00000004 -> 000000 65 00 00 00 00 00 21 00 00 00 
00000708 <- 000000 81 00 00 00 00 00 21 01 00 01 
00000005 ifdhandler.c:1891:IFDHICCPresence() Card present
00000003 ifdhandler.c:291:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/002/005 (lun: 0) 600000 ms
00000003 ccid_usb.c:1202:InterruptRead() before (0)