Can’t run smp on 4 cores

[sunvich]

Hi, I configured the sun8i-h3.dts by adding the text enable-method = "allwinner,sun8i-h3" in the node "cpus", and modifed the platsmp.c to enable 4 cores. But after starting kernel, it seems all cores stalled. I think this a big problem that my bord can't run with 4 cores. Oops!

[sunvich]

By the way, I runed 4.9 kernel on orangepi-pc board.

[sunvich]

3.4 kernel will run all cores well on my board.

[sunvich]

I hope someone working on the project could help me. Did you guys test running 4 cores on 4.9 kernel? If not, maybe I can offer the debug info to help you guys resolving this problem. @orangepi-xunlong @cbbc

Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.9.0-rc1 (root@sunvich) (gcc version 4.6.3 20120201 (prerelease) (crosstool-NG linaro-1.13.1-2012.02-20120222 - Linaro GCC 2012.02) ) #37 SMP Tue Mar 21 18:55:18 CST 2017
[ 0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] OF: fdt:Machine model: Xunlong Orange Pi PC
[ 0.000000] OF: fdt:Ignoring memory range 0x40000000 - 0x48000000
[ 0.000000] cma: Reserved 64 MiB at 0x7c000000
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] On node 0 totalpages: 229376
[ 0.000000] free_area_init_node: node 0, pgdat c093d5c0, node_mem_map ef8fa000
[ 0.000000] Normal zone: 1536 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 196608 pages, LIFO batch:31
[ 0.000000] HighMem zone: 32768 pages, LIFO batch:7
[ 0.000000] percpu: Embedded 14 pages/cpu @ef8ae000 s25024 r8192 d24128 u57344
[ 0.000000] pcpu-alloc: s25024 r8192 d24128 u57344 alloc=14*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 227840
[ 0.000000] Kernel command line: earlyprintk=ttyS0,115200 loglevel=8 root=/dev/mmcblk0p2 rootwait rootfstype=ext4 video=HDMI-A-1:1920x1080-32@60 console=tty1 console=ttyS0,115200
[ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Memory: 834940K/917504K available (5120K kernel code, 248K rwdata, 1092K rodata, 1024K init, 267K bss, 17028K reserved, 65536K cma-reserved, 65536K highmem)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xf0800000 - 0xff800000 ( 240 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xf0000000 ( 768 MB)
[ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
[ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
[ 0.000000] .text : 0xc0008000 - 0xc0600000 (6112 kB)
[ 0.000000] .init : 0xc0800000 - 0xc0900000 (1024 kB)
[ 0.000000] .data : 0xc0900000 - 0xc093e1c0 ( 249 kB)
[ 0.000000] .bss : 0xc0940000 - 0xc0982f88 ( 268 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] Build-time adjustment of leaf fanout to 32.
[ 0.000000] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=4.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=32, nr_cpu_ids=4
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000000] arm_arch_timer: Architected cp15 timer(s) running at 24.00MHz (virt).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns
[ 0.000013] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[ 0.000037] Switching to timer-based delay loop, resolution 41ns
[ 0.000390] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[ 0.000936] Console: colour dummy device 80x30
[ 0.002597] console [tty1] enabled
[ 0.002673] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=240000)
[ 0.002771] pid_max: default: 32768 minimum: 301
[ 0.002976] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.003038] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.004289] CPU: Testing write buffer coherency: ok
[ 0.004846] CPU0: update cpu_capacity 1024
[ 0.004907] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.005500] Setting up static identity map for 0x48100000 - 0x48100058
[ 0.007523] SMP: cpu[0]:
[ 0.007551] online
[ 0.007598] SMP: cpu[1]:
[ 5543.815704] CPU1: update cpu_capacity 1024
[ 5543.815716] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.020259] offline, try up ret 0
[ 0.020397] SMP: cpu[2]:
[ 2111.261965] CPU2: update cpu_capacity 1024
[ 2111.261976] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.032576] offline, try up ret 0
[ 0.032712] SMP: cpu[3]:
[ 6932.165741] CPU3: update cpu_capacity 1024
[ 6932.165752] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.044899] offline, try up ret 0
[ 0.045035] Brought up 4 CPUs
[ 0.045084] SMP: Total of 4 processors activated (192.00 BogoMIPS).
[ 0.045134] CPU: All CPU(s) started in SVC mode.
[ 0.046855] devtmpfs: initialized
[ 0.057922] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[ 0.058462] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.062876] pinctrl core: initialized pinctrl subsystem
[ 0.064492] NET: Registered protocol family 16
[ 0.066400] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.068762] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.068851] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.122321] reg-fixed-voltage usb0-vbus: could not find pctldev for node /soc/pinctrl@01f02c00/usb0_vbus_pin@0, deferring probe
[ 0.124356] SCSI subsystem initialized
[ 0.124654] usbcore: registered new interface driver usbfs
[ 0.124824] usbcore: registered new interface driver hub
[ 0.124986] usbcore: registered new device driver usb
[ 0.127401] clocksource: Switched to clocksource arch_sys_counter
[ 2111.362081] INFO: rcu_sched self-detected stall on CPU
[ 2111.362162] 2-...: (1 ticks this GP) idle=059/1/0 softirq=3/3 fqs=0
[ 2111.362213] (t=4811 jiffies g=-298 c=-299 q=0)
[ 2111.362283] rcu_sched kthread starved for 4811 jiffies! g4294966998 c4294966997 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
[ 2111.362366] rcu_sched S c0525338 0 7 2 0x00000000
[ 2111.362485] [] (__schedule) from [] (schedule+0x38/0x9c)
[ 2111.362559] [] (schedule) from [] (schedule_timeout+0x15c/0x218)
[ 2111.362661] [] (schedule_timeout) from [] (rcu_gp_kthread+0x528/0x8ec)
[ 2111.362764] [] (rcu_gp_kthread) from [] (kthread+0xd8/0xf4)
[ 2111.362863] [] (kthread) from [] (ret_from_fork+0x14/0x3c)
[ 2111.362949] Task dump for CPU 1:
[ 2111.362992] swapper/1 R running 0 0 1 0x00000000
[ 2111.363076] [] (__schedule) from [] (0xffffffff)
[ 2111.363127] Task dump for CPU 2:
[ 2111.363170] swapper/2 R running 0 0 1 0x00000000
[ 2111.363261] [] (unwind_backtrace) from [] (show_stack+0x10/0x14)
[ 2111.363364] [] (show_stack) from [] (rcu_dump_cpu_stacks+0x74/0xc4)
[ 2111.363462] [] (rcu_dump_cpu_stacks) from [] (rcu_check_callbacks+0x604/0x7cc)
[ 2111.363560] [] (rcu_check_callbacks) from [] (update_process_times+0x30/0x5c)
[ 2111.363660] [] (update_process_times) from [] (tick_handle_periodic+0x2c/0xa8)
[ 2111.363765] [] (tick_handle_periodic) from [] (arch_timer_handler_virt+0x28/0x30)
[ 2111.363869] [] (arch_timer_handler_virt) from [] (handle_percpu_devid_irq+0x70/0x120)
[ 2111.363971] [] (handle_percpu_devid_irq) from [] (generic_handle_irq+0x18/0x28)
[ 2111.364073] [] (generic_handle_irq) from [] (__handle_domain_irq+0x54/0xac)
[ 2111.364169] [] (__handle_domain_irq) from [] (gic_handle_irq+0x44/0x94)
[ 2111.364262] [] (gic_handle_irq) from [] (__irq_svc+0x6c/0x90)
[ 2111.364343] Exception stack(0xef099f98 to 0xef099fe0)
[ 2111.364397] 9f80: 00000000 ef8cc370
[ 6932.255866] INFO: rcu_sched self-detected stall on CPU
[ 6932.255885] 3-...: (1 ticks this GP) idle=057/1/0 softirq=3/3 fqs=0
[ 6932.255897] (t=4811 jiffies g=-298 c=-299 q=0)
[ 6932.255913] rcu_sched kthread starved for 4811 jiffies! g4294966998 c4294966997 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x100
[ 6932.255929] rcu_sched W c0525338 0 7 2 0x00000000
[ 6932.255960] [] (__schedule) from [] (schedule+0x38/0x9c)
[ 6932.255982] [] (schedule) from [] (schedule_timeout+0x15c/0x218)
[ 6932.256008] [] (schedule_timeout) from [] (rcu_gp_kthread+0x528/0x8ec)
[ 6932.256031] [] (rcu_gp_kthread) from [] (kthread+0xd8/0xf4)
[ 6932.256055] [] (kthread) from [] (ret_from_fork+0x14/0x3c)
[ 2111.365077] 9fa0: ef099ff0 c0116fc0 00000000 00000004 c0902490 c090242c c090ce85 c090ce85
[ 2111.365168] 9fc0: 00000001 00000000 c0843370 ef099fe8 c0107fe0 c0107fe4 60000013 ffffffff
[ 2111.365263] [] (__irq_svc) from [] (arch_cpu_idle+0x30/0x3c)
[ 2111.365363] [] (arch_cpu_idle) from [] (cpu_startup_entry+0x8c/0x144)
[ 2111.365458] [] (cpu_startup_entry) from [<4810152c>] (0x4810152c)
[ 2111.365510] Task dump for CPU 3:
[ 2111.365553] swapper/3 R running 0 0 1 0x00000000
[ 2111.365632] [] (__schedule) from [] (0xffffffff)
[ 6932.257133] Task dump for CPU 1:
[ 6932.257184] swapper/1 R running 0 0 1 0x00000000
[ 6932.257266] [] (__schedule) from [] (0xffffffff)
[ 6932.257317] Task dump for CPU 2:
[ 6932.257360] swapper/2 R running 0 0 1 0x00000000
[ 6932.257438] [] (__schedule) from [] (0xffffffff)
[ 6932.257489] Task dump for CPU 3:
[ 6932.257532] swapper/3 R running 0 0 1 0x00000000
[ 6932.257616] [] (unwind_backtrace) from [] (show_stack+0x10/0x14)
[ 6932.257715] [] (show_stack) from [] (rcu_dump_cpu_stacks+0x74/0xc4)
[ 6932.257811] [] (rcu_dump_cpu_stacks) from [] (rcu_check_callbacks+0x604/0x7cc)
[ 6932.257907] [] (rcu_check_callbacks) from [] (update_process_times+0x30/0x5c)
[ 6932.258005] [] (update_process_times) from [] (tick_handle_periodic+0x2c/0xa8)
[ 6932.258106] [] (tick_handle_periodic) from [] (arch_timer_handler_virt+0x28/0x30)
[ 6932.258207] [] (arch_timer_handler_virt) from [] (handle_percpu_devid_irq+0x70/0x120)
[ 6932.258305] [] (handle_percpu_devid_irq) from [] (generic_handle_irq+0x18/0x28)
[ 6932.258405] [] (generic_handle_irq) from [] (__handle_domain_irq+0x54/0xac)
[ 6932.258501] [] (__handle_domain_irq) from [] (gic_handle_irq+0x44/0x94)
[ 6932.258592] [] (gic_handle_irq) from [] (__irq_svc+0x6c/0x90)
[ 6932.258672] Exception stack(0xef09bf98 to 0xef09bfe0)
[ 6932.258725] bf80: 00000000 ef8da370
[ 6932.258816] bfa0: ef09bff0 c0116fc0 00000000 00000008 c0902490 c090242c c090ce85 c090ce85
[ 6932.258907] bfc0: 00000001 00000000 c0843370 ef09bfe8 c0107fe0 c0107fe4 60000013 ffffffff
[ 6932.259001] [] (__irq_svc) from [] (arch_cpu_idle+0x30/0x3c)
[ 6932.259099] [] (arch_cpu_idle) from [] (cpu_startup_entry+0x8c/0x144)
[ 6932.259192] [] (cpu_startup_entry) from [<4810152c>] (0x4810152c)
[ 1826.458195] INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1826.458270] 1-...: (0 ticks this GP) idle=08b/140000000000000/0 softirq=3/3 fqs=0
[ 1826.458347] (detected by 0, t=327685672 jiffies, g=-298, c=-299, q=0)
[ 1826.458411] Task dump for CPU 1:
[ 1826.458454] swapper/1 R running 0 0 1 0x00000002
[ 1826.458538] [] (__schedule) from [<00000000>] ( (null))
[ 1826.458601] rcu_sched kthread starved for 327685672 jiffies! g4294966998 c4294966997 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x100
[ 1826.458684] rcu_sched W c0525338 0 7 2 0x00000000
[ 1826.458769] [] (__schedule) from [] (schedule+0x38/0x9c)
[ 1826.458839] [] (schedule) from [] (schedule_timeout+0x15c/0x218)
[ 1826.458936] [] (schedule_timeout) from [] (rcu_gp_kthread+0x528/0x8ec)
[ 1826.459034] [] (rcu_gp_kthread) from [] (kthread+0xd8/0xf4)
[ 1826.459127] [] (kthread) from [] (ret_from_fork+0x14/0x3c)
[11276.196715] ------------[ cut here ]------------
[11276.196789] WARNING: CPU: 1 PID: 0 at kernel/time/clockevents.c:314 clockevents_program_event+0x144/0x184
[11276.196869] Modules linked in:
[11276.196929] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.9.0-rc1 #37
[11276.196979] Hardware name: Allwinner sun8i Family
[11276.197051] [] (unwind_backtrace) from [] (show_stack+0x10/0x14)
[11276.197152] [] (show_stack) from [] (dump_stack+0x78/0x98)
[11276.197247] [] (dump_stack) from [] (__warn+0xcc/0xf4)
[11276.197313] [] (__warn) from [] (warn_slowpath_null+0x20/0x28)
[11276.197406] [] (warn_slowpath_null) from [] (clockevents_program_event+0x144/0x184)
[11276.197508] [] (clockevents_program_event) from [] (tick_program_event+0x58/0x90)
[11276.197608] [] (tick_program_event) from [] (hrtimer_interrupt+0x1e4/0x250)
[11276.197709] [] (hrtimer_interrupt) from [] (arch_timer_handler_virt+0x28/0x30)
[11276.197809] [] (arch_timer_handler_virt) from [] (handle_percpu_devid_irq+0x70/0x120)
[11276.197908] [] (handle_percpu_devid_irq) from [] (generic_handle_irq+0x18/0x28)
[11276.198007] [] (generic_handle_irq) from [] (__handle_domain_irq+0x54/0xac)
[11276.198102] [] (__handle_domain_irq) from [] (gic_handle_irq+0x44/0x94)
[11276.198193] [] (gic_handle_irq) from [] (__irq_svc+0x6c/0x90)
[11276.198272] Exception stack(0xef097f40 to 0xef097f88)
[11276.198332] 7f40: 00000000 00000000 00000001 00000000 00000000 00000002 c0846740 c090242c
[11276.198424] 7f60: c0846740 c090ce85 c09025e4 ef097fdc c0424328 ef097f90 c05257c4 c05251b4
[11276.198504] 7f80: 60000013 ffffffff
[11276.198565] [] (__irq_svc) from [] (__schedule+0x30/0x520)
[11276.198661] [] (__schedule) from [] (schedule+0x38/0x9c)
[11276.198733] [] (schedule) from [] (schedule_preempt_disabled+0xc/0x10)
[11276.198834] [] (schedule_preempt_disabled) from [] (cpu_startup_entry+0x100/0x144)
[11276.198929] [] (cpu_startup_entry) from [<4810152c>] (0x4810152c)
[11276.198996] ---[ end trace 840ea3cf58cec2f4 ]---
[11276.199045] hrtimer: interrupt took 6004803148833488392 ns
[ 7289.822099] NET: Registered protocol family 2
[ 7289.823288] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 7289.823528] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[ 7289.823848] TCP: Hash tables configured (established 8192 bind 8192)
[ 7289.824011] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 7289.824138] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 7289.824527] NET: Registered protocol family 1
[ 7289.827359] futex hash table entries: 1024 (order: 4, 65536 bytes)
[ 7289.829146] workingset: timestamp_bits=30 max_order=18 bucket_order=0
[ 7289.849041] bounce: pool size: 64 pages
[ 7289.849514] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 7289.849601] io scheduler noop registered
[ 7289.849647] io scheduler deadline registered
[ 7289.850048] io scheduler cfq registered (default)
[ 7289.850447] sun4i-usb-phy 1c19400.phy: could not find pctldev for node /soc/pinctrl@01c20800/usb0_id_detect_pin@0, deferring probe
[ 7289.860637] sun8i-h3-pinctrl 1c20800.pinctrl: initialized sunXi PIO driver
[ 7289.990360] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[ 7289.992938] console [ttyS0] disabled
[ 7290.013200] 1c28000.serial: ttyS0 at MMIO 0x1c28000 (irq = 39, base_baud = 1500000) is a U6_16550A
[ 7291.463101] console [ttyS0] enabled
[ 7291.467605] dw-apb-uart: probe of 1c28400.serial failed with error -28
[ 7291.474965] [drm] Initialized
[ 7291.478724] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 7291.485295] ehci-platform: EHCI generic platform driver
[ 7291.491465] usbcore: registered new interface driver usb-storage
[ 7291.498155] mousedev: PS/2 mouse device common for all mice
[ 7291.504882] sun6i-rtc 1f00000.rtc: rtc core: registered rtc-sun6i as rtc0
[ 7291.511721] sun6i-rtc 1f00000.rtc: RTC enabled
[ 7291.516952] thermal thermal_zone0: failed to read out thermal zone (-16)
[ 7291.526281] sunxi-mmc 1c0f000.mmc: Got CD GPIO
[ 7432.032931] random: fast init done
[ 5837.035655] random: crng init done
[ 119.917689] INFO: rcu_sched self-detected stall on CPU
[ 119.922905] 1-...: (1 GPs behind) idle=a15/140000000000001/0 softirq=7/9 fqs=0
[ 447.138086] INFO: rcu_sched self-detected stall on CPU
[ 447.138104] 0-...: (1 ticks this GP) idle=9f9/1/0 softirq=13/13 fqs=0
[ 447.138117] (t=107693 jiffies g=-289 c=-290 q=22)
[ 447.138135] rcu_sched kthread starved for 107693 jiffies! g4294967007 c4294967006 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
[ 447.138154] rcu_sched S c0525338 0 7 2 0x00000000
[ 447.138211] [] (__schedule) from [] (schedule+0x38/0x9c)
[ 447.138236] [] (schedule) from [] (schedule_timeout+0x15c/0x218)
[ 447.138264] [] (schedule_timeout) from [] (rcu_gp_kthread+0x528/0x8ec)
[ 447.138291] [] (rcu_gp_kthread) from [] (kthread+0xd8/0xf4)
[ 447.138317] []