Re: [BUG] Core2 cpu triggers hard lockup with perf test
From: Jiri Olsa
Date: Tue Mar 01 2016 - 12:17:32 EST
On Tue, Mar 01, 2016 at 03:59:09PM +0100, Peter Zijlstra wrote:
> On Tue, Mar 01, 2016 at 03:51:05PM +0100, Andi Kleen wrote:
> > > im on it.. also the patch that makes this happen just
> > > enlarge the buffer for PEBS:
> > >
> > > 156174999dd1 perf/intel/x86: Enlarge the PEBS buffer
> > >
> > > but I did not find anyaPEBS buffer lenght limitations in SDM
> >
> > May be the easiest would be to just keep the old buffer size
> > on Merom.
>
> I would still like to know why it breaks though. Just changing code
> about because it makes fail go away is never the right answer.
I had to go throught several config switch offs,
however now it's pretty clear where it hangs
I got one (just one occurance):
[ 125.982977] NMI watchdog: Watchdog detected hard LOCKUP on cpu 1^M
[ 125.982977] Modules linked in: rpcrdma ib_isert iscsi_target_mod ib_iser libiscsi scsi_transport_iscsi ib_srpt target_core_mod ib_srp scsi_transport_srp ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_sa ib_mad ocrdma ib_core snd_hda_codec_idt snd_hda_codec_generic ib_addr snd_hda_intel snd_hda_codec snd_hda_core coretemp kvm_intel snd_hwdep snd_seq kvm snd_seq_device snd_pcm snd_timer snd nfsd soundcore shpchp pcspkr auth_rpcgss ppdev nfs_acl sg irqbypass parport_serial parport_pc lockd i2c_i801 parport acpi_cpufreq grace sunrpc ip_tables xfs libcrc32c sr_mod sd_mod cdrom i915 video i2c_algo_bit ahci drm_kms_helper libahci syscopyarea sysfillrect sysimgblt fb_sys_fops e1000e drm ptp pps_core i2c_core lpfc libata scsi_transport_fc be2net vxlan ip6_udp_tunnel udp_tunnel fjes dm_mirror dm_region_hash dm_log dm_mod^M
[ 125.982977] CPU: 1 PID: 5586 Comm: perf Not tainted 4.5.0-rc4fix+ #10^M
[ 125.982977] Hardware name: System Manufacturer To Be Filled By O.E.M. Product Name To Be Filled By O.E.M./BB Name To be filled by O.E.M., BIOS CGELIA55.86^M
[ 125.982977] 0000000000000086 00000000522d7515 ffff88007d885bb0 ffffffff8131dd11^M
[ 125.982977] 0000000000000000 0000000000000000 ffff88007d885bc8 ffffffff811279cb^M
[ 125.982977] ffff88007a548000 ffff88007d885c00 ffffffff81168618 0000000000000002^M
[ 125.982977] Call Trace:^M
[ 125.982977] <NMI> [<ffffffff8131dd11>] dump_stack+0x4d/0x6c^M
[ 125.982977] [<ffffffff811279cb>] watchdog_overflow_callback+0xeb/0x100^M
[ 125.982977] [<ffffffff81168618>] __perf_event_overflow+0x88/0x1c0^M
[ 125.982977] [<ffffffff81169194>] perf_event_overflow+0x14/0x20^M
[ 125.982977] [<ffffffff8100b656>] intel_pmu_handle_irq+0x1e6/0x4a0^M
[ 125.982977] [<ffffffff810413bf>] ? native_apic_wait_icr_idle+0x1f/0x30^M
[ 125.982977] [<ffffffff81021d15>] ? arch_irq_work_raise+0x35/0x40^M
[ 125.982977] [<ffffffff8115c54e>] ? irq_work_queue+0x6e/0x80^M
[ 125.982977] [<ffffffff8100466d>] perf_event_nmi_handler+0x2d/0x50^M
[ 125.982977] [<ffffffff81020382>] nmi_handle+0x62/0xf0^M
[ 125.982977] [<ffffffff810209d6>] default_do_nmi+0xe6/0x110^M
[ 125.982977] [<ffffffff81020ad7>] do_nmi+0xd7/0x140^M
[ 125.982977] [<ffffffff8167af37>] end_repeat_nmi+0x1a/0x1e^M
[ 125.982977] [<ffffffff8100ae7b>] ? __intel_pmu_enable_all.isra.11+0x4b/0xd0^M
[ 125.982977] [<ffffffff8100ae7b>] ? __intel_pmu_enable_all.isra.11+0x4b/0xd0^M
[ 125.982977] [<ffffffff8100ae7b>] ? __intel_pmu_enable_all.isra.11+0x4b/0xd0^M
[ 125.982977] <<EOE>> [<ffffffff8100af10>] intel_pmu_enable_all+0x10/0x20^M
[ 125.982977] [<ffffffff81006283>] x86_pmu_enable+0x263/0x2f0^M
[ 125.982977] [<ffffffff811632d2>] perf_pmu_enable+0x22/0x30^M
[ 125.982977] [<ffffffff81163f51>] ctx_resched+0x51/0x60^M
[ 125.982977] [<ffffffff81164b09>] perf_event_exec+0x109/0x150^M
[ 125.982977] [<ffffffff811fff7d>] setup_new_exec+0x6d/0x1a0^M
[ 125.982977] [<ffffffff8125104a>] load_elf_binary+0x37a/0x10e0^M
[ 125.982977] [<ffffffff811a06c2>] ? get_user_pages+0x52/0x60^M
[ 125.982977] [<ffffffff811fe32e>] search_binary_handler+0x9e/0x1e0^M
[ 125.982977] [<ffffffff811ffccd>] do_execveat_common.isra.37+0x54d/0x6e0^M
[ 125.982977] [<ffffffff812000ea>] SyS_execve+0x3a/0x50^M
[ 125.982977] [<ffffffff81679065>] stub_execve+0x5/0x5^M
[ 125.982977] [<ffffffff81678dd7>] ? entry_SYSCALL_64_fastpath+0x12/0x6a^M
and several rcu stalls.. I guess that's because above path did rcu_read_lock:
[ 166.667008] INFO: rcu_sched detected stalls on CPUs/tasks:^M
[ 166.668003] 1-...: (16 GPs behind) idle=b13/140000000000000/0 softirq=6921/6923 fqs=19790 ^M
[ 166.774020] (detected by 2, t=60168 jiffies, g=6522, c=6521, q=0)^M
[ 166.774020] Task dump for CPU 1:^M
[ 166.774020] perf R running task 0 5586 5585 0x00000088^M
[ 166.774020] 0000000000000001 ffff88007144fd70 ffffffff81164b09 ffff88007d899808^M
[ 166.774020] 0000000000000286 ffff88007d899808 ffff880076f8e7c0 ffff880079734200^M
[ 166.774020] ffff880071450000 0000000000000000 ffff880078dfc500 ffff88007144fd90^M
[ 166.774020] Call Trace:^M
[ 166.774020] [<ffffffff81164b09>] ? perf_event_exec+0x109/0x150^M
[ 166.774020] [<ffffffff811fff7d>] ? setup_new_exec+0x6d/0x1a0^M
[ 166.774020] [<ffffffff8125104a>] ? load_elf_binary+0x37a/0x10e0^M
[ 166.774020] [<ffffffff811a06c2>] ? get_user_pages+0x52/0x60^M
[ 166.774020] [<ffffffff811fe32e>] ? search_binary_handler+0x9e/0x1e0^M
[ 166.774020] [<ffffffff811ffccd>] ? do_execveat_common.isra.37+0x54d/0x6e0^M
[ 166.774020] [<ffffffff812000ea>] ? SyS_execve+0x3a/0x50^M
[ 166.774020] [<ffffffff81679065>] ? stub_execve+0x5/0x5^M
[ 166.774020] [<ffffffff81678dd7>] ? entry_SYSCALL_64_fastpath+0x12/0x6a^M
[ 346.672008] INFO: rcu_sched detected stalls on CPUs/tasks:^M
the exception addr is on wrmsr:
ffffffff8100ae30 <__intel_pmu_enable_all.isra.11>:
ffffffff8100ae30: e8 bb 02 67 00 callq ffffffff8167b0f0 <__fentry__>
ffffffff8100ae35: 55 push %rbp
ffffffff8100ae36: 48 89 e5 mov %rsp,%rbp
ffffffff8100ae39: 41 54 push %r12
ffffffff8100ae3b: 41 89 fc mov %edi,%r12d
ffffffff8100ae3e: 53 push %rbx
ffffffff8100ae3f: 48 c7 c3 80 a3 00 00 mov $0xa380,%rbx
ffffffff8100ae46: 65 48 03 1d d2 f2 ff add %gs:0x7efff2d2(%rip),%rbx # a120 <this_cpu_off>
ffffffff8100ae4d: 7e
ffffffff8100ae4e: e8 6d 49 00 00 callq ffffffff8100f7c0 <intel_pmu_pebs_enable_all>
ffffffff8100ae53: 41 0f b6 fc movzbl %r12b,%edi
ffffffff8100ae57: e8 94 58 00 00 callq ffffffff810106f0 <intel_pmu_lbr_enable_all>
ffffffff8100ae5c: 48 8b 83 68 0c 00 00 mov 0xc68(%rbx),%rax
ffffffff8100ae63: b9 8f 03 00 00 mov $0x38f,%ecx
ffffffff8100ae68: 48 f7 d0 not %rax
ffffffff8100ae6b: 48 23 05 26 80 ad 00 and 0xad8026(%rip),%rax # ffffffff81ae2e98 <x86_pmu+0x138>
ffffffff8100ae72: 48 89 c2 mov %rax,%rdx
ffffffff8100ae75: 48 c1 ea 20 shr $0x20,%rdx
ffffffff8100ae79: 0f 30 wrmsr
I tried what Andy suggested below (not sure what he meant by Merom,
I took PEBS format0 instead), works for me
jirka
---
diff --git a/arch/x86/events/intel/ds.c b/arch/x86/events/intel/ds.c
index c8a243d6fc82..c4a1a769bae7 100644
--- a/arch/x86/events/intel/ds.c
+++ b/arch/x86/events/intel/ds.c
@@ -269,7 +269,7 @@ static int alloc_pebs_buffer(int cpu)
if (!x86_pmu.pebs)
return 0;
- buffer = kzalloc_node(PEBS_BUFFER_SIZE, GFP_KERNEL, node);
+ buffer = kzalloc_node(x86_pmu.pebs_buffer_size, GFP_KERNEL, node);
if (unlikely(!buffer))
return -ENOMEM;
@@ -286,7 +286,7 @@ static int alloc_pebs_buffer(int cpu)
per_cpu(insn_buffer, cpu) = ibuffer;
}
- max = PEBS_BUFFER_SIZE / x86_pmu.pebs_record_size;
+ max = x86_pmu.pebs_buffer_size / x86_pmu.pebs_record_size;
ds->pebs_buffer_base = (u64)(unsigned long)buffer;
ds->pebs_index = ds->pebs_buffer_base;
@@ -1319,6 +1319,7 @@ void __init intel_ds_init(void)
x86_pmu.bts = boot_cpu_has(X86_FEATURE_BTS);
x86_pmu.pebs = boot_cpu_has(X86_FEATURE_PEBS);
+ x86_pmu.pebs_buffer_size = PEBS_BUFFER_SIZE;
if (x86_pmu.pebs) {
char pebs_type = x86_pmu.intel_cap.pebs_trap ? '+' : '-';
int format = x86_pmu.intel_cap.pebs_format;
@@ -1327,6 +1328,7 @@ void __init intel_ds_init(void)
case 0:
pr_cont("PEBS fmt0%c, ", pebs_type);
x86_pmu.pebs_record_size = sizeof(struct pebs_record_core);
+ x86_pmu.pebs_buffer_size = PAGE_SIZE;
x86_pmu.drain_pebs = intel_pmu_drain_pebs_core;
break;
diff --git a/arch/x86/events/perf_event.h b/arch/x86/events/perf_event.h
index 7bb61e32fb29..1ab6279fed1d 100644
--- a/arch/x86/events/perf_event.h
+++ b/arch/x86/events/perf_event.h
@@ -586,6 +586,7 @@ struct x86_pmu {
pebs_broken :1,
pebs_prec_dist :1;
int pebs_record_size;
+ int pebs_buffer_size;
void (*drain_pebs)(struct pt_regs *regs);
struct event_constraint *pebs_constraints;
void (*pebs_aliases)(struct perf_event *event);