aboutsummaryrefslogtreecommitdiffstats
path: root/kernel
diff options
context:
space:
mode:
authorFrederic Weisbecker <fweisbec@gmail.com>2009-04-05 19:49:33 -0400
committerIngo Molnar <mingo@elte.hu>2009-04-10 06:50:56 -0400
commit2062501ae6505dbc5bff3a792246c2661d114050 (patch)
tree59792987c9e9fd1ae657c2e4a5cdb14545523e24 /kernel
parent1cad1252ed279ea59f3f8d3d3a5817eeb2f7a4d3 (diff)
tracing/lockdep: report the time waited for a lock
While trying to optimize the new lock on reiserfs to replace the bkl, I find the lock tracing very useful though it lacks something important for performance (and latency) instrumentation: the time a task waits for a lock. That's what this patch implements: bash-4816 [000] 202.652815: lock_contended: lock_contended: &sb->s_type->i_mutex_key bash-4816 [000] 202.652819: lock_acquired: &rq->lock (0.000 us) <...>-4787 [000] 202.652825: lock_acquired: &rq->lock (0.000 us) <...>-4787 [000] 202.652829: lock_acquired: &rq->lock (0.000 us) bash-4816 [000] 202.652833: lock_acquired: &sb->s_type->i_mutex_key (16.005 us) As shown above, the "lock acquired" field is followed by the time it has been waiting for the lock. Usually, a lock contended entry is followed by a near lock_acquired entry with a non-zero time waited. Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com> Acked-by: Peter Zijlstra <peterz@infradead.org> Cc: Steven Rostedt <rostedt@goodmis.org> LKML-Reference: <1238975373-15739-1-git-send-email-fweisbec@gmail.com> Signed-off-by: Ingo Molnar <mingo@elte.hu>
Diffstat (limited to 'kernel')
-rw-r--r--kernel/lockdep.c8
1 files changed, 4 insertions, 4 deletions
diff --git a/kernel/lockdep.c b/kernel/lockdep.c
index b0f011866969..c4582a6ea953 100644
--- a/kernel/lockdep.c
+++ b/kernel/lockdep.c
@@ -3061,6 +3061,8 @@ found_it:
3061 put_lock_stats(stats); 3061 put_lock_stats(stats);
3062} 3062}
3063 3063
3064DEFINE_TRACE(lock_acquired);
3065
3064static void 3066static void
3065__lock_acquired(struct lockdep_map *lock, unsigned long ip) 3067__lock_acquired(struct lockdep_map *lock, unsigned long ip)
3066{ 3068{
@@ -3099,6 +3101,8 @@ found_it:
3099 hlock->holdtime_stamp = now; 3101 hlock->holdtime_stamp = now;
3100 } 3102 }
3101 3103
3104 trace_lock_acquired(lock, ip, waittime);
3105
3102 stats = get_lock_stats(hlock_class(hlock)); 3106 stats = get_lock_stats(hlock_class(hlock));
3103 if (waittime) { 3107 if (waittime) {
3104 if (hlock->read) 3108 if (hlock->read)
@@ -3137,14 +3141,10 @@ void lock_contended(struct lockdep_map *lock, unsigned long ip)
3137} 3141}
3138EXPORT_SYMBOL_GPL(lock_contended); 3142EXPORT_SYMBOL_GPL(lock_contended);
3139 3143
3140DEFINE_TRACE(lock_acquired);
3141
3142void lock_acquired(struct lockdep_map *lock, unsigned long ip) 3144void lock_acquired(struct lockdep_map *lock, unsigned long ip)
3143{ 3145{
3144 unsigned long flags; 3146 unsigned long flags;
3145 3147
3146 trace_lock_acquired(lock, ip);
3147
3148 if (unlikely(!lock_stat)) 3148 if (unlikely(!lock_stat))
3149 return; 3149 return;
3150 3150