Re: [Boost-users] [thread] Mysterious deadlock

From: Andrew Smith (absmith_at_[hidden])
Date: 2006-02-09 18:17:18

I haven't looked at the code very closely, but it looks like there's a
potential for deadlock in the Consumer's wait_for_data and push methods.
Here is the scenario (in hypothetical deadlock time order.)

1. consumer thread in wait_for_data(): acquires full_mutex, calls empty()
2. producer thread in push(): called by Producer, acquires mutex
3. consumer thread in wait_for_data()'s call to empty(): attempts to acquire
mutex, blocks on producer thread
4. producer thread in push(): attempts to acquire full_mutex, blocks on
consumer thread
5. neither thread can advance

As a general rule, interleaved acquistions like this of two or more
resources is fraught with peril.  If you want an unbounded queue (as it
appears in your code) it can be done with a single mutex and condition
variable.

Andrew

On 2/9/06, David Greene <greened_at_[hidden]> wrote:
>
> I have this simple testcase (below) which runs into deadlock (full
> run trace after the testcase):
>
> ...
> [Producer] Producer generated data 28
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 29
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Consumer] Signaled for data
> [Consumer] empty(): about to lock
> <<DEADLOCK>>
>
> The call to empty() by Consumer is after the first time
> it is woken up from full_condition.  So the deadlock
> occurs right when the consumer first attempts to grab
> some data.
>
> Is there something I'm not understanding about how
> mutexes and locks work in Boost.Thread?  I feel like
> I'm missing something obvious.  This comes out of a
> larger and more complicated program but I was able to
> isolate the mysterious (to me) behavior I'm seeing.
>
> I used to use LOG for debugging but I thought there might be
> some interaction between the queue mutex locks and the print
> mutex locks so I switched to the non-locking LOG_NOLCK but
> observed no change in behavior.
>
> Any help is greatly appreciated.
>
>                        -Dave
>
> ---------------------------------
> Testcase
>
> #include <iostream>
> #include <queue>
> #include <map>
> #include <string>
>
> #include <boost/thread.hpp>
> #include <boost/thread/recursive_mutex.hpp>
> #include <boost/thread/condition.hpp>
> #include <boost/bind.hpp>
>
> #include <pthread.h>
>
> typedef boost::recursive_mutex mutex_type;
> typedef mutex_type::scoped_lock lock_type;
>
> // Atomic prints
> mutex_type print_mutex;
> mutex_type print_map_mutex;
>
> // For print/debug purposes
> typedef std::map<pthread_t, std::string> thread_map_type;
> thread_map_type thread_map;
>
> template<typename T>
> void register_thread_id(const T &entity)
> {
>    lock_type lock(print_map_mutex);
>    std::cout << "Registering " << pthread_self() << " to " << entity.name
> ()
>              << std::endl;
>    thread_map[pthread_self()] = entity.name();
> }
>
> #define LOG(msg)                                  \
> {                                                 \
>    lock_type lock(print_mutex);                   \
>    std::cout << "[" << thread_map[pthread_self()] \
>              << "] " << msg << std::endl;         \
> }
>
> #define LOG_NOLCK(msg)                            \
> {                                                 \
>    std::cout << "[" << thread_map[pthread_self()] \
>              << "] " << msg << std::endl;         \
> }
>
> // Synchronize start (make sure all registered)
> mutex_type go_mutex;
> boost::condition go_condition;
>
> bool ready = false;
>
>
> class Consumer {
>    private:
>       boost::thread thread;
>
>       std::queue<int> queue;
>
>       typedef boost::recursive_mutex mutex_type;
>       typedef mutex_type::scoped_lock lock_type;
>
>       mutable mutex_type mutex;
>       mutable mutex_type full_mutex;
>
>       mutable boost::condition full_condition;
>
>       void wait_until_ready(void) const {
>          ::lock_type lock(go_mutex);
>
>          while(!ready) {
>             go_condition.wait(lock);
>          }
>          LOG_NOLCK("go!");
>       };
>
>       void wait_for_data(void) const {
>          lock_type lock(full_mutex);
>          while(empty()) {
>             LOG_NOLCK("Waiting for data");
>             full_condition.wait(lock);
>             LOG_NOLCK("Signaled for data");
>          }
>          LOG_NOLCK("Wakeup for data");
>       };
>
>       void event_loop(void) {
>          register_thread_id(*this);
>          wait_until_ready();
>
>          while(true) {
>             wait_for_data();
>             LOG_NOLCK("Consumer received data " << top());
>             pop();
>          }
>       };
>
>    public:
>       Consumer(void) : thread(boost::bind(&Consumer::event_loop, this))
> {};
>
>       std::string name(void) const { return("Consumer"); };
>
>       void push(int val) {
>          LOG_NOLCK("push(): about to lock");
>          {
>             lock_type lock(mutex);
>             LOG_NOLCK("push(): locked");
>             queue.push(val);
>
>             lock_type full_lock(full_mutex);
>             LOG_NOLCK("push(): about to unlock");
>          }
>          full_condition.notify_all();
>       };
>
>       int top(void) const {
>          LOG_NOLCK("top(): about to lock");
>          lock_type lock(mutex);
>          LOG_NOLCK("top(): locked");
>          int item = queue.front();
>          LOG_NOLCK("top(): about to unlock");
>          return(item);
>       };
>
>       void pop(void) {
>          LOG_NOLCK("pop(): about to lock");
>          lock_type lock(mutex);
>          LOG_NOLCK("pop(): locked");
>          queue.pop();
>          LOG_NOLCK("pop(): about to unlock");
>       };
>
>       bool empty (void) const {
>          LOG_NOLCK("empty(): about to lock");
>          lock_type lock(mutex);
>          LOG_NOLCK("empty(): locked");
>          bool val = queue.empty();
>          LOG_NOLCK("empty(): about to unlock");
>          return(val);
>       };
> };
>
> class Producer {
>    private:
>       boost::thread thread;
>
>       void wait_until_ready(void) const {
>          lock_type lock(go_mutex);
>
>          while(!ready) {
>             go_condition.wait(lock);
>          }
>          LOG_NOLCK("go!");
>       };
>
>       void event_loop(void) {
>          int i = 0;
>
>          register_thread_id(*this);
>          wait_until_ready();
>
>          while(true) {
>             LOG_NOLCK("Producer generated data " << i);
>             consumer->push(i);
>             ++i;
>          };
>       };
>
>       Consumer *consumer;
>
>    public:
>       Producer(Consumer *c) : consumer(c),
>                               thread(boost::bind(&Producer::event_loop,
> this)) {};
>
>       std::string name(void) const { return("Producer"); };
> };
>
> void go(void)
> {
>    // Wait until everyone arrives
>    lock_type lock(go_mutex);
>    ready = true;
>
>    // Notify everyone
>    go_condition.notify_all();
> }
>
> int main(void)
> {
>    Consumer c;
>    Producer p(&c);
>
>    go();
>
>    while(true);
>
>    return(0);
> }
>
> -----------------
> Ouput Trace
>
> [Consumer] empty(): about to unlock
> [Consumer] Waiting for data
> Registering 48958384 to Producer
> [Producer] go!
> [Producer] Producer generated data 0
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 1
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 2
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 3
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 4
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 5
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 6
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 7
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 8
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 9
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 10
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 11
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 12
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 13
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 14
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 15
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 16
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 17
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 18
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 19
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 20
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 21
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 22
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 23
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 24
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 25
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 26
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 27
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 28
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Producer] push(): about to unlock
> [Producer] Producer generated data 29
> [Producer] push(): about to lock
> [Producer] push(): locked
> [Consumer] Signaled for data
> [Consumer] empty(): about to lock
> <<DEADLOCK>>
> _______________________________________________
> Boost-users mailing list
> Boost-users_at_[hidden]
> http://lists.boost.org/mailman/listinfo.cgi/boost-users
>