Dear Ludovic, I just saw the link to your page on how to properly submit a log file". :) Here it comes...
-Smart card reader driver name and version: CCID version 1.4.6 -PCSC-Lite version: 1.8.6 -Smart card reader name: Feitian R-301 - "pcscd --version": pcsc-lite version 1.8.6. Copyright (C) 1999-2002 by David Corcoran <[email protected]>. Copyright (C) 2001-2011 by Ludovic Rousseau <[email protected]>. Copyright (C) 2003-2004 by Damien Sauveron <[email protected]>. Report bugs to <[email protected]>. Enabled features: Linux i686-pc-linux-gnu serial usb libudev usbdropdir=/usr/local/lib/pcsc/drivers ipcdir=/var/run/pcscd configdir=/usr/local/etc/reader.conf.d - Operating system name and version: Xubuntu Linux 12.04 -Smart card middleware name and version: OpenSC 0.12.2 - Reader manufacturer, reader model name and smart card: As above, Feitian R-301 with Feitian ePass PKI token - PCSC_SCAN If I compile and start "pcsc_scan" properly it usually fails with the following message: --- cut here--- PC/SC device scanner V 1.4.20 (c) 2001-2011, Ludovic Rousseau <[email protected]> Compiled with PC/SC lite version: 1.8.6 Using reader plug'n play mechanism Scanning present readers... 0: Feitian SCR301 00 00 Fri Sep 7 16:32:12 2012 Reader 0: Feitian SCR301 00 00 Card state: Card inserted, ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 0F D9 Can't locate Chipcard/PCSC/Card.pm in @INC (@INC contains: /etc/perl /usr/local/lib/perl/5.14.2 /usr/local/share/perl/5.14.2 /usr/lib/perl5 /usr/share/perl5 /usr/lib/perl/5.14 /usr/share/perl/5.14 /usr/local/lib/site_perl .) at /usr/local/bin/ATR_analysis line 47. BEGIN failed--compilation aborted at /usr/local/bin/ATR_analysis line 47. ATR_analysis '3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 0F D9': No such file or directory --- cut here --- It is not stable, however. Sometimes it simply crashes without further notice. - "sudo LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu | tee pcscd186log.txt" Please find the log file attached. As before, it reflects the execution of the commands "opensc-tool -a", "pkcs11-tool [mod] -O" and "pkcs15-tool -C". Keep in mind that everything works well if I use "pcsclite" version 1.8.3. Hope that helps a bit. Have a nice weekend, Ingo On Thu, Sep 6, 2012 at 12:41 PM, Ingo Naumann <[email protected]> wrote: >> You did not sent the log files to the MUSLE list. >> You also failed to answer my questions in the previous email. > > I did actually send the log files, in my previous mail. I just didn't > want to spam the list participants by re-sending two relatively long > files. > > As for "pcsc_scan", it either crashes (for all versions of PC/SC) and > I still have to find out why or it gives the "Service not available" > message .... > > Sorry for that, > Ingo
00000000 debuglog.c:269:DebugLogSetLevel() debug level=debug 00000137 debuglog.c:298:DebugLogSetCategory() Debug options: APDU 00000526 configfile.l:298:DBGetReaderList() Parsing conf file: /usr/local/etc/reader.conf.d 00000101 pcscdaemon.c:525:main() pcsc-lite 1.8.6 daemon ready. 00001126 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/002/001 00000156 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/002/001 00000133 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x096E, PID: 0x0503, path: /dev/bus/usb/002/002 00000076 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x096E, PID: 0x0503, path: /dev/bus/usb/002/002 00000056 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Feitian SCR301 00000118 readerfactory.c:978:RFInitializeReader() Attempting startup of Feitian SCR301 00 00 using /usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so 00045992 readerfactory.c:868:RFBindFunctions() Loading IFD Handler 3.0 00000327 ifdhandler.c:1768:init_driver() Driver version: 1.4.6 00000321 ifdhandler.c:1785:init_driver() LogLevel: 0x0003 00000019 ifdhandler.c:1796:init_driver() DriverOptions: 0x0000 00000062 ifdhandler.c:1809:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F 00000013 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 0, device: usb:096e/0503:libudev:0:/dev/bus/usb/002/002 00000015 ccid_usb.c:180:OpenUSBByName() Reader index: 0, Device: usb:096e/0503:libudev:0:/dev/bus/usb/002/002 00000023 ccid_usb.c:212:OpenUSBByName() interface_number: 0 00000246 ccid_usb.c:245:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau ([email protected]) 00000091 ccid_usb.c:246:OpenUSBByName() ifdProductString: Generic CCID driver 00000057 ccid_usb.c:247: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. 00000508 ccid_usb.c:365:OpenUSBByName() Checking device: 2/2 00000067 ccid_usb.c:420:OpenUSBByName() Trying to open USB bus/device: 2/2 00098281 ccid_usb.c:509:OpenUSBByName() Found Vendor/Product: 096E/0503 (Feitian SCR301) 00000042 ccid_usb.c:511:OpenUSBByName() Using USB bus/device: 2/2 00000012 ccid_usb.c:1029:ControlUSB() request: 0x03 00003241 receive: 01 2A 00 00 01 38 00 00 09 3D 00 00 34 43 00 00 61 51 00 00 01 54 00 00 8E 5B 00 00 CE 64 00 00 02 70 00 00 12 7A 00 00 02 7E 00 00 69 86 00 00 97 98 00 00 C3 A2 00 00 03 A8 00 00 1B B7 00 00 73 CB 00 00 03 D2 00 00 04 E0 00 00 24 F4 00 00 04 FC 00 00 D1 0C 01 00 05 18 01 00 2D 31 01 00 85 45 01 00 06 50 01 00 36 6E 01 00 E7 96 01 00 07 A4 01 00 07 C0 01 00 48 E8 01 00 08 F8 01 00 09 30 02 00 5A 62 02 00 0B 8B 02 00 0B A0 02 00 0E 48 03 00 0F 80 03 00 90 D0 03 00 16 40 05 00 00000029 ccid_usb.c:1009:get_data_rates() declared: 10753 bps 00000011 ccid_usb.c:1009:get_data_rates() declared: 14337 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 15625 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 17204 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 20833 bps 00000010 ccid_usb.c:1009:get_data_rates() declared: 21505 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 23438 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 25806 bps 00000008 ccid_usb.c:1009:get_data_rates() declared: 28674 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 31250 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 32258 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 34409 bps 00000008 ccid_usb.c:1009:get_data_rates() declared: 39063 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 41667 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 43011 bps 00000008 ccid_usb.c:1009:get_data_rates() declared: 46875 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 52083 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 53763 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 57348 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 62500 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 64516 bps 00000018 ccid_usb.c:1009:get_data_rates() declared: 68817 bps 00000010 ccid_usb.c:1009:get_data_rates() declared: 71685 bps 00000008 ccid_usb.c:1009:get_data_rates() declared: 78125 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 83333 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 86022 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 93750 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 104167 bps 00000008 ccid_usb.c:1009:get_data_rates() declared: 107527 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 114695 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 125000 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 129032 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 143369 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 156250 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 166667 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 172043 bps 00000008 ccid_usb.c:1009:get_data_rates() declared: 215054 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 229391 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 250000 bps 00000009 ccid_usb.c:1009:get_data_rates() declared: 344086 bps 00004790 ccid_usb.c:1078:InterruptRead() before (0) 00019492 ccid_usb.c:1120:InterruptRead() after (0) (0) 00000049 NotifySlotChange: 50 03 00000016 -> 000000 65 00 00 00 00 00 00 00 00 00 00002670 <- 000000 81 00 00 00 00 00 00 00 00 00 00000055 ifdhandler.c:353:IFDHGetCapabilities() tag: 0xFB3, usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000012 readerfactory.c:332:RFAddReader() Using the reader polling thread 00000010 ifdhandler.c:1631:IFDHICCPresence() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000011 -> 000000 65 00 00 00 00 00 01 00 00 00 00002489 <- 000000 81 00 00 00 00 00 01 00 00 00 00000042 ifdhandler.c:1749:IFDHICCPresence() Card present 00000062 ifdhandler.c:353:IFDHGetCapabilities() tag: 0xFAE, usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000014 ifdhandler.c:441:IFDHGetCapabilities() Reader supports 1 slot(s) 00000163 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000086 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001 00000088 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x203A, PID: 0xFFF9, path: /dev/bus/usb/001/002 00000083 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x203A, PID: 0xFFF9, path: /dev/bus/usb/001/002 00000031 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00000106 ifdhandler.c:1631:IFDHICCPresence() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000026 -> 000000 65 00 00 00 00 00 02 00 00 00 00002081 <- 000000 81 00 00 00 00 00 02 00 00 00 00000029 ifdhandler.c:1749:IFDHICCPresence() Card present 00000011 ifdhandler.c:1631:IFDHICCPresence() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000011 -> 000000 65 00 00 00 00 00 03 00 00 00 00002679 <- 000000 81 00 00 00 00 00 03 00 00 00 00000076 ifdhandler.c:1749:IFDHICCPresence() Card present 00000058 ifdhandler.c:1114:IFDHPowerICC() action: PowerUp, usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000054 -> 000000 62 00 00 00 00 00 04 00 00 00 00004985 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00011248 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010162 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00011299 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010893 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00011029 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010528 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010728 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00011040 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010418 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010157 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010911 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00011062 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010174 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00010790 readerfactory.c:1306:RFWaitForReaderInit() Waiting init for reader: Feitian SCR301 00 00 00009439 <- 000000 80 17 00 00 00 00 04 00 00 00 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 0F D9 00000086 eventhandler.c:256:EHStatusHandlerThread() powerState: POWER_STATE_POWERED 00000027 Card ATR: 3B 9F 95 81 31 FE 9F 00 65 46 53 05 30 06 71 DF 00 00 00 81 61 0F D9 00000020 ifdhandler.c:1631:IFDHICCPresence() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000021 -> 000000 65 00 00 00 00 00 05 00 00 00 00002795 <- 000000 81 00 00 00 00 00 05 00 00 00 00000068 ifdhandler.c:1749:IFDHICCPresence() Card present 00000022 ifdhandler.c:282:IFDHPolling() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 5000 ms 00000019 ccid_usb.c:1078:InterruptRead() before (0) 05004590 ccid_usb.c:1120:InterruptRead() after (0) (2) 00000109 ifdhandler.c:1631:IFDHICCPresence() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000037 -> 000000 65 00 00 00 00 00 06 00 00 00 00011725 <- 000000 81 00 00 00 00 00 06 00 00 00 00000140 ifdhandler.c:1749:IFDHICCPresence() Card present 00000025 ifdhandler.c:1114:IFDHPowerICC() action: PowerDown, usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000031 -> 000000 63 00 00 00 00 00 07 00 00 00 00004490 <- 000000 81 00 00 00 00 00 07 01 00 00 00000086 eventhandler.c:446:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED 00000024 ifdhandler.c:1631:IFDHICCPresence() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 00000022 -> 000000 65 00 00 00 00 00 08 00 00 00 00002569 <- 000000 81 00 00 00 00 00 08 01 00 00 00000039 ifdhandler.c:1749:IFDHICCPresence() Card present 00000017 ifdhandler.c:282:IFDHPolling() usb:096e/0503:libudev:0:/dev/bus/usb/002/002 (lun: 0) 600000 ms 00000015 ccid_usb.c:1078:InterruptRead() before (0) 45763530 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival 00000050 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 9 00000013 pcscdaemon.c:93:SVCServiceRunLoop() A new context thread creation is requested: 9 00000092 winscard_svc.c:299:ContextThread() Thread is started: dwClientID=9, threadContext @0x983e5c8 00000097 winscard_svc.c:317:ContextThread() Received command: CMD_VERSION from client 9 00000073 winscard_svc.c:329:ContextThread() Client is protocol version 4:2 00000017 winscard_svc.c:349:ContextThread() CMD_VERSION rv=0x0 for client 9 00000057 winscard_svc.c:317:ContextThread() Received command: ESTABLISH_CONTEXT from client 9 00000059 winscard.c:193:SCardEstablishContext() Establishing Context: 0x3F01E0F4 00000014 winscard_svc.c:410:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 9 00000051 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000050 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000064 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000052 winscard_svc.c:317:ContextThread() Received command: CONNECT from client 9 00000014 winscard_svc.c:721:ContextThread() Wrong length: 9 00000016 winscard.c:204:SCardReleaseContext() Releasing Context: 0x3F01E0F4 00000012 winscard_svc.c:926:MSGCleanupClient() Thread is stopping: dwClientID=9, threadContext @0x983e5c8 00000011 winscard_svc.c:932:MSGCleanupClient() Freeing SCONTEXT @0x983e5c8 06755772 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival 00000020 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 9 00000005 pcscdaemon.c:93:SVCServiceRunLoop() A new context thread creation is requested: 9 00000221 winscard_svc.c:299:ContextThread() Thread is started: dwClientID=9, threadContext @0x9853978 00000130 winscard_svc.c:317:ContextThread() Received command: CMD_VERSION from client 9 00000067 winscard_svc.c:329:ContextThread() Client is protocol version 4:2 00000020 winscard_svc.c:349:ContextThread() CMD_VERSION rv=0x0 for client 9 00000135 winscard_svc.c:317:ContextThread() Received command: ESTABLISH_CONTEXT from client 9 00000071 winscard.c:193:SCardEstablishContext() Establishing Context: 0x263152ED 00000020 winscard_svc.c:410:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 9 00000073 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000072 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000082 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000076 winscard_svc.c:317:ContextThread() Received command: CONNECT from client 9 00000019 winscard_svc.c:721:ContextThread() Wrong length: 9 00000022 winscard.c:204:SCardReleaseContext() Releasing Context: 0x263152ED 00000018 winscard_svc.c:926:MSGCleanupClient() Thread is stopping: dwClientID=9, threadContext @0x9853978 00000014 winscard_svc.c:932:MSGCleanupClient() Freeing SCONTEXT @0x9853978 20302603 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival 00000022 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 9 00000006 pcscdaemon.c:93:SVCServiceRunLoop() A new context thread creation is requested: 9 00000096 winscard_svc.c:299:ContextThread() Thread is started: dwClientID=9, threadContext @0x98536d0 00005760 winscard_svc.c:317:ContextThread() Received command: CMD_VERSION from client 9 00000074 winscard_svc.c:329:ContextThread() Client is protocol version 4:2 00000019 winscard_svc.c:349:ContextThread() CMD_VERSION rv=0x0 for client 9 00000046 winscard_svc.c:317:ContextThread() Received command: ESTABLISH_CONTEXT from client 9 00000030 winscard.c:193:SCardEstablishContext() Establishing Context: 0x9EE1A08 00000016 winscard_svc.c:410:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 9 00000041 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000035 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000103 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 9 00000114 winscard_svc.c:317:ContextThread() Received command: CONNECT from client 9 00000019 winscard_svc.c:721:ContextThread() Wrong length: 9 00000023 winscard.c:204:SCardReleaseContext() Releasing Context: 0x9EE1A08 00000017 winscard_svc.c:926:MSGCleanupClient() Thread is stopping: dwClientID=9, threadContext @0x98536d0 00000014 winscard_svc.c:932:MSGCleanupClient() Freeing SCONTEXT @0x98536d0
_______________________________________________ Muscle mailing list [email protected] http://lists.drizzle.com/mailman/listinfo/muscle
