Created attachment 116147 [details] pthread_rwlock_timedwrlock false positive demo Unlike drd helgrind demonstrates false positive on timedwrlock. 1. Build example from attach with "gcc test_timedwrlock.c -lpthread" 2. Run under helgrind. Notice error. --- cut --- ==31157== Helgrind, a thread error detector ==31157== Copyright (C) 2007-2017, and GNU GPL'd, by OpenWorks LLP et al. ==31157== Using Valgrind-3.14.0 and LibVEX; rerun with -h for copyright info ==31157== Command: /tmp/a.out ==31157== ==31157== ---Thread-Announcement------------------------------------------ ==31157== ==31157== Thread #2 was created ==31157== at 0x494DAD1: clone (clone.S:87) ==31157== by 0x484E1F2: create_thread (createthread.c:102) ==31157== by 0x484F97B: pthread_create@@GLIBC_2.1 (pthread_create.c:679) ==31157== by 0x4834056: pthread_create_WRK (hg_intercepts.c:427) ==31157== by 0x4834C67: pthread_create@* (hg_intercepts.c:460) ==31157== by 0x1089F6: main (in /tmp/a.out) ==31157== ==31157== ---------------------------------------------------------------- ==31157== ==31157== Thread #2 unlocked a not-locked lock at 0x10A080 ==31157== at 0x4833963: pthread_rwlock_unlock_WRK (hg_intercepts.c:2540) ==31157== by 0x4835334: pthread_rwlock_unlock (hg_intercepts.c:2559) ==31157== by 0x108947: threadFuncSimple (in /tmp/a.out) ==31157== by 0x48341E1: mythread_wrapper (hg_intercepts.c:389) ==31157== by 0x484F279: start_thread (pthread_create.c:333) ==31157== by 0x494DAE5: clone (clone.S:110) ==31157== Lock at 0x10A080 was first observed ==31157== at 0x48332FD: pthread_rwlock_init_WRK (hg_intercepts.c:2027) ==31157== by 0x48352E6: pthread_rwlock_init (hg_intercepts.c:2042) ==31157== by 0x1089BC: main (in /tmp/a.out) ==31157== Address 0x10a080 is 0 bytes inside data symbol "lock" ==31157== ==31157== { <insert_a_suppression_name_here> Helgrind:UnlockUnlocked fun:pthread_rwlock_unlock_WRK fun:pthread_rwlock_unlock fun:threadFuncSimple fun:mythread_wrapper fun:start_thread fun:clone } ==31157== ---Thread-Announcement------------------------------------------ ==31157== ==31157== Thread #3 was created ==31157== at 0x494DAD1: clone (clone.S:87) ==31157== by 0x484E1F2: create_thread (createthread.c:102) ==31157== by 0x484F97B: pthread_create@@GLIBC_2.1 (pthread_create.c:679) ==31157== by 0x4834056: pthread_create_WRK (hg_intercepts.c:427) ==31157== by 0x4834C67: pthread_create@* (hg_intercepts.c:460) ==31157== by 0x1089F6: main (in /tmp/a.out) ==31157== ==31157== ---------------------------------------------------------------- ==31157== ==31157== Possible data race during read of size 4 at 0x10A064 by thread #3 ==31157== Locks held: none ==31157== at 0x108911: threadFuncSimple (in /tmp/a.out) ==31157== by 0x48341E1: mythread_wrapper (hg_intercepts.c:389) ==31157== by 0x484F279: start_thread (pthread_create.c:333) ==31157== by 0x494DAE5: clone (clone.S:110) ==31157== ==31157== This conflicts with a previous write of size 4 by thread #2 ==31157== Locks held: none ==31157== at 0x10891A: threadFuncSimple (in /tmp/a.out) ==31157== by 0x48341E1: mythread_wrapper (hg_intercepts.c:389) ==31157== by 0x484F279: start_thread (pthread_create.c:333) ==31157== by 0x494DAE5: clone (clone.S:110) ==31157== Address 0x10a064 is 0 bytes inside data symbol "global_a" ==31157== --- cut --- 3. Run under drd. Notice success. --- cut --- ==31123== drd, a thread error detector ==31123== Copyright (C) 2006-2017, and GNU GPL'd, by Bart Van Assche. ==31123== Using Valgrind-3.14.0 and LibVEX; rerun with -h for copyright info ==31123== Command: /tmp/a.out ==31123== global_a = 1 global_a = 2 global_a = 3 global_a = 4 global_a = 5 global_a = 6 global_a = 7 global_a = 8 global_a = 9 Can't lock Can't lock Can't lock Can't lock Can't lock Can't lock global_a = a ==31123== ==31123== For counts of detected and suppressed errors, rerun with: -v ==31123== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 147 from 62) --- cut --- Tested libc-pthread versions: 2.23, 2.24. Tested platform: amd64.
This happens because Helgrind on Linux doesn't intercept pthread_rwlock_timedwrlock and so it doesn't know that the lock has been taken. The strange thing is, the code to do the intercept actually exists; it just isn't enabled on Linux. See helgrind/hg_intercepts.c.
This works on FreeBSD, which has the intercept. Should be easy to add for Linux.
commit 6ffb70e650ee7cf4ada829557dd30ababb09e078 Author: Paul Floyd <pjfloyd@wanadoo.fr> Date: Thu Dec 29 22:00:53 2022 +0100 Bug 400793 - pthread_rwlock_timedwrlock false positive Add Helgrind intercepts for pthread_rwlock_timedwrlock (and pthread_rwlock_timedrdlock) Reuse the DRD trylock test
Thanks for your fix but latest code from git still has the problem (test from attachment 116147 [details] from message above): [user@test-x64-alt8 helgrind_test]$ gcc t.c -o t -lpthread [user@test-x64-alt8 helgrind_test]$ /usr/bin/valgrind --tool=helgrind ./t ==11633== Helgrind, a thread error detector ==11633== Copyright (C) 2007-2017, and GNU GPL'd, by OpenWorks LLP et al. ==11633== Using Valgrind-3.21.0.GIT and LibVEX; rerun with -h for copyright info ==11633== Command: ./t ==11633== global_a = 1 global_a = 2 global_a = 3 global_a = 4 global_a = 5 global_a = 6 global_a = 7 global_a = 8 global_a = 9 global_a = a ==11633== ---Thread-Announcement------------------------------------------ ==11633== ==11633== Thread #13 was created ==11633== at 0x514B36E: clone (in /lib64/libc-2.23.so) ==11633== by 0x4E4C189: create_thread (in /lib64/libpthread-2.23.so) ==11633== by 0x4E4DBDB: pthread_create@@GLIBC_2.2.5 (in /lib64/libpthread-2.23.so) ==11633== by 0x4C387B2: pthread_create_WRK (hg_intercepts.c:445) ==11633== by 0x4C39CA2: pthread_create@* (hg_intercepts.c:478) ==11633== by 0x400AB7: main (in /root/helgrind_test/t) ==11633== ==11633== ---------------------------------------------------------------- ==11633== ==11633== Thread #13's call to pthread_rwlock_timedwrlock failed ==11633== with error code 110 (ETIMEDOUT: Connection timed out) ==11633== at 0x4C37AB5: pthread_rwlock_timedwrlock_WRK (hg_intercepts.c:2814) ==11633== by 0x4C3A5FA: pthread_rwlock_timedwrlock (hg_intercepts.c:2826) ==11633== by 0x4009B1: ten_seconds_wrlock (in /root/helgrind_test/t) ==11633== by 0x4009C9: threadFuncSimple (in /root/helgrind_test/t) ==11633== by 0x4C389A6: mythread_wrapper (hg_intercepts.c:406) ==11633== by 0x4E4D413: start_thread (in /lib64/libpthread-2.23.so) ==11633== Can't lock ==11633== ---Thread-Announcement------------------------------------------ ==11633== ==11633== Thread #14 was created ==11633== at 0x514B36E: clone (in /lib64/libc-2.23.so) ==11633== by 0x4E4C189: create_thread (in /lib64/libpthread-2.23.so) ==11633== by 0x4E4DBDB: pthread_create@@GLIBC_2.2.5 (in /lib64/libpthread-2.23.so) ==11633== by 0x4C387B2: pthread_create_WRK (hg_intercepts.c:445) ==11633== by 0x4C39CA2: pthread_create@* (hg_intercepts.c:478) ==11633== by 0x400AB7: main (in /root/helgrind_test/t) ==11633== ==11633== ---------------------------------------------------------------- ==11633== ==11633== Thread #14's call to pthread_rwlock_timedwrlock failed ==11633== with error code 110 (ETIMEDOUT: Connection timed out) ==11633== at 0x4C37AB5: pthread_rwlock_timedwrlock_WRK (hg_intercepts.c:2814) ==11633== by 0x4C3A5FA: pthread_rwlock_timedwrlock (hg_intercepts.c:2826) ==11633== by 0x4009B1: ten_seconds_wrlock (in /root/helgrind_test/t) ==11633== by 0x4009C9: threadFuncSimple (in /root/helgrind_test/t) ==11633== by 0x4C389A6: mythread_wrapper (hg_intercepts.c:406) ==11633== by 0x4E4D413: start_thread (in /lib64/libpthread-2.23.so) ==11633== Can't lock ==11633== ---Thread-Announcement------------------------------------------ ==11633== ==11633== Thread #15 was created ==11633== at 0x514B36E: clone (in /lib64/libc-2.23.so) ==11633== by 0x4E4C189: create_thread (in /lib64/libpthread-2.23.so) ==11633== by 0x4E4DBDB: pthread_create@@GLIBC_2.2.5 (in /lib64/libpthread-2.23.so) ==11633== by 0x4C387B2: pthread_create_WRK (hg_intercepts.c:445) ==11633== by 0x4C39CA2: pthread_create@* (hg_intercepts.c:478) ==11633== by 0x400AB7: main (in /root/helgrind_test/t) ==11633== ==11633== ---------------------------------------------------------------- ==11633== ==11633== Thread #15's call to pthread_rwlock_timedwrlock failed ==11633== with error code 110 (ETIMEDOUT: Connection timed out) ==11633== at 0x4C37AB5: pthread_rwlock_timedwrlock_WRK (hg_intercepts.c:2814) ==11633== by 0x4C3A5FA: pthread_rwlock_timedwrlock (hg_intercepts.c:2826) ==11633== by 0x4009B1: ten_seconds_wrlock (in /root/helgrind_test/t) ==11633== by 0x4009C9: threadFuncSimple (in /root/helgrind_test/t) ==11633== by 0x4C389A6: mythread_wrapper (hg_intercepts.c:406) ==11633== by 0x4E4D413: start_thread (in /lib64/libpthread-2.23.so) ==11633== Can't lock ==11633== ---Thread-Announcement------------------------------------------ ==11633== ==11633== Thread #16 was created ==11633== at 0x514B36E: clone (in /lib64/libc-2.23.so) ==11633== by 0x4E4C189: create_thread (in /lib64/libpthread-2.23.so) ==11633== by 0x4E4DBDB: pthread_create@@GLIBC_2.2.5 (in /lib64/libpthread-2.23.so) ==11633== by 0x4C387B2: pthread_create_WRK (hg_intercepts.c:445) ==11633== by 0x4C39CA2: pthread_create@* (hg_intercepts.c:478) ==11633== by 0x400AB7: main (in /root/helgrind_test/t) ==11633== ==11633== ---------------------------------------------------------------- ==11633== ==11633== Thread #16's call to pthread_rwlock_timedwrlock failed ==11633== with error code 110 (ETIMEDOUT: Connection timed out) ==11633== at 0x4C37AB5: pthread_rwlock_timedwrlock_WRK (hg_intercepts.c:2814) ==11633== by 0x4C3A5FA: pthread_rwlock_timedwrlock (hg_intercepts.c:2826) ==11633== by 0x4009B1: ten_seconds_wrlock (in /root/helgrind_test/t) ==11633== by 0x4009C9: threadFuncSimple (in /root/helgrind_test/t) ==11633== by 0x4C389A6: mythread_wrapper (hg_intercepts.c:406) ==11633== by 0x4E4D413: start_thread (in /lib64/libpthread-2.23.so) ==11633== Can't lock ==11633== ---Thread-Announcement------------------------------------------ ==11633== ==11633== Thread #17 was created ==11633== at 0x514B36E: clone (in /lib64/libc-2.23.so) ==11633== by 0x4E4C189: create_thread (in /lib64/libpthread-2.23.so) ==11633== by 0x4E4DBDB: pthread_create@@GLIBC_2.2.5 (in /lib64/libpthread-2.23.so) ==11633== by 0x4C387B2: pthread_create_WRK (hg_intercepts.c:445) ==11633== by 0x4C39CA2: pthread_create@* (hg_intercepts.c:478) ==11633== by 0x400AB7: main (in /root/helgrind_test/t) ==11633== ==11633== ---------------------------------------------------------------- ==11633== ==11633== Thread #17's call to pthread_rwlock_timedwrlock failed ==11633== with error code 110 (ETIMEDOUT: Connection timed out) ==11633== at 0x4C37AB5: pthread_rwlock_timedwrlock_WRK (hg_intercepts.c:2814) ==11633== by 0x4C3A5FA: pthread_rwlock_timedwrlock (hg_intercepts.c:2826) ==11633== by 0x4009B1: ten_seconds_wrlock (in /root/helgrind_test/t) ==11633== by 0x4009C9: threadFuncSimple (in /root/helgrind_test/t) ==11633== by 0x4C389A6: mythread_wrapper (hg_intercepts.c:406) ==11633== by 0x4E4D413: start_thread (in /lib64/libpthread-2.23.so) ==11633== Can't lock global_a = b ==11633== ==11633== Use --history-level=approx or =none to gain increased speed, at ==11633== the cost of reduced accuracy of conflicting-access information ==11633== For lists of detected and suppressed errors, rerun with: -s ==11633== ERROR SUMMARY: 5 errors from 5 contexts (suppressed: 430 from 55)
That's how Helgrind works. The original problem (missing intercepts) was fixed. If you think that Helgrind shouldn't report timeouts, please open a separate bugzilla item.