[cfe-dev] TSAN and pthread_setcancelstate()

[Rainer Gerhards via cfe-dev]

Hi all,

I am reposting a question asked last december on the users lists. I
hope find a solution here, as we have an issue that prevents us from
using TSAN in CI. My apologies if this is the wrong list for such
questions.

As a side-note, we have a corresponding issue tracker open here:

    https://github.com/rsyslog/rsyslog/issues/2323

I am using TSAN together with clang (3,4,5) on Linux (in this Case
Ubuntu 16.04). It works great, but I always get race reports (sample
after my sig) on pthread_setcancelstate(). The POSIX doc states that
it sets the cancellation state for the *current thread* so there
should be no cross-thread data races. To validate this, I have also
checked the GNU libc and pthread implemenation and the both access
thread-local storage.

So I wonder what I may be doing wrong and most importantly what I can
decently do in order to get rid of the TSAN message (false positive?).
I know I can disable TSAN on a function basis, but that is a bit
clumpsy as I do not want to disable if for more but the
pthread_setcancelstate. In an extreme, I probably need to move it to
an inline wrapper, but I don't consider this to be really clean.

Any advise, especially on the root cause, would be much appreciated.
It makes me kind of nervous not understanding why this happens at
all...

Thanks in advance,
Rainer

Sample Report:
WARNING: ThreadSanitizer: data race (pid=103016)
  Write of size 1 at 0x7c0000000000 by main thread:
    #0 pthread_setcancelstate <null> (rsyslogd+0x00000043a830)
    #1 qqueueEnqMsg /home/rger/proj/rsyslog/runtime/queue.c:3039:3
(rsyslogd+0x0000005a20d9)
    #2 submitMsg2 /home/rger/proj/rsyslog/tools/rsyslogd.c:1015:2
(rsyslogd+0x0000004b08b0)
    #3 logmsgInternal_doWrite
/home/rger/proj/rsyslog/tools/rsyslogd.c:864:3
(rsyslogd+0x0000004b0cc0)
    #4 processImInternal
/home/rger/proj/rsyslog/tools/rsyslogd.c:1566:4
(rsyslogd+0x0000004b0c4b)
    #5 mainloop /home/rger/proj/rsyslog/tools/rsyslogd.c:1787:3
(rsyslogd+0x0000004b2df5)
    #6 main /home/rger/proj/rsyslog/tools/rsyslogd.c:1965:2
(rsyslogd+0x0000004b15cf)

  Previous write of size 1 at 0x7c0000000000 by thread T1:
    #0 pthread_setcancelstate <null> (rsyslogd+0x00000043a830)
    #1 ConsumerReg /home/rger/proj/rsyslog/runtime/queue.c:2029:2
(rsyslogd+0x00000059e6f9)
    #2 wtiWorker /home/rger/proj/rsyslog/runtime/wti.c:366:14
(rsyslogd+0x000000591683)
    #3 wtpWorker /home/rger/proj/rsyslog/runtime/wtp.c:415:2
(rsyslogd+0x00000058e371)

  Thread T1 'rs:main Q[DA]:R' (tid=103049, running) created by main thread at:
    #0 pthread_create <null> (rsyslogd+0x00000042dc76)
    #1 wtpStartWrkr /home/rger/proj/rsyslog/runtime/wtp.c:464:11
(rsyslogd+0x00000058cf50)
    #2 wtpAdviseMaxWorkers /home/rger/proj/rsyslog/runtime/wtp.c:520:4
(rsyslogd+0x00000058c783)
    #3 qqueueAdviseMaxWorkers
/home/rger/proj/rsyslog/runtime/queue.c:380:3
(rsyslogd+0x00000059f899)
    #4 qqueueStart /home/rger/proj/rsyslog/runtime/queue.c:2437:2
(rsyslogd+0x0000005990bf)
    #5 StartDA /home/rger/proj/rsyslog/runtime/queue.c:450:9
(rsyslogd+0x0000005ae6cf)
    #6 InitDA /home/rger/proj/rsyslog/runtime/queue.c:514:3
(rsyslogd+0x00000059f281)
    #7 qqueueStart /home/rger/proj/rsyslog/runtime/queue.c:2430:3
(rsyslogd+0x00000059905d)
    #8 startMainQueue /home/rger/proj/rsyslog/tools/rsyslogd.c:829:2
(rsyslogd+0x0000004afa7f)
    #9 activateMainQueue
/home/rger/proj/rsyslog/runtime/rsconf.c:817:10
(rsyslogd+0x000000524349)
    #10 activate /home/rger/proj/rsyslog/runtime/rsconf.c:883:2
(rsyslogd+0x00000051fbf8)
    #11 initAll /home/rger/proj/rsyslog/tools/rsyslogd.c:1507:2
(rsyslogd+0x0000004b2b2c)
    #12 main /home/rger/proj/rsyslog/tools/rsyslogd.c:1957:2
(rsyslogd+0x0000004b151e)

SUMMARY: ThreadSanitizer: data race
(/home/rger/proj/rsyslog/tools/rsyslogd+0x43a830) in
__interceptor_pthread_setcancelstate