Re: RCU CPU stall console spews leads to soft lockup disabled is reasonable ?

[Don Zickus <dzickus@redhat.com>]

On Mon, Jan 19, 2015 at 05:04:29PM +0800, Zhang Zhen wrote:
> > 
> > Did you really intend to acquire the same spinlock twice in a row,
> > forcing a self-deadlock?  If not, I of course suggest changing the second
> > "spin_lock()" to "spin_unlock()".
> > 
> 
> Yes, i acquire the same spinlock twice in order to reproduce the problem.
> 
> > If your .config has CONFIG_TREE_RCU=y, the above is quite likely to
> > give you an RCU CPU stall warning.
> > 
> 
> In my .config CONFIG_TREE_RCU=y.
> 
> If softlockup_thresh < rcu_cpu_stall_timeout, it will give soft lockup warning.
> If softlockup_thresh > rcu_cpu_stall_timeout, it will likely to give RCU CPU stall warning
> just like above and no give soft lockup warning.
> 
> It means that RCU CPU stall console spews leads to soft lockup disabled.
> Is this reasonable ?

I believe so.  In kernel v3.10.., all activity to the console executed
touch_nmi_watchdog() which calls touch_softlockup_watchdog, which delayed
the softlockup for another round of 'softlockup_thresh'.

Of course back then, touch_nmi_watchdog touched all cpus.  So a problem
like this was masked.  I believe this upstream commit 62572e29bc53, solved
the problem.

You can apply that commit and see if you if you get both RCU stall
messages _and_ softlockup messages.  I believe that is what you were
expecting, correct?


Of course, on a non-virt guest, your test case would normally trigger a
hardlockup warning first.  And a later kernel version for the guest may
actually do that (not quite sure if the emulated PMU stuff is upstream or
not yet).  Just to set your expectations correctly.

Cheers,
Don

> 
> Thanks!
> 
> >>         return 0;
> >> }
> >>
> >> static int __init test_init(void)
> >> {
> >>         hello_start();
> >>
> >>         printk(KERN_INFO "Module init\n");
> >>         return 0;
> >> }
> >>
> >> static void __exit test_exit(void)
> >> {
> >>         printk(KERN_INFO "Module exit!\n");
> >> }
> >>
> >> module_init(test_init)
> >> module_exit(test_exit)
> >> MODULE_LICENSE("GPL");
> >> //
> >>
> >> My kernel version is v3.10.63, and i checked the kernel source code,
> >>
> >> update_process_times
> >> 	-> run_local_timers
> >> 		-> hrtimer_run_queues
> >> 			-> __run_hrtimer
> >> 				-> watchdog_timer_fn
> >> 					-> is_softlockup
> >> 					
> >> 	-> rcu_check_callbacks
> >> 		-> __rcu_pending
> >> 			-> check_cpu_stall
> >> 				-> print_cpu_stall
> >>
> >> If softlockup_thresh > rcu_cpu_stall_timeout, print_cpu_stall will print log to serial port.
> >>
> >> The 8250 serial driver will call serial8250_console_write => touch_nmi_watchdog() which reset
> >> watchdog_touch_ts to 0. So the softlockup will not be triggered.
> >>
> >> Is this reasonable? Why?
> > 
> > Is exactly what reasonable?  ;-)
> > 
> > Yes, it is reasonable that your code triggers an RCU CPU stall warning.
> > 
> > No, it is not reasonable that the RCU CPU stall warning does not include
> > a stack trace, and the fix for that bug will be going into the next merge
> > window.
> > 
> > Yes, is is reasonable that varying the softlockup and RCU CPU stall
> > timeouts might change the behavior.
> > 
> > No, your code is not reasonable, except perhaps as a test of the
> > generation of softlockup and RCU CPU stall warnings.  If you are not
> > trying to test softlockup and RCU CPU stall warnings, you should of course
> > not try to acquire any non-recursive exclusive lock that you already hold.
> > 
> >> If it is not reasonable, we should adjust the printk loglevel from *KERN_ERR* to *KERN_INFO*
> >> in print_cpu_stall.
> > 
> > Given that RCU CPU stall warnings are supposed to be pointing out errors
> > elsewhere in the kernel, and in this case are pointing out errors elsewhere
> > in the kernel, namely in your hello_start() function, it is reasonable
> > that the RCU CPU stall warnings use the KERN_ERR loglevel.
> > 
> > Or am I missing something here?
> > 
> > 							Thanx, Paul
> > 
> > 
> > .
> > 
> 
>