Re: [RESEND PATCH 0/5 V2] x86: mce: Bugfixes, cleanups and a new CMCI poll version

[Chen Gong <gong.chen@linux.intel.com>]

[-- Attachment #1: Type: text/plain, Size: 3809 bytes --]

On Fri, Aug 03, 2012 at 03:29:50PM -0700, Luck, Tony wrote:
> Date: Fri, 03 Aug 2012 15:29:50 -0700
> From: "Luck, Tony" <tony.luck@intel.com>
> To: Chen Gong <gong.chen@linux.intel.com>
> Cc: bp@amd64.org, x86@kernel.org, linux-kernel@vger.kernel.org
> Subject: Re: [RESEND PATCH 0/5 V2] x86: mce: Bugfixes, cleanups and a new
>  CMCI poll version
> 
> I applied this series on top of v3.6-rc1 and took it for
> a test drive with a little storm of 20 corrected interrupts.
> 
> The series worked ... but the console log was entirely unhelpful
> in letting me know what had just happened to my system.  All I saw
> was:
> 
> mce: [Hardware Error]: Machine check events logged
> mce: [Hardware Error]: Machine check events logged
>     ... several seconds pass ...
> CPU 35 MCA banks CMCI:0 CMCI:1 CMCI:3 CMCI:5 CMCI:6 CMCI:7 CMCI:8 CMCI:9 CMCI:10 CMCI:11
> mce_notify_irq: 3 callbacks suppressed
> CPU 1 MCA banks CMCI:0 CMCI:1 CMCI:3
> CPU 39 MCA banks CMCI:0 CMCI:1 CMCI:3
> CPU 38 MCA banks CMCI:0 CMCI:1 CMCI:3
> CPU 32 MCA banks CMCI:0 CMCI:1 CMCI:3
> CPU 37 MCA banks CMCI:0 CMCI:1 CMCI:3
> CPU 36 MCA banks CMCI:0 CMCI:1 CMCI:3
> CPU 34 MCA banks CMCI:0 CMCI:1 CMCI:3
> mce: [Hardware Error]: Machine check events logged
> 
> No mention of the storm, no mention that we switched to polling
> mode (and so missed some of the reports). Just the cryptic output
> as the kernel re-established the CMCI on processors that had been
> affected by the storm.
> 
> I tried the patch below to log the start/end of the storm. But I
> may be doing something wrong with printk_timed_ratelimit() because
> I saw two "storm detected" and two "storm subsided" messages.

You saw two times because the injection speed is not quick enough so that
the poll timer thinks during the expected time it doesn't meet new CMC, and
then double this timer, again, no CMC... until restore for poll timer to
INT mode. Under the real situation, thousands of CMCI come in so this
situation wil not happen. In fact, during the test I met this kind of 
situations many times.

> 
> It would also be nice to avoid all the "CPU 1 MCA banks CMCI:0 CMCI:1 CMCI:3"
> messages.
> 
> -Tony
> 
> diff --git a/arch/x86/kernel/cpu/mcheck/mce_intel.c b/arch/x86/kernel/cpu/mcheck/mce_intel.c
> index 693bc7d..236f60e 100644
> --- a/arch/x86/kernel/cpu/mcheck/mce_intel.c
> +++ b/arch/x86/kernel/cpu/mcheck/mce_intel.c
> @@ -87,6 +87,8 @@ void mce_intel_hcpu_update(unsigned long cpu)
>  
>  unsigned long mce_intel_adjust_timer(unsigned long interval)
>  {
> +	static unsigned long jiffie_state;
> +
>  	if (interval < CMCI_POLL_INTERVAL)
>  		return interval;
>  
> @@ -108,6 +110,8 @@ unsigned long mce_intel_adjust_timer(unsigned long interval)
>  		 */
>  		if (!atomic_read(&cmci_storm_on_cpus)) {
>  			__this_cpu_write(cmci_storm_state, CMCI_STORM_NONE);
> +			if (printk_timed_ratelimit(&jiffie_state, CMCI_STORM_INTERVAL/HZ*1000))
> +				pr_notice("CMCI storm subsided, switching to interrupt mode\n");
>  			cmci_reenable();
>  			cmci_recheck();
>  		}
> @@ -126,6 +130,7 @@ static bool cmci_storm_detect(void)
>  	unsigned int cnt = __this_cpu_read(cmci_storm_cnt);
>  	unsigned long ts = __this_cpu_read(cmci_time_stamp);
>  	unsigned long now = jiffies;
> +	static unsigned long jiffie_state;
>  
>  	if (__this_cpu_read(cmci_storm_state) != CMCI_STORM_NONE)
>  		return true;
> @@ -145,6 +150,9 @@ static bool cmci_storm_detect(void)
>  	__this_cpu_write(cmci_storm_state, CMCI_STORM_ACTIVE);
>  	atomic_inc(&cmci_storm_on_cpus);
>  	mce_timer_kick(CMCI_POLL_INTERVAL);
> +
> +	if (printk_timed_ratelimit(&jiffie_state, CMCI_STORM_INTERVAL/HZ*1000))
> +		pr_notice("CMCI storm detected, switching to poll mode\n");
>  	return true;
>  }
>  

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]