2012-11-10 05:32:33

by Hannes Frederic Sowa

[permalink] [raw]
Subject: [PATCH] perf: call perf_event_comm under task_lock to fix suspicious rcu usage

Following RCU warning showed up while executing a shebang-script under
perf-record (could even be an empty script) on a 3.7-rc4 stable kernel:

[ 32.185108]
[ 32.185332] ===============================
[ 32.185602] [ INFO: suspicious RCU usage. ]
[ 32.185903] 3.7.0-rc4 #1 Not tainted
[ 32.186021] -------------------------------
[ 32.186021] include/linux/cgroup.h:566 suspicious rcu_dereference_check() usage!
[ 32.186021]
[ 32.186021] other info that might help us debug this:
[ 32.186021]
[ 32.186021]
[ 32.186021] rcu_scheduler_active = 1, debug_locks = 0
[ 32.186021] 1 lock held by empty.sh/556:
[ 32.186021] #0: (&sig->cred_guard_mutex){+.+.+.}, at: [<ffffffff811d1d16>] prepare_bprm_creds+0x36/0x80
[ 32.186021]
[ 32.186021] stack backtrace:
[ 32.186021] Pid: 556, comm: empty.sh Not tainted 3.7.0-rc4 #1
[ 32.186021] Call Trace:
[ 32.186021] [<ffffffff810d336d>] lockdep_rcu_suspicious+0xfd/0x130
[ 32.186021] [<ffffffff81153de6>] perf_event_comm+0x436/0x610
[ 32.186021] [<ffffffff810d181d>] ? trace_hardirqs_off+0xd/0x10
[ 32.186021] [<ffffffff810ac37f>] ? local_clock+0x6f/0x80
[ 32.186021] [<ffffffff810d217f>] ? lock_release_holdtime.part.26+0xf/0x180
[ 32.186021] [<ffffffff811d1bd3>] set_task_comm+0x73/0x180
[ 32.186021] [<ffffffff811d24ba>] setup_new_exec+0x9a/0x210
[ 32.186021] [<ffffffff81225cf3>] load_elf_binary+0x3e3/0x1ab0
[ 32.186021] [<ffffffff810ac0f5>] ? sched_clock_local+0x25/0xa0
[ 32.186021] [<ffffffff810ac298>] ? sched_clock_cpu+0xa8/0x120
[ 32.186021] [<ffffffff810d181d>] ? trace_hardirqs_off+0xd/0x10
[ 32.186021] [<ffffffff810ac37f>] ? local_clock+0x6f/0x80
[ 32.186021] [<ffffffff81225910>] ? load_elf_library+0x240/0x240
[ 32.186021] [<ffffffff81225910>] ? load_elf_library+0x240/0x240
[ 32.186021] [<ffffffff811d14a4>] search_binary_handler+0x194/0x4f0
[ 32.186021] [<ffffffff811d136f>] ? search_binary_handler+0x5f/0x4f0
[ 32.186021] [<ffffffff81225220>] ? compat_sys_ioctl+0x1510/0x1510
[ 32.186021] [<ffffffff812254b4>] load_script+0x294/0x2c0
[ 32.186021] [<ffffffff810d217f>] ? lock_release_holdtime.part.26+0xf/0x180
[ 32.186021] [<ffffffff81225220>] ? compat_sys_ioctl+0x1510/0x1510
[ 32.186021] [<ffffffff811d14a4>] search_binary_handler+0x194/0x4f0
[ 32.186021] [<ffffffff811d136f>] ? search_binary_handler+0x5f/0x4f0
[ 32.186021] [<ffffffff811d22cb>] do_execve_common.isra.25+0x50b/0x5b0
[ 32.186021] [<ffffffff811d1eea>] ? do_execve_common.isra.25+0x12a/0x5b0
[ 32.186021] [<ffffffff811d238b>] do_execve+0x1b/0x20
[ 32.186021] [<ffffffff811d26c4>] sys_execve+0x54/0x80
[ 32.186021] [<ffffffff816d8f99>] stub_execve+0x69/0xc0

I think this dereference qualifies for the task_lock exception (as noted
in kernel/cgroup.c), thus this patch ensures calling perf_event_comm
before giving up the task_lock.

Changelog -v2 (since <[email protected]>):
1) rebased to 3.7-rc4
2) slightly improved/updated commit msg and added more people to Cc

Cc: Peter Zijlstra <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Arnaldo Carvalho de Melo <[email protected]>
Signed-off-by: Hannes Frederic Sowa <[email protected]>
---
fs/exec.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/fs/exec.c b/fs/exec.c
index 0039055..a961b9d 100644
--- a/fs/exec.c
+++ b/fs/exec.c
@@ -1038,8 +1038,8 @@ void set_task_comm(struct task_struct *tsk, char *buf)
memset(tsk->comm, 0, TASK_COMM_LEN);
wmb();
strlcpy(tsk->comm, buf, sizeof(tsk->comm));
- task_unlock(tsk);
perf_event_comm(tsk);
+ task_unlock(tsk);
}

static void filename_to_taskname(char *tcomm, const char *fn, unsigned int len)


2012-11-21 19:40:18

by Hannes Frederic Sowa

[permalink] [raw]
Subject: Re: [PATCH] perf: call perf_event_comm under task_lock to fix suspicious rcu usage

Ping, this problem still persists in v3.7-rc6. Could someone have a look?

On Sat, Nov 10, 2012 at 06:32:28AM +0100, Hannes Frederic Sowa wrote:
> Following RCU warning showed up while executing a shebang-script under
> perf-record (could even be an empty script) on a 3.7-rc4 stable kernel:
>
> [ 32.185108]
> [ 32.185332] ===============================
> [ 32.185602] [ INFO: suspicious RCU usage. ]
> [ 32.185903] 3.7.0-rc4 #1 Not tainted
> [ 32.186021] -------------------------------
> [ 32.186021] include/linux/cgroup.h:566 suspicious rcu_dereference_check() usage!
> [ 32.186021]
> [ 32.186021] other info that might help us debug this:
> [ 32.186021]
> [ 32.186021]
> [ 32.186021] rcu_scheduler_active = 1, debug_locks = 0
> [ 32.186021] 1 lock held by empty.sh/556:
> [ 32.186021] #0: (&sig->cred_guard_mutex){+.+.+.}, at: [<ffffffff811d1d16>] prepare_bprm_creds+0x36/0x80
> [ 32.186021]
> [ 32.186021] stack backtrace:
> [ 32.186021] Pid: 556, comm: empty.sh Not tainted 3.7.0-rc4 #1
> [ 32.186021] Call Trace:
> [ 32.186021] [<ffffffff810d336d>] lockdep_rcu_suspicious+0xfd/0x130
> [ 32.186021] [<ffffffff81153de6>] perf_event_comm+0x436/0x610
> [ 32.186021] [<ffffffff810d181d>] ? trace_hardirqs_off+0xd/0x10
> [ 32.186021] [<ffffffff810ac37f>] ? local_clock+0x6f/0x80
> [ 32.186021] [<ffffffff810d217f>] ? lock_release_holdtime.part.26+0xf/0x180
> [ 32.186021] [<ffffffff811d1bd3>] set_task_comm+0x73/0x180
> [ 32.186021] [<ffffffff811d24ba>] setup_new_exec+0x9a/0x210
> [ 32.186021] [<ffffffff81225cf3>] load_elf_binary+0x3e3/0x1ab0
> [ 32.186021] [<ffffffff810ac0f5>] ? sched_clock_local+0x25/0xa0
> [ 32.186021] [<ffffffff810ac298>] ? sched_clock_cpu+0xa8/0x120
> [ 32.186021] [<ffffffff810d181d>] ? trace_hardirqs_off+0xd/0x10
> [ 32.186021] [<ffffffff810ac37f>] ? local_clock+0x6f/0x80
> [ 32.186021] [<ffffffff81225910>] ? load_elf_library+0x240/0x240
> [ 32.186021] [<ffffffff81225910>] ? load_elf_library+0x240/0x240
> [ 32.186021] [<ffffffff811d14a4>] search_binary_handler+0x194/0x4f0
> [ 32.186021] [<ffffffff811d136f>] ? search_binary_handler+0x5f/0x4f0
> [ 32.186021] [<ffffffff81225220>] ? compat_sys_ioctl+0x1510/0x1510
> [ 32.186021] [<ffffffff812254b4>] load_script+0x294/0x2c0
> [ 32.186021] [<ffffffff810d217f>] ? lock_release_holdtime.part.26+0xf/0x180
> [ 32.186021] [<ffffffff81225220>] ? compat_sys_ioctl+0x1510/0x1510
> [ 32.186021] [<ffffffff811d14a4>] search_binary_handler+0x194/0x4f0
> [ 32.186021] [<ffffffff811d136f>] ? search_binary_handler+0x5f/0x4f0
> [ 32.186021] [<ffffffff811d22cb>] do_execve_common.isra.25+0x50b/0x5b0
> [ 32.186021] [<ffffffff811d1eea>] ? do_execve_common.isra.25+0x12a/0x5b0
> [ 32.186021] [<ffffffff811d238b>] do_execve+0x1b/0x20
> [ 32.186021] [<ffffffff811d26c4>] sys_execve+0x54/0x80
> [ 32.186021] [<ffffffff816d8f99>] stub_execve+0x69/0xc0
>
> I think this dereference qualifies for the task_lock exception (as noted
> in kernel/cgroup.c), thus this patch ensures calling perf_event_comm
> before giving up the task_lock.
>
> Changelog -v2 (since <[email protected]>):
> 1) rebased to 3.7-rc4
> 2) slightly improved/updated commit msg and added more people to Cc
>
> Cc: Peter Zijlstra <[email protected]>
> Cc: Paul Mackerras <[email protected]>
> Cc: Ingo Molnar <[email protected]>
> Cc: Arnaldo Carvalho de Melo <[email protected]>
> Signed-off-by: Hannes Frederic Sowa <[email protected]>
> ---
> fs/exec.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/fs/exec.c b/fs/exec.c
> index 0039055..a961b9d 100644
> --- a/fs/exec.c
> +++ b/fs/exec.c
> @@ -1038,8 +1038,8 @@ void set_task_comm(struct task_struct *tsk, char *buf)
> memset(tsk->comm, 0, TASK_COMM_LEN);
> wmb();
> strlcpy(tsk->comm, buf, sizeof(tsk->comm));
> - task_unlock(tsk);
> perf_event_comm(tsk);
> + task_unlock(tsk);
> }
>
> static void filename_to_taskname(char *tcomm, const char *fn, unsigned int len)
>