Bug#822936: INFO: rcu_sched self-detected stall on CPU

[Ben Hutchings <ben@decadent.org.uk>]

On Fri, 2016-04-29 at 03:10 -0400, Jiann-Ming Su wrote:

> Package: linux-image-3.16.0-4-686-pae
> Version: 3.16.7-ckt25-1
> 
> The netbook doesn't crash, but the entire networking stack freezes up.
> When I press a key on the keyboard, the backlight comes on, and
> everything is functional again.
> 
> Apr 27 21:53:20 ranfan kernel: INFO: rcu_sched self-detected stall on CPU { 0}  (t=6590 jiffies g=23325 c=23324 q=2)
> Apr 27 21:53:20 ranfan kernel: sending NMI to all CPUs:
> Apr 27 21:53:20 ranfan kernel: NMI backtrace for cpu 0
[...]
> Apr 27 21:52:54 ranfan kernel: NMI backtrace for cpu 1

Notice how the log time goes backward by 26 seconds, which corresponds
closely to the stall time of 6590 jiffies.  The syslog daemon generates
the timestamps, not the kernel, but presumably it has been woken up
once on each of the CPUs as they started to write a call trace.

[...]
> Apr 28 03:19:37 ranfan kernel: INFO: rcu_sched self-detected stall on CPU { 0}  (t=67279 jiffies g=88895 c=88894 q=1)
> Apr 28 03:19:37 ranfan kernel: sending NMI to all CPUs:
> Apr 28 03:19:37 ranfan kernel: NMI backtrace for cpu 0
[...]
> Apr 28 03:15:08 ranfan kernel: NMI backtrace for cpu 1

The log time goes backward by 269 seconds, which again corresponds
closely to the stall time of 67279 jiffies.

After that long a stall, the soft-lockup watchdog should also have
fired and logged errror messages, but we don't see them.

In the first two cases the CPU that didn't detect the stall is in
cpu_startup_entry which implies it's just coming online.  But in the
last case, both CPUs seem to be in a more normal state.  Also there's
no sign of clock skew in the log, though it doesn't mean there isn't a
skew.

Ben.

-- 
Ben Hutchings
Life is what happens to you while you're busy making other plans.
                                                               - John Lennon

Attachment: signature.asc
Description: This is a digitally signed message part