[Boost-users] thread lock-guard race condition

Subject: [Boost-users] thread lock-guard race condition
From: Kraus Philipp (philipp.kraus_at_[hidden])
Date: 2010-11-24 11:05:43

Hello,

I have written this little example:

boost::mutex mutex;

void thread()
{
     for (int i = 0; i < 5; ++i)
     {
         boost::this_thread::sleep(boost::posix_time::seconds(3));
         boost::lock_guard<boost::mutex> lock(mutex);
         std::cout << "Thread " << boost::this_thread::get_id() << ":  
" << i << std::endl;
     }
}

int main(int argc, char *argv[]) {
     boost::thread t1(thread);
     boost::thread t2(thread);
     t1.join();
     t2.join();
}

I compile the code with pthread option on the gcc (4.0.1). In the  
first case the program works, but if I use the helgrind tool of  
valgrind I'll get this errors (sorry for the long messages).
I would like to understand what I have done wrong. I hope I understand  
the lock_guard in the correct way: If I create the lock with the mutex  
variable the thread, that creates the lock runs down the next lines.  
All other threads that run into the lock_guard line blocks until the  
lock variable of the first thread call the destructor (which should be  
on every loop iteration).

Thanks for help

Phil

------Valgrind Logs-----------

==19846== Thread #1 is the program's root thread

==19846== Thread #3 & #2 was created
==19846==    at 0x15A1FDE: __bsdthread_create (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x378F4: pthread_create_WRK (hg_intercepts.c:257)
==19846==    by 0x379C8: pthread_create (hg_intercepts.c:294)
==19846==    by 0x55C06: boost::thread::start_thread() (in  
libboost_thread.dylib)
==19846==    by 0x9FED: boost::thread::thread<void (*)()>(void (*)(),  
boost::disable_if<boost::is_convertible<void (*&)(),  
boost::detail::thread_move_t<void (*)()> >,  
boost::thread::dummy*>::type) (in ./main)
==19846==    by 0x2A82: main (in ./main)

This message is show for thread #1, #2 and #3

==19846== Possible data race during read of size 4 at 0x5e008 by  
thread #3
==19846==    at 0x56381: void boost::call_once<void (*) 
()>(boost::once_flag&, void (*)()) (in libboost_thread.dylib)
==19846==    by 0x545AC: thread_proxy (in libboost_thread.dylib)
==19846==    by 0x37828: mythread_wrapper (hg_intercepts.c:221)
==19846==    by 0x15A2154: _pthread_start (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x15A2011: thread_start (in /usr/lib/libSystem.B.dylib)
==19846==  This conflicts with a previous write of size 4 by thread #2
==19846==    at 0x5647F: void boost::call_once<void (*) 
()>(boost::once_flag&, void (*)()) (in /libboost_thread.dylib)
==19846==    by 0x545AC: thread_proxy (in /libboost_thread.dylib)
==19846==    by 0x37828: mythread_wrapper (hg_intercepts.c:221)
==19846==    by 0x15A2154: _pthread_start (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x15A2011: thread_start (in /usr/lib/libSystem.B.dylib)

==19846== Thread #2: Bug in libpthread: recursive write lock granted  
on mutex/wrlock which does not support recursion
==19846==    at 0x385D2: pthread_cond_timedwait_WRK (hg_intercepts.c: 
764)
==19846==    by 0x386B0: pthread_cond_timedwait$* (hg_intercepts.c:798)
==19846==    by 0x5AABB:  
boost 
::condition_variable::timed_wait(boost::unique_lock<boost::mutex>&,  
boost::posix_time::ptime const&) (in libboost_thread.dylib)
==19846==    by 0x54DC5:  
boost::this_thread::sleep(boost::posix_time::ptime const&) (in  
libboost_thread.dylib)
==19846==    by 0xEE31: void  
boost 
::this_thread 
::sleep<boost::posix_time::seconds>(boost::posix_time::seconds const&)  
(in ./main)
==19846==    by 0x23F8: thread() (in ./main)
==19846==    by 0x545CC: thread_proxy (in libboost_thread.dylib)
==19846==    by 0x37828: mythread_wrapper (hg_intercepts.c:221)
==19846==    by 0x15A2154: _pthread_start (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x15A2011: thread_start (in /usr/lib/libSystem.B.dylib)

The next message is shown for the thread #2 & #3

==19846== Thread #3: lock order "0x2500668 before 0x25005C8" violated
==19846==    at 0x37E1B: pthread_mutex_lock (hg_intercepts.c:496)
==19846==    by 0x5ABA3:  
boost 
::condition_variable::timed_wait(boost::unique_lock<boost::mutex>&,  
boost::posix_time::ptime const&) (in libboost_thread.dylib)
==19846==    by 0x54DC5:  
boost::this_thread::sleep(boost::posix_time::ptime const&) (in  
libboost_thread.dylib)
==19846==    by 0xEE31: void  
boost 
::this_thread 
::sleep<boost::posix_time::seconds>(boost::posix_time::seconds const&)  
(in ./main)
==19846==    by 0x23F8: thread() (in ./main)
==19846==    by 0x545CC: thread_proxy (in libboost_thread.dylib)
==19846==    by 0x37828: mythread_wrapper (hg_intercepts.c:221)
==19846==    by 0x15A2154: _pthread_start (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x15A2011: thread_start (in /usr/lib/libSystem.B.dylib)
==19846==   Required order was established by acquisition of lock at  
0x2500668
==19846==    at 0x37E1B: pthread_mutex_lock (hg_intercepts.c:496)
==19846==    by 0x15A3452: _pthread_cond_wait (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x15C89F7: pthread_cond_timedwait$UNIX2003 (in /usr/ 
lib/libSystem.B.dylib)
==19846==    by 0x38575: pthread_cond_timedwait_WRK (hg_intercepts.c: 
760)
==19846==    by 0x386B0: pthread_cond_timedwait$* (hg_intercepts.c:798)
==19846==    by 0x5AABB:  
boost 
::condition_variable::timed_wait(boost::unique_lock<boost::mutex>&,  
boost::posix_time::ptime const&) (in libboost_thread.dylib)
==19846==    by 0x54DC5:  
boost::this_thread::sleep(boost::posix_time::ptime const&) (in  
libboost_thread.dylib)
==19846==    by 0xEE31: void  
boost 
::this_thread 
::sleep<boost::posix_time::seconds>(boost::posix_time::seconds const&)  
(in ./main)
==19846==    by 0x23F8: thread() (in ./main)
==19846==    by 0x545CC: thread_proxy (in libboost_thread.dylib)
==19846==    by 0x37828: mythread_wrapper (hg_intercepts.c:221)
==19846==    by 0x15A2154: _pthread_start (in /usr/lib/ 
libSystem.B.dylib)
==19846==   followed by a later acquisition of lock at 0x25005C8
==19846==    at 0x37E1B: pthread_mutex_lock (hg_intercepts.c:496)
==19846==    by 0x53E6A: boost::this_thread::interruption_point() (in  
libboost_thread.dylib)
==19846==    by 0x5AAC2:  
boost 
::condition_variable::timed_wait(boost::unique_lock<boost::mutex>&,  
boost::posix_time::ptime const&) (in /libboost_thread.dylib)
==19846==    by 0x54DC5:  
boost::this_thread::sleep(boost::posix_time::ptime const&) (in  
libboost_thread.dylib)
==19846==    by 0xEE31: void  
boost 
::this_thread 
::sleep<boost::posix_time::seconds>(boost::posix_time::seconds const&)  
(in ./main)
==19846==    by 0x23F8: thread() (in ./main)
==19846==    by 0x545CC: thread_proxy (in libboost_thread.dylib)
==19846==    by 0x37828: mythread_wrapper (hg_intercepts.c:221)
==19846==    by 0x15A2154: _pthread_start (in /usr/lib/ 
libSystem.B.dylib)
==19846==    by 0x15A2011: thread_start (in /usr/lib/libSystem.B.dylib)