Re: [PATCH v2] tracing: Fix lock inversion in trace_event_enable_tgid_record()

From: Prateek Sood
Date: Fri Dec 06 2019 - 07:31:23 EST


Steve,

Does the deadlock reflected here looks valid?

Any outcome of your local verification?


Regards

Prateek


On 12/4/2019 3:06 PM, Prateek Sood wrote:
Task T2ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ Task T3
trace_options_core_write()ÂÂÂÂÂÂÂÂÂÂÂ subsystem_open()

Âmutex_lock(trace_types_lock)ÂÂÂÂÂÂÂÂÂÂ mutex_lock(event_mutex)

Âset_tracer_flag()

ÂÂ trace_event_enable_tgid_record() mutex_lock(trace_types_lock)

ÂÂÂ mutex_lock(event_mutex)

This gives a circular dependency deadlock between trace_types_lock and
event_mutex. To fix this invert the usage of trace_types_lock and
event_mutex in trace_options_core_write(). This keeps the sequence of
lock usage consistent.

Signed-off-by: Prateek Sood<prsood@xxxxxxxxxxxxxx>
---
Âkernel/trace/trace.cÂÂÂÂÂÂÂÂÂÂÂÂÂ | 6 ++++++
Âkernel/trace/trace_events.cÂÂÂÂÂÂ | 8 ++++----
Âkernel/trace/trace_irqsoff.cÂÂÂÂÂ | 4 ++++
Âkernel/trace/trace_sched_wakeup.c | 4 ++++
Â4 files changed, 18 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 6a0ee91..2c09aa1 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4590,6 +4590,8 @@ int trace_keep_overwrite(struct tracer *tracer, u32 mask, int set)

Âint set_tracer_flag(struct trace_array *tr, unsigned int mask, int enabled)
Â{
+ÂÂÂ lockdep_assert_held(&event_mutex);
+
ÂÂÂÂ /* do nothing if flag is already set */
ÂÂÂÂ if (!!(tr->trace_flags & mask) == !!enabled)
ÂÂÂÂÂÂÂÂ return 0;
@@ -4657,6 +4659,7 @@ static int trace_set_options(struct trace_array *tr, char *option)

ÂÂÂÂ cmp += len;

+ÂÂÂ mutex_lock(&event_mutex);
ÂÂÂÂ mutex_lock(&trace_types_lock);

ÂÂÂÂ ret = match_string(trace_options, -1, cmp);
@@ -4667,6 +4670,7 @@ static int trace_set_options(struct trace_array *tr, char *option)
ÂÂÂÂÂÂÂÂ ret = set_tracer_flag(tr, 1 << ret, !neg);

ÂÂÂÂ mutex_unlock(&trace_types_lock);
+ÂÂÂ mutex_unlock(&event_mutex);

ÂÂÂÂ /*
ÂÂÂÂÂ * If the first trailing whitespace is replaced with '\0' by strstrip,
@@ -7972,9 +7976,11 @@ static void get_tr_index(void *data, struct trace_array **ptr,
ÂÂÂÂ if (val != 0 && val != 1)
ÂÂÂÂÂÂÂÂ return -EINVAL;

+ÂÂÂ mutex_lock(&event_mutex);
ÂÂÂÂ mutex_lock(&trace_types_lock);
ÂÂÂÂ ret = set_tracer_flag(tr, 1 << index, val);
ÂÂÂÂ mutex_unlock(&trace_types_lock);
+ÂÂÂ mutex_unlock(&event_mutex);

ÂÂÂÂ if (ret < 0)
ÂÂÂÂÂÂÂÂ return ret;
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index fba87d1..995061b 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -320,7 +320,8 @@ void trace_event_enable_cmd_record(bool enable)
ÂÂÂÂ struct trace_event_file *file;
ÂÂÂÂ struct trace_array *tr;

-ÂÂÂ mutex_lock(&event_mutex);
+ÂÂÂ lockdep_assert_held(&event_mutex);
+
ÂÂÂÂ do_for_each_event_file(tr, file) {

ÂÂÂÂÂÂÂÂ if (!(file->flags & EVENT_FILE_FL_ENABLED))
@@ -334,7 +335,6 @@ void trace_event_enable_cmd_record(bool enable)
ÂÂÂÂÂÂÂÂÂÂÂÂ clear_bit(EVENT_FILE_FL_RECORDED_CMD_BIT, &file->flags);
ÂÂÂÂÂÂÂÂ }
ÂÂÂÂ } while_for_each_event_file();
-ÂÂÂ mutex_unlock(&event_mutex);
Â}

Âvoid trace_event_enable_tgid_record(bool enable)
@@ -342,7 +342,8 @@ void trace_event_enable_tgid_record(bool enable)
ÂÂÂÂ struct trace_event_file *file;
ÂÂÂÂ struct trace_array *tr;

-ÂÂÂ mutex_lock(&event_mutex);
+ÂÂÂ lockdep_assert_held(&event_mutex);
+
ÂÂÂÂ do_for_each_event_file(tr, file) {
ÂÂÂÂÂÂÂÂ if (!(file->flags & EVENT_FILE_FL_ENABLED))
ÂÂÂÂÂÂÂÂÂÂÂÂ continue;
@@ -356,7 +357,6 @@ void trace_event_enable_tgid_record(bool enable)
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ &file->flags);
ÂÂÂÂÂÂÂÂ }
ÂÂÂÂ } while_for_each_event_file();
-ÂÂÂ mutex_unlock(&event_mutex);
Â}

Âstatic int __ftrace_event_enable_disable(struct trace_event_file *file,
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index a745b0c..887cdb5 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -560,8 +560,10 @@ static int __irqsoff_tracer_init(struct trace_array *tr)
ÂÂÂÂ save_flags = tr->trace_flags;

ÂÂÂÂ /* non overwrite screws up the latency tracers */
+ÂÂÂ mutex_lock(&event_mutex);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_OVERWRITE, 1);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, 1);
+ÂÂÂ mutex_unlock(&event_mutex);

ÂÂÂÂ tr->max_latency = 0;
ÂÂÂÂ irqsoff_trace = tr;
@@ -586,8 +588,10 @@ static void __irqsoff_tracer_reset(struct trace_array *tr)

ÂÂÂÂ stop_irqsoff_tracer(tr, is_graph(tr));

+ÂÂÂ mutex_lock(&event_mutex);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, lat_flag);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_OVERWRITE, overwrite_flag);
+ÂÂÂ mutex_unlock(&event_mutex);
ÂÂÂÂ ftrace_reset_array_ops(tr);

ÂÂÂÂ irqsoff_busy = false;
diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index 5e43b96..0bc67d1 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -671,8 +671,10 @@ static int __wakeup_tracer_init(struct trace_array *tr)
ÂÂÂÂ save_flags = tr->trace_flags;

ÂÂÂÂ /* non overwrite screws up the latency tracers */
+ÂÂÂ mutex_lock(&event_mutex);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_OVERWRITE, 1);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, 1);
+ÂÂÂ mutex_unlock(&event_mutex);

ÂÂÂÂ tr->max_latency = 0;
ÂÂÂÂ wakeup_trace = tr;
@@ -722,8 +724,10 @@ static void wakeup_tracer_reset(struct trace_array *tr)
ÂÂÂÂ /* make sure we put back any tasks we are tracing */
ÂÂÂÂ wakeup_reset(tr);

+ÂÂÂ mutex_lock(&event_mutex);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, lat_flag);
ÂÂÂÂ set_tracer_flag(tr, TRACE_ITER_OVERWRITE, overwrite_flag);
+ÂÂÂ mutex_unlock(&event_mutex);
ÂÂÂÂ ftrace_reset_array_ops(tr);
ÂÂÂÂ wakeup_busy = false;
Â}
-- Qualcomm India Private Limited, on behalf of Qualcomm Innovation Center, Inc., is a member of Code Aurora Forum, a Linux Foundation Collaborative Project.

--
Qualcomm India Private Limited, on behalf of Qualcomm Innovation
Center, Inc., is a member of Code Aurora Forum, a Linux Foundation
Collaborative Project