pcscd jams when using '--auto-exit'

Hello!

Since some time I have problems with pcscd. I'm using pcscd in
conjunction with online banking and after a short period of working it
stops and jams the banking application.

A 'strace' to the pcscd showed that it is still running somewhere
deep in the USB stack.

The problem is, when manually running the the pcscd, there is no
problem at all - only when running from systemd.
Therefore I searched for the differences and found one: the
'--auto-exit'. Downloaded the source and had a closer look.

What I understand from the source code is, that when '--auto-exit' is
given, a SIGALRM is generated which (should) terminate the process.

I have noticed that the signal handler 'signal_trap()' uses some
function calls that are not allowed in signal handlers; like:
* syslog()
* gettimeofday()
* remove()

Using this creates undefined behavior.
(Please see 'man 7 signal' for a complete list of system calls that
are not allowed in signal handlers.)


I found a workaround for the issue.
Changed the service file to:

===
[Unit]
Description=PC/SC Smart Card Daemon
#Requires=pcscd.socket

[Service]
#ExecStart=/usr/sbin/pcscd --foreground --auto-exit
ExecStart=/usr/sbin/pcscd --foreground --debug -a
ExecReload=/usr/sbin/pcscd --hotplug

[Install]
Also=pcscd.socket
===

and disabling the pcscd.socket gives me a stable system.
(Yes - pcscd is now started at boot time and runs the whole time
 - which is fine for me.)

If you need more information, please drop me a note.

Kind regards

Andre



Tested with ReinerSCT cyberjack and ReinerSCT RFID basic card readers.
Tested with the driver from Debian and from the vendor itself.

ii  libifd-cyberjack6                 3.99.5final.sp07      amd64                 REINER SCT cyberJack USB chipcard reader user space driver

$ /usr/sbin/pcscd --version
pcsc-lite version 1.8.16.
Copyright (C) 1999-2002 by David Corcoran <[email protected]>.
Copyright (C) 2001-2015 by Ludovic Rousseau <[email protected]>.
Copyright (C) 2003-2004 by Damien Sauveron <[email protected]>.
Report bugs to <[email protected]>.
Enabled features: Linux x86_64-pc-linux-gnu serial usb libudev usbdropdir=/usr/lib/pcsc/drivers ipcdir=/var/run/pcscd configdir=/etc/reader.conf.d

This is the version from Stretch - but with 1.8.13-1 the same problem occurs.

Running Debian Jessie (8.3)

journald:
Apr 08 18:03:18 thynias pcscd[11053]: CYBERJACK: Started

(gdb) info threads
  Id   Target Id         Frame
  2    Thread 0x7f9a3f412700 (LWP 11056) "pcscd" 0x00007f9a40170d3d in poll () at ../sysdeps/unix/syscall-template.S:81
* 1    Thread 0x7f9a4107a700 (LWP 11053) "pcscd" 0x00007f9a40170d3d in poll () at ../sysdeps/unix/syscall-template.S:81
(gdb) bt
#0  0x00007f9a40170d3d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f9a3fc3dc07 in ?? () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#2  0x00007f9a3fc3e8d3 in libusb_handle_events_timeout_completed () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#3  0x00007f9a3fc3e9d0 in libusb_handle_events_completed () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#4  0x00007f9a3fc3f231 in ?? () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#5  0x00007f9a3fc3f309 in ?? () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#6  0x00007f9a3fc3f69f in libusb_bulk_transfer () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#7  0x00007f9a3fe7e552 in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#8  0x00007f9a3fe7cbbe in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#9  0x00007f9a3fe79944 in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#10 0x00007f9a3fe663be in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#11 0x00007f9a3fe6dc8a in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#12 0x00007f9a3fe6fa1a in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#13 0x00007f9a3fe6fbe6 in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#14 0x00007f9a3fe652fe in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#15 0x00007f9a3fe70326 in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#16 0x00007f9a3fe781fe in CReader::Connect() () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#17 0x00007f9a3fe63114 in ?? () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#18 0x00007f9a3fe634e8 in IFDHCreateChannelByName () from /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
#19 0x00007f9a40e9e40a in IFDOpenIFD ()
#20 0x00007f9a40ea00b3 in RFInitializeReader ()
#21 0x00007f9a40ea0a5d in RFAddReader ()
#22 0x00007f9a40ea6632 in HPAddDevice ()
#23 0x00007f9a40ea6e5e in HPRegisterForHotplugEvents ()
#24 0x00007f9a40e9a818 in main ()
(gdb) thread 2
[Switching to thread 2 (Thread 0x7f9a3f412700 (LWP 11056))]
#0  0x00007f9a40170d3d in poll () at ../sysdeps/unix/syscall-template.S:81
81	in ../sysdeps/unix/syscall-template.S
(gdb) bt
#0  0x00007f9a40170d3d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f9a3fc43fd8 in ?? () from /lib/x86_64-linux-gnu/libusb-1.0.so.0
#2  0x00007f9a404440a4 in start_thread (arg=0x7f9a3f412700) at pthread_create.c:309
#3  0x00007f9a4017987d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111


First start - everything is fine:

00000053 winscard_svc.c:343:ContextThread() Client die: 14
00000011 winscard_svc.c:986:MSGCleanupClient() Thread is stopping: dwClientID=14, threadContext @0x7fc9ef7f6d90
00000004 winscard_svc.c:992:MSGCleanupClient() Freeing SCONTEXT @0x7fc9ef7f6d90
00000003 winscard_svc.c:1007:MSGCleanupClient() Starting suicide alarm in 60 seconds
00344636 eventhandler.c:491:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
00403458 eventhandler.c:479:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
59251946 pcscdaemon.c:749:signal_trap() Received signal: 14
00000016 pcscdaemon.c:768:signal_trap() Preparing for suicide
00000204 hotplug_libudev.c:710:HPStopHotPluggables() Hotplug stopped
01000083 readerfactory.c:1350:RFCleanupReaders() entering cleaning function
00000019 readerfactory.c:1359:RFCleanupReaders() Stopping reader: REINER SCT cyberJack pp_a2 (3176975693) 00 00
00000007 readerfactory.c:605:RFRemoveReader() UnrefReader() count was: 1
00000006 eventhandler.c:176:EHDestroyEventHandler() Stomping thread.
00000009 eventhandler.c:205:EHDestroyEventHandler() Waiting polling thread
00325937 eventhandler.c:502:EHStatusHandlerThread() Die
00000081 eventhandler.c:216:EHDestroyEventHandler() Thread stomped.
00000017 readerfactory.c:1117:RFUnInitializeReader() Attempting shutdown of REINER SCT cyberJack pp_a2 (3176975693) 00 00.
00001290 readerfactory.c:988:RFUnloadReader() Unloading reader driver.
00000082 winscard_svc.c:152:ContextsDeinitialize() remaining threads: 0
00000007 pcscdaemon.c:693:at_exit() cleaning /var/run/pcscd
root@thynias:~#
root@thynias:~#

Second start: jammed!
Never stops - even not after 60 seconds. Also no additional logs after
60 seconds.

root@thynias:~# /usr/sbin/pcscd --foreground --debug --auto-exit -a
00000000 debuglog.c:289:DebugLogSetLevel() debug level=debug
00000041 pcscdaemon.c:331:main() Auto exit after 60 seconds of inactivity
00000010 debuglog.c:310:DebugLogSetCategory() Debug options: APDU
00000095 configfile.l:281:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d
00000029 configfile.l:353:DBGetReaderList() Parsing conf file: /etc/reader.conf.d/libccidtwin
00000048 configfile.l:315:DBGetReaderListDir() Skipping non regular file: .
00000012 configfile.l:315:DBGetReaderListDir() Skipping non regular file: ..
00000012 pcscdaemon.c:567:main() pcsc-lite 1.8.16 daemon ready.
00001634 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001
00000088 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/003/001
00000087 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0C4B, PID: 0x0401, path: /dev/bus/usb/003/006
00000025 hotplug_libudev.c:433:HPAddDevice() Adding USB device: REINER SCT cyberJack pp_a2
00000046 readerfactory.c:1066:RFInitializeReader() Attempting startup of REINER SCT cyberJack pp_a2 (3176975693) 00 00 using /usr/lib/pcsc/drivers/libifd-cyberjack.bundle/Contents/Linux/libifd-cyberjack.so
CYBERJACK: Started
00001102 readerfactory.c:951:RFBindFunctions() Loading IFD Handler 3.0

What also not really helps at this point is to unplug and plug-in the
card reader

99999999 readerfactory.c:1097:RFInitializeReader() Open Port 0x200000 Failed (usb:0c4b/0401:libudev:0:/dev/bus/usb/003/006)
00000018 readerfactory.c:372:RFAddReader() REINER SCT cyberJack pp_a2 (3176975693) init failed.
00000007 readerfactory.c:605:RFRemoveReader() UnrefReader() count was: 1
00000005 readerfactory.c:1117:RFUnInitializeReader() Attempting shutdown of REINER SCT cyberJack pp_a2 (3176975693) 00 00.
00000004 readerfactory.c:988:RFUnloadReader() Unloading reader driver.
00000064 hotplug_libudev.c:520:HPAddDevice() Failed adding USB device: REINER SCT cyberJack pp_a2
00000154 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/004/001
00000075 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/004/001
00000073 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1058, PID: 0x10B8, path: /dev/bus/usb/004/002
00000068 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/004/001
00000071 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x05E3, PID: 0x0732, path: /dev/bus/usb/004/003
00000090 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000067 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
00000072 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/001/002
00000102 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/005/001
00000069 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/005/001
00000074 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x046D, PID: 0xC03E, path: /dev/bus/usb/005/002
00000068 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/005/001
00000074 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0409, PID: 0x005A, path: /dev/bus/usb/005/003
00000076 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0402, PID: 0x5602, path: /dev/bus/usb/005/004
00000072 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x0409, PID: 0x005A, path: /dev/bus/usb/005/003
00000098 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/006/001
00000097 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000063 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/002/001
00000066 hotplug_libudev.c:294:get_driver() Looking for a driver for VID: 0x8087, PID: 0x0024, path: /dev/bus/usb/002/002
Segmentation fault