Skip to contentSkip to conversation

cgroup: INFO: suspicious RCU usage. in cgroup_name

DISCUSSION Sasha Levin 3 participants 4 messages Mar 6, 2013 – Mar 7, 2013 cgroup

lore
Share & tools
lore
#0 lore raw

Hi all,

While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following:

[  450.180599] ===============================
[  450.181392] [ INFO: suspicious RCU usage. ]
[  450.182101] 3.9.0-rc1-next-20130305-sasha-00048-g35e9ec5-dirty #1032 Tainted: G        W
[  450.183482] -------------------------------
[  450.184343] include/linux/cgroup.h:429 suspicious rcu_dereference_check() usage!
[  450.185575]
[  450.185575] other info that might help us debug this:
[  450.185575]
[  450.186961]
[  450.186961] rcu_scheduler_active = 1, debug_locks = 1
[  450.188001] 4 locks held by kworker/u:0/6:
[  450.188646]  #0:  (khelper){.+.+.+}, at: [<ffffffff8112ba98>] process_one_work+0x238/0x570
[  450.190186]  #1:  ((&sub_info->work)){+.+.+.}, at: [<ffffffff8112ba98>] process_one_work+0x238/0x570
[  450.191824]  #2:  (&(&p->alloc_lock)->rlock){+.+.-.}, at: [<ffffffff812036d3>] dump_header+0x43/0xe0
[  450.193366]  #3:  (cpuset_buffer_lock){+.+...}, at: [<ffffffff811a06d0>] cpuset_print_task_mems_allowed+0x60/0x150
[  450.195281]
[  450.195281] stack backtrace:
[  450.195987] Pid: 6, comm: kworker/u:0 Tainted: G        W    3.9.0-rc1-next-20130305-sasha-00048-g35e9ec5-dirty #1032
[  450.197678] Call Trace:
[  450.198086]  [<ffffffff811793b3>] lockdep_rcu_suspicious+0x113/0x130
[  450.199077]  [<ffffffff811a0757>] cpuset_print_task_mems_allowed+0xe7/0x150
[  450.200263]  [<ffffffff8120370c>] dump_header+0x7c/0xe0
[  450.201135]  [<ffffffff81203972>] oom_kill_process+0x82/0x370
[  450.202048]  [<ffffffff812040cb>] out_of_memory+0x1ab/0x200
[  450.202921]  [<ffffffff83d44e00>] ? _raw_write_unlock_irq+0x50/0x80
[  450.204068]  [<ffffffff8120ad1f>] __alloc_pages_slowpath+0x5bf/0x700
[  450.205075]  [<ffffffff8120b135>] __alloc_pages_nodemask+0x2d5/0x400
[  450.206067]  [<ffffffff811047c8>] dup_task_struct+0x68/0x1c0
[  450.206975]  [<ffffffff81105b19>] copy_process+0xe9/0xfd0
[  450.207798]  [<ffffffff8114dd25>] ? sched_clock_local+0x25/0x90
[  450.208679]  [<ffffffff81127c50>] ? call_helper+0x20/0x20
[  450.209496]  [<ffffffff81106e6b>] do_fork+0xbb/0x280
[  450.210384]  [<ffffffff811070b1>] kernel_thread+0x21/0x30
[  450.211323]  [<ffffffff81127a93>] __call_usermodehelper+0x33/0xa0
[  450.212260]  [<ffffffff8112bbc8>] process_one_work+0x368/0x570
[  450.213201]  [<ffffffff8112ba98>] ? process_one_work+0x238/0x570
[  450.214248]  [<ffffffff8112d735>] worker_thread+0x1f5/0x340
[  450.215159]  [<ffffffff8112d540>] ? manage_workers+0x160/0x160
[  450.216078]  [<ffffffff81135ec2>] kthread+0xe2/0xf0
[  450.216901]  [<ffffffff8117e34a>] ? __lock_release+0x1da/0x1f0
[  450.217824]  [<ffffffff81135de0>] ? __init_kthread_worker+0x70/0x70
[  450.218791]  [<ffffffff83d4ddbc>] ret_from_fork+0x7c/0xb0
[  450.219627]  [<ffffffff81135de0>] ? __init_kthread_worker+0x70/0x70
[  450.220780] kworker/u:0 cpuset=/ mems_allowed=0

The offending commit looks like "cgroup: fix cgroup_path() vs rename() race".

Thanks,
Sasha

#1 lore raw
Quoted 10 lines · Sasha Levin

Hi all,

While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following:

[  450.180599] ===============================
[  450.181392] [ INFO: suspicious RCU usage. ]
[  450.182101] 3.9.0-rc1-next-20130305-sasha-00048-g35e9ec5-dirty #1032 Tainted: G        W
[  450.183482] -------------------------------
[  450.184343] include/linux/cgroup.h:429 suspicious rcu_dereference_check() usage!

My fault. I didn't trigger a OOM to test my patch. I thought the caller of cpuset_print_task_mems_allowed() already acquired rcu_read_lock()...

Thanks for the report.

#2 lore raw
In reply to Sasha Levin
Quoted 5 lines · Sasha Levin

Hi all,

While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following:

Quoted 14 lines
[  450.180599] ===============================
[  450.181392] [ INFO: suspicious RCU usage. ]
[  450.182101] 3.9.0-rc1-next-20130305-sasha-00048-g35e9ec5-dirty #1032 Tainted: G        W
[  450.183482] -------------------------------
[  450.184343] include/linux/cgroup.h:429 suspicious rcu_dereference_check() usage!
[  450.185575]
[  450.185575] other info that might help us debug this:
[  450.185575]
[  450.186961]
[  450.186961] rcu_scheduler_active = 1, debug_locks = 1
[  450.188001] 4 locks held by kworker/u:0/6:
[  450.188646]  #0:  (khelper){.+.+.+}, at: [<ffffffff8112ba98>] process_one_work+0x238/0x570
[  450.190186]  #1:  ((&sub_info->work)){+.+.+.}, at: [<ffffffff8112ba98>] process_one_work+0x238/0x570
[  450.191824]  #2:  (&(&p->alloc_lock)->rlock){+.+.-.}, at: [<ffffffff812036d3>] dump_header+0x43/0xe0

Hi, Sasha

I suppose this is the warn context:

cpuset_print_task_mems_allowed() -> task_cs() -> task_subsys_state()

and this is the definition of task_subsys_state():

#define task_subsys_state_check(task, subsys_id, __c)                   \
        rcu_dereference_check(task->cgroups->subsys[subsys_id],         \
                              lockdep_is_held(&task->alloc_lock) ||     \
                              cgroup_lock_is_held() || (__c))

the condition "lockdep_is_held(&task->alloc_lock)" should match (#2 lock), the warn doesn't make sense to me...

Regards,
Michael Wang

Quoted 42 lines
[  450.193366]  #3:  (cpuset_buffer_lock){+.+...}, at: [<ffffffff811a06d0>] cpuset_print_task_mems_allowed+0x60/0x150
[  450.195281]
[  450.195281] stack backtrace:
[  450.195987] Pid: 6, comm: kworker/u:0 Tainted: G        W    3.9.0-rc1-next-20130305-sasha-00048-g35e9ec5-dirty #1032
[  450.197678] Call Trace:
[  450.198086]  [<ffffffff811793b3>] lockdep_rcu_suspicious+0x113/0x130
[  450.199077]  [<ffffffff811a0757>] cpuset_print_task_mems_allowed+0xe7/0x150
[  450.200263]  [<ffffffff8120370c>] dump_header+0x7c/0xe0
[  450.201135]  [<ffffffff81203972>] oom_kill_process+0x82/0x370
[  450.202048]  [<ffffffff812040cb>] out_of_memory+0x1ab/0x200
[  450.202921]  [<ffffffff83d44e00>] ? _raw_write_unlock_irq+0x50/0x80
[  450.204068]  [<ffffffff8120ad1f>] __alloc_pages_slowpath+0x5bf/0x700
[  450.205075]  [<ffffffff8120b135>] __alloc_pages_nodemask+0x2d5/0x400
[  450.206067]  [<ffffffff811047c8>] dup_task_struct+0x68/0x1c0
[  450.206975]  [<ffffffff81105b19>] copy_process+0xe9/0xfd0
[  450.207798]  [<ffffffff8114dd25>] ? sched_clock_local+0x25/0x90
[  450.208679]  [<ffffffff81127c50>] ? call_helper+0x20/0x20
[  450.209496]  [<ffffffff81106e6b>] do_fork+0xbb/0x280
[  450.210384]  [<ffffffff811070b1>] kernel_thread+0x21/0x30
[  450.211323]  [<ffffffff81127a93>] __call_usermodehelper+0x33/0xa0
[  450.212260]  [<ffffffff8112bbc8>] process_one_work+0x368/0x570
[  450.213201]  [<ffffffff8112ba98>] ? process_one_work+0x238/0x570
[  450.214248]  [<ffffffff8112d735>] worker_thread+0x1f5/0x340
[  450.215159]  [<ffffffff8112d540>] ? manage_workers+0x160/0x160
[  450.216078]  [<ffffffff81135ec2>] kthread+0xe2/0xf0
[  450.216901]  [<ffffffff8117e34a>] ? __lock_release+0x1da/0x1f0
[  450.217824]  [<ffffffff81135de0>] ? __init_kthread_worker+0x70/0x70
[  450.218791]  [<ffffffff83d4ddbc>] ret_from_fork+0x7c/0xb0
[  450.219627]  [<ffffffff81135de0>] ? __init_kthread_worker+0x70/0x70
[  450.220780] kworker/u:0 cpuset=/ mems_allowed=0

The offending commit looks like "cgroup: fix cgroup_path() vs rename() race".

Thanks,
Sasha
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

#3 lore raw
Quoted 29 lines · Michael Wang
Quoted 5 lines · Sasha Levin

Hi all,

While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following:

Quoted 14 lines
[  450.180599] ===============================
[  450.181392] [ INFO: suspicious RCU usage. ]
[  450.182101] 3.9.0-rc1-next-20130305-sasha-00048-g35e9ec5-dirty #1032 Tainted: G        W
[  450.183482] -------------------------------
[  450.184343] include/linux/cgroup.h:429 suspicious rcu_dereference_check() usage!
[  450.185575]
[  450.185575] other info that might help us debug this:
[  450.185575]
[  450.186961]
[  450.186961] rcu_scheduler_active = 1, debug_locks = 1
[  450.188001] 4 locks held by kworker/u:0/6:
[  450.188646]  #0:  (khelper){.+.+.+}, at: [<ffffffff8112ba98>] process_one_work+0x238/0x570
[  450.190186]  #1:  ((&sub_info->work)){+.+.+.}, at: [<ffffffff8112ba98>] process_one_work+0x238/0x570
[  450.191824]  #2:  (&(&p->alloc_lock)->rlock){+.+.-.}, at: [<ffffffff812036d3>] dump_header+0x43/0xe0

Hi, Sasha

I suppose this is the warn context:

cpuset_print_task_mems_allowed() -> task_cs() -> task_subsys_state()

and this is the definition of task_subsys_state():

Quoted 8 lines
#define task_subsys_state_check(task, subsys_id, __c)                   \
        rcu_dereference_check(task->cgroups->subsys[subsys_id],         \
                              lockdep_is_held(&task->alloc_lock) ||     \
                              cgroup_lock_is_held() || (__c))

the condition "lockdep_is_held(&task->alloc_lock)" should match (#2 lock), the warn doesn't make sense to me...

nope..note this is 3.9-rc1-next, not 3.9-rc1.

The warning is from this:

/* Caller should hold rcu_read_lock() */
static inline const char *cgroup_name(const struct cgroup *cgrp)

{
        return rcu_dereference(cgrp->name)->name;
}

I've cooked up a patch. Will send out today.