linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Mark Rutland <mark.rutland@arm.com>
To: linux-kernel@vger.kernel.org
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>,
	Ingo Molnar <mingo@redhat.com>,
	Arnaldo Carvalho de Melo <acme@kernel.org>,
	Thomas Gleixner <tglx@linutronix.de>,
	Sebastian Andrzej Siewior <bigeasy@linutronix.de>,
	jeremy.linton@arm.com
Subject: Re: Perf hotplug lockup in v4.9-rc8
Date: Wed, 7 Dec 2016 14:30:59 +0000	[thread overview]
Message-ID: <20161207143058.GC25605@leverpostej> (raw)
In-Reply-To: <20161207135217.GA25605@leverpostej>

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.

  reply	other threads:[~2016-12-07 14:31 UTC|newest]

Thread overview: 17+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2016-12-07 13:53 Perf hotplug lockup in v4.9-rc8 Mark Rutland
2016-12-07 14:30 ` Mark Rutland [this message]
2016-12-07 16:39   ` Mark Rutland
2016-12-07 17:53 ` Mark Rutland
2016-12-07 18:34   ` Peter Zijlstra
2016-12-07 19:56     ` Mark Rutland
2016-12-09 13:59     ` Peter Zijlstra
2016-12-12 11:46       ` Will Deacon
2016-12-12 12:42         ` Peter Zijlstra
2016-12-22  8:45           ` Peter Zijlstra
2016-12-22 14:00             ` Peter Zijlstra
2016-12-22 16:33               ` Paul E. McKenney
2017-01-11 14:59       ` Mark Rutland
2017-01-11 16:03         ` Peter Zijlstra
2017-01-11 16:26           ` Mark Rutland
2017-01-11 19:51           ` Peter Zijlstra
2017-01-14 12:28       ` [tip:perf/urgent] perf/core: Fix sys_perf_event_open() vs. hotplug tip-bot for Peter Zijlstra

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20161207143058.GC25605@leverpostej \
    --to=mark.rutland@arm.com \
    --cc=a.p.zijlstra@chello.nl \
    --cc=acme@kernel.org \
    --cc=bigeasy@linutronix.de \
    --cc=jeremy.linton@arm.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mingo@redhat.com \
    --cc=tglx@linutronix.de \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).