Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.debian.kernel > #53834 > unrolled thread

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

Started byJiann-Ming Su <sujiannming@gmail.com>
First post2016-04-29 09:20 +0200
Last post2017-11-21 17:30 +0100
Articles 5 — 2 participants

Back to article view | Back to linux.debian.kernel

Contents

  Bug#822936: INFO: rcu_sched self-detected stall on CPU Jiann-Ming Su <sujiannming@gmail.com> - 2016-04-29 09:20 +0200
    Bug#822936: INFO: rcu_sched self-detected stall on CPU Ben Hutchings <ben@decadent.org.uk> - 2016-05-02 22:10 +0200
    Bug#822936: Occurs on Stretch Jiann-Ming Su <sujiannming@gmail.com> - 2017-10-29 03:50 +0100
      Bug#822936: Occurs on Stretch Jiann-Ming Su <sujiannming@gmail.com> - 2017-11-06 04:00 +0100
        Bug#822936: Occurs on Stretch Jiann-Ming Su <sujiannming@gmail.com> - 2017-11-21 17:30 +0100

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

FromJiann-Ming Su <sujiannming@gmail.com>
Date2016-04-29 09:20 +0200
SubjectBug#822936: INFO: rcu_sched self-detected stall on CPU
Message-ID<rtaSu-1U4-7@gated-at.bofh.it>
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:53:20 ranfan kernel: CPU: 0 PID: 0 Comm: swapper/0 Not
tainted 3.16.0-4-686-pae #1 Debian 3.16.7-ckt25-1
Apr 27 21:53:20 ranfan kernel: Hardware name: Acer             AO751h
         /JV11-ML          , BIOS V0.3212 02/26/2010
Apr 27 21:53:20 ranfan kernel: task: c15fca00 ti: c15ee000 task.ti: c15ee00
0
Apr 27 21:53:20 ranfan kernel: EIP: 0060:[<c1040385>] EFLAGS: 00200006 CPU: 0
Apr 27 21:53:20 ranfan kernel: EIP is at
arch_trigger_all_cpu_backtrace+0x95/0xd0
Apr 27 21:53:20 ranfan kernel: EAX: 00418958 EBX: 00002710 ECX:
fffff000 EDX: fffff000
Apr 27 21:53:20 ranfan kernel: ESI: c1614f80 EDI: f75d9620 EBP:
f5007e40 ESP: f5007e34
Apr 27 21:53:20 ranfan kernel:  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Apr 27 21:53:20 ranfan kernel: CR0: 8005003b CR2: b7765000 CR3:
0171e000 CR4: 000007f0
Apr 27 21:53:20 ranfan kernel: Stack:
Apr 27 21:53:20 ranfan kernel:  c1548401 c157a0ce c1614f80 f5007e88
c10ac95d c1557924 000019be 00005b1d
Apr 27 21:53:20 ranfan kernel:  00005b1c 00000002 00000000 f5007e88
c1084790 00000001 c166a5ec c1614f80
Apr 27 21:53:20 ranfan kernel:  f75d9620 00000000 c15fca00 00000000
00000000 f5007e9c c1062dac f5009f7c
Apr 27 21:53:20 ranfan kernel: Call Trace:
Apr 27 21:53:20 ranfan kernel:  [<c10ac95d>] ? rcu_check_callbacks+0x38d/0x5b0
Apr 27 21:53:20 ranfan kernel:  [<c1084790>] ? account_process_tick+0x60/0x130
Apr 27 21:53:20 ranfan kernel:  [<c1062dac>] ? update_process_times+0x3c/0x60
Apr 27 21:53:20 ranfan kernel:  [<c10b78e6>] ?
tick_sched_handle.isra.13+0x26/0x60
Apr 27 21:53:20 ranfan kernel:  [<c10b7957>] ? tick_sched_timer+0x37/0x70
Apr 27 21:53:20 ranfan kernel:  [<c1075db8>] ? __remove_hrtimer+0x38/0x90
Apr 27 21:53:20 ranfan kernel:  [<c10766cd>] ? __run_hrtimer+0x6d/0x190
Apr 27 21:53:20 ranfan kernel:  [<c10b7920>] ?
tick_sched_handle.isra.13+0x60/0x60
Apr 27 21:53:20 ranfan kernel:  [<c1076e48>] ? hrtimer_interrupt+0x1e8/0x2a
0
Apr 27 21:53:20 ranfan kernel:  [<c10b64eb>] ?
tick_do_broadcast.constprop.7+0x6b/0x70
Apr 27 21:53:20 ranfan kernel:  [<c10b6685>] ?
tick_handle_oneshot_broadcast+0x105/0x180
Apr 27 21:53:20 ranfan kernel:  [<c132d35a>] ?
add_interrupt_randomness+0x15a/0x1a0
Apr 27 21:53:20 ranfan kernel:  [<c1011be2>] ? timer_interrupt+0x12/0x20
Apr 27 21:53:20 ranfan kernel:  [<c10a3685>] ?
handle_irq_event_percpu+0x35/0x180
Apr 27 21:53:20 ranfan kernel:  [<c10a37fa>] ? handle_irq_event+0x2a/0x50
Apr 27 21:53:20 ranfan kernel:  [<c10a5bd0>] ? handle_simple_irq+0x70/0x70
Apr 27 21:53:20 ranfan kernel:  [<c10a5c36>] ? handle_edge_irq+0x66/0x100
Apr 27 21:53:20 ranfan kernel:  [<c1011751>] ? handle_irq+0x71/0x90
Apr 27 21:53:20 ranfan kernel:  <IRQ>
Apr 27 21:53:20 ranfan kernel:
Apr 27 21:53:20 ranfan kernel:  [<c147fd7c>] ? do_IRQ+0x3c/0xd0
Apr 27 21:53:20 ranfan kernel:  [<c108ba5e>] ? rebalance_domains+0x14e/0x25
0
Apr 27 21:53:20 ranfan kernel:  [<c147f2b3>] ? common_interrupt+0x33/0x38
Apr 27 21:53:20 ranfan kernel:  [<f838007b>] ?
psb_intel_sdvo_read_response+0xcb/0x200 [gma500_gfx]
Apr 27 21:53:20 ranfan kernel:  [<c105b5dd>] ? __do_softirq+0x6d/0x230
Apr 27 21:53:20 ranfan kernel:  [<c105b570>] ? cpu_callback+0x160/0x160
Apr 27 21:53:20 ranfan kernel:  [<c10116d2>] ? do_softirq_own_stack+0x22/0x30
Apr 27 21:53:20 ranfan kernel:  <IRQ>
Apr 27 21:53:20 ranfan kernel:
Apr 27 21:53:20 ranfan kernel:  [<c105b9bd>] ? irq_exit+0x8d/0xa0
Apr 27 21:53:20 ranfan kernel:  [<c147fd85>] ? do_IRQ+0x45/0xd0
Apr 27 21:53:20 ranfan kernel:  [<c10b6afb>] ?
tick_broadcast_oneshot_control+0x7b/0x210
Apr 27 21:53:20 ranfan kernel:  [<c147f2b3>] ? common_interrupt+0x33/0x38
Apr 27 21:53:20 ranfan kernel:  [<c13770ae>] ? cpuidle_enter_state+0x3e/0xd
0
Apr 27 21:53:20 ranfan kernel:  [<c1090c4e>] ? cpu_startup_entry+0x2be/0x3b
0
Apr 27 21:53:20 ranfan kernel:  [<c1671bf9>] ? start_kernel+0x3dd/0x3e2
Apr 27 21:53:20 ranfan kernel:  [<c1671625>] ? set_init_arg+0x45/0x45
Apr 27 21:53:20 ranfan kernel: Code: 08 5b 5d c3 66 90 f0 0f b3 15 a8
a4 66 c1 a1 a8 a4 66 c1 85 c0 75 3a 31 c0 bb 10 27 00 00 eb 1f 8d b6
00 00 00 00 b8 58 89 41 00 <e8> 36 aa 21 00 e8 91 ca 09 00 83 eb 01 74
09 a1 a8 a4 66 c1 85
Apr 27 21:52:54 ranfan kernel: NMI backtrace for cpu 1
Apr 27 21:52:54 ranfan kernel: CPU: 1 PID: 0 Comm: swapper/1 Not
tainted 3.16.0-4-686-pae #1 Debian 3.16.7-ckt25-1
Apr 27 21:52:54 ranfan kernel: Hardware name: Acer             AO751h
         /JV11-ML          , BIOS V0.3212 02/26/2010
Apr 27 21:52:54 ranfan kernel: task: f50b9560 ti: f50d0000 task.ti: f50d000
0
Apr 27 21:52:54 ranfan kernel: EIP: 0060:[<c1090a82>] EFLAGS: 00200246 CPU: 1
Apr 27 21:52:54 ranfan kernel: EIP is at cpu_startup_entry+0xf2/0x3b0
Apr 27 21:52:54 ranfan kernel: EAX: 00200000 EBX: f50d0000 ECX:
00000001 EDX: f50d1fec
Apr 27 21:52:54 ranfan kernel: ESI: 00000004 EDI: 00000001 EBP:
f50d1f90 ESP: f50d1f60
Apr 27 21:52:54 ranfan kernel:  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Apr 27 21:52:54 ranfan kernel: CR0: 8005003b CR2: b7617000 CR3:
0171e000 CR4: 000007f0
Apr 27 21:52:54 ranfan kernel: Stack:
Apr 27 21:52:54 ranfan kernel:  f50d1fec 00000000 f50d1fec 00000001
f50d1fec 00000004 f75ef600 557b25eb
Apr 27 21:52:54 ranfan kernel:  dd6adfe5 2fe19f2f 00000000 00000000
f50d1fb4 c103c587 28c824c6 c4d106c0
Apr 27 21:52:54 ranfan kernel:  0006b1e4 28360103 598dfc74 2fe19f2f
01020800 00000000 00000000 00000000
Apr 27 21:52:54 ranfan kernel: Call Trace:
Apr 27 21:52:54 ranfan kernel:  [<c103c587>] ? start_secondary+0x207/0x2e0
Apr 27 21:52:54 ranfan kernel: Code: e8 24 a4 01 00 64 8b 3d 10 e0 70
c1 3e 8d 74 26 00 fb 90 8d 74 26 00 64 8b 15 18 f0 70 c1 8b 82 1c e0
ff ff a8 08 75 0d 90 f3 90 <8b> 82 1c e0 ff ff a8 08 74 f4 64 8b 3d 10
e0 70 c1 3e 8d 74 26
Apr 27 21:53:20 ranfan kernel: INFO: NMI handler
(arch_trigger_all_cpu_backtrace_handler) took too long to run: 695.735
msecs
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:19:37 ranfan kernel: CPU: 0 PID: 0 Comm: swapper/0 Not
tainted 3.16.0-4-686-pae #1 Debian 3.16.7-ckt25-1
Apr 28 03:19:37 ranfan kernel: Hardware name: Acer             AO751h
         /JV11-ML          , BIOS V0.3212 02/26/2010
Apr 28 03:19:37 ranfan kernel: task: c15fca00 ti: c15ee000 task.ti: c15ee00
0
Apr 28 03:19:37 ranfan kernel: EIP: 0060:[<c1040385>] EFLAGS: 00200006 CPU: 0
Apr 28 03:19:37 ranfan kernel: EIP is at
arch_trigger_all_cpu_backtrace+0x95/0xd0
Apr 28 03:19:37 ranfan kernel: EAX: 00418958 EBX: 00002710 ECX:
fffff000 EDX: fffff000
Apr 28 03:19:37 ranfan kernel: ESI: c1614f80 EDI: f75d9620 EBP:
f5007e40 ESP: f5007e34
Apr 28 03:19:37 ranfan kernel:  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Apr 28 03:19:37 ranfan kernel: CR0: 8005003b CR2: b7617000 CR3:
0171e000 CR4: 000007f0
Apr 28 03:19:37 ranfan kernel: Stack:
Apr 28 03:19:37 ranfan kernel:  c1548401 c157a0ce c1614f80 f5007e88
c10ac95d c1557924 000106cf 00015b3f
Apr 28 03:19:37 ranfan kernel:  00015b3e 00000001 00000000 f5007e88
c1084790 00000001 c166a5ec c1614f80
Apr 28 03:19:37 ranfan kernel:  f75d9620 00000000 c15fca00 00000000
00000000 f5007e9c c1062dac f5009f7c
Apr 28 03:19:37 ranfan kernel: Call Trace:
Apr 28 03:19:37 ranfan kernel:  [<c10ac95d>] ? rcu_check_callbacks+0x38d/0x5b0
Apr 28 03:19:37 ranfan kernel:  [<c1084790>] ? account_process_tick+0x60/0x130
Apr 28 03:19:37 ranfan kernel:  [<c1062dac>] ? update_process_times+0x3c/0x60
Apr 28 03:19:37 ranfan kernel:  [<c10b78e6>] ?
tick_sched_handle.isra.13+0x26/0x60
Apr 28 03:19:37 ranfan kernel:  [<c10b7957>] ? tick_sched_timer+0x37/0x70
Apr 28 03:19:37 ranfan kernel:  [<c1075db8>] ? __remove_hrtimer+0x38/0x90
Apr 28 03:19:37 ranfan kernel:  [<c10766cd>] ? __run_hrtimer+0x6d/0x190
Apr 28 03:19:37 ranfan kernel:  [<c10b7920>] ?
tick_sched_handle.isra.13+0x60/0x60
Apr 28 03:19:37 ranfan kernel:  [<c1076e48>] ? hrtimer_interrupt+0x1e8/0x2a
0
Apr 28 03:19:37 ranfan kernel:  [<c10b64eb>] ?
tick_do_broadcast.constprop.7+0x6b/0x70
Apr 28 03:19:37 ranfan kernel:  [<c10b6685>] ?
tick_handle_oneshot_broadcast+0x105/0x180
Apr 28 03:19:37 ranfan kernel:  [<c132d35a>] ?
add_interrupt_randomness+0x15a/0x1a0
Apr 28 03:19:37 ranfan kernel:  [<c1011be2>] ? timer_interrupt+0x12/0x20
Apr 28 03:19:37 ranfan kernel:  [<c10a3685>] ?
handle_irq_event_percpu+0x35/0x180
Apr 28 03:19:37 ranfan kernel:  [<c10a37fa>] ? handle_irq_event+0x2a/0x50
Apr 28 03:19:37 ranfan kernel:  [<c10a5bd0>] ? handle_simple_irq+0x70/0x70
Apr 28 03:19:37 ranfan kernel:  [<c10a5c36>] ? handle_edge_irq+0x66/0x100
Apr 28 03:19:37 ranfan kernel:  [<c1011751>] ? handle_irq+0x71/0x90
Apr 28 03:19:37 ranfan kernel:  <IRQ>
Apr 28 03:19:37 ranfan kernel:
Apr 28 03:19:37 ranfan kernel:  [<c147fd7c>] ? do_IRQ+0x3c/0xd0
Apr 28 03:19:37 ranfan kernel:  [<c10aa8f5>] ? __note_gp_changes+0x45/0x50
Apr 28 03:19:37 ranfan kernel:  [<c147f2b3>] ? common_interrupt+0x33/0x38
Apr 28 03:19:37 ranfan kernel:  [<c105b5dd>] ? __do_softirq+0x6d/0x230
Apr 28 03:19:37 ranfan kernel:  [<c105b570>] ? cpu_callback+0x160/0x160
Apr 28 03:19:37 ranfan kernel:  [<c10116d2>] ? do_softirq_own_stack+0x22/0x30
Apr 28 03:19:37 ranfan kernel:  <IRQ>
Apr 28 03:19:37 ranfan kernel:
Apr 28 03:19:37 ranfan kernel:  [<c105b9bd>] ? irq_exit+0x8d/0xa0
Apr 28 03:19:37 ranfan kernel:  [<c147fd85>] ? do_IRQ+0x45/0xd0
Apr 28 03:19:37 ranfan kernel:  [<c10b6afb>] ?
tick_broadcast_oneshot_control+0x7b/0x210
Apr 28 03:19:37 ranfan kernel:  [<c147f2b3>] ? common_interrupt+0x33/0x38
Apr 28 03:19:37 ranfan kernel:  [<c13770ae>] ? cpuidle_enter_state+0x3e/0xd
0
Apr 28 03:19:37 ranfan kernel:  [<c1090c4e>] ? cpu_startup_entry+0x2be/0x3b
0
Apr 28 03:19:37 ranfan kernel:  [<c1671bf9>] ? start_kernel+0x3dd/0x3e2
Apr 28 03:19:37 ranfan kernel:  [<c1671625>] ? set_init_arg+0x45/0x45
Apr 28 03:19:37 ranfan kernel: Code: 08 5b 5d c3 66 90 f0 0f b3 15 a8
a4 66 c1 a1 a8 a4 66 c1 85 c0 75 3a 31 c0 bb 10 27 00 00 eb 1f 8d b6
00 00 00 00 b8 58 89 41 00 <e8> 36 aa 21 00 e8 91 ca 09 00 83 eb 01 74
09 a1 a8 a4 66 c1 85
Apr 28 03:15:08 ranfan kernel: NMI backtrace for cpu 1
Apr 28 03:15:08 ranfan kernel: CPU: 1 PID: 0 Comm: swapper/1 Not
tainted 3.16.0-4-686-pae #1 Debian 3.16.7-ckt25-1
Apr 28 03:15:08 ranfan kernel: Hardware name: Acer             AO751h
         /JV11-ML          , BIOS V0.3212 02/26/2010
Apr 28 03:15:08 ranfan kernel: task: f50b9560 ti: f50d0000 task.ti: f50d000
0
Apr 28 03:15:08 ranfan kernel: EIP: 0060:[<c1090a82>] EFLAGS: 00200246 CPU: 1
Apr 28 03:15:08 ranfan kernel: EIP is at cpu_startup_entry+0xf2/0x3b0
Apr 28 03:15:08 ranfan kernel: EAX: 00200000 EBX: f50d0000 ECX:
00000001 EDX: f50d1fec
Apr 28 03:15:08 ranfan kernel: ESI: 00000004 EDI: 00000001 EBP:
f50d1f90 ESP: f50d1f60
Apr 28 03:15:08 ranfan kernel:  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Apr 28 03:15:08 ranfan kernel: CR0: 8005003b CR2: bfb488d8 CR3:
0171e000 CR4: 000007f0
Apr 28 03:15:08 ranfan kernel: Stack:
Apr 28 03:15:08 ranfan kernel:  f50d1fec 00000000 f50d1fec 00000001
f50d1fec 00000004 f75ef600 557b25eb
Apr 28 03:15:08 ranfan kernel:  dd6adfe5 2fe19f2f 00000000 00000000
f50d1fb4 c103c587 28c824c6 c4d106c0
Apr 28 03:15:08 ranfan kernel:  0006b1e4 28360103 598dfc74 2fe19f2f
01020800 00000000 00000000 00000000
Apr 28 03:15:08 ranfan kernel: Call Trace:
Apr 28 03:15:08 ranfan kernel:  [<c103c587>] ? start_secondary+0x207/0x2e0
Apr 28 03:15:08 ranfan kernel: Code: e8 24 a4 01 00 64 8b 3d 10 e0 70
c1 3e 8d 74 26 00 fb 90 8d 74 26 00 64 8b 15 18 f0 70 c1 8b 82 1c e0
ff ff a8 08 75 0d 90 f3 90 <8b> 82 1c e0 ff ff a8 08 74 f4 64 8b 3d 10
e0 70 c1 3e 8d 74 26
Apr 28 03:19:37 ranfan kernel: INFO: NMI handler
(arch_trigger_all_cpu_backtrace_handler) took too long to run: 759.702
msecs
Apr 28 08:32:34 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 28 08:32:34 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 28 08:44:30 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 28 08:44:30 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 28 22:16:16 ranfan kernel: [sched_delayed] sched: RT throttling activated
Apr 29 01:55:32 ranfan kernel: INFO: rcu_sched self-detected stall on
CPU { 0}  (t=29431 jiffies g=345118 c=345117 q=3)
Apr 29 01:55:32 ranfan kernel: sending NMI to all CPUs:
Apr 29 01:55:32 ranfan kernel: NMI backtrace for cpu 1
Apr 29 01:55:32 ranfan kernel: CPU: 1 PID: 0 Comm: swapper/1 Not
tainted 3.16.0-4-686-pae #1 Debian 3.16.7-ckt25-1
Apr 29 01:55:32 ranfan kernel: Hardware name: Acer             AO751h
         /JV11-ML          , BIOS V0.3212 02/26/2010
Apr 29 01:55:32 ranfan kernel: task: f50b9560 ti: f50d0000 task.ti: f50d000
0
Apr 29 01:55:32 ranfan kernel: EIP: 0060:[<c147e7d1>] EFLAGS: 00200002 CPU: 1
Apr 29 01:55:32 ranfan kernel: EIP is at _raw_spin_lock_irqsave+0x31/0x40
Apr 29 01:55:32 ranfan kernel: EAX: 00000064 EBX: 00200002 ECX:
c17552ec EDX: 00000063
Apr 29 01:55:32 ranfan kernel: ESI: f75e7100 EDI: c1608440 EBP:
f50d1ed8 ESP: f50d1ed4
Apr 29 01:55:32 ranfan kernel:  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Apr 29 01:55:32 ranfan kernel: CR0: 8005003b CR2: b7617000 CR3:
0171e000 CR4: 000007f0
Apr 29 01:55:32 ranfan kernel: Stack:
Apr 29 01:55:32 ranfan kernel:  00000001 f50d1f04 c10b6ad3 00000595
f75e95ac f75e95a0 f50d1efc 00000004
Apr 29 01:55:32 ranfan kernel:  f50d1ef8 f50d1f28 00200096 00000004
f50d1f1c c10b580f f75ef600 00000040
Apr 29 01:55:32 ranfan kernel:  00000004 00000006 f50d1f38 c12bdab5
00000052 00000001 c1642780 f75ef600
Apr 29 01:55:32 ranfan kernel: Call Trace:
Apr 29 01:55:32 ranfan kernel:  [<c10b6ad3>] ?
tick_broadcast_oneshot_control+0x53/0x210
Apr 29 01:55:32 ranfan kernel:  [<c10b580f>] ? clockevents_notify+0x13f/0x180
Apr 29 01:55:32 ranfan kernel:  [<c12bdab5>] ? intel_idle+0x105/0x120
Apr 29 01:55:32 ranfan kernel:  [<c13770a1>] ? cpuidle_enter_state+0x31/0xd
0
Apr 29 01:55:32 ranfan kernel:  [<c1090c4e>] ? cpu_startup_entry+0x2be/0x3b
0
Apr 29 01:55:32 ranfan kernel:  [<c103c587>] ? start_secondary+0x207/0x2e0
Apr 29 01:55:32 ranfan kernel: Code: 74 26 00 89 c1 9c 58 8d 74 26 00
89 c3 fa 90 8d 74 26 00 ba 00 01 00 00 f0 66 0f c1 11 0f b6 c6 38 d0
75 07 89 d8 5b 5d c3 f3 90 <0f> b6 11 38 d0 75 f7 eb f0 8d b6 00 00 00
00 55 89 e5 3e 8d 74
Apr 29 01:55:32 ranfan kernel: NMI backtrace for cpu 0
Apr 29 01:55:32 ranfan kernel: CPU: 0 PID: 0 Comm: swapper/0 Not
tainted 3.16.0-4-686-pae #1 Debian 3.16.7-ckt25-1
Apr 29 01:55:32 ranfan kernel: Hardware name: Acer             AO751h
         /JV11-ML          , BIOS V0.3212 02/26/2010
Apr 29 01:55:32 ranfan kernel: task: c15fca00 ti: c15ee000 task.ti: c15ee00
0
Apr 29 01:55:32 ranfan kernel: EIP: 0060:[<c1040385>] EFLAGS: 00200006 CPU: 0
Apr 29 01:55:32 ranfan kernel: EIP is at
arch_trigger_all_cpu_backtrace+0x95/0xd0
Apr 29 01:55:32 ranfan kernel: EAX: 00418958 EBX: 00002710 ECX:
fffff000 EDX: fffff000
Apr 29 01:55:32 ranfan kernel: ESI: c1614f80 EDI: f75d9620 EBP:
f5007e40 ESP: f5007e34
Apr 29 01:55:32 ranfan kernel:  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Apr 29 01:55:32 ranfan kernel: CR0: 8005003b CR2: b7765000 CR3:
0171e000 CR4: 000007f0
Apr 29 01:55:32 ranfan kernel: Stack:
Apr 29 01:55:32 ranfan kernel:  c1548401 c157a0ce c1614f80 f5007e88
c10ac95d c1557924 000072f7 0005441e
Apr 29 01:55:32 ranfan kernel:  0005441d 00000003 00000000 f5007e88
c1084790 00000001 c166a5ec c1614f80
Apr 29 01:55:32 ranfan kernel:  f75d9620 00000000 c15fca00 00000000
00000000 f5007e9c c1062dac f5009f7c
Apr 29 01:55:32 ranfan kernel: Call Trace:
Apr 29 01:55:32 ranfan kernel:  [<c10ac95d>] ? rcu_check_callbacks+0x38d/0x5b0
Apr 29 01:55:32 ranfan kernel:  [<c1084790>] ? account_process_tick+0x60/0x130
Apr 29 01:55:32 ranfan kernel:  [<c1062dac>] ? update_process_times+0x3c/0x60
Apr 29 01:55:32 ranfan kernel:  [<c10b78e6>] ?
tick_sched_handle.isra.13+0x26/0x60
Apr 29 01:55:32 ranfan kernel:  [<c10b7957>] ? tick_sched_timer+0x37/0x70
Apr 29 01:55:32 ranfan kernel:  [<c1075db8>] ? __remove_hrtimer+0x38/0x90
Apr 29 01:55:32 ranfan kernel:  [<c10766cd>] ? __run_hrtimer+0x6d/0x190
Apr 29 01:55:32 ranfan kernel:  [<c10b7920>] ?
tick_sched_handle.isra.13+0x60/0x60
Apr 29 01:55:32 ranfan kernel:  [<c1076e48>] ? hrtimer_interrupt+0x1e8/0x2a
0
Apr 29 01:55:32 ranfan kernel:  [<c10b64eb>] ?
tick_do_broadcast.constprop.7+0x6b/0x70
Apr 29 01:55:32 ranfan kernel:  [<c10b6685>] ?
tick_handle_oneshot_broadcast+0x105/0x180
Apr 29 01:55:32 ranfan kernel:  [<c132d35a>] ?
add_interrupt_randomness+0x15a/0x1a0
Apr 29 01:55:32 ranfan kernel:  [<c1011be2>] ? timer_interrupt+0x12/0x20
Apr 29 01:55:32 ranfan kernel:  [<c10a3685>] ?
handle_irq_event_percpu+0x35/0x180
Apr 29 01:55:32 ranfan kernel:  [<c10a5bd0>] ? handle_simple_irq+0x70/0x70
Apr 29 01:55:32 ranfan kernel:  [<c147fc27>] ? nmi_stack_correct+0x2f/0x34
Apr 29 01:55:32 ranfan kernel:  [<c10a37fa>] ? handle_irq_event+0x2a/0x50
Apr 29 01:55:32 ranfan kernel:  [<c10a5bd0>] ? handle_simple_irq+0x70/0x70
Apr 29 01:55:32 ranfan kernel:  [<c10a5c36>] ? handle_edge_irq+0x66/0x100
Apr 29 01:55:32 ranfan kernel:  [<c1011751>] ? handle_irq+0x71/0x90
Apr 29 01:55:32 ranfan kernel:  <IRQ>
Apr 29 01:55:32 ranfan kernel:
Apr 29 01:55:32 ranfan kernel:  [<c147fd7c>] ? do_IRQ+0x3c/0xd0
Apr 29 01:55:32 ranfan kernel:  [<c147f2b3>] ? common_interrupt+0x33/0x38
Apr 29 01:55:32 ranfan kernel:  [<c105b5dd>] ? __do_softirq+0x6d/0x230
Apr 29 01:55:32 ranfan kernel:  [<c105b570>] ? cpu_callback+0x160/0x160
Apr 29 01:55:32 ranfan kernel:  [<c147fc27>] ? nmi_stack_correct+0x2f/0x34
Apr 29 01:55:32 ranfan kernel:  [<c105b570>] ? cpu_callback+0x160/0x160
Apr 29 01:55:32 ranfan kernel:  [<c10116d2>] ? do_softirq_own_stack+0x22/0x30
Apr 29 01:55:32 ranfan kernel:  <IRQ>
Apr 29 01:55:32 ranfan kernel:
Apr 29 01:55:32 ranfan kernel:  [<c105b9bd>] ? irq_exit+0x8d/0xa0
Apr 29 01:55:32 ranfan kernel:  [<c147fd85>] ? do_IRQ+0x45/0xd0
Apr 29 01:55:32 ranfan kernel:  [<c10b6afb>] ?
tick_broadcast_oneshot_control+0x7b/0x210
Apr 29 01:55:32 ranfan kernel:  [<c147f2b3>] ? common_interrupt+0x33/0x38
Apr 29 01:55:32 ranfan kernel:  [<c13770ae>] ? cpuidle_enter_state+0x3e/0xd
0
Apr 29 01:55:32 ranfan kernel:  [<c1090c4e>] ? cpu_startup_entry+0x2be/0x3b
0
Apr 29 01:55:32 ranfan kernel:  [<c1671bf9>] ? start_kernel+0x3dd/0x3e2
Apr 29 01:55:32 ranfan kernel:  [<c1671625>] ? set_init_arg+0x45/0x45
Apr 29 01:55:32 ranfan kernel: Code: 08 5b 5d c3 66 90 f0 0f b3 15 a8
a4 66 c1 a1 a8 a4 66 c1 85 c0 75 3a 31 c0 bb 10 27 00 00 eb 1f 8d b6
00 00 00 00 b8 58 89 41 00 <e8> 36 aa 21 00 e8 91 ca 09 00 83 eb 01 74
09 a1 a8 a4 66 c1 85
Apr 29 01:55:32 ranfan kernel: INFO: NMI handler
(arch_trigger_all_cpu_backtrace_handler) took too long to run: 760.343
msecs
Apr 29 01:55:33 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 29 01:55:33 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 29 02:00:48 ranfan kernel: device-mapper: uevent: version 1.0.3
Apr 29 02:00:48 ranfan kernel: device-mapper: ioctl: 4.27.0-ioctl
(2013-10-30) initialised: dm-devel@redhat.com
Apr 29 02:00:51 ranfan kernel: SGI XFS with ACLs, security attributes,
realtime, large block/inode numbers, no debug enabled
Apr 29 02:00:51 ranfan kernel: JFS: nTxBlock = 8192, nTxLock = 65536
Apr 29 02:00:51 ranfan kernel: ntfs: driver 2.1.30 [Flags: R/W MODULE].
Apr 29 02:00:51 ranfan kernel: QNX4 filesystem 0.2.3 registered.
Apr 29 02:00:51 ranfan kernel: fuse init (API version 7.23)
Apr 29 02:06:29 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a
Apr 29 02:06:29 ranfan kernel: gma500 0000:00:02.0: Backlight lvds set
brightness 186a186a


-- 
Jiann-Ming Su
"I have to decide between two equally frightening options.
 If I wanted to do that, I'd vote." --Duckman
"The system's broke, Hank.  The election baby has peed in
the bath water.  You got to throw 'em both out."  --Dale Gribble
"Those who vote decide nothing.
Those who count the votes decide everything.”  --Joseph Stalin

[toc] | [next] | [standalone]

#53897

FromBen Hutchings <ben@decadent.org.uk>
Date2016-05-02 22:10 +0200
Message-ID<ruski-1EO-5@gated-at.bofh.it>
In reply to#53834

[Multipart message — attachments visible in raw view] — view raw

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

[toc] | [prev] | [next] | [standalone]

#59283 — Bug#822936: Occurs on Stretch

FromJiann-Ming Su <sujiannming@gmail.com>
Date2017-10-29 03:50 +0100
SubjectBug#822936: Occurs on Stretch
Message-ID<uFLPI-1sJ-1@gated-at.bofh.it>
In reply to#53834
linux-image-4.9.0-4-686-pae      4.9.51-1

Oct 27 08:15:19 puar kernel: [26080.447922] INFO: rcu_sched
self-detected stall on CPU
Oct 27 08:15:19 puar kernel: [26080.447946] INFO: rcu_sched
self-detected stall on CPU
Oct 27 08:15:19 puar kernel: [26080.447964]     1-...: (1 GPs behind)
idle=c41/1/0 softirq=1143278/1143279 fqs=0
Oct 27 08:15:19 puar kernel: [26080.447968]
Oct 27 08:15:19 puar kernel: [26080.447976]  (t=9226 jiffies g=487334
c=487333 q=1)
Oct 27 08:15:19 puar kernel: [26080.447988] rcu_sched kthread starved
for 9226 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
Oct 27 08:15:19 puar kernel: [26080.447993] rcu_sched       S
Oct 27 08:15:19 puar kernel: [26080.448001]     0     7      2 0x00000000
Oct 27 08:15:19 puar kernel: 00000000
Oct 27 08:15:19 puar kernel: [26080.448012]  f300a100 f68b8800
f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280 0051bec4
Oct 27 08:15:19 puar kernel: [26080.448041]  f7518db8 c7767680
f300a100 f79deac0 f75189c0 f751bee0 f75189c0 f79d8900
Oct 27 08:15:19 puar kernel: [26080.448069]  f751bf00 f751bee0
c75aa3ae f79d8900 f751bf28 c75ad08f 00000002Call Trace:
Oct 27 08:15:19 puar kernel: [26080.448126]  [<c75a9e7e>] ?
__schedule+0x25e/0x760
Oct 27 08:15:19 puar kernel: [26080.448144]  [<c70d4cd7>] ?
lock_timer_base+0x67/0x80
Oct 27 08:15:19 puar kernel: [26080.448158]  [<c75aa3ae>] ? schedule+0x2e/0x80
Oct 27 08:15:19 puar kernel: [26080.448172]  [<c75ad08f>] ?
schedule_timeout+0x12f/0x300
Oct 27 08:15:19 puar kernel: [26080.448186]  [<c70d5d40>] ?
del_timer_sync+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.448199]  [<c70d0651>] ?
rcu_gp_kthread+0x4a1/0x7c0
Oct 27 08:15:19 puar kernel: [26080.448214]  [<c7084314>] ? kthread+0xb4/0xd0
Oct 27 08:15:19 puar kernel: [26080.448225]  [<c70d01b0>] ?
rcu_note_context_switch+0xf0/0xf0
Oct 27 08:15:19 puar kernel: [26080.448237]  [<c7084260>] ?
kthread_park+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.448248]  [<c75ae643>] ?
ret_from_fork+0x1b/0x28
Oct 27 08:15:19 puar kernel: [26080.448299] Task dump for CPU 0:
Oct 27 08:15:19 puar kernel: [26080.448307] swapper/0       R
Oct 27 08:15:19 puar kernel: [26080.448310]   running task        0
 0      0 0x00000000
Oct 27 08:15:19 puar kernel: c77c55f0
Oct 27 08:15:19 puar kernel: [26080.448327]  c7761fbc 00000000
c776007b bc31007b 000000d8 c77c00e0 ffffff5e c7480944
Oct 27 08:15:19 puar kernel: [26080.448355]  00000060 00000246
00001667 bc2ca3cb 000017af 00000000 c77c54a0 00000004
Oct 27 08:15:19 puar kernel: [26080.448382]  ff9d7fe0 bc314afc
000017af 00000000 ff9d7fe0 c77c54a0 c7761fe4Call Trace:
Oct 27 08:15:19 puar kernel: [26080.448435]  [<c7480944>] ?
cpuidle_enter_state+0x134/0x330
Oct 27 08:15:19 puar kernel: [26080.448451]  [<c70a9355>] ?
cpu_startup_entry+0x135/0x220
Oct 27 08:15:19 puar kernel: [26080.448467]  [<c7803b53>] ?
start_kernel+0x39d/0x3b4
Oct 27 08:15:19 puar kernel: [26080.448473] Task dump for CPU 1:
Oct 27 08:15:19 puar kernel: [26080.448478] swapper/1       R
Oct 27 08:15:19 puar kernel: [26080.448481]   running task        0
 0      1 0x00000008
Oct 27 08:15:19 puar kernel: f7527dcc
Oct 27 08:15:19 puar kernel: [26080.448495]  c7091941 c76b35df
00000000 00000000 00000001 00000008 c7782140 c7782140
Oct 27 08:15:19 puar kernel: [26080.448522]  00000001 f7527de4
c7166884 00000087 f79f3300 c7782140 c7782140 f7527e30
Oct 27 08:15:19 puar kernel: [26080.448550]  c70d20e1 c76a9ed0
0000240a 00076fa6 00076fa5 00000001 603ea661Call Trace:
Oct 27 08:15:19 puar kernel: [26080.448593]  [<c7091941>] ?
sched_show_task+0xf1/0x160
Oct 27 08:15:19 puar kernel: [26080.448612]  [<c7166884>] ?
rcu_dump_cpu_stacks+0x79/0x95
Oct 27 08:15:19 puar kernel: [26080.448633]  [<c70d20e1>] ?
rcu_check_callbacks+0x631/0x780
Oct 27 08:15:19 puar kernel: [26080.448652]  [<c70d7748>] ?
update_process_times+0x28/0x50
Oct 27 08:15:19 puar kernel: [26080.448665]  [<c70e8c86>] ?
tick_sched_handle.isra.11+0x26/0x60
Oct 27 08:15:19 puar kernel: [26080.448675]  [<c70e8cfa>] ?
tick_sched_timer+0x3a/0x80
Oct 27 08:15:19 puar kernel: [26080.448688]  [<c70d81df>] ?
__remove_hrtimer+0x3f/0x80
Oct 27 08:15:19 puar kernel: [26080.448700]  [<c70d8400>] ?
__hrtimer_run_queues+0xc0/0x260
Oct 27 08:15:19 puar kernel: [26080.448712]  [<c70e8cc0>] ?
tick_sched_handle.isra.11+0x60/0x60
Oct 27 08:15:19 puar kernel: [26080.448725]  [<c70d8c23>] ?
hrtimer_interrupt+0x93/0x1a0
Oct 27 08:15:19 puar kernel: [26080.448742]  [<c75afa63>] ?
smp_apic_timer_interrupt+0x33/0x50
Oct 27 08:15:19 puar kernel: [26080.448753]  [<c75af178>] ?
apic_timer_interrupt+0x34/0x3c
Oct 27 08:15:19 puar kernel: [26080.448772]  [<c7480944>] ?
cpuidle_enter_state+0x134/0x330
Oct 27 08:15:19 puar kernel: [26080.448787]  [<c70a9355>] ?
cpu_startup_entry+0x135/0x220
Oct 27 08:15:19 puar kernel: [26080.448801]  [<c70450f5>] ?
start_secondary+0x155/0x1b0
Oct 27 08:15:19 puar kernel: [26080.449772]     0-...: (1 ticks this
GP) idle=3e1/2/0 softirq=1245237/1245237 fqs=0
Oct 27 08:15:19 puar kernel: [26080.450190]      (t=9227 jiffies
g=487334 c=487333 q=3)
Oct 27 08:15:19 puar kernel: [26080.450514] rcu_sched kthread starved
for 9227 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0
Oct 27 08:15:19 puar kernel: [26080.451087] rcu_sched       R  running
task        0     7      2 0x00000000
Oct 27 08:15:19 puar kernel: [26080.451109]  00000000 f300a100
f68b8800 f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280
Oct 27 08:15:19 puar kernel: [26080.451143]  0051bec4 f7518db8
c7767680 f300a100 f79deac0 f75189c0 f751bee0 f75189c0
Oct 27 08:15:19 puar kernel: [26080.451175]  f79d8900 f79d8900
f751bee0 c70d5d39 f79ec900 f751bf28 c75ad08f c7782140
Oct 27 08:15:19 puar kernel: [26080.451205] Call Trace:
Oct 27 08:15:19 puar kernel: [26080.451240]  [<c75a9e7e>] ?
__schedule+0x25e/0x760
Oct 27 08:15:19 puar kernel: [26080.451257]  [<c70d4cd7>] ?
lock_timer_base+0x67/0x80
Oct 27 08:15:19 puar kernel: [26080.451271]  [<c75aa3ae>] ? schedule+0x2e/0x80
Oct 27 08:15:19 puar kernel: [26080.451285]  [<c75ad08f>] ?
schedule_timeout+0x12f/0x300
Oct 27 08:15:19 puar kernel: [26080.451298]  [<c70d5d40>] ?
del_timer_sync+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.451311]  [<c70d0651>] ?
rcu_gp_kthread+0x4a1/0x7c0
Oct 27 08:15:19 puar kernel: [26080.451326]  [<c7084314>] ? kthread+0xb4/0xd0
Oct 27 08:15:19 puar kernel: [26080.451337]  [<c70d01b0>] ?
rcu_note_context_switch+0xf0/0xf0
Oct 27 08:15:19 puar kernel: [26080.451349]  [<c7084260>] ?
kthread_park+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.451360]  [<c75ae643>] ?
ret_from_fork+0x1b/0x28
Oct 27 08:15:19 puar kernel: [26080.451399] Task dump for CPU 0:
Oct 27 08:15:19 puar kernel: [26080.451404] swapper/0       R  running
task        0     0      0 0x00000008
Oct 27 08:15:19 puar kernel: [26080.451419]  f742fe54 c7091941
c76b35df 00000000 00000000 00000000 00000008 c7782140
Oct 27 08:15:19 puar kernel: [26080.451446]  c7782140 00000000
f742fe6c c7166884 00000087 f79df300 c7782140 c7782140
Oct 27 08:15:19 puar kernel: [26080.451473]  f742feb8 c70d20e1
c76a9ed0 0000240b 00076fa6 00076fa5 00000003 f79deac0
Oct 27 08:15:19 puar kernel: [26080.451500] Call Trace:
Oct 27 08:15:19 puar kernel: [26080.451506]  <IRQ>
Oct 27 08:15:19 puar kernel: [26080.451525]  [<c7091941>] ?
sched_show_task+0xf1/0x160
Oct 27 08:15:19 puar kernel: [26080.451543]  [<c7166884>] ?
rcu_dump_cpu_stacks+0x79/0x95
Oct 27 08:15:19 puar kernel: [26080.451555]  [<c70d20e1>] ?
rcu_check_callbacks+0x631/0x780
Oct 27 08:15:19 puar kernel: [26080.451569]  [<c7094f7a>] ?
account_process_tick+0x5a/0x150
Oct 27 08:15:19 puar kernel: [26080.451583]  [<c70d7748>] ?
update_process_times+0x28/0x50
Oct 27 08:15:19 puar kernel: [26080.451596]  [<c70e8c86>] ?
tick_sched_handle.isra.11+0x26/0x60
Oct 27 08:15:19 puar kernel: [26080.451606]  [<c70e8cfa>] ?
tick_sched_timer+0x3a/0x80
Oct 27 08:15:19 puar kernel: [26080.451618]  [<c70d81df>] ?
__remove_hrtimer+0x3f/0x80
Oct 27 08:15:19 puar kernel: [26080.451631]  [<c70d8400>] ?
__hrtimer_run_queues+0xc0/0x260
Oct 27 08:15:19 puar kernel: [26080.451642]  [<c70e8cc0>] ?
tick_sched_handle.isra.11+0x60/0x60
Oct 27 08:15:19 puar kernel: [26080.451656]  [<c70d8c23>] ?
hrtimer_interrupt+0x93/0x1a0
Oct 27 08:15:19 puar kernel: [26080.451671]  [<c7024d02>] ?
timer_interrupt+0x12/0x20
Oct 27 08:15:19 puar kernel: [26080.451687]  [<c70c4ba8>] ?
__handle_irq_event_percpu+0x78/0x190
Oct 27 08:15:19 puar kernel: [26080.451700]  [<c70c4ceb>] ?
handle_irq_event_percpu+0x2b/0x70
Oct 27 08:15:19 puar kernel: [26080.451713]  [<c70c4d5f>] ?
handle_irq_event+0x2f/0x50
Oct 27 08:15:19 puar kernel: [26080.451724]  [<c70c810d>] ?
handle_edge_irq+0x6d/0x120
Oct 27 08:15:19 puar kernel: [26080.451735]  [<c70c80a0>] ?
handle_level_irq+0xe0/0xe0
Oct 27 08:15:19 puar kernel: [26080.451745]  [<c7024844>] ? handle_irq+0x54/0x70
Oct 27 08:15:19 puar kernel: [26080.451749]  <EOI>
Oct 27 08:15:19 puar kernel: [26080.451754]  <IRQ>
Oct 27 08:15:19 puar kernel: [26080.451767]  [<c75af9ac>] ? do_IRQ+0x3c/0xc
0
Oct 27 08:15:19 puar kernel: [26080.451779]  [<c70a8d25>] ?
swake_up_locked+0x25/0x30
Oct 27 08:15:19 puar kernel: [26080.451790]  [<c75aee73>] ?
common_interrupt+0x33/0x38
Oct 27 08:15:19 puar kernel: [26080.451803]  [<c75afb98>] ?
__do_softirq+0x58/0x240
Oct 27 08:15:19 puar kernel: [26080.451817]  [<c75afb40>] ?
__irqentry_text_end+0x3/0x3
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c70247e8>] ?
do_softirq_own_stack+0x28/0x30
Oct 27 08:15:19 puar kernel: [26080.451828]  <EOI>
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c706cc9d>] ? irq_exit+0xad/0xb0
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75af9b5>] ? do_IRQ+0x45/0xc
0
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75aee73>] ?
common_interrupt+0x33/0x38
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7480944>] ?
cpuidle_enter_state+0x134/0x330
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c70a9355>] ?
cpu_startup_entry+0x135/0x220
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7803b53>] ?
start_kernel+0x39d/0x3b4
Oct 27 08:15:19 puar kernel: [26080.451828] Task dump for CPU 1:
Oct 27 08:15:19 puar kernel: [26080.451828] kworker/1:1     R  running
task        0 11974      2 0x00000000
Oct 27 08:15:19 puar kernel: [26080.451828] Workqueue: events
output_poll_execute [drm_kms_helper]
Oct 27 08:15:19 puar kernel: [26080.451828]  f90bf4e0 f690ca7c
f690c94c 0000001f f690ca7c f6cd0d80 f79f2640 f31c5f38
Oct 27 08:15:19 puar kernel: [26080.451828]  c707ee21 f750cd78
f79f2ac0 f7520a00 f79f2ac0 f750c980 00000000 f79f8100
Oct 27 08:15:19 puar kernel: [26080.451828]  00000000 f79f2640
f6cd0d98 f6cd0d80 f79f2640 f31c5f64 c707f0a1 f79f2ac0
Oct 27 08:15:19 puar kernel: [26080.451828] Call Trace:
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707ee21>] ?
process_one_work+0x141/0x380
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707f0a1>] ?
worker_thread+0x41/0x460
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7084314>] ? kthread+0xb4/0xd0
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707f060>] ?
process_one_work+0x380/0x380
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7084260>] ?
kthread_park+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75ae643>] ?
ret_from_fork+0x1b/0x28


-- 
Jiann-Ming Su
"I have to decide between two equally frightening options.
 If I wanted to do that, I'd vote." --Duckman
"The system's broke, Hank.  The election baby has peed in
the bath water.  You got to throw 'em both out."  --Dale Gribble
"Those who vote decide nothing.
Those who count the votes decide everything.”  --Joseph Stalin

[toc] | [prev] | [next] | [standalone]

#59359 — Bug#822936: Occurs on Stretch

FromJiann-Ming Su <sujiannming@gmail.com>
Date2017-11-06 04:00 +0100
SubjectBug#822936: Occurs on Stretch
Message-ID<uIFNL-5cn-1@gated-at.bofh.it>
In reply to#59283
# uname -v
#1 SMP Debian 4.9.51-1 (2017-09-28)

[256204.725417] INFO: rcu_sched self-detected stall on CPU
[256204.725450] INFO: rcu_sched detected stalls on CPUs/tasks:
[256204.725473]     0-...: (2 GPs behind) idle=52b/2/0
softirq=1717403/1717404 fqs=0
[256204.725477]
[256204.725485] (detected by 1, t=18640 jiffies, g=600410, c=600409, q=1)
[256204.725490] Task dump for CPU 0:
[256204.725495] swapper/0       R
[256204.725498]   running task
[256204.725505]     0     0      0 0x00000008
[256204.725512]  d07c55f0
[256204.725517]  d0761fbc
[256204.725520]  00000000
[256204.725523]  d076007b
[256204.725527]  f3ec007b
[256204.725530]  000000d8
[256204.725533]  d07c00e0
[256204.725537]  ffffff5e
[256204.725542]  d0480944
[256204.725545]  00000060
[256204.725548]  00200246
[256204.725552]  000ad6bb
[256204.725555]  f3ea7231
[256204.725558]  0000e8f2
[256204.725561]  00000000
[256204.725565]  d07c54a0
[256204.725570]  00000004
[256204.725573]  ff9d7fe0
[256204.725576]  f3ec141f
[256204.725580]  0000e8f2
[256204.725583]  00000000
[256204.725586]  ff9d7fe0
[256204.725589]  d07c54a0
[256204.725593]  d0761fe4
[256204.725598] Call Trace:
[256204.725653]  [<d0480944>] ? cpuidle_enter_state+0x134/0x330
[256204.725673]  [<d00a9355>] ? cpu_startup_entry+0x135/0x220
[256204.725685]  [<d0803b53>] ? start_kernel+0x39d/0x3b4
[256204.725696] rcu_sched kthread starved for 18640 jiffies! g600410
c600409 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
[256204.725701] rcu_sched       S
[256204.725705]     0     7      2 0x00000000
[256204.725709]  00000000
[256204.725711]  f79f2ac0
[256204.725713]  f6c9be00
[256204.725715]  f751bed4
[256204.725717]  d05a9e7e
[256204.725719]  f751bebc
[256204.725727]  d00d4cd7
[256204.725729]  d08b8280
[256204.725732]  0051bec4
[256204.725734]  f7518db8
[256204.725736]  f7520a00
[256204.725737]  f7520a00
[256204.725739]  f79f2ac0
[256204.725741]  f75189c0
[256204.725744]  f751bee0
[256204.725746]  f75189c0
[256204.725749]  f79ec900
[256204.725750]  f751bf00
[256204.725752]  f751bee0
[256204.725754]  d05aa3ae
[256204.725756]  f79ec900
[256204.725758]  f751bf28
[256204.725760]  d05ad08f
[256204.725762]  00000002
[256204.725765] Call Trace:
[256204.725779]  [<d05a9e7e>] ? __schedule+0x25e/0x760
[256204.725790]  [<d00d4cd7>] ? lock_timer_base+0x67/0x80
[256204.725798]  [<d05aa3ae>] ? schedule+0x2e/0x80
[256204.725807]  [<d05ad08f>] ? schedule_timeout+0x12f/0x300
[256204.725815]  [<d00d5d40>] ? del_timer_sync+0x50/0x50
[256204.725823]  [<d00d0651>] ? rcu_gp_kthread+0x4a1/0x7c0
[256204.725833]  [<d0084314>] ? kthread+0xb4/0xd0
[256204.725839]  [<d00d01b0>] ? rcu_note_context_switch+0xf0/0xf0
[256204.725847]  [<d0084260>] ? kthread_park+0x50/0x50
[256204.725854]  [<d05ae643>] ? ret_from_fork+0x1b/0x28
[256204.726675]     0-...: (2 GPs behind) idle=52b/2/0
softirq=1717403/1717404 fqs=0
[256204.726951]      (t=18640 jiffies g=600410 c=600409 q=1)
[256204.727207] rcu_sched kthread starved for 18640 jiffies! g600410
c600409 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0
[256204.727557] rcu_sched       R  running task        0     7      2 0x00000000
[256204.727579]  00000000 f79f2ac0 f6c9be00 f751bed4 d05a9e7e f751bebc
d00d4cd7 d08b8280
[256204.727599]  0051bec4 f7518db8 f7520a00 f7520a00 f79f2ac0 f75189c0
f751bee0 f75189c0
[256204.727618]  f79ec900 f751bf00 f751bee0 d05aa3ae f79ec900 f751bf28
d05ad08f 00000002
[256204.727638] Call Trace:
[256204.727667]  [<d05a9e7e>] ? __schedule+0x25e/0x760
[256204.727681]  [<d00d4cd7>] ? lock_timer_base+0x67/0x80
[256204.727693]  [<d05aa3ae>] ? schedule+0x2e/0x80
[256204.727704]  [<d05ad08f>] ? schedule_timeout+0x12f/0x300
[256204.727714]  [<d00d5d40>] ? del_timer_sync+0x50/0x50
[256204.727722]  [<d00d0651>] ? rcu_gp_kthread+0x4a1/0x7c0
[256204.727733]  [<d0084314>] ? kthread+0xb4/0xd0
[256204.727741]  [<d00d01b0>] ? rcu_note_context_switch+0xf0/0xf0
[256204.727750]  [<d0084260>] ? kthread_park+0x50/0x50
[256204.727758]  [<d05ae643>] ? ret_from_fork+0x1b/0x28
[256204.727769] Task dump for CPU 0:
[256204.727774] swapper/0       R  running task        0     0      0 0x00000008
[256204.727784]  f742fe54 d0091941 d06b35df 00000000 00000000 00000000
00000008 d0782140
[256204.727802]  d0782140 00000000 f742fe6c d0166884 00200087 f79df300
d0782140 d0782140
[256204.727820]  f742feb8 d00d20e1 d06a9ed0 000048d0 0009295a 00092959
00000001 f79deac0
[256204.727839] Call Trace:
[256204.727848]  <IRQ>
[256204.727872]  [<d0091941>] ? sched_show_task+0xf1/0x160
[256204.727892]  [<d0166884>] ? rcu_dump_cpu_stacks+0x79/0x95
[256204.727908]  [<d00d20e1>] ? rcu_check_callbacks+0x631/0x780
[256204.727922]  [<d0094f7a>] ? account_process_tick+0x5a/0x150
[256204.727937]  [<d00d7748>] ? update_process_times+0x28/0x50
[256204.727949]  [<d00e8c86>] ? tick_sched_handle.isra.11+0x26/0x60
[256204.727956]  [<d00e8cfa>] ? tick_sched_timer+0x3a/0x80
[256204.727965]  [<d00d81df>] ? __remove_hrtimer+0x3f/0x80
[256204.727976]  [<d00d8400>] ? __hrtimer_run_queues+0xc0/0x260
[256204.727987]  [<d00e8cc0>] ? tick_sched_handle.isra.11+0x60/0x60
[256204.727999]  [<d00d8c23>] ? hrtimer_interrupt+0x93/0x1a0
[256204.728012]  [<d0024d02>] ? timer_interrupt+0x12/0x20
[256204.728024]  [<d00c4ba8>] ? __handle_irq_event_percpu+0x78/0x190
[256204.728034]  [<d00c4ceb>] ? handle_irq_event_percpu+0x2b/0x70
[256204.728041]  [<d00c4d5f>] ? handle_irq_event+0x2f/0x50
[256204.728049]  [<d00c810d>] ? handle_edge_irq+0x6d/0x120
[256204.728057]  [<d00c80a0>] ? handle_level_irq+0xe0/0xe0
[256204.728063]  [<d0024844>] ? handle_irq+0x54/0x70
[256204.728067]  <EOI>
[256204.728072]  <IRQ>
[256204.728084]  [<d05af9ac>] ? do_IRQ+0x3c/0xc0
[256204.728099]  [<d0146a6d>] ? irq_work_run_list+0x3d/0x60
[256204.728109]  [<d05aee73>] ? common_interrupt+0x33/0x38
[256204.728119]  [<d00600e0>] ? pre+0x150/0x270
[256204.728127]  [<d05afb98>] ? __do_softirq+0x58/0x240
[256204.728135]  [<d05afb40>] ? __irqentry_text_end+0x3/0x3
[256204.728143]  [<d05af87f>] ? nmi+0x53/0x6d
[256204.728153]  [<d05afb40>] ? __irqentry_text_end+0x3/0x3
[256204.728162]  [<d00247e8>] ? do_softirq_own_stack+0x28/0x30
[256204.728165]  <EOI>
[256204.728175]  [<d006cc9d>] ? irq_exit+0xad/0xb0
[256204.728183]  [<d05af9b5>] ? do_IRQ+0x45/0xc0
[256204.728192]  [<d05aee73>] ? common_interrupt+0x33/0x38
[256204.728206]  [<d0480944>] ? cpuidle_enter_state+0x134/0x330
[256204.728218]  [<d00a9355>] ? cpu_startup_entry+0x135/0x220
[256204.728228]  [<d0803b53>] ? start_kernel+0x39d/0x3b4

On Sat, Oct 28, 2017 at 10:44 PM, Jiann-Ming Su <sujiannming@gmail.com> wrote:
> linux-image-4.9.0-4-686-pae      4.9.51-1
>
> Oct 27 08:15:19 puar kernel: [26080.447922] INFO: rcu_sched
> self-detected stall on CPU
> Oct 27 08:15:19 puar kernel: [26080.447946] INFO: rcu_sched
> self-detected stall on CPU
> Oct 27 08:15:19 puar kernel: [26080.447964]     1-...: (1 GPs behind)
> idle=c41/1/0 softirq=1143278/1143279 fqs=0
> Oct 27 08:15:19 puar kernel: [26080.447968]
> Oct 27 08:15:19 puar kernel: [26080.447976]  (t=9226 jiffies g=487334
> c=487333 q=1)
> Oct 27 08:15:19 puar kernel: [26080.447988] rcu_sched kthread starved
> for 9226 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> Oct 27 08:15:19 puar kernel: [26080.447993] rcu_sched       S
> Oct 27 08:15:19 puar kernel: [26080.448001]     0     7      2 0x00000000
> Oct 27 08:15:19 puar kernel: 00000000
> Oct 27 08:15:19 puar kernel: [26080.448012]  f300a100 f68b8800
> f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280 0051bec4
> Oct 27 08:15:19 puar kernel: [26080.448041]  f7518db8 c7767680
> f300a100 f79deac0 f75189c0 f751bee0 f75189c0 f79d8900
> Oct 27 08:15:19 puar kernel: [26080.448069]  f751bf00 f751bee0
> c75aa3ae f79d8900 f751bf28 c75ad08f 00000002Call Trace:
> Oct 27 08:15:19 puar kernel: [26080.448126]  [<c75a9e7e>] ?
> __schedule+0x25e/0x760
> Oct 27 08:15:19 puar kernel: [26080.448144]  [<c70d4cd7>] ?
> lock_timer_base+0x67/0x80
> Oct 27 08:15:19 puar kernel: [26080.448158]  [<c75aa3ae>] ? schedule+0x2e/0x80
> Oct 27 08:15:19 puar kernel: [26080.448172]  [<c75ad08f>] ?
> schedule_timeout+0x12f/0x300
> Oct 27 08:15:19 puar kernel: [26080.448186]  [<c70d5d40>] ?
> del_timer_sync+0x50/0x50
> Oct 27 08:15:19 puar kernel: [26080.448199]  [<c70d0651>] ?
> rcu_gp_kthread+0x4a1/0x7c0
> Oct 27 08:15:19 puar kernel: [26080.448214]  [<c7084314>] ? kthread+0xb4/0xd0
> Oct 27 08:15:19 puar kernel: [26080.448225]  [<c70d01b0>] ?
> rcu_note_context_switch+0xf0/0xf0
> Oct 27 08:15:19 puar kernel: [26080.448237]  [<c7084260>] ?
> kthread_park+0x50/0x50
> Oct 27 08:15:19 puar kernel: [26080.448248]  [<c75ae643>] ?
> ret_from_fork+0x1b/0x28
> Oct 27 08:15:19 puar kernel: [26080.448299] Task dump for CPU 0:
> Oct 27 08:15:19 puar kernel: [26080.448307] swapper/0       R
> Oct 27 08:15:19 puar kernel: [26080.448310]   running task        0
>  0      0 0x00000000
> Oct 27 08:15:19 puar kernel: c77c55f0
> Oct 27 08:15:19 puar kernel: [26080.448327]  c7761fbc 00000000
> c776007b bc31007b 000000d8 c77c00e0 ffffff5e c7480944
> Oct 27 08:15:19 puar kernel: [26080.448355]  00000060 00000246
> 00001667 bc2ca3cb 000017af 00000000 c77c54a0 00000004
> Oct 27 08:15:19 puar kernel: [26080.448382]  ff9d7fe0 bc314afc
> 000017af 00000000 ff9d7fe0 c77c54a0 c7761fe4Call Trace:
> Oct 27 08:15:19 puar kernel: [26080.448435]  [<c7480944>] ?
> cpuidle_enter_state+0x134/0x330
> Oct 27 08:15:19 puar kernel: [26080.448451]  [<c70a9355>] ?
> cpu_startup_entry+0x135/0x220
> Oct 27 08:15:19 puar kernel: [26080.448467]  [<c7803b53>] ?
> start_kernel+0x39d/0x3b4
> Oct 27 08:15:19 puar kernel: [26080.448473] Task dump for CPU 1:
> Oct 27 08:15:19 puar kernel: [26080.448478] swapper/1       R
> Oct 27 08:15:19 puar kernel: [26080.448481]   running task        0
>  0      1 0x00000008
> Oct 27 08:15:19 puar kernel: f7527dcc
> Oct 27 08:15:19 puar kernel: [26080.448495]  c7091941 c76b35df
> 00000000 00000000 00000001 00000008 c7782140 c7782140
> Oct 27 08:15:19 puar kernel: [26080.448522]  00000001 f7527de4
> c7166884 00000087 f79f3300 c7782140 c7782140 f7527e30
> Oct 27 08:15:19 puar kernel: [26080.448550]  c70d20e1 c76a9ed0
> 0000240a 00076fa6 00076fa5 00000001 603ea661Call Trace:
> Oct 27 08:15:19 puar kernel: [26080.448593]  [<c7091941>] ?
> sched_show_task+0xf1/0x160
> Oct 27 08:15:19 puar kernel: [26080.448612]  [<c7166884>] ?
> rcu_dump_cpu_stacks+0x79/0x95
> Oct 27 08:15:19 puar kernel: [26080.448633]  [<c70d20e1>] ?
> rcu_check_callbacks+0x631/0x780
> Oct 27 08:15:19 puar kernel: [26080.448652]  [<c70d7748>] ?
> update_process_times+0x28/0x50
> Oct 27 08:15:19 puar kernel: [26080.448665]  [<c70e8c86>] ?
> tick_sched_handle.isra.11+0x26/0x60
> Oct 27 08:15:19 puar kernel: [26080.448675]  [<c70e8cfa>] ?
> tick_sched_timer+0x3a/0x80
> Oct 27 08:15:19 puar kernel: [26080.448688]  [<c70d81df>] ?
> __remove_hrtimer+0x3f/0x80
> Oct 27 08:15:19 puar kernel: [26080.448700]  [<c70d8400>] ?
> __hrtimer_run_queues+0xc0/0x260
> Oct 27 08:15:19 puar kernel: [26080.448712]  [<c70e8cc0>] ?
> tick_sched_handle.isra.11+0x60/0x60
> Oct 27 08:15:19 puar kernel: [26080.448725]  [<c70d8c23>] ?
> hrtimer_interrupt+0x93/0x1a0
> Oct 27 08:15:19 puar kernel: [26080.448742]  [<c75afa63>] ?
> smp_apic_timer_interrupt+0x33/0x50
> Oct 27 08:15:19 puar kernel: [26080.448753]  [<c75af178>] ?
> apic_timer_interrupt+0x34/0x3c
> Oct 27 08:15:19 puar kernel: [26080.448772]  [<c7480944>] ?
> cpuidle_enter_state+0x134/0x330
> Oct 27 08:15:19 puar kernel: [26080.448787]  [<c70a9355>] ?
> cpu_startup_entry+0x135/0x220
> Oct 27 08:15:19 puar kernel: [26080.448801]  [<c70450f5>] ?
> start_secondary+0x155/0x1b0
> Oct 27 08:15:19 puar kernel: [26080.449772]     0-...: (1 ticks this
> GP) idle=3e1/2/0 softirq=1245237/1245237 fqs=0
> Oct 27 08:15:19 puar kernel: [26080.450190]      (t=9227 jiffies
> g=487334 c=487333 q=3)
> Oct 27 08:15:19 puar kernel: [26080.450514] rcu_sched kthread starved
> for 9227 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0
> Oct 27 08:15:19 puar kernel: [26080.451087] rcu_sched       R  running
> task        0     7      2 0x00000000
> Oct 27 08:15:19 puar kernel: [26080.451109]  00000000 f300a100
> f68b8800 f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280
> Oct 27 08:15:19 puar kernel: [26080.451143]  0051bec4 f7518db8
> c7767680 f300a100 f79deac0 f75189c0 f751bee0 f75189c0
> Oct 27 08:15:19 puar kernel: [26080.451175]  f79d8900 f79d8900
> f751bee0 c70d5d39 f79ec900 f751bf28 c75ad08f c7782140
> Oct 27 08:15:19 puar kernel: [26080.451205] Call Trace:
> Oct 27 08:15:19 puar kernel: [26080.451240]  [<c75a9e7e>] ?
> __schedule+0x25e/0x760
> Oct 27 08:15:19 puar kernel: [26080.451257]  [<c70d4cd7>] ?
> lock_timer_base+0x67/0x80
> Oct 27 08:15:19 puar kernel: [26080.451271]  [<c75aa3ae>] ? schedule+0x2e/0x80
> Oct 27 08:15:19 puar kernel: [26080.451285]  [<c75ad08f>] ?
> schedule_timeout+0x12f/0x300
> Oct 27 08:15:19 puar kernel: [26080.451298]  [<c70d5d40>] ?
> del_timer_sync+0x50/0x50
> Oct 27 08:15:19 puar kernel: [26080.451311]  [<c70d0651>] ?
> rcu_gp_kthread+0x4a1/0x7c0
> Oct 27 08:15:19 puar kernel: [26080.451326]  [<c7084314>] ? kthread+0xb4/0xd0
> Oct 27 08:15:19 puar kernel: [26080.451337]  [<c70d01b0>] ?
> rcu_note_context_switch+0xf0/0xf0
> Oct 27 08:15:19 puar kernel: [26080.451349]  [<c7084260>] ?
> kthread_park+0x50/0x50
> Oct 27 08:15:19 puar kernel: [26080.451360]  [<c75ae643>] ?
> ret_from_fork+0x1b/0x28
> Oct 27 08:15:19 puar kernel: [26080.451399] Task dump for CPU 0:
> Oct 27 08:15:19 puar kernel: [26080.451404] swapper/0       R  running
> task        0     0      0 0x00000008
> Oct 27 08:15:19 puar kernel: [26080.451419]  f742fe54 c7091941
> c76b35df 00000000 00000000 00000000 00000008 c7782140
> Oct 27 08:15:19 puar kernel: [26080.451446]  c7782140 00000000
> f742fe6c c7166884 00000087 f79df300 c7782140 c7782140
> Oct 27 08:15:19 puar kernel: [26080.451473]  f742feb8 c70d20e1
> c76a9ed0 0000240b 00076fa6 00076fa5 00000003 f79deac0
> Oct 27 08:15:19 puar kernel: [26080.451500] Call Trace:
> Oct 27 08:15:19 puar kernel: [26080.451506]  <IRQ>
> Oct 27 08:15:19 puar kernel: [26080.451525]  [<c7091941>] ?
> sched_show_task+0xf1/0x160
> Oct 27 08:15:19 puar kernel: [26080.451543]  [<c7166884>] ?
> rcu_dump_cpu_stacks+0x79/0x95
> Oct 27 08:15:19 puar kernel: [26080.451555]  [<c70d20e1>] ?
> rcu_check_callbacks+0x631/0x780
> Oct 27 08:15:19 puar kernel: [26080.451569]  [<c7094f7a>] ?
> account_process_tick+0x5a/0x150
> Oct 27 08:15:19 puar kernel: [26080.451583]  [<c70d7748>] ?
> update_process_times+0x28/0x50
> Oct 27 08:15:19 puar kernel: [26080.451596]  [<c70e8c86>] ?
> tick_sched_handle.isra.11+0x26/0x60
> Oct 27 08:15:19 puar kernel: [26080.451606]  [<c70e8cfa>] ?
> tick_sched_timer+0x3a/0x80
> Oct 27 08:15:19 puar kernel: [26080.451618]  [<c70d81df>] ?
> __remove_hrtimer+0x3f/0x80
> Oct 27 08:15:19 puar kernel: [26080.451631]  [<c70d8400>] ?
> __hrtimer_run_queues+0xc0/0x260
> Oct 27 08:15:19 puar kernel: [26080.451642]  [<c70e8cc0>] ?
> tick_sched_handle.isra.11+0x60/0x60
> Oct 27 08:15:19 puar kernel: [26080.451656]  [<c70d8c23>] ?
> hrtimer_interrupt+0x93/0x1a0
> Oct 27 08:15:19 puar kernel: [26080.451671]  [<c7024d02>] ?
> timer_interrupt+0x12/0x20
> Oct 27 08:15:19 puar kernel: [26080.451687]  [<c70c4ba8>] ?
> __handle_irq_event_percpu+0x78/0x190
> Oct 27 08:15:19 puar kernel: [26080.451700]  [<c70c4ceb>] ?
> handle_irq_event_percpu+0x2b/0x70
> Oct 27 08:15:19 puar kernel: [26080.451713]  [<c70c4d5f>] ?
> handle_irq_event+0x2f/0x50
> Oct 27 08:15:19 puar kernel: [26080.451724]  [<c70c810d>] ?
> handle_edge_irq+0x6d/0x120
> Oct 27 08:15:19 puar kernel: [26080.451735]  [<c70c80a0>] ?
> handle_level_irq+0xe0/0xe0
> Oct 27 08:15:19 puar kernel: [26080.451745]  [<c7024844>] ? handle_irq+0x54/0x70
> Oct 27 08:15:19 puar kernel: [26080.451749]  <EOI>
> Oct 27 08:15:19 puar kernel: [26080.451754]  <IRQ>
> Oct 27 08:15:19 puar kernel: [26080.451767]  [<c75af9ac>] ? do_IRQ+0x3c/0xc0
> Oct 27 08:15:19 puar kernel: [26080.451779]  [<c70a8d25>] ?
> swake_up_locked+0x25/0x30
> Oct 27 08:15:19 puar kernel: [26080.451790]  [<c75aee73>] ?
> common_interrupt+0x33/0x38
> Oct 27 08:15:19 puar kernel: [26080.451803]  [<c75afb98>] ?
> __do_softirq+0x58/0x240
> Oct 27 08:15:19 puar kernel: [26080.451817]  [<c75afb40>] ?
> __irqentry_text_end+0x3/0x3
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c70247e8>] ?
> do_softirq_own_stack+0x28/0x30
> Oct 27 08:15:19 puar kernel: [26080.451828]  <EOI>
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c706cc9d>] ? irq_exit+0xad/0xb0
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75af9b5>] ? do_IRQ+0x45/0xc0
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75aee73>] ?
> common_interrupt+0x33/0x38
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7480944>] ?
> cpuidle_enter_state+0x134/0x330
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c70a9355>] ?
> cpu_startup_entry+0x135/0x220
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7803b53>] ?
> start_kernel+0x39d/0x3b4
> Oct 27 08:15:19 puar kernel: [26080.451828] Task dump for CPU 1:
> Oct 27 08:15:19 puar kernel: [26080.451828] kworker/1:1     R  running
> task        0 11974      2 0x00000000
> Oct 27 08:15:19 puar kernel: [26080.451828] Workqueue: events
> output_poll_execute [drm_kms_helper]
> Oct 27 08:15:19 puar kernel: [26080.451828]  f90bf4e0 f690ca7c
> f690c94c 0000001f f690ca7c f6cd0d80 f79f2640 f31c5f38
> Oct 27 08:15:19 puar kernel: [26080.451828]  c707ee21 f750cd78
> f79f2ac0 f7520a00 f79f2ac0 f750c980 00000000 f79f8100
> Oct 27 08:15:19 puar kernel: [26080.451828]  00000000 f79f2640
> f6cd0d98 f6cd0d80 f79f2640 f31c5f64 c707f0a1 f79f2ac0
> Oct 27 08:15:19 puar kernel: [26080.451828] Call Trace:
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707ee21>] ?
> process_one_work+0x141/0x380
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707f0a1>] ?
> worker_thread+0x41/0x460
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7084314>] ? kthread+0xb4/0xd0
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707f060>] ?
> process_one_work+0x380/0x380
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7084260>] ?
> kthread_park+0x50/0x50
> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75ae643>] ?
> ret_from_fork+0x1b/0x28
>
>
> --
> Jiann-Ming Su
> "I have to decide between two equally frightening options.
>  If I wanted to do that, I'd vote." --Duckman
> "The system's broke, Hank.  The election baby has peed in
> the bath water.  You got to throw 'em both out."  --Dale Gribble
> "Those who vote decide nothing.
> Those who count the votes decide everything.”  --Joseph Stalin



-- 
Jiann-Ming Su
"I have to decide between two equally frightening options.
 If I wanted to do that, I'd vote." --Duckman
"The system's broke, Hank.  The election baby has peed in
the bath water.  You got to throw 'em both out."  --Dale Gribble
"Those who vote decide nothing.
Those who count the votes decide everything.”  --Joseph Stalin

[toc] | [prev] | [next] | [standalone]

#59450 — Bug#822936: Occurs on Stretch

FromJiann-Ming Su <sujiannming@gmail.com>
Date2017-11-21 17:30 +0100
SubjectBug#822936: Occurs on Stretch
Message-ID<uOjAS-4PT-11@gated-at.bofh.it>
In reply to#59359
[814247.295392] INFO: rcu_sched self-detected stall on CPU
[814247.295421] INFO: rcu_sched detected stalls on CPUs/tasks:
[814247.295444]     0-...: (1 ticks this GP) idle=d81/2/0
softirq=3762400/3762400 fqs=1
[814247.295448]
[814247.295456] (detected by 1, t=27866 jiffies, g=2973706, c=2973705, q=0)
[814247.295461] Task dump for CPU 0:
[814247.295466] swapper/0       R
[814247.295469]   running task
[814247.295476]     0     0      0 0x00000008
[814247.295483]  da7c55f0
[814247.295487]  da761fbc
[814247.295491]  00000000
[814247.295494]  da76007b
[814247.295497]  c58b007b
[814247.295501]  000200d8
[814247.295504]  da7c00e0
[814247.295507]  ffffff5e
[814247.295512]  da480944
[814247.295516]  00000060
[814247.295519]  00200246
[814247.295522]  0000a575
[814247.295526]  c58a7700
[814247.295529]  0002e473
[814247.295532]  00000000
[814247.295535]  da7c54a0
[814247.295540]  00000004
[814247.295543]  ff9d7fe0
[814247.295547]  c58bc430
[814247.295550]  0002e473
[814247.295553]  00000000
[814247.295556]  ff9d7fe0
[814247.295559]  da7c54a0
[814247.295563]  da761fe4
[814247.295568] Call Trace:
[814247.295605]  [<da480944>] ? cpuidle_enter_state+0x134/0x330
[814247.295623]  [<da0a9355>] ? cpu_startup_entry+0x135/0x220
[814247.295640]  [<da803b53>] ? start_kernel+0x39d/0x3b4
[814247.295656] rcu_sched kthread starved for 27864 jiffies! g2973706
c2973705 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
[814247.295661] rcu_sched       S
[814247.295668]     0     7      2 0x00000000
[814247.295673]  00000000
[814247.295677]  f79f2ac0
[814247.295680]  f65c8c00
[814247.295684]  f751bed4
[814247.295687]  da5a9e7e
[814247.295690]  f751bebc
[814247.295694]  da0d4cd7
[814247.295697]  da8b8280
[814247.295702]  0051bec4
[814247.295706]  f7518db8
[814247.295709]  f7520a00
[814247.295712]  f7520a00
[814247.295715]  f79f2ac0
[814247.295719]  f75189c0
[814247.295722]  f751bee0
[814247.295726]  f75189c0
[814247.295731]  f79ec900
[814247.295734]  f751bf00
[814247.295737]  f751bee0
[814247.295741]  da5aa3ae
[814247.295744]  f79ec900
[814247.295747]  f751bf28
[814247.295750]  da5ad08f
[814247.295763]  da782140
[814247.295767] Call Trace:
[814247.295788]  [<da5a9e7e>] ? __schedule+0x25e/0x760
[814247.295805]  [<da0d4cd7>] ? lock_timer_base+0x67/0x80
[814247.295818]  [<da5aa3ae>] ? schedule+0x2e/0x80
[814247.295832]  [<da5ad08f>] ? schedule_timeout+0x12f/0x300
[814247.295846]  [<da0d5d40>] ? del_timer_sync+0x50/0x50
[814247.295858]  [<da0d0651>] ? rcu_gp_kthread+0x4a1/0x7c0
[814247.295873]  [<da084314>] ? kthread+0xb4/0xd0
[814247.295884]  [<da0d01b0>] ? rcu_note_context_switch+0xf0/0xf0
[814247.295896]  [<da084260>] ? kthread_park+0x50/0x50
[814247.295908]  [<da5ae643>] ? ret_from_fork+0x1b/0x28
[814247.297335]     0-...: (1 ticks this GP) idle=d81/2/0
softirq=3762400/3762400 fqs=1
[814247.297772]      (t=27867 jiffies g=2973706 c=2973705 q=2)
[814247.298125] rcu_sched kthread starved for 27865 jiffies! g2973706
c2973705 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0
[814247.298718] rcu_sched       R  running task        0     7      2 0x00000000
[814247.298741]  00000000 f79f2ac0 f65c8c00 f751bed4 da5a9e7e f751bebc
da0d4cd7 da8b8280
[814247.298774]  0051bec4 f7518db8 f7520a00 f7520a00 f79f2ac0 f75189c0
f751bee0 f75189c0
[814247.298805]  f79ec900 f751bf00 f751bee0 da5aa3ae f79ec900 f751bf28
da5ad08f da782140
[814247.298835] Call Trace:
[814247.298871]  [<da5a9e7e>] ? __schedule+0x25e/0x760
[814247.298893]  [<da0d4cd7>] ? lock_timer_base+0x67/0x80
[814247.298909]  [<da5aa3ae>] ? schedule+0x2e/0x80
[814247.298924]  [<da5ad08f>] ? schedule_timeout+0x12f/0x300
[814247.298941]  [<da0d5d40>] ? del_timer_sync+0x50/0x50
[814247.298957]  [<da0d0651>] ? rcu_gp_kthread+0x4a1/0x7c0
[814247.298976]  [<da084314>] ? kthread+0xb4/0xd0
[814247.298990]  [<da0d01b0>] ? rcu_note_context_switch+0xf0/0xf0
[814247.299005]  [<da084260>] ? kthread_park+0x50/0x50
[814247.299019]  [<da5ae643>] ? ret_from_fork+0x1b/0x28
[814247.299030] Task dump for CPU 0:
[814247.299037] swapper/0       R  running task        0     0      0 0x00000008
[814247.299054]  f742fe54 da091941 da6b35df 00000000 00000000 00000000
00000008 da782140
[814247.299082]  da782140 00000000 f742fe6c da166884 00200087 f79df300
da782140 da782140
[814247.299112]  f742feb8 da0d20e1 da6a9ed0 00006cdb 002d600a 002d6009
00000002 f79deac0
[814247.299142] Call Trace:
[814247.299150]  <IRQ>
[814247.299172]  [<da091941>] ? sched_show_task+0xf1/0x160
[814247.299186]  [<da166884>] ? rcu_dump_cpu_stacks+0x79/0x95
[814247.299186]  [<da0d20e1>] ? rcu_check_callbacks+0x631/0x780
[814247.299186]  [<da094f7a>] ? account_process_tick+0x5a/0x150
[814247.299186]  [<da0d7748>] ? update_process_times+0x28/0x50
[814247.299186]  [<da0e8c86>] ? tick_sched_handle.isra.11+0x26/0x60
[814247.299186]  [<da0e8cfa>] ? tick_sched_timer+0x3a/0x80
[814247.299186]  [<da0d81df>] ? __remove_hrtimer+0x3f/0x80
[814247.299186]  [<da0d8400>] ? __hrtimer_run_queues+0xc0/0x260
[814247.299186]  [<da0e8cc0>] ? tick_sched_handle.isra.11+0x60/0x60
[814247.299186]  [<da0d8c23>] ? hrtimer_interrupt+0x93/0x1a0
[814247.299186]  [<da024d02>] ? timer_interrupt+0x12/0x20
[814247.299186]  [<da0c4ba8>] ? __handle_irq_event_percpu+0x78/0x190
[814247.299186]  [<da0c4ceb>] ? handle_irq_event_percpu+0x2b/0x70
[814247.299186]  [<da0c4d5f>] ? handle_irq_event+0x2f/0x50
[814247.299186]  [<da0c810d>] ? handle_edge_irq+0x6d/0x120
[814247.299186]  [<da0c80a0>] ? handle_level_irq+0xe0/0xe0
[814247.299186]  [<da024844>] ? handle_irq+0x54/0x70
[814247.299186]  <EOI>
[814247.299186]  <IRQ>
[814247.299186]  [<da5af9ac>] ? do_IRQ+0x3c/0xc0
[814247.299186]  [<da146a6d>] ? irq_work_run_list+0x3d/0x60
[814247.299186]  [<da5aee73>] ? common_interrupt+0x33/0x38
[814247.299186]  [<da5afb98>] ? __do_softirq+0x58/0x240
[814247.299186]  [<da5afb40>] ? __irqentry_text_end+0x3/0x3
[814247.299186]  [<da5af87f>] ? nmi+0x53/0x6d
[814247.299186]  [<da5afb40>] ? __irqentry_text_end+0x3/0x3
[814247.299186]  [<da0247e8>] ? do_softirq_own_stack+0x28/0x30
[814247.299186]  <EOI>
[814247.299186]  [<da06cc9d>] ? irq_exit+0xad/0xb0
[814247.299186]  [<da5af9b5>] ? do_IRQ+0x45/0xc0
[814247.299186]  [<da5aee73>] ? common_interrupt+0x33/0x38
[814247.299186]  [<da480944>] ? cpuidle_enter_state+0x134/0x330
[814247.299186]  [<da0a9355>] ? cpu_startup_entry+0x135/0x220
[814247.299186]  [<da803b53>] ? start_kernel+0x39d/0x3b4

On Sun, Nov 5, 2017 at 9:52 PM, Jiann-Ming Su <sujiannming@gmail.com> wrote:
> # uname -v
> #1 SMP Debian 4.9.51-1 (2017-09-28)
>
> [256204.725417] INFO: rcu_sched self-detected stall on CPU
> [256204.725450] INFO: rcu_sched detected stalls on CPUs/tasks:
> [256204.725473]     0-...: (2 GPs behind) idle=52b/2/0
> softirq=1717403/1717404 fqs=0
> [256204.725477]
> [256204.725485] (detected by 1, t=18640 jiffies, g=600410, c=600409, q=1)
> [256204.725490] Task dump for CPU 0:
> [256204.725495] swapper/0       R
> [256204.725498]   running task
> [256204.725505]     0     0      0 0x00000008
> [256204.725512]  d07c55f0
> [256204.725517]  d0761fbc
> [256204.725520]  00000000
> [256204.725523]  d076007b
> [256204.725527]  f3ec007b
> [256204.725530]  000000d8
> [256204.725533]  d07c00e0
> [256204.725537]  ffffff5e
> [256204.725542]  d0480944
> [256204.725545]  00000060
> [256204.725548]  00200246
> [256204.725552]  000ad6bb
> [256204.725555]  f3ea7231
> [256204.725558]  0000e8f2
> [256204.725561]  00000000
> [256204.725565]  d07c54a0
> [256204.725570]  00000004
> [256204.725573]  ff9d7fe0
> [256204.725576]  f3ec141f
> [256204.725580]  0000e8f2
> [256204.725583]  00000000
> [256204.725586]  ff9d7fe0
> [256204.725589]  d07c54a0
> [256204.725593]  d0761fe4
> [256204.725598] Call Trace:
> [256204.725653]  [<d0480944>] ? cpuidle_enter_state+0x134/0x330
> [256204.725673]  [<d00a9355>] ? cpu_startup_entry+0x135/0x220
> [256204.725685]  [<d0803b53>] ? start_kernel+0x39d/0x3b4
> [256204.725696] rcu_sched kthread starved for 18640 jiffies! g600410
> c600409 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> [256204.725701] rcu_sched       S
> [256204.725705]     0     7      2 0x00000000
> [256204.725709]  00000000
> [256204.725711]  f79f2ac0
> [256204.725713]  f6c9be00
> [256204.725715]  f751bed4
> [256204.725717]  d05a9e7e
> [256204.725719]  f751bebc
> [256204.725727]  d00d4cd7
> [256204.725729]  d08b8280
> [256204.725732]  0051bec4
> [256204.725734]  f7518db8
> [256204.725736]  f7520a00
> [256204.725737]  f7520a00
> [256204.725739]  f79f2ac0
> [256204.725741]  f75189c0
> [256204.725744]  f751bee0
> [256204.725746]  f75189c0
> [256204.725749]  f79ec900
> [256204.725750]  f751bf00
> [256204.725752]  f751bee0
> [256204.725754]  d05aa3ae
> [256204.725756]  f79ec900
> [256204.725758]  f751bf28
> [256204.725760]  d05ad08f
> [256204.725762]  00000002
> [256204.725765] Call Trace:
> [256204.725779]  [<d05a9e7e>] ? __schedule+0x25e/0x760
> [256204.725790]  [<d00d4cd7>] ? lock_timer_base+0x67/0x80
> [256204.725798]  [<d05aa3ae>] ? schedule+0x2e/0x80
> [256204.725807]  [<d05ad08f>] ? schedule_timeout+0x12f/0x300
> [256204.725815]  [<d00d5d40>] ? del_timer_sync+0x50/0x50
> [256204.725823]  [<d00d0651>] ? rcu_gp_kthread+0x4a1/0x7c0
> [256204.725833]  [<d0084314>] ? kthread+0xb4/0xd0
> [256204.725839]  [<d00d01b0>] ? rcu_note_context_switch+0xf0/0xf0
> [256204.725847]  [<d0084260>] ? kthread_park+0x50/0x50
> [256204.725854]  [<d05ae643>] ? ret_from_fork+0x1b/0x28
> [256204.726675]     0-...: (2 GPs behind) idle=52b/2/0
> softirq=1717403/1717404 fqs=0
> [256204.726951]      (t=18640 jiffies g=600410 c=600409 q=1)
> [256204.727207] rcu_sched kthread starved for 18640 jiffies! g600410
> c600409 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0
> [256204.727557] rcu_sched       R  running task        0     7      2 0x00000000
> [256204.727579]  00000000 f79f2ac0 f6c9be00 f751bed4 d05a9e7e f751bebc
> d00d4cd7 d08b8280
> [256204.727599]  0051bec4 f7518db8 f7520a00 f7520a00 f79f2ac0 f75189c0
> f751bee0 f75189c0
> [256204.727618]  f79ec900 f751bf00 f751bee0 d05aa3ae f79ec900 f751bf28
> d05ad08f 00000002
> [256204.727638] Call Trace:
> [256204.727667]  [<d05a9e7e>] ? __schedule+0x25e/0x760
> [256204.727681]  [<d00d4cd7>] ? lock_timer_base+0x67/0x80
> [256204.727693]  [<d05aa3ae>] ? schedule+0x2e/0x80
> [256204.727704]  [<d05ad08f>] ? schedule_timeout+0x12f/0x300
> [256204.727714]  [<d00d5d40>] ? del_timer_sync+0x50/0x50
> [256204.727722]  [<d00d0651>] ? rcu_gp_kthread+0x4a1/0x7c0
> [256204.727733]  [<d0084314>] ? kthread+0xb4/0xd0
> [256204.727741]  [<d00d01b0>] ? rcu_note_context_switch+0xf0/0xf0
> [256204.727750]  [<d0084260>] ? kthread_park+0x50/0x50
> [256204.727758]  [<d05ae643>] ? ret_from_fork+0x1b/0x28
> [256204.727769] Task dump for CPU 0:
> [256204.727774] swapper/0       R  running task        0     0      0 0x00000008
> [256204.727784]  f742fe54 d0091941 d06b35df 00000000 00000000 00000000
> 00000008 d0782140
> [256204.727802]  d0782140 00000000 f742fe6c d0166884 00200087 f79df300
> d0782140 d0782140
> [256204.727820]  f742feb8 d00d20e1 d06a9ed0 000048d0 0009295a 00092959
> 00000001 f79deac0
> [256204.727839] Call Trace:
> [256204.727848]  <IRQ>
> [256204.727872]  [<d0091941>] ? sched_show_task+0xf1/0x160
> [256204.727892]  [<d0166884>] ? rcu_dump_cpu_stacks+0x79/0x95
> [256204.727908]  [<d00d20e1>] ? rcu_check_callbacks+0x631/0x780
> [256204.727922]  [<d0094f7a>] ? account_process_tick+0x5a/0x150
> [256204.727937]  [<d00d7748>] ? update_process_times+0x28/0x50
> [256204.727949]  [<d00e8c86>] ? tick_sched_handle.isra.11+0x26/0x60
> [256204.727956]  [<d00e8cfa>] ? tick_sched_timer+0x3a/0x80
> [256204.727965]  [<d00d81df>] ? __remove_hrtimer+0x3f/0x80
> [256204.727976]  [<d00d8400>] ? __hrtimer_run_queues+0xc0/0x260
> [256204.727987]  [<d00e8cc0>] ? tick_sched_handle.isra.11+0x60/0x60
> [256204.727999]  [<d00d8c23>] ? hrtimer_interrupt+0x93/0x1a0
> [256204.728012]  [<d0024d02>] ? timer_interrupt+0x12/0x20
> [256204.728024]  [<d00c4ba8>] ? __handle_irq_event_percpu+0x78/0x190
> [256204.728034]  [<d00c4ceb>] ? handle_irq_event_percpu+0x2b/0x70
> [256204.728041]  [<d00c4d5f>] ? handle_irq_event+0x2f/0x50
> [256204.728049]  [<d00c810d>] ? handle_edge_irq+0x6d/0x120
> [256204.728057]  [<d00c80a0>] ? handle_level_irq+0xe0/0xe0
> [256204.728063]  [<d0024844>] ? handle_irq+0x54/0x70
> [256204.728067]  <EOI>
> [256204.728072]  <IRQ>
> [256204.728084]  [<d05af9ac>] ? do_IRQ+0x3c/0xc0
> [256204.728099]  [<d0146a6d>] ? irq_work_run_list+0x3d/0x60
> [256204.728109]  [<d05aee73>] ? common_interrupt+0x33/0x38
> [256204.728119]  [<d00600e0>] ? pre+0x150/0x270
> [256204.728127]  [<d05afb98>] ? __do_softirq+0x58/0x240
> [256204.728135]  [<d05afb40>] ? __irqentry_text_end+0x3/0x3
> [256204.728143]  [<d05af87f>] ? nmi+0x53/0x6d
> [256204.728153]  [<d05afb40>] ? __irqentry_text_end+0x3/0x3
> [256204.728162]  [<d00247e8>] ? do_softirq_own_stack+0x28/0x30
> [256204.728165]  <EOI>
> [256204.728175]  [<d006cc9d>] ? irq_exit+0xad/0xb0
> [256204.728183]  [<d05af9b5>] ? do_IRQ+0x45/0xc0
> [256204.728192]  [<d05aee73>] ? common_interrupt+0x33/0x38
> [256204.728206]  [<d0480944>] ? cpuidle_enter_state+0x134/0x330
> [256204.728218]  [<d00a9355>] ? cpu_startup_entry+0x135/0x220
> [256204.728228]  [<d0803b53>] ? start_kernel+0x39d/0x3b4
>
> On Sat, Oct 28, 2017 at 10:44 PM, Jiann-Ming Su <sujiannming@gmail.com> wrote:
>> linux-image-4.9.0-4-686-pae      4.9.51-1
>>
>> Oct 27 08:15:19 puar kernel: [26080.447922] INFO: rcu_sched
>> self-detected stall on CPU
>> Oct 27 08:15:19 puar kernel: [26080.447946] INFO: rcu_sched
>> self-detected stall on CPU
>> Oct 27 08:15:19 puar kernel: [26080.447964]     1-...: (1 GPs behind)
>> idle=c41/1/0 softirq=1143278/1143279 fqs=0
>> Oct 27 08:15:19 puar kernel: [26080.447968]
>> Oct 27 08:15:19 puar kernel: [26080.447976]  (t=9226 jiffies g=487334
>> c=487333 q=1)
>> Oct 27 08:15:19 puar kernel: [26080.447988] rcu_sched kthread starved
>> for 9226 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
>> Oct 27 08:15:19 puar kernel: [26080.447993] rcu_sched       S
>> Oct 27 08:15:19 puar kernel: [26080.448001]     0     7      2 0x0000000
0
>> Oct 27 08:15:19 puar kernel: 00000000
>> Oct 27 08:15:19 puar kernel: [26080.448012]  f300a100 f68b8800
>> f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280 0051bec4
>> Oct 27 08:15:19 puar kernel: [26080.448041]  f7518db8 c7767680
>> f300a100 f79deac0 f75189c0 f751bee0 f75189c0 f79d8900
>> Oct 27 08:15:19 puar kernel: [26080.448069]  f751bf00 f751bee0
>> c75aa3ae f79d8900 f751bf28 c75ad08f 00000002Call Trace:
>> Oct 27 08:15:19 puar kernel: [26080.448126]  [<c75a9e7e>] ?
>> __schedule+0x25e/0x760
>> Oct 27 08:15:19 puar kernel: [26080.448144]  [<c70d4cd7>] ?
>> lock_timer_base+0x67/0x80
>> Oct 27 08:15:19 puar kernel: [26080.448158]  [<c75aa3ae>] ? schedule+0x2e/0x80
>> Oct 27 08:15:19 puar kernel: [26080.448172]  [<c75ad08f>] ?
>> schedule_timeout+0x12f/0x300
>> Oct 27 08:15:19 puar kernel: [26080.448186]  [<c70d5d40>] ?
>> del_timer_sync+0x50/0x50
>> Oct 27 08:15:19 puar kernel: [26080.448199]  [<c70d0651>] ?
>> rcu_gp_kthread+0x4a1/0x7c0
>> Oct 27 08:15:19 puar kernel: [26080.448214]  [<c7084314>] ? kthread+0xb4/0xd0
>> Oct 27 08:15:19 puar kernel: [26080.448225]  [<c70d01b0>] ?
>> rcu_note_context_switch+0xf0/0xf0
>> Oct 27 08:15:19 puar kernel: [26080.448237]  [<c7084260>] ?
>> kthread_park+0x50/0x50
>> Oct 27 08:15:19 puar kernel: [26080.448248]  [<c75ae643>] ?
>> ret_from_fork+0x1b/0x28
>> Oct 27 08:15:19 puar kernel: [26080.448299] Task dump for CPU 0:
>> Oct 27 08:15:19 puar kernel: [26080.448307] swapper/0       R
>> Oct 27 08:15:19 puar kernel: [26080.448310]   running task        0
>>  0      0 0x00000000
>> Oct 27 08:15:19 puar kernel: c77c55f0
>> Oct 27 08:15:19 puar kernel: [26080.448327]  c7761fbc 00000000
>> c776007b bc31007b 000000d8 c77c00e0 ffffff5e c7480944
>> Oct 27 08:15:19 puar kernel: [26080.448355]  00000060 00000246
>> 00001667 bc2ca3cb 000017af 00000000 c77c54a0 00000004
>> Oct 27 08:15:19 puar kernel: [26080.448382]  ff9d7fe0 bc314afc
>> 000017af 00000000 ff9d7fe0 c77c54a0 c7761fe4Call Trace:
>> Oct 27 08:15:19 puar kernel: [26080.448435]  [<c7480944>] ?
>> cpuidle_enter_state+0x134/0x330
>> Oct 27 08:15:19 puar kernel: [26080.448451]  [<c70a9355>] ?
>> cpu_startup_entry+0x135/0x220
>> Oct 27 08:15:19 puar kernel: [26080.448467]  [<c7803b53>] ?
>> start_kernel+0x39d/0x3b4
>> Oct 27 08:15:19 puar kernel: [26080.448473] Task dump for CPU 1:
>> Oct 27 08:15:19 puar kernel: [26080.448478] swapper/1       R
>> Oct 27 08:15:19 puar kernel: [26080.448481]   running task        0
>>  0      1 0x00000008
>> Oct 27 08:15:19 puar kernel: f7527dcc
>> Oct 27 08:15:19 puar kernel: [26080.448495]  c7091941 c76b35df
>> 00000000 00000000 00000001 00000008 c7782140 c7782140
>> Oct 27 08:15:19 puar kernel: [26080.448522]  00000001 f7527de4
>> c7166884 00000087 f79f3300 c7782140 c7782140 f7527e30
>> Oct 27 08:15:19 puar kernel: [26080.448550]  c70d20e1 c76a9ed0
>> 0000240a 00076fa6 00076fa5 00000001 603ea661Call Trace:
>> Oct 27 08:15:19 puar kernel: [26080.448593]  [<c7091941>] ?
>> sched_show_task+0xf1/0x160
>> Oct 27 08:15:19 puar kernel: [26080.448612]  [<c7166884>] ?
>> rcu_dump_cpu_stacks+0x79/0x95
>> Oct 27 08:15:19 puar kernel: [26080.448633]  [<c70d20e1>] ?
>> rcu_check_callbacks+0x631/0x780
>> Oct 27 08:15:19 puar kernel: [26080.448652]  [<c70d7748>] ?
>> update_process_times+0x28/0x50
>> Oct 27 08:15:19 puar kernel: [26080.448665]  [<c70e8c86>] ?
>> tick_sched_handle.isra.11+0x26/0x60
>> Oct 27 08:15:19 puar kernel: [26080.448675]  [<c70e8cfa>] ?
>> tick_sched_timer+0x3a/0x80
>> Oct 27 08:15:19 puar kernel: [26080.448688]  [<c70d81df>] ?
>> __remove_hrtimer+0x3f/0x80
>> Oct 27 08:15:19 puar kernel: [26080.448700]  [<c70d8400>] ?
>> __hrtimer_run_queues+0xc0/0x260
>> Oct 27 08:15:19 puar kernel: [26080.448712]  [<c70e8cc0>] ?
>> tick_sched_handle.isra.11+0x60/0x60
>> Oct 27 08:15:19 puar kernel: [26080.448725]  [<c70d8c23>] ?
>> hrtimer_interrupt+0x93/0x1a0
>> Oct 27 08:15:19 puar kernel: [26080.448742]  [<c75afa63>] ?
>> smp_apic_timer_interrupt+0x33/0x50
>> Oct 27 08:15:19 puar kernel: [26080.448753]  [<c75af178>] ?
>> apic_timer_interrupt+0x34/0x3c
>> Oct 27 08:15:19 puar kernel: [26080.448772]  [<c7480944>] ?
>> cpuidle_enter_state+0x134/0x330
>> Oct 27 08:15:19 puar kernel: [26080.448787]  [<c70a9355>] ?
>> cpu_startup_entry+0x135/0x220
>> Oct 27 08:15:19 puar kernel: [26080.448801]  [<c70450f5>] ?
>> start_secondary+0x155/0x1b0
>> Oct 27 08:15:19 puar kernel: [26080.449772]     0-...: (1 ticks this
>> GP) idle=3e1/2/0 softirq=1245237/1245237 fqs=0
>> Oct 27 08:15:19 puar kernel: [26080.450190]      (t=9227 jiffies
>> g=487334 c=487333 q=3)
>> Oct 27 08:15:19 puar kernel: [26080.450514] rcu_sched kthread starved
>> for 9227 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0
>> Oct 27 08:15:19 puar kernel: [26080.451087] rcu_sched       R  running
>> task        0     7      2 0x00000000
>> Oct 27 08:15:19 puar kernel: [26080.451109]  00000000 f300a100
>> f68b8800 f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280
>> Oct 27 08:15:19 puar kernel: [26080.451143]  0051bec4 f7518db8
>> c7767680 f300a100 f79deac0 f75189c0 f751bee0 f75189c0
>> Oct 27 08:15:19 puar kernel: [26080.451175]  f79d8900 f79d8900
>> f751bee0 c70d5d39 f79ec900 f751bf28 c75ad08f c7782140
>> Oct 27 08:15:19 puar kernel: [26080.451205] Call Trace:
>> Oct 27 08:15:19 puar kernel: [26080.451240]  [<c75a9e7e>] ?
>> __schedule+0x25e/0x760
>> Oct 27 08:15:19 puar kernel: [26080.451257]  [<c70d4cd7>] ?
>> lock_timer_base+0x67/0x80
>> Oct 27 08:15:19 puar kernel: [26080.451271]  [<c75aa3ae>] ? schedule+0x2e/0x80
>> Oct 27 08:15:19 puar kernel: [26080.451285]  [<c75ad08f>] ?
>> schedule_timeout+0x12f/0x300
>> Oct 27 08:15:19 puar kernel: [26080.451298]  [<c70d5d40>] ?
>> del_timer_sync+0x50/0x50
>> Oct 27 08:15:19 puar kernel: [26080.451311]  [<c70d0651>] ?
>> rcu_gp_kthread+0x4a1/0x7c0
>> Oct 27 08:15:19 puar kernel: [26080.451326]  [<c7084314>] ? kthread+0xb4/0xd0
>> Oct 27 08:15:19 puar kernel: [26080.451337]  [<c70d01b0>] ?
>> rcu_note_context_switch+0xf0/0xf0
>> Oct 27 08:15:19 puar kernel: [26080.451349]  [<c7084260>] ?
>> kthread_park+0x50/0x50
>> Oct 27 08:15:19 puar kernel: [26080.451360]  [<c75ae643>] ?
>> ret_from_fork+0x1b/0x28
>> Oct 27 08:15:19 puar kernel: [26080.451399] Task dump for CPU 0:
>> Oct 27 08:15:19 puar kernel: [26080.451404] swapper/0       R  running
>> task        0     0      0 0x00000008
>> Oct 27 08:15:19 puar kernel: [26080.451419]  f742fe54 c7091941
>> c76b35df 00000000 00000000 00000000 00000008 c7782140
>> Oct 27 08:15:19 puar kernel: [26080.451446]  c7782140 00000000
>> f742fe6c c7166884 00000087 f79df300 c7782140 c7782140
>> Oct 27 08:15:19 puar kernel: [26080.451473]  f742feb8 c70d20e1
>> c76a9ed0 0000240b 00076fa6 00076fa5 00000003 f79deac0
>> Oct 27 08:15:19 puar kernel: [26080.451500] Call Trace:
>> Oct 27 08:15:19 puar kernel: [26080.451506]  <IRQ>
>> Oct 27 08:15:19 puar kernel: [26080.451525]  [<c7091941>] ?
>> sched_show_task+0xf1/0x160
>> Oct 27 08:15:19 puar kernel: [26080.451543]  [<c7166884>] ?
>> rcu_dump_cpu_stacks+0x79/0x95
>> Oct 27 08:15:19 puar kernel: [26080.451555]  [<c70d20e1>] ?
>> rcu_check_callbacks+0x631/0x780
>> Oct 27 08:15:19 puar kernel: [26080.451569]  [<c7094f7a>] ?
>> account_process_tick+0x5a/0x150
>> Oct 27 08:15:19 puar kernel: [26080.451583]  [<c70d7748>] ?
>> update_process_times+0x28/0x50
>> Oct 27 08:15:19 puar kernel: [26080.451596]  [<c70e8c86>] ?
>> tick_sched_handle.isra.11+0x26/0x60
>> Oct 27 08:15:19 puar kernel: [26080.451606]  [<c70e8cfa>] ?
>> tick_sched_timer+0x3a/0x80
>> Oct 27 08:15:19 puar kernel: [26080.451618]  [<c70d81df>] ?
>> __remove_hrtimer+0x3f/0x80
>> Oct 27 08:15:19 puar kernel: [26080.451631]  [<c70d8400>] ?
>> __hrtimer_run_queues+0xc0/0x260
>> Oct 27 08:15:19 puar kernel: [26080.451642]  [<c70e8cc0>] ?
>> tick_sched_handle.isra.11+0x60/0x60
>> Oct 27 08:15:19 puar kernel: [26080.451656]  [<c70d8c23>] ?
>> hrtimer_interrupt+0x93/0x1a0
>> Oct 27 08:15:19 puar kernel: [26080.451671]  [<c7024d02>] ?
>> timer_interrupt+0x12/0x20
>> Oct 27 08:15:19 puar kernel: [26080.451687]  [<c70c4ba8>] ?
>> __handle_irq_event_percpu+0x78/0x190
>> Oct 27 08:15:19 puar kernel: [26080.451700]  [<c70c4ceb>] ?
>> handle_irq_event_percpu+0x2b/0x70
>> Oct 27 08:15:19 puar kernel: [26080.451713]  [<c70c4d5f>] ?
>> handle_irq_event+0x2f/0x50
>> Oct 27 08:15:19 puar kernel: [26080.451724]  [<c70c810d>] ?
>> handle_edge_irq+0x6d/0x120
>> Oct 27 08:15:19 puar kernel: [26080.451735]  [<c70c80a0>] ?
>> handle_level_irq+0xe0/0xe0
>> Oct 27 08:15:19 puar kernel: [26080.451745]  [<c7024844>] ? handle_irq+0x54/0x70
>> Oct 27 08:15:19 puar kernel: [26080.451749]  <EOI>
>> Oct 27 08:15:19 puar kernel: [26080.451754]  <IRQ>
>> Oct 27 08:15:19 puar kernel: [26080.451767]  [<c75af9ac>] ? do_IRQ+0x3c/0xc0
>> Oct 27 08:15:19 puar kernel: [26080.451779]  [<c70a8d25>] ?
>> swake_up_locked+0x25/0x30
>> Oct 27 08:15:19 puar kernel: [26080.451790]  [<c75aee73>] ?
>> common_interrupt+0x33/0x38
>> Oct 27 08:15:19 puar kernel: [26080.451803]  [<c75afb98>] ?
>> __do_softirq+0x58/0x240
>> Oct 27 08:15:19 puar kernel: [26080.451817]  [<c75afb40>] ?
>> __irqentry_text_end+0x3/0x3
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c70247e8>] ?
>> do_softirq_own_stack+0x28/0x30
>> Oct 27 08:15:19 puar kernel: [26080.451828]  <EOI>
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c706cc9d>] ? irq_exit+0xad/0xb0
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75af9b5>] ? do_IRQ+0x45/0xc0
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75aee73>] ?
>> common_interrupt+0x33/0x38
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7480944>] ?
>> cpuidle_enter_state+0x134/0x330
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c70a9355>] ?
>> cpu_startup_entry+0x135/0x220
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7803b53>] ?
>> start_kernel+0x39d/0x3b4
>> Oct 27 08:15:19 puar kernel: [26080.451828] Task dump for CPU 1:
>> Oct 27 08:15:19 puar kernel: [26080.451828] kworker/1:1     R  running
>> task        0 11974      2 0x00000000
>> Oct 27 08:15:19 puar kernel: [26080.451828] Workqueue: events
>> output_poll_execute [drm_kms_helper]
>> Oct 27 08:15:19 puar kernel: [26080.451828]  f90bf4e0 f690ca7c
>> f690c94c 0000001f f690ca7c f6cd0d80 f79f2640 f31c5f38
>> Oct 27 08:15:19 puar kernel: [26080.451828]  c707ee21 f750cd78
>> f79f2ac0 f7520a00 f79f2ac0 f750c980 00000000 f79f8100
>> Oct 27 08:15:19 puar kernel: [26080.451828]  00000000 f79f2640
>> f6cd0d98 f6cd0d80 f79f2640 f31c5f64 c707f0a1 f79f2ac0
>> Oct 27 08:15:19 puar kernel: [26080.451828] Call Trace:
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707ee21>] ?
>> process_one_work+0x141/0x380
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707f0a1>] ?
>> worker_thread+0x41/0x460
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7084314>] ? kthread+0xb4/0xd0
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c707f060>] ?
>> process_one_work+0x380/0x380
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c7084260>] ?
>> kthread_park+0x50/0x50
>> Oct 27 08:15:19 puar kernel: [26080.451828]  [<c75ae643>] ?
>> ret_from_fork+0x1b/0x28
>>
>>
>> --
>> Jiann-Ming Su
>> "I have to decide between two equally frightening options.
>>  If I wanted to do that, I'd vote." --Duckman
>> "The system's broke, Hank.  The election baby has peed in
>> the bath water.  You got to throw 'em both out."  --Dale Gribble
>> "Those who vote decide nothing.
>> Those who count the votes decide everything.”  --Joseph Stalin
>
>
>
> --
> Jiann-Ming Su
> "I have to decide between two equally frightening options.
>  If I wanted to do that, I'd vote." --Duckman
> "The system's broke, Hank.  The election baby has peed in
> the bath water.  You got to throw 'em both out."  --Dale Gribble
> "Those who vote decide nothing.
> Those who count the votes decide everything.”  --Joseph Stalin



-- 
Jiann-Ming Su
"I have to decide between two equally frightening options.
 If I wanted to do that, I'd vote." --Duckman
"The system's broke, Hank.  The election baby has peed in
the bath water.  You got to throw 'em both out."  --Dale Gribble
"Those who vote decide nothing.
Those who count the votes decide everything.”  --Joseph Stalin

[toc] | [prev] | [standalone]

Back to top | Article view | linux.debian.kernel

csiph-web