Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1727025 > unrolled thread

[PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken

Started byTom Zanussi <tom.zanussi@linux.intel.com>
First post2017-09-06 00:10 +0200
Last post2017-09-08 22:10 +0200
Articles 4 — 2 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken Tom Zanussi <tom.zanussi@linux.intel.com> - 2017-09-06 00:10 +0200
    Re: [PATCH v2 35/40] tracing: Reverse the order  event_mutex/trace_types_lock are taken Steven Rostedt <rostedt@goodmis.org> - 2017-09-08 21:40 +0200
      Re: [PATCH v2 35/40] tracing: Reverse the order  event_mutex/trace_types_lock are taken Steven Rostedt <rostedt@goodmis.org> - 2017-09-08 21:50 +0200
        Re: [PATCH v2 35/40] tracing: Reverse the order  event_mutex/trace_types_lock are taken Steven Rostedt <rostedt@goodmis.org> - 2017-09-08 22:10 +0200

#1727025 — [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken

FromTom Zanussi <tom.zanussi@linux.intel.com>
Date2017-09-06 00:10 +0200
Subject[PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken
Message-ID<umucG-oz-11@gated-at.bofh.it>
Change the order event_mutex and trace_types_lock are taken, to avoid
circular dependencies and lockdep spew.

Changing the order shouldn't matter to any current code, but does to
anything that takes the event_mutex first and then trace_types_lock.
This is the case when calling tracing_set_clock from inside an event
command, which already holds the event_mutex.

Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
---
 kernel/trace/trace_events.c | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index c93540c..889802c 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -1406,8 +1406,8 @@ static int subsystem_open(struct inode *inode, struct file *filp)
 		return -ENODEV;
 
 	/* Make sure the system still exists */
-	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
+	mutex_lock(&trace_types_lock);
 	list_for_each_entry(tr, &ftrace_trace_arrays, list) {
 		list_for_each_entry(dir, &tr->systems, list) {
 			if (dir == inode->i_private) {
@@ -1421,8 +1421,8 @@ static int subsystem_open(struct inode *inode, struct file *filp)
 		}
 	}
  exit_loop:
-	mutex_unlock(&event_mutex);
 	mutex_unlock(&trace_types_lock);
+	mutex_unlock(&event_mutex);
 
 	if (!system)
 		return -ENODEV;
@@ -2294,15 +2294,15 @@ void trace_event_eval_update(struct trace_eval_map **map, int len)
 int trace_add_event_call(struct trace_event_call *call)
 {
 	int ret;
-	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
+	mutex_lock(&trace_types_lock);
 
 	ret = __register_event(call, NULL);
 	if (ret >= 0)
 		__add_event_to_tracers(call);
 
-	mutex_unlock(&event_mutex);
 	mutex_unlock(&trace_types_lock);
+	mutex_unlock(&event_mutex);
 	return ret;
 }
 
@@ -2356,13 +2356,13 @@ int trace_remove_event_call(struct trace_event_call *call)
 {
 	int ret;
 
-	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
+	mutex_lock(&trace_types_lock);
 	down_write(&trace_event_sem);
 	ret = probe_remove_event_call(call);
 	up_write(&trace_event_sem);
-	mutex_unlock(&event_mutex);
 	mutex_unlock(&trace_types_lock);
+	mutex_unlock(&event_mutex);
 
 	return ret;
 }
@@ -2424,8 +2424,8 @@ static int trace_module_notify(struct notifier_block *self,
 {
 	struct module *mod = data;
 
-	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
+	mutex_lock(&trace_types_lock);
 	switch (val) {
 	case MODULE_STATE_COMING:
 		trace_module_add_events(mod);
@@ -2434,8 +2434,8 @@ static int trace_module_notify(struct notifier_block *self,
 		trace_module_remove_events(mod);
 		break;
 	}
-	mutex_unlock(&event_mutex);
 	mutex_unlock(&trace_types_lock);
+	mutex_unlock(&event_mutex);
 
 	return 0;
 }
-- 
1.9.3

[toc] | [next] | [standalone]

#1729224 — Re: [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken

FromSteven Rostedt <rostedt@goodmis.org>
Date2017-09-08 21:40 +0200
SubjectRe: [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken
Message-ID<unxi9-2YY-9@gated-at.bofh.it>
In reply to#1727025
On Tue,  5 Sep 2017 16:57:47 -0500
Tom Zanussi <tom.zanussi@linux.intel.com> wrote:

> Change the order event_mutex and trace_types_lock are taken, to avoid
> circular dependencies and lockdep spew.
> 
> Changing the order shouldn't matter to any current code, but does to
> anything that takes the event_mutex first and then trace_types_lock.
> This is the case when calling tracing_set_clock from inside an event
> command, which already holds the event_mutex.

This is a very scary patch. I'll apply it and run a bunch of tests with
lockdep enabled. Let's see what blows up (or not).

-- Steve

> 
> Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
> ---
>  kernel/trace/trace_events.c | 16 ++++++++--------
>  1 file changed, 8 insertions(+), 8 deletions(-)
> 
> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index c93540c..889802c 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -1406,8 +1406,8 @@ static int subsystem_open(struct inode *inode, struct file *filp)
>  		return -ENODEV;
>  
>  	/* Make sure the system still exists */
> -	mutex_lock(&trace_types_lock);
>  	mutex_lock(&event_mutex);
> +	mutex_lock(&trace_types_lock);
>  	list_for_each_entry(tr, &ftrace_trace_arrays, list) {
>  		list_for_each_entry(dir, &tr->systems, list) {
>  			if (dir == inode->i_private) {
> @@ -1421,8 +1421,8 @@ static int subsystem_open(struct inode *inode, struct file *filp)
>  		}
>  	}
>   exit_loop:
> -	mutex_unlock(&event_mutex);
>  	mutex_unlock(&trace_types_lock);
> +	mutex_unlock(&event_mutex);
>  
>  	if (!system)
>  		return -ENODEV;
> @@ -2294,15 +2294,15 @@ void trace_event_eval_update(struct trace_eval_map **map, int len)
>  int trace_add_event_call(struct trace_event_call *call)
>  {
>  	int ret;
> -	mutex_lock(&trace_types_lock);
>  	mutex_lock(&event_mutex);
> +	mutex_lock(&trace_types_lock);
>  
>  	ret = __register_event(call, NULL);
>  	if (ret >= 0)
>  		__add_event_to_tracers(call);
>  
> -	mutex_unlock(&event_mutex);
>  	mutex_unlock(&trace_types_lock);
> +	mutex_unlock(&event_mutex);
>  	return ret;
>  }
>  
> @@ -2356,13 +2356,13 @@ int trace_remove_event_call(struct trace_event_call *call)
>  {
>  	int ret;
>  
> -	mutex_lock(&trace_types_lock);
>  	mutex_lock(&event_mutex);
> +	mutex_lock(&trace_types_lock);
>  	down_write(&trace_event_sem);
>  	ret = probe_remove_event_call(call);
>  	up_write(&trace_event_sem);
> -	mutex_unlock(&event_mutex);
>  	mutex_unlock(&trace_types_lock);
> +	mutex_unlock(&event_mutex);
>  
>  	return ret;
>  }
> @@ -2424,8 +2424,8 @@ static int trace_module_notify(struct notifier_block *self,
>  {
>  	struct module *mod = data;
>  
> -	mutex_lock(&trace_types_lock);
>  	mutex_lock(&event_mutex);
> +	mutex_lock(&trace_types_lock);
>  	switch (val) {
>  	case MODULE_STATE_COMING:
>  		trace_module_add_events(mod);
> @@ -2434,8 +2434,8 @@ static int trace_module_notify(struct notifier_block *self,
>  		trace_module_remove_events(mod);
>  		break;
>  	}
> -	mutex_unlock(&event_mutex);
>  	mutex_unlock(&trace_types_lock);
> +	mutex_unlock(&event_mutex);
>  
>  	return 0;
>  }

[toc] | [prev] | [next] | [standalone]

#1729233 — Re: [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken

FromSteven Rostedt <rostedt@goodmis.org>
Date2017-09-08 21:50 +0200
SubjectRe: [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken
Message-ID<unxrR-36G-31@gated-at.bofh.it>
In reply to#1729224
On Fri, 8 Sep 2017 15:31:35 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Tue,  5 Sep 2017 16:57:47 -0500
> Tom Zanussi <tom.zanussi@linux.intel.com> wrote:
> 
> > Change the order event_mutex and trace_types_lock are taken, to avoid
> > circular dependencies and lockdep spew.
> > 
> > Changing the order shouldn't matter to any current code, but does to
> > anything that takes the event_mutex first and then trace_types_lock.
> > This is the case when calling tracing_set_clock from inside an event
> > command, which already holds the event_mutex.  
> 
> This is a very scary patch. I'll apply it and run a bunch of tests with
> lockdep enabled. Let's see what blows up (or not).

Boom!

 ======================================================
 WARNING: possible circular locking dependency detected
 4.13.0-rc7-test+ #84 Not tainted
 ------------------------------------------------------
 mkdir/1674 is trying to acquire lock:
  (event_mutex){+.+.+.}, at: [<ffffffff811b18bd>] event_trace_add_tracer+0x1d/0xb0
 
               but task is already holding lock:
  (trace_types_lock){+.+.+.}, at: [<ffffffff811a121f>] instance_mkdir+0x2f/0x250
 
               which lock already depends on the new lock.

 
               the existing dependency chain (in reverse order) is:
 
               -> #1 (trace_types_lock){+.+.+.}:
        lock_acquire+0xe3/0x1d0
        __mutex_lock+0x81/0x950
        mutex_lock_nested+0x1b/0x20
        trace_module_notify+0x33/0x1b0
        notifier_call_chain+0x4a/0x70
        __blocking_notifier_call_chain+0x4d/0x70
        blocking_notifier_call_chain+0x16/0x20
        load_module+0x21df/0x2dd0
        SYSC_finit_module+0xbc/0xf0
        SyS_finit_module+0xe/0x10
        do_syscall_64+0x62/0x140
        return_from_SYSCALL_64+0x0/0x7a
 
               -> #0 (event_mutex){+.+.+.}:
        __lock_acquire+0x1026/0x11d0
        lock_acquire+0xe3/0x1d0
        __mutex_lock+0x81/0x950
        mutex_lock_nested+0x1b/0x20
        event_trace_add_tracer+0x1d/0xb0
        instance_mkdir+0x173/0x250
        tracefs_syscall_mkdir+0x40/0x70
        vfs_mkdir+0xfb/0x190
        SyS_mkdir+0x6b/0xd0
        entry_SYSCALL_64_fastpath+0x1f/0xbe
 
               other info that might help us debug this:

  Possible unsafe locking scenario:

        CPU0                    CPU1
        ----                    ----
   lock(trace_types_lock);
                                lock(event_mutex);
                                lock(trace_types_lock);
   lock(event_mutex);
 
                *** DEADLOCK ***

 2 locks held by mkdir/1674:
  #0:  (sb_writers#10){.+.+.+}, at: [<ffffffff812b4824>] mnt_want_write+0x24/0x50
  #1:  (trace_types_lock){+.+.+.}, at: [<ffffffff811a121f>] instance_mkdir+0x2f/0x250
 
               stack backtrace:
 CPU: 3 PID: 1674 Comm: mkdir Not tainted 4.13.0-rc7-test+ #84
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:
  dump_stack+0x86/0xcf
  print_circular_bug+0x1be/0x210
  __lock_acquire+0x1026/0x11d0
  lock_acquire+0xe3/0x1d0
  ? lock_acquire+0xe3/0x1d0
  ? event_trace_add_tracer+0x1d/0xb0
  ? event_trace_add_tracer+0x1d/0xb0
  __mutex_lock+0x81/0x950
  ? event_trace_add_tracer+0x1d/0xb0
  ? event_trace_add_tracer+0x1d/0xb0
  ? __create_dir+0xcb/0x130
  mutex_lock_nested+0x1b/0x20
  ? mutex_lock_nested+0x1b/0x20
  event_trace_add_tracer+0x1d/0xb0
  instance_mkdir+0x173/0x250
  tracefs_syscall_mkdir+0x40/0x70
  ? tracefs_syscall_mkdir+0x40/0x70
  vfs_mkdir+0xfb/0x190
  SyS_mkdir+0x6b/0xd0
  entry_SYSCALL_64_fastpath+0x1f/0xbe
 RIP: 0033:0x7f4867afa947
 RSP: 002b:00007ffd3dc35c08 EFLAGS: 00000202 ORIG_RAX: 0000000000000053
 RAX: ffffffffffffffda RBX: 0000000000000046 RCX: 00007f4867afa947
 RDX: 0000000000000000 RSI: 00000000000001ff RDI: 00007ffd3dc3764f
 RBP: ffffc90000f2ff98 R08: 00000000000001ff R09: 000055f96a551ac0
 R10: 000055f96b700010 R11: 0000000000000202 R12: 0000000000000001
 R13: 00007ffd3dc35f28 R14: 00000000000001ff R15: ffffffff8189316a
  ? entry_SYSCALL_64_after_swapgs+0x17/0x4f

It appears to be caused by instance creation. I'll look at that.


-- Steve

[toc] | [prev] | [next] | [standalone]

#1729249 — Re: [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken

FromSteven Rostedt <rostedt@goodmis.org>
Date2017-09-08 22:10 +0200
SubjectRe: [PATCH v2 35/40] tracing: Reverse the order event_mutex/trace_types_lock are taken
Message-ID<unxLb-3sR-1@gated-at.bofh.it>
In reply to#1729233
On Fri, 8 Sep 2017 15:41:36 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Fri, 8 Sep 2017 15:31:35 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > On Tue,  5 Sep 2017 16:57:47 -0500
> > Tom Zanussi <tom.zanussi@linux.intel.com> wrote:
> >   
> > > Change the order event_mutex and trace_types_lock are taken, to avoid
> > > circular dependencies and lockdep spew.
> > > 
> > > Changing the order shouldn't matter to any current code, but does to
> > > anything that takes the event_mutex first and then trace_types_lock.
> > > This is the case when calling tracing_set_clock from inside an event
> > > command, which already holds the event_mutex.    
> > 
> > This is a very scary patch. I'll apply it and run a bunch of tests with
> > lockdep enabled. Let's see what blows up (or not).  
> 
> Boom!
>


> It appears to be caused by instance creation. I'll look at that.

OK, this may be a simple fix. I'll send you a patch to fold in after I
finish testing it.

-- Steve

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web