00000000 debuglog.c:269:DebugLogSetLevel() debug level=debug 00000022 debuglog.c:298:DebugLogSetCategory() Debug options: APDU 00000101 configfile.l:254:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d 00000062 configfile.l:307:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin 00000078 configfile.l:266:DBGetReaderListDir() Skipping non regular file: .. 00000007 configfile.l:266:DBGetReaderListDir() Skipping non regular file: . 00000007 pcscdaemon.c:545:main() pcsc-lite 1.8.10 daemon ready. 00001666 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000097 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001 00000130 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001 00000098 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001 00000102 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/003/002 00000101 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC52B, path: /dev/bus/usb/003/003 00000101 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC52B, path: /dev/bus/usb/003/003 00000099 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC52B, path: /dev/bus/usb/003/003 00000097 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/003/002 00000116 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/004/001 00000096 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/004/001 00000099 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/004/002 00000108 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x05E3, PID: 0x070E, path: /dev/bus/usb/004/003 00000392 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/004/002 00000164 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9520, path: /dev/bus/usb/004/004 00000050 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9520, path: /dev/bus/usb/004/004 00000026 hotplug_libudev.c:321:HPAddDevice() Adding USB device: Alcor Micro AU9520 00000075 readerfactory.c:989:RFInitializeReader() Attempting startup of Alcor Micro AU9520 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so 00000217 readerfactory.c:874:RFBindFunctions() Loading IFD Handler 3.0 00000058 ifdhandler.c:1950:init_driver() Driver version: 1.4.22 00001031 ifdhandler.c:1967:init_driver() LogLevel: 0x0003 00000043 ifdhandler.c:1978:init_driver() DriverOptions: 0x0000 00000336 ifdhandler.c:1991:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F 00000031 ifdhandler.c:110:CreateChannelByNameOrChannel() Lun: 0, device: usb:058f/9520:libudev:0:/dev/bus/usb/004/004 00000024 ccid_usb.c:234:OpenUSBByName() Reader index: 0, Device: usb:058f/9520:libudev:0:/dev/bus/usb/004/004 00000030 ccid_usb.c:266:OpenUSBByName() interface_number: 0 00000020 ccid_usb.c:267:OpenUSBByName() usb bus/device: 4/4 00000032 ccid_usb.c:284:OpenUSBByName() Using: /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist 00000659 ccid_usb.c:302:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr) 00000007 ccid_usb.c:303:OpenUSBByName() ifdProductString: Generic CCID driver 00000003 ccid_usb.c:304: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. 00002473 ccid_usb.c:388:OpenUSBByName() Try device: 4/4 00000067 ccid_usb.c:398:OpenUSBByName() vid/pid : 058F/9520 00000022 ccid_usb.c:445:OpenUSBByName() Checking device: 4/4 00000020 ccid_usb.c:507:OpenUSBByName() Trying to open USB bus/device: 4/4 00000117 ccid_usb.c:609:OpenUSBByName() Found Vendor/Product: 058F/9520 (Alcor Micro AU9520) 00000034 ccid_usb.c:611:OpenUSBByName() Using USB bus/device: 4/4 00000021 ccid_usb.c:1172:ControlUSB() request: 0x03 00001924 receive: 0F 07 00 00 C5 07 00 00 69 09 00 00 B7 09 00 00 F3 0C 00 00 1D 0E 00 00 8A 0F 00 00 D2 12 00 00 6D 13 00 00 E7 19 00 00 3B 1C 00 00 15 1F 00 00 A3 25 00 00 DA 26 00 00 CE 33 00 00 75 38 00 00 2A 3E 00 00 47 4B 00 00 B4 4D 00 00 B0 54 00 00 3F 5D 00 00 9B 67 00 00 EA 70 00 00 8F 74 00 00 54 7C 00 00 25 8D 00 00 8E 96 00 00 69 9B 00 00 5F A9 00 00 31 BC 00 00 43 C2 00 00 37 CF 00 00 D5 E1 00 00 1D E9 00 00 A8 F8 00 00 04 03 01 00 4A 1A 01 00 1B 2D 01 00 D2 36 01 00 BF 52 01 00 62 78 01 00 86 84 01 00 6D 9E 01 00 A9 C3 01 00 3B D2 01 00 08 06 02 00 93 34 02 00 37 5A 02 00 A4 6D 02 00 0D 09 03 00 DA 3C 03 00 52 87 03 00 48 DB 04 00 00000018 ccid_usb.c:1152:get_data_rates() declared: 1807 bps 00000003 ccid_usb.c:1152:get_data_rates() declared: 1989 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 2409 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 2487 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 3315 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 3613 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 3978 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 4818 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 4973 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 6631 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 7227 bps 00000003 ccid_usb.c:1152:get_data_rates() declared: 7957 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 9635 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 9946 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 13262 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 14453 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 15914 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 19271 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 19892 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 21680 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 23871 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 26523 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 28906 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 29839 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 31828 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 36133 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 38542 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 39785 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 43359 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 48177 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 49731 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 53047 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 57813 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 59677 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 63656 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 66308 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 72266 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 77083 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 79570 bps 00000011 ccid_usb.c:1152:get_data_rates() declared: 86719 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 96354 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 99462 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 106093 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 115625 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 119355 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 132616 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 144531 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 154167 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 159140 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 198925 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 212186 bps 00000001 ccid_usb.c:1152:get_data_rates() declared: 231250 bps 00000002 ccid_usb.c:1152:get_data_rates() declared: 318280 bps 00000915 ccid_usb.c:1225:InterruptRead() before (0) 00019280 ccid_usb.c:1269:InterruptRead() after (0) (0) 00000015 NotifySlotChange: 50 02 00000005 -> 000000 65 00 00 00 00 00 00 00 00 00 00000456 <- 000000 81 00 00 00 00 00 00 42 FE 01 00000039 -> 000000 65 00 00 00 00 00 01 00 00 00 00000465 <- 000000 81 00 00 00 00 00 01 42 FE 01 00000017 ifdhandler.c:376:IFDHGetCapabilities() tag: 0xFB3, usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000003 readerfactory.c:332:RFAddReader() Using the reader polling thread 00000003 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 65 00 00 00 00 00 02 00 00 00 00000475 <- 000000 81 00 00 00 00 00 02 42 FE 01 00000010 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000099 ifdhandler.c:376:IFDHGetCapabilities() tag: 0xFAE, usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000006 ifdhandler.c:467:IFDHGetCapabilities() Reader supports 1 slot(s) 00000061 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000026 -> 000000 65 00 00 00 00 00 03 00 00 00 00000039 hotplug_libudev.c:269:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/004/002 00000105 readerfactory.c:1330:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9520 00 00 00000441 <- 000000 81 00 00 00 00 00 03 42 FE 01 00000012 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000006 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 65 00 00 00 00 00 04 00 00 00 00000556 <- 000000 81 00 00 00 00 00 04 42 FE 01 00000018 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000004 ifdhandler.c:305:IFDHPolling() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 600000 ms 00000003 ccid_usb.c:1225:InterruptRead() before (0) 08860550 ccid_usb.c:1269:InterruptRead() after (0) (0) 00000017 NotifySlotChange: 50 03 00000006 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000005 -> 000000 65 00 00 00 00 00 05 00 00 00 00000425 <- 000000 81 00 00 00 00 00 05 00 00 00 00000011 ifdhandler.c:1931:IFDHICCPresence() Card present 00000005 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 65 00 00 00 00 00 06 00 00 00 00000543 <- 000000 81 00 00 00 00 00 06 00 00 00 00000013 ifdhandler.c:1931:IFDHICCPresence() Card present 00000005 ifdhandler.c:1143:IFDHPowerICC() action: PowerUp, usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 62 00 00 00 00 00 07 00 00 00 00000952 <- 000000 80 14 00 00 00 00 07 00 00 00 3B FA 18 00 00 80 31 FE 45 FE 65 49 44 20 2F 20 50 4B 49 03 00000019 eventhandler.c:381:EHStatusHandlerThread() powerState: POWER_STATE_POWERED 00000004 eventhandler.c:396:EHStatusHandlerThread() Card inserted into Alcor Micro AU9520 00 00 00000006 Card ATR: 3B FA 18 00 00 80 31 FE 45 FE 65 49 44 20 2F 20 50 4B 49 03 00000004 ifdhandler.c:305:IFDHPolling() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 5000 ms 00000002 ccid_usb.c:1225:InterruptRead() before (0) 01533878 ccid_usb.c:1269:InterruptRead() after (0) (0) 00000015 NotifySlotChange: 50 02 00000006 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000005 -> 000000 65 00 00 00 00 00 08 00 00 00 00000424 <- 000000 81 00 00 00 00 00 08 42 FE 01 00000012 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000004 eventhandler.c:455:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED 00000003 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 65 00 00 00 00 00 09 00 00 00 00000476 <- 000000 81 00 00 00 00 00 09 42 FE 01 00000015 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000004 eventhandler.c:335:EHStatusHandlerThread() Card Removed From Alcor Micro AU9520 00 00 00000004 ifdhandler.c:305:IFDHPolling() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 600000 ms 00000003 ccid_usb.c:1225:InterruptRead() before (0) 01882582 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival 00000083 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 14 00000021 pcscdaemon.c:111:SVCServiceRunLoop() A new context thread creation is requested: 14 00000116 winscard_svc.c:301:ContextThread() Thread is started: dwClientID=14, threadContext @0xe30500 00000023 winscard_svc.c:319:ContextThread() Received command: CMD_VERSION from client 14 00000007 winscard_svc.c:331:ContextThread() Client is protocol version 4:3 00000003 winscard_svc.c:351:ContextThread() CMD_VERSION rv=0x0 for client 14 00000108 winscard_svc.c:319:ContextThread() Received command: ESTABLISH_CONTEXT from client 14 00000031 winscard.c:193:SCardEstablishContext() Establishing Context: 0x2CF23B48 00000004 winscard_svc.c:412:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 14 00000089 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000083 winscard_svc.c:319:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 00000026 winscard_svc.c:319:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 14 00000006 winscard_svc.c:393:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 14 00000018 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000066 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000058 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000107 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000178 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000111 winscard_svc.c:319:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 02531038 ccid_usb.c:1269:InterruptRead() after (0) (0) 00000019 NotifySlotChange: 50 03 00000006 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000005 -> 000000 65 00 00 00 00 00 0A 00 00 00 00000562 <- 000000 81 00 00 00 00 00 0A 00 00 00 00000012 ifdhandler.c:1931:IFDHICCPresence() Card present 00000004 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 65 00 00 00 00 00 0B 00 00 00 00000456 <- 000000 81 00 00 00 00 00 0B 00 00 00 00000011 ifdhandler.c:1931:IFDHICCPresence() Card present 00000005 ifdhandler.c:1143:IFDHPowerICC() action: PowerUp, usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000004 -> 000000 62 00 00 00 00 00 0C 00 00 00 00000850 <- 000000 80 14 00 00 00 00 0C 00 00 00 3B FA 18 00 00 80 31 FE 45 FE 65 49 44 20 2F 20 50 4B 49 03 00000014 eventhandler.c:381:EHStatusHandlerThread() powerState: POWER_STATE_POWERED 00000003 eventhandler.c:396:EHStatusHandlerThread() Card inserted into Alcor Micro AU9520 00 00 00000004 winscard_svc.c:735:MSGSignalClient() Signal client: 14 00000002 winscard_svc.c:738:MSGSignalClient() SIGNAL rv=0x0 for client 14 00000019 Card ATR: 3B FA 18 00 00 80 31 FE 45 FE 65 49 44 20 2F 20 50 4B 49 03 00000004 ifdhandler.c:305:IFDHPolling() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 5000 ms 00000003 ccid_usb.c:1225:InterruptRead() before (0) 00000043 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00041858 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000043 winscard_svc.c:319:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 02355900 ccid_usb.c:1269:InterruptRead() after (0) (0) 00000017 NotifySlotChange: 50 02 00000006 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000005 -> 000000 65 00 00 00 00 00 0D 00 00 00 00000422 <- 000000 81 00 00 00 00 00 0D 42 FE 01 00000012 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000004 eventhandler.c:455:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED 00000003 ifdhandler.c:1810:IFDHICCPresence() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 00000005 -> 000000 65 00 00 00 00 00 0E 00 00 00 00000508 <- 000000 81 00 00 00 00 00 0E 42 FE 01 00000012 ifdhandler.c:1931:IFDHICCPresence() Card absent 00000004 eventhandler.c:335:EHStatusHandlerThread() Card Removed From Alcor Micro AU9520 00 00 00000003 winscard_svc.c:735:MSGSignalClient() Signal client: 14 00000003 winscard_svc.c:738:MSGSignalClient() SIGNAL rv=0x0 for client 14 00000017 ifdhandler.c:305:IFDHPolling() usb:058f/9520:libudev:0:/dev/bus/usb/004/004 (lun: 0) 600000 ms 00000003 ccid_usb.c:1225:InterruptRead() before (0) 00000050 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000162 winscard_svc.c:319:ContextThread() Received command: CMD_GET_READERS_STATE from client 14 00000159 winscard_svc.c:319:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 14 01635046 winscard_svc.c:311:ContextThread() Client die: 14 00000078 winscard.c:204:SCardReleaseContext() Releasing Context: 0x2CF23B48 00000022 winscard_svc.c:933:MSGCleanupClient() Thread is stopping: dwClientID=14, threadContext @0xe30500 00000016 winscard_svc.c:939:MSGCleanupClient() Freeing SCONTEXT @0xe30500