Panda3D

mutexDebug.cxx

00001 // Filename: mutexDebug.cxx
00002 // Created by:  drose (13Feb06)
00003 //
00004 ////////////////////////////////////////////////////////////////////
00005 //
00006 // PANDA 3D SOFTWARE
00007 // Copyright (c) Carnegie Mellon University.  All rights reserved.
00008 //
00009 // All use of this software is subject to the terms of the revised BSD
00010 // license.  You should have received a copy of this license along
00011 // with this source code in a file named "LICENSE."
00012 //
00013 ////////////////////////////////////////////////////////////////////
00014 
00015 #include "mutexDebug.h"
00016 #include "thread.h"
00017 #include "config_pipeline.h"
00018 
00019 #ifdef DEBUG_THREADS
00020 
00021 int MutexDebug::_pstats_count = 0;
00022 MutexTrueImpl *MutexDebug::_global_lock;
00023 
00024 ////////////////////////////////////////////////////////////////////
00025 //     Function: MutexDebug::Constructor
00026 //       Access: Protected
00027 //  Description:
00028 ////////////////////////////////////////////////////////////////////
00029 MutexDebug::
00030 MutexDebug(const string &name, bool allow_recursion, bool lightweight) :
00031   Namable(name),
00032   _allow_recursion(allow_recursion),
00033   _lightweight(lightweight),
00034   _locking_thread(NULL),
00035   _lock_count(0),
00036   _deleted_name(NULL),
00037   _cvar_impl(*get_global_lock())
00038 {
00039 #ifndef SIMPLE_THREADS
00040   // If we're using real threads, there's no such thing as a
00041   // lightweight mutex.
00042   _lightweight = false;
00043 #endif
00044 }
00045 
00046 ////////////////////////////////////////////////////////////////////
00047 //     Function: MutexDebug::Destructor
00048 //       Access: Protected, Virtual
00049 //  Description:
00050 ////////////////////////////////////////////////////////////////////
00051 MutexDebug::
00052 ~MutexDebug() {
00053   nassertv(_locking_thread == NULL && _lock_count == 0);
00054 
00055   // If the config variable says to, allocate (and leak) a string name
00056   // for the mutex, so we can report which mutex it is that has
00057   // destructed after the fact.
00058   if (name_deleted_mutexes) {
00059     ostringstream strm;
00060     strm << *this;
00061     string name = strm.str();
00062     _deleted_name = strdup((char *)name.c_str());
00063   }
00064 
00065   // Put a distinctive, bogus lock count in upon destruction, so we'll
00066   // be more likely to notice a floating pointer.
00067   _lock_count = -100;
00068 }
00069 
00070 ////////////////////////////////////////////////////////////////////
00071 //     Function: MutexDebug::output
00072 //       Access: Public, Virtual
00073 //  Description: This method is declared virtual in MutexDebug, but
00074 //               non-virtual in MutexDirect.
00075 ////////////////////////////////////////////////////////////////////
00076 void MutexDebug::
00077 output(ostream &out) const {
00078   if (_lightweight) {
00079     out << "Light";
00080   }
00081   if (_allow_recursion) {
00082     out << "ReMutex " << get_name() << " " << (void *)this;
00083   } else {
00084     out << "Mutex " << get_name() << " " << (void *)this;
00085   }
00086 }
00087 
00088 ////////////////////////////////////////////////////////////////////
00089 //     Function: MutexDebug::output_with_holder
00090 //       Access: Public
00091 //  Description: Reports the mutex as well as the thread that is
00092 //               currently holding it, if any.
00093 ////////////////////////////////////////////////////////////////////
00094 void MutexDebug::
00095 output_with_holder(ostream &out) const {
00096   _global_lock->acquire();
00097   output(out);
00098   if (_locking_thread != (Thread *)NULL) {
00099     out << " (held by " << *_locking_thread << ")\n";
00100   }
00101   _global_lock->release();
00102 }
00103 
00104 ////////////////////////////////////////////////////////////////////
00105 //     Function: MutexDebug::increment_pstats
00106 //       Access: Public, Static
00107 //  Description: Intended to be called only by
00108 //               PStatClientImpl::client_connect(), this tells the
00109 //               global mutex system that PStats is active.  Once
00110 //               PStats is active, all "light" mutexes are treated the
00111 //               same as full mutexes.
00112 ////////////////////////////////////////////////////////////////////
00113 void MutexDebug::
00114 increment_pstats() {
00115   _global_lock->acquire();
00116   ++_pstats_count;
00117   _global_lock->release();
00118 }
00119 
00120 ////////////////////////////////////////////////////////////////////
00121 //     Function: MutexDebug::decrement_pstats
00122 //       Access: Public, Static
00123 //  Description: Intended to be called only by
00124 //               PStatClientImpl::client_disconnect(), this tells the
00125 //               global mutex system that PStats is no longer active.
00126 ////////////////////////////////////////////////////////////////////
00127 void MutexDebug::
00128 decrement_pstats() {
00129   _global_lock->acquire();
00130   --_pstats_count;
00131   _global_lock->release();
00132 }
00133 
00134 ////////////////////////////////////////////////////////////////////
00135 //     Function: MutexDebug::do_acquire
00136 //       Access: Private
00137 //  Description: The private implementation of acquire() assumes that
00138 //               _lock_impl is held.
00139 ////////////////////////////////////////////////////////////////////
00140 void MutexDebug::
00141 do_acquire(Thread *current_thread) {
00142   // If this assertion is triggered, you tried to lock a
00143   // recently-destructed mutex.
00144   nassertd(_lock_count != -100) {
00145     pipeline_cat.error()
00146       << "Destructed mutex: " << (void *)this << "\n";
00147     if (name_deleted_mutexes && _deleted_name != NULL) {
00148       pipeline_cat.error()
00149         << _deleted_name << "\n";
00150     } else {
00151       pipeline_cat.error()
00152         << "Configure name-deleted-mutexes 1 to see the mutex name.\n";
00153     }
00154     return;
00155   }
00156 
00157   if (_locking_thread == (Thread *)NULL) {
00158     // The mutex is not already locked by anyone.  Lock it.
00159     _locking_thread = current_thread;
00160     ++_lock_count;
00161     nassertv(_lock_count == 1);
00162 
00163   } else if (_locking_thread == current_thread) {
00164     // The mutex is already locked by this thread.  Increment the lock
00165     // count.
00166     nassertv(_lock_count > 0);
00167     if (!_allow_recursion) {
00168       ostringstream ostr;
00169       ostr << *current_thread << " attempted to double-lock non-reentrant "
00170            << *this;
00171       nassert_raise(ostr.str());
00172     }
00173     ++_lock_count;
00174 
00175   } else {
00176     // The mutex is locked by some other thread.
00177 
00178     if (_lightweight && _pstats_count == 0) {
00179       // In this case, it's not a real mutex.  Just watch it go by.
00180       MissedThreads::iterator mi = _missed_threads.insert(MissedThreads::value_type(current_thread, 0)).first;
00181       if ((*mi).second == 0) {
00182         ostringstream ostr;
00183         ostr << *current_thread << " not stopped by " << *this << " (held by "
00184              << *_locking_thread << ")\n";
00185         nassert_raise(ostr.str());
00186       } else {
00187         if (!_allow_recursion) {
00188           ostringstream ostr;
00189           ostr << *current_thread << " attempted to double-lock non-reentrant "
00190                << *this;
00191           nassert_raise(ostr.str());
00192         }
00193       }
00194       ++((*mi).second);
00195 
00196     } else {
00197       // This is the real case.  It's a real mutex, so block if necessary.
00198 
00199       // Check for deadlock.
00200       MutexDebug *next_mutex = this;
00201       while (next_mutex != NULL) {
00202         if (next_mutex->_locking_thread == current_thread) {
00203           // Whoops, the thread is blocked on me!  Deadlock!
00204           report_deadlock(current_thread);
00205           nassert_raise("Deadlock");
00206           return;
00207         }
00208         Thread *next_thread = next_mutex->_locking_thread;
00209         if (next_thread == NULL) {
00210           // Looks like this mutex isn't actually locked, which means
00211           // the last thread isn't really blocked--it just hasn't woken
00212           // up yet to discover that.  In any case, no deadlock.
00213           break;
00214         }
00215         
00216         // The last thread is blocked on this "next thread"'s mutex, but
00217         // what mutex is the next thread blocked on?
00218         next_mutex = next_thread->_blocked_on_mutex;
00219       }
00220       
00221       // OK, no deadlock detected.  Carry on.
00222       current_thread->_blocked_on_mutex = this;
00223       
00224       // Go to sleep on the condition variable until it's unlocked.
00225       
00226       if (thread_cat->is_debug()) {
00227         thread_cat.debug()
00228           << *current_thread << " blocking on " << *this << " (held by "
00229           << *_locking_thread << ")\n";
00230       }
00231       
00232       while (_locking_thread != (Thread *)NULL) {
00233         thread_cat.debug()
00234           << *current_thread << " still blocking on " << *this << " (held by "
00235           << *_locking_thread << ")\n";
00236         _cvar_impl.wait();
00237       }
00238       
00239       if (thread_cat.is_debug()) {
00240         thread_cat.debug()
00241           << *current_thread << " acquired " << *this << "\n";
00242       }
00243       
00244       current_thread->_blocked_on_mutex = NULL;
00245       
00246       _locking_thread = current_thread;
00247       ++_lock_count;
00248       nassertv(_lock_count == 1);
00249     }
00250   }
00251 }
00252 
00253 ////////////////////////////////////////////////////////////////////
00254 //     Function: MutexDebug::do_try_acquire
00255 //       Access: Private
00256 //  Description: The private implementation of acquire(false) assumes
00257 //               that _lock_impl is held.
00258 ////////////////////////////////////////////////////////////////////
00259 bool MutexDebug::
00260 do_try_acquire(Thread *current_thread) {
00261   // If this assertion is triggered, you tried to lock a
00262   // recently-destructed mutex.
00263   nassertd(_lock_count != -100) {
00264     pipeline_cat.error()
00265       << "Destructed mutex: " << (void *)this << "\n";
00266     if (name_deleted_mutexes && _deleted_name != NULL) {
00267       pipeline_cat.error()
00268         << _deleted_name << "\n";
00269     } else {
00270       pipeline_cat.error()
00271         << "Configure name-deleted-mutexes 1 to see the mutex name.\n";
00272     }
00273     return false;
00274   }
00275 
00276   bool acquired = true;
00277   if (_locking_thread == (Thread *)NULL) {
00278     // The mutex is not already locked by anyone.  Lock it.
00279     _locking_thread = current_thread;
00280     ++_lock_count;
00281     nassertr(_lock_count == 1, false);
00282 
00283   } else if (_locking_thread == current_thread) {
00284     // The mutex is already locked by this thread.  Increment the lock
00285     // count.
00286     nassertr(_lock_count > 0, false);
00287     if (!_allow_recursion) {
00288       // Non-recursive lock; return false.
00289       acquired = false;
00290     } else {
00291       ++_lock_count;
00292     }
00293 
00294   } else {
00295     // The mutex is locked by some other thread.  Return false.
00296 
00297     if (_lightweight && _pstats_count == 0) {
00298       // In this case, it's not a real mutex.  Just watch it go by.
00299       MissedThreads::iterator mi = _missed_threads.insert(MissedThreads::value_type(current_thread, 0)).first;
00300       if ((*mi).second == 0) {
00301         thread_cat.info()
00302           << *current_thread << " not stopped by " << *this << " (held by "
00303           << *_locking_thread << ")\n";
00304       } else {
00305         if (!_allow_recursion) {
00306           ostringstream ostr;
00307           ostr << *current_thread << " attempted to double-lock non-reentrant "
00308                << *this;
00309           nassert_raise(ostr.str());
00310         }
00311       }
00312       ++((*mi).second);
00313 
00314     } else {
00315       // This is the real case.
00316       acquired = false;
00317     }
00318   }
00319 
00320   return acquired;
00321 }
00322 
00323 ////////////////////////////////////////////////////////////////////
00324 //     Function: MutexDebug::do_release
00325 //       Access: Private
00326 //  Description: The private implementation of acquire() assumes that
00327 //               _lock_impl is held.
00328 ////////////////////////////////////////////////////////////////////
00329 void MutexDebug::
00330 do_release() {
00331   // If this assertion is triggered, you tried to release a
00332   // recently-destructed mutex.
00333   nassertd(_lock_count != -100) {
00334     pipeline_cat.error()
00335       << "Destructed mutex: " << (void *)this << "\n";
00336     if (name_deleted_mutexes && _deleted_name != NULL) {
00337       pipeline_cat.error()
00338         << _deleted_name << "\n";
00339     } else {
00340       pipeline_cat.error()
00341         << "Configure name-deleted-mutexes 1 to see the mutex name.\n";
00342     }
00343     return;
00344   }
00345 
00346   Thread *current_thread = Thread::get_current_thread();
00347 
00348   if (_locking_thread != current_thread) {
00349     // We're not holding this mutex.
00350 
00351     if (_lightweight) {
00352       // Not a real mutex.  This just means we blew past a mutex
00353       // without locking it, above.
00354 
00355       MissedThreads::iterator mi = _missed_threads.find(current_thread);
00356       nassertv(mi != _missed_threads.end());
00357       nassertv((*mi).second > 0);
00358       --((*mi).second);
00359       
00360       if ((*mi).second == 0) {
00361         _missed_threads.erase(mi);
00362       }
00363 
00364     } else {
00365       // In the real-mutex case, this is an error condition.
00366       ostringstream ostr;
00367       ostr << *current_thread << " attempted to release "
00368            << *this << " which it does not own";
00369       nassert_raise(ostr.str());
00370     }
00371     return;
00372   }
00373 
00374   nassertv(_lock_count > 0);
00375 
00376   --_lock_count;
00377   if (_lock_count == 0) {
00378     // That was the last lock held by this thread.  Release the lock.
00379     _locking_thread = (Thread *)NULL;
00380 
00381     if (_lightweight) {
00382       if (!_missed_threads.empty()) {
00383         // Promote some other thread to be the honorary lock holder.
00384         MissedThreads::iterator mi = _missed_threads.begin();
00385         _locking_thread = (*mi).first;
00386         _lock_count = (*mi).second;
00387         _missed_threads.erase(mi);
00388         nassertv(_lock_count > 0);
00389       }
00390     } else {
00391 
00392       /*
00393       if (thread_cat.is_debug()) {
00394         thread_cat.debug()
00395           << *current_thread << " releasing " << *this << "\n";
00396       }
00397       */
00398       _cvar_impl.notify();
00399     }
00400   }
00401 }
00402 
00403 ////////////////////////////////////////////////////////////////////
00404 //     Function: MutexDebug::do_debug_is_locked
00405 //       Access: Private
00406 //  Description: The private implementation of debug_is_locked()
00407 //               assumes that _lock_impl is held.
00408 ////////////////////////////////////////////////////////////////////
00409 bool MutexDebug::
00410 do_debug_is_locked() const {
00411   Thread *current_thread = Thread::get_current_thread();
00412   if (_locking_thread == current_thread) {
00413     return true;
00414   }
00415 
00416   if (_lightweight) {
00417     MissedThreads::const_iterator mi = _missed_threads.find(current_thread);
00418     if (mi != _missed_threads.end()) {
00419       nassertr((*mi).second > 0, false);
00420       return true;
00421     }
00422   }
00423 
00424   return false;
00425 }
00426 
00427 ////////////////////////////////////////////////////////////////////
00428 //     Function: MutexDebug::report_deadlock
00429 //       Access: Private
00430 //  Description: Reports a detected deadlock situation.  _lock_impl
00431 //               should be already held.
00432 ////////////////////////////////////////////////////////////////////
00433 void MutexDebug::
00434 report_deadlock(Thread *current_thread) {
00435   thread_cat->error()
00436     << "\n\n"
00437     << "****************************************************************\n"
00438     << "*****                 Deadlock detected!                   *****\n"
00439     << "****************************************************************\n"
00440     << "\n";
00441 
00442   thread_cat.error()
00443     << *current_thread << " attempted to lock " << *this
00444     << " which is held by " << *_locking_thread << "\n";
00445 
00446   MutexDebug *next_mutex = this;
00447   Thread *next_thread = next_mutex->_locking_thread;
00448   next_mutex = next_thread->_blocked_on_mutex;
00449   while (next_mutex != NULL) {
00450     thread_cat.error()
00451       << *next_thread << " is blocked waiting on "
00452       << *next_mutex << " which is held by "
00453       << *next_mutex->_locking_thread << "\n";
00454     next_thread = next_mutex->_locking_thread;
00455     next_mutex = next_thread->_blocked_on_mutex;
00456   }
00457 
00458   thread_cat.error() 
00459     << "Deadlock!\n";
00460 }
00461 
00462 #endif  //  DEBUG_THREADS
 All Classes Functions Variables Enumerations