From 7d0389956e5e6ff182fdf4c2a3a9f8a202a927d4 Mon Sep 17 00:00:00 2001 From: Paul Floyd Date: Sun, 25 Dec 2022 21:43:36 +0100 Subject: [PATCH] Bug 392331 - Spurious lock not held error from inside pthread_cond_timedwait Added a "Dubious" error category to cover this kind of error. --- .gitignore | 1 + NEWS | 1 + helgrind/hg_errors.c | 74 +++++++++++++++++++++++- helgrind/hg_errors.h | 5 ++ helgrind/hg_main.c | 2 +- helgrind/tests/Makefile.am | 7 +++ helgrind/tests/bug392331.cpp | 58 +++++++++++++++++++ helgrind/tests/bug392331.stderr.exp | 31 ++++++++++ helgrind/tests/bug392331.stdout.exp | 4 ++ helgrind/tests/bug392331.suppr | 7 +++ helgrind/tests/bug392331.vgtest | 2 + helgrind/tests/bug392331_supp.stderr.exp | 0 helgrind/tests/bug392331_supp.stdout.exp | 4 ++ helgrind/tests/bug392331_supp.vgtest | 2 + 14 files changed, 195 insertions(+), 3 deletions(-) create mode 100644 helgrind/tests/bug392331.cpp create mode 100644 helgrind/tests/bug392331.stderr.exp create mode 100644 helgrind/tests/bug392331.stdout.exp create mode 100644 helgrind/tests/bug392331.suppr create mode 100644 helgrind/tests/bug392331.vgtest create mode 100644 helgrind/tests/bug392331_supp.stderr.exp create mode 100644 helgrind/tests/bug392331_supp.stdout.exp create mode 100644 helgrind/tests/bug392331_supp.vgtest diff --git a/.gitignore b/.gitignore index a72b1dcae..20282b8a2 100644 --- a/.gitignore +++ b/.gitignore @@ -653,6 +653,7 @@ /helgrind/tests/bar_bad /helgrind/tests/bar_trivial /helgrind/tests/bug322621 +/helgrind/tests/bug392331 /helgrind/tests/cond_init_destroy /helgrind/tests/cond_timedwait_invalid /helgrind/tests/cond_timedwait_test diff --git a/NEWS b/NEWS index e1befb56f..b538ad524 100644 --- a/NEWS +++ b/NEWS @@ -24,6 +24,7 @@ are not entered into bugzilla tend to get forgotten about or ignored. 170510 Don't warn about ioctl of size 0 without direction hint 351857 confusing error message about valid command line option +392331 Spurious lock not held error from inside pthread_cond_timedwait 444110 priv/guest_ppc_toIR.c:36198:31: warning: duplicated 'if' condition. 444488 Use glibc.pthread.stack_cache_size tunable 444568 drd/tests/pth_barrier_thr_cr fails on Fedora 38 diff --git a/helgrind/hg_errors.c b/helgrind/hg_errors.c index e612449b5..638739dc6 100644 --- a/helgrind/hg_errors.c +++ b/helgrind/hg_errors.c @@ -293,7 +293,9 @@ typedef XE_UnlockBogus, // unlocking an address not known to be a lock XE_PthAPIerror, // error from the POSIX pthreads API XE_LockOrder, // lock order error - XE_Misc // misc other error (w/ string to describe it) + XE_Misc, // misc other error (w/ string to describe it) + XE_Dubious // a bit like misc for cases where the POSIX + // spec is unclear on error conditons } XErrorTag; @@ -381,7 +383,8 @@ typedef XS_UnlockBogus, XS_PthAPIerror, XS_LockOrder, - XS_Misc + XS_Misc, + XS_Dubious } XSuppTag; @@ -654,6 +657,30 @@ void HG_(record_error_Misc) ( Thread* thr, const HChar* errstr ) HG_(record_error_Misc_w_aux)(thr, errstr, NULL, NULL); } +void HG_(record_error_Dubious_w_aux) ( Thread* thr, const HChar* errstr, + const HChar* auxstr, ExeContext* auxctx ) +{ + XError xe; + tl_assert( HG_(is_sane_Thread)(thr) ); + tl_assert(errstr); + init_XError(&xe); + xe.tag = XE_Dubious; + xe.XE.Misc.thr = thr; + xe.XE.Misc.errstr = string_table_strdup(errstr); + xe.XE.Misc.auxstr = auxstr ? string_table_strdup(auxstr) : NULL; + xe.XE.Misc.auxctx = auxctx; + // FIXME: tid vs thr + tl_assert( HG_(is_sane_ThreadId)(thr->coretid) ); + tl_assert( thr->coretid != VG_INVALID_THREADID ); + VG_(maybe_record_error)( thr->coretid, + XE_Dubious, 0, NULL, &xe ); +} + +void HG_(record_error_Dubious) ( Thread* thr, const HChar* errstr ) +{ + HG_(record_error_Dubious_w_aux)(thr, errstr, NULL, NULL); +} + Bool HG_(eq_Error) ( VgRes not_used, const Error* e1, const Error* e2 ) { XError *xe1, *xe2; @@ -692,6 +719,9 @@ Bool HG_(eq_Error) ( VgRes not_used, const Error* e1, const Error* e2 ) case XE_Misc: return xe1->XE.Misc.thr == xe2->XE.Misc.thr && 0==VG_(strcmp)(xe1->XE.Misc.errstr, xe2->XE.Misc.errstr); + case XE_Dubious: + return xe1->XE.Misc.thr == xe2->XE.Misc.thr + && 0==VG_(strcmp)(xe1->XE.Misc.errstr, xe2->XE.Misc.errstr); default: tl_assert(0); } @@ -872,6 +902,9 @@ void HG_(before_pp_Error) ( const Error* err ) tl_assert(xe); switch (VG_(get_error_kind)(err)) { + case XE_Dubious: + announce_one_thread( xe->XE.Misc.thr ); + break; case XE_Misc: announce_one_thread( xe->XE.Misc.thr ); break; @@ -931,6 +964,40 @@ void HG_(pp_Error) ( const Error* err ) emit( " %s\n", HG_(get_error_name)(err)); switch (VG_(get_error_kind)(err)) { + case XE_Dubious: { + tl_assert( HG_(is_sane_Thread)( xe->XE.Misc.thr ) ); + + if (xml) { + + emit( " \n" ); + emit( " Thread #%d: %s\n", + (Int)xe->XE.Misc.thr->errmsg_index, + xe->XE.Misc.errstr ); + emit( " %d\n", + (Int)xe->XE.Misc.thr->errmsg_index ); + emit( " \n" ); + VG_(pp_ExeContext)( VG_(get_error_where)(err) ); + if (xe->XE.Misc.auxstr) { + emit(" %s\n", xe->XE.Misc.auxstr); + if (xe->XE.Misc.auxctx) + VG_(pp_ExeContext)( xe->XE.Misc.auxctx ); + } + + } else { + + emit( "Thread #%d: %s\n", + (Int)xe->XE.Misc.thr->errmsg_index, + xe->XE.Misc.errstr ); + VG_(pp_ExeContext)( VG_(get_error_where)(err) ); + if (xe->XE.Misc.auxstr) { + emit(" %s\n", xe->XE.Misc.auxstr); + if (xe->XE.Misc.auxctx) + VG_(pp_ExeContext)( xe->XE.Misc.auxctx ); + } + + } + break; + } case XE_Misc: { tl_assert( HG_(is_sane_Thread)( xe->XE.Misc.thr ) ); @@ -1325,6 +1392,7 @@ const HChar* HG_(get_error_name) ( const Error* err ) case XE_PthAPIerror: return "PthAPIerror"; case XE_LockOrder: return "LockOrder"; case XE_Misc: return "Misc"; + case XE_Dubious: return "Dubious"; default: tl_assert(0); /* fill in missing case */ } } @@ -1344,6 +1412,7 @@ Bool HG_(recognised_suppression) ( const HChar* name, Supp *su ) TRY("PthAPIerror", XS_PthAPIerror); TRY("LockOrder", XS_LockOrder); TRY("Misc", XS_Misc); + TRY("Dubious", XS_Dubious); return False; # undef TRY } @@ -1366,6 +1435,7 @@ Bool HG_(error_matches_suppression) ( const Error* err, const Supp* su ) case XS_PthAPIerror: return VG_(get_error_kind)(err) == XE_PthAPIerror; case XS_LockOrder: return VG_(get_error_kind)(err) == XE_LockOrder; case XS_Misc: return VG_(get_error_kind)(err) == XE_Misc; + case XS_Dubious: return VG_(get_error_kind)(err) == XE_Dubious; //case XS_: return VG_(get_error_kind)(err) == XE_; default: tl_assert(0); /* fill in missing cases */ } diff --git a/helgrind/hg_errors.h b/helgrind/hg_errors.h index 08191e1b3..5824151c9 100644 --- a/helgrind/hg_errors.h +++ b/helgrind/hg_errors.h @@ -78,6 +78,11 @@ void HG_(record_error_Misc_w_aux) ( Thread*, const HChar* errstr, ExeContext* auxctx ); void HG_(record_error_Misc) ( Thread* thr, const HChar* errstr ); +void HG_(record_error_Dubious_w_aux) ( Thread*, const HChar* errstr, + const HChar* auxstr, + ExeContext* auxctx ); +void HG_(record_error_Dubious) ( Thread* thr, const HChar* errstr ); + /* Statistics pertaining to error management. */ extern ULong HG_(stats__LockN_to_P_queries); diff --git a/helgrind/hg_main.c b/helgrind/hg_main.c index 490fc38fe..813c983a4 100644 --- a/helgrind/hg_main.c +++ b/helgrind/hg_main.c @@ -2448,7 +2448,7 @@ static void evh__HG_PTHREAD_COND_SIGNAL_PRE ( ThreadId tid, void* cond ) "pthread_cond_{signal,broadcast}: associated lock is a rwlock"); } if (lk->heldBy == NULL) { - HG_(record_error_Misc)(thr, + HG_(record_error_Dubious)(thr, "pthread_cond_{signal,broadcast}: dubious: " "associated lock is not held by any thread"); } diff --git a/helgrind/tests/Makefile.am b/helgrind/tests/Makefile.am index 05e145f7b..926a367c7 100755 --- a/helgrind/tests/Makefile.am +++ b/helgrind/tests/Makefile.am @@ -16,6 +16,9 @@ EXTRA_DIST = \ annotate_smart_pointer.vgtest annotate_smart_pointer.stdout.exp \ annotate_smart_pointer.stderr.exp \ bug322621.vgtest bug322621.stderr.exp \ + bug392331.vgtest bug392331.stdout.exp bug392331.stderr.exp \ + bug392331_supp.vgtest bug392331_supp.stdout.exp bug392331_supp.stderr.exp \ + bug392331.supp \ cond_init_destroy.vgtest cond_init_destroy.stderr.exp \ cond_timedwait_invalid.vgtest cond_timedwait_invalid.stdout.exp \ cond_timedwait_invalid.stderr.exp \ @@ -139,6 +142,7 @@ noinst_HEADERS = safe-pthread.h safe-semaphore.h # should be conditionally compiled like tc20_verifywrap is. check_PROGRAMS = \ annotate_hbefore \ + bug392331 \ cond_init_destroy \ cond_timedwait_invalid \ cond_timedwait_test \ @@ -238,3 +242,6 @@ annotate_hbefore_CFLAGS = $(AM_CFLAGS) endif bug322621_SOURCES = bug322621.cpp +bug392331_SOURCES = bug392331.cpp +bug392331_CXXFLAGS = $(AM_CXXFLAGS) -std=c++17 + diff --git a/helgrind/tests/bug392331.cpp b/helgrind/tests/bug392331.cpp new file mode 100644 index 000000000..ff26883b7 --- /dev/null +++ b/helgrind/tests/bug392331.cpp @@ -0,0 +1,58 @@ +// For this Bugzilla item https://bugs.kde.org/show_bug.cgi?id=392331 +// Example from https://en.cppreference.com/w/cpp/thread/condition_variable + +#include +#include +#include +#include +#include + +std::mutex m; +std::condition_variable cv; +std::string data; +bool ready = false; +bool processed = false; + +void worker_thread() +{ + // Wait until main() sends data + std::unique_lock lk(m); + cv.wait(lk, []{return ready;}); + + // after the wait, we own the lock. + std::cout << "Worker thread is processing data\n"; + data += " after processing"; + + // Send data back to main() + processed = true; + std::cout << "Worker thread signals data processing completed\n"; + + // Manual unlocking is done before notifying, to avoid waking up + // the waiting thread only to block again (see notify_one for details) + lk.unlock(); + cv.notify_one(); +} + +int main() +{ + std::thread worker(worker_thread); + + data = "Example data"; + // send data to the worker thread + { + std::lock_guard lk(m); + ready = true; + std::cout << "main() signals data ready for processing\n"; + } + cv.notify_one(); + + // wait for the worker + { + std::unique_lock lk(m); + cv.wait(lk, []{return processed;}); + } + std::cout << "Back in main(), data = " << data << '\n'; + + worker.join(); +} + diff --git a/helgrind/tests/bug392331.stderr.exp b/helgrind/tests/bug392331.stderr.exp new file mode 100644 index 000000000..f278e3b08 --- /dev/null +++ b/helgrind/tests/bug392331.stderr.exp @@ -0,0 +1,31 @@ +---Thread-Announcement------------------------------------------ + +Thread #x is the program's root thread + +---------------------------------------------------------------- + +Thread #x: pthread_cond_{signal,broadcast}: dubious: associated lock is not held by any thread + at 0x........: pthread_cond_signal_WRK (hg_intercepts.c:...) + by 0x........: pthread_cond_signal (hg_intercepts.c:...) + ... + by 0x........: main (bug392331.cpp:47) + +---Thread-Announcement------------------------------------------ + +Thread #x was created + ... + by 0x........: pthread_create@* (hg_intercepts.c:...) + ... + by 0x........: main (bug392331.cpp:38) + +---------------------------------------------------------------- + +Thread #x: pthread_cond_{signal,broadcast}: dubious: associated lock is not held by any thread + at 0x........: pthread_cond_signal_WRK (hg_intercepts.c:...) + by 0x........: pthread_cond_signal (hg_intercepts.c:...) + ... + by 0x........: worker_thread() (bug392331.cpp:33) + ... + by 0x........: mythread_wrapper (hg_intercepts.c:...) + ... + diff --git a/helgrind/tests/bug392331.stdout.exp b/helgrind/tests/bug392331.stdout.exp new file mode 100644 index 000000000..4d6f703ee --- /dev/null +++ b/helgrind/tests/bug392331.stdout.exp @@ -0,0 +1,4 @@ +main() signals data ready for processing +Worker thread is processing data +Worker thread signals data processing completed +Back in main(), data = Example data after processing diff --git a/helgrind/tests/bug392331.suppr b/helgrind/tests/bug392331.suppr new file mode 100644 index 000000000..8262d142e --- /dev/null +++ b/helgrind/tests/bug392331.suppr @@ -0,0 +1,7 @@ +{ + Check that Dubious suppression works + Helgrind:Dubious + fun:pthread_cond_signal_WRK + fun:pthread_cond_signal + fun:_ZNSt3__118condition_variable10notify_oneEv +} diff --git a/helgrind/tests/bug392331.vgtest b/helgrind/tests/bug392331.vgtest new file mode 100644 index 000000000..6c4aff6bf --- /dev/null +++ b/helgrind/tests/bug392331.vgtest @@ -0,0 +1,2 @@ +vgopts: -q +prog: bug392331 diff --git a/helgrind/tests/bug392331_supp.stderr.exp b/helgrind/tests/bug392331_supp.stderr.exp new file mode 100644 index 000000000..e69de29bb diff --git a/helgrind/tests/bug392331_supp.stdout.exp b/helgrind/tests/bug392331_supp.stdout.exp new file mode 100644 index 000000000..4d6f703ee --- /dev/null +++ b/helgrind/tests/bug392331_supp.stdout.exp @@ -0,0 +1,4 @@ +main() signals data ready for processing +Worker thread is processing data +Worker thread signals data processing completed +Back in main(), data = Example data after processing diff --git a/helgrind/tests/bug392331_supp.vgtest b/helgrind/tests/bug392331_supp.vgtest new file mode 100644 index 000000000..8e0fc7a38 --- /dev/null +++ b/helgrind/tests/bug392331_supp.vgtest @@ -0,0 +1,2 @@ +vgopts: -q --suppressions=bug392331.suppr +prog: bug392331