Uploaded image for project: 'Qpid'
  1. Qpid
  2. QPID-2567

[c++] Timer - possible thread lock ordering violation

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 0.7
    • Fix Version/s: 0.17
    • Component/s: C++ Broker
    • Labels:
      None
    • Environment:

      RHEL-6 beta

      Description

      Starting the broker using valgrind and the helgrind thread check tool shows several lock order violations centered around the qpid::sys::Timer class.

      valgrind --tool=helgrind .libs/lt-qpidd --auth no --log-enable info+

      results in the following message (and others that are similar):

      ==31280== Thread #2: lock order "0x597D548 before 0x59AE350" violated
      ==31280== at 0x4A0679C: pthread_mutex_lock (hg_intercepts.c:464)
      ==31280== by 0x4E8C27B: qpid::sys::Mutex::lock() (Mutex.h:116)
      ==31280== by 0x4E8CD82: qpid::sys::ScopedLock<qpid::sys::Mutex>::ScopedLock(qpid::sys::Mutex&) (Mutex.h:33)
      ==31280== by 0x56346FF: qpid::sys::Timer::add(boost::intrusive_ptr<qpid::sys::TimerTask>) (Timer.cpp:162)
      ==31280== by 0x4EFDCD0: qpid::broker::LinkRegistry::Periodic::fire() (LinkRegistry.cpp:73)
      ==31280== by 0x563344C: qpid::sys::TimerTask::fireTask() (Timer.cpp:57)
      ==31280== by 0x5634917: qpid::sys::Timer::fire(boost::intrusive_ptr<qpid::sys::TimerTask>) (Timer.cpp:190)
      ==31280== by 0x5633E84: qpid::sys::Timer::run() (Timer.cpp:119)
      ==31280== by 0x5525BEE: qpid::sys::(anonymous namespace)::runRunnable(void*) (Thread.cpp:35)
      ==31280== by 0x4A0A1A5: mythread_wrapper (hg_intercepts.c:201)
      ==31280== by 0x31D6C07950: start_thread (pthread_create.c:301)
      ==31280== by 0x31D68E4D3C: clone (clone.S:115)
      ==31280== Required order was established by acquisition of lock at 0x597D548
      ==31280== at 0x4A095F6: pthread_cond_wait_WRK (hg_intercepts.c:653)
      ==31280== by 0x4A096B8: pthread_cond_wait@* (hg_intercepts.c:675)
      ==31280== by 0x4EF587A: qpid::sys::Condition::wait(qpid::sys::Mutex&) (Condition.h:63)
      ==31280== by 0x4EF5932: qpid::sys::Monitor::wait() (Monitor.h:41)
      ==31280== by 0x5633AA6: qpid::sys::Timer::run() (Timer.cpp:98)
      ==31280== by 0x5525BEE: qpid::sys::(anonymous namespace)::runRunnable(void*) (Thread.cpp:35)
      ==31280== by 0x4A0A1A5: mythread_wrapper (hg_intercepts.c:201)
      ==31280== by 0x31D6C07950: start_thread (pthread_create.c:301)
      ==31280== by 0x31D68E4D3C: clone (clone.S:115)
      ==31280== followed by a later acquisition of lock at 0x59AE350
      ==31280== at 0x4A0679C: pthread_mutex_lock (hg_intercepts.c:464)
      ==31280== by 0x4E8C27B: qpid::sys::Mutex::lock() (Mutex.h:116)
      ==31280== by 0x4E8CD82: qpid::sys::ScopedLock<qpid::sys::Mutex>::ScopedLock(qpid::sys::Mutex&) (Mutex.h:33)
      ==31280== by 0x5633B97: qpid::sys::Timer::run() (Timer.cpp:108)
      ==31280== by 0x5525BEE: qpid::sys::(anonymous namespace)::runRunnable(void*) (Thread.cpp:35)
      ==31280== by 0x4A0A1A5: mythread_wrapper (hg_intercepts.c:201)
      ==31280== by 0x31D6C07950: start_thread (pthread_create.c:301)
      ==31280== by 0x31D68E4D3C: clone (clone.S:115)

      Running perftest against this broker shows numerous read/write conflicts too.

        Attachments

          Activity

            People

            • Assignee:
              astitcher Andrew Stitcher
              Reporter:
              kpvdr Kim van der Riet
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: