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] []