lkml.org 
[lkml]   [2019]   [Jun]   [24]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Subject[next][PowerPC] RCU stalls while booting linux-next on PowerVM LPAR
Date
Latest -next fails to boot on POWER9 PowerVM LPAR due to RCU stalls.

This problem was introduced with next-20190620 (dc636f5d78).
next-20190619 was last good kernel.

Reverting following commit allows the kernel to boot.
2fd4aeea6b603 : mm/memory_hotplug: move and simplify walk_memory_blocks()


[ 0.014409] Using shared cache scheduler topology
[ 0.016302] devtmpfs: initialized
[ 0.031022] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.031034] futex hash table entries: 16384 (order: 5, 2097152 bytes, linear)
[ 0.031575] NET: Registered protocol family 16
[ 0.031724] audit: initializing netlink subsys (disabled)
[ 0.031796] audit: type=2000 audit(1561344029.030:1): state=initialized audit_enabled=0 res=1
[ 0.032249] cpuidle: using governor menu
[ 0.032403] pstore: Registered nvram as persistent store backend
[ 60.061246] rcu: INFO: rcu_sched self-detected stall on CPU
[ 60.061254] rcu: 0-....: (5999 ticks this GP) idle=1ea/1/0x4000000000000002 softirq=5/5 fqs=2999
[ 60.061261] (t=6000 jiffies g=-1187 q=0)
[ 60.061265] NMI backtrace for cpu 0
[ 60.061269] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.2.0-rc5-next-20190621-autotest-autotest #1
[ 60.061275] Call Trace:
[ 60.061280] [c0000018ee85f380] [c000000000b624ec] dump_stack+0xb0/0xf4 (unreliable)
[ 60.061287] [c0000018ee85f3c0] [c000000000b6d464] nmi_cpu_backtrace+0x144/0x150
[ 60.061293] [c0000018ee85f450] [c000000000b6d61c] nmi_trigger_cpumask_backtrace+0x1ac/0x1f0
[ 60.061300] [c0000018ee85f4f0] [c0000000000692c8] arch_trigger_cpumask_backtrace+0x28/0x40
[ 60.061306] [c0000018ee85f510] [c0000000001c5f90] rcu_dump_cpu_stacks+0x10c/0x16c
[ 60.061313] [c0000018ee85f560] [c0000000001c4fe4] rcu_sched_clock_irq+0x744/0x990
[ 60.061318] [c0000018ee85f630] [c0000000001d5b58] update_process_times+0x48/0x90
[ 60.061325] [c0000018ee85f660] [c0000000001ea03c] tick_periodic+0x4c/0x120
[ 60.061330] [c0000018ee85f690] [c0000000001ea150] tick_handle_periodic+0x40/0xe0
[ 60.061336] [c0000018ee85f6d0] [c00000000002b5cc] timer_interrupt+0x10c/0x2e0
[ 60.061342] [c0000018ee85f730] [c000000000009204] decrementer_common+0x134/0x140
[ 60.061350] --- interrupt: 901 at replay_interrupt_return+0x0/0x4
[ 60.061350] LR = arch_local_irq_restore+0x84/0x90
[ 60.061357] [c0000018ee85fa30] [c0000018ee85fbac] 0xc0000018ee85fbac (unreliable)
[ 60.061364] [c0000018ee85fa50] [c000000000b88300] _raw_spin_unlock_irqrestore+0x50/0x80
[ 60.061369] [c0000018ee85fa70] [c000000000b69da4] klist_next+0xb4/0x150
[ 60.061376] [c0000018ee85fac0] [c000000000766ea0] subsys_find_device_by_id+0xf0/0x1a0
[ 60.061382] [c0000018ee85fb20] [c000000000797a94] walk_memory_blocks+0x84/0x100
[ 60.061388] [c0000018ee85fb80] [c000000000795ea0] link_mem_sections+0x40/0x60
[ 60.061395] [c0000018ee85fbb0] [c000000000f28c28] topology_init+0xa0/0x268
[ 60.061400] [c0000018ee85fc10] [c000000000010448] do_one_initcall+0x68/0x2c0
[ 60.061406] [c0000018ee85fce0] [c000000000f247dc] kernel_init_freeable+0x318/0x47c
[ 60.061411] [c0000018ee85fdb0] [c0000000000107c4] kernel_init+0x24/0x150
[ 60.061417] [c0000018ee85fe20] [c00000000000ba54] ret_from_kernel_thread+0x5c/0x68
[ 88.016563] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:1]
[ 88.016569] Modules linked in:


Thanks
-Sachin


[ 0.000000] hash-mmu: Page sizes from device-tree:
[ 0.000000] hash-mmu: base_shift=12: shift=12, sllp=0x0000, avpnm=0x00000000, tlbiel=1, penc=0
[ 0.000000] hash-mmu: base_shift=12: shift=16, sllp=0x0000, avpnm=0x00000000, tlbiel=1, penc=7
[ 0.000000] hash-mmu: base_shift=12: shift=24, sllp=0x0000, avpnm=0x00000000, tlbiel=1, penc=56
[ 0.000000] hash-mmu: base_shift=16: shift=16, sllp=0x0110, avpnm=0x00000000, tlbiel=1, penc=1
[ 0.000000] hash-mmu: base_shift=16: shift=24, sllp=0x0110, avpnm=0x00000000, tlbiel=1, penc=8
[ 0.000000] hash-mmu: base_shift=24: shift=24, sllp=0x0100, avpnm=0x00000001, tlbiel=0, penc=0
[ 0.000000] hash-mmu: base_shift=34: shift=34, sllp=0x0120, avpnm=0x000007ff, tlbiel=0, penc=3
[ 0.000000] Using 1TB segments
[ 0.000000] hash-mmu: Initializing hash mmu with SLB
[ 0.000000] Linux version 5.2.0-rc5-next-20190620-autotest (root@ltczep10-lp3.aus.stglabs.ibm.com) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-36) (GCC)) #1 SMP Mon Jun 24 06:38:12 PDT 2019
[ 0.000000] Found initrd at 0xc0000000032b0000:0xc0000000044c4efc
[ 0.000000] Using pSeries machine description
[ 0.000000] printk: bootconsole [udbg0] enabled
[ 0.000000] Partition configured for 40 cpus.
[ 0.000000] CPU maps initialized for 8 threads per core
[ 0.000000] -----------------------------------------------------
[ 0.000000] phys_mem_size = 0x1900000000
[ 0.000000] dcache_bsize = 0x80
[ 0.000000] icache_bsize = 0x80
[ 0.000000] cpu_features = 0x0000c07f8f5f91a7
[ 0.000000] possible = 0x0000fbffcf5fb1a7
[ 0.000000] always = 0x00000003800081a1
[ 0.000000] cpu_user_features = 0xdc0065c2 0xefe00000
[ 0.000000] mmu_features = 0x7c006001
[ 0.000000] firmware_features = 0x00000013c45bfc57
[ 0.000000] hash-mmu: ppc64_pft_size = 0x1e
[ 0.000000] hash-mmu: htab_hash_mask = 0x7fffff
[ 0.000000] hash-mmu: kernel vmalloc start = 0xc008000000000000
[ 0.000000] hash-mmu: kernel IO start = 0xc00a000000000000
[ 0.000000] hash-mmu: kernel vmemmap start = 0xc00c000000000000
[ 0.000000] -----------------------------------------------------
[ 0.000000] numa: NODE_DATA [mem 0x18ffe98980-0x18ffe9ffff]
[ 0.000000] numa: NODE_DATA(0) on node 3
[ 0.000000] numa: NODE_DATA [mem 0x18ffe91300-0x18ffe9897f]
[ 0.000000] rfi-flush: fallback displacement flush available
[ 0.000000] rfi-flush: mttrig type flush available
[ 0.000000] count-cache-flush: full software flush sequence enabled.
[ 0.000000] stf-barrier: eieio barrier available
[ 0.000000] PPC64 nvram contains 15360 bytes
[ 0.000000] barrier-nospec: using ORI speculation barrier
[ 0.000000] Zone ranges:
[ 0.000000] Normal [mem 0x0000000000000000-0x00000018ffffffff]
[ 0.000000] Device empty
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 3: [mem 0x0000000000000000-0x00000018ffffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000000000000]
[ 0.000000] Initmem setup node 3 [mem 0x0000000000000000-0x00000018ffffffff]
[ 0.000000] percpu: Embedded 11 pages/cpu s631960 r0 d88936 u1048576
[ 0.000000] node[0] zonelist: 3:Normal
[ 0.000000] node[3] zonelist: 3:Normal
[ 0.000000] Built 2 zonelists, mobility grouping on. Total pages: 1636800
[ 0.000000] Policy zone: Normal
[ 0.000000] Kernel command line: root=UUID=5b503143-3264-4a73-bd1b-2b1cd7d250f6
[ 0.000000] Dentry cache hash table entries: 8388608 (order: 10, 67108864 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 4194304 (order: 9, 33554432 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] Memory: 104547200K/104857600K available (11840K kernel code, 1792K rwdata, 3584K rodata, 4992K init, 3850K bss, 310400K reserved, 0K cma-reserved)
[ 0.000000] random: get_random_u64 called from cache_random_seq_create+0xa4/0x1c0 with crng_init=0
[ 0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=40, Nodes=32
[ 0.000000] ftrace: allocating 31746 entries in 12 pages
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=40.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=40
[ 0.000000] NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
[ 0.000000] rcu: Offload RCU callbacks from CPUs: (none).
[ 0.000002] time_init: 56 bit decrementer (max: 7fffffffffffff)
[ 0.000067] clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns
[ 0.000178] clocksource: timebase mult[1f40000] shift[24] registered
[ 0.000312] Console: colour dummy device 80x25
[ 0.000363] printk: console [hvc0] enabled
[ 0.000363] printk: console [hvc0] enabled
[ 0.000411] printk: bootconsole [udbg0] disabled
[ 0.000411] printk: bootconsole [udbg0] disabled
[ 0.000508] mempolicy: Enabling automatic NUMA balancing. Configure with numa_balancing= or the kernel.numa_balancing sysctl
[ 0.000521] pid_max: default: 40960 minimum: 320
[ 0.000673] LSM: Security Framework initializing
[ 0.000759] Yama: becoming mindful.
[ 0.000781] SELinux: Initializing.
[ 0.000944] *** VALIDATE SELinux ***
[ 0.001035] Mount-cache hash table entries: 131072 (order: 4, 1048576 bytes, linear)
[ 0.001073] Mountpoint-cache hash table entries: 131072 (order: 4, 1048576 bytes, linear)
[ 0.001370] *** VALIDATE proc ***
[ 0.001623] *** VALIDATE cgroup1 ***
[ 0.001629] *** VALIDATE cgroup2 ***
[ 0.002225] EEH: pSeries platform initialized
[ 0.002233] POWER9 performance monitor hardware support registered
[ 0.002272] rcu: Hierarchical SRCU implementation.
[ 0.003078] smp: Bringing up secondary CPUs ...
[ 0.014555] smp: Brought up 2 nodes, 40 CPUs
[ 0.014564] numa: Node 0 CPUs:
[ 0.014567] numa: Node 3 CPUs: 0-39
[ 0.014571] Using small cores at SMT level
[ 0.014575] Using shared cache scheduler topology
[ 0.016465] devtmpfs: initialized
[ 0.031046] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.031058] futex hash table entries: 16384 (order: 5, 2097152 bytes, linear)
[ 0.031602] NET: Registered protocol family 16
[ 0.031751] audit: initializing netlink subsys (disabled)
[ 0.031822] audit: type=2000 audit(1561384091.030:1): state=initialized audit_enabled=0 res=1
[ 0.032275] cpuidle: using governor menu
[ 0.032429] pstore: Registered nvram as persistent store backend
[ 60.061325] rcu: INFO: rcu_sched self-detected stall on CPU
[ 60.061333] rcu: 0-....: (5999 ticks this GP) idle=1ca/1/0x4000000000000002 softirq=5/5 fqs=2999
[ 60.061340] (t=6000 jiffies g=-1187 q=0)
[ 60.061343] NMI backtrace for cpu 0
[ 60.061349] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.2.0-rc5-next-20190620-autotest #1
[ 60.061354] Call Trace:
[ 60.061358] [c0000018ee813360] [c000000000b625cc] dump_stack+0xb0/0xf4 (unreliable)
[ 60.061365] [c0000018ee8133a0] [c000000000b6d544] nmi_cpu_backtrace+0x144/0x150
[ 60.061371] [c0000018ee813430] [c000000000b6d6fc] nmi_trigger_cpumask_backtrace+0x1ac/0x1f0
[ 60.061378] [c0000018ee8134d0] [c0000000000692c8] arch_trigger_cpumask_backtrace+0x28/0x40
[ 60.061385] [c0000018ee8134f0] [c0000000001c6210] rcu_dump_cpu_stacks+0x10c/0x16c
[ 60.061391] [c0000018ee813540] [c0000000001c5264] rcu_sched_clock_irq+0x744/0x990
[ 60.061397] [c0000018ee813610] [c0000000001d5e38] update_process_times+0x48/0x90
[ 60.061403] [c0000018ee813640] [c0000000001ea31c] tick_periodic+0x4c/0x120
[ 60.061408] [c0000018ee813670] [c0000000001ea430] tick_handle_periodic+0x40/0xe0
[ 60.061414] [c0000018ee8136b0] [c00000000002b5cc] timer_interrupt+0x10c/0x2e0
[ 60.061420] [c0000018ee813710] [c000000000009204] decrementer_common+0x134/0x140
[ 60.061427] --- interrupt: 901 at replay_interrupt_return+0x0/0x4
[ 60.061427] LR = arch_local_irq_restore+0x84/0x90
[ 60.061434] [c0000018ee813a10] [c0000018ee813bac] 0xc0000018ee813bac (unreliable)
[ 60.061441] [c0000018ee813a30] [c000000000b883e0] _raw_spin_unlock_irqrestore+0x50/0x80
[ 60.061447] [c0000018ee813a50] [c000000000b69e84] klist_next+0xb4/0x150
[ 60.061453] [c0000018ee813aa0] [c000000000766f60] subsys_find_device_by_id+0xf0/0x1a0
[ 60.061459] [c0000018ee813b00] [c000000000796464] find_memory_block_by_id+0x94/0xb0
[ 60.061466] [c0000018ee813b30] [c000000000797b1c] walk_memory_blocks+0x7c/0xf0
[ 60.061472] [c0000018ee813b80] [c000000000795f60] link_mem_sections+0x40/0x60
[ 60.061478] [c0000018ee813bb0] [c000000000f28c28] topology_init+0xa0/0x268
[ 60.061483] [c0000018ee813c10] [c000000000010448] do_one_initcall+0x68/0x2c0
[ 60.061489] [c0000018ee813ce0] [c000000000f247dc] kernel_init_freeable+0x318/0x47c
[ 60.061495] [c0000018ee813db0] [c0000000000107c4] kernel_init+0x24/0x150
[ 60.061500] [c0000018ee813e20] [c00000000000ba54] ret_from_kernel_thread+0x5c/0x68
[ 88.016703] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:1]
[ 88.016709] Modules linked in:
[ 88.016713] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.2.0-rc5-next-20190620-autotest #1
[ 88.016718] NIP: c00000000000ab8c LR: c00000000001b434 CTR: 0000000000000000
[ 88.016724] REGS: c0000018ee813780 TRAP: 0901 Not tainted (5.2.0-rc5-next-20190620-autotest)
[ 88.016730] MSR: 8000000002009033 <SF,VEC,EE,ME,IR,DR,RI,LE> CR: 44008484 XER: 00000005
[ 88.016738] CFAR: c000000000b69e30 IRQMASK: 0
[ 88.016738] GPR00: c000000000b883e0 c0000018ee813a10 c000000001544d00 0000000000000900
[ 88.016738] GPR04: 0000000000000000 0000000000000000 0000000000000001 0000000000000004
[ 88.016738] GPR08: 0000000000000000 c0000018eb436d80 0000000000000001 0000000000000220
[ 88.016738] GPR12: 0000000000000000 c000000001990000
[ 88.016761] NIP [c00000000000ab8c] replay_interrupt_return+0x0/0x4
[ 88.016767] LR [c00000000001b434] arch_local_irq_restore+0x84/0x90
[ 88.016771] Call Trace:
[ 88.016774] [c0000018ee813a10] [c0000018ee813bac] 0xc0000018ee813bac (unreliable)
[ 88.016780] [c0000018ee813a30] [c000000000b883e0] _raw_spin_unlock_irqrestore+0x50/0x80
[ 88.016786] [c0000018ee813a50] [c000000000b69e84] klist_next+0xb4/0x150
[ 88.016792] [c0000018ee813aa0] [c000000000766f60] subsys_find_device_by_id+0xf0/0x1a0
[ 88.016798] [c0000018ee813b00] [c000000000796464] find_memory_block_by_id+0x94/0xb0
[ 88.016804] [c0000018ee813b30] [c000000000797b1c] walk_memory_blocks+0x7c/0xf0
[ 88.016810] [c0000018ee813b80] [c000000000795f60] link_mem_sections+0x40/0x60
[ 88.016816] [c0000018ee813bb0] [c000000000f28c28] topology_init+0xa0/0x268
[ 88.016821] [c0000018ee813c10] [c000000000010448] do_one_initcall+0x68/0x2c0
[ 88.016827] [c0000018ee813ce0] [c000000000f247dc] kernel_init_freeable+0x318/0x47c
[ 88.016833] [c0000018ee813db0] [c0000000000107c4] kernel_init+0x24/0x150
[ 88.016838] [c0000018ee813e20] [c00000000000ba54] ret_from_kernel_thread+0x5c/0x68
[ 88.016843] Instruction dump:
[ 88.016847] 7d200026 618c8000 2c030900 4182e568 2c030500 4182e010 2c030f00 4182f2d8
[ 88.016854] 2c030a00 4182ffb8 60000000 60000000 <4e800020> 7c781b78 480003e1 480003f9


\
 
 \ /
  Last update: 2019-06-24 16:10    [W:0.052 / U:1.008 seconds]
©2003-2018 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site