Messages in this thread | | | Date | Thu, 20 Sep 2012 00:27:33 +0200 | From | Sasha Levin <> | Subject | Re: RCU idle CPU detection is broken in linux-next |
| |
On 09/19/2012 07:06 PM, Paul E. McKenney wrote: > On Wed, Sep 19, 2012 at 06:35:36PM +0200, Sasha Levin wrote: >> On 09/19/2012 05:39 PM, Paul E. McKenney wrote: >>> On Wed, Sep 12, 2012 at 07:56:48PM +0200, Sasha Levin wrote: >>>>> Hi Paul, >>>>> >>>>> While fuzzing using trinity inside a KVM tools guest, I've managed to trigger >>>>> "RCU used illegally from idle CPU!" warnings several times. >>>>> >>>>> There are a bunch of traces which seem to pop exactly at the same time and from >>>>> different places around the kernel. Here are several of them: >>> Hello, Sasha, >>> >>> OK, interesting. Could you please try reproducing with the diagnostic >>> patch shown below? >> >> Sure - here are the results (btw, it reproduces very easily): >> >> [ 13.525119] ================================================ >> [ 13.527165] [ BUG: lock held when returning to user space! ] >> [ 13.528752] 3.6.0-rc6-next-20120918-sasha-00002-g190c311-dirty #362 Tainted: GW >> [ 13.531314] ------------------------------------------------ >> [ 13.532918] init/1 is leaving the kernel with locks still held! >> [ 13.534574] 1 lock held by init/1: >> [ 13.535533] #0: (rcu_idle){.+.+..}, at: [<ffffffff811c36d0>] >> rcu_eqs_enter_common+0x1a0/0x9a0 >> >> I'm basically seeing lots of the above, so I can't even get to the point where I >> get the previous lockdep warnings. > > OK, that diagnostic patch was unhelpful. Back to the drawing board...
Not sure if it's related, but I'm seeing this during guest shutdown:
[ 602.020174] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.025010] Disabling non-boot CPUs ... [ 602.027180] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.780182] rcu-torture: rtc: ffffffff86480c00 ver: 745 tfle: 0 rta: 745 rtaf: 0 rtf: 744 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 5744 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=100) barrier: 0/0:0 [ 602.780182] rcu-torture: Reader Pipe: 805299 14 0 0 0 0 0 0 0 0 0 [ 602.780182] rcu-torture: Reader Batch: 805307 6 0 0 0 0 0 0 0 0 0 [ 602.780182] rcu-torture: Free-Block Circulation: 744 744 744 744 744 744 744 744 744 744 0 [ 602.784782] rcutorture thread rcu_torture_stats parking due to system shutdown [ 602.850145] rcutorture thread rcu_torture_stutter parking due to system shutdown [ 602.950402] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.952262] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.953628] rcutorture thread rcu_torture_fakewriter parking due to system shutdown [ 602.955100] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.956775] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.958121] rcutorture thread rcu_torture_fakewriter parking due to system shutdown [ 602.959677] rcutorture thread rcu_torture_fakewriter parking due to system shutdown [ 602.960213] rcutorture thread rcu_torture_reader parking due to system shutdown [ 602.960222] rcutorture thread rcu_torture_writer parking due to system shutdown [ 602.960263] rcutorture thread rcu_torture_fakewriter parking due to system shutdown [ 602.960277] rcutorture thread rcu_torture_reader parking due to system shutdown [ 667.060185] INFO: rcu_preempt detected stalls on CPUs/tasks: [ 667.062678] (detected by 1, t=6502 jiffies) [ 667.064549] INFO: Stall ended before state dump start [ 722.680332] INFO: task init:1 blocked for more than 120 seconds. [ 722.685077] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 722.686542] init D ffff880035600000 3528 1 0 0x00000000 [ 722.687638] ffff88000d5b3a48 0000000000000002 ffff88000d5b3a18 ffffffff810a2d96 [ 722.688756] ffff88000d5b3fd8 ffff88000d5b3fd8 ffff88000d5b3fd8 ffff88000d5b3fd8 [ 722.690137] ffff880035600000 ffff88000d5b8000 ffff88000d5b3a28 ffff88000d5b3be0 [ 722.691487] Call Trace: [ 722.691926] [<ffffffff810a2d96>] ? kvm_clock_read+0x46/0x80 [ 722.692877] [<ffffffff839eace5>] schedule+0x55/0x60 [ 722.693716] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 722.694702] [<ffffffff8117a1f3>] ? mark_held_locks+0x113/0x130 [ 722.695654] [<ffffffff8117793e>] ? put_lock_stats.isra.16+0xe/0x40 [ 722.696757] [<ffffffff839ec48b>] ? _raw_spin_unlock_irq+0x2b/0x80 [ 722.697796] [<ffffffff839eb458>] wait_for_common+0x138/0x180 [ 722.698778] [<ffffffff8114ca70>] ? try_to_wake_up+0x360/0x360 [ 722.699793] [<ffffffff811c4650>] ? __call_rcu+0x6b0/0x6b0 [ 722.700883] [<ffffffff839eb548>] wait_for_completion+0x18/0x20 [ 722.701832] [<ffffffff81132d4f>] wait_rcu_gp+0x6f/0xa0 [ 722.702675] [<ffffffff811308f0>] ? perf_trace_rcu_utilization+0xe0/0xe0 [ 722.703791] [<ffffffff839eb364>] ? wait_for_common+0x44/0x180 [ 722.704693] [<ffffffff811c9026>] synchronize_rcu+0x86/0x90 [ 722.705623] [<ffffffff811fa3c5>] padata_replace+0x35/0xd0 [ 722.706498] [<ffffffff811fa526>] __padata_remove_cpu+0xc6/0x160 [ 722.707486] [<ffffffff811fa94c>] padata_cpu_callback+0x2bc/0x350 [ 722.708534] [<ffffffff8113de7e>] notifier_call_chain+0xee/0x130 [ 722.709524] [<ffffffff8113e459>] __raw_notifier_call_chain+0x9/0x10 [ 722.710925] [<ffffffff8110a4ab>] __cpu_notify+0x1b/0x40 [ 722.711817] [<ffffffff8383133e>] _cpu_down+0xae/0x350 [ 722.712679] [<ffffffff8398fc88>] ? printk+0x5c/0x5e [ 722.713516] [<ffffffff8110a8e6>] disable_nonboot_cpus+0x86/0x1c0 [ 722.714526] [<ffffffff811240c6>] kernel_restart+0x16/0x60 [ 722.715435] [<ffffffff81124341>] sys_reboot+0x151/0x2a0 [ 722.716316] [<ffffffff811c5d13>] ? rcu_cleanup_after_idle+0x23/0x170 [ 722.717415] [<ffffffff811c6624>] ? rcu_eqs_exit_common+0x64/0x3a0 [ 722.718453] [<ffffffff811c6d15>] ? rcu_user_exit+0xa5/0xd0 [ 722.719372] [<ffffffff8117a44d>] ? trace_hardirqs_on+0xd/0x10 [ 722.720531] [<ffffffff8107c8f0>] ? syscall_trace_enter+0x20/0x2e0 [ 722.721759] [<ffffffff839edea8>] tracesys+0xe1/0xe6 [ 722.722614] 4 locks held by init/1: [ 722.723123] #0: (reboot_mutex){+.+.+.}, at: [<ffffffff811242c6>] sys_reboot+0xd6/0x2a0 [ 722.724537] #1: (cpu_add_remove_lock){+.+.+.}, at: [<ffffffff8110a582>] cpu_maps_update_begin+0x12/0x20 [ 722.726129] #2: (cpu_hotplug.lock){+.+.+.}, at: [<ffffffff8110a53a>] cpu_hotplug_begin+0x2a/0x60 [ 722.727609] #3: (&pinst->lock){+.+.+.}, at: [<ffffffff811fa941>] padata_cpu_callback+0x2b1/0x350 [ 722.729133] INFO: task rcu_preempt:11 blocked for more than 120 seconds. [ 722.730370] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 722.731686] rcu_preempt D ffff88000d620000 5480 11 2 0x00000000 [ 722.732901] ffff88000d5fbc20 0000000000000002 0000000000000006 ffff88000d600000 [ 722.734177] ffff88000d5fbfd8 ffff88000d5fbfd8 ffff88000d5fbfd8 ffff88000d5fbfd8 [ 722.735456] ffff88000d620000 ffff88000d600000 ffffffff839e9575 ffffffff84c50948 [ 722.736707] Call Trace: [ 722.737122] [<ffffffff839e9575>] ? __mutex_lock_common+0x335/0x5a0 [ 722.738165] [<ffffffff839eace5>] schedule+0x55/0x60 [ 722.739001] [<ffffffff839ead03>] schedule_preempt_disabled+0x13/0x20 [ 722.740098] [<ffffffff839e95ad>] __mutex_lock_common+0x36d/0x5a0 [ 722.741410] [<ffffffff8110a5e7>] ? get_online_cpus+0x37/0x50 [ 722.742645] [<ffffffff81150008>] ? sched_clock_cpu+0xf8/0x110 [ 722.743627] [<ffffffff8110a5e7>] ? get_online_cpus+0x37/0x50 [ 722.744599] [<ffffffff839e981f>] mutex_lock_nested+0x3f/0x50 [ 722.745484] [<ffffffff8110a5e7>] get_online_cpus+0x37/0x50 [ 722.746418] [<ffffffff811c718f>] rcu_gp_kthread+0x28f/0xed0 [ 722.747314] [<ffffffff839ec48b>] ? _raw_spin_unlock_irq+0x2b/0x80 [ 722.748350] [<ffffffff81136fe0>] ? abort_exclusive_wait+0xb0/0xb0 [ 722.749303] [<ffffffff811c6f00>] ? rcu_gp_fqs+0x80/0x80 [ 722.750358] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 722.751124] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 722.752048] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 722.753023] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 722.754006] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 722.754905] 1 lock held by rcu_preempt/11: [ 722.755590] #0: (cpu_hotplug.lock){+.+.+.}, at: [<ffffffff8110a5e7>] get_online_cpus+0x37/0x50 [ 722.757584] INFO: task rcu_torture_rea:2728 blocked for more than 120 seconds. [ 722.759393] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 722.761810] rcu_torture_rea D ffff88000d620000 5512 2728 2 0x00000000 [ 722.763586] ffff880034c3bc30 0000000000000002 0000000000000001 0000000010000000 [ 722.765069] ffff880034c3bfd8 ffff880034c3bfd8 ffff880034c3bfd8 ffff880034c3bfd8 [ 722.766211] ffff88000d620000 ffff8800356fb000 0000000000000000 ffffffff845c0398 [ 722.767470] Call Trace: [ 722.767891] [<ffffffff839eace5>] schedule+0x55/0x60 [ 722.768707] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 722.769651] [<ffffffff8398fc88>] ? printk+0x5c/0x5e [ 722.770441] [<ffffffff839e8fd9>] schedule_timeout_uninterruptible+0x19/0x20 [ 722.771624] [<ffffffff811bc49f>] rcutorture_shutdown_absorb+0x2f/0x40 [ 722.772695] [<ffffffff811bc7aa>] rcu_stutter_wait+0x4a/0x70 [ 722.773627] [<ffffffff811bf4de>] rcu_torture_reader+0x34e/0x450 [ 722.774626] [<ffffffff81143fea>] ? finish_task_switch+0x3a/0x110 [ 722.775649] [<ffffffff811bf5e0>] ? rcu_torture_reader+0x450/0x450 [ 722.776463] [<ffffffff811bf190>] ? rcutorture_trace_dump+0x40/0x40 [ 722.776964] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 722.777526] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 722.778543] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 722.779564] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 722.780552] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 722.781403] no locks held by rcu_torture_rea/2728. [ 722.782221] INFO: task rcu_torture_rea:2733 blocked for more than 120 seconds. [ 722.783478] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 722.784770] rcu_torture_rea D ffff88000d618000 5512 2733 2 0x00000000 [ 722.785969] ffff880034d09c30 0000000000000002 ffff880034d09be0 ffffffff819e6eb8 [ 722.787240] ffff880034d09fd8 ffff880034d09fd8 ffff880034d09fd8 ffff880034d09fd8 [ 722.788486] ffff88000d618000 ffff880035600000 0000000000000043 ffffffff845c0398 [ 722.789640] Call Trace: [ 722.790159] [<ffffffff819e6eb8>] ? do_raw_spin_unlock+0xc8/0xe0 [ 722.791127] [<ffffffff839eace5>] schedule+0x55/0x60 [ 722.791979] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 722.792939] [<ffffffff819d3bee>] ? trace_hardirqs_on_thunk+0x3a/0x3f [ 722.794014] [<ffffffff8398fc88>] ? printk+0x5c/0x5e [ 722.794864] [<ffffffff839e8fd9>] schedule_timeout_uninterruptible+0x19/0x20 [ 722.796050] [<ffffffff811bc49f>] rcutorture_shutdown_absorb+0x2f/0x40 [ 722.797145] [<ffffffff811bc7aa>] rcu_stutter_wait+0x4a/0x70 [ 722.798091] [<ffffffff811bf4de>] rcu_torture_reader+0x34e/0x450 [ 722.799021] [<ffffffff81143fea>] ? finish_task_switch+0x3a/0x110 [ 722.799995] [<ffffffff811bf5e0>] ? rcu_torture_reader+0x450/0x450 [ 722.801154] [<ffffffff811bf190>] ? rcutorture_trace_dump+0x40/0x40 [ 722.802186] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 722.803007] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 722.803995] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 722.805015] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 722.806048] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 722.806931] no locks held by rcu_torture_rea/2733. [ 722.807754] INFO: task kworker/u:2:3994 blocked for more than 120 seconds. [ 722.808895] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 722.810090] kworker/u:2 D ffff8800356fb000 3144 3994 2 0x00000000 [ 722.811344] ffff880028de9a50 0000000000000002 0000000000000006 ffff88002973b000 [ 722.812546] ffff880028de9fd8 ffff880028de9fd8 ffff880028de9fd8 ffff880028de9fd8 [ 722.813759] ffff8800356fb000 ffff88002973b000 ffffffff839e9575 ffffffff84c50948 [ 722.814970] Call Trace: [ 722.815363] [<ffffffff839e9575>] ? __mutex_lock_common+0x335/0x5a0 [ 722.816324] [<ffffffff839eace5>] schedule+0x55/0x60 [ 722.817126] [<ffffffff839ead03>] schedule_preempt_disabled+0x13/0x20 [ 722.818198] [<ffffffff839e95ad>] __mutex_lock_common+0x36d/0x5a0 [ 722.819261] [<ffffffff8110a5e7>] ? get_online_cpus+0x37/0x50 [ 722.820356] [<ffffffff8110a5e7>] ? get_online_cpus+0x37/0x50 [ 722.821328] [<ffffffff839e981f>] mutex_lock_nested+0x3f/0x50 [ 722.822292] [<ffffffff8110a5e7>] get_online_cpus+0x37/0x50 [ 722.823227] [<ffffffff811c9053>] synchronize_rcu_expedited+0x23/0x250 [ 722.824323] [<ffffffff833698d5>] synchronize_net+0x25/0x40 [ 722.825258] [<ffffffff83369a05>] rollback_registered_many+0x115/0x240 [ 722.826359] [<ffffffff83369c34>] unregister_netdevice_many+0x14/0x60 [ 722.827583] [<ffffffff8355bdf3>] ip6gre_exit_net+0x273/0x290 [ 722.828937] [<ffffffff8355bb80>] ? ip6gre_tunnel_uninit+0x1b0/0x1b0 [ 722.830323] [<ffffffff8335cce5>] ops_exit_list.isra.0+0x45/0x70 [ 722.831436] [<ffffffff8335d6c0>] cleanup_net+0x130/0x1b0 [ 722.832564] [<ffffffff8112a039>] process_one_work+0x3b9/0x770 [ 722.833577] [<ffffffff81129ee8>] ? process_one_work+0x268/0x770 [ 722.834683] [<ffffffff811778b2>] ? get_lock_stats+0x22/0x70 [ 722.835601] [<ffffffff8335d590>] ? net_drop_ns+0x40/0x40 [ 722.837311] [<ffffffff8112a9ba>] worker_thread+0x2ba/0x3f0 [ 722.838626] [<ffffffff8112a700>] ? rescuer_thread+0x2d0/0x2d0 [ 722.839750] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 722.840709] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 722.841761] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 722.842749] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 722.843734] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 722.844626] 5 locks held by kworker/u:2/3994: [ 722.845352] #0: (netns){.+.+.+}, at: [<ffffffff81129ee8>] process_one_work+0x268/0x770 [ 722.846585] #1: (net_cleanup_work){+.+.+.}, at: [<ffffffff81129ee8>] process_one_work+0x268/0x770 [ 722.848008] #2: (net_mutex){+.+.+.}, at: [<ffffffff8335d610>] cleanup_net+0x80/0x1b0 [ 722.849300] #3: (rtnl_mutex){+.+.+.}, at: [<ffffffff83376fc2>] rtnl_lock+0x12/0x20 [ 722.850678] #4: (cpu_hotplug.lock){+.+.+.}, at: [<ffffffff8110a5e7>] get_online_cpus+0x37/0x50 [ 722.852191] INFO: task trinity-child41:8464 blocked for more than 120 seconds. [ 722.853303] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 722.854599] trinity-child41 D ffff88000d5d0000 4912 8464 1 0x00000006 [ 722.855746] ffff8800306cb9d8 0000000000000002 ffff8800306cb9a8 ffffffff810a2d96 [ 722.857062] ffff8800306cbfd8 ffff8800306cbfd8 ffff8800306cbfd8 ffff8800306cbfd8 [ 722.858324] ffff88000d5d0000 ffff88002e9eb000 ffff8800306cb9b8 ffff8800306cbb70 [ 722.859576] Call Trace: [ 722.860060] [<ffffffff810a2d96>] ? kvm_clock_read+0x46/0x80 [ 722.861428] [<ffffffff839eace5>] schedule+0x55/0x60 [ 722.862256] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 722.863207] [<ffffffff8117a1f3>] ? mark_held_locks+0x113/0x130 [ 722.864197] [<ffffffff8117793e>] ? put_lock_stats.isra.16+0xe/0x40 [ 722.865246] [<ffffffff839ec48b>] ? _raw_spin_unlock_irq+0x2b/0x80 [ 722.866282] [<ffffffff839eb458>] wait_for_common+0x138/0x180 [ 722.867240] [<ffffffff8114ca70>] ? try_to_wake_up+0x360/0x360 [ 722.868213] [<ffffffff811c4650>] ? __call_rcu+0x6b0/0x6b0 [ 722.869165] [<ffffffff839eb548>] wait_for_completion+0x18/0x20 [ 722.870177] [<ffffffff81132d4f>] wait_rcu_gp+0x6f/0xa0 [ 722.871058] [<ffffffff811308f0>] ? perf_trace_rcu_utilization+0xe0/0xe0 [ 722.872176] [<ffffffff839eb364>] ? wait_for_common+0x44/0x180 [ 722.873152] [<ffffffff811c9026>] synchronize_rcu+0x86/0x90 [ 722.874046] [<ffffffff82c135bd>] input_close_device+0x5d/0x80 [ 722.875036] [<ffffffff82c1a9e7>] evdev_release+0x77/0xa0 [ 722.875982] [<ffffffff81271bc2>] __fput+0x122/0x2d0 [ 722.876818] [<ffffffff81271d79>] ____fput+0x9/0x10 [ 722.877748] [<ffffffff8112ebae>] task_work_run+0xbe/0x100 [ 722.878695] [<ffffffff8110da92>] do_exit+0x322/0xa90 [ 722.879556] [<ffffffff811778b2>] ? get_lock_stats+0x22/0x70 [ 722.880554] [<ffffffff8117793e>] ? put_lock_stats.isra.16+0xe/0x40 [ 722.881622] [<ffffffff839ec48b>] ? _raw_spin_unlock_irq+0x2b/0x80 [ 722.882665] [<ffffffff8110e2c4>] do_group_exit+0x84/0xd0 [ 722.883610] [<ffffffff811215a1>] get_signal_to_deliver+0x801/0x920 [ 722.884701] [<ffffffff819e9d2b>] ? debug_object_assert_init+0xbb/0x110 [ 722.885831] [<ffffffff8118445d>] ? do_futex+0xbd/0xa80 [ 722.886736] [<ffffffff8106cc47>] do_signal+0x27/0x100 [ 722.887803] [<ffffffff811c6624>] ? rcu_eqs_exit_common+0x64/0x3a0 [ 722.888867] [<ffffffff811c6d15>] ? rcu_user_exit+0xa5/0xd0 [ 722.889803] [<ffffffff8117a44d>] ? trace_hardirqs_on+0xd/0x10 [ 722.890817] [<ffffffff8106cd8f>] do_notify_resume+0x4f/0xa0 [ 722.891801] [<ffffffff839edfba>] int_signal+0x12/0x17 [ 722.892679] 2 locks held by trinity-child41/8464: [ 722.893494] #0: (&evdev->mutex){+.+...}, at: [<ffffffff82c1a9d0>] evdev_release+0x60/0xa0 [ 722.894954] #1: (&dev->mutex){+.+...}, at: [<ffffffff82c1358d>] input_close_device+0x2d/0x80 [ 842.890317] INFO: task init:1 blocked for more than 120 seconds. [ 842.894043] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 842.895451] init D ffff880035600000 3528 1 0 0x00000000 [ 842.896619] ffff88000d5b3a48 0000000000000002 ffff88000d5b3a18 ffffffff810a2d96 [ 842.897942] ffff88000d5b3fd8 ffff88000d5b3fd8 ffff88000d5b3fd8 ffff88000d5b3fd8 [ 842.899168] ffff880035600000 ffff88000d5b8000 ffff88000d5b3a28 ffff88000d5b3be0 [ 842.900468] Call Trace: [ 842.900911] [<ffffffff810a2d96>] ? kvm_clock_read+0x46/0x80 [ 842.901884] [<ffffffff839eace5>] schedule+0x55/0x60 [ 842.902752] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 842.903751] [<ffffffff8117a1f3>] ? mark_held_locks+0x113/0x130 [ 842.904777] [<ffffffff8117793e>] ? put_lock_stats.isra.16+0xe/0x40 [ 842.905852] [<ffffffff839ec48b>] ? _raw_spin_unlock_irq+0x2b/0x80 [ 842.906923] [<ffffffff839eb458>] wait_for_common+0x138/0x180 [ 842.907930] [<ffffffff8114ca70>] ? try_to_wake_up+0x360/0x360 [ 842.908939] [<ffffffff811c4650>] ? __call_rcu+0x6b0/0x6b0 [ 842.909888] [<ffffffff839eb548>] wait_for_completion+0x18/0x20 [ 842.910849] [<ffffffff81132d4f>] wait_rcu_gp+0x6f/0xa0 [ 842.911764] [<ffffffff811308f0>] ? perf_trace_rcu_utilization+0xe0/0xe0 [ 842.912921] [<ffffffff839eb364>] ? wait_for_common+0x44/0x180 [ 842.913932] [<ffffffff811c9026>] synchronize_rcu+0x86/0x90 [ 842.914899] [<ffffffff811fa3c5>] padata_replace+0x35/0xd0 [ 842.915847] [<ffffffff811fa526>] __padata_remove_cpu+0xc6/0x160 [ 842.916875] [<ffffffff811fa94c>] padata_cpu_callback+0x2bc/0x350 [ 842.917940] [<ffffffff8113de7e>] notifier_call_chain+0xee/0x130 [ 842.918980] [<ffffffff8113e459>] __raw_notifier_call_chain+0x9/0x10 [ 842.920152] [<ffffffff8110a4ab>] __cpu_notify+0x1b/0x40 [ 842.921172] [<ffffffff8383133e>] _cpu_down+0xae/0x350 [ 842.922072] [<ffffffff8398fc88>] ? printk+0x5c/0x5e [ 842.922942] [<ffffffff8110a8e6>] disable_nonboot_cpus+0x86/0x1c0 [ 842.923860] [<ffffffff811240c6>] kernel_restart+0x16/0x60 [ 842.924842] [<ffffffff81124341>] sys_reboot+0x151/0x2a0 [ 842.925759] [<ffffffff811c5d13>] ? rcu_cleanup_after_idle+0x23/0x170 [ 842.926874] [<ffffffff811c6624>] ? rcu_eqs_exit_common+0x64/0x3a0 [ 842.927948] [<ffffffff811c6d15>] ? rcu_user_exit+0xa5/0xd0 [ 842.928919] [<ffffffff8117a44d>] ? trace_hardirqs_on+0xd/0x10 [ 842.929939] [<ffffffff8107c8f0>] ? syscall_trace_enter+0x20/0x2e0 [ 842.930903] [<ffffffff839edea8>] tracesys+0xe1/0xe6 [ 842.931755] 4 locks held by init/1: [ 842.932364] #0: (reboot_mutex){+.+.+.}, at: [<ffffffff811242c6>] sys_reboot+0xd6/0x2a0 [ 842.933713] #1: (cpu_add_remove_lock){+.+.+.}, at: [<ffffffff8110a582>] cpu_maps_update_begin+0x12/0x20 [ 842.935390] #2: (cpu_hotplug.lock){+.+.+.}, at: [<ffffffff8110a53a>] cpu_hotplug_begin+0x2a/0x60 [ 842.936920] #3: (&pinst->lock){+.+.+.}, at: [<ffffffff811fa941>] padata_cpu_callback+0x2b1/0x350 [ 842.938362] INFO: task rcu_preempt:11 blocked for more than 120 seconds. [ 842.939476] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 842.940786] rcu_preempt D ffff88000d620000 5480 11 2 0x00000000 [ 842.941894] ffff88000d5fbc20 0000000000000002 0000000000000006 ffff88000d600000 [ 842.943104] ffff88000d5fbfd8 ffff88000d5fbfd8 ffff88000d5fbfd8 ffff88000d5fbfd8 [ 842.944349] ffff88000d620000 ffff88000d600000 ffffffff839e9575 ffffffff84c50948 [ 842.945571] Call Trace: [ 842.945994] [<ffffffff839e9575>] ? __mutex_lock_common+0x335/0x5a0 [ 842.947042] [<ffffffff839eace5>] schedule+0x55/0x60 [ 842.947815] [<ffffffff839ead03>] schedule_preempt_disabled+0x13/0x20 [ 842.948895] [<ffffffff839e95ad>] __mutex_lock_common+0x36d/0x5a0 [ 842.949917] [<ffffffff8110a5e7>] ? get_online_cpus+0x37/0x50 [ 842.950826] [<ffffffff81150008>] ? sched_clock_cpu+0xf8/0x110 [ 842.951753] [<ffffffff8110a5e7>] ? get_online_cpus+0x37/0x50 [ 842.952688] [<ffffffff839e981f>] mutex_lock_nested+0x3f/0x50 [ 842.953619] [<ffffffff8110a5e7>] get_online_cpus+0x37/0x50 [ 842.954558] [<ffffffff811c718f>] rcu_gp_kthread+0x28f/0xed0 [ 842.955500] [<ffffffff839ec48b>] ? _raw_spin_unlock_irq+0x2b/0x80 [ 842.956532] [<ffffffff81136fe0>] ? abort_exclusive_wait+0xb0/0xb0 [ 842.957563] [<ffffffff811c6f00>] ? rcu_gp_fqs+0x80/0x80 [ 842.958456] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 842.959227] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 842.960247] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 842.961260] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 842.962659] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 842.963949] 1 lock held by rcu_preempt/11: [ 842.964615] #0: (cpu_hotplug.lock){+.+.+.}, at: [<ffffffff8110a5e7>] get_online_cpus+0x37/0x50 [ 842.966102] INFO: task rcu_torture_wri:2723 blocked for more than 120 seconds. [ 842.967302] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 842.968599] rcu_torture_wri D ffff880035543000 5672 2723 2 0x00000000 [ 842.969792] ffff880034d49ce0 0000000000000002 ffff880034d49c90 ffffffff819e6eb8 [ 842.971057] ffff880034d49fd8 ffff880034d49fd8 ffff880034d49fd8 ffff880034d49fd8 [ 842.972245] ffff880035543000 ffff880034d58000 0000000000000043 ffffffff845c032a [ 842.973504] Call Trace: [ 842.973930] [<ffffffff819e6eb8>] ? do_raw_spin_unlock+0xc8/0xe0 [ 842.974924] [<ffffffff839eace5>] schedule+0x55/0x60 [ 842.975759] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 842.976727] [<ffffffff8398fc88>] ? printk+0x5c/0x5e [ 842.977575] [<ffffffff839e8fd9>] schedule_timeout_uninterruptible+0x19/0x20 [ 842.978753] [<ffffffff811bc49f>] rcutorture_shutdown_absorb+0x2f/0x40 [ 842.979850] [<ffffffff811bc7aa>] rcu_stutter_wait+0x4a/0x70 [ 842.980829] [<ffffffff811be20c>] rcu_torture_writer+0x1cc/0x240 [ 842.981841] [<ffffffff811be040>] ? cpumask_next+0x80/0x80 [ 842.982764] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 842.983585] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 842.984592] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 842.985610] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 842.986633] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 842.987511] no locks held by rcu_torture_wri/2723. [ 842.988316] INFO: task rcu_torture_fak:2724 blocked for more than 120 seconds. [ 842.989515] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 842.990934] rcu_torture_fak D ffff88000d620000 5416 2724 2 0x00000000 [ 842.992218] ffff880034d35ce0 0000000000000002 0000000000000001 0000000010000000 [ 842.993508] ffff880034d35fd8 ffff880034d35fd8 ffff880034d35fd8 ffff880034d35fd8 [ 842.994677] ffff88000d620000 ffff880034cf3000 0000000000000000 ffffffff845c023f [ 842.995848] Call Trace: [ 842.996275] [<ffffffff811bd2b0>] ? rcu_torture_barrier_cbs+0x210/0x210 [ 842.997348] [<ffffffff839eace5>] schedule+0x55/0x60 [ 842.998179] [<ffffffff839e8c65>] schedule_timeout+0x45/0x360 [ 842.999143] [<ffffffff811c4650>] ? __call_rcu+0x6b0/0x6b0 [ 843.000091] [<ffffffff811bd2b0>] ? rcu_torture_barrier_cbs+0x210/0x210 [ 843.001201] [<ffffffff8398fc88>] ? printk+0x5c/0x5e [ 843.002031] [<ffffffff811bd2b0>] ? rcu_torture_barrier_cbs+0x210/0x210 [ 843.003131] [<ffffffff839e8fd9>] schedule_timeout_uninterruptible+0x19/0x20 [ 843.004316] [<ffffffff811bc49f>] rcutorture_shutdown_absorb+0x2f/0x40 [ 843.005405] [<ffffffff811bc7aa>] rcu_stutter_wait+0x4a/0x70 [ 843.006325] [<ffffffff811bd39f>] rcu_torture_fakewriter+0xef/0x160 [ 843.007370] [<ffffffff81135c13>] kthread+0xe3/0xf0 [ 843.008188] [<ffffffff839ef044>] kernel_thread_helper+0x4/0x10 [ 843.009138] [<ffffffff839ed3b4>] ? retint_restore_args+0x13/0x13 [ 843.010146] [<ffffffff81135b30>] ? insert_kthread_work+0x90/0x90 [ 843.011159] [<ffffffff839ef040>] ? gs_change+0x13/0x13 [ 843.011999] no locks held by rcu_torture_fak/2724. [ 862.110052] INFO: rcu_preempt detected stalls on CPUs/tasks: [ 862.111263] (detected by 0, t=26007 jiffies) [ 862.112099] INFO: Stall ended before state dump start
| |