Menu
▾
▴
[Opensc-devel] PKCS11 Token Initialisation failure
|
From: Fred <fre...@gm...> - 2013-03-28 16:11:29
|
Hi all, I am trying to compile cryptlib 3.4.2 against OpenSC PKCS11 api. I am using a Feitian PKI smart card (from www.gooze.eu) I have initialized using pkcs15-tool with a test pin. I changed cryptlib/testlib.c to have device tested. Currently, device is opened and logged-in OK, but further device initialization seems to fail. He follows debug of pcscd when cryptlib/testlib -d tries to access the device. Can you help to diagnose what is failing ? Best regards, Fred ##### 00000000 debuglog.c:269:DebugLogSetLevel() debug level=debug 00000066 debuglog.c:298:DebugLogSetCategory() Debug options: APDU 00000270 configfile.l:245:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d 00000040 configfile.l:257:DBGetReaderListDir() Skipping non regular file: . 00000016 configfile.l:298:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/reader.conf 00000099 configfile.l:298:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin 00000057 configfile.l:257:DBGetReaderListDir() Skipping non regular file: .. 00000019 pcscdaemon.c:525:main() pcsc-lite 1.8.8 daemon ready. 00003710 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/002/001 00000095 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/002/001 00000098 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x096E, PID: 0x0503, path: /dev/bus/usb/002/003 00000023 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x096E, PID: 0x0503, path: /dev/bus/usb/002/003 00000005 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Feitian SCR301 00000027 readerfactory.c:978:RFInitializeReader() Attempting startup of Feitian SCR301 00 00 using /usr/lib/readers/ifd-ccid.bundle/Contents/Linux/libccid.so 00000179 readerfactory.c:868:RFBindFunctions() Loading IFD Handler 3.0 00000035 ifdhandler.c:1840:init_driver() Driver version: 1.4.9 00000624 ifdhandler.c:1857:init_driver() LogLevel: 0x0003 00000007 ifdhandler.c:1868:init_driver() DriverOptions: 0x0000 00000125 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 0, device: usb:096e/0503:libudev:0:/dev/bus/usb/002/003 00000030 ccid_usb.c:228:OpenUSBByName() Using: /usr/lib/readers/ifd-ccid.bundle/Contents/Info.plist 00000548 ccid_usb.c:246:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (lud...@fr...) 00000007 ccid_usb.c:247:OpenUSBByName() ifdProductString: Generic CCID driver 00000007 ccid_usb.c:248: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. 00071330 ccid_usb.c:521:OpenUSBByName() Found Vendor/Product: 096E/0503 (Feitian SCR301) 00000129 ccid_usb.c:523:OpenUSBByName() Using USB bus/device: 2/3 00002452 ccid_usb.c:1021:get_data_rates() declared: 10753 bps 00000058 ccid_usb.c:1021:get_data_rates() declared: 14337 bps 00000041 ccid_usb.c:1021:get_data_rates() declared: 15625 bps 00000038 ccid_usb.c:1021:get_data_rates() declared: 17204 bps 00000037 ccid_usb.c:1021:get_data_rates() declared: 20833 bps 00000037 ccid_usb.c:1021:get_data_rates() declared: 21505 bps 00000038 ccid_usb.c:1021:get_data_rates() declared: 23438 bps 00000270 ccid_usb.c:1021:get_data_rates() declared: 25806 bps 00000253 ccid_usb.c:1021:get_data_rates() declared: 28674 bps 00000311 ccid_usb.c:1021:get_data_rates() declared: 31250 bps 00000253 ccid_usb.c:1021:get_data_rates() declared: 32258 bps 00000251 ccid_usb.c:1021:get_data_rates() declared: 34409 bps 00000250 ccid_usb.c:1021:get_data_rates() declared: 39063 bps 00000282 ccid_usb.c:1021:get_data_rates() declared: 41667 bps 00000157 ccid_usb.c:1021:get_data_rates() declared: 43011 bps 00000057 ccid_usb.c:1021:get_data_rates() declared: 46875 bps 00000156 ccid_usb.c:1021:get_data_rates() declared: 52083 bps 00000055 ccid_usb.c:1021:get_data_rates() declared: 53763 bps 00000155 ccid_usb.c:1021:get_data_rates() declared: 57348 bps 00000053 ccid_usb.c:1021:get_data_rates() declared: 62500 bps 00000169 ccid_usb.c:1021:get_data_rates() declared: 64516 bps 00000058 ccid_usb.c:1021:get_data_rates() declared: 68817 bps 00000158 ccid_usb.c:1021:get_data_rates() declared: 71685 bps 00000053 ccid_usb.c:1021:get_data_rates() declared: 78125 bps 00000155 ccid_usb.c:1021:get_data_rates() declared: 83333 bps 00000054 ccid_usb.c:1021:get_data_rates() declared: 86022 bps 00000154 ccid_usb.c:1021:get_data_rates() declared: 93750 bps 00000053 ccid_usb.c:1021:get_data_rates() declared: 104167 bps 00000153 ccid_usb.c:1021:get_data_rates() declared: 107527 bps 00000087 ccid_usb.c:1021:get_data_rates() declared: 114695 bps 00000179 ccid_usb.c:1021:get_data_rates() declared: 125000 bps 00000153 ccid_usb.c:1021:get_data_rates() declared: 129032 bps 00000056 ccid_usb.c:1021:get_data_rates() declared: 143369 bps 00000153 ccid_usb.c:1021:get_data_rates() declared: 156250 bps 00000057 ccid_usb.c:1021:get_data_rates() declared: 166667 bps 00000152 ccid_usb.c:1021:get_data_rates() declared: 172043 bps 00000056 ccid_usb.c:1021:get_data_rates() declared: 215054 bps 00000052 ccid_usb.c:1021:get_data_rates() declared: 229391 bps 00000157 ccid_usb.c:1021:get_data_rates() declared: 250000 bps 00000181 ccid_usb.c:1021:get_data_rates() declared: 344086 bps 00013077 ccid_usb.c:660:WriteUSB() write failed (2/3): -4 No such device 00000080 readerfactory.c:1009:RFInitializeReader() Open Port 0x200000 Failed (usb:096e/0503:libudev:0:/dev/bus/usb/002/003) 00000044 readerfactory.c:312:RFAddReader() Feitian SCR301 init failed. 00000045 readerfactory.c:529:RFRemoveReader() UnrefReader() count was: 1 00000039 readerfactory.c:1029:RFUnInitializeReader() Attempting shutdown of Feitian SCR301 00 00. 00000039 readerfactory.c:905:RFUnloadReader() Unloading reader driver. 00000446 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/003/001 00000368 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/004/001 00001095 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/005/001 00001005 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00001158 hotplug_libudev.c:587:HPEstablishUSBNotifications() Device removed 00001963 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/002/001 00000889 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/003/001 00000159 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/004/001 00000639 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/005/001 00000503 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000355 hotplug_libudev.c:513:HPRescanUsbBus() Removing USB device[0]: Feitian SCR301 at /dev/bus/usb/002/003 00655829 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x096E, PID: 0x0503, path: /dev/bus/usb/002/004 00000084 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Feitian SCR301 00000088 readerfactory.c:978:RFInitializeReader() Attempting startup of Feitian SCR301 00 00 using /usr/lib/readers/ifd-ccid.bundle/Contents/Linux/libccid.so 00000232 readerfactory.c:868:RFBindFunctions() Loading IFD Handler 3.0 00000053 ifdhandler.c:1840:init_driver() Driver version: 1.4.9 00000707 ifdhandler.c:1857:init_driver() LogLevel: 0x0003 00000036 ifdhandler.c:1868:init_driver() DriverOptions: 0x0000 00000202 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 0, device: usb:096e/0503:libudev:0:/dev/bus/usb/002/004 00000046 ccid_usb.c:228:OpenUSBByName() Using: /usr/lib/readers/ifd-ccid.bundle/Contents/Info.plist 00000622 ccid_usb.c:246:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (lud...@fr...) 00000030 ccid_usb.c:247:OpenUSBByName() ifdProductString: Generic CCID driver 00000027 ccid_usb.c:248: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. 00002035 ccid_usb.c:521:OpenUSBByName() Found Vendor/Product: 096E/0503 (Feitian SCR301) 00000047 ccid_usb.c:523:OpenUSBByName() Using USB bus/device: 2/4 00004051 ccid_usb.c:1021:get_data_rates() declared: 10753 bps 00000077 ccid_usb.c:1021:get_data_rates() declared: 14337 bps 00000019 ccid_usb.c:1021:get_data_rates() declared: 15625 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 17204 bps 00000047 ccid_usb.c:1021:get_data_rates() declared: 20833 bps 00000018 ccid_usb.c:1021:get_data_rates() declared: 21505 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 23438 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 25806 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 28674 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 31250 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 32258 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 34409 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 39063 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 41667 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 43011 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 46875 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 52083 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 53763 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 57348 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 62500 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 64516 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 68817 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 71685 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 78125 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 83333 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 86022 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 93750 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 104167 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 107527 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 114695 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 125000 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 129032 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 143369 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 156250 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 166667 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 172043 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 215054 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 229391 bps 00000016 ccid_usb.c:1021:get_data_rates() declared: 250000 bps 00000017 ccid_usb.c:1021:get_data_rates() declared: 344086 bps 00019218 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFB3, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000084 readerfactory.c:332:RFAddReader() Using the reader polling thread 00001968 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAE, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000044 ifdhandler.c:446:IFDHGetCapabilities() Reader supports 1 slot(s) 00003894 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00090695 eventhandler.c:256:EHStatusHandlerThread() powerState: POWER_STATE_POWERED 00000131 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 19 CF 05005318 ifdhandler.c:1122:IFDHPowerICC() action: PowerDown, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00003996 eventhandler.c:446:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED 07758378 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival 00000062 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 13 00000013 pcscdaemon.c:93:SVCServiceRunLoop() A new context thread creation is requested: 13 00000278 winscard_svc.c:299:ContextThread() Thread is started: dwClientID=13, threadContext @0x8744580 00000340 winscard_svc.c:317:ContextThread() Received command: CMD_VERSION from client 13 00000190 winscard_svc.c:329:ContextThread() Client is protocol version 4:2 00000050 winscard_svc.c:349:ContextThread() CMD_VERSION rv=0x0 for client 13 00000218 winscard_svc.c:317:ContextThread() Received command: ESTABLISH_CONTEXT from client 13 00000207 winscard.c:193:SCardEstablishContext() Establishing Context: 0x6AC591CA 00000063 winscard_svc.c:410:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 13 00000217 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000247 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000220 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000210 winscard_svc.c:317:ContextThread() Received command: CONNECT from client 13 00000213 winscard.c:235:SCardConnect() Attempting Connect to Feitian SCR301 00 00 using protocol: 3 00000053 readerfactory.c:739:RFReaderInfo() RefReader() count was: 1 00003241 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00091067 winscard.c:310:SCardConnect() power up complete. 00000127 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 19 CF 00000044 winscard.c:330:SCardConnect() powerState: POWER_STATE_INUSE 00000041 prothandler.c:87:PHSetProtocol() Attempting PTS to T=1 00000041 ifdhandler.c:668:IFDHSetProtocolParameters() protocol T=1, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00033963 winscard.c:409:SCardConnect() Active Protocol: T=1 00000114 winscard.c:429:SCardConnect() hCard Identity: 528132b8 00000052 winscard.c:490:SCardConnect() UnrefReader() count was: 2 00000046 winscard_svc.c:451:ContextThread() CONNECT rv=0x0 for client 13 00000198 winscard_svc.c:317:ContextThread() Received command: CONTROL from client 13 00000072 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000049 ifdhandler.c:1359:IFDHControl() ControlCode: 0x42000D48, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000044 Control TxBuffer: 00000062 Control RxBuffer: 0A 04 42 33 00 0A 12 04 42 33 00 12 00000071 winscard.c:1344:SCardControl() UnrefReader() count was: 2 00000054 winscard_svc.c:650:ContextThread() CONTROL rv=0x0 for client 13 00000131 winscard_svc.c:317:ContextThread() Received command: CONTROL from client 13 00000066 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000057 ifdhandler.c:1359:IFDHControl() ControlCode: 0x4233000A, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000051 Control TxBuffer: 00000053 Control RxBuffer: 00 00 07 00 00000051 winscard.c:1344:SCardControl() UnrefReader() count was: 2 00000052 winscard_svc.c:650:ContextThread() CONTROL rv=0x0 for client 13 00000134 winscard_svc.c:317:ContextThread() Received command: DISCONNECT from client 13 00000069 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000056 winscard.c:851:SCardDisconnect() Active Contexts: 1 00000052 winscard.c:852:SCardDisconnect() dwDisposition: 0 00000058 winscard.c:1017:SCardDisconnect() powerState: POWER_STATE_GRACE_PERIOD 00000066 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFB2, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000056 winscard.c:1031:SCardDisconnect() Stopping polling thread 00000053 ifdhandler.c:323:IFDHStopPolling() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000954 winscard.c:1044:SCardDisconnect() UnrefReader() count was: 2 00000074 winscard_svc.c:488:ContextThread() DISCONNECT rv=0x0 for client 13 00000243 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000134 winscard_svc.c:317:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 13 00000074 winscard_svc.c:317:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 13 00000082 winscard_svc.c:391:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 13 00000096 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000100 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000115 winscard_svc.c:317:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 13 00000132 winscard_svc.c:317:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 13 00000065 winscard_svc.c:391:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 13 00000090 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000117 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000157 winscard_svc.c:317:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 13 00000072 winscard_svc.c:317:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 13 00000204 winscard_svc.c:391:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 13 00000218 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000207 winscard_svc.c:317:ContextThread() Received command: CONNECT from client 13 00000071 winscard.c:235:SCardConnect() Attempting Connect to Feitian SCR301 00 00 using protocol: 3 00000162 readerfactory.c:739:RFReaderInfo() RefReader() count was: 1 00000055 winscard.c:330:SCardConnect() powerState: POWER_STATE_INUSE 00000178 winscard.c:409:SCardConnect() Active Protocol: T=1 00000056 winscard.c:429:SCardConnect() hCard Identity: 780b5cda 00000161 winscard.c:490:SCardConnect() UnrefReader() count was: 2 00000060 winscard_svc.c:451:ContextThread() CONNECT rv=0x0 for client 13 00000842 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000076 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000057 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000052 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000052 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000171 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000071 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000055 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000058 APDU: 00 A4 00 00 02 3F 00 E0 00000053 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00010879 SW: 6F 17 84 10 00 C0 6F B7 D8 A2 A6 09 B8 92 5B B7 D8 60 A6 09 A5 03 88 01 00 90 00 00000098 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000056 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000203 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000077 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000056 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000056 APDU: 00 A4 00 00 02 2F 00 E0 00000053 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00009777 SW: 6F 07 82 01 00 80 02 00 80 90 00 00000074 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000057 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000181 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000074 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000057 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000055 APDU: 00 B0 00 00 80 00000051 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00030152 SW: 61 25 4F 0C A0 00 00 00 63 50 4B 43 53 2D 31 35 50 0F 43 72 79 70 74 6C 69 62 44 65 76 44 65 73 74 51 04 3F 00 50 15 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 90 00 00000109 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000043 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000299 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000068 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000054 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000045 APDU: 00 A4 00 00 02 3F 00 E0 00000043 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00011100 SW: 6F 17 84 10 00 C0 6F B7 D8 A2 A6 09 B8 92 5B B7 D8 60 A6 09 A5 03 88 01 00 90 00 00000049 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000020 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000398 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000034 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000021 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000019 APDU: 00 A4 00 00 02 50 15 E0 00000019 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00011505 SW: 6F 12 84 10 A0 00 00 00 63 50 4B 43 53 2D 31 35 D8 60 A6 09 90 00 00000060 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000035 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000199 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000050 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000033 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000050 APDU: 00 A4 00 00 02 50 31 E0 00000032 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00006590 SW: 6F 07 82 01 00 80 02 01 00 90 00 00000062 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000042 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000148 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000059 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000061 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000042 APDU: 00 B0 00 00 E0 00000038 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00050594 SW: A8 0A 30 08 04 06 3F 00 50 15 44 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 90 00 00000136 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000024 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000192 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000070 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000046 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000042 APDU: 00 B0 00 E0 20 00000043 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00010411 SW: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 90 00 00000059 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000042 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000240 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000065 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000044 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000043 APDU: 00 A4 00 00 02 50 32 E0 00000040 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00006471 SW: 6F 07 82 01 00 80 02 00 80 90 00 00000069 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000043 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000163 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000077 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000047 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000041 APDU: 00 B0 00 00 80 00000039 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00030672 SW: 30 3E 02 01 00 04 08 16 75 04 55 09 13 02 12 0C 09 45 6E 74 65 72 53 61 66 65 80 0F 43 72 79 70 74 6C 69 62 44 65 76 44 65 73 74 03 02 04 10 85 0F 32 30 31 33 30 33 32 38 31 35 30 30 31 31 5A 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 90 00 00000201 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000051 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000279 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000064 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000046 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000039 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000040 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00006712 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000051 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000021 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000018 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000018 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000613 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000053 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000020 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000021 APDU: 00 A4 00 00 02 44 01 E0 00000019 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00007447 SW: 6F 07 82 01 00 80 02 01 00 90 00 00000052 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000025 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000111 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000032 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000024 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000022 APDU: 00 B0 00 00 E0 00000023 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00050025 SW: 30 37 30 0E 0C 08 55 73 65 72 20 50 49 4E 03 02 06 C0 30 03 04 01 FF A1 20 30 1E 03 02 02 4C 0A 01 01 02 01 04 02 01 10 02 01 10 80 01 01 04 01 00 30 06 04 04 3F 00 50 15 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 90 00 00000130 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000063 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000191 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000064 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000043 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000054 APDU: 00 B0 00 E0 20 00000040 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00010263 SW: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 90 00 00000080 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000044 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000287 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000064 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000044 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000038 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000040 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00004680 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000181 winscard_svc.c:317:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 13 00000067 winscard_svc.c:317:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 13 00000092 winscard_svc.c:391:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 13 00000089 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000117 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000121 winscard_svc.c:317:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 13 00000072 winscard_svc.c:317:ContextThread() Received command: CMD_STOP_WAITING_READER_STATE_CHANGE from client 13 00000066 winscard_svc.c:391:ContextThread() CMD_STOP_WAITING_READER_STATE_CHANGE rv=0x0 for client 13 00000093 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13 00000338 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000860 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000061 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000052 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000052 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000146 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000071 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000054 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000065 APDU: 00 20 00 01 10 74 65 73 74 00 00 00 00 00 00 00 00 00 00 00 00 00000053 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00008059 SW: 90 00 00000096 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000046 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000266 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000063 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000045 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000038 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000040 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00004613 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000071 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000064 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000043 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000042 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000117 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000060 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000042 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000041 APDU: 00 84 00 00 08 00000040 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00009249 SW: B0 CF 3A 9A 2A 97 48 C4 90 00 00000068 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000056 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000129 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000179 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000056 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000052 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000052 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00001863 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000071 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000056 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000052 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000056 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000106 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000068 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000054 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000053 APDU: 00 84 00 00 08 00000051 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00008978 SW: 6A 1C B2 92 07 18 20 0C 90 00 00000067 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000053 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000127 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000064 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000552 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000054 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000052 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00007656 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000078 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000057 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000052 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000052 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000106 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000067 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000053 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000053 APDU: 00 84 00 00 08 00000051 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00009831 SW: 05 DA 2C 7A 07 A7 C6 5D 90 00 00000099 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000044 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000143 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000080 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000045 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000040 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000039 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00002143 winscard_svc.c:317:ContextThread() Received command: BEGIN_TRANSACTION from client 13 00000062 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000043 winscard.c:1083:SCardBeginTransaction() Status: 0x00000000 00000039 winscard.c:1086:SCardBeginTransaction() UnrefReader() count was: 2 00000040 winscard_svc.c:503:ContextThread() BEGIN_TRANSACTION rv=0x0 for client 13 00000103 winscard_svc.c:317:ContextThread() Received command: TRANSMIT from client 13 00000070 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000056 winscard.c:1581:SCardTransmit() Send Protocol: T=1 00000053 APDU: 00 84 00 00 08 00000053 ifdhandler.c:1265:IFDHTransmitToICC() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00009837 SW: 84 9B 4F 11 33 51 EA EE 90 00 00000081 winscard.c:1626:SCardTransmit() UnrefReader() count was: 2 00000043 winscard_svc.c:606:ContextThread() TRANSMIT rv=0x0 for client 13 00000129 winscard_svc.c:317:ContextThread() Received command: END_TRANSACTION from client 13 00000091 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000047 winscard.c:1219:SCardEndTransaction() Status: 0x00000000 00000039 winscard.c:1222:SCardEndTransaction() UnrefReader() count was: 2 00000039 winscard_svc.c:519:ContextThread() END_TRANSACTION rv=0x0 for client 13 00008351 winscard_svc.c:317:ContextThread() Received command: DISCONNECT from client 13 00000073 readerfactory.c:766:RFReaderInfoById() RefReader() count was: 1 00000045 winscard.c:851:SCardDisconnect() Active Contexts: 1 00000039 winscard.c:852:SCardDisconnect() dwDisposition: 1 00001741 ifdhandler.c:1122:IFDHPowerICC() action: Reset, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00093169 winscard.c:918:SCardDisconnect() Reset complete. 00000145 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 19 CF 00000051 winscard.c:1017:SCardDisconnect() powerState: POWER_STATE_GRACE_PERIOD 00001690 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFB2, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000057 winscard.c:1031:SCardDisconnect() Stopping polling thread 00000042 ifdhandler.c:323:IFDHStopPolling() usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00000889 winscard.c:1044:SCardDisconnect() UnrefReader() count was: 2 00000058 winscard_svc.c:488:ContextThread() DISCONNECT rv=0x0 for client 13 00000215 winscard_svc.c:317:ContextThread() Received command: RELEASE_CONTEXT from client 13 00000058 winscard.c:204:SCardReleaseContext() Releasing Context: 0x6AC591CA 00000046 winscard_svc.c:425:ContextThread() RELEASE_CONTEXT rv=0x0 for client 13 00001048 winscard_svc.c:309:ContextThread() Client die: 13 00000073 winscard_svc.c:928:MSGCleanupClient() Thread is stopping: dwClientID=13, threadContext @0x8744580 00000044 winscard_svc.c:934:MSGCleanupClient() Freeing SCONTEXT @0x8744580 00398593 eventhandler.c:458:EHStatusHandlerThread() powerState: POWER_STATE_POWERED 05006947 ifdhandler.c:1122:IFDHPowerICC() action: PowerDown, usb:096e/0503:libudev:0:/dev/bus/usb/002/004 (lun: 0) 00004008 eventhandler.c:446:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED |
