Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756779Ab3EJPEF (ORCPT ); Fri, 10 May 2013 11:04:05 -0400 Received: from cantor2.suse.de ([195.135.220.15]:59018 "EHLO mx2.suse.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753951Ab3EJPEA (ORCPT ); Fri, 10 May 2013 11:04:00 -0400 Date: Fri, 10 May 2013 17:03:56 +0200 (CEST) From: Jiri Kosina To: Frederic Weisbecker Cc: Tony Luck , Borislav Petkov , linux-kernel@vger.kernel.org, x86@kernel.org Subject: Re: NOHZ: WARNING: at arch/x86/kernel/smp.c:123 native_smp_send_reschedule In-Reply-To: <20130510002930.GB2394@somewhere> Message-ID: References: <20130510002930.GB2394@somewhere> User-Agent: Alpine 2.00 (LNX 1167 2008-08-23) MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4877 Lines: 103 On Fri, 10 May 2013, Frederic Weisbecker wrote: > Like Borislav said, it's due to the scheduler IPI sent to an offline > target. Here this is because we enqueue a timer and we must ensure the > target handles this timer by rescheduling its tick if necessary. > > But it's weird because the mce timer at this stage should only enqueue > to the current CPU and the tick shouldn't be stopped. So there shouldn't > be an IPI sent. > > Could you please apply this patch and tell me what you can see in the > logs? > > Thanks. > > diff --git a/kernel/sched/core.c b/kernel/sched/core.c > index 58453b8..19e841a 100644 > --- a/kernel/sched/core.c > +++ b/kernel/sched/core.c > @@ -616,8 +616,17 @@ static bool wake_up_full_nohz_cpu(int cpu) > { > if (tick_nohz_full_cpu(cpu)) { > if (cpu != smp_processor_id() || > - tick_nohz_tick_stopped()) > + tick_nohz_tick_stopped()) { > + if (!cpu_online(cpu)) { > + static int printed = 0; > + if (!printed) { > + printk("%d %d\n", cpu, smp_processor_id()); > + dump_stack(); > + printed = 1; > + } > + } > smp_send_reschedule(cpu); > + } > return true; > } Absolutely, here it goes. [ ... snip ... ] Enabling non-boot CPUs ... smpboot: Booting Node 0 Processor 1 APIC 0x1 CPU1 microcode updated early to revision 0x60f, date = 2010-09-29 Disabled fast string operations 1 1 CPU: 1 PID: 0 Comm: swapper/1 Not tainted 3.9.0-12317-gb2031d4 #1 Hardware name: LENOVO 7470BN2/7470BN2, BIOS 6DET38WW (2.02 ) 12/19/2008 ffff88007c28cca0 ffff880079851e08 ffffffff8154837e ffff880079851e28 ffffffff81077514 ffff88007c28cca0 ffff88007c28cca0 ffff880079851e68 ffffffff810529db 0000000179851e78 ffff88007c28cca0 0000000000000001 Call Trace: [] dump_stack+0x19/0x1b [] wake_up_nohz_cpu+0xd4/0xf0 [] add_timer_on+0xdb/0x110 [] mce_start_timer+0x64/0x70 [] __mcheck_cpu_init_timer+0x52/0x60 [] mcheck_cpu_init+0x6f/0x111 [] identify_cpu+0x3cc/0x3f9 [] identify_secondary_cpu+0x12/0x1d [] smp_store_cpu_info+0x3a/0x3c [] smp_callin+0xea/0x1c1 [] start_secondary+0x24/0x97 ------------[ cut here ]------------ WARNING: at arch/x86/kernel/smp.c:123 native_smp_send_reschedule+0x59/0x60() Modules linked in: af_packet tun iptable_mangle xt_DSCP nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables rfcomm bnep btusb bluetooth cpufreq_conservative cpufreq_userspace cpufreq_powersave iTCO_wdt iTCO_vendor_support snd_hda_codec_conexant acpi_cpufreq mperf kvm_intel kvm iwldvm mac80211 thinkpad_acpi snd_hda_intel sg microcode snd_hda_codec snd_seq iwlwifi snd_hwdep cfg80211 snd_seq_device pcspkr i2c_i801 snd_pcm lpc_ich mfd_core rfkill e1000e snd_timer snd_page_alloc ehci_pci ptp mei_me pps_core mei snd wmi soundcore tpm_tis battery tpm ac tpm_bios autofs4 uhci_hcd ehci_hcd i915 drm_kms_helper drm i2c_algo_bit usbcore button video usb_common edd fan processor ata_generic thermal thermal_sys CPU: 1 PID: 0 Comm: swapper/1 Not tainted 3.9.0-12317-gb2031d4 #1 Hardware name: LENOVO 7470BN2/7470BN2, BIOS 6DET38WW (2.02 ) 12/19/2008 000000000000007b ffff880079851da8 ffffffff8154837e ffff880079851de8 ffffffff8104212b ffff88007c28cca0 0000000000000001 ffff88007c28cca0 ffff880079878000 0000000100004525 0000000000000096 ffff880079851df8 Call Trace: [] dump_stack+0x19/0x1b [] warn_slowpath_common+0x6b/0xa0 [] warn_slowpath_null+0x15/0x20 [] native_smp_send_reschedule+0x59/0x60 [] wake_up_nohz_cpu+0x46/0xf0 [] add_timer_on+0xdb/0x110 [] mce_start_timer+0x64/0x70 [] __mcheck_cpu_init_timer+0x52/0x60 [] mcheck_cpu_init+0x6f/0x111 [] identify_cpu+0x3cc/0x3f9 [] identify_secondary_cpu+0x12/0x1d [] smp_store_cpu_info+0x3a/0x3c [] smp_callin+0xea/0x1c1 [] start_secondary+0x24/0x97 ---[ end trace 954b959ede48c006 ]--- microcode: CPU1 sig=0x10676, pf=0x80, revision=0x60f CPU1 is up i915 0000:00:02.0: power state changed by ACPI to D0 [ ... snip ... ] I.e. the "CPU1 is up" happens only after the microcode has been updated, but the attempt to send IPI to it indeed seems to happen earlier. -- Jiri Kosina SUSE Labs -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/