diff options
Diffstat (limited to 'runtime/base')
-rw-r--r-- | runtime/base/mutex-inl.h | 24 | ||||
-rw-r--r-- | runtime/base/mutex.cc | 229 | ||||
-rw-r--r-- | runtime/base/mutex.h | 55 |
3 files changed, 180 insertions, 128 deletions
diff --git a/runtime/base/mutex-inl.h b/runtime/base/mutex-inl.h index 1337dff..7f3b459 100644 --- a/runtime/base/mutex-inl.h +++ b/runtime/base/mutex-inl.h @@ -40,29 +40,25 @@ static inline int futex(volatile int *uaddr, int op, int val, const struct times class ScopedContentionRecorder { public: -#if CONTENTION_LOGGING - ScopedContentionRecorder(BaseMutex* mutex, uint64_t blocked_tid, uint64_t owner_tid) : - mutex_(mutex), blocked_tid_(blocked_tid), owner_tid_(owner_tid), - start_milli_time_(MilliTime()) { + ScopedContentionRecorder(BaseMutex* mutex, uint64_t blocked_tid, uint64_t owner_tid) + : mutex_(kLogLockContentions ? mutex : NULL), + blocked_tid_(kLogLockContentions ? blocked_tid : 0), + owner_tid_(kLogLockContentions ? owner_tid : 0), + start_nano_time_(kLogLockContentions ? NanoTime() : 0) { } -#else - ScopedContentionRecorder(BaseMutex*, uint64_t, uint64_t) {} -#endif ~ScopedContentionRecorder() { -#if CONTENTION_LOGGING - uint64_t end_milli_time = MilliTime(); - mutex_->RecordContention(blocked_tid_, owner_tid_, end_milli_time - start_milli_time_); -#endif + if (kLogLockContentions) { + uint64_t end_nano_time = NanoTime(); + mutex_->RecordContention(blocked_tid_, owner_tid_, end_nano_time - start_nano_time_); + } } private: -#if CONTENTION_LOGGING BaseMutex* const mutex_; const uint64_t blocked_tid_; const uint64_t owner_tid_; - const uint64_t start_milli_time_; -#endif + const uint64_t start_nano_time_; }; static inline uint64_t SafeGetTid(const Thread* self) { diff --git a/runtime/base/mutex.cc b/runtime/base/mutex.cc index d822eed..3007978 100644 --- a/runtime/base/mutex.cc +++ b/runtime/base/mutex.cc @@ -19,6 +19,7 @@ #include <errno.h> #include <sys/time.h> +#include "atomic.h" #include "base/logging.h" #include "cutils/atomic.h" #include "cutils/atomic-inline.h" @@ -94,59 +95,78 @@ static bool ComputeRelativeTimeSpec(timespec* result_ts, const timespec& lhs, co } #endif -#if CONTENTION_LOGGING -// A guard for all_mutexes_ that's not a mutex (Mutexes must CAS to acquire and busy wait). -static AtomicInteger all_mutexes_guard_; -// All created mutexes guarded by all_mutexes_guard_. -std::set<BaseMutex*>* all_mutexes_; +struct AllMutexData { + // A guard for all_mutexes_ that's not a mutex (Mutexes must CAS to acquire and busy wait). + AtomicInteger all_mutexes_guard; + // All created mutexes guarded by all_mutexes_guard_. + std::set<BaseMutex*>* all_mutexes; + AllMutexData() : all_mutexes(NULL) {} +}; +static struct AllMutexData all_mutex_data[kAllMutexDataSize]; class ScopedAllMutexesLock { public: explicit ScopedAllMutexesLock(const BaseMutex* mutex) : mutex_(mutex) { - while (!all_mutexes_guard_.CompareAndSwap(0, reinterpret_cast<int32_t>(mutex))) { + while (!all_mutex_data->all_mutexes_guard.compare_and_swap(0, reinterpret_cast<int32_t>(mutex))) { NanoSleep(100); } } ~ScopedAllMutexesLock() { - while (!all_mutexes_guard_.CompareAndSwap(reinterpret_cast<int32_t>(mutex_), 0)) { + while (!all_mutex_data->all_mutexes_guard.compare_and_swap(reinterpret_cast<int32_t>(mutex_), 0)) { NanoSleep(100); } } private: const BaseMutex* const mutex_; }; -#endif BaseMutex::BaseMutex(const char* name, LockLevel level) : level_(level), name_(name) { -#if CONTENTION_LOGGING - ScopedAllMutexesLock mu(this); - if (all_mutexes_ == NULL) { - // We leak the global set of all mutexes to avoid ordering issues in global variable - // construction/destruction. - all_mutexes_ = new std::set<BaseMutex*>(); - } - all_mutexes_->insert(this); -#endif + if (kLogLockContentions) { + ScopedAllMutexesLock mu(this); + std::set<BaseMutex*>** all_mutexes_ptr = &all_mutex_data->all_mutexes; + if (*all_mutexes_ptr == NULL) { + // We leak the global set of all mutexes to avoid ordering issues in global variable + // construction/destruction. + *all_mutexes_ptr = new std::set<BaseMutex*>(); + } + (*all_mutexes_ptr)->insert(this); + } } BaseMutex::~BaseMutex() { -#if CONTENTION_LOGGING - ScopedAllMutexesLock mu(this); - all_mutexes_->erase(this); -#endif + if (kLogLockContentions) { + ScopedAllMutexesLock mu(this); + all_mutex_data->all_mutexes->erase(this); + } } void BaseMutex::DumpAll(std::ostream& os) { -#if CONTENTION_LOGGING - os << "Mutex logging:\n"; - ScopedAllMutexesLock mu(reinterpret_cast<const BaseMutex*>(-1)); - typedef std::set<BaseMutex*>::const_iterator It; - for (It it = all_mutexes_->begin(); it != all_mutexes_->end(); ++it) { - BaseMutex* mutex = *it; - mutex->Dump(os); - os << "\n"; + if (kLogLockContentions) { + os << "Mutex logging:\n"; + ScopedAllMutexesLock mu(reinterpret_cast<const BaseMutex*>(-1)); + std::set<BaseMutex*>* all_mutexes = all_mutex_data->all_mutexes; + if (all_mutexes == NULL) { + // No mutexes have been created yet during at startup. + return; + } + typedef std::set<BaseMutex*>::const_iterator It; + os << "(Contented)\n"; + for (It it = all_mutexes->begin(); it != all_mutexes->end(); ++it) { + BaseMutex* mutex = *it; + if (mutex->HasEverContended()) { + mutex->Dump(os); + os << "\n"; + } + } + os << "(Never contented)\n"; + for (It it = all_mutexes->begin(); it != all_mutexes->end(); ++it) { + BaseMutex* mutex = *it; + if (!mutex->HasEverContended()) { + mutex->Dump(os); + os << "\n"; + } + } } -#endif } void BaseMutex::CheckSafeToWait(Thread* self) { @@ -172,85 +192,102 @@ void BaseMutex::CheckSafeToWait(Thread* self) { } } +inline void BaseMutex::ContentionLogData::AddToWaitTime(uint64_t value) { + if (kLogLockContentions) { + // Atomically add value to wait_time. + uint64_t new_val, old_val; + volatile int64_t* addr = reinterpret_cast<volatile int64_t*>(&wait_time); + volatile const int64_t* caddr = const_cast<volatile const int64_t*>(addr); + do { + old_val = static_cast<uint64_t>(QuasiAtomic::Read64(caddr)); + new_val = old_val + value; + } while (!QuasiAtomic::Cas64(static_cast<int64_t>(old_val), static_cast<int64_t>(new_val), addr)); + } +} + void BaseMutex::RecordContention(uint64_t blocked_tid, uint64_t owner_tid, - uint64_t milli_time_blocked) { -#if CONTENTION_LOGGING - ++contention_count_; - wait_time_ += static_cast<uint32_t>(milli_time_blocked); // May overflow. - // This code is intentionally racy as it is only used for diagnostics. - uint32_t slot = cur_content_log_entry_; - if (contention_log_[slot].blocked_tid == blocked_tid && - contention_log_[slot].owner_tid == blocked_tid) { - ++contention_log_[slot].count; - } else { - uint32_t new_slot; - do { - slot = cur_content_log_entry_; - new_slot = (slot + 1) % kContentionLogSize; - } while (!cur_content_log_entry_.CompareAndSwap(slot, new_slot)); - contention_log_[new_slot].blocked_tid = blocked_tid; - contention_log_[new_slot].owner_tid = owner_tid; - contention_log_[new_slot].count = 1; + uint64_t nano_time_blocked) { + if (kLogLockContentions) { + ContentionLogData* data = contetion_log_data_; + ++(data->contention_count); + data->AddToWaitTime(nano_time_blocked); + ContentionLogEntry* log = data->contention_log; + // This code is intentionally racy as it is only used for diagnostics. + uint32_t slot = data->cur_content_log_entry; + if (log[slot].blocked_tid == blocked_tid && + log[slot].owner_tid == blocked_tid) { + ++log[slot].count; + } else { + uint32_t new_slot; + do { + slot = data->cur_content_log_entry; + new_slot = (slot + 1) % kContentionLogSize; + } while (!data->cur_content_log_entry.compare_and_swap(slot, new_slot)); + log[new_slot].blocked_tid = blocked_tid; + log[new_slot].owner_tid = owner_tid; + log[new_slot].count = 1; + } } -#endif } void BaseMutex::DumpContention(std::ostream& os) const { -#if CONTENTION_LOGGING - uint32_t wait_time = wait_time_; - uint32_t contention_count = contention_count_; - if (contention_count == 0) { - os << "never contended"; - } else { - os << "contended " << contention_count - << " times, average wait of contender " << (wait_time / contention_count) << "ms"; - SafeMap<uint64_t, size_t> most_common_blocker; - SafeMap<uint64_t, size_t> most_common_blocked; - typedef SafeMap<uint64_t, size_t>::const_iterator It; - for (size_t i = 0; i < kContentionLogSize; ++i) { - uint64_t blocked_tid = contention_log_[i].blocked_tid; - uint64_t owner_tid = contention_log_[i].owner_tid; - uint32_t count = contention_log_[i].count; - if (count > 0) { - It it = most_common_blocked.find(blocked_tid); - if (it != most_common_blocked.end()) { - most_common_blocked.Overwrite(blocked_tid, it->second + count); - } else { - most_common_blocked.Put(blocked_tid, count); + if (kLogLockContentions) { + const ContentionLogData* data = contetion_log_data_; + const ContentionLogEntry* log = data->contention_log; + uint64_t wait_time = data->wait_time; + uint32_t contention_count = data->contention_count; + if (contention_count == 0) { + os << "never contended"; + } else { + os << "contended " << contention_count + << " times, average wait of contender " << PrettyDuration(wait_time / contention_count); + SafeMap<uint64_t, size_t> most_common_blocker; + SafeMap<uint64_t, size_t> most_common_blocked; + typedef SafeMap<uint64_t, size_t>::const_iterator It; + for (size_t i = 0; i < kContentionLogSize; ++i) { + uint64_t blocked_tid = log[i].blocked_tid; + uint64_t owner_tid = log[i].owner_tid; + uint32_t count = log[i].count; + if (count > 0) { + It it = most_common_blocked.find(blocked_tid); + if (it != most_common_blocked.end()) { + most_common_blocked.Overwrite(blocked_tid, it->second + count); + } else { + most_common_blocked.Put(blocked_tid, count); + } + it = most_common_blocker.find(owner_tid); + if (it != most_common_blocker.end()) { + most_common_blocker.Overwrite(owner_tid, it->second + count); + } else { + most_common_blocker.Put(owner_tid, count); + } } - it = most_common_blocker.find(owner_tid); - if (it != most_common_blocker.end()) { - most_common_blocker.Overwrite(owner_tid, it->second + count); - } else { - most_common_blocker.Put(owner_tid, count); + } + uint64_t max_tid = 0; + size_t max_tid_count = 0; + for (It it = most_common_blocked.begin(); it != most_common_blocked.end(); ++it) { + if (it->second > max_tid_count) { + max_tid = it->first; + max_tid_count = it->second; } } - } - uint64_t max_tid = 0; - size_t max_tid_count = 0; - for (It it = most_common_blocked.begin(); it != most_common_blocked.end(); ++it) { - if (it->second > max_tid_count) { - max_tid = it->first; - max_tid_count = it->second; + if (max_tid != 0) { + os << " sample shows most blocked tid=" << max_tid; } - } - if (max_tid != 0) { - os << " sample shows most blocked tid=" << max_tid; - } - max_tid = 0; - max_tid_count = 0; - for (It it = most_common_blocker.begin(); it != most_common_blocker.end(); ++it) { - if (it->second > max_tid_count) { - max_tid = it->first; - max_tid_count = it->second; + max_tid = 0; + max_tid_count = 0; + for (It it = most_common_blocker.begin(); it != most_common_blocker.end(); ++it) { + if (it->second > max_tid_count) { + max_tid = it->first; + max_tid_count = it->second; + } + } + if (max_tid != 0) { + os << " sample shows tid=" << max_tid << " owning during this time"; } - } - if (max_tid != 0) { - os << " sample shows tid=" << max_tid << " owning during this time"; } } -#endif } diff --git a/runtime/base/mutex.h b/runtime/base/mutex.h index 2f41bcd..0e5445f 100644 --- a/runtime/base/mutex.h +++ b/runtime/base/mutex.h @@ -23,6 +23,7 @@ #include <iosfwd> #include <string> +#include "atomic_integer.h" #include "base/logging.h" #include "base/macros.h" #include "globals.h" @@ -41,13 +42,6 @@ #define HAVE_TIMED_RWLOCK 0 #endif -// Record Log contention information, dumpable via SIGQUIT. -#define CONTENTION_LOGGING (0 && ART_USE_FUTEXES) -const size_t kContentionLogSize = 64; -#if CONTENTION_LOGGING -#include "atomic_integer.h" -#endif - namespace art { class ScopedContentionRecorder; @@ -55,6 +49,19 @@ class Thread; const bool kDebugLocking = true || kIsDebugBuild; +// Record Log contention information, dumpable via SIGQUIT. +#ifdef ART_USE_FUTEXES +// To enable lock contention logging, flip this to true. +const bool kLogLockContentions = false; +#else +// Keep this false as lock contention logging is supported only with +// futex. +const bool kLogLockContentions = false; +#endif +const size_t kContentionLogSize = 64; +const size_t kContentionLogDataSize = kLogLockContentions ? 1 : 0; +const size_t kAllMutexDataSize = kLogLockContentions ? 1 : 0; + // Base class for all Mutex implementations class BaseMutex { public: @@ -80,12 +87,12 @@ class BaseMutex { friend class ScopedContentionRecorder; - void RecordContention(uint64_t blocked_tid, uint64_t owner_tid, uint64_t milli_time_blocked); + void RecordContention(uint64_t blocked_tid, uint64_t owner_tid, uint64_t nano_time_blocked); void DumpContention(std::ostream& os) const; const LockLevel level_; // Support for lock hierarchy. const char* const name_; -#if CONTENTION_LOGGING + // A log entry that records contention but makes no guarantee that either tid will be held live. struct ContentionLogEntry { ContentionLogEntry() : blocked_tid(0), owner_tid(0) {} @@ -93,15 +100,27 @@ class BaseMutex { uint64_t owner_tid; AtomicInteger count; }; - ContentionLogEntry contention_log_[kContentionLogSize]; - // The next entry in the contention log to be updated. Value ranges from 0 to - // kContentionLogSize - 1. - AtomicInteger cur_content_log_entry_; - // Number of times the Mutex has been contended. - AtomicInteger contention_count_; - // Sum of time waited by all contenders in ms. - AtomicInteger wait_time_; -#endif + struct ContentionLogData { + ContentionLogEntry contention_log[kContentionLogSize]; + // The next entry in the contention log to be updated. Value ranges from 0 to + // kContentionLogSize - 1. + AtomicInteger cur_content_log_entry; + // Number of times the Mutex has been contended. + AtomicInteger contention_count; + // Sum of time waited by all contenders in ns. + volatile uint64_t wait_time; + void AddToWaitTime(uint64_t value); + ContentionLogData() : wait_time(0) {} + }; + ContentionLogData contetion_log_data_[kContentionLogDataSize]; + + public: + bool HasEverContended() const { + if (kLogLockContentions) { + return contetion_log_data_->contention_count > 0; + } + return false; + } }; // A Mutex is used to achieve mutual exclusion between threads. A Mutex can be used to gain |