Re: softlockup with 4.6.0-rc3-00130-g4d2a14c

[Balbir Singh]

On 11 May 2016 01:05, "Aneesh Kumar K.V" 
wrote:
>
>
> I am finding the below softlockups with kvm guest. This is using the
> same version of kernel for host and guest.
>
> [  323.547841] NMI watchdog: BUG: soft lockup - CPU#7 stuck for 22s!
[systemd-timesyn:3116]
> [  323.548023] Modules linked in:
> [  323.548029] CPU: 7 PID: 3116 Comm: systemd-timesyn Not tainted
4.6.0-rc3-00130-g4d2a14c #2
> [  323.548031] task: c00038b16d00 ti: c0003baac000 task.ti:
c0003baac000
> [  323.548032] NIP: c005b404 LR: c0934c68 CTR:
c0099650
> [  323.548033] REGS: c0003baaf9d0 TRAP: 0901   Not tainted
(4.6.0-rc3-00130-g4d2a14c)
> [  323.548034] MSR: 80009033   CR:
48002844  XER: 
> [  323.548040] CFAR: c0934c64 SOFTE: 1
>GPR00: c0934c68 c0003baafc50 c0db3f00
c0e7e978
>GPR04: 0001 81d0 000bdb0f5a4e

>GPR08: c0e207b8 0002 8001

>GPR12: c001cfb0 cfe01c00
> [  323.548055] NIP [c005b404] __spin_yield+0x14/0xa0
> [  323.548059] LR [c0934c68] _raw_spin_lock_irqsave+0x118/0x120
> [  323.548060] Call Trace:
> [  323.548062] [c0003baafc50] [c0934c68]
_raw_spin_lock_irqsave+0x118/0x120 (unreliable)
> [  323.548065] [c0003baafc90] [c0139a6c]
do_adjtimex+0x9c/0x1c0
> [  323.548068] [c0003baafd00] [c013238c]
posix_clock_realtime_adj+0x1c/0x30
> [  323.548070] [c0003baafd20] [c0133920]
SyS_clock_adjtime+0xa0/0x150
> [  323.548073] [c0003baafe30] [c0009260]
system_call+0x38/0x108
> [  323.548074] Instruction dump:
> [  323.548075] eba1ffe8 eb81ffe0 eb61ffd8 4e800020 6000 6000
6000 3c4c00d6
> [  323.548078] 38428b10 8143 2faa 4d9e0020 <79490420> 2b8907ff
79290020 7d101026
>
>
> 
>
> [   21.926941] INFO: rcu_sched self-detected stall on CPU
> [   21.931553]  7-...: (2098 ticks this GP) idle=9b3/141/0
softirq=204/267 fqs=2097
> [   21.931601]   (t=2100 jiffies g=-249 c=-250 q=23178)
> [   21.931751] Task dump for CPU 7:
> [   21.931755] systemd R  running task 9872 1  0
0x00040004
> [   21.931763] Call Trace:
> [   21.931773] [c0003e503630] [c00e783c]
sched_show_task+0xec/0x180 (unreliable)
> [   21.931779] [c0003e5036a0] [c0123504]
rcu_dump_cpu_stacks+0xe4/0x150
> [   21.931783] [c0003e5036f0] [c0128214]
rcu_check_callbacks+0x6b4/0x9c0
> [   21.931804] [c0003e503810] [c012ec7c]
update_process_times+0x4c/0xa0
> [   21.931809] [c0003e503840] [c0143828]
tick_sched_handle.isra.5+0x28/0xb0
> [   21.931812] [c0003e503870] [c014390c]
tick_sched_timer+0x5c/0xd0
> [   21.931816] [c0003e5038b0] [c012f528]
__hrtimer_run_queues+0xf8/0x380
> [   21.931819] [c0003e503930] [c01303e0]
hrtimer_interrupt+0xe0/0x2b0
> [   21.931823] [c0003e5039f0] [c001d57c]
__timer_interrupt+0x8c/0x270
> [   21.931826] [c0003e503a40] [c001dc5c]
timer_interrupt+0x9c/0xe0
> [   21.931830] [c0003e503a70] [c0002750]
decrementer_common+0x150/0x180
> [   21.931834] --- interrupt: 901 at ktime_get_ts64+0xf0/0x150
>LR = ktime_get_ts64+0x74/0x150
> [   21.931836] [c0003e503d60] []   (null)
(unreliable)
> [   21.931841] [c0003e503da0] [c029fa38]
poll_select_set_timeout+0x78/0xd0
> [   21.931844] [c0003e503de0] [c02a1020] SyS_poll+0x80/0x150
> [   21.931847] [c0003e503e30] [c0009260]
system_call+0x38/0x108
> [   24.006941] NMI watchdog: BUG: soft lockup - CPU#7 stuck for 21s!
[systemd:1]
> [   24.007117] Modules linked in:
> [   24.007122] CPU: 7 PID: 1 Comm: systemd Not tainted
4.6.0-rc3-00130-g4d2a14c #1
> [   24.007123] task: c0003e4c ti: c0003e50 task.ti:
c0003e50
> [   24.007125] NIP: c0137400 LR: c0137384 CTR:
c001cfb0
> [   24.007126] REGS: c0003e503ae0 TRAP: 0901   Not tainted
(4.6.0-rc3-00130-g4d2a14c)
> [   24.007126] MSR: 80009033   CR:
28424844  XER: 2000
> [   24.007132] CFAR: c0137414 SOFTE: 1
>GPR00: c029fa38 c0003e503d60 c0db3a00
0025ff39
>GPR04: a8ce0e65 ac491cb5c5ec 5731f19b

>GPR08: 3b9ac9ff 2af484699eac9820 93054a12

>GPR12: c001cfb0 cfe01c00
> [   24.007141] NIP [c0137400] ktime_get_ts64+0xf0/0x150
> [   24.007143] LR [c0137384] ktime_get_ts64+0x74/0x150
> [   24.007143] Call Trace:
> [   24.007145] [c0003e503da0] [c029fa38]
poll_select_set_timeout+0x78/0xd0
> [   24.007146] [c0003e503de0] 

softlockup with 4.6.0-rc3-00130-g4d2a14c

[Aneesh Kumar K.V]

I am finding the below softlockups with kvm guest. This is using the
same version of kernel for host and guest.

[  323.547841] NMI watchdog: BUG: soft lockup - CPU#7 stuck for 22s! 
[systemd-timesyn:3116]
[  323.548023] Modules linked in:
[  323.548029] CPU: 7 PID: 3116 Comm: systemd-timesyn Not tainted 
4.6.0-rc3-00130-g4d2a14c #2
[  323.548031] task: c00038b16d00 ti: c0003baac000 task.ti: 
c0003baac000
[  323.548032] NIP: c005b404 LR: c0934c68 CTR: c0099650
[  323.548033] REGS: c0003baaf9d0 TRAP: 0901   Not tainted  
(4.6.0-rc3-00130-g4d2a14c)
[  323.548034] MSR: 80009033   CR: 48002844  XER: 

[  323.548040] CFAR: c0934c64 SOFTE: 1 
   GPR00: c0934c68 c0003baafc50 c0db3f00 
c0e7e978 
   GPR04: 0001 81d0 000bdb0f5a4e 
 
   GPR08: c0e207b8 0002 8001 
 
   GPR12: c001cfb0 cfe01c00 
[  323.548055] NIP [c005b404] __spin_yield+0x14/0xa0
[  323.548059] LR [c0934c68] _raw_spin_lock_irqsave+0x118/0x120
[  323.548060] Call Trace:
[  323.548062] [c0003baafc50] [c0934c68] 
_raw_spin_lock_irqsave+0x118/0x120 (unreliable)
[  323.548065] [c0003baafc90] [c0139a6c] do_adjtimex+0x9c/0x1c0
[  323.548068] [c0003baafd00] [c013238c] 
posix_clock_realtime_adj+0x1c/0x30
[  323.548070] [c0003baafd20] [c0133920] 
SyS_clock_adjtime+0xa0/0x150
[  323.548073] [c0003baafe30] [c0009260] system_call+0x38/0x108
[  323.548074] Instruction dump:
[  323.548075] eba1ffe8 eb81ffe0 eb61ffd8 4e800020 6000 6000 6000 
3c4c00d6 
[  323.548078] 38428b10 8143 2faa 4d9e0020 <79490420> 2b8907ff 79290020 
7d101026




[   21.926941] INFO: rcu_sched self-detected stall on CPU
[   21.931553]  7-...: (2098 ticks this GP) idle=9b3/141/0 
softirq=204/267 fqs=2097 
[   21.931601]   (t=2100 jiffies g=-249 c=-250 q=23178)
[   21.931751] Task dump for CPU 7:
[   21.931755] systemd R  running task 9872 1  0 0x00040004
[   21.931763] Call Trace:
[   21.931773] [c0003e503630] [c00e783c] sched_show_task+0xec/0x180 
(unreliable)
[   21.931779] [c0003e5036a0] [c0123504] 
rcu_dump_cpu_stacks+0xe4/0x150
[   21.931783] [c0003e5036f0] [c0128214] 
rcu_check_callbacks+0x6b4/0x9c0
[   21.931804] [c0003e503810] [c012ec7c] 
update_process_times+0x4c/0xa0
[   21.931809] [c0003e503840] [c0143828] 
tick_sched_handle.isra.5+0x28/0xb0
[   21.931812] [c0003e503870] [c014390c] tick_sched_timer+0x5c/0xd0
[   21.931816] [c0003e5038b0] [c012f528] 
__hrtimer_run_queues+0xf8/0x380
[   21.931819] [c0003e503930] [c01303e0] 
hrtimer_interrupt+0xe0/0x2b0
[   21.931823] [c0003e5039f0] [c001d57c] 
__timer_interrupt+0x8c/0x270
[   21.931826] [c0003e503a40] [c001dc5c] timer_interrupt+0x9c/0xe0
[   21.931830] [c0003e503a70] [c0002750] 
decrementer_common+0x150/0x180
[   21.931834] --- interrupt: 901 at ktime_get_ts64+0xf0/0x150
   LR = ktime_get_ts64+0x74/0x150
[   21.931836] [c0003e503d60] []   (null) 
(unreliable)
[   21.931841] [c0003e503da0] [c029fa38] 
poll_select_set_timeout+0x78/0xd0
[   21.931844] [c0003e503de0] [c02a1020] SyS_poll+0x80/0x150
[   21.931847] [c0003e503e30] [c0009260] system_call+0x38/0x108
[   24.006941] NMI watchdog: BUG: soft lockup - CPU#7 stuck for 21s! [systemd:1]
[   24.007117] Modules linked in:
[   24.007122] CPU: 7 PID: 1 Comm: systemd Not tainted 4.6.0-rc3-00130-g4d2a14c 
#1
[   24.007123] task: c0003e4c ti: c0003e50 task.ti: 
c0003e50
[   24.007125] NIP: c0137400 LR: c0137384 CTR: c001cfb0
[   24.007126] REGS: c0003e503ae0 TRAP: 0901   Not tainted  
(4.6.0-rc3-00130-g4d2a14c)
[   24.007126] MSR: 80009033   CR: 28424844  XER: 
2000
[   24.007132] CFAR: c0137414 SOFTE: 1 
   GPR00: c029fa38 c0003e503d60 c0db3a00 
0025ff39 
   GPR04: a8ce0e65 ac491cb5c5ec 5731f19b 
 
   GPR08: 3b9ac9ff 2af484699eac9820 93054a12 
 
   GPR12: c001cfb0 cfe01c00 
[   24.007141] NIP [c0137400] ktime_get_ts64+0xf0/0x150
[   24.007143] LR [c0137384] ktime_get_ts64+0x74/0x150
[   24.007143] Call Trace:
[   24.007145] [c0003e503da0] [c029fa38] 
poll_select_set_timeout+0x78/0xd0
[   24.007146] [c0003e503de0] [c02a1020] SyS_poll+0x80/0x150
[   24.007148] [c0003e503e30] [c0009260] system_call+0x38/0x108
[   24.007149] Instruction dump:
[   24.007151] 7ce94e34 7ce43214