Improve mutex debugging prints

When lock contention is detected, print also the name of the thread
holding the lock and also where the lock was tried to acquire.

After the lock is finally acquired after the contention, add a new
print there as well to indicate that the lock is now acquired and the
thread will continue.

This adds overhead to the mutex operations, but that shouldn't be an
issue yet. If it becomes too slow, an option can be added later to
remove the prints and the overhead altogether. Now we are more happy
about the improved verbosity of the locking operations.

Signed-off-by: Timo Kokkonen <timo.t.kokkonen@iki.fi>

diff --git a/process.c b/process.c
index 13fe7e58fbd5a0f6e828e72d0bbff0e0df11575b..a54f3dd0ffb5dd00e00823d07b2c6f700ccdb7b0 100644 (file)
--- a/process.c
+++ b/process.c
@@ -608,24 +608,32 @@ void _mutex_lock_acquired(struct mutex *lock, char *file, int line)
 {
        lock->line = line;
        lock->file = file;
+       pthread_getname_np(pthread_self(),
+                       lock->owner_name, sizeof(lock->owner_name));
 }
 
 int _mutex_lock(struct mutex *lock, char *file, int line)
 {
        int ret = 0;
+       int contended = 0;
 
        if (!pthread_mutex_trylock(&lock->lock))
                goto out_lock;
 
-       pr_info("Lock contention on lock %s on %s:%d\n",
-               lock->name, lock->file, lock->line);
+       contended = 1;
+       pr_info("Lock contention at %s:%d on lock %s acquired by %s at %s:%d\n",
+               file, line, lock->name,
+               lock->owner_name, lock->file, lock->line);
 
        ret = pthread_mutex_lock(&lock->lock);
        if (ret)
-               pr_err("Acquirin lock %s failed: %m, acquired %s:%d\n",
+               pr_err("Acquirin lock %s failed: %m, acquired on %s:%d\n",
                        lock->name, lock->file, lock->line);
 
 out_lock:
+       if (contended)
+               pr_info("Lock %s acquired at %s:%d after contention\n",
+                       lock->name, file, line);
        _mutex_lock_acquired(lock, file, line);
        return ret;
 }

diff --git a/process.h b/process.h
index 4134d30969895411c780435f9312ade19741965f..2d58565ff883d5a9b80281bd73d7c127467254b9 100644 (file)
--- a/process.h
+++ b/process.h
@@ -27,6 +27,7 @@ struct mutex {
        pthread_mutex_t lock;
        int line;
        char *file;
+       char owner_name[16];
        time_t lock_time;
        char *name;
 };