Assertion on mutex when using multiple threads and mutexes

Question

As a part of a project I'm writing a logger function. This logger function sends an e-mail when the program wants to log something. Since it has happened that the SMTP server was non responsive, I've decided to do the sending of the mails in a separate thread. This thread reads messages from an std::deque which is filled by the logging function. The thread is setup as follows:

while (!boost::this_thread::interruption_requested())
{
  EmailItem emailItem;
  {
    boost::unique_lock<boost::mutex> lock(mMutex);
    while (mEmailBuffer.empty())
      mCond.wait(lock);

    bufferOverflow = mBufferOverflow;
    mBufferOverflow = false;
    nrOfItems = mEmailBuffer.size();

    if (nrOfItems > 0)
    {
      emailItem = mEmailBuffer.front();
      mEmailBuffer.pop_front();
    }
  }

  if (nrOfItems > 0)
  {
      bool sent = false;
      while(!sent)
      {
          try
          {
             ..... Do something with the message .....
            {
                boost::this_thread::disable_interruption di;
                boost::lock_guard<boost::mutex> lock(mLoggerMutex);
                mLogFile << emailItem.mMessage << std::endl;
            }
            sent = true;
          }
          catch (const std::exception &e)
          {
            // Unable to send mail, an exception occurred. Retry sending it after some time
            sent = false;
            boost::this_thread::sleep(boost::posix_time::seconds(LOG_WAITBEFORE_RETRY));
          }
      }
  }
}

The function log() adds a new message to the deque (mEmailBuffer) as follows:

{
  boost::lock_guard<boost::mutex> lock(mMutex);
  mEmailBuffer.push_back(e);
  mCond.notify_one();
}

When the main program exits, the destructor of the logger object is called. This is where it goes wrong, the application crashes with an error:

/usr/include/boost/thread/pthread/mutex.hpp:45: boost::mutex::~mutex(): Assertion `!pthread_mutex_destroy(&m)' failed.

The destructor merely calls an interrupt on the thread and then joins it:

mQueueThread.interrupt();
mQueueThread.join();

In the main program, I use multiple different classes which make use of boost threading and mutex as well, could this cause this behaviour? Not calling the destructor of the logger object results in no errors, as does using the logger object and not doing anything else.

My guess is I am doing something very wrong, or there is a bug in the threading library when using multiple threads divided over several classes. Does anyone have a idea what the reason for this error might be?

EDIT: I did as @Andy T proposed and stripped the code as much as possible. I removed nearly everything in the function which is ran in a different thread. The thread now looks like:

void Vi::Logger::ThreadedQueue()
{
  bool bufferOverflow = false;
  time_t last_overflow = 0;
  unsigned int nrOfItems = 0;

  while (!boost::this_thread::interruption_requested())
  {
    EmailItem emailItem;
    // Check for new log entries
    {
      boost::unique_lock<boost::mutex> lock(mMutex);
      while (mEmailBuffer.empty())
        mCond.wait(lock);
    }
  }
}

The problem still persists. Backtracking of the problem however showed me something different from the initial code:

#0  0x00007ffff53e9ba5 in raise (sig=<value optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x00007ffff53ed6b0 in abort () at abort.c:92
#2  0x00007ffff53e2a71 in __assert_fail (assertion=0x7ffff7bb6407 "!pthread_mutex_lock(&m)", file=<value optimized out>, line=50, function=0x7ffff7bb7130 "void boost::mutex::lock()") at assert.c:81
#3  0x00007ffff7b930f3 in boost::mutex::lock (this=0x7fffe2c1b0b8) at /usr/include/boost/thread/pthread/mutex.hpp:50
#4  0x00007ffff7b9596c in boost::unique_lock<boost::mutex>::lock (this=0x7fffe48b3b40) at /usr/include/boost/thread/locks.hpp:349
#5  0x00007ffff7b958db in boost::unique_lock<boost::mutex>::unique_lock (this=0x7fffe48b3b40, m_=...) at /usr/include/boost/thread/locks.hpp:227
#6  0x00007ffff6ac2bb7 in Vi::Logger::ThreadedQueue (this=0x7fffe2c1ade0) at /data/repos_ViNotion/stdcomp/Logging/trunk/src/Logger.cpp:198
#7  0x00007ffff6acf2b2 in boost::_mfi::mf0<void, Vi::Logger>::operator() (this=0x7fffe2c1d890, p=0x7fffe2c1ade0) at /usr/include/boost/bind/mem_fn_template.hpp:49
#8  0x00007ffff6acf222 in boost::_bi::list1<boost::_bi::value<Vi::Logger*> >::operator()<boost::_mfi::mf0<void, Vi::Logger>, boost::_bi::list0> (this=0x7fffe2c1d8a0, f=..., a=...) at /usr/include/boost/bind/bind.hpp:253
#9  0x00007ffff6acf1bd in boost::_bi::bind_t<void, boost::_mfi::mf0<void, Vi::Logger>, boost::_bi::list1<boost::_bi::value<Vi::Logger*> > >::operator() (this=0x7fffe2c1d890) at /usr/include/boost/bind/bind_template.hpp:20
#10 0x00007ffff6aceff2 in boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf0<void, Vi::Logger>, boost::_bi::list1<boost::_bi::value<Vi::Logger*> > > >::run (this=0x7fffe2c1d760)
    at /usr/include/boost/thread/detail/thread.hpp:56
#11 0x00007ffff2cc5230 in thread_proxy () from /usr/lib/libboost_thread.so.1.42.0
#12 0x00007ffff4d87971 in start_thread (arg=<value optimized out>) at pthread_create.c:304
#13 0x00007ffff549c92d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#14 0x0000000000000000 in ?? ()

Might it be possible that mMutex is not unlocked in the combination of using an unique_lock() and then interrupting the thread?

Answer 1

do you join your thread before exiting? as tyz suggested, your thread can still keep it locked when mutex is destroyed.

[EDIT]

you didn't provide complete example that can be compiled and run, it's hard to help w/o it.

check this simple example that should be similar to your one:

#include <boost/thread.hpp>
#include <boost/bind.hpp>
#include <queue>

class Test
{
public:
    Test()
    {
        thread = boost::thread(boost::bind(&Test::thread_func, this));
    }

    ~Test()
    {
        thread.interrupt();
        thread.join();
    }

    void run()
    {
        for (size_t i = 0; i != 10000; ++i) {
            boost::lock_guard<boost::mutex> lock(mutex);
            queue.push(i);
            condition_var.notify_one();
        }
    }

private:
    void thread_func()
    {
        while (!boost::this_thread::interruption_requested())
        {
            {
                boost::unique_lock<boost::mutex> lock(mutex);
                while (queue.empty())
                    condition_var.wait(lock);
                queue.pop();
            }
        }
    }

private:
    boost::thread thread;
    boost::mutex mutex;
    boost::condition_variable condition_var;
    std::queue<int> queue;
};

int main()
{
    Test test;
    test.run();

    return 0;
}

compare with your case

Answer 2

You should unlock mutex before you delete it.