| Message ID | 20220316224548.500123-2-namhyung@kernel.org (mailing list archive) |
|---|---|
| State | Not Applicable |
| Headers | show |
| Series | locking: Add new lock contention tracepoints (v3) | expand |
| Context | Check | Description |
|---|---|---|
| netdev/tree_selection | success | Not a local patch |
On Wed, 16 Mar 2022 15:45:47 -0700 Namhyung Kim <namhyung@kernel.org> wrote: > This adds two new lock contention tracepoints like below: > > * lock:contention_begin > * lock:contention_end > > The lock:contention_begin takes a flags argument to classify locks. I > found it useful to identify what kind of locks it's tracing like if > it's spinning or sleeping, reader-writer lock, real-time, and per-cpu. > > Move tracepoint definitions into mutex.c so that we can use them > without lockdep. > > Signed-off-by: Namhyung Kim <namhyung@kernel.org> > --- > include/trace/events/lock.h | 54 ++++++++++++++++++++++++++++++++++--- > kernel/locking/lockdep.c | 1 - > kernel/locking/mutex.c | 3 +++ > 3 files changed, 54 insertions(+), 4 deletions(-) > > diff --git a/include/trace/events/lock.h b/include/trace/events/lock.h > index d7512129a324..2a3df36d4fdb 100644 > --- a/include/trace/events/lock.h > +++ b/include/trace/events/lock.h > @@ -5,11 +5,21 @@ > #if !defined(_TRACE_LOCK_H) || defined(TRACE_HEADER_MULTI_READ) > #define _TRACE_LOCK_H > > -#include <linux/lockdep.h> > +#include <linux/sched.h> > #include <linux/tracepoint.h> > > +/* flags for lock:contention_begin */ > +#define LCB_F_SPIN (1U << 0) > +#define LCB_F_READ (1U << 1) > +#define LCB_F_WRITE (1U << 2) > +#define LCB_F_RT (1U << 3) > +#define LCB_F_PERCPU (1U << 4) > + > + > #ifdef CONFIG_LOCKDEP > > +#include <linux/lockdep.h> > + > TRACE_EVENT(lock_acquire, > > TP_PROTO(struct lockdep_map *lock, unsigned int subclass, > @@ -78,8 +88,46 @@ DEFINE_EVENT(lock, lock_acquired, > TP_ARGS(lock, ip) > ); > > -#endif > -#endif > +#endif /* CONFIG_LOCK_STAT */ > +#endif /* CONFIG_LOCKDEP */ > + > +TRACE_EVENT(contention_begin, > + > + TP_PROTO(void *lock, unsigned int flags), > + > + TP_ARGS(lock, flags), > + > + TP_STRUCT__entry( > + __field(void *, lock_addr) > + __field(unsigned int, flags) > + ), > + > + TP_fast_assign( > + __entry->lock_addr = lock; > + __entry->flags = flags; > + ), > + > + TP_printk("%p (flags=%x)", __entry->lock_addr, __entry->flags) Perhaps make this into: TP_printk("%p (flags=%s)", __entry->lock_addr, __print_flags(__entry->flags, "|", {LCB_F_SPIN, "spin" }, {LCB_F_READ, "read" }, {LCB_F_WRITE, "write" }, {LCB_F_RT, "rt" }, {LCB_F_PERCPU, "percpu" } )) That way, the use doesn't need to figure out what the numbers mean. -- Steve > +); > + > +TRACE_EVENT(contention_end, > + > + TP_PROTO(void *lock, int ret), > + > + TP_ARGS(lock, ret), > + > + TP_STRUCT__entry( > + __field(void *, lock_addr) > + __field(int, ret) > + ), > + > + TP_fast_assign( > + __entry->lock_addr = lock; > + __entry->ret = ret; > + ), > + > + TP_printk("%p (ret=%d)", __entry->lock_addr, __entry->ret) > +); > > #endif /* _TRACE_LOCK_H */ > > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c > index 50036c10b518..08f8fb6a2d1e 100644 > --- a/kernel/locking/lockdep.c > +++ b/kernel/locking/lockdep.c > @@ -60,7 +60,6 @@ > > #include "lockdep_internals.h" > > -#define CREATE_TRACE_POINTS > #include <trace/events/lock.h> > > #ifdef CONFIG_PROVE_LOCKING > diff --git a/kernel/locking/mutex.c b/kernel/locking/mutex.c > index 5e3585950ec8..ee2fd7614a93 100644 > --- a/kernel/locking/mutex.c > +++ b/kernel/locking/mutex.c > @@ -30,6 +30,9 @@ > #include <linux/debug_locks.h> > #include <linux/osq_lock.h> > > +#define CREATE_TRACE_POINTS > +#include <trace/events/lock.h> > + > #ifndef CONFIG_PREEMPT_RT > #include "mutex.h" >
----- On Mar 16, 2022, at 6:45 PM, Namhyung Kim namhyung@kernel.org wrote: > This adds two new lock contention tracepoints like below: > > * lock:contention_begin > * lock:contention_end > > The lock:contention_begin takes a flags argument to classify locks. I > found it useful to identify what kind of locks it's tracing like if > it's spinning or sleeping, reader-writer lock, real-time, and per-cpu. > > Move tracepoint definitions into mutex.c so that we can use them > without lockdep. > > Signed-off-by: Namhyung Kim <namhyung@kernel.org> > --- > include/trace/events/lock.h | 54 ++++++++++++++++++++++++++++++++++--- > kernel/locking/lockdep.c | 1 - > kernel/locking/mutex.c | 3 +++ > 3 files changed, 54 insertions(+), 4 deletions(-) > > diff --git a/include/trace/events/lock.h b/include/trace/events/lock.h > index d7512129a324..2a3df36d4fdb 100644 > --- a/include/trace/events/lock.h > +++ b/include/trace/events/lock.h > @@ -5,11 +5,21 @@ > #if !defined(_TRACE_LOCK_H) || defined(TRACE_HEADER_MULTI_READ) > #define _TRACE_LOCK_H > > -#include <linux/lockdep.h> > +#include <linux/sched.h> > #include <linux/tracepoint.h> > > +/* flags for lock:contention_begin */ > +#define LCB_F_SPIN (1U << 0) > +#define LCB_F_READ (1U << 1) > +#define LCB_F_WRITE (1U << 2) > +#define LCB_F_RT (1U << 3) > +#define LCB_F_PERCPU (1U << 4) Unless there is a particular reason for using preprocessor defines here, the following form is typically better because it does not pollute the preprocessor defines, e.g.: enum lock_contention_flags { LCB_F_SPIN = 1U << 0; LCB_F_READ = 1U << 1; LCB_F_WRITE = 1U << 2; LCB_F_RT = 1U << 3; LCB_F_PERCPU = 1U << 4; }; Thanks, Mathieu > + > + > #ifdef CONFIG_LOCKDEP > > +#include <linux/lockdep.h> > + > TRACE_EVENT(lock_acquire, > > TP_PROTO(struct lockdep_map *lock, unsigned int subclass, > @@ -78,8 +88,46 @@ DEFINE_EVENT(lock, lock_acquired, > TP_ARGS(lock, ip) > ); > > -#endif > -#endif > +#endif /* CONFIG_LOCK_STAT */ > +#endif /* CONFIG_LOCKDEP */ > + > +TRACE_EVENT(contention_begin, > + > + TP_PROTO(void *lock, unsigned int flags), > + > + TP_ARGS(lock, flags), > + > + TP_STRUCT__entry( > + __field(void *, lock_addr) > + __field(unsigned int, flags) > + ), > + > + TP_fast_assign( > + __entry->lock_addr = lock; > + __entry->flags = flags; > + ), > + > + TP_printk("%p (flags=%x)", __entry->lock_addr, __entry->flags) > +); > + > +TRACE_EVENT(contention_end, > + > + TP_PROTO(void *lock, int ret), > + > + TP_ARGS(lock, ret), > + > + TP_STRUCT__entry( > + __field(void *, lock_addr) > + __field(int, ret) > + ), > + > + TP_fast_assign( > + __entry->lock_addr = lock; > + __entry->ret = ret; > + ), > + > + TP_printk("%p (ret=%d)", __entry->lock_addr, __entry->ret) > +); > > #endif /* _TRACE_LOCK_H */ > > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c > index 50036c10b518..08f8fb6a2d1e 100644 > --- a/kernel/locking/lockdep.c > +++ b/kernel/locking/lockdep.c > @@ -60,7 +60,6 @@ > > #include "lockdep_internals.h" > > -#define CREATE_TRACE_POINTS > #include <trace/events/lock.h> > > #ifdef CONFIG_PROVE_LOCKING > diff --git a/kernel/locking/mutex.c b/kernel/locking/mutex.c > index 5e3585950ec8..ee2fd7614a93 100644 > --- a/kernel/locking/mutex.c > +++ b/kernel/locking/mutex.c > @@ -30,6 +30,9 @@ > #include <linux/debug_locks.h> > #include <linux/osq_lock.h> > > +#define CREATE_TRACE_POINTS > +#include <trace/events/lock.h> > + > #ifndef CONFIG_PREEMPT_RT > #include "mutex.h" > > -- > 2.35.1.894.gb6a874cedc-goog
On Thu, 17 Mar 2022 09:32:55 -0400 (EDT) Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote: > Unless there is a particular reason for using preprocessor defines here, the > following form is typically better because it does not pollute the preprocessor > defines, e.g.: > > enum lock_contention_flags { > LCB_F_SPIN = 1U << 0; > LCB_F_READ = 1U << 1; > LCB_F_WRITE = 1U << 2; > LCB_F_RT = 1U << 3; > LCB_F_PERCPU = 1U << 4; > }; If you do this, then to use the __print_flags(), You'll also need to add: TRACE_DEFINE_ENUM(LCB_F_SPIN); TRACE_DEFINE_ENUM(LCB_F_READ); TRACE_DEFINE_ENUM(LCB_F_WRITE); TRACE_DEFINE_ENUM(LCB_F_RT); TRACE_DEFINE_ENUM(LCB_F_PERCPU); Which does slow down boot up slightly. -- Steve
----- On Mar 17, 2022, at 12:07 PM, rostedt rostedt@goodmis.org wrote: > On Thu, 17 Mar 2022 09:32:55 -0400 (EDT) > Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote: > >> Unless there is a particular reason for using preprocessor defines here, the >> following form is typically better because it does not pollute the preprocessor >> defines, e.g.: >> >> enum lock_contention_flags { >> LCB_F_SPIN = 1U << 0; >> LCB_F_READ = 1U << 1; >> LCB_F_WRITE = 1U << 2; >> LCB_F_RT = 1U << 3; >> LCB_F_PERCPU = 1U << 4; >> }; > > If you do this, then to use the __print_flags(), You'll also need to add: > > TRACE_DEFINE_ENUM(LCB_F_SPIN); > TRACE_DEFINE_ENUM(LCB_F_READ); > TRACE_DEFINE_ENUM(LCB_F_WRITE); > TRACE_DEFINE_ENUM(LCB_F_RT); > TRACE_DEFINE_ENUM(LCB_F_PERCPU); > > Which does slow down boot up slightly. So it looks like there is (currently) a good reason for going with the #define. As a side-discussion, I keep finding it odd that this adds overhead on boot. I suspect this is also implemented as a linked list which needs to be iterated over at boot-time. With a few changes to these macros, these linked lists could be turned into arrays, and thus remove the boot-time overhead. Thanks, Mathieu > > -- Steve
Hi Mathieu and Steve, On Thu, Mar 17, 2022 at 9:37 AM Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote: > > ----- On Mar 17, 2022, at 12:07 PM, rostedt rostedt@goodmis.org wrote: > > > On Thu, 17 Mar 2022 09:32:55 -0400 (EDT) > > Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote: > > > >> Unless there is a particular reason for using preprocessor defines here, the > >> following form is typically better because it does not pollute the preprocessor > >> defines, e.g.: > >> > >> enum lock_contention_flags { > >> LCB_F_SPIN = 1U << 0; > >> LCB_F_READ = 1U << 1; > >> LCB_F_WRITE = 1U << 2; > >> LCB_F_RT = 1U << 3; > >> LCB_F_PERCPU = 1U << 4; > >> }; > > > > If you do this, then to use the __print_flags(), You'll also need to add: > > > > TRACE_DEFINE_ENUM(LCB_F_SPIN); > > TRACE_DEFINE_ENUM(LCB_F_READ); > > TRACE_DEFINE_ENUM(LCB_F_WRITE); > > TRACE_DEFINE_ENUM(LCB_F_RT); > > TRACE_DEFINE_ENUM(LCB_F_PERCPU); > > > > Which does slow down boot up slightly. > > So it looks like there is (currently) a good reason for going with the #define. Thanks for your suggestions, I'd go with define this time and we could convert it to enum later (hopefully after the boot time is resolved). Thanks, Namhyung > > As a side-discussion, I keep finding it odd that this adds overhead on boot. I suspect > this is also implemented as a linked list which needs to be iterated over at boot-time. > > With a few changes to these macros, these linked lists could be turned into arrays, > and thus remove the boot-time overhead.
diff --git a/include/trace/events/lock.h b/include/trace/events/lock.h index d7512129a324..2a3df36d4fdb 100644 --- a/include/trace/events/lock.h +++ b/include/trace/events/lock.h @@ -5,11 +5,21 @@ #if !defined(_TRACE_LOCK_H) || defined(TRACE_HEADER_MULTI_READ) #define _TRACE_LOCK_H -#include <linux/lockdep.h> +#include <linux/sched.h> #include <linux/tracepoint.h> +/* flags for lock:contention_begin */ +#define LCB_F_SPIN (1U << 0) +#define LCB_F_READ (1U << 1) +#define LCB_F_WRITE (1U << 2) +#define LCB_F_RT (1U << 3) +#define LCB_F_PERCPU (1U << 4) + + #ifdef CONFIG_LOCKDEP +#include <linux/lockdep.h> + TRACE_EVENT(lock_acquire, TP_PROTO(struct lockdep_map *lock, unsigned int subclass, @@ -78,8 +88,46 @@ DEFINE_EVENT(lock, lock_acquired, TP_ARGS(lock, ip) ); -#endif -#endif +#endif /* CONFIG_LOCK_STAT */ +#endif /* CONFIG_LOCKDEP */ + +TRACE_EVENT(contention_begin, + + TP_PROTO(void *lock, unsigned int flags), + + TP_ARGS(lock, flags), + + TP_STRUCT__entry( + __field(void *, lock_addr) + __field(unsigned int, flags) + ), + + TP_fast_assign( + __entry->lock_addr = lock; + __entry->flags = flags; + ), + + TP_printk("%p (flags=%x)", __entry->lock_addr, __entry->flags) +); + +TRACE_EVENT(contention_end, + + TP_PROTO(void *lock, int ret), + + TP_ARGS(lock, ret), + + TP_STRUCT__entry( + __field(void *, lock_addr) + __field(int, ret) + ), + + TP_fast_assign( + __entry->lock_addr = lock; + __entry->ret = ret; + ), + + TP_printk("%p (ret=%d)", __entry->lock_addr, __entry->ret) +); #endif /* _TRACE_LOCK_H */ diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c index 50036c10b518..08f8fb6a2d1e 100644 --- a/kernel/locking/lockdep.c +++ b/kernel/locking/lockdep.c @@ -60,7 +60,6 @@ #include "lockdep_internals.h" -#define CREATE_TRACE_POINTS #include <trace/events/lock.h> #ifdef CONFIG_PROVE_LOCKING diff --git a/kernel/locking/mutex.c b/kernel/locking/mutex.c index 5e3585950ec8..ee2fd7614a93 100644 --- a/kernel/locking/mutex.c +++ b/kernel/locking/mutex.c @@ -30,6 +30,9 @@ #include <linux/debug_locks.h> #include <linux/osq_lock.h> +#define CREATE_TRACE_POINTS +#include <trace/events/lock.h> + #ifndef CONFIG_PREEMPT_RT #include "mutex.h"
This adds two new lock contention tracepoints like below: * lock:contention_begin * lock:contention_end The lock:contention_begin takes a flags argument to classify locks. I found it useful to identify what kind of locks it's tracing like if it's spinning or sleeping, reader-writer lock, real-time, and per-cpu. Move tracepoint definitions into mutex.c so that we can use them without lockdep. Signed-off-by: Namhyung Kim <namhyung@kernel.org> --- include/trace/events/lock.h | 54 ++++++++++++++++++++++++++++++++++--- kernel/locking/lockdep.c | 1 - kernel/locking/mutex.c | 3 +++ 3 files changed, 54 insertions(+), 4 deletions(-)