Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1537765 > unrolled thread

Perf hotplug lockup in v4.9-rc8

Back to article view | Back to linux.kernel

Contents

  Perf hotplug lockup in v4.9-rc8 Mark Rutland <mark.rutland@arm.com> - 2016-12-07 15:00 +0100
    Re: Perf hotplug lockup in v4.9-rc8 Mark Rutland <mark.rutland@arm.com> - 2016-12-07 15:40 +0100
      Re: Perf hotplug lockup in v4.9-rc8 Mark Rutland <mark.rutland@arm.com> - 2016-12-07 17:50 +0100
    Re: Perf hotplug lockup in v4.9-rc8 Mark Rutland <mark.rutland@arm.com> - 2016-12-07 19:10 +0100
      Re: Perf hotplug lockup in v4.9-rc8 Peter Zijlstra <peterz@infradead.org> - 2016-12-07 19:40 +0100
        Re: Perf hotplug lockup in v4.9-rc8 Mark Rutland <mark.rutland@arm.com> - 2016-12-07 21:00 +0100
        Re: Perf hotplug lockup in v4.9-rc8 Peter Zijlstra <peterz@infradead.org> - 2016-12-09 15:00 +0100

#1537765 — Perf hotplug lockup in v4.9-rc8

Hi all

Jeremy noticed a kernel lockup on arm64 when the perf tool was used in
parallel with hotplug, which I've reproduced on arm64 and x86(-64) with
v4.9-rc8. In both cases I'm using defconfig; I've tried enabling lockdep
but it was silent for arm64 and x86.

I haven't yet tested earlier kernels and I'm not sure how long this has
been around for; I'm currently building a v4.8 defconfig to compare
with. In the meantime, info dump below.

I'm running:

$ while true; do ./perf stat -e cycles true; done

In parallel with the following script:

---
#!/bin/bash

CPUS=3;

ONLINEFMT="/sys/devices/system/cpu/cpu%s/online";

while true; do
	# Don't bother trying CPU0
        CPU=$((($RANDOM % $CPUS) + 1))
	        ONLINEFILE=$(printf $ONLINEFMT $CPU);
		        echo $(( $RANDOM  % 2 )) > $ONLINEFILE;
			done
----

After a few successful runs, the perf tool locks up, as does my process
monitor. On arm64 I'm abel to kill the perf tool and make forward
progress, but on x86 my SSH session is dead at this point.

A short while later, I get an RCU stall warning:

[ 4134.743008] INFO: rcu_sched self-detected stall on CPU[ 4134.744023] INFO: rcu_sched detected stalls on CPUs/tasks:
[ 4134.744028]  0-...: (26000 ticks this GP) idle=699/140000000000001/0 softirq=84552/84553 fqs=6491
[ 4134.744029]
[ 4134.744030] (detected by 1, t=26002 jiffies, g=42991, c=42990, q=437)
[ 4134.744032] Task dump for CPU 0:
[ 4134.744033] perf            R
[ 4134.744034]   running task    13936  5195   3415 0x00000008
 ffffc90005ed7d30
[ 4134.744042]  ffffffff81095268 ffff8801b73d9040 00000000001d9040 ffff8801a830ead0
[ 4134.744044]  0000000000000139 ffffffff8114454f ffff8801a830ead0 ffff8801b2918400
[ 4134.744047]  ffff8801b2918400 ffff8801afa2e000 ffff8801b2918408Call Trace:
[ 4134.744055]  [<ffffffff81095268>] ? sched_clock_local+0x18/0x80
[ 4134.744058]  [<ffffffff8114454f>] ? perf_install_in_context+0x7f/0x160
[ 4134.744062]  [<ffffffff81a8fb29>] ? _raw_spin_unlock_irq+0x29/0x40
[ 4134.744064]  [<ffffffff8114454f>] ? perf_install_in_context+0x7f/0x160
[ 4134.744066]  [<ffffffff8114b790>] ? __perf_event_enable+0x140/0x140
[ 4134.744068]  [<ffffffff8114e8b2>] ? SYSC_perf_event_open+0x512/0xf20
[ 4134.744070]  [<ffffffff81151df9>] ? SyS_perf_event_open+0x9/0x10
[ 4134.744072]  [<ffffffff81a9026a>] ? entry_SYSCALL_64_fastpath+0x18/0xad
[ 4134.743008]  0-...: (26000 ticks this GP) idle=699/140000000000001/0 softirq=84552/84553 fqs=6519
[ 4134.743008]   (t=26123 jiffies g=42991 c=42990 q=437)
[ 4134.743008] Task dump for CPU 0:
[ 4134.743008] perf            R  running task    13936  5195   3415 0x00000008
[ 4134.743008]  ffff8801b7203cf8 ffffffff81091cc7 0000000000000000 0000000000000000
[ 4134.743008]  0000000000000086 ffff8801b7203d10 ffffffff81094db4 ffffffff82062180
[ 4134.743008]  ffff8801b7203d40 ffffffff81156f72 ffff8801b73d92c0 ffffffff82062180
[ 4134.743008] Call Trace:
[ 4134.743008]  <IRQ> [ 4134.743008]  [<ffffffff81091cc7>] sched_show_task+0x117/0x1c0
[ 4134.743008]  [<ffffffff81094db4>] dump_cpu_task+0x34/0x40
[ 4134.743008]  [<ffffffff81156f72>] rcu_dump_cpu_stacks+0x88/0xc4
[ 4134.743008]  [<ffffffff810d25c7>] rcu_check_callbacks+0x8a7/0xa00
[ 4134.743008]  [<ffffffff810aae4d>] ? trace_hardirqs_off+0xd/0x10
[ 4134.743008]  [<ffffffff81066860>] ? raise_softirq+0x110/0x180
[ 4134.743008]  [<ffffffff810e8dc0>] ? tick_sched_do_timer+0x30/0x30
[ 4134.743008]  [<ffffffff810d7eca>] update_process_times+0x2a/0x50
[ 4134.743008]  [<ffffffff810e8651>] tick_sched_handle.isra.15+0x31/0x40
[ 4134.743008]  [<ffffffff810e8df8>] tick_sched_timer+0x38/0x70
[ 4134.743008]  [<ffffffff810d8f0f>] __hrtimer_run_queues+0xef/0x510
[ 4134.743008]  [<ffffffff810d96f2>] hrtimer_interrupt+0xb2/0x1d0
[ 4134.743008]  [<ffffffff8104b171>] hpet_interrupt_handler+0x11/0x30
[ 4134.743008]  [<ffffffff810c4c77>] __handle_irq_event_percpu+0x37/0x330
[ 4134.743008]  [<ffffffff810c4f8e>] handle_irq_event_percpu+0x1e/0x50
[ 4134.743008]  [<ffffffff810c4ff4>] handle_irq_event+0x34/0x60
[ 4134.743008]  [<ffffffff810c8217>] handle_edge_irq+0x87/0x140
[ 4134.743008]  [<ffffffff8101e486>] handle_irq+0xa6/0x130
[ 4134.743008]  [<ffffffff8101dafe>] do_IRQ+0x5e/0x120
[ 4134.743008]  [<ffffffff81a90c09>] common_interrupt+0x89/0x89
[ 4134.743008]  <EOI> [ 4134.743008]  [<ffffffff81a8fb29>] ? _raw_spin_unlock_irq+0x29/0x40
[ 4134.743008]  [<ffffffff8114454f>] perf_install_in_context+0x7f/0x160
[ 4134.743008]  [<ffffffff8114b790>] ? __perf_event_enable+0x140/0x140
[ 4134.743008]  [<ffffffff8114e8b2>] SYSC_perf_event_open+0x512/0xf20
[ 4134.743008]  [<ffffffff81151df9>] SyS_perf_event_open+0x9/0x10
[ 4134.743008]  [<ffffffff81a9026a>] entry_SYSCALL_64_fastpath+0x18/0xad
[ 4212.748006] INFO: rcu_sched self-detected stall on CPU[ 4212.749020] INFO: rcu_sched detected stalls on CPUs/tasks:
[ 4212.749023]  0-...: (103687 ticks this GP) idle=699/140000000000001/0 softirq=84552/84553 fqs=25939
[ 4212.749024]
[ 4212.749026] (detected by 1, t=104007 jiffies, g=42991, c=42990, q=2440)
[ 4212.749027] Task dump for CPU 0:
[ 4212.749028] perf            R
[ 4212.749028]   running task    13936  5195   3415 0x00000008
 ffffc90005ed7d30
[ 4212.749034]  ffffffff81095268 ffff8801b73d9040 00000000001d9040 ffff8801a830ead0
[ 4212.749037]  00000000000000eb ffffffff8114454f ffff8801a830ead0 ffff8801b2918400
[ 4212.749039]  ffff8801b2918400 ffff8801afa2e000 ffff8801b2918408Call Trace:
[ 4212.749046]  [<ffffffff81095268>] ? sched_clock_local+0x18/0x80
[ 4212.749049]  [<ffffffff8114454f>] ? perf_install_in_context+0x7f/0x160
[ 4212.749052]  [<ffffffff81a8fb29>] ? _raw_spin_unlock_irq+0x29/0x40
[ 4212.749053]  [<ffffffff8114454f>] ? perf_install_in_context+0x7f/0x160
[ 4212.749055]  [<ffffffff8114b790>] ? __perf_event_enable+0x140/0x140
[ 4212.749056]  [<ffffffff8114e8b2>] ? SYSC_perf_event_open+0x512/0xf20
[ 4212.749058]  [<ffffffff81151df9>] ? SyS_perf_event_open+0x9/0x10
[ 4212.749059]  [<ffffffff81a9026a>] ? entry_SYSCALL_64_fastpath+0x18/0xad
[ 4212.748007]  0-...: (103687 ticks this GP) idle=699/140000000000001/0 softirq=84552/84553 fqs=25967
[ 4212.748007]   (t=104129 jiffies g=42991 c=42990 q=2440)
[ 4212.748007] Task dump for CPU 0:
[ 4212.748007] perf            R  running task    13936  5195   3415 0x00000008
[ 4212.748007]  ffff8801b7203cf8 ffffffff81091cc7 0000000000000000 0000000000000000
[ 4212.748007]  0000000000000086 ffff8801b7203d10 ffffffff81094db4 ffffffff82062180
[ 4212.748007]  ffff8801b7203d40 ffffffff81156f72 ffff8801b73d92c0 ffffffff82062180
[ 4212.748007] Call Trace:
[ 4212.748007]  <IRQ> [ 4212.748007]  [<ffffffff81091cc7>] sched_show_task+0x117/0x1c0
[ 4212.748007]  [<ffffffff81094db4>] dump_cpu_task+0x34/0x40
[ 4212.748007]  [<ffffffff81156f72>] rcu_dump_cpu_stacks+0x88/0xc4
[ 4212.748007]  [<ffffffff810d25c7>] rcu_check_callbacks+0x8a7/0xa00
[ 4212.748007]  [<ffffffff810aae4d>] ? trace_hardirqs_off+0xd/0x10
[ 4212.748007]  [<ffffffff81066860>] ? raise_softirq+0x110/0x180
[ 4212.748007]  [<ffffffff810e8dc0>] ? tick_sched_do_timer+0x30/0x30
[ 4212.748007]  [<ffffffff810d7eca>] update_process_times+0x2a/0x50
[ 4212.748007]  [<ffffffff810e8651>] tick_sched_handle.isra.15+0x31/0x40
[ 4212.748007]  [<ffffffff810e8df8>] tick_sched_timer+0x38/0x70
[ 4212.748007]  [<ffffffff810d8f0f>] __hrtimer_run_queues+0xef/0x510
[ 4212.748007]  [<ffffffff810d96f2>] hrtimer_interrupt+0xb2/0x1d0
[ 4212.748007]  [<ffffffff8104b171>] hpet_interrupt_handler+0x11/0x30
[ 4212.748007]  [<ffffffff810c4c77>] __handle_irq_event_percpu+0x37/0x330
[ 4212.748007]  [<ffffffff810c4f8e>] handle_irq_event_percpu+0x1e/0x50
[ 4212.748007]  [<ffffffff810c4ff4>] handle_irq_event+0x34/0x60
[ 4212.748007]  [<ffffffff810c8217>] handle_edge_irq+0x87/0x140
[ 4212.748007]  [<ffffffff8101e486>] handle_irq+0xa6/0x130
[ 4212.748007]  [<ffffffff8101dafe>] do_IRQ+0x5e/0x120
[ 4212.748007]  [<ffffffff81a90c09>] common_interrupt+0x89/0x89
[ 4212.748007]  <EOI> [ 4212.748007]  [<ffffffff81a8fb29>] ? _raw_spin_unlock_irq+0x29/0x40
[ 4212.748007]  [<ffffffff8114454f>] perf_install_in_context+0x7f/0x160
[ 4212.748007]  [<ffffffff8114b790>] ? __perf_event_enable+0x140/0x140
[ 4212.748007]  [<ffffffff8114e8b2>] SYSC_perf_event_open+0x512/0xf20
[ 4212.748007]  [<ffffffff81151df9>] SyS_perf_event_open+0x9/0x10
[ 4212.748007]  [<ffffffff81a9026a>] entry_SYSCALL_64_fastpath+0x18/0xad

Dumping the blocked task state:

[ 4314.359550] sysrq: SysRq : Show Blocked State
[ 4314.360006]   task                        PC stack   pid father
[ 4314.360006] jbd2/sda1-8     D13728  1370      2 0x00000000
[ 4314.360006]  ffff8801b75d8518 ffff8801b5da8000 ffff8801b75d8500 ffff8801b3e3e7c0
[ 4314.360006]  ffff8801b3e3e200 ffffc9000108fa40 ffffffff81a8922c ffff8801b3e3e200
[ 4314.360006]  ffff8801b3e3e200 ffff8801b75d8518 0000b43c001d9040 ffff8801b3e3e200
[ 4314.360006] Call Trace:
[ 4314.360006]  [<ffffffff81a8922c>] ? __schedule+0x2cc/0xa90
[ 4314.360006]  [<ffffffff81a8a1b0>] ? bit_wait+0x50/0x50
[ 4314.360006]  [<ffffffff81a89a28>] schedule+0x38/0x90
[ 4314.360006]  [<ffffffff81a8e687>] schedule_timeout+0x2f7/0x600
[ 4314.360006]  [<ffffffff8104b27a>] ? read_hpet+0xea/0x100
[ 4314.360006]  [<ffffffff810adbfd>] ? trace_hardirqs_on+0xd/0x10
[ 4314.360006]  [<ffffffff810df841>] ? ktime_get+0x91/0x110
[ 4314.360006]  [<ffffffff8111f06a>] ? __delayacct_blkio_start+0x1a/0x30
[ 4314.360006]  [<ffffffff81a8a1b0>] ? bit_wait+0x50/0x50
[ 4314.360006]  [<ffffffff81a88ef1>] io_schedule_timeout+0xa1/0x110
[ 4314.360006]  [<ffffffff81a8a1c6>] bit_wait_io+0x16/0x50
[ 4314.360006]  [<ffffffff81a89e0f>] __wait_on_bit+0x5f/0x90
[ 4314.360006]  [<ffffffff81a8a1b0>] ? bit_wait+0x50/0x50
[ 4314.360006]  [<ffffffff81a89f6d>] out_of_line_wait_on_bit+0x6d/0x80
[ 4314.360006]  [<ffffffff810a7780>] ? autoremove_wake_function+0x30/0x30
[ 4314.360006]  [<ffffffff811f6330>] __wait_on_buffer+0x40/0x50
[ 4314.360006]  [<ffffffff812a0f6c>] jbd2_journal_commit_transaction+0x193c/0x2180
[ 4314.360006]  [<ffffffff81095268>] ? sched_clock_local+0x18/0x80
[ 4314.360006]  [<ffffffff81a8fae1>] ? _raw_spin_unlock_irqrestore+0x31/0x50
[ 4314.360006]  [<ffffffff810adbfd>] ? trace_hardirqs_on+0xd/0x10
[ 4314.360006]  [<ffffffff812a5cb0>] kjournald2+0xc0/0x270
[ 4314.360006]  [<ffffffff810a7750>] ? prepare_to_wait_event+0x110/0x110
[ 4314.360006]  [<ffffffff812a5bf0>] ? commit_timeout+0x10/0x10
[ 4314.360006]  [<ffffffff8108306e>] kthread+0xee/0x110
[ 4314.360006]  [<ffffffff81082f80>] ? kthread_park+0x60/0x60
[ 4314.360006]  [<ffffffff81a904c7>] ret_from_fork+0x27/0x40
[ 4314.360006] irqbalance      D13560  2290      1 0x00000000
[ 4314.360006]  ffff8801b75d8518 ffff8801b5d81880 ffff8801b75d8500 ffff8801af849e40
[ 4314.360006]  ffff8801af849880 ffffc90003667c88 ffffffff81a8922c 0000000000000006
[ 4314.360006]  00000000ffffffff ffff8801b75d8518 0000d33e810ad9d1 ffff8801af849880
[ 4314.360006] Call Trace:
[ 4314.360006]  [<ffffffff81a8922c>] ? __schedule+0x2cc/0xa90
[ 4314.360006]  [<ffffffff81a89a28>] schedule+0x38/0x90
[ 4314.360006]  [<ffffffff81a89d00>] schedule_preempt_disabled+0x10/0x20
[ 4314.360006]  [<ffffffff81a8b3d3>] mutex_lock_nested+0x173/0x3a0
[ 4314.360006]  [<ffffffff815830ad>] ? online_show+0x1d/0x60
[ 4314.360006]  [<ffffffff815830ad>] ? online_show+0x1d/0x60
[ 4314.360006]  [<ffffffff815830ad>] online_show+0x1d/0x60
[ 4314.360006]  [<ffffffff815834cb>] dev_attr_show+0x1b/0x50
[ 4314.360006]  [<ffffffff8124220c>] ? sysfs_file_ops+0x3c/0x60
[ 4314.360006]  [<ffffffff81242533>] sysfs_kf_seq_show+0xc3/0x1a0
[ 4314.360006]  [<ffffffff81240b81>] kernfs_seq_show+0x21/0x30
[ 4314.360006]  [<ffffffff811e590f>] seq_read+0xff/0x3b0
[ 4314.360006]  [<ffffffff81241566>] kernfs_fop_read+0x126/0x1a0
[ 4314.360006]  [<ffffffff811bc343>] __vfs_read+0x23/0x110
[ 4314.360006]  [<ffffffff8132df6b>] ? security_file_permission+0x9b/0xc0
[ 4314.360006]  [<ffffffff811bc9f4>] ? rw_verify_area+0x44/0xb0
[ 4314.360006]  [<ffffffff811bcaea>] vfs_read+0x8a/0x140
[ 4314.360006]  [<ffffffff811bdf04>] SyS_read+0x44/0xa0
[ 4314.360006]  [<ffffffff81a9026a>] entry_SYSCALL_64_fastpath+0x18/0xad
[ 4314.360006] randomhotplug.s D13376  3371   3370 0x00000000
[ 4314.360006]  ffff8801b75d8518 ffff8801b3e16200 ffff8801b75d8500 ffff8801b29d4f40
[ 4314.360006]  ffff8801b29d4980 ffffc90004ee7c80 ffffffff81a8922c ffffc90004ee7c58
[ 4314.360006]  0000000000000246 ffff8801b75d8518 0000248281a8be7e ffff8801b29d4980
[ 4314.360006] Call Trace:
[ 4314.360006]  [<ffffffff81a8922c>] ? __schedule+0x2cc/0xa90
[ 4314.360006]  [<ffffffff81a89a28>] schedule+0x38/0x90
[ 4314.360006]  [<ffffffff81060eef>] cpu_hotplug_begin+0xaf/0xc0
[ 4314.360006]  [<ffffffff81060e40>] ? __cpuhp_remove_state+0x130/0x130
[ 4314.360006]  [<ffffffff810a7750>] ? prepare_to_wait_event+0x110/0x110
[ 4314.360006]  [<ffffffff81060fcd>] _cpu_up+0x2d/0xc0
[ 4314.360006]  [<ffffffff810610bf>] do_cpu_up+0x5f/0x80
[ 4314.360006]  [<ffffffff810610ee>] cpu_up+0xe/0x10
[ 4314.360006]  [<ffffffff8158a177>] cpu_subsys_online+0x37/0x80
[ 4314.360006]  [<ffffffff815852cc>] device_online+0x5c/0x80
[ 4314.360006]  [<ffffffff8158535a>] online_store+0x6a/0x70
[ 4314.360006]  [<ffffffff81582aa3>] dev_attr_store+0x13/0x20
[ 4314.360006]  [<ffffffff8124226f>] sysfs_kf_write+0x3f/0x50
[ 4314.360006]  [<ffffffff81241bbf>] kernfs_fop_write+0x13f/0x1d0
[ 4314.360006]  [<ffffffff811bbde3>] __vfs_write+0x23/0x120
[ 4314.360006]  [<ffffffff810ccda7>] ? rcu_read_lock_sched_held+0x87/0x90
[ 4314.360006]  [<ffffffff810cd07a>] ? rcu_sync_lockdep_assert+0x2a/0x50
[ 4314.360006]  [<ffffffff811bfe38>] ? __sb_start_write+0x148/0x1f0
[ 4314.360006]  [<ffffffff811bcd1f>] ? vfs_write+0x17f/0x1b0
[ 4314.360006]  [<ffffffff811bcc50>] vfs_write+0xb0/0x1b0
[ 4314.360006]  [<ffffffff811bdfa4>] SyS_write+0x44/0xa0
[ 4314.360006]  [<ffffffff81a9026a>] entry_SYSCALL_64_fastpath+0x18/0xad

... and on arm64:

[  435.030575]   task                        PC stack   pid father
[  435.036581] randomhotplug.s D    0  2264   2263 0x00000000
[  435.042060] Call trace:
[  435.044507] [<ffff200008088fe4>] __switch_to+0x15c/0x220
[  435.049817] [<ffff2000096d0910>] __schedule+0x480/0x10f8
[  435.055118] [<ffff2000096d165c>] schedule+0xd4/0x260
[  435.060078] [<ffff20000810f5ec>] cpu_hotplug_begin+0x134/0x148
[  435.065900] [<ffff2000096cdaa8>] _cpu_down+0xb0/0x358
[  435.070941] [<ffff20000810f644>] do_cpu_down+0x44/0x70
[  435.076068] [<ffff20000810f680>] cpu_down+0x10/0x18
[  435.080942] [<ffff200008c92438>] cpu_subsys_offline+0x40/0x58
[  435.086677] [<ffff200008c86b60>] device_offline+0x140/0x1c8
[  435.092237] [<ffff200008c86dec>] online_store+0x8c/0xe8
[  435.097458] [<ffff200008c80a48>] dev_attr_store+0x38/0x70
[  435.102850] [<ffff20000850d248>] sysfs_kf_write+0x108/0x190
[  435.108411] [<ffff20000850b348>] kernfs_fop_write+0x1c8/0x3c8
[  435.114147] [<ffff2000083dce10>] __vfs_write+0xc8/0x3c8
[  435.119360] [<ffff2000083df224>] vfs_write+0x11c/0x428
[  435.124487] [<ffff2000083e28ac>] SyS_write+0xdc/0x1a8
[  435.129528] [<ffff200008083ef0>] el0_svc_naked+0x24/0x28

... and again on arm64:

[  898.370984] htop            D    0 16851  15240 0x00000000
[  898.376459] Call trace:
[  898.378895] [<ffff200008088fe4>] __switch_to+0x15c/0x220
[  898.384195] [<ffff2000096d0910>] __schedule+0x480/0x10f8
[  898.389496] [<ffff2000096d165c>] schedule+0xd4/0x260
[  898.394450] [<ffff2000096d227c>] schedule_preempt_disabled+0x74/0x110
[  898.400879] [<ffff2000096d4390>] __mutex_lock_killable_slowpath+0x270/0x670
[  898.407828] [<ffff2000096d480c>] mutex_lock_killable+0x7c/0x98
[  898.413649] [<ffff2000084e7b14>] do_io_accounting+0x164/0x660
[  898.419383] [<ffff2000084e8028>] proc_tgid_io_accounting+0x18/0x20
[  898.425551] [<ffff2000084e64b4>] proc_single_show+0xcc/0x148
[  898.431199] [<ffff20000843f3dc>] seq_read+0x26c/0xdb0
[  898.436238] [<ffff2000083dca58>] __vfs_read+0xc8/0x3b8
[  898.441364] [<ffff2000083def00>] vfs_read+0xc8/0x2d0
[  898.446317] [<ffff2000083e2704>] SyS_read+0xdc/0x1a8
[  898.451269] [<ffff200008083ef0>] el0_svc_naked+0x24/0x28
[  898.456568] perf            R  running task        0 17019  10076 0x0000000a
[  898.463609] Call trace:
[  898.466046] [<ffff2000080902b8>] dump_backtrace+0x0/0x3d0
[  898.471433] [<ffff20000809069c>] show_stack+0x14/0x20
[  898.476476] [<ffff200008173550>] sched_show_task+0x188/0x248
[  898.482123] [<ffff200008173704>] show_state_filter+0xf4/0x168
[  898.487858] [<ffff200008bc8418>] sysrq_handle_showstate+0x10/0x20
[  898.493940] [<ffff200008bc9760>] __handle_sysrq+0x218/0x318
[  898.499500] [<ffff200008bc9888>] handle_sysrq+0x28/0x30
[  898.504718] [<ffff200008c1fb78>] pl011_fifo_to_tty+0x110/0x498
[  898.510539] [<ffff200008c21fb0>] pl011_int+0x740/0xbe8
[  898.515666] [<ffff2000081c9004>] __handle_irq_event_percpu+0x154/0x260
[  898.522182] [<ffff2000081c917c>] handle_irq_event_percpu+0x6c/0x110
[  898.528436] [<ffff2000081c92cc>] handle_irq_event+0xac/0x148
[  898.534086] [<ffff2000081d2780>] handle_fasteoi_irq+0x218/0x5e8
[  898.539994] [<ffff2000081c6fa8>] generic_handle_irq+0x48/0x68
[  898.545728] [<ffff2000081c7ca4>] __handle_domain_irq+0x9c/0x158
[  898.551636] [<ffff200008081b20>] gic_handle_irq+0x58/0xb0
[  898.557023] Exception stack(0xffff80034e8c3a90 to 0xffff80034e8c3bc0)
[  898.563452] 3a80:                                   ffff80034e8c001c ffff2000082a66c0
[  898.571270] 3aa0: ffff80034e8c3d10 0000000000000001 0000000000000007 0000000000000000
[  898.579088] 3ac0: 1ffff00069d18003 ffff100069d18784 0000000041b58ab3 ffff80034e8c0000
[  898.586905] 3ae0: 0000000000000880 0000000000000000 ffff8003fff788cc ffff80035476a780
[  898.594723] 3b00: 0000000002da8fa8 0000000000000000 0000000000000000 0000000000000000
[  898.602541] 3b20: 0000000000000000 1ffff00069d18784 ffff80034e8c0000 ffff80034e8c0000
[  898.610359] 3b40: 0000000000000001 0000000000000006 ffff80034a27c000 00000000fffffffa
[  898.618176] 3b60: ffff2000082a6000 ffff10006a0021c3 ffff80034e8c3d10 ffff80034e8c3bc0
[  898.625994] 3b80: ffff2000082a07cc ffff80034e8c3bc0 ffff20000822586c 0000000020000145
[  898.633811] 3ba0: 0000000000000000 0000000000000000 0001000000000000 ffff800350010d88
[  898.641628] [<ffff2000080837b0>] el1_irq+0xb0/0x124
[  898.646496] [<ffff20000822586c>] smp_call_function_single+0xe4/0x3b8
[  898.652839] [<ffff2000082a07cc>] perf_install_in_context+0x15c/0x268
[  898.659187] [<ffff2000082c1558>] SyS_perf_event_open+0x1138/0x1908
[  898.665357] [<ffff200008083ef0>] el0_svc_naked+0x24/0x28
[  898.670657] perf            S    0 17020  17019 0x00000000
[  898.676133] Call trace:
[  898.678569] [<ffff200008088fe4>] __switch_to+0x15c/0x220
[  898.683870] [<ffff2000096d0910>] __schedule+0x480/0x10f8
[  898.689170] [<ffff2000096d165c>] schedule+0xd4/0x260
[  898.694123] [<ffff2000083f4a14>] pipe_wait+0xec/0x180
[  898.699163] [<ffff2000083f5d94>] pipe_read+0x404/0x750
[  898.704289] [<ffff2000083dcb9c>] __vfs_read+0x20c/0x3b8
[  898.709501] [<ffff2000083def00>] vfs_read+0xc8/0x2d0
[  898.714454] [<ffff2000083e2704>] SyS_read+0xdc/0x1a8
[  898.719407] [<ffff200008083ef0>] el0_svc_naked+0x24/0x28

Thanks,
Mark.

[toc] | [next] | [standalone]

#1537785

On Wed, Dec 07, 2016 at 01:52:17PM +0000, Mark Rutland wrote:
> Hi all
> 
> Jeremy noticed a kernel lockup on arm64 when the perf tool was used in
> parallel with hotplug, which I've reproduced on arm64 and x86(-64) with
> v4.9-rc8. In both cases I'm using defconfig; I've tried enabling lockdep
> but it was silent for arm64 and x86.
> 
> I haven't yet tested earlier kernels and I'm not sure how long this has
> been around for; I'm currently building a v4.8 defconfig to compare
> with. In the meantime, info dump below.

On v4.8 it hangs on x86, but my SSH session survived. Log below; I'll
give v4.7 a go...

[  111.155981] sysrq: SysRq : Show Blocked State
[  111.156971]   task                        PC stack   pid father
[  111.156971] randomhotplug.s D ffff8801b4bafc80 13296  3597   3596 0x00000000
[  111.156971]  ffff8801b4bafc80 ffff8801b4bafc58 0000000000000246 ffffffff8201d540
[  111.156971]  ffff8801a7881880 ffff8801b4bb0000 0000000000000079 0000000000000002
[  111.156971]  0000000000000002 0000000000000000 ffff8801b4bafc98 ffffffff81a752d7
[  111.156971] Call Trace:
[  111.156971]  [<ffffffff81a752d7>] schedule+0x37/0x90
[  111.156971]  [<ffffffff8105fcaf>] cpu_hotplug_begin+0xaf/0xc0
[  111.156971]  [<ffffffff8105fc00>] ? __cpuhp_setup_state+0x210/0x210
[  111.156971]  [<ffffffff810a5440>] ? prepare_to_wait_event+0x100/0x100
[  111.156971]  [<ffffffff8105fd8d>] _cpu_up+0x2d/0xc0
[  111.156971]  [<ffffffff8105fe7f>] do_cpu_up+0x5f/0x80
[  111.156971]  [<ffffffff8105feae>] cpu_up+0xe/0x10
[  111.156971]  [<ffffffff81583357>] cpu_subsys_online+0x37/0x80
[  111.156971]  [<ffffffff8157e43c>] device_online+0x5c/0x80
[  111.156971]  [<ffffffff8157e4ca>] online_store+0x6a/0x70
[  111.156971]  [<ffffffff8157bc33>] dev_attr_store+0x13/0x20
[  111.156971]  [<ffffffff8123f0ff>] sysfs_kf_write+0x3f/0x50
[  111.156971]  [<ffffffff8123ea4f>] kernfs_fop_write+0x13f/0x1d0
[  111.156971]  [<ffffffff811ba0b3>] __vfs_write+0x23/0x120
[  111.156971]  [<ffffffff810a7be7>] ? percpu_down_read+0x57/0x90
[  111.156971]  [<ffffffff811bd875>] ? __sb_start_write+0xc5/0xe0
[  111.156971]  [<ffffffff811bd875>] ? __sb_start_write+0xc5/0xe0
[  111.156971]  [<ffffffff811ba790>] vfs_write+0xb0/0x1b0
[  111.156971]  [<ffffffff811bbae4>] SyS_write+0x44/0xa0
[  111.156971]  [<ffffffff81a7b565>] entry_SYSCALL_64_fastpath+0x18/0xa8

[  134.865008] INFO: rcu_sched self-detected stall on CPU[  134.866024] INFO: rcu_sched detected stalls on CPUs/tasks:
[  134.866028]  1-...: (26000 ticks this GP) idle=163/140000000000001/0 softirq=13624/13624 fqs=6461
[  134.866028]  (detected by 0, t=26002 jiffies, g=13692, c=13691, q=422)
[  134.866031] Task dump for CPU 1:
[  134.866032] perf            R  running task    14392  6398   3677 0x00000008
[  134.866038]  ffff8801a7807c00 ffff8801a7807c00 ffff8801af66e800 ffff8801a7807c08
[  134.866040]  ffff8801a4553df0 ffff8801b4059880 0000000000000001 0000000000000001
[  134.866042]  0000000000000000 0000000000000000 ffff8801b2cac980 0000000000000006
[  134.866045] Call Trace:
[  134.866050]  [<ffffffff81a7ae19>] ? _raw_spin_unlock_irq+0x29/0x40
[  134.866053]  [<ffffffff81141c1f>] ? perf_install_in_context+0x7f/0x160
[  134.866055]  [<ffffffff81148ed0>] ? __perf_event_enable+0x140/0x140
[  134.866056]  [<ffffffff8114bf40>] ? SYSC_perf_event_open+0x510/0xf10
[  134.866058]  [<ffffffff8114f479>] ? SyS_perf_event_open+0x9/0x10
[  134.866059]  [<ffffffff81a7b565>] ? entry_SYSCALL_64_fastpath+0x18/0xa8

[  134.865009]
[  134.865009]  1-...: (26000 ticks this GP) idle=163/140000000000001/0 softirq=13624/13624 fqs=6486
[  134.865009]   (t=26111 jiffies g=13692 c=13691 q=422)
[  134.865009] Task dump for CPU 1:
[  134.865009] perf            R  running task    14392  6398   3677 0x00000008
[  134.865009]  0000000000000e5d ffff8801b7403ca8 ffffffff810900d6 ffffffff8108fff7
[  134.865009]  0000000000000001 0000000000000001 0000000000000086 ffff8801b7403cc0
[  134.865009]  ffffffff81093134 ffffffff82059a80 ffff8801b7403cf0 ffffffff811545aa
[  134.865009] Call Trace:
[  134.865009]  <IRQ>  [<ffffffff810900d6>] sched_show_task+0x156/0x260
[  134.865009]  [<ffffffff8108fff7>] ? sched_show_task+0x77/0x260
[  134.865009]  [<ffffffff81093134>] dump_cpu_task+0x34/0x40
[  134.865009]  [<ffffffff811545aa>] rcu_dump_cpu_stacks+0x88/0xc4
[  134.865009]  [<ffffffff810d02d7>] rcu_check_callbacks+0x8a7/0xa00
[  134.865009]  [<ffffffff8111dd6b>] ? __acct_update_integrals+0x2b/0xb0
[  134.865009]  [<ffffffff810e6b40>] ? tick_sched_do_timer+0x30/0x30
[  134.865009]  [<ffffffff810d5c8a>] update_process_times+0x2a/0x50
[  134.865009]  [<ffffffff810e6390>] tick_sched_handle.isra.15+0x20/0x60
[  134.865009]  [<ffffffff810e6b78>] tick_sched_timer+0x38/0x70
[  134.865009]  [<ffffffff810d6c9f>] __hrtimer_run_queues+0xef/0x510
[  134.865009]  [<ffffffff810d7482>] hrtimer_interrupt+0xb2/0x1d0
[  134.865009]  [<ffffffff8104b161>] hpet_interrupt_handler+0x11/0x30
[  134.865009]  [<ffffffff810c2d37>] __handle_irq_event_percpu+0x37/0x330
[  134.865009]  [<ffffffff810c304e>] handle_irq_event_percpu+0x1e/0x50
[  134.865009]  [<ffffffff810c30b4>] handle_irq_event+0x34/0x60
[  134.865009]  [<ffffffff810c62b7>] handle_edge_irq+0x87/0x140
[  134.865009]  [<ffffffff8101e4b6>] handle_irq+0xa6/0x130
[  134.865009]  [<ffffffff8101db2e>] do_IRQ+0x5e/0x120
[  134.865009]  [<ffffffff81a7bec9>] common_interrupt+0x89/0x89
[  134.865009]  <EOI>  [<ffffffff81a7ae19>] ? _raw_spin_unlock_irq+0x29/0x40
[  134.865009]  [<ffffffff81141c1f>] perf_install_in_context+0x7f/0x160
[  134.865009]  [<ffffffff81148ed0>] ? __perf_event_enable+0x140/0x140
[  134.865009]  [<ffffffff8114bf40>] SYSC_perf_event_open+0x510/0xf10
[  134.865009]  [<ffffffff8114f479>] SyS_perf_event_open+0x9/0x10
[  134.865009]  [<ffffffff81a7b565>] entry_SYSCALL_64_fastpath+0x18/0xa8
[  160.688129] NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [perf:6398]
[  160.689009] Modules linked in:
[  160.689009] irq event stamp: 196860054
[  160.689009] hardirqs last  enabled at (196860053): [<ffffffff81a7ae17>] _raw_spin_unlock_irq+0x27/0x40
[  160.689009] hardirqs last disabled at (196860054): [<ffffffff81a7bec4>] common_interrupt+0x84/0x89
[  160.689009] softirqs last  enabled at (196859662): [<ffffffff8106502d>] __do_softirq+0x30d/0x470
[  160.689009] softirqs last disabled at (196859655): [<ffffffff81065407>] irq_exit+0x97/0xa0
[  160.689009] CPU: 1 PID: 6398 Comm: perf Not tainted 4.8.0 #3
[  160.689009] Hardware name: LENOVO 7484A3G/LENOVO, BIOS 5CKT54AUS 09/07/2009
[  160.689009] task: ffff8801b2cac980 task.stack: ffff8801a4550000
[  160.689009] RIP: 0010:[<ffffffff81a7ae19>]  [<ffffffff81a7ae19>] _raw_spin_unlock_irq+0x29/0x40
[  160.689009] RSP: 0018:ffff8801a4553df0  EFLAGS: 00000206
[  160.689009] RAX: ffff8801b2cac980 RBX: ffff8801b4059880 RCX: 0000000000000006
[  160.689009] RDX: 0000000000004d60 RSI: ffff8801b2cad220 RDI: ffff8801b2cac980
[  160.689009] RBP: ffff8801a4553df0 R08: 0000000000000000 R09: 0000000000000000
[  160.689009] R10: 0000000000000001 R11: 0000000000000001 R12: ffff8801a7807c08
[  160.689009] R13: ffff8801af66e800 R14: ffff8801a7807c00 R15: ffff8801a7807c00
[  160.689009] FS:  00007f5cb7301740(0000) GS:ffff8801b7400000(0000) knlGS:0000000000000000
[  160.689009] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  160.689009] CR2: 00007f95f49e8000 CR3: 00000001a7b9a000 CR4: 00000000000406e0
[  160.689009] Stack:
[  160.689009]  ffff8801a4553e40 ffffffff81141c1f 0000000000000000 ffffffff81148ed0
[  160.689009]  ffff8801af66e800 ffff8801fffffffa ffff8801b4059880 ffff8801af66e93c
[  160.689009]  ffff8801a7807c50 0000000000000003 ffff8801a4553f38 ffffffff8114bf40
[  160.689009] Call Trace:
[  160.689009]  [<ffffffff81141c1f>] perf_install_in_context+0x7f/0x160
[  160.689009]  [<ffffffff81148ed0>] ? __perf_event_enable+0x140/0x140
[  160.689009]  [<ffffffff8114bf40>] SYSC_perf_event_open+0x510/0xf10
[  160.689009]  [<ffffffff8114f479>] SyS_perf_event_open+0x9/0x10
[  160.689009]  [<ffffffff81a7b565>] entry_SYSCALL_64_fastpath+0x18/0xa8
[  160.689009] Code: 00 00 55 be 01 00 00 00 48 89 e5 53 48 89 fb 48 8b 55 08 48 8d 7f 18 e8 e6 31 63 ff 48 89 df e8 2e 85 63 ff e8 e9 0d 63 ff fb 5b <65> ff 0d 78 17 59 7e 5d c3 66 66 66 66 66 2e 0f 1f 84 00 00 00

Thanks,
Mark.

[toc] | [prev] | [next] | [standalone]

#1537898

On Wed, Dec 07, 2016 at 02:30:58PM +0000, Mark Rutland wrote:
> On Wed, Dec 07, 2016 at 01:52:17PM +0000, Mark Rutland wrote:
> > Hi all
> > 
> > Jeremy noticed a kernel lockup on arm64 when the perf tool was used in
> > parallel with hotplug, which I've reproduced on arm64 and x86(-64) with
> > v4.9-rc8. In both cases I'm using defconfig; I've tried enabling lockdep
> > but it was silent for arm64 and x86.
> > 
> > I haven't yet tested earlier kernels and I'm not sure how long this has
> > been around for; I'm currently building a v4.8 defconfig to compare
> > with. In the meantime, info dump below.
> 
> On v4.8 it hangs on x86, but my SSH session survived. Log below; I'll
> give v4.7 a go...

It seems the lockup has been around at least since v4.6, so I'll give up
trying to find a point when it didn't exist.

Peter had some ideas over IRC, so I'll give those a go atop of v4.9-rc8.

Thanks,
Mark.

[toc] | [prev] | [next] | [standalone]

#1537966

On Wed, Dec 07, 2016 at 01:52:17PM +0000, Mark Rutland wrote:
> Hi all
> 
> Jeremy noticed a kernel lockup on arm64 when the perf tool was used in
> parallel with hotplug, which I've reproduced on arm64 and x86(-64) with
> v4.9-rc8. In both cases I'm using defconfig; I've tried enabling lockdep
> but it was silent for arm64 and x86.

It looks like we're trying to install a task-bound event into a context
where task_cpu(ctx->task) is dead, and thus the cpu_function_call() in
perf_install_in_context() fails. We retry repeatedly.

On !PREEMPT (as with x86 defconfig), we manage to prevent the hotplug
machinery from making progress, and this turns into a livelock.

On PREEMPT (as with arm64 defconfig), I'm somewhat lost.

Thanks,
Mark.

[toc] | [prev] | [next] | [standalone]

#1537991

On Wed, Dec 07, 2016 at 05:53:47PM +0000, Mark Rutland wrote:
> On Wed, Dec 07, 2016 at 01:52:17PM +0000, Mark Rutland wrote:
> > Hi all
> > 
> > Jeremy noticed a kernel lockup on arm64 when the perf tool was used in
> > parallel with hotplug, which I've reproduced on arm64 and x86(-64) with
> > v4.9-rc8. In both cases I'm using defconfig; I've tried enabling lockdep
> > but it was silent for arm64 and x86.
> 
> It looks like we're trying to install a task-bound event into a context
> where task_cpu(ctx->task) is dead, and thus the cpu_function_call() in
> perf_install_in_context() fails. We retry repeatedly.
> 
> On !PREEMPT (as with x86 defconfig), we manage to prevent the hotplug
> machinery from making progress, and this turns into a livelock.
> 
> On PREEMPT (as with arm64 defconfig), I'm somewhat lost.

So the problem is that even with PREEMPT we can hit a blocked task
that has a 'dead' cpu.

We'll spin until either the task wakes up or the CPU does, either can
take a very long time.

How exactly your test-case triggers this, all it executes is 'true' and
that really shouldn't block much, is a mystery still.

In any case, the below cures things, but it is, as the comment says,
horrific.

I'm yet to come up with a better patch that doesn't violate scheduler
internals.

---
 kernel/events/core.c | 27 +++++++++++++++++++++++++++
 1 file changed, 27 insertions(+)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index 6ee1febdf6ff..6faf4b03396e 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -1203,6 +1203,11 @@ static void put_ctx(struct perf_event_context *ctx)
  *	      perf_event_context::lock
  *	    perf_event::mmap_mutex
  *	    mmap_sem
+ *
+ *    task_struct::pi_lock
+ *      rq::lock
+ *        perf_event_context::lock
+ *
  */
 static struct perf_event_context *
 perf_event_ctx_lock_nested(struct perf_event *event, int nesting)
@@ -2352,6 +2357,28 @@ perf_install_in_context(struct perf_event_context *ctx,
 		return;
 	}
 	raw_spin_unlock_irq(&ctx->lock);
+
+	raw_spin_lock_irq(&task->pi_lock);
+	if (!(task->state == TASK_RUNNING || task->state == TASK_WAKING)) {
+		/*
+		 * XXX horrific hack...
+		 */
+		raw_spin_lock(&ctx->lock);
+		if (task != ctx->task) {
+			raw_spin_unlock(&ctx->lock);
+			raw_spin_unlock_irq(&task->pi_lock);
+			goto again;
+		}
+
+		add_event_to_ctx(event, ctx);
+		raw_spin_unlock(&ctx->lock);
+		raw_spin_unlock_irq(&task->pi_lock);
+		return;
+	}
+	raw_spin_unlock_irq(&task->pi_lock);
+
+	cond_resched();
+
 	/*
 	 * Since !ctx->is_active doesn't mean anything, we must IPI
 	 * unconditionally.

[toc] | [prev] | [next] | [standalone]

#1538044

On Wed, Dec 07, 2016 at 07:34:55PM +0100, Peter Zijlstra wrote:
> On Wed, Dec 07, 2016 at 05:53:47PM +0000, Mark Rutland wrote:
> > On Wed, Dec 07, 2016 at 01:52:17PM +0000, Mark Rutland wrote:
> > > Hi all
> > > 
> > > Jeremy noticed a kernel lockup on arm64 when the perf tool was used in
> > > parallel with hotplug, which I've reproduced on arm64 and x86(-64) with
> > > v4.9-rc8. In both cases I'm using defconfig; I've tried enabling lockdep
> > > but it was silent for arm64 and x86.
> > 
> > It looks like we're trying to install a task-bound event into a context
> > where task_cpu(ctx->task) is dead, and thus the cpu_function_call() in
> > perf_install_in_context() fails. We retry repeatedly.
> > 
> > On !PREEMPT (as with x86 defconfig), we manage to prevent the hotplug
> > machinery from making progress, and this turns into a livelock.
> > 
> > On PREEMPT (as with arm64 defconfig), I'm somewhat lost.
> 
> So the problem is that even with PREEMPT we can hit a blocked task
> that has a 'dead' cpu.
> 
> We'll spin until either the task wakes up or the CPU does, either can
> take a very long time.
> 
> How exactly your test-case triggers this, all it executes is 'true' and
> that really shouldn't block much, is a mystery still.

The perf tool forks a helper process, which blocks on a pipe, and once
signalled, execs the target (i.e. true). The main perf process opens
(enable-on-exec) events on that, then writes to the pipe to wake up the
helper.

... so now I see why that makes us see a dead task_cpu(); thanks for the
explanation above!

[...]

> @@ -2352,6 +2357,28 @@ perf_install_in_context(struct perf_event_context *ctx,
>  		return;
>  	}
>  	raw_spin_unlock_irq(&ctx->lock);
> +
> +	raw_spin_lock_irq(&task->pi_lock);
> +	if (!(task->state == TASK_RUNNING || task->state == TASK_WAKING)) {

For a moment I thought there was a remaining race here with the lazy
ctx-switch if the new task was RUNNING on an online CPU, but I guess
we'll retry the cpu_function_call() in that case.

I'll attack this tomorrow when I can think again...

Thanks,
Mark.

[toc] | [prev] | [next] | [standalone]

#1539364

On Wed, Dec 07, 2016 at 07:34:55PM +0100, Peter Zijlstra wrote:

> @@ -2352,6 +2357,28 @@ perf_install_in_context(struct perf_event_context *ctx,
>  		return;
>  	}
>  	raw_spin_unlock_irq(&ctx->lock);
> +
> +	raw_spin_lock_irq(&task->pi_lock);
> +	if (!(task->state == TASK_RUNNING || task->state == TASK_WAKING)) {
> +		/*
> +		 * XXX horrific hack...
> +		 */
> +		raw_spin_lock(&ctx->lock);
> +		if (task != ctx->task) {
> +			raw_spin_unlock(&ctx->lock);
> +			raw_spin_unlock_irq(&task->pi_lock);
> +			goto again;
> +		}
> +
> +		add_event_to_ctx(event, ctx);
> +		raw_spin_unlock(&ctx->lock);
> +		raw_spin_unlock_irq(&task->pi_lock);
> +		return;
> +	}
> +	raw_spin_unlock_irq(&task->pi_lock);
> +
> +	cond_resched();
> +
>  	/*
>  	 * Since !ctx->is_active doesn't mean anything, we must IPI
>  	 * unconditionally.

So while I went back and forth trying to make that less ugly, I figured
there was another problem.

Imagine the cpu_function_call() hitting the 'right' cpu, but not finding
the task current. It will then continue to install the event in the
context. However, that doesn't stop another CPU from pulling the task in
question from our rq and scheduling it elsewhere.

This all lead me to the below patch.. Now it has a rather large comment,
and while it represents my current thinking on the matter, I'm not at
all sure its entirely correct. I got my brain in a fair twist while
writing it.

Please as to carefully think about it.

---
 kernel/events/core.c | 70 +++++++++++++++++++++++++++++++++++-----------------
 1 file changed, 48 insertions(+), 22 deletions(-)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index 6ee1febdf6ff..7d9ae461c535 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -2252,7 +2252,7 @@ static int  __perf_install_in_context(void *info)
 	struct perf_event_context *ctx = event->ctx;
 	struct perf_cpu_context *cpuctx = __get_cpu_context(ctx);
 	struct perf_event_context *task_ctx = cpuctx->task_ctx;
-	bool activate = true;
+	bool reprogram = true;
 	int ret = 0;
 
 	raw_spin_lock(&cpuctx->ctx.lock);
@@ -2260,27 +2260,26 @@ static int  __perf_install_in_context(void *info)
 		raw_spin_lock(&ctx->lock);
 		task_ctx = ctx;
 
-		/* If we're on the wrong CPU, try again */
-		if (task_cpu(ctx->task) != smp_processor_id()) {
-			ret = -ESRCH;
-			goto unlock;
-		}
+		reprogram = (ctx->task == current);
 
 		/*
-		 * If we're on the right CPU, see if the task we target is
-		 * current, if not we don't have to activate the ctx, a future
-		 * context switch will do that for us.
+		 * If the task is running, it must be running on this CPU,
+		 * otherwise we cannot reprogram things.
+		 *
+		 * If its not running, we don't care, ctx->lock will
+		 * serialize against it becoming runnable.
 		 */
-		if (ctx->task != current)
-			activate = false;
-		else
-			WARN_ON_ONCE(cpuctx->task_ctx && cpuctx->task_ctx != ctx);
+		if (task_curr(ctx->task) && !reprogram) {
+			ret = -ESRCH;
+			goto unlock;
+		}
 
+		WARN_ON_ONCE(reprogram && cpuctx->task_ctx && cpuctx->task_ctx != ctx);
 	} else if (task_ctx) {
 		raw_spin_lock(&task_ctx->lock);
 	}
 
-	if (activate) {
+	if (reprogram) {
 		ctx_sched_out(ctx, cpuctx, EVENT_TIME);
 		add_event_to_ctx(event, ctx);
 		ctx_resched(cpuctx, task_ctx);
@@ -2331,13 +2330,36 @@ perf_install_in_context(struct perf_event_context *ctx,
 	/*
 	 * Installing events is tricky because we cannot rely on ctx->is_active
 	 * to be set in case this is the nr_events 0 -> 1 transition.
+	 *
+	 * Instead we use task_curr(), which tells us if the task is running.
+	 * However, since we use task_curr() outside of rq::lock, we can race
+	 * against the actual state. This means the result can be wrong.
+	 *
+	 * If we get a false positive, we retry, this is harmless.
+	 *
+	 * If we get a false negative, things are complicated. If we are after
+	 * perf_event_context_sched_in() ctx::lock will serialize us, and the
+	 * value must be correct. If we're before, it doesn't matter since
+	 * perf_event_context_sched_in() will program the counter.
+	 *
+	 * However, this hinges on the remote context switch having observed
+	 * our task->perf_event_ctxp[] store, such that it will in fact take
+	 * ctx::lock in perf_event_context_sched_in().
+	 *
+	 * We do this by task_function_call(), if the IPI fails to hit the task
+	 * we know any future context switch of task must see the
+	 * perf_event_ctpx[] store.
 	 */
-again:
+
 	/*
-	 * Cannot use task_function_call() because we need to run on the task's
-	 * CPU regardless of whether its current or not.
+	 * This smp_mb() orders the task->perf_event_ctxp[] store with the
+	 * task_cpu() load, such that if the IPI then does not find the task
+	 * running, a future context switch of that task must observe the
+	 * store.
 	 */
-	if (!cpu_function_call(task_cpu(task), __perf_install_in_context, event))
+	smp_mb();
+again:
+	if (!task_function_call(task, __perf_install_in_context, event))
 		return;
 
 	raw_spin_lock_irq(&ctx->lock);
@@ -2351,12 +2373,16 @@ perf_install_in_context(struct perf_event_context *ctx,
 		raw_spin_unlock_irq(&ctx->lock);
 		return;
 	}
-	raw_spin_unlock_irq(&ctx->lock);
 	/*
-	 * Since !ctx->is_active doesn't mean anything, we must IPI
-	 * unconditionally.
+	 * If the task is not running, ctx->lock will avoid it becoming so,
+	 * thus we can safely install the event.
 	 */
-	goto again;
+	if (task_curr(task)) {
+		raw_spin_unlock_irq(&ctx->lock);
+		goto again;
+	}
+	add_event_to_ctx(event, ctx);
+	raw_spin_unlock_irq(&ctx->lock);
 }
 
 /*

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web