2022-03-23 15:04:31

by Namhyung Kim

[permalink] [raw]
Subject: [PATCH 0/2] locking: Add new lock contention tracepoints (v4)

Hello,

There have been some requests for low-overhead kernel lock contention
monitoring. The kernel has CONFIG_LOCK_STAT to provide such an infra
either via /proc/lock_stat or tracepoints directly.

However it's not light-weight and hard to be used in production. So
I'm trying to add new tracepoints for lock contention and using them
as a base to build a new monitoring system.

* Changes in v4
- use __print_flags in the TP_printk()
- reworked __down_common for semaphore
- add Tested-by from Hyeonggon Yoo

* Changes in v3
- move the tracepoints deeper in the slow path
- remove the caller ip
- don't use task state in the flags
- add 'ret' field to the contention end tracepoint

* Changes in v2
- do not use lockdep infrastructure
- add flags argument to lock:contention_begin tracepoint

I added a flags argument in the contention_begin to classify locks in
question. It can tell whether it's a spinlock, reader-writer lock or
a mutex. With stacktrace, users can identify which lock is contended.

The patch 01 added the tracepoints and move the definition to the
mutex.c file so that it can see the tracepoints without lockdep.

The patch 02 actually installs the tracepoints in the locking code.
To minimize the overhead, they were added in the slow path of the code
separately. As spinlocks are defined in the arch headers, I couldn't
handle them all. I've just added it to generic queued spinlock and
rwlocks only. Each arch can add the tracepoints later.

This series base on the current tip/locking/core and you get it from
'locking/tracepoint-v4' branch in my tree at:

git://git.kernel.org/pub/scm/linux/kernel/git/namhyung/linux-perf.git


Thanks,
Namhyung


Namhyung Kim (2):
locking: Add lock contention tracepoints
locking: Apply contention tracepoints in the slow path

include/trace/events/lock.h | 61 +++++++++++++++++++++++++++++++++--
kernel/locking/lockdep.c | 1 -
kernel/locking/mutex.c | 6 ++++
kernel/locking/percpu-rwsem.c | 3 ++
kernel/locking/qrwlock.c | 9 ++++++
kernel/locking/qspinlock.c | 5 +++
kernel/locking/rtmutex.c | 11 +++++++
kernel/locking/rwbase_rt.c | 3 ++
kernel/locking/rwsem.c | 9 ++++++
kernel/locking/semaphore.c | 15 ++++++++-
10 files changed, 118 insertions(+), 5 deletions(-)


base-commit: cd27ccfc727e99352321c0c75012ab9c5a90321e
--
2.35.1.894.gb6a874cedc-goog


2022-03-23 22:54:48

by Namhyung Kim

[permalink] [raw]
Subject: [PATCH 1/2] locking: Add lock contention tracepoints

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.

Tested-by: Hyeonggon Yoo <[email protected]>
Signed-off-by: Namhyung Kim <[email protected]>
---
include/trace/events/lock.h | 61 +++++++++++++++++++++++++++++++++++--
kernel/locking/lockdep.c | 1 -
kernel/locking/mutex.c | 3 ++
3 files changed, 61 insertions(+), 4 deletions(-)

diff --git a/include/trace/events/lock.h b/include/trace/events/lock.h
index d7512129a324..b9b6e3edd518 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,53 @@ 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=%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" }
+ ))
+);
+
+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

2022-04-05 20:49:58

by tip-bot2 for Haifeng Xu

[permalink] [raw]
Subject: [tip: locking/core] locking: Add lock contention tracepoints

The following commit has been merged into the locking/core branch of tip:

Commit-ID: 16edd9b511a13e7760ed4b92ba4e39bacda5c86f
Gitweb: https://git.kernel.org/tip/16edd9b511a13e7760ed4b92ba4e39bacda5c86f
Author: Namhyung Kim <[email protected]>
AuthorDate: Tue, 22 Mar 2022 11:57:08 -07:00
Committer: Peter Zijlstra <[email protected]>
CommitterDate: Tue, 05 Apr 2022 10:24:35 +02:00

locking: Add lock contention tracepoints

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 <[email protected]>
Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
Tested-by: Hyeonggon Yoo <[email protected]>
Link: https://lkml.kernel.org/r/[email protected]
---
include/trace/events/lock.h | 61 ++++++++++++++++++++++++++++++++++--
kernel/locking/lockdep.c | 1 +-
kernel/locking/mutex.c | 3 ++-
3 files changed, 61 insertions(+), 4 deletions(-)

diff --git a/include/trace/events/lock.h b/include/trace/events/lock.h
index d751212..b9b6e3e 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,53 @@ 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=%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" }
+ ))
+);
+
+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 3cbd492..a6e671b 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 5e35859..ee2fd76 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"