Fixed compilation on OS X #1

frankmorgner · 2015-05-13T09:17:26Z

... and I think FreeBSD in general.

LudovicRousseau · 2015-05-13T15:35:06Z

What are the errors you are trying to solve?

frankmorgner · 2015-05-13T16:42:59Z

Compilation errors, basically:

LONG is an int, which contradicts the definition of the functions interface if LOG is not defined.
You need to check for strlcpy and strlcat in order to have HAVE_STRLCPY/HAVE_STRLCAT defined in config.h. Those defines are used in strlcpycat.h

LudovicRousseau · 2015-05-14T19:18:59Z

Your patch fixes warnings and not errors. Exact?

PCSC is not supposed to be used on Mac OS X.

frankmorgner · 2015-05-14T19:34:04Z

No, these are errors, not warnings.

Trying to compile with -DNO_LOG on any platform will fail!
Try to compile on a platform that implements strlcpy and strlcat should fail (i.e. FreeBSD or OS X)! I tested the code on Mac.

LudovicRousseau · 2015-05-14T19:51:44Z

Using -DNO_LOG make the compilation fail on Mac OS X.

error.c:53:16: error: conflicting types for 'pcsc_stringify_error'
PCSC_API char* pcsc_stringify_error(const long pcscError)
               ^
../src/PCSC/pcsclite.h:237:7: note: previous declaration is here
char *pcsc_stringify_error(const LONG);
      ^

But it works correctly on Debian GNU/Linux.
What is your target system?

And I have no problem with strlcpy and strlcat on Mac OS X.

frankmorgner · 2015-05-14T20:58:57Z

Sorry, I don't have the time to dig deeper into this. But if you have two different definitions of pcsc_stringify_error in the same file, it's obviously a problem. If you are using HAVE_STRLCAT,which is typically generated from autoconf, without looking for it with an autoconf macro, it's obviously a problem.

I just wanted to contribute back my findings. I am totally fine if you choose not to integrate this.

If NO_LOG is defined the code failed to build on Mac OS X: error.c:53:16: error: conflicting types for 'pcsc_stringify_error' PCSC_API char* pcsc_stringify_error(const long pcscError) ^ ../src/PCSC/pcsclite.h:237:7: note: previous declaration is here char *pcsc_stringify_error(const LONG); ^ 1 error generated. The prototype used in the case of NO_LOG was not the same as in the normal case: "long" instead of "LONG". Thanks to Frank Morgner for the bug report. #1

LudovicRousseau · 2015-05-15T16:05:29Z

NO_LOG issue fixed in e2752b7

pcsclite do not use strlcpy and strlcat anymore (see afc3f76). So there is nothing to fix.

From Maksim Ivanov: " It seems that there are still some issues with regard to the blocking requests cancellation functionality in PC/SC-Lite: 1. Extra SCARD_E_CANCELLED events may be sent by the daemon to the client that was previously performing an SCardGetStatusChange call. One scenario is that two concurrent SCardCancel calls succeeding simultaneously, and another scenario is an SCardCancel call succeeding simultaneously with an event sending from the status handler thread. As a result, the app<->daemon communication will break. Suggested solutions: For #1, suggesting to change the SCARD_CANCEL handler to firstly do EHUnregisterClientForEvent, and, only if it returns success, then send the SCARD_E_CANCELLED event to the client. " Now MSGSignalClient() is called only if EHUnregisterClientForEvent() succeeds i.e. the client was still blocked in a SCardGetStatusChange(). If SCardGetStatusChange() was already canceled or finished then we do not signal the client. Thanks to Maksim Ivanov for the bug report and solution "[Pcsclite-muscle] Data races related to SCardCancel" http:https://lists.alioth.debian.org/pipermail/pcsclite-muscle/Week-of-Mon-20170116/000789.html

.tv_sec and .tv_usec in struct timeval may be long (and should be) to avoid the year-2038 problem. Thanks to Coverity: CID 1453385 (#1 of 1): Invalid type in argument to printf format specifier (PRINTF_ARGS) invalid_type: Argument profile_time.tv_usec to format specifier %d was expected to have type int but has type long. CID 1453384 (#1 of 1): Invalid type in argument to printf format specifier (PRINTF_ARGS) invalid_type: Argument profile_time.tv_sec to format specifier %d was expected to have type int but has type long.

Use %08lX for rv codes (LONG) Thanks to Coverity: CID 1453383 (#1 of 1): Invalid type in argument to printf format specifier (PRINTF_ARGS) invalid_type: Argument rv to format specifier %08X was expected to have type unsigned int but has type long.

Issue reported by clang ThreadSanitizer WARNING: ThreadSanitizer: data race (pid=14419) Read of size 1 at 0x000000f3a9c8 by main thread: #0 SVCServiceRunLoop <null> (pcscd+0x4c0da9) #1 main <null> (pcscd+0x4c0694) Previous write of size 1 at 0x000000f3a9c8 by thread T1: #0 signal_thread <null> (pcscd+0x4c0aca) As if synchronized via sleep: #0 nanosleep <null> (pcscd+0x4297dd) #1 SYS_USleep <null> (pcscd+0x4c6c36) #2 SVCServiceRunLoop <null> (pcscd+0x4c0cef) #3 main <null> (pcscd+0x4c0694) Location is global 'AraKiri' of size 1 at 0x000000f3a9c8 (pcscd+0x000000f3a9c8) Thread T1 (tid=14421, running) created by main thread at: #0 pthread_create <null> (pcscd+0x42be9b) #1 main <null> (pcscd+0x4c01c8) SUMMARY: ThreadSanitizer: data race (/home/rousseau/sc/costa/PCSC/src/pcscd+0x4c0da9) in SVCServiceRunLoop

Problem: The thread running EHStatusHandlerThread() will race all the rContext->readerState->fields as well as the powerState and some other flags. These flags are both consumed and set by the thread running the ccid driver as well. Solution: Make the flow unidirectional*: the status thread will always set its own copy and "stash" a unique copy ready to be consumed by the driver thread. That copy is consumed and rcontext->readerState is updated in RFCheckReaderStatus() and a few other functions in readerfactory.c. Whenever a copy is consumed it is also freed. Note that even though this adds dynamic allocation it's at most 2 instances of READER_STATE. This PR uses the C11 _Atomic feature. I'm not very familiar with all the compilers pcsc is built with, but if you deem this to be incompatible, please review the overall approach and I can #ifdef and do some mutexes for platforms which do not provide _Atomic * the flow is unidirectional except for the readerName which is logged at the beginning of the status thread. That should not be a problem since the name is set from the driver thread before the status thread is spawned. ================== WARNING: ThreadSanitizer: data race (pid=28786) Write of size 4 at 0x000000f55c10 by thread T3: #0 EHStatusHandlerThread <null> (pcscd+0x4c3aed) Previous read of size 4 at 0x000000f55c10 by main thread: #0 RFWaitForReaderInit <null> (pcscd+0x4d0e27) #1 main <null> (pcscd+0x4c70c6) Location is global 'readerStates' of size 2944 at 0x000000f55b60 (pcscd+0x000000f55c10) Thread T3 (tid=28790, running) created by main thread at: #0 pthread_create <null> (pcscd+0x42be9b) #1 ThreadCreate <null> (pcscd+0x4e1c79) #2 EHSpawnEventHandler <null> (pcscd+0x4c2e9f) #3 RFAddReader <null> (pcscd+0x4cac07) #4 HPAddDevice <null> (pcscd+0x4e0a2e) #5 HPScanUSB <null> (pcscd+0x4dfe65) #6 HPRegisterForHotplugEvents <null> (pcscd+0x4dfd3a) #7 main <null> (pcscd+0x4c705c) SUMMARY: ThreadSanitizer: data race (/home/rousseau/sc/costa/PCSC/src/pcscd+0x4c3aed) in EHStatusHandlerThread ==================

The problem is (in part) with the switch() that may read the variable more than once. ================== WARNING: ThreadSanitizer: data race (pid=10828) Write of size 8 at 0x7b040000ae78 by thread T6 (mutexes: write M0): #0 RFSetReaderEventState PCSC/src/readerfactory.c:1321:32 (pcscd+0x4c45ce) #1 EHStatusHandlerThread PCSC/src/eventhandler.c:382:11 (pcscd+0x4bee54) Previous read of size 8 at 0x7b040000ae78 by thread T8: #0 RFCheckReaderEventState PCSC/src/readerfactory.c:1350:24 (pcscd+0x4c46c6) #1 SCardStatus PCSC/src/winscard.c:1286:7 (pcscd+0x4ce7b5) #2 ContextThread PCSC/src/winscard_svc.c:635:16 (pcscd+0x4d0cc1) Location is heap block of size 16 at 0x7b040000ae70 allocated by thread T8: #0 malloc <null> (pcscd+0x42a65c) #1 RFAddReaderHandle PCSC/src/readerfactory.c:1249:14 (pcscd+0x4c43b4) #2 SCardConnect PCSC/src/winscard.c:491:7 (pcscd+0x4ccc16) #3 ContextThread PCSC/src/winscard_svc.c:502:16 (pcscd+0x4d0a70) Mutex M0 (0x7b4c000000a0) created at: #0 pthread_mutex_init <null> (pcscd+0x42d2fd) #1 RFAddReader PCSC/src/readerfactory.c:329:8 (pcscd+0x4c1d18) #2 HPAddDevice PCSC/src/hotplug_libudev.c:534:8 (pcscd+0x4cba1c) #3 HPEstablishUSBNotifications PCSC/src/hotplug_libudev.c:668:6 (pcscd+0x4cb4d4) Thread T6 (tid=11122, running) created by thread T2 at: #0 pthread_create <null> (pcscd+0x42be8b) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0x4cc2dc) #2 EHSpawnEventHandler PCSC/src/eventhandler.c:237:7 (pcscd+0x4beb59) #3 RFAddReader PCSC/src/readerfactory.c:426:8 (pcscd+0x4c21b9) #4 HPAddDevice PCSC/src/hotplug_libudev.c:534:8 (pcscd+0x4cba1c) #5 HPEstablishUSBNotifications PCSC/src/hotplug_libudev.c:668:6 (pcscd+0x4cb4d4) Thread T8 (tid=11173, running) created by main thread at: #0 pthread_create <null> (pcscd+0x42be8b) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0x4cc2dc) #2 CreateContextThread PCSC/src/winscard_svc.c:236:7 (pcscd+0x4cfd8b) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:134:9 (pcscd+0x4c1082) #4 main PCSC/src/pcscdaemon.c:786:2 (pcscd+0x4c09c4) SUMMARY: ThreadSanitizer: data race PCSC/src/readerfactory.c:1321:32 in RFSetReaderEventState ==================

Thansk to Coverity for the bug report: CID 1503363 (#1 of 1): Resource leak (RESOURCE_LEAK) 26. leaked_storage: Variable deviceName going out of scope leaks the storage it points to.

Remove a test code duplication Thanks to Coverity for the bug report: CID 1503368 (#1 of 1): Untrusted loop bound (TAINTED_SCALAR) 45. tainted_data: Using tainted variable iReader as a loop boundary.

This check is already made on the server side at winscard_svc.c line 737. But the client may be connected to a rogue server. So double check does not hurt. Thanks to Coverity for the bug report: CID 1503367 (#1 of 1): Untrusted loop bound (TAINTED_SCALAR) 10. tainted_data: Passing tainted expression scControlStruct.dwBytesReturned to MessageReceive, which uses it as a loop boundary.

This check is already made on the server side at winscard_svc.c line 683. But the client may be connected to a rogue server. So double check does not hurt. Thanks to Coverity for the bug report: CID 1503364 (#1 of 1): Untrusted loop bound (TAINTED_SCALAR) 15. tainted_data: Passing tainted expression scTransmitStruct.pcbRecvLength to MessageReceive, which uses it as a loop boundary.

protect accesses to readerStates[] using a mutex so that 2 threads cannot interfere for example by calling SCardGetStatusChange() and SCardStatus() at the same time. The ThreadSanitizer trace was: ================== WARNING: ThreadSanitizer: data race (pid=13125) Write of size 8 at 0x7fd3afc2b040 by main thread (mutexes: write M0): #0 read <null> (pcsc_demo+0x5d8a4) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #1 read /usr/include/x86_64-linux-gnu/bits/unistd.h:38:10 (libpcsclite.so.1+0xab3c) (BuildId: 53195794f51c4d60ff5688d377d82ae2e264554e) #2 MessageReceive src/winscard_msg.c:491:17 (libpcsclite.so.1+0xab3c) #3 getReaderStates src/winscard_clnt.c:3552:7 (libpcsclite.so.1+0x4109) (BuildId: 53195794f51c4d60ff5688d377d82ae2e264554e) #4 SCardStatus src/winscard_clnt.c:1441:7 (libpcsclite.so.1+0x4109) #5 main /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:108:7 (pcsc_demo+0xd1bc4) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) Previous write of size 8 at 0x7fd3afc2b040 by thread T1 (mutexes: write M1): #0 read <null> (pcsc_demo+0x5d8a4) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #1 read /usr/include/x86_64-linux-gnu/bits/unistd.h:38:10 (libpcsclite.so.1+0xab3c) (BuildId: 53195794f51c4d60ff5688d377d82ae2e264554e) #2 MessageReceive src/winscard_msg.c:491:17 (libpcsclite.so.1+0xab3c) #3 getReaderStatesAndRegisterForEvents src/winscard_clnt.c:3571:7 (libpcsclite.so.1+0x47b3) (BuildId: 53195794f51c4d60ff5688d377d82ae2e264554e) #4 SCardGetStatusChange src/winscard_clnt.c:1747:7 (libpcsclite.so.1+0x47b3) #5 do_statuschange /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:35:10 (pcsc_demo+0xd1e6d) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #6 statuschange_thread /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:53:2 (pcsc_demo+0xd19fd) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) Location is global 'readerStates' of size 2944 at 0x7fd3afc2b040 (libpcsclite.so.1+0xf040) Mutex M0 (0x7b3000006010) created at: #0 pthread_mutex_init <null> (pcsc_demo+0x5431f) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #1 SCardAddContext src/winscard_clnt.c:3259:8 (libpcsclite.so.1+0x6adc) (BuildId: 53195794f51c4d60ff5688d377d82ae2e264554e) #2 SCardEstablishContextTH src/winscard_clnt.c:659:7 (libpcsclite.so.1+0x6adc) #3 SCardEstablishContext src/winscard_clnt.c:483:7 (libpcsclite.so.1+0x6adc) #4 main /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:86:7 (pcsc_demo+0xd1aca) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) Mutex M1 (0x7b3000000010) created at: #0 pthread_mutex_init <null> (pcsc_demo+0x5431f) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #1 SCardAddContext src/winscard_clnt.c:3259:8 (libpcsclite.so.1+0x6adc) (BuildId: 53195794f51c4d60ff5688d377d82ae2e264554e) #2 SCardEstablishContextTH src/winscard_clnt.c:659:7 (libpcsclite.so.1+0x6adc) #3 SCardEstablishContext src/winscard_clnt.c:483:7 (libpcsclite.so.1+0x6adc) #4 do_statuschange /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:12:7 (pcsc_demo+0xd1d84) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #5 statuschange_thread /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:53:2 (pcsc_demo+0xd19fd) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) Thread T1 (tid=13127, running) created by main thread at: #0 pthread_create <null> (pcsc_demo+0x52b4d) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #1 start_thread /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:61:6 (pcsc_demo+0xd1964) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) #2 main /tmp/x/pcsc-lite-2.0.0/pcsc_demo.c:84:8 (pcsc_demo+0xd1ab1) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) SUMMARY: ThreadSanitizer: data race (/tmp/x/pcsc-lite-2.0.0/pcsc_demo+0x5d8a4) (BuildId: 1ce759cdf5448d9e6401e93f7f56d4c7caa8ede7) in __interceptor_read ================== Thanks to Stefan Ehmann for the bug report.

Use pthread_once() to initialize the variable only once. It was possible that 2 threads were modifying the variable at the same time. The ThreadSanitizer trace was: ================== WARNING: ThreadSanitizer: data race (pid=14864) Write of size 1 at 0x7f8803cccd2b by main thread: #0 getSocketName src/winscard_msg.c:101 (libpcsclite.so.1+0xa28c) #1 getSocketName src/winscard_msg.c:85 (libpcsclite.so.1+0xa28c) #2 SCardCheckDaemonAvailability src/winscard_clnt.c:3550 (libpcsclite.so.1+0x65cf) #3 SCardEstablishContext src/winscard_clnt.c:479 (libpcsclite.so.1+0x66a7) #4 main /tmp/pcsc/pcsc_demo.cpp:86 (pcsc_demo+0x1517) Previous write of size 1 at 0x7f8803cccd2b by thread T1: #0 getSocketName src/winscard_msg.c:101 (libpcsclite.so.1+0xa28c) #1 getSocketName src/winscard_msg.c:85 (libpcsclite.so.1+0xa28c) #2 SCardCheckDaemonAvailability src/winscard_clnt.c:3550 (libpcsclite.so.1+0x65cf) #3 SCardEstablishContext src/winscard_clnt.c:479 (libpcsclite.so.1+0x66a7) #4 do_statuschange /tmp/pcsc/pcsc_demo.cpp:12 (pcsc_demo+0x1264) #5 statuschange_thread /tmp/pcsc/pcsc_demo.cpp:53 (pcsc_demo+0x1264) Location is global '<null>' at 0x000000000000 (libpcsclite.so.1+0xfd2b) Thread T1 (tid=14867, running) created by main thread at: #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1001 (libtsan.so.2+0x5e686) #1 start_thread(char const*) /tmp/pcsc/pcsc_demo.cpp:61 (pcsc_demo+0x1432) #2 main /tmp/pcsc/pcsc_demo.cpp:84 (pcsc_demo+0x14cc) SUMMARY: ThreadSanitizer: data race src/winscard_msg.c:101 in getSocketName ================== ThreadSanitizer: reported 1 warnings Thanks to Stefan Ehmann for the bug report.

The field .cardAtrLength is used to know if a card is inserted and is accessed from different threads. We define it as _Atomic to have atomic accesses to the field and fix a TSAN warning: ================== WARNING: ThreadSanitizer: data race (pid=14987) Read of size 4 at 0x557bacd39cb0 by main thread: #0 RFWaitForReaderInit PCSC/src/readerfactory.c:1430:43 (pcscd+0xdda24) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #1 main PCSC/src/pcscdaemon.c:773:2 (pcscd+0xd87d4) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) Previous write of size 8 at 0x557bacd39cb0 by thread T3: #0 EHStatusHandlerThread PCSC/src/eventhandler.c:314:40 (pcscd+0xd6a47) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) Location is global 'readerStates' of size 2944 at 0x557bacd39c00 (pcscd+0x1496cb0) Thread T3 (tid=14992, running) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe38cb) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #2 EHSpawnEventHandler PCSC/src/eventhandler.c:233:7 (pcscd+0xd6960) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #3 RFAddReader PCSC/src/readerfactory.c:397:8 (pcscd+0xdb632) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #4 HPAddDevice PCSC/src/hotplug_libudev.c:512:8 (pcscd+0xe3029) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #5 HPScanUSB PCSC/src/hotplug_libudev.c:579:3 (pcscd+0xe263d) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) #6 HPRegisterForHotplugEvents PCSC/src/hotplug_libudev.c:761:2 (pcscd+0xe263d) #7 main PCSC/src/pcscdaemon.c:766:7 (pcscd+0xd87c7) (BuildId: b43179fc4c418df0dad65d97dc7a0d9cc226d42f) SUMMARY: ThreadSanitizer: data race PCSC/src/readerfactory.c:1430:43 in RFWaitForReaderInit ================== Thanks to Stefan Ehmann for the bug report.

ContextsDeinitialize() was called by thread A in the middle of list_delete() from thread B. We already have a mutex to protect access to contextsList. ================== WARNING: ThreadSanitizer: data race (pid=17581) Write of size 8 at 0x5606b8d11b60 by main thread: #0 list_clear PCSC/src/simclist.c:694:12 (pcscd+0xde66c) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #1 list_destroy PCSC/src/simclist.c:313:5 (pcscd+0xde26c) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #2 ContextsDeinitialize PCSC/src/winscard_svc.c:159:2 (pcscd+0xe4d13) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:122:4 (pcscd+0xd9699) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #4 main PCSC/src/pcscdaemon.c:799:2 (pcscd+0xd8930) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) Previous write of size 8 at 0x5606b8d11b60 by thread T6 (mutexes: write M0): #0 list_drop_elem PCSC/src/simclist.c:1457:36 (pcscd+0xdf63e) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #1 list_delete_at PCSC/src/simclist.c:580:5 (pcscd+0xdf63e) #2 list_delete PCSC/src/simclist.c:563:6 (pcscd+0xdf1c7) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #3 MSGCleanupClient PCSC/src/winscard_svc.c:1083:8 (pcscd+0xe9f6a) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #4 ContextThread PCSC/src/winscard_svc.c:818:2 (pcscd+0xe98fd) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) As if synchronized via sleep: #0 nanosleep <null> (pcscd+0x515ed) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #1 SYS_Sleep PCSC/src/sys_unix.c:69:9 (pcscd+0xdf8e9) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #2 SVCServiceRunLoop PCSC/src/pcscdaemon.c:117:10 (pcscd+0xd968a) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #3 main PCSC/src/pcscdaemon.c:799:2 (pcscd+0xd8930) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) Location is global 'contextsList' of size 120 at 0x5606b8d11b50 (pcscd+0x1497b60) Mutex M0 (0x5606b8d11bc8) created at: #0 pthread_mutex_init <null> (pcscd+0x555cf) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #1 ContextsInitialize PCSC/src/winscard_svc.c:144:8 (pcscd+0xe4be5) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #2 main PCSC/src/pcscdaemon.c:737:7 (pcscd+0xd8780) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) Thread T6 (tid=17591, finished) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe399b) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #2 CreateContextThread PCSC/src/winscard_svc.c:237:7 (pcscd+0xd936e) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:131:9 (pcscd+0xd936e) #4 main PCSC/src/pcscdaemon.c:799:2 (pcscd+0xd8930) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) #5 main PCSC/src/pcscdaemon.c:799:2 (pcscd+0xd8930) (BuildId: 807b741f905324f3ef4d96796ee2663eb8beddec) SUMMARY: ThreadSanitizer: data race PCSC/src/simclist.c:694:12 in list_clear ==================

The struct timeval used in log_line() can't be accessed in a atomic way so we should protect it using a mutex. ================== WARNING: ThreadSanitizer: data race (pid=5391) Read of size 8 at 0x55b3bba7b950 by thread T3 (mutexes: write M17): #0 log_line /PCSC-debug/src/debuglog.c:217 (pcscd+0x9d7e) #1 log_msg /PCSC-debug/src/debuglog.c:148 (pcscd+0x9a85) #2 IFDHPowerICC <null> (libccid.so+0x8a54) #3 EHStatusHandlerThread /PCSC-debug/src/eventhandler.c:395 (pcscd+0xbafe) Previous write of size 8 at 0x55b3bba7b950 by main thread: #0 log_line /PCSC-debug/src/debuglog.c:232 (pcscd+0x9e77) #1 log_msg /PCSC-debug/src/debuglog.c:148 (pcscd+0x9a85) #2 get_driver /PCSC-debug/src/hotplug_libudev.c:298 (pcscd+0x1f75d) #3 HPAddDevice /PCSC-debug/src/hotplug_libudev.c:394 (pcscd+0x1ff32) #4 HPScanUSB /PCSC-debug/src/hotplug_libudev.c:579 (pcscd+0x209db) #5 HPRegisterForHotplugEvents /PCSC-debug/src/hotplug_libudev.c:761 (pcscd+0x21255) #6 main /PCSC-debug/src/pcscdaemon.c:766 (pcscd+0xe6fa) Location is global 'last_time.3' of size 16 at 0x55b3bba7b950 (pcscd+0x35950) Mutex M17 (0x7b0c000014d0) created at: #0 pthread_mutex_init ../../../../src/libsanitizer/tsan/ tsan_interceptors_posix.cpp:1295 (libtsan.so.2+0x50468) #1 RFAddReader /PCSC-debug/src/readerfactory.c:355 (pcscd+0x10b8c) #2 HPAddDevice /PCSC-debug/src/hotplug_libudev.c:512 (pcscd+0x205b0) #3 HPScanUSB /PCSC-debug/src/hotplug_libudev.c:579 (pcscd+0x209db) #4 HPRegisterForHotplugEvents /PCSC-debug/src/hotplug_libudev.c:761 (pcscd+0x21255) #5 main /PCSC-debug/src/pcscdaemon.c:766 (pcscd+0xe6fa) Thread T3 (tid=5395, running) created by main thread at: #0 pthread_create ../../../../src/libsanitizer/tsan/ tsan_interceptors_posix.cpp:1001 (libtsan.so.2+0x5e686) #1 ThreadCreate /PCSC-debug/src/utils.c:184 (pcscd+0x21755) #2 EHSpawnEventHandler /PCSC-debug/src/eventhandler.c:233 (pcscd+0xb2d9) #3 RFAddReader /PCSC-debug/src/readerfactory.c:397 (pcscd+0x10f1a) #4 HPAddDevice /PCSC-debug/src/hotplug_libudev.c:512 (pcscd+0x205b0) #5 HPScanUSB /PCSC-debug/src/hotplug_libudev.c:579 (pcscd+0x209db) #6 HPRegisterForHotplugEvents /PCSC-debug/src/hotplug_libudev.c:761 (pcscd+0x21255) #7 main /PCSC-debug/src/pcscdaemon.c:766 (pcscd+0xe6fa) SUMMARY: ThreadSanitizer: data race /PCSC-debug/src/debuglog.c:217 in log_line ================== Thanks to Stefan Ehmann for the bug report and patch.

The field .vHandle is used to check the validity of the reader. It is accessed in write mode in RFUnloadReader() from a thread A while it is also accessed in read mode in RFWaitForReaderInit() from thread B. ================== WARNING: ThreadSanitizer: data race (pid=23997) Write of size 8 at 0x7b4c000002d8 by thread T5: #0 RFUnloadReader PCSC/src/readerfactory.c:1005:20 (pcscd+0xda017) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #1 RFUnInitializeReader PCSC/src/readerfactory.c:1151:8 (pcscd+0xda017) #2 removeReader PCSC/src/readerfactory.c:645:2 (pcscd+0xda017) #3 _UnrefReader PCSC/src/readerfactory.c:120:3 (pcscd+0xda017) #4 RFRemoveReader PCSC/src/readerfactory.c:624:5 (pcscd+0xdd11b) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #5 RFRemoveReader PCSC/src/readerfactory.c:624:5 (pcscd+0xdd11b) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #6 HPRemoveDevice PCSC/src/hotplug_libudev.c:348:4 (pcscd+0xe35af) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #7 HPEstablishUSBNotifications PCSC/src/hotplug_libudev.c:640:6 (pcscd+0xe35af) Previous read of size 8 at 0x7b4c000002d8 by main thread: #0 RFWaitForReaderInit PCSC/src/readerfactory.c:1426:29 (pcscd+0xddabe) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #1 main PCSC/src/pcscdaemon.c:773:2 (pcscd+0xd8864) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) Location is heap block of size 400 at 0x7b4c000001c0 allocated by main thread: #0 malloc <null> (pcscd+0x52691) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #1 RFAllocateReaderSpace PCSC/src/readerfactory.c:135:25 (pcscd+0xda3b9) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #2 main PCSC/src/pcscdaemon.c:643:7 (pcscd+0xd85a5) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) Thread T5 (tid=24004, running) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe39bb) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #2 HPRegisterForHotplugEvents PCSC/src/hotplug_libudev.c:763:6 (pcscd+0xe2768) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) #3 main PCSC/src/pcscdaemon.c:766:7 (pcscd+0xd8857) (BuildId: db0b27e1c3b409153327b14d9e501205ed34fb6e) SUMMARY: ThreadSanitizer: data race PCSC/src/readerfactory.c:1005:20 in RFUnloadReader ==================

When pcscd exits we must first terminate any client thread on the server side before closing the reader threads. This is to prevent a client thread to access a now deactivated reader. The error was: ^C00250854 [140433941325504] pcscdaemon.c:192:signal_thread() Received signal: 2 00000036 [140433941325504] pcscdaemon.c:226:signal_thread() Preparing for suicide [...readers are stopped here...] 00000042 [140433995138368] pcscdaemon.c:809:at_exit() cleaning /run/pcscd [...but we get a new request from a client...] 00000016 [140433906050752] winscard_svc.c:384:ContextThread() Received command: CMD_WAIT_READER_STATE_CHANGE from client 12 ================== WARNING: ThreadSanitizer: use of an invalid mutex (e.g. uninitialized or destroyed) (pid=62372) #0 pthread_mutex_lock <null> (pcscd+0x71ada) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #1 EHRegisterClientForEvent PCSC/src/eventhandler.c:68:8 (pcscd+0xe5b2a) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #2 ContextThread PCSC/src/winscard_svc.c:446:5 (pcscd+0xe5b2a) #3 __tsan_thread_start_func <null> (pcscd+0x53d66) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) Location is global 'ClientsWaitingForEvent_lock' of size 40 at 0x556bd69d67c8 (pcscd+0x14977c8) Mutex M0 (0x556bd69d67c8) created at: [failed to restore the stack] SUMMARY: ThreadSanitizer: use of an invalid mutex (e.g. uninitialized or destroyed) (PCSC/src/pcscd+0x71ada) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) in __interceptor_pthread_mutex_lock ================== ================== WARNING: ThreadSanitizer: heap-use-after-free (pid=62372) Read of size 8 at 0x7b0c00000060 by thread T5: #0 list_insert_at PCSC/src/simclist.c:503:16 (pcscd+0xdea60) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #1 list_append PCSC/src/simclist.c:397:12 (pcscd+0xdea60) #2 EHRegisterClientForEvent PCSC/src/eventhandler.c:70:8 (pcscd+0xe5b39) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #3 ContextThread PCSC/src/winscard_svc.c:446:5 (pcscd+0xe5b39) #4 EHRegisterClientForEvent PCSC/src/eventhandler.c:70:8 (pcscd+0xe5b39) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #5 ContextThread PCSC/src/winscard_svc.c:446:5 (pcscd+0xe5b39) #6 __tsan_thread_start_func <null> (pcscd+0x53d66) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) Previous write of size 8 at 0x7b0c00000060 by main thread: #0 free <null> (pcscd+0x52c84) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #1 list_destroy PCSC/src/simclist.c:317:5 (pcscd+0xde590) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #2 EHDeinitializeEventStructures PCSC/src/eventhandler.c:152:2 (pcscd+0xd6866) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:124:4 (pcscd+0xd9649) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #4 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd88e0) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) Thread T5 (tid=62379, running) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe3c7b) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #2 CreateContextThread PCSC/src/winscard_svc.c:258:7 (pcscd+0xd931e) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:133:9 (pcscd+0xd931e) #4 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd88e0) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) #5 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd88e0) (BuildId: 1bcd3f8a880d8c656c6e6bbe77b504b573d68914) SUMMARY: ThreadSanitizer: heap-use-after-free PCSC/src/simclist.c:503:16 in list_insert_at ================== etc..

The field .readerSharing can be used from different theads at the same time. We define it as _Atomic to have atomic accesses to the field and fix a TSAN warning: ================== WARNING: ThreadSanitizer: data race (pid=63123) Write of size 4 at 0x5575884d8cb8 by thread T3: #0 EHStatusHandlerThread PCSC/src/eventhandler.c:449:41 (pcscd+0xd6f12) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) Previous write of size 4 at 0x5575884d8cb8 by thread T8: #0 SCardDisconnect PCSC/src/winscard.c:1034:39 (pcscd+0xe4779) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #1 ContextThread PCSC/src/winscard_svc.c:575:16 (pcscd+0xe6507) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) As if synchronized via sleep: #0 nanosleep <null> (pcscd+0x515ed) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #1 SYS_USleep PCSC/src/sys_unix.c:87:9 (pcscd+0xd6fca) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #2 EHStatusHandlerThread PCSC/src/eventhandler.c (pcscd+0xd6fca) #3 __tsan_thread_start_func <null> (pcscd+0x53d66) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) Location is global 'readerStates' of size 2944 at 0x5575884d8c30 (pcscd+0x1497cb8) Thread T3 (tid=63127, running) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe3cab) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #2 EHSpawnEventHandler PCSC/src/eventhandler.c:233:7 (pcscd+0xd6840) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #3 RFAddReader PCSC/src/readerfactory.c:397:8 (pcscd+0xdb6dd) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #4 HPAddDevice PCSC/src/hotplug_libudev.c:512:8 (pcscd+0xe3409) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #5 HPScanUSB PCSC/src/hotplug_libudev.c:579:3 (pcscd+0xe2a1d) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #6 HPRegisterForHotplugEvents PCSC/src/hotplug_libudev.c:761:2 (pcscd+0xe2a1d) #7 main PCSC/src/pcscdaemon.c:768:7 (pcscd+0xd8717) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) Thread T8 (tid=63221, finished) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe3cab) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #2 CreateContextThread PCSC/src/winscard_svc.c:256:7 (pcscd+0xd924e) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:133:9 (pcscd+0xd924e) #4 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd8810) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) #5 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd8810) (BuildId: b2f519c8807f458b6282d631fe17086d4f6da420) SUMMARY: ThreadSanitizer: data race PCSC/src/eventhandler.c:449:41 in EHStatusHandlerThread ==================

The field .LockCount can be used from different theads at the same time. We define it as _Atomic to have atomic accesses to the field and fix a TSAN warning: ================== WARNING: ThreadSanitizer: data race (pid=64069) Write of size 4 at 0x7b4c00000138 by thread T6 (mutexes: write M0): #0 RFUnlockAllSharing PCSC/src/readerfactory.c:1080:23 (pcscd+0xe3f15) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #1 SCardDisconnect PCSC/src/winscard.c:863:7 (pcscd+0xe3f15) #2 ContextThread PCSC/src/winscard_svc.c:575:16 (pcscd+0xe64f7) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #3 ContextThread PCSC/src/winscard_svc.c:575:16 (pcscd+0xe64f7) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) Previous write of size 4 at 0x7b4c00000138 by thread T3: #0 RFSetReaderEventState PCSC/src/readerfactory.c:1304:23 (pcscd+0xdd8f2) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #1 EHStatusHandlerThread PCSC/src/eventhandler.c:362:11 (pcscd+0xd6c9c) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) Location is heap block of size 400 at 0x7b4c00000000 allocated by main thread: #0 malloc <null> (pcscd+0x52691) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #1 RFAllocateReaderSpace PCSC/src/readerfactory.c:135:25 (pcscd+0xda2e9) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #2 main PCSC/src/pcscdaemon.c:645:7 (pcscd+0xd8465) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) Mutex M0 (0x55dc20366908) created at: #0 pthread_mutex_lock <null> (pcscd+0x71ada) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #1 RFUnlockAllSharing PCSC/src/readerfactory.c:1076:8 (pcscd+0xe3ecf) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #2 SCardDisconnect PCSC/src/winscard.c:863:7 (pcscd+0xe3ecf) #3 ContextThread PCSC/src/winscard_svc.c:575:16 (pcscd+0xe64f7) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #4 ContextThread PCSC/src/winscard_svc.c:575:16 (pcscd+0xe64f7) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) Thread T6 (tid=64077, running) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe3c9b) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #2 CreateContextThread PCSC/src/winscard_svc.c:256:7 (pcscd+0xd924e) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #3 SVCServiceRunLoop PCSC/src/pcscdaemon.c:133:9 (pcscd+0xd924e) #4 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd8810) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #5 main PCSC/src/pcscdaemon.c:801:2 (pcscd+0xd8810) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) Thread T3 (tid=64073, running) created by main thread at: #0 pthread_create <null> (pcscd+0x53dfd) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #1 ThreadCreate PCSC/src/utils.c:184:8 (pcscd+0xe3c9b) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #2 EHSpawnEventHandler PCSC/src/eventhandler.c:233:7 (pcscd+0xd6840) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #3 RFAddReader PCSC/src/readerfactory.c:397:8 (pcscd+0xdb6cd) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #4 HPAddDevice PCSC/src/hotplug_libudev.c:512:8 (pcscd+0xe33f9) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #5 HPScanUSB PCSC/src/hotplug_libudev.c:579:3 (pcscd+0xe2a0d) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) #6 HPRegisterForHotplugEvents PCSC/src/hotplug_libudev.c:761:2 (pcscd+0xe2a0d) #7 main PCSC/src/pcscdaemon.c:768:7 (pcscd+0xd8717) (BuildId: ca24a31c13ced4613b52730b820229170aba90d6) SUMMARY: ThreadSanitizer: data race PCSC/src/readerfactory.c:1080:23 in RFUnlockAllSharing ==================

Frank Morgner added 2 commits May 13, 2015 11:12

fixed compiling without LOG

b17e39e

fixed check for strlcpy and strlcat

f02e423

frankmorgner closed this May 14, 2015

omaryesith mentioned this pull request Jan 13, 2020

ccid_usb.c:1316:ReadUSB() read failed (2/3): -7 LIBUSB_ERROR_TIME OUT #73

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fixed compilation on OS X #1

Fixed compilation on OS X #1

frankmorgner commented May 13, 2015

LudovicRousseau commented May 13, 2015

frankmorgner commented May 13, 2015

LudovicRousseau commented May 14, 2015

frankmorgner commented May 14, 2015

LudovicRousseau commented May 14, 2015

frankmorgner commented May 14, 2015

LudovicRousseau commented May 15, 2015

Fixed compilation on OS X #1

Fixed compilation on OS X #1

Conversation

frankmorgner commented May 13, 2015

LudovicRousseau commented May 13, 2015

frankmorgner commented May 13, 2015

LudovicRousseau commented May 14, 2015

frankmorgner commented May 14, 2015

LudovicRousseau commented May 14, 2015

frankmorgner commented May 14, 2015

LudovicRousseau commented May 15, 2015