Mac OS X Lion and tokend

This article is not very technical. This is part of my view of the tokend situation.

It follows the two previous articles about Lion: Mac OS X Lion and smart cards status and Mac OS X Lion and OpenSSL.

Tokend

A tokend is a piece of software used to bridge a cryptographic device (like a smart card) and the CDSA (Common Data Security Architecture) architecture. CDSA and tokend are now deprecated by Apple: [Fed-Talk] [Announcement] OS X Lion - Smart Card Services (emphasis is mine):

" The foundational components for Smart Card Services in OS X have been based on an architecture (CDSA) that has been deprecated in the released version of OS X Lion.

This indicates CDSA's use and support has stopped and will be removed completely in a future release of OS X.

Any solution for OS X still leveraging the deprecated CDSA can continue to function for now, but the CDSA infrastructure would no longer receive enhancements or bug fixes.

CDSA will no longer ship in future releases of OS X. "

This email is written by Shawn Geddis, Security Consulting Engineer. Shawn works at Apple.

Tokend from Apple

So in Mac OS X 10.7 Lion no tokend are provided any more. The directory /System/Library/Security/tokend/ is now empty in a Lion fresh installation.

Tokend from other sources

In the same email Shawn gives some options to replace the tokend no more provided by Apple:

• Open Source Options (from "Apple")
  
  The source code of the tokend provided by Apple (in Tiger, Leopard and Snow Leopard) were already available as Free Software from the Smart Card Services project. It is now the official source to get them.
• Open Source Options (from the rest of the world)
  
  The OpenSC project provides a tokend to be used with OpenSC. The tokend in included in the installer for Mac OS X.
• Commercial Options
  
  Commercial tokend from third parties should still be available and usable on Lion.

Since installing a tokend from source code is not a trivial task "Apple" provides an installer. It is not really Apple that provides the installer but the Smart Card services project. So bugs should be reported to the project bug tracker.

Note that these tokend are (still) signed by Apple:

$ codesign --display --verbose=4 /System/Library/Security/tokend/CACNG.tokend
Executable=/System/Library/Security/tokend/CACNG.tokend/Contents/MacOS/CACNG
Identifier=com.apple.tokend.cacng
Format=bundle with Mach-O universal (i386 ppc7400 x86_64)
CodeDirectory v=20100 size=1351 flags=0x0(none) hashes=61+3 location=embedded
Hash type=sha1 size=20
CDHash=b41a98c192eb5196353926288ff208b5d2415a3e
Signature size=4064
Authority=Software Signing
Authority=Apple Code Signing Certification Authority
Authority=Apple Root CA
Info.plist entries=9
Sealed Resources rules=10 files=6
Internal requirements count=1 size=148

Smart Card Services project

This project has been started by Shawn Geddis in January 2009. The members of the project are listed in this page.

I was invited to join the team to work on the pcsc-lite and CCID parts. These parts are still provided by Apple in Lion.

I am not an Apple employee so know no Apple secret plans. For example I do not know why Lion provides the CCID driver version 1.3.11 and not a more recent version (the latest is 1.4.4). See Mac OS X Lion and smart cards status for more information.

You can see from the project bug tracker that a lot of bugs are open and some are quiet old now (like this one requesting help about a tokend for Mac OS X 10.4 Tiger on a G4 processor). It is hard to get people working for free on a project. So if Apple does not invest some manpower into fixing bugs and answering bug reports the bugs will not be fixed.

After tokend

I guess Apple is working on something to replace tokend when CDSA will be removed. But I have no idea what it will be.

Conclusion

My interpretation is that Apple is doing with tokend what they also do with Java and Flash: they let other people/companies provide and maintain the software.

[update] Add a "Open Source Options (from the rest of the world)"

Mac OS X Lion and OpenSSL

In Mac OS X 10.7 Lion Apple deprecates the use of OpenSSL. You can see deprecation messages when compiling.

OpenSSL is deprecated in Lion

For example with the following deprecated.c source code:

#include <openssl/crypto.h>

int main(void)
{
    OPENSSL_init();
    return 0;
}

We get a compilation warning:
$ gcc deprecated.c -lcrypto
deprecated.c: In function ‘main’:
deprecated.c:5: warning: ‘OPENSSL_init’ is deprecated (declared at /usr/include/openssl/crypto.h:600)

Line 600 of /usr/include/openssl/crypto.h is:

void OPENSSL_init(void) DEPRECATED_IN_MAC_OS_X_VERSION_10_7_AND_LATER;

and is replaced by Common Cypto

Common Crypto is Apple "own" implementation of low level crypto algorithms. See the CC_crypto(3cc) man page. The manage is also available online at http://developer.apple.com/library/mac/#documentation/Darwin/Reference/ManPages/man3/CC_crypto.3cc.html and says:

CC_crypto(3cc)                      LOCAL                  CC_crypto(3cc)

NAME
     Common Crypto -- libSystem digest library

DESCRIPTION
     The libSystem Common Crypto library implements a wide range of
cryptographic algorithms used in various Internet standards. The services
provided by this library are used by the CDSA implementations of SSL,
TLS and S/MIME.

OVERVIEW
     libSystem contains the Common Crypto collection of algorithms.
Digest and encryption algorithms contained in this library are optimized for
speed.  The algorithms have been collected from various sources and chosen
for their performance characteristics.  Since libSystem is linked into all
executables it is preferable for applications to use these functions rather
than implementing their own versions.

NOTES
     To use the digest functions with existing code which uses the
corresponding openssl functions, #define the symbol
COMMON_DIGEST_FOR_OPENSSL in your client code (BEFORE including
<CommonCrypto/CommonDigest.h> ).

     You can *NOT* mix and match functions operating on a given data type
from the two implementations; i.e., if you do a CC_MD5_Init()
on a CC_MD5_CTX object, do not assume that you can do an openssl-style
MD5_Update() on that same context.

     The interfaces to the encryption and HMAC algorithms have a calling
interface that is different from that provided by OpenSSL.

SEE ALSO
     CC_MD5(3cc), CC_SHA(3cc), CCHmac(3cc), CCCryptor(3cc)

BSD                           April 5, 2007                             BSD

Notes

The man page is quiet old (April 2007) and references CDSA. CDSA has also been deprecated in Lion but we will talk about that later.

Common Crypto should also be available in Leopard (the man page exists for 10.5). So you can update you project to use Common Crypto for Lion and the same source code could be used on Snow Leopard (and maybe even Leopard)

Conclusion

OpenSSL should be removed in a later Mac OS X version.

For projects using OpenSSL on Mac OS X you have two options:

• move from OpenSSL to Common Crypto
• provide your own version of OpenSSL in the installer (or use a static link)

Mac OS X Lion and smart cards status

The new major version of Mac OS X is now available: code name Lion, version 10.7.

Mac OS X Lion

pcsc-lite

The version returned by pcscd has not changed. It is still 1.4.0.

$ /usr/sbin/pcscd -v
PCSC Framework version 1.4.0.
Copyright (C) 1999-2002 by David Corcoran <corcoran@linuxnet.com>.
Copyright (C) 2001-2005 by Ludovic Rousseau <ludovic.rousseau@free.fr>.
Copyright (C) 2003-2004 by Damien Sauveron <sauveron@labri.fr>.
Portions Copyright (C) 2000-2007 by Apple Inc.
Report bugs to <sclinux@linuxnet.com>.

But the version from the header file indicates Apple now provides a version from the http://smartcardservices.macosforge.org/ project.

$ grep '$Id' /System/Library/Frameworks/PCSC.framework/Headers/pcsclite.h
* $Id: pcsclite.h 123 2010-03-27 10:50:42Z ludovic.rousseau@gmail.com $

The version from the SmartCard Services macosforge project has mainly be contributed by myself.

The subversion revision 123 is not the latest one. It is dated 03/27/2010 03:50:42 (17 months ago). But no bugs has been fixed since this version (on macosforge). The current SVN version (on macosforge) is 139.

Bugs fixed

I extracted the major changes from the subversion history. The release number points to the change in the repository (if you need more details).

• [r28] /trunk/SmartCardServices/src/PCSC/atrhandler.c: resynch with pcsc-lite. Closes bug rdar://problem/6920676 Smart cards defining support of T=0 and T=15 (but not T=1) in their ATR can't be used since pcscd tells the driver to use T=1 and the card does not support that protocol.
• [r76] /trunk/SmartCardServices/src/PCSC/wintypes.h: remove the deprecated warning on LPTSTR and LPCTSTR since they are the documented types for Windows WinSCard API This will remove compilation warnings on cross OS applications
• [r93] /trunk/SmartCardServices/src/PCSC/readerfactory.c: RFAddReader(): remove an extra call to EHSpawnEventHandler() Fixes rdar://5697379 "pcscd does not correctly support multi-slot smart card readers"
• [r94]
  /trunk/SmartCardServices/src/PCSC/readerfactory.c: RFAwakeAllReaders(): restart all the slots of a reader, not just the first one, when the computer comes back from hibernation
• [r98] /trunk/SmartCardServices/src/PCSC/atrhandler.c:
  TRDecodeAtr(): check for TA2 (specific mode) even if TD2 is not present
  "3F 80 10 01" was not parsed correctly for example and T=0 was used
  instead of T=1 (specific mode)
  Same patch as revision 4615 in upstream pcsc-lite
  http://svn.debian.org/viewsvn/pcsclite?view=rev&revision=4615

The bugs were either Mac OS X specific or already fixed in pcsc-lite "upstream".

CCID driver

The CCID driver also has been updated. Snow Leopard provided the version 1.3.8 of my CCID driver. Lion now provides version 1.3.11. See the upstream README file for changes.
Version 1.3.11 was released on 28 July 2009 (2 years ago) and is not the latest version available (1.4.4 as of today).

Issues and limitations

i386 driver

The driver is (still) a i386 binary only. Even if Lion does not support 32-bits CPU any more the CCID driver is not available as a 64-bits binary.

$ file /usr/libexec/SmartCardServices/drivers/ifd-ccid.bundle/Contents/MacOS/libccid.dylib.1.3.11 
/usr/libexec/SmartCardServices/drivers/ifd-ccid.bundle/Contents/MacOS/libccid.dylib.1.3.11: Mach-O dynamically linked shared library i386

The side effect is that pcscd is started by default in 64-bits mode and will then need to restart in 32-bits mode when a CCID reader is connected.

/SourceCache/SmartCardServices/SmartCardServices-55000/src/PCSC/readerfactory.c:1545:ReaderCheckArchitecture() Send respawn signal to pcscd (pid=803)
/SourceCache/SmartCardServices/SmartCardServices-55000/src/PCSC/pcscdaemon.c:678:signal_respawn() Got signal to respawn in 32 bit mode
/SourceCache/SmartCardServices/SmartCardServices-55000/src/PCSC/pcscdaemon.c:294:SVCServiceRunLoop() Preparing to exit...

Maybe Apple will "fix" this in a next 10.7.x update and before the Lion+1 version.

Gemalto Prox DU reader

The Gemalto Prox DU reader is a dual-CCID reader (the reader is composite with two CCID interfaces). Its support has been aded in the CCID driver version 1.3.11. So it is supported by default in Mac OS X Lion.

Apple version of pcsc-lite does not support such composite devices. So the CCID driver contains a trick to simulate a dual-slot reader instead. This is enabled using the ./configure --enable-composite-as-multislot option. Unfortunately Apple has not built the driver with this option (and I can't blame Apple for not using an obscure option). So only the first CCID interface is available.

In Snow Leopard the Gemalto Prox DU reader was not supported so a new driver had to be installed. If configured correctly both CCID interfaces are available.
In Lion the reader is supported by default but only the first CCID interface is available. Installing another driver compiled with the correct option will not solve the problem since the reader is already supported by the default CCID driver. pcscd will use the first driver it find supporting a given smart card reader.
A solution is to remove the Gemalto Prox DU from the list of supported readers from the CCID driver provided by default and install a new driver just for the Gemalto Prox DU driver. But I don't like modifying files provided by others (Apple in this case).

Conclusion

The good news is that Apple has updated the PC/SC layer provided in Mac OS X Lion (versus the one provided in Snow Leopard). The SmartCard Services project was a good idea since Apple reused the code from this project. Apple has then out-sourced the maintenance of pcsc-lite.

EMV-CAP in MISC Magazine n°56

I just read an article about EMV-CAP protocol in the latest number of MISC Magazine (n°56 July-August 2011).

Misc 56 cover

The article is "Banque en ligne : à la découverte d'EMV-CAP" from Jean-Pierre Szikora and Philippe Teuwen. The 13 pages long article (and the complete magazine) is in French. Sorry if you can't read French.

Some page samples:

Article first page

Article 4th page

Article 5th page

The article is also linked to a web site from the authors with more information:

• an Python application to get a lot of information from a EMV-CAP card
• a trace generated by the above application using a real card
• a JavaCard applet to simulate an EMV-CAP applet

If you have a bank card and want to play with it you should have a look at their application.

You should be able to buy this MISC Magazine n°56 in France and other countries until the end of this month. Or buy it online from the editor web site.

You can also (re-)read a previous blog article titles "PSSI: SIM card phone book listing (part 2)" also about an EMV card dump application.

Happy hacking!

Extended APDU cards

In a previous article "Extended APDU status per reader" I wrote about readers status regarding extended APDU. Since I have a rather long list of ATRs (1147 different cards) I tried to find cards supporting extended APDU.

Extended APDU cards

Cards can declare support of extended APDU in the historical bytes part of the ATR. Using my ATR parsing program it is visible as: Extended Lc and Le fields

Cards found

I used my stress test program to scan the complete ATR list. I found 5 cards with expicit extended APDU support:

• ePerso - German ID card
• SignTrust (www.signtrust.de) or Infinion SLE66CX680PE with Starcos 3.2
• Serbian Identity Card
• TCOS 3.0 / NetKey 3.0
• GnuPG card V2

Not all the cards declare extended APDU support in the ATR. So the list above is not exhaustive.

Comments

The 5 cards do all support the T=1 protocol. The German ID card does also support T=0. This is because extended APDU is very hard to use using T=0.

The 5 cards are used for asymmetric cryptography (RSA) with "long" keys (2048 bits or 256 bytes) and so require the use of extended APDU.

pcscd debug output on Mac OS X

In my previous article "pcscd debug output" comments Koen asked about the same information but for Mac OS X.

pcscd start on Mac OS X

On Mac OS X pcscd is not started on system boot (as it used to be the case on GNU/Linux distributions) nor using the autostart feature (as it should be the case for pcsc-lite > 1.6.0). On Mac OS X the pcscd daemon is launched when a USB smart card reader is connected to the system. It is the job of securityd.

securityd

The securityd manpage is short and not very information for our problem. In particular the command line options are not documented in the manpage. But the options are available from the command line itself:

$ securityd -h
securityd: illegal option -- h
Usage: securityd [-dwX]
 [-a authConfigFile]                    Authorization configuration file
 [-c tokencache]                        smartcard token cache directory
 [-e equivDatabase]                     path to code equivalence database
 [-N serviceName]                       MACH service name
 [-s off|on|conservative|aggressive]    smartcard operation level
 [-t maxthreads] [-T threadTimeout]     server thread control

The important option here is -s. If you want to disable the automatic launch of pcscd you need to start securityd with -s off. But you do not start securityd yourself. securityd is started by another daemon: launchd.

launchd

The launchd configuration file for securityd is /System/Library/LaunchDaemons/com.apple.securityd.plist.

You need to edit it and add the two colored lines:

<array>
  <string>/usr/sbin/securityd</string>
  <string>-i</string>
  <string>-s</string>
  <string>off</string>
 </array>

You then need to restart launchd. The easiest way it to reboot the computer.

See also this mail from the apple-cdsa mailing list.

pcscd manual start on Mac OS X

After that change you can start pcscd manually in a terminal. No other pcscd process will be started when a smart card reader is connected.

The same arguments as on GNU/Linux can be used: pcscd --foreground --debug --apdu

Mac OS X pcscd logs

The Apple version of pcscd logs a lot of internal information about the protocol between the daemon and the library (the PCSC framework). If find the pcscd logs nearly useless and very difficult to exploit. But that is better than nothing.

pcscd debug output

pcscd output

pcscd is a daemon (PC/SC Daemon) and as such do not send any message to a terminal since, in general, no terminal is connected to the process standard output.

By default pcscd run as a daemon and any message is sent to the syslog system. These messages are then written in a log file like /var/log/messages.

Silent logs

Since version 1.7.3 some error messages are now debug messages and not logged by default. An error message was generated when the PC/SC call SCardConnect() failed because no card was in the reader. Since a PC/SC failure may be a normal behavior in some cases the file /var/log/messages was growing up to filling the disk. This problem was reported as Red Hat bug 707412 "PCSCD filling /var/log/messages".

Now pcscd will be much more silent by default. And system logs should not fill disks anymore.

Debug logs

Of course it is still possible to activate logs. In general you also run pcscd in the foreground (instead of in the background).

Example:
$ pcscd --foreground --debug

00000000 debuglog.c:269:DebugLogSetLevel() debug level=debug
00000174 configfile.l:245:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d
00000012 configfile.l:287:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin
00000050 pcscdaemon.c:552:main() pcsc-lite 1.7.4 daemon ready.
00001897 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/003/001
00000161 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/004/001
00000125 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/004/001
00000130 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC063, path: /dev/bus/usb/004/002
00000124 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/004/001
00000129 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x413C, PID: 0x2003, path: /dev/bus/usb/004/003
00000161 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/005/001
00000159 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000159 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/006/001
00000157 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/007/001
00000160 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/008/001
00000127 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0001, path: /dev/bus/usb/008/001
00000130 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x04CC, PID: 0x1122, path: /dev/bus/usb/008/002
00000136 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x08E6, PID: 0x8180, path: /dev/bus/usb/008/014
00000132 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x08E6, PID: 0x8180, path: /dev/bus/usb/008/014
00000126 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x04CC, PID: 0x1122, path: /dev/bus/usb/008/002
00000136 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x04B4, PID: 0xAEF3, path: /dev/bus/usb/008/013
00000127 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x04CC, PID: 0x1122, path: /dev/bus/usb/008/002
00000139 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x08E6, PID: 0x3437, path: /dev/bus/usb/008/018
00000028 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x08E6, PID: 0x3437, path: /dev/bus/usb/008/018
00000004 hotplug_libudev.c:309:HPAddDevice() Adding USB device: Gemalto GemPC Twin
00000028 readerfactory.c:934:RFInitializeReader() Attempting startup of Gemalto GemPC Twin 00 00 using /usr/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
00000202 readerfactory.c:824:RFBindFunctions() Loading IFD Handler 3.0
00000026 ifdhandler.c:1750:init_driver() Driver version: 1.4.4
00000490 ifdhandler.c:1767:init_driver() LogLevel: 0x0003
00000004 ifdhandler.c:1778:init_driver() DriverOptions: 0x0000
00000081 ifdhandler.c:79:IFDHCreateChannelByName() lun: 0, device: usb:08e6/3437:libudev:0:/dev/bus/usb/008/018
00000396 ccid_usb.c:245:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau@free.fr)
00000004 ccid_usb.c:246:OpenUSBByName() ifdProductString: Generic CCID driver
00000004 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.
00054079 ccid_usb.c:504:OpenUSBByName() Found Vendor/Product: 08E6/3437 (Gemalto GemPC Twin)
00000004 ccid_usb.c:506:OpenUSBByName() Using USB bus/device: 8/18
00003836 ccid_usb.c:972:get_data_rates() declared: 10753 bps
00000003 ccid_usb.c:972:get_data_rates() declared: 14337 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 15625 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 17204 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 20833 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 21505 bps
00000001 ccid_usb.c:972:get_data_rates() declared: 23438 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 25806 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 28674 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 31250 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 32258 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 34409 bps
00000001 ccid_usb.c:972:get_data_rates() declared: 39063 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 41667 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 43011 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 46875 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 52083 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 53763 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 57348 bps
00000001 ccid_usb.c:972:get_data_rates() declared: 62500 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 64516 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 68817 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 71685 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 78125 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 83333 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 86022 bps
00000001 ccid_usb.c:972:get_data_rates() declared: 93750 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 104167 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 107527 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 114695 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 125000 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 129032 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 143369 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 156250 bps
00000001 ccid_usb.c:972:get_data_rates() declared: 166667 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 172043 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 215054 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 229391 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 250000 bps
00000002 ccid_usb.c:972:get_data_rates() declared: 344086 bps
00009925 ifdhandler.c:401:IFDHGetCapabilities() tag: 0xFB3, usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00000003 readerfactory.c:295:RFAddReader() Using the reader polling thread
00002046 ifdhandler.c:401:IFDHGetCapabilities() tag: 0xFAE, usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00000003 ifdhandler.c:489:IFDHGetCapabilities() Reader supports 1 slot(s)
00000192 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x04CC, PID: 0x1122, path: /dev/bus/usb/008/002
00000183 hotplug_libudev.c:258:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000077 readerfactory.c:1301:RFWaitForReaderInit() Waiting init for reader: Gemalto GemPC Twin 00 00
03633021 ifdhandler.c:1151:IFDHPowerICC() action: PowerUp, usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00055002 commands.c:233:CmdPowerOn Card absent or mute
00000004 ifdhandler.c:1204:IFDHPowerICC() PowerUp failed
00000003 eventhandler.c:378:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
00000003 eventhandler.c:387:EHStatusHandlerThread() Card inserted into Gemalto GemPC Twin 00 00
00000003 eventhandler.c:403:EHStatusHandlerThread() Error powering up card.
01620802 pcscdaemon.c:678:signal_trap() Received signal: 2
00000005 pcscdaemon.c:691:signal_trap() Preparing for suicide
00000017 pcscdaemon.c:678:signal_trap() Received signal: 2
00000004 readerfactory.c:1254:RFCleanupReaders() entering cleaning function
00000003 readerfactory.c:1263:RFCleanupReaders() Stopping reader: Gemalto GemPC Twin 00 00
00000004 eventhandler.c:148:EHDestroyEventHandler() Stomping thread.
00000005 ifdhandler.c:401:IFDHGetCapabilities() tag: 0xFB1, usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00000003 ifdhandler.c:401:IFDHGetCapabilities() tag: 0xFB2, usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00000002 eventhandler.c:173:EHDestroyEventHandler() Request stoping of polling thread
00000003 ifdhandler.c:366:IFDHStopPolling() usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00401452 eventhandler.c:469:EHStatusHandlerThread() Die
00000211 eventhandler.c:188:EHDestroyEventHandler() Thread stomped.
00000004 readerfactory.c:985:RFUnInitializeReader() Attempting shutdown of Gemalto GemPC Twin 00 00.
00000006 ifdhandler.c:293:IFDHCloseChannel() usb:08e6/3437:libudev:0:/dev/bus/usb/008/018 (lun: 0)
00002768 readerfactory.c:861:RFUnloadReader() Unloading reader driver.
00000035 winscard_svc.c:130:ContextsDeinitialize() remaining threads: 0
00000002 pcscdaemon.c:630:at_exit() cleaning /var/run/pcscd

The log contains messages from pcscd itself and also messages from the drivers. It may not be easy to differentiate the two sources of messages. The file name indicates the source.

Colorization

Lines have a different color depending on the importance of the log message. pcscd uses 4 log levels:

• debug (in black)
• info (in blue)
• error (in magenta)
• critical (in red)

In the previous example we have one sample of each level.

These two lines are from the CCID driver:

00055002 commands.c:233:CmdPowerOn Card absent or mute
00000004 ifdhandler.c:1204:IFDHPowerICC() PowerUp failed

This two lines are from pcscd:

00000003 eventhandler.c:387:EHStatusHandlerThread() Card inserted into Gemalto GemPC Twin 00 00
00000003 eventhandler.c:403:EHStatusHandlerThread() Error powering up card.

You may note that the CCID driver uses a higher level when logging a power up failure. Maybe that should be changed.

Time information

Each log line also contains a number on the first column. This is the time difference with the previous log line. This information is useful to detect timeout issues and also to perform some performance profiling using the pcscd_perfs.py tool.
The time information was used to improve performances. See "RAM and CPU improvements in pcsc-lite 1.6.x" for example.

Logs redirection

When you have a problem and I ask for logs, the best way to generate them is to redirect the output of pcscd to a file and send me the generated file.

By default the colorization is disabled when the pcscd output is redirected (using pcscd --foreground > log.txt) but it is possible to force the colorization using -T or --color. Colorized logs are much more easy to read for me.

Generating a colorized log file

The magic line to generate a log file with color is:

sudo pcscd --foreground --debug --apdu --color | tee log.txt

The use of the tee command will allow to redirect the pcscd output in the log file and also send this output to the screen. You can then also see the log and stop pcscd after the problem you want to report occurs.

You can use cat log.txt to display the log and you should see the colors. If you edit the log.txt file you should see control characters.

Conclusion

If I get nicer log files it will be more easy for me to spot problems. Logs are very important and in general the only way to find issues.