From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752154AbcCARR3 (ORCPT ); Tue, 1 Mar 2016 12:17:29 -0500 Received: from mx1.redhat.com ([209.132.183.28]:41907 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750862AbcCARR2 (ORCPT ); Tue, 1 Mar 2016 12:17:28 -0500 Date: Tue, 1 Mar 2016 18:17:22 +0100 From: Jiri Olsa To: Peter Zijlstra Cc: Andi Kleen , "Liang, Kan" , Arnaldo Carvalho de Melo , Ingo Molnar , Stephane Eranian , Wang Nan , "zheng.z.yan@intel.com" , LKML Subject: Re: [BUG] Core2 cpu triggers hard lockup with perf test Message-ID: <20160301171722.GA2666@krava.redhat.com> References: <20160227123636.GB30858@krava.redhat.com> <37D7C6CF3E00A74B8858931C1DB2F0770589EC94@SHSMSX103.ccr.corp.intel.com> <20160301091703.GN6356@twins.programming.kicks-ass.net> <20160301110651.GA15260@krava.redhat.com> <20160301145105.GQ5083@two.firstfloor.org> <20160301145909.GS6356@twins.programming.kicks-ass.net> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20160301145909.GS6356@twins.programming.kicks-ass.net> User-Agent: Mutt/1.5.24 (2015-08-30) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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] [] dump_stack+0x4d/0x6c^M [ 125.982977] [] watchdog_overflow_callback+0xeb/0x100^M [ 125.982977] [] __perf_event_overflow+0x88/0x1c0^M [ 125.982977] [] perf_event_overflow+0x14/0x20^M [ 125.982977] [] intel_pmu_handle_irq+0x1e6/0x4a0^M [ 125.982977] [] ? native_apic_wait_icr_idle+0x1f/0x30^M [ 125.982977] [] ? arch_irq_work_raise+0x35/0x40^M [ 125.982977] [] ? irq_work_queue+0x6e/0x80^M [ 125.982977] [] perf_event_nmi_handler+0x2d/0x50^M [ 125.982977] [] nmi_handle+0x62/0xf0^M [ 125.982977] [] default_do_nmi+0xe6/0x110^M [ 125.982977] [] do_nmi+0xd7/0x140^M [ 125.982977] [] end_repeat_nmi+0x1a/0x1e^M [ 125.982977] [] ? __intel_pmu_enable_all.isra.11+0x4b/0xd0^M [ 125.982977] [] ? __intel_pmu_enable_all.isra.11+0x4b/0xd0^M [ 125.982977] [] ? __intel_pmu_enable_all.isra.11+0x4b/0xd0^M [ 125.982977] <> [] intel_pmu_enable_all+0x10/0x20^M [ 125.982977] [] x86_pmu_enable+0x263/0x2f0^M [ 125.982977] [] perf_pmu_enable+0x22/0x30^M [ 125.982977] [] ctx_resched+0x51/0x60^M [ 125.982977] [] perf_event_exec+0x109/0x150^M [ 125.982977] [] setup_new_exec+0x6d/0x1a0^M [ 125.982977] [] load_elf_binary+0x37a/0x10e0^M [ 125.982977] [] ? get_user_pages+0x52/0x60^M [ 125.982977] [] search_binary_handler+0x9e/0x1e0^M [ 125.982977] [] do_execveat_common.isra.37+0x54d/0x6e0^M [ 125.982977] [] SyS_execve+0x3a/0x50^M [ 125.982977] [] stub_execve+0x5/0x5^M [ 125.982977] [] ? 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] [] ? perf_event_exec+0x109/0x150^M [ 166.774020] [] ? setup_new_exec+0x6d/0x1a0^M [ 166.774020] [] ? load_elf_binary+0x37a/0x10e0^M [ 166.774020] [] ? get_user_pages+0x52/0x60^M [ 166.774020] [] ? search_binary_handler+0x9e/0x1e0^M [ 166.774020] [] ? do_execveat_common.isra.37+0x54d/0x6e0^M [ 166.774020] [] ? SyS_execve+0x3a/0x50^M [ 166.774020] [] ? stub_execve+0x5/0x5^M [ 166.774020] [] ? 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 ffffffff8100ae4d: 7e ffffffff8100ae4e: e8 6d 49 00 00 callq ffffffff8100f7c0 ffffffff8100ae53: 41 0f b6 fc movzbl %r12b,%edi ffffffff8100ae57: e8 94 58 00 00 callq ffffffff810106f0 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 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);