My ToT kernel is:
fbcb3ab08e68 UPSTREAM: drm/atomic: Add drm_atomic_helper_best_encoder()
...make sure you're not too much older, since we've been fixing lots of RCU / Lockdep stuff
I also have the following relevant changes:
* A revert of commit 161967830028 ("CHROMIUM: MALI: Move fence signaling earlier"). See b/35586182
* Patch set #4 from <https://chromium-review.googlesource.com/c/500109/4>.
* This CL to turn on lockdep <https://chromium-review.googlesource.com/c/497931/>. There are other ways, but that's what I have right now.
---
When I do that, sometimes I see this when I login:
[ 123.934728] ===============================
[ 123.938915] [ INFO: suspicious RCU usage. ]
[ 123.943110] 4.4.64 #167 Not tainted
[ 123.946600] -------------------------------
[ 123.950782] /mnt/host/source/src/third_party/kernel/v4.4/include/linux/rcupdate.h:863 rcu_read_lock() used illegally while idle!
[ 123.954978]
[ 123.954980] ===============================
[ 123.954982] [ INFO: suspicious RCU usage. ]
[ 123.954986] 4.4.64 #167 Not tainted
[ 123.954987] -------------------------------
[ 123.954991] /mnt/host/source/src/third_party/kernel/v4.4/kernel/events/core.c:4476 suspicious rcu_dereference_check() usage!
[ 123.954992]
[ 123.954992] other info that might help us debug this:
[ 123.954992]
[ 123.954995]
[ 123.954995] RCU used illegally from idle CPU!
[ 123.954995] rcu_scheduler_active = 1, debug_locks = 1
[ 123.954996] RCU used illegally from extended quiescent state!
[ 123.954999] 2 locks held by swapper/0/0:
[ 123.955018] #0: (cpu_pm_notifier_lock){......}, at: [<ffffffc0003245e4>] cpu_pm_exit+0x24/0x50
[ 123.955030] #1: (rcu_read_lock){......}, at: [<ffffffc00032b708>] perf_event_update_userpage+0x0/0x258
[ 123.955031]
[ 123.955031] stack backtrace:
[ 123.955035] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.4.64 #167
[ 123.955037] Hardware name: Google Kevin (DT)
[ 123.955039] Call trace:
[ 123.955045] [<ffffffc000208ae4>] dump_backtrace+0x0/0x160
[ 123.955049] [<ffffffc000208d74>] show_stack+0x20/0x28
[ 123.955054] [<ffffffc000514470>] dump_stack+0xb4/0xf0
[ 123.955060] [<ffffffc000282de0>] lockdep_rcu_suspicious+0x104/0x114
[ 123.955065] [<ffffffc00032b7d8>] perf_event_update_userpage+0xd0/0x258
[ 123.955071] [<ffffffc000814b18>] armpmu_event_set_period+0x90/0xa0
[ 123.955075] [<ffffffc000814b80>] armpmu_start+0x58/0x70
[ 123.955079] [<ffffffc000814f6c>] cpu_pm_pmu_notify+0x158/0x174
[ 123.955085] [<ffffffc000247b28>] notifier_call_chain+0x60/0x94
[ 123.955088] [<ffffffc000247b9c>] __raw_notifier_call_chain+0x40/0x4c
[ 123.955092] [<ffffffc000324510>] cpu_pm_notify+0x40/0x64
[ 123.955096] [<ffffffc0003245f4>] cpu_pm_exit+0x34/0x50
[ 123.955100] [<ffffffc0007aa194>] arm_enter_idle_state+0x48/0x5c
[ 123.955106] [<ffffffc0007a800c>] cpuidle_enter_state+0x204/0x3bc
[ 123.955110] [<ffffffc0007a8238>] cpuidle_enter+0x34/0x40
[ 123.955114] [<ffffffc000276ca0>] call_cpuidle+0x68/0x74
[ 123.955117] [<ffffffc000277064>] cpu_startup_entry+0x3b8/0x424
[ 123.955122] [<ffffffc0009cb7c8>] rest_init+0x154/0x164
[ 123.955129] [<ffffffc000e0099c>] start_kernel+0x3c0/0x418
[ 123.955132] [<0000000000bd5000>] 0xbd5000
[ 123.955135]
[ 123.955136] ===============================
[ 123.955137] [ INFO: suspicious RCU usage. ]
[ 123.955139] 4.4.64 #167 Not tainted
[ 123.955141] -------------------------------
[ 123.955143] /mnt/host/source/src/third_party/kernel/v4.4/include/linux/rcupdate.h:914 rcu_read_unlock() used illegally while idle!
[ 123.955144]
[ 123.955144] other info that might help us debug this:
[ 123.955144]
[ 123.955146]
[ 123.955146] RCU used illegally from idle CPU!
[ 123.955146] rcu_scheduler_active = 1, debug_locks = 1
[ 123.955148] RCU used illegally from extended quiescent state!
[ 123.955149] 2 locks held by swapper/0/0:
[ 123.955158] #0: (cpu_pm_notifier_lock){......}, at: [<ffffffc0003245e4>] cpu_pm_exit+0x24/0x50
[ 123.955167] #1: (rcu_read_lock){......}, at: [<ffffffc00032b708>] perf_event_update_userpage+0x0/0x258
[ 123.955169]
[ 123.955169] stack backtrace:
[ 123.955172] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.4.64 #167
[ 123.955173] Hardware name: Google Kevin (DT)
[ 123.955174] Call trace:
[ 123.955178] [<ffffffc000208ae4>] dump_backtrace+0x0/0x160
[ 123.955183] [<ffffffc000208d74>] show_stack+0x20/0x28
[ 123.955185] [<ffffffc000514470>] dump_stack+0xb4/0xf0
[ 123.955190] [<ffffffc000282de0>] lockdep_rcu_suspicious+0x104/0x114
[ 123.955194] [<ffffffc00032b928>] perf_event_update_userpage+0x220/0x258
[ 123.955199] [<ffffffc000814b18>] armpmu_event_set_period+0x90/0xa0
[ 123.955202] [<ffffffc000814b80>] armpmu_start+0x58/0x70
[ 123.955206] [<ffffffc000814f6c>] cpu_pm_pmu_notify+0x158/0x174
[ 123.955211] [<ffffffc000247b28>] notifier_call_chain+0x60/0x94
[ 123.955215] [<ffffffc000247b9c>] __raw_notifier_call_chain+0x40/0x4c
[ 123.955218] [<ffffffc000324510>] cpu_pm_notify+0x40/0x64
[ 123.955222] [<ffffffc0003245f4>] cpu_pm_exit+0x34/0x50
[ 123.955225] [<ffffffc0007aa194>] arm_enter_idle_state+0x48/0x5c
[ 123.955229] [<ffffffc0007a800c>] cpuidle_enter_state+0x204/0x3bc
[ 123.955233] [<ffffffc0007a8238>] cpuidle_enter+0x34/0x40
[ 123.955237] [<ffffffc000276ca0>] call_cpuidle+0x68/0x74
[ 123.955240] [<ffffffc000277064>] cpu_startup_entry+0x3b8/0x424
[ 123.955244] [<ffffffc0009cb7c8>] rest_init+0x154/0x164
[ 123.955248] [<ffffffc000e0099c>] start_kernel+0x3c0/0x418
[ 123.955250] [<0000000000bd5000>] 0xbd5000
[ 123.979529] perf interrupt took too long (2536 > 2500), lowering kernel.perf_event_max_sample_rate to 50000
[ 124.046726] perf interrupt took too long (5016 > 5000), lowering kernel.perf_event_max_sample_rate to 25000
[ 124.389106]
[ 124.389106] other info that might help us debug this:
[ 124.389106]
[ 124.397103]
[ 124.397103] RCU used illegally from idle CPU!
[ 124.397103] rcu_scheduler_active = 1, debug_locks = 1
tended quiescent state!
0:
[ 124.417622] #0: (cpu_pm_notifier_lock){......}, at: [<ffffffc0003245e4>] cpu_pm_exit+0x24/0x50
[ 124.426480] #1: (rcu_read_lock){......}, at: [<ffffffc00032b708>] perf_event_update_userpage+0x0/0x258
[ 124.436025]
[ 124.436025] stack backtrace:
r/3 Not tainted 4.4.64 #167
n (DT)
[ 124.450739] Call trace:
[ 124.453191] [<ffffffc000208ae4>] dump_backtrace+0x0/0x160
[ 124.458586] [<ffffffc000208d74>] show_stack+0x20/0x28
[ 124.463637] [<ffffffc000514470>] dump_stack+0xb4/0xf0
[ 124.468691] [<ffffffc000282de0>] lockdep_rcu_suspicious+0x104/0x114
[ 124.474957] [<ffffffc00032b794>] perf_event_update_userpage+0x8c/0x258
[ 124.481484] [<ffffffc000814b18>] armpmu_event_set_period+0x90/0xa0
[ 124.487661] [<ffffffc000814b80>] armpmu_start+0x58/0x70
[ 124.492883] [<ffffffc000814f6c>] cpu_pm_pmu_notify+0x158/0x174
[ 124.498714] [<ffffffc000247b28>] notifier_call_chain+0x60/0x94
[ 124.504544] [<ffffffc000247b9c>] __raw_notifier_call_chain+0x40/0x4c
[ 124.510896] [<ffffffc000324510>] cpu_pm_notify+0x40/0x64
[ 124.516207] [<ffffffc0003245f4>] cpu_pm_exit+0x34/0x50
[ 124.521344] [<ffffffc0007aa194>] arm_enter_idle_state+0x48/0x5c
[ 124.527261] [<ffffffc0007a800c>] cpuidle_enter_state+0x204/0x3bc
[ 124.533265] [<ffffffc0007a8238>] cpuidle_enter+0x34/0x40
[ 124.538574] [<ffffffc000276ca0>] call_cpuidle+0x68/0x74
[ 124.543796] [<ffffffc000277064>] cpu_startup_entry+0x3b8/0x424
[ 124.549624] [<ffffffc00020e708>] secondary_start_kernel+0x150/0x15c
[ 124.555887] [<0000000000400e8c>] 0x400e8c
[ 124.641720] perf interrupt took too long (13307 > 9615), lowering kernel.perf_event_max_sample_rate to 13000
Comment 1 by diand...@chromium.org
, May 11 2017