summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--mutrace.c96
1 files changed, 69 insertions, 27 deletions
diff --git a/mutrace.c b/mutrace.c
index e1176aa..8d5648c 100644
--- a/mutrace.c
+++ b/mutrace.c
@@ -84,6 +84,10 @@ struct mutex_info {
uint64_t nsec_locked_total;
uint64_t nsec_locked_max;
+ uint64_t nsec_contended_total; /* mutexes only */
+ uint64_t nsec_read_contended_total; /* rwlocks only */
+ uint64_t nsec_write_contended_total; /* rwlocks only */
+
uint64_t nsec_timestamp;
struct stacktrace_info stacktrace;
@@ -537,14 +541,14 @@ static bool mutex_info_stat(struct mutex_info *mi) {
return false;
fprintf(stderr,
- "%8u %8u %8u %8u %12.3f %12.3f %12.3f %c%c%c%c%c%c\n",
+ "%8u %8u %8u %8u %13.3f %12.3f %12.3f %c%c%c%c%c%c\n",
mi->id,
mi->n_locked,
mi->n_owner_changed,
mi->n_contended,
+ (double) mi->nsec_contended_total / 1000000.0,
(double) mi->nsec_locked_total / 1000000.0,
(double) mi->nsec_locked_total / mi->n_locked / 1000000.0,
- (double) mi->nsec_locked_max / 1000000.0,
mi->mutex ? 'M' : 'W',
mi->broken ? '!' : (mi->dead ? 'x' : '-'),
track_rt ? (mi->realtime ? 'R' : '-') : '.',
@@ -613,7 +617,7 @@ static void show_summary_internal(void) {
"\n"
"mutrace: Showing %u most contended mutexes:\n"
"\n"
- " Mutex # Locked Changed Cont. tot.Time[ms] avg.Time[ms] max.Time[ms] Flags\n",
+ " Mutex # Locked Changed Cont. cont.Time[ms] tot.Time[ms] avg.Time[ms] Flags\n",
m);
for (i = 0, m = 0; i < n && (show_n_max <= 0 || m < show_n_max); i++)
@@ -622,19 +626,19 @@ static void show_summary_internal(void) {
if (i < n)
fprintf(stderr,
- " ... ... ... ... ... ... ... ||||||\n");
+ " ... ... ... ... ... ... ... ||||||\n");
else
fprintf(stderr,
- " ||||||\n");
+ " ||||||\n");
fprintf(stderr,
- " /|||||\n"
- " Object: M = Mutex, W = RWLock /||||\n"
- " State: x = dead, ! = inconsistent /|||\n"
- " Use: R = used in realtime thread /||\n"
- " Mutex Type: r = RECURSIVE, e = ERRORCHECK, a = ADAPTIVE /|\n"
- " Mutex Protocol: i = INHERIT, p = PROTECT /\n"
- " RWLock Kind: r = PREFER_READER, w = PREFER_WRITER, W = PREFER_WRITER_NONREC \n");
+ " /|||||\n"
+ " Object: M = Mutex, W = RWLock /||||\n"
+ " State: x = dead, ! = inconsistent /|||\n"
+ " Use: R = used in realtime thread /||\n"
+ " Mutex Type: r = RECURSIVE, e = ERRORCHECK, a = ADAPTIVE /|\n"
+ " Mutex Protocol: i = INHERIT, p = PROTECT /\n"
+ " RWLock Kind: r = PREFER_READER, w = PREFER_WRITER, W = PREFER_WRITER_NONREC \n");
if (!track_rt)
fprintf(stderr,
@@ -992,7 +996,7 @@ int pthread_mutex_destroy(pthread_mutex_t *mutex) {
return real_pthread_mutex_destroy(mutex);
}
-static void mutex_lock(pthread_mutex_t *mutex, bool busy) {
+static void mutex_lock(pthread_mutex_t *mutex, bool busy, uint64_t nsec_contended) {
struct mutex_info *mi;
pid_t tid;
@@ -1013,8 +1017,10 @@ static void mutex_lock(pthread_mutex_t *mutex, bool busy) {
mi->n_lock_level++;
mi->n_locked++;
- if (busy)
+ if (busy) {
mi->n_contended++;
+ mi->nsec_contended_total += nsec_contended;
+ }
tid = _gettid();
if (mi->last_owner != tid) {
@@ -1036,6 +1042,7 @@ static void mutex_lock(pthread_mutex_t *mutex, bool busy) {
int pthread_mutex_lock(pthread_mutex_t *mutex) {
int r;
bool busy;
+ uint64_t wait_time = 0;
if (UNLIKELY(!initialized && recursive)) {
/* During the initialization phase we might be called
@@ -1056,19 +1063,24 @@ int pthread_mutex_lock(pthread_mutex_t *mutex) {
return r;
if (UNLIKELY((busy = (r == EBUSY)))) {
+ uint64_t start_time = nsec_now();
+
r = real_pthread_mutex_lock(mutex);
+ wait_time = nsec_now() - start_time;
+
if (UNLIKELY(r != 0))
return r;
}
- mutex_lock(mutex, busy);
+ mutex_lock(mutex, busy, wait_time);
return r;
}
int pthread_mutex_timedlock(pthread_mutex_t *mutex, const struct timespec *abstime) {
int r;
bool busy;
+ uint64_t wait_time = 0;
if (UNLIKELY(!initialized && recursive)) {
assert(!threads_existing);
@@ -1082,15 +1094,19 @@ int pthread_mutex_timedlock(pthread_mutex_t *mutex, const struct timespec *absti
return r;
if (UNLIKELY((busy = (r == EBUSY)))) {
+ uint64_t start_time = nsec_now();
+
r = real_pthread_mutex_timedlock(mutex, abstime);
+ wait_time = nsec_now() - start_time;
+
if (UNLIKELY(r == ETIMEDOUT))
busy = true;
else if (UNLIKELY(r != 0))
return r;
}
- mutex_lock(mutex, busy);
+ mutex_lock(mutex, busy, wait_time);
return r;
}
@@ -1108,7 +1124,7 @@ int pthread_mutex_trylock(pthread_mutex_t *mutex) {
if (UNLIKELY(r != 0))
return r;
- mutex_lock(mutex, false);
+ mutex_lock(mutex, false, 0);
return r;
}
@@ -1168,7 +1184,7 @@ int pthread_cond_wait(pthread_cond_t *cond, pthread_mutex_t *mutex) {
/* Unfortunately we cannot distuingish mutex contention and
* the condition not being signalled here. */
- mutex_lock(mutex, false);
+ mutex_lock(mutex, false, 0);
return r;
}
@@ -1182,7 +1198,7 @@ int pthread_cond_timedwait(pthread_cond_t *cond, pthread_mutex_t *mutex, const s
mutex_unlock(mutex);
r = real_pthread_cond_timedwait(cond, mutex, abstime);
- mutex_lock(mutex, false);
+ mutex_lock(mutex, false, 0);
return r;
}
@@ -1370,7 +1386,7 @@ int pthread_rwlock_destroy(pthread_rwlock_t *rwlock) {
return real_pthread_rwlock_destroy(rwlock);
}
-static void rwlock_lock(pthread_rwlock_t *rwlock, bool for_write, bool busy) {
+static void rwlock_lock(pthread_rwlock_t *rwlock, bool for_write, bool busy, uint64_t nsec_contended) {
struct mutex_info *mi;
pid_t tid;
@@ -1391,9 +1407,15 @@ static void rwlock_lock(pthread_rwlock_t *rwlock, bool for_write, bool busy) {
mi->n_lock_level++;
mi->n_locked++;
- if (busy)
+ if (busy) {
mi->n_contended++;
+ if (for_write)
+ mi->nsec_write_contended_total += nsec_contended;
+ else
+ mi->nsec_read_contended_total += nsec_contended;
+ }
+
tid = _gettid();
if (mi->last_owner != tid) {
if (mi->last_owner != 0)
@@ -1414,6 +1436,7 @@ static void rwlock_lock(pthread_rwlock_t *rwlock, bool for_write, bool busy) {
int pthread_rwlock_rdlock(pthread_rwlock_t *rwlock) {
int r;
bool busy;
+ uint64_t wait_time = 0;
if (UNLIKELY(!initialized && recursive)) {
assert(!threads_existing);
@@ -1427,15 +1450,19 @@ int pthread_rwlock_rdlock(pthread_rwlock_t *rwlock) {
return r;
if (UNLIKELY((busy = (r == EBUSY)))) {
+ uint64_t start_time = nsec_now();
+
r = real_pthread_rwlock_rdlock(rwlock);
+ wait_time = nsec_now() - start_time;
+
if (UNLIKELY(r == ETIMEDOUT))
busy = true;
else if (UNLIKELY(r != 0))
return r;
}
- rwlock_lock(rwlock, false, busy);
+ rwlock_lock(rwlock, false, busy, wait_time);
return r;
}
@@ -1453,13 +1480,14 @@ int pthread_rwlock_tryrdlock(pthread_rwlock_t *rwlock) {
if (UNLIKELY(r != EBUSY && r != 0))
return r;
- rwlock_lock(rwlock, false, false);
+ rwlock_lock(rwlock, false, false, 0);
return r;
}
int pthread_rwlock_timedrdlock(pthread_rwlock_t *rwlock, const struct timespec *abstime) {
int r;
bool busy;
+ uint64_t wait_time = 0;
if (UNLIKELY(!initialized && recursive)) {
assert(!threads_existing);
@@ -1473,21 +1501,26 @@ int pthread_rwlock_timedrdlock(pthread_rwlock_t *rwlock, const struct timespec *
return r;
if (UNLIKELY((busy = (r == EBUSY)))) {
+ uint64_t start_time = nsec_now();
+
r = real_pthread_rwlock_timedrdlock(rwlock, abstime);
+ wait_time = nsec_now() - start_time;
+
if (UNLIKELY(r == ETIMEDOUT))
busy = true;
else if (UNLIKELY(r != 0))
return r;
}
- rwlock_lock(rwlock, false, busy);
+ rwlock_lock(rwlock, false, busy, wait_time);
return r;
}
int pthread_rwlock_wrlock(pthread_rwlock_t *rwlock) {
int r;
bool busy;
+ uint64_t wait_time = 0;
if (UNLIKELY(!initialized && recursive)) {
assert(!threads_existing);
@@ -1501,15 +1534,19 @@ int pthread_rwlock_wrlock(pthread_rwlock_t *rwlock) {
return r;
if (UNLIKELY((busy = (r == EBUSY)))) {
+ uint64_t start_time = nsec_now();
+
r = real_pthread_rwlock_wrlock(rwlock);
+ wait_time = nsec_now() - start_time;
+
if (UNLIKELY(r == ETIMEDOUT))
busy = true;
else if (UNLIKELY(r != 0))
return r;
}
- rwlock_lock(rwlock, true, busy);
+ rwlock_lock(rwlock, true, busy, wait_time);
return r;
}
@@ -1527,13 +1564,14 @@ int pthread_rwlock_trywrlock(pthread_rwlock_t *rwlock) {
if (UNLIKELY(r != EBUSY && r != 0))
return r;
- rwlock_lock(rwlock, true, false);
+ rwlock_lock(rwlock, true, false, 0);
return r;
}
int pthread_rwlock_timedwrlock(pthread_rwlock_t *rwlock, const struct timespec *abstime) {
int r;
bool busy;
+ uint64_t wait_time = 0;
if (UNLIKELY(!initialized && recursive)) {
assert(!threads_existing);
@@ -1547,15 +1585,19 @@ int pthread_rwlock_timedwrlock(pthread_rwlock_t *rwlock, const struct timespec *
return r;
if (UNLIKELY((busy = (r == EBUSY)))) {
+ uint64_t start_time = nsec_now();
+
r = real_pthread_rwlock_timedwrlock(rwlock, abstime);
+ wait_time = nsec_now() - start_time;
+
if (UNLIKELY(r == ETIMEDOUT))
busy = true;
else if (UNLIKELY(r != 0))
return r;
}
- rwlock_lock(rwlock, true, busy);
+ rwlock_lock(rwlock, true, busy, wait_time);
return r;
}