* kvm: RCU warning in async pf
@ 2012-04-03 0:54 Sasha Levin
2012-04-03 10:52 ` Gleb Natapov
2012-04-03 13:06 ` Paul E. McKenney
0 siblings, 2 replies; 17+ messages in thread
From: Sasha Levin @ 2012-04-03 0:54 UTC (permalink / raw)
To: Avi Kivity, Marcelo Tosatti, Gleb Natapov, Thomas Gleixner,
Peter Zijlstra, Ingo Molnar, Paul E. McKenney
Cc: kvm, linux-kernel, Dave Jones
Hi all,
I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
[12140.220507] ===============================
[12140.220507] [ INFO: suspicious RCU usage. ]
[12140.220507] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.220507] -------------------------------
[12140.220507] include/linux/rcupdate.h:729 rcu_read_lock() used illegally while idle!
[12140.220507]
[12140.220507] other info that might help us debug this:
[12140.220507]
[12140.220507]
[12140.220507] RCU used illegally from idle CPU!
[12140.220507] rcu_scheduler_active = 1, debug_locks = 1
[12140.220507] RCU used illegally from extended quiescent state!
[12140.220507] 4 locks held by swapper/1/0:
[12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
[12140.253991]
[12140.253991] stack backtrace:
[12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.253991] Call Trace:
[12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.253991] [<ffffffff810f3ce5>] select_task_rq_fair+0x115/0x5c0
[12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
[12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
[12140.253991]
[12140.253991] ===============================
[12140.253991] [ INFO: suspicious RCU usage. ]
[12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.253991] -------------------------------
[12140.253991] kernel/sched/fair.c:2716 suspicious rcu_dereference_check() usage!
[12140.253991]
[12140.253991] other info that might help us debug this:
[12140.253991]
[12140.253991]
[12140.253991] RCU used illegally from idle CPU!
[12140.253991] rcu_scheduler_active = 1, debug_locks = 1
[12140.253991] RCU used illegally from extended quiescent state!
[12140.253991] 4 locks held by swapper/1/0:
[12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
[12140.253991]
[12140.253991] stack backtrace:
[12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.253991] Call Trace:
[12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.253991] [<ffffffff810f3d4c>] select_task_rq_fair+0x17c/0x5c0
[12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
[12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
[12140.253991]
[12140.253991] ===============================
[12140.253991] [ INFO: suspicious RCU usage. ]
[12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.253991] -------------------------------
[12140.253991] kernel/sched/fair.c:2660 suspicious rcu_dereference_check() usage!
[12140.253991]
[12140.253991] other info that might help us debug this:
[12140.253991]
[12140.253991]
[12140.253991] RCU used illegally from idle CPU!
[12140.253991] rcu_scheduler_active = 1, debug_locks = 1
[12140.253991] RCU used illegally from extended quiescent state!
[12140.253991] 4 locks held by swapper/1/0:
[12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
[12140.253991]
[12140.253991] stack backtrace:
[12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.253991] Call Trace:
[12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.253991] [<ffffffff810f062f>] select_idle_sibling+0xaf/0x1c0
[12140.253991] [<ffffffff810f3f51>] select_task_rq_fair+0x381/0x5c0
[12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
[12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
[12140.253991]
[12140.253991] ===============================
[12140.253991] [ INFO: suspicious RCU usage. ]
[12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.253991] -------------------------------
[12140.253991] include/linux/rcupdate.h:750 rcu_read_unlock() used illegally while idle!
[12140.253991]
[12140.253991] other info that might help us debug this:
[12140.253991]
[12140.253991]
[12140.253991] RCU used illegally from idle CPU!
[12140.253991] rcu_scheduler_active = 1, debug_locks = 1
[12140.253991] RCU used illegally from extended quiescent state!
[12140.253991] 4 locks held by swapper/1/0:
[12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
[12140.253991]
[12140.253991] stack backtrace:
[12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.253991] Call Trace:
[12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.253991] [<ffffffff810f412a>] select_task_rq_fair+0x55a/0x5c0
[12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
[12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
[12140.623131]
[12140.623131] ===============================
[12140.623131] [ INFO: suspicious RCU usage. ]
[12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.623131] -------------------------------
[12140.623131] include/linux/rcupdate.h:729 rcu_read_lock() used illegally while idle!
[12140.623131]
[12140.623131] other info that might help us debug this:
[12140.623131]
[12140.623131]
[12140.623131] RCU used illegally from idle CPU!
[12140.623131] rcu_scheduler_active = 1, debug_locks = 1
[12140.623131] RCU used illegally from extended quiescent state!
[12140.623131] 4 locks held by swapper/1/0:
[12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
[12140.623131]
[12140.623131] stack backtrace:
[12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.623131] Call Trace:
[12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.623131] [<ffffffff810ea537>] ttwu_stat+0xc7/0x230
[12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
[12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
[12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
[12140.623131]
[12140.623131] ===============================
[12140.623131] [ INFO: suspicious RCU usage. ]
[12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.623131] -------------------------------
[12140.623131] kernel/sched/core.c:1375 suspicious rcu_dereference_check() usage!
[12140.623131]
[12140.623131] other info that might help us debug this:
[12140.623131]
[12140.623131]
[12140.623131] RCU used illegally from idle CPU!
[12140.623131] rcu_scheduler_active = 1, debug_locks = 1
[12140.623131] RCU used illegally from extended quiescent state!
[12140.623131] 4 locks held by swapper/1/0:
[12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
[12140.623131]
[12140.623131] stack backtrace:
[12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.623131] Call Trace:
[12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.623131] [<ffffffff810ea5a8>] ttwu_stat+0x138/0x230
[12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
[12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
[12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
[12140.623131]
[12140.623131] ===============================
[12140.623131] [ INFO: suspicious RCU usage. ]
[12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
[12140.623131] -------------------------------
[12140.623131] include/linux/rcupdate.h:750 rcu_read_unlock() used illegally while idle!
[12140.623131]
[12140.623131] other info that might help us debug this:
[12140.623131]
[12140.623131]
[12140.623131] RCU used illegally from idle CPU!
[12140.623131] rcu_scheduler_active = 1, debug_locks = 1
[12140.623131] RCU used illegally from extended quiescent state!
[12140.623131] 4 locks held by swapper/1/0:
[12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
[12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
[12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
[12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
[12140.623131]
[12140.623131] stack backtrace:
[12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
[12140.623131] Call Trace:
[12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
[12140.623131] [<ffffffff810ea643>] ttwu_stat+0x1d3/0x230
[12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
[12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
[12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
[12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
[12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
[12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
[12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
[12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
[12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
[12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
[12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
[12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
[12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
[12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
[12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
[12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
[12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
[12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
[12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
--
Sasha.
^ permalink raw reply [flat|nested] 17+ messages in thread* Re: kvm: RCU warning in async pf
2012-04-03 0:54 kvm: RCU warning in async pf Sasha Levin
@ 2012-04-03 10:52 ` Gleb Natapov
2012-04-04 12:30 ` Gleb Natapov
2012-04-03 13:06 ` Paul E. McKenney
1 sibling, 1 reply; 17+ messages in thread
From: Gleb Natapov @ 2012-04-03 10:52 UTC (permalink / raw)
To: Sasha Levin
Cc: Avi Kivity, Marcelo Tosatti, Thomas Gleixner, Peter Zijlstra,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
> Hi all,
>
> I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
>
> I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
>
This is not regular page fault. This is async page fault that tells the
guest that a page, previously swapped out by hypervisor, is now swapped
back in and it can happen while vcpu is idle. The code does not leave
idle state properly though. We probably need to call rcu_irq_enter()
there. Will look into it.
> [12140.220507] ===============================
> [12140.220507] [ INFO: suspicious RCU usage. ]
> [12140.220507] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.220507] -------------------------------
> [12140.220507] include/linux/rcupdate.h:729 rcu_read_lock() used illegally while idle!
> [12140.220507]
> [12140.220507] other info that might help us debug this:
> [12140.220507]
> [12140.220507]
> [12140.220507] RCU used illegally from idle CPU!
> [12140.220507] rcu_scheduler_active = 1, debug_locks = 1
> [12140.220507] RCU used illegally from extended quiescent state!
> [12140.220507] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f3ce5>] select_task_rq_fair+0x115/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.253991]
> [12140.253991] ===============================
> [12140.253991] [ INFO: suspicious RCU usage. ]
> [12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.253991] -------------------------------
> [12140.253991] kernel/sched/fair.c:2716 suspicious rcu_dereference_check() usage!
> [12140.253991]
> [12140.253991] other info that might help us debug this:
> [12140.253991]
> [12140.253991]
> [12140.253991] RCU used illegally from idle CPU!
> [12140.253991] rcu_scheduler_active = 1, debug_locks = 1
> [12140.253991] RCU used illegally from extended quiescent state!
> [12140.253991] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f3d4c>] select_task_rq_fair+0x17c/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.253991]
> [12140.253991] ===============================
> [12140.253991] [ INFO: suspicious RCU usage. ]
> [12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.253991] -------------------------------
> [12140.253991] kernel/sched/fair.c:2660 suspicious rcu_dereference_check() usage!
> [12140.253991]
> [12140.253991] other info that might help us debug this:
> [12140.253991]
> [12140.253991]
> [12140.253991] RCU used illegally from idle CPU!
> [12140.253991] rcu_scheduler_active = 1, debug_locks = 1
> [12140.253991] RCU used illegally from extended quiescent state!
> [12140.253991] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f062f>] select_idle_sibling+0xaf/0x1c0
> [12140.253991] [<ffffffff810f3f51>] select_task_rq_fair+0x381/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.253991]
> [12140.253991] ===============================
> [12140.253991] [ INFO: suspicious RCU usage. ]
> [12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.253991] -------------------------------
> [12140.253991] include/linux/rcupdate.h:750 rcu_read_unlock() used illegally while idle!
> [12140.253991]
> [12140.253991] other info that might help us debug this:
> [12140.253991]
> [12140.253991]
> [12140.253991] RCU used illegally from idle CPU!
> [12140.253991] rcu_scheduler_active = 1, debug_locks = 1
> [12140.253991] RCU used illegally from extended quiescent state!
> [12140.253991] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f412a>] select_task_rq_fair+0x55a/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.623131]
> [12140.623131] ===============================
> [12140.623131] [ INFO: suspicious RCU usage. ]
> [12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.623131] -------------------------------
> [12140.623131] include/linux/rcupdate.h:729 rcu_read_lock() used illegally while idle!
> [12140.623131]
> [12140.623131] other info that might help us debug this:
> [12140.623131]
> [12140.623131]
> [12140.623131] RCU used illegally from idle CPU!
> [12140.623131] rcu_scheduler_active = 1, debug_locks = 1
> [12140.623131] RCU used illegally from extended quiescent state!
> [12140.623131] 4 locks held by swapper/1/0:
> [12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
> [12140.623131]
> [12140.623131] stack backtrace:
> [12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.623131] Call Trace:
> [12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.623131] [<ffffffff810ea537>] ttwu_stat+0xc7/0x230
> [12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
> [12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
> [12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.623131]
> [12140.623131] ===============================
> [12140.623131] [ INFO: suspicious RCU usage. ]
> [12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.623131] -------------------------------
> [12140.623131] kernel/sched/core.c:1375 suspicious rcu_dereference_check() usage!
> [12140.623131]
> [12140.623131] other info that might help us debug this:
> [12140.623131]
> [12140.623131]
> [12140.623131] RCU used illegally from idle CPU!
> [12140.623131] rcu_scheduler_active = 1, debug_locks = 1
> [12140.623131] RCU used illegally from extended quiescent state!
> [12140.623131] 4 locks held by swapper/1/0:
> [12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
> [12140.623131]
> [12140.623131] stack backtrace:
> [12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.623131] Call Trace:
> [12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.623131] [<ffffffff810ea5a8>] ttwu_stat+0x138/0x230
> [12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
> [12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
> [12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.623131]
> [12140.623131] ===============================
> [12140.623131] [ INFO: suspicious RCU usage. ]
> [12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.623131] -------------------------------
> [12140.623131] include/linux/rcupdate.h:750 rcu_read_unlock() used illegally while idle!
> [12140.623131]
> [12140.623131] other info that might help us debug this:
> [12140.623131]
> [12140.623131]
> [12140.623131] RCU used illegally from idle CPU!
> [12140.623131] rcu_scheduler_active = 1, debug_locks = 1
> [12140.623131] RCU used illegally from extended quiescent state!
> [12140.623131] 4 locks held by swapper/1/0:
> [12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
> [12140.623131]
> [12140.623131] stack backtrace:
> [12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.623131] Call Trace:
> [12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.623131] [<ffffffff810ea643>] ttwu_stat+0x1d3/0x230
> [12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
> [12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
> [12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
>
> --
>
> Sasha.
--
Gleb.
^ permalink raw reply [flat|nested] 17+ messages in thread* Re: kvm: RCU warning in async pf
2012-04-03 10:52 ` Gleb Natapov
@ 2012-04-04 12:30 ` Gleb Natapov
2012-04-04 14:04 ` Paul E. McKenney
` (3 more replies)
0 siblings, 4 replies; 17+ messages in thread
From: Gleb Natapov @ 2012-04-04 12:30 UTC (permalink / raw)
To: Sasha Levin
Cc: Avi Kivity, Marcelo Tosatti, Thomas Gleixner, Peter Zijlstra,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Tue, Apr 03, 2012 at 01:52:26PM +0300, Gleb Natapov wrote:
> On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
> > Hi all,
> >
> > I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
> >
> > I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
> >
> This is not regular page fault. This is async page fault that tells the
> guest that a page, previously swapped out by hypervisor, is now swapped
> back in and it can happen while vcpu is idle. The code does not leave
> idle state properly though. We probably need to call rcu_irq_enter()
> there. Will look into it.
>
The patch below solves it for me:
"Page ready" async PF can kick vcpu out of idle state much like IRQ.
We need to tell RCU about this.
Signed-off-by: Gleb Natapov <gleb@redhat.com>
diff --git a/arch/x86/kernel/kvm.c b/arch/x86/kernel/kvm.c
index f0c6fd6..380079f 100644
--- a/arch/x86/kernel/kvm.c
+++ b/arch/x86/kernel/kvm.c
@@ -38,6 +38,7 @@
#include <asm/traps.h>
#include <asm/desc.h>
#include <asm/tlbflush.h>
+#include <asm/idle.h>
static int kvmapf = 1;
@@ -253,7 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
kvm_async_pf_task_wait((u32)read_cr2());
break;
case KVM_PV_REASON_PAGE_READY:
+ rcu_irq_enter();
+ exit_idle();
kvm_async_pf_task_wake((u32)read_cr2());
+ rcu_irq_exit();
break;
}
}
--
Gleb.
^ permalink raw reply related [flat|nested] 17+ messages in thread* Re: kvm: RCU warning in async pf
2012-04-04 12:30 ` Gleb Natapov
@ 2012-04-04 14:04 ` Paul E. McKenney
2012-04-04 14:18 ` Gleb Natapov
2012-04-04 20:13 ` Sasha Levin
` (2 subsequent siblings)
3 siblings, 1 reply; 17+ messages in thread
From: Paul E. McKenney @ 2012-04-04 14:04 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Peter Zijlstra, Ingo Molnar, kvm, linux-kernel, Dave Jones
On Wed, Apr 04, 2012 at 03:30:33PM +0300, Gleb Natapov wrote:
> On Tue, Apr 03, 2012 at 01:52:26PM +0300, Gleb Natapov wrote:
> > On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
> > > Hi all,
> > >
> > > I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
> > >
> > > I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
> > >
> > This is not regular page fault. This is async page fault that tells the
> > guest that a page, previously swapped out by hypervisor, is now swapped
> > back in and it can happen while vcpu is idle. The code does not leave
> > idle state properly though. We probably need to call rcu_irq_enter()
> > there. Will look into it.
> >
>
> The patch below solves it for me:
>
> "Page ready" async PF can kick vcpu out of idle state much like IRQ.
> We need to tell RCU about this.
This is invoked from an exception or interrupt handler, not from
process-level code? If so:
Reviewed-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> Signed-off-by: Gleb Natapov <gleb@redhat.com>
> diff --git a/arch/x86/kernel/kvm.c b/arch/x86/kernel/kvm.c
> index f0c6fd6..380079f 100644
> --- a/arch/x86/kernel/kvm.c
> +++ b/arch/x86/kernel/kvm.c
> @@ -38,6 +38,7 @@
> #include <asm/traps.h>
> #include <asm/desc.h>
> #include <asm/tlbflush.h>
> +#include <asm/idle.h>
>
> static int kvmapf = 1;
>
> @@ -253,7 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
> kvm_async_pf_task_wait((u32)read_cr2());
> break;
> case KVM_PV_REASON_PAGE_READY:
> + rcu_irq_enter();
> + exit_idle();
> kvm_async_pf_task_wake((u32)read_cr2());
> + rcu_irq_exit();
> break;
> }
> }
> --
> Gleb.
>
^ permalink raw reply [flat|nested] 17+ messages in thread* Re: kvm: RCU warning in async pf
2012-04-04 14:04 ` Paul E. McKenney
@ 2012-04-04 14:18 ` Gleb Natapov
0 siblings, 0 replies; 17+ messages in thread
From: Gleb Natapov @ 2012-04-04 14:18 UTC (permalink / raw)
To: Paul E. McKenney
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Peter Zijlstra, Ingo Molnar, kvm, linux-kernel, Dave Jones
On Wed, Apr 04, 2012 at 07:04:16AM -0700, Paul E. McKenney wrote:
> On Wed, Apr 04, 2012 at 03:30:33PM +0300, Gleb Natapov wrote:
> > On Tue, Apr 03, 2012 at 01:52:26PM +0300, Gleb Natapov wrote:
> > > On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
> > > > Hi all,
> > > >
> > > > I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
> > > >
> > > > I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
> > > >
> > > This is not regular page fault. This is async page fault that tells the
> > > guest that a page, previously swapped out by hypervisor, is now swapped
> > > back in and it can happen while vcpu is idle. The code does not leave
> > > idle state properly though. We probably need to call rcu_irq_enter()
> > > there. Will look into it.
> > >
> >
> > The patch below solves it for me:
> >
> > "Page ready" async PF can kick vcpu out of idle state much like IRQ.
> > We need to tell RCU about this.
>
> This is invoked from an exception or interrupt handler, not from
> process-level code? If so:
>
>From an exception.
> Reviewed-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
>
> > Signed-off-by: Gleb Natapov <gleb@redhat.com>
> > diff --git a/arch/x86/kernel/kvm.c b/arch/x86/kernel/kvm.c
> > index f0c6fd6..380079f 100644
> > --- a/arch/x86/kernel/kvm.c
> > +++ b/arch/x86/kernel/kvm.c
> > @@ -38,6 +38,7 @@
> > #include <asm/traps.h>
> > #include <asm/desc.h>
> > #include <asm/tlbflush.h>
> > +#include <asm/idle.h>
> >
> > static int kvmapf = 1;
> >
> > @@ -253,7 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
> > kvm_async_pf_task_wait((u32)read_cr2());
> > break;
> > case KVM_PV_REASON_PAGE_READY:
> > + rcu_irq_enter();
> > + exit_idle();
> > kvm_async_pf_task_wake((u32)read_cr2());
> > + rcu_irq_exit();
> > break;
> > }
> > }
> > --
> > Gleb.
> >
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
--
Gleb.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-04 12:30 ` Gleb Natapov
2012-04-04 14:04 ` Paul E. McKenney
@ 2012-04-04 20:13 ` Sasha Levin
2012-04-05 16:10 ` Avi Kivity
2012-04-14 9:44 ` Peter Zijlstra
3 siblings, 0 replies; 17+ messages in thread
From: Sasha Levin @ 2012-04-04 20:13 UTC (permalink / raw)
To: Gleb Natapov
Cc: Avi Kivity, Marcelo Tosatti, Thomas Gleixner, Peter Zijlstra,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Wed, Apr 4, 2012 at 2:30 PM, Gleb Natapov <gleb@redhat.com> wrote:
> On Tue, Apr 03, 2012 at 01:52:26PM +0300, Gleb Natapov wrote:
>> On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
>> > Hi all,
>> >
>> > I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
>> >
>> > I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
>> >
>> This is not regular page fault. This is async page fault that tells the
>> guest that a page, previously swapped out by hypervisor, is now swapped
>> back in and it can happen while vcpu is idle. The code does not leave
>> idle state properly though. We probably need to call rcu_irq_enter()
>> there. Will look into it.
>>
>
> The patch below solves it for me:
>
> "Page ready" async PF can kick vcpu out of idle state much like IRQ.
> We need to tell RCU about this.
Looks good here.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-04 12:30 ` Gleb Natapov
2012-04-04 14:04 ` Paul E. McKenney
2012-04-04 20:13 ` Sasha Levin
@ 2012-04-05 16:10 ` Avi Kivity
2012-04-14 9:44 ` Peter Zijlstra
3 siblings, 0 replies; 17+ messages in thread
From: Avi Kivity @ 2012-04-05 16:10 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Marcelo Tosatti, Thomas Gleixner, Peter Zijlstra,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On 04/04/2012 03:30 PM, Gleb Natapov wrote:
> On Tue, Apr 03, 2012 at 01:52:26PM +0300, Gleb Natapov wrote:
> > On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
> > > Hi all,
> > >
> > > I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
> > >
> > > I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
> > >
> > This is not regular page fault. This is async page fault that tells the
> > guest that a page, previously swapped out by hypervisor, is now swapped
> > back in and it can happen while vcpu is idle. The code does not leave
> > idle state properly though. We probably need to call rcu_irq_enter()
> > there. Will look into it.
> >
>
> The patch below solves it for me:
>
> "Page ready" async PF can kick vcpu out of idle state much like IRQ.
> We need to tell RCU about this.
>
>
Applied it, thanks.
--
error compiling committee.c: too many arguments to function
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-04 12:30 ` Gleb Natapov
` (2 preceding siblings ...)
2012-04-05 16:10 ` Avi Kivity
@ 2012-04-14 9:44 ` Peter Zijlstra
2012-04-16 10:28 ` Gleb Natapov
3 siblings, 1 reply; 17+ messages in thread
From: Peter Zijlstra @ 2012-04-14 9:44 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Wed, 2012-04-04 at 15:30 +0300, Gleb Natapov wrote:
>
> @@ -253,7 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
> kvm_async_pf_task_wait((u32)read_cr2());
> break;
> case KVM_PV_REASON_PAGE_READY:
> + rcu_irq_enter();
> + exit_idle();
> kvm_async_pf_task_wake((u32)read_cr2());
> + rcu_irq_exit();
> break;
> }
> }
Wouldn't irq_enter() / irq_exit() be more appropriate? You're basically
taking an interrupt/exception from idle, irq_enter() will fix up
everything that needs fixing up, including time sources (which the
scheduler expects to be up-to-date).
^ permalink raw reply [flat|nested] 17+ messages in thread* Re: kvm: RCU warning in async pf
2012-04-14 9:44 ` Peter Zijlstra
@ 2012-04-16 10:28 ` Gleb Natapov
2012-04-16 12:58 ` Gleb Natapov
0 siblings, 1 reply; 17+ messages in thread
From: Gleb Natapov @ 2012-04-16 10:28 UTC (permalink / raw)
To: Peter Zijlstra
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Sat, Apr 14, 2012 at 11:44:53AM +0200, Peter Zijlstra wrote:
> On Wed, 2012-04-04 at 15:30 +0300, Gleb Natapov wrote:
> >
> > @@ -253,7 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
> > kvm_async_pf_task_wait((u32)read_cr2());
> > break;
> > case KVM_PV_REASON_PAGE_READY:
> > + rcu_irq_enter();
> > + exit_idle();
> > kvm_async_pf_task_wake((u32)read_cr2());
> > + rcu_irq_exit();
> > break;
> > }
> > }
>
> Wouldn't irq_enter() / irq_exit() be more appropriate? You're basically
> taking an interrupt/exception from idle, irq_enter() will fix up
> everything that needs fixing up, including time sources (which the
> scheduler expects to be up-to-date).
>
You are right. Will send a patch.
--
Gleb.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 10:28 ` Gleb Natapov
@ 2012-04-16 12:58 ` Gleb Natapov
2012-04-16 13:05 ` Peter Zijlstra
0 siblings, 1 reply; 17+ messages in thread
From: Gleb Natapov @ 2012-04-16 12:58 UTC (permalink / raw)
To: Peter Zijlstra
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, Apr 16, 2012 at 01:28:55PM +0300, Gleb Natapov wrote:
> On Sat, Apr 14, 2012 at 11:44:53AM +0200, Peter Zijlstra wrote:
> > On Wed, 2012-04-04 at 15:30 +0300, Gleb Natapov wrote:
> > >
> > > @@ -253,7 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
> > > kvm_async_pf_task_wait((u32)read_cr2());
> > > break;
> > > case KVM_PV_REASON_PAGE_READY:
> > > + rcu_irq_enter();
> > > + exit_idle();
> > > kvm_async_pf_task_wake((u32)read_cr2());
> > > + rcu_irq_exit();
> > > break;
> > > }
> > > }
> >
> > Wouldn't irq_enter() / irq_exit() be more appropriate? You're basically
> > taking an interrupt/exception from idle, irq_enter() will fix up
> > everything that needs fixing up, including time sources (which the
> > scheduler expects to be up-to-date).
> >
> You are right. Will send a patch.
>
KVM: Call irq_enter() instead of rcu_irq_enter() during async PF.
As Peter noted there are more things that should be done when leaving
idle state. irq_(enter|exit)() does them and also call rcu functions.
Signed-off-by: Gleb Natapov <gleb@redhat.com>
diff --git a/arch/x86/kernel/kvm.c b/arch/x86/kernel/kvm.c
index b8ba6e4..83a48f6 100644
--- a/arch/x86/kernel/kvm.c
+++ b/arch/x86/kernel/kvm.c
@@ -254,10 +254,10 @@ do_async_page_fault(struct pt_regs *regs, unsigned long error_code)
kvm_async_pf_task_wait((u32)read_cr2());
break;
case KVM_PV_REASON_PAGE_READY:
- rcu_irq_enter();
+ irq_enter();
exit_idle();
kvm_async_pf_task_wake((u32)read_cr2());
- rcu_irq_exit();
+ irq_exit();
break;
}
}
--
Gleb.
^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 12:58 ` Gleb Natapov
@ 2012-04-16 13:05 ` Peter Zijlstra
2012-04-16 13:08 ` Gleb Natapov
0 siblings, 1 reply; 17+ messages in thread
From: Peter Zijlstra @ 2012-04-16 13:05 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, 2012-04-16 at 15:58 +0300, Gleb Natapov wrote:
> - rcu_irq_enter();
> + irq_enter();
> exit_idle();
Do we really need the exit_idle()? I can't remember other interrupt
handlers doing that.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 13:05 ` Peter Zijlstra
@ 2012-04-16 13:08 ` Gleb Natapov
2012-04-16 13:18 ` Peter Zijlstra
0 siblings, 1 reply; 17+ messages in thread
From: Gleb Natapov @ 2012-04-16 13:08 UTC (permalink / raw)
To: Peter Zijlstra
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, Apr 16, 2012 at 03:05:48PM +0200, Peter Zijlstra wrote:
> On Mon, 2012-04-16 at 15:58 +0300, Gleb Natapov wrote:
> > - rcu_irq_enter();
> > + irq_enter();
> > exit_idle();
>
> Do we really need the exit_idle()? I can't remember other interrupt
> handlers doing that.
They do. That's where I got the idea.
--
Gleb.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 13:08 ` Gleb Natapov
@ 2012-04-16 13:18 ` Peter Zijlstra
2012-04-16 13:27 ` Peter Zijlstra
0 siblings, 1 reply; 17+ messages in thread
From: Peter Zijlstra @ 2012-04-16 13:18 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, 2012-04-16 at 16:08 +0300, Gleb Natapov wrote:
> On Mon, Apr 16, 2012 at 03:05:48PM +0200, Peter Zijlstra wrote:
> > On Mon, 2012-04-16 at 15:58 +0300, Gleb Natapov wrote:
> > > - rcu_irq_enter();
> > > + irq_enter();
> > > exit_idle();
> >
> > Do we really need the exit_idle()? I can't remember other interrupt
> > handlers doing that.
> They do. That's where I got the idea.
Some do.. some don't.. /me goes have a look what this exit_idle nonsense
is all about. Looks to be something broken.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 13:18 ` Peter Zijlstra
@ 2012-04-16 13:27 ` Peter Zijlstra
2012-04-16 14:17 ` Gleb Natapov
0 siblings, 1 reply; 17+ messages in thread
From: Peter Zijlstra @ 2012-04-16 13:27 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, 2012-04-16 at 15:18 +0200, Peter Zijlstra wrote:
> On Mon, 2012-04-16 at 16:08 +0300, Gleb Natapov wrote:
> > On Mon, Apr 16, 2012 at 03:05:48PM +0200, Peter Zijlstra wrote:
> > > On Mon, 2012-04-16 at 15:58 +0300, Gleb Natapov wrote:
> > > > - rcu_irq_enter();
> > > > + irq_enter();
> > > > exit_idle();
> > >
> > > Do we really need the exit_idle()? I can't remember other interrupt
> > > handlers doing that.
> > They do. That's where I got the idea.
>
> Some do.. some don't.. /me goes have a look what this exit_idle nonsense
> is all about. Looks to be something broken.
Yeah, its broken and the whole implementation is crap anyway. There's
only one user (drivers/idle/i7300_idle.c) so it likely doesn't matter
(much) anyway.
Thomas, can we rip that stuff out? or do we have to like actually fix
it?
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 13:27 ` Peter Zijlstra
@ 2012-04-16 14:17 ` Gleb Natapov
2012-04-16 14:24 ` Peter Zijlstra
0 siblings, 1 reply; 17+ messages in thread
From: Gleb Natapov @ 2012-04-16 14:17 UTC (permalink / raw)
To: Peter Zijlstra
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, Apr 16, 2012 at 03:27:20PM +0200, Peter Zijlstra wrote:
> On Mon, 2012-04-16 at 15:18 +0200, Peter Zijlstra wrote:
> > On Mon, 2012-04-16 at 16:08 +0300, Gleb Natapov wrote:
> > > On Mon, Apr 16, 2012 at 03:05:48PM +0200, Peter Zijlstra wrote:
> > > > On Mon, 2012-04-16 at 15:58 +0300, Gleb Natapov wrote:
> > > > > - rcu_irq_enter();
> > > > > + irq_enter();
> > > > > exit_idle();
> > > >
> > > > Do we really need the exit_idle()? I can't remember other interrupt
> > > > handlers doing that.
> > > They do. That's where I got the idea.
> >
> > Some do.. some don't.. /me goes have a look what this exit_idle nonsense
> > is all about. Looks to be something broken.
>
> Yeah, its broken and the whole implementation is crap anyway. There's
> only one user (drivers/idle/i7300_idle.c) so it likely doesn't matter
> (much) anyway.
>
Should I resend the patch with removal of exit_idle() call or it will
be removed by a patch that removes exit_idle() completely later?
> Thomas, can we rip that stuff out? or do we have to like actually fix
> it?
--
Gleb.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-16 14:17 ` Gleb Natapov
@ 2012-04-16 14:24 ` Peter Zijlstra
0 siblings, 0 replies; 17+ messages in thread
From: Peter Zijlstra @ 2012-04-16 14:24 UTC (permalink / raw)
To: Gleb Natapov
Cc: Sasha Levin, Avi Kivity, Marcelo Tosatti, Thomas Gleixner,
Ingo Molnar, Paul E. McKenney, kvm, linux-kernel, Dave Jones
On Mon, 2012-04-16 at 17:17 +0300, Gleb Natapov wrote:
> Should I resend the patch with removal of exit_idle() call or it will
> be removed by a patch that removes exit_idle() completely later?
>
I think we can do the latter, once we decided what to do with that stuff
we can clean it up/remove it whole sale.
^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: kvm: RCU warning in async pf
2012-04-03 0:54 kvm: RCU warning in async pf Sasha Levin
2012-04-03 10:52 ` Gleb Natapov
@ 2012-04-03 13:06 ` Paul E. McKenney
1 sibling, 0 replies; 17+ messages in thread
From: Paul E. McKenney @ 2012-04-03 13:06 UTC (permalink / raw)
To: Sasha Levin
Cc: Avi Kivity, Marcelo Tosatti, Gleb Natapov, Thomas Gleixner,
Peter Zijlstra, Ingo Molnar, kvm, linux-kernel, Dave Jones
On Mon, Apr 02, 2012 at 08:54:32PM -0400, Sasha Levin wrote:
> Hi all,
>
> I got the spew at the bottom of the mail in a KVM guest using the KVM tools and running trinity.
>
> I'm not quite sure how default_idle managed to trigger a pagefault, so that part looks odd to me.
Wrapping the offending RCU read-side critical section in RCU_NONIDLE()
is the intended solution -- though that assumes that you can tell where
the page fault will occur.
Thanx, Paul
> [12140.220507] ===============================
> [12140.220507] [ INFO: suspicious RCU usage. ]
> [12140.220507] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.220507] -------------------------------
> [12140.220507] include/linux/rcupdate.h:729 rcu_read_lock() used illegally while idle!
> [12140.220507]
> [12140.220507] other info that might help us debug this:
> [12140.220507]
> [12140.220507]
> [12140.220507] RCU used illegally from idle CPU!
> [12140.220507] rcu_scheduler_active = 1, debug_locks = 1
> [12140.220507] RCU used illegally from extended quiescent state!
> [12140.220507] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f3ce5>] select_task_rq_fair+0x115/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.253991]
> [12140.253991] ===============================
> [12140.253991] [ INFO: suspicious RCU usage. ]
> [12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.253991] -------------------------------
> [12140.253991] kernel/sched/fair.c:2716 suspicious rcu_dereference_check() usage!
> [12140.253991]
> [12140.253991] other info that might help us debug this:
> [12140.253991]
> [12140.253991]
> [12140.253991] RCU used illegally from idle CPU!
> [12140.253991] rcu_scheduler_active = 1, debug_locks = 1
> [12140.253991] RCU used illegally from extended quiescent state!
> [12140.253991] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f3d4c>] select_task_rq_fair+0x17c/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.253991]
> [12140.253991] ===============================
> [12140.253991] [ INFO: suspicious RCU usage. ]
> [12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.253991] -------------------------------
> [12140.253991] kernel/sched/fair.c:2660 suspicious rcu_dereference_check() usage!
> [12140.253991]
> [12140.253991] other info that might help us debug this:
> [12140.253991]
> [12140.253991]
> [12140.253991] RCU used illegally from idle CPU!
> [12140.253991] rcu_scheduler_active = 1, debug_locks = 1
> [12140.253991] RCU used illegally from extended quiescent state!
> [12140.253991] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f062f>] select_idle_sibling+0xaf/0x1c0
> [12140.253991] [<ffffffff810f3f51>] select_task_rq_fair+0x381/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.253991]
> [12140.253991] ===============================
> [12140.253991] [ INFO: suspicious RCU usage. ]
> [12140.253991] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.253991] -------------------------------
> [12140.253991] include/linux/rcupdate.h:750 rcu_read_unlock() used illegally while idle!
> [12140.253991]
> [12140.253991] other info that might help us debug this:
> [12140.253991]
> [12140.253991]
> [12140.253991] RCU used illegally from idle CPU!
> [12140.253991] rcu_scheduler_active = 1, debug_locks = 1
> [12140.253991] RCU used illegally from extended quiescent state!
> [12140.253991] 4 locks held by swapper/1/0:
> [12140.253991] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.253991] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.253991] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.253991] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810f3c80>] select_task_rq_fair+0xb0/0x5c0
> [12140.253991]
> [12140.253991] stack backtrace:
> [12140.253991] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.253991] Call Trace:
> [12140.253991] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.253991] [<ffffffff810f412a>] select_task_rq_fair+0x55a/0x5c0
> [12140.253991] [<ffffffff810f3c80>] ? select_task_rq_fair+0xb0/0x5c0
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.253991] [<ffffffff810ec561>] try_to_wake_up+0x191/0x290
> [12140.253991] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.253991] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.253991] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.253991] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.253991] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.253991] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.253991] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.253991] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.253991] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.253991] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.253991] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.253991] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.253991] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.253991] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.253991] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.253991] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.623131]
> [12140.623131] ===============================
> [12140.623131] [ INFO: suspicious RCU usage. ]
> [12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.623131] -------------------------------
> [12140.623131] include/linux/rcupdate.h:729 rcu_read_lock() used illegally while idle!
> [12140.623131]
> [12140.623131] other info that might help us debug this:
> [12140.623131]
> [12140.623131]
> [12140.623131] RCU used illegally from idle CPU!
> [12140.623131] rcu_scheduler_active = 1, debug_locks = 1
> [12140.623131] RCU used illegally from extended quiescent state!
> [12140.623131] 4 locks held by swapper/1/0:
> [12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
> [12140.623131]
> [12140.623131] stack backtrace:
> [12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.623131] Call Trace:
> [12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.623131] [<ffffffff810ea537>] ttwu_stat+0xc7/0x230
> [12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
> [12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
> [12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.623131]
> [12140.623131] ===============================
> [12140.623131] [ INFO: suspicious RCU usage. ]
> [12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.623131] -------------------------------
> [12140.623131] kernel/sched/core.c:1375 suspicious rcu_dereference_check() usage!
> [12140.623131]
> [12140.623131] other info that might help us debug this:
> [12140.623131]
> [12140.623131]
> [12140.623131] RCU used illegally from idle CPU!
> [12140.623131] rcu_scheduler_active = 1, debug_locks = 1
> [12140.623131] RCU used illegally from extended quiescent state!
> [12140.623131] 4 locks held by swapper/1/0:
> [12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
> [12140.623131]
> [12140.623131] stack backtrace:
> [12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.623131] Call Trace:
> [12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.623131] [<ffffffff810ea5a8>] ttwu_stat+0x138/0x230
> [12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
> [12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
> [12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
> [12140.623131]
> [12140.623131] ===============================
> [12140.623131] [ INFO: suspicious RCU usage. ]
> [12140.623131] 3.4.0-rc1-next-20120402-sasha #46 Tainted: G W
> [12140.623131] -------------------------------
> [12140.623131] include/linux/rcupdate.h:750 rcu_read_unlock() used illegally while idle!
> [12140.623131]
> [12140.623131] other info that might help us debug this:
> [12140.623131]
> [12140.623131]
> [12140.623131] RCU used illegally from idle CPU!
> [12140.623131] rcu_scheduler_active = 1, debug_locks = 1
> [12140.623131] RCU used illegally from extended quiescent state!
> [12140.623131] 4 locks held by swapper/1/0:
> [12140.623131] #0: (&(&async_pf_sleepers[i].lock)->rlock){..-...}, at: [<ffffffff8107cdc8>] kvm_async_pf_task_wake+0x48/0x130
> [12140.623131] #1: (&n.wq){......}, at: [<ffffffff810e200d>] __wake_up+0x2d/0x70
> [12140.623131] #2: (&p->pi_lock){-.-.-.}, at: [<ffffffff810ec404>] try_to_wake_up+0x34/0x290
> [12140.623131] #3: (rcu_read_lock){.+.+..}, at: [<ffffffff810ea4c0>] ttwu_stat+0x50/0x230
> [12140.623131]
> [12140.623131] stack backtrace:
> [12140.623131] Pid: 0, comm: swapper/1 Tainted: G W 3.4.0-rc1-next-20120402-sasha #46
> [12140.623131] Call Trace:
> [12140.623131] [<ffffffff81114173>] lockdep_rcu_suspicious+0x113/0x130
> [12140.623131] [<ffffffff810ea643>] ttwu_stat+0x1d3/0x230
> [12140.623131] [<ffffffff810ea4c0>] ? ttwu_stat+0x50/0x230
> [12140.623131] [<ffffffff810ec404>] ? try_to_wake_up+0x34/0x290
> [12140.623131] [<ffffffff810ec62a>] try_to_wake_up+0x25a/0x290
> [12140.623131] [<ffffffff81114850>] ? __lock_acquired+0x1c0/0x210
> [12140.623131] [<ffffffff810ec66d>] default_wake_function+0xd/0x10
> [12140.623131] [<ffffffff810d7208>] autoremove_wake_function+0x18/0x40
> [12140.623131] [<ffffffff810e11e2>] __wake_up_common+0x52/0x90
> [12140.623131] [<ffffffff810e200d>] ? __wake_up+0x2d/0x70
> [12140.623131] [<ffffffff810e2023>] __wake_up+0x43/0x70
> [12140.623131] [<ffffffff8107cb07>] apf_task_wake_one+0x87/0x90
> [12140.623131] [<ffffffff8107cdf5>] kvm_async_pf_task_wake+0x75/0x130
> [12140.623131] [<ffffffff8107d1e6>] do_async_page_fault+0x86/0xa0
> [12140.623131] [<ffffffff82657a55>] async_page_fault+0x25/0x30
> [12140.623131] [<ffffffff8107d626>] ? native_safe_halt+0x6/0x10
> [12140.623131] [<ffffffff81116fed>] ? trace_hardirqs_on+0xd/0x10
> [12140.623131] [<ffffffff8105857d>] default_idle+0x4d/0xa0
> [12140.623131] [<ffffffff810582af>] cpu_idle+0x11f/0x180
> [12140.623131] [<ffffffff8264b9e0>] ? setup_APIC_timer+0x88/0x8c
> [12140.623131] [<ffffffff8264b004>] start_secondary+0xe1/0xe8
>
> --
>
> Sasha.
>
^ permalink raw reply [flat|nested] 17+ messages in thread
end of thread, other threads:[~2012-04-16 14:24 UTC | newest]
Thread overview: 17+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2012-04-03 0:54 kvm: RCU warning in async pf Sasha Levin
2012-04-03 10:52 ` Gleb Natapov
2012-04-04 12:30 ` Gleb Natapov
2012-04-04 14:04 ` Paul E. McKenney
2012-04-04 14:18 ` Gleb Natapov
2012-04-04 20:13 ` Sasha Levin
2012-04-05 16:10 ` Avi Kivity
2012-04-14 9:44 ` Peter Zijlstra
2012-04-16 10:28 ` Gleb Natapov
2012-04-16 12:58 ` Gleb Natapov
2012-04-16 13:05 ` Peter Zijlstra
2012-04-16 13:08 ` Gleb Natapov
2012-04-16 13:18 ` Peter Zijlstra
2012-04-16 13:27 ` Peter Zijlstra
2012-04-16 14:17 ` Gleb Natapov
2012-04-16 14:24 ` Peter Zijlstra
2012-04-03 13:06 ` Paul E. McKenney
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox