foss-for-synopsys-dwc-arc-processors / linux

Helpful resources for users & developers of Linux kernel for ARC
22 stars 13 forks source link

top freezes when running rcutorture kernel module [v5.10-rcX kernel] #31

Closed vineetgarc closed 3 years ago

vineetgarc commented 3 years ago

A customer reported a soft lockup when running rcutorture test (as loadable module) and running top in foreground. After sometime top stops updating, the interactive shell is not responsive (doesn't respond to ctrl+c). However the system is not dead and ssh to target still works.

This was reproduced on HSDK dev platform with buildroot-2020.02.4 and buildroot-2020.02.7 (both using kernel 4.19.31).

  1. Enable RCU torture test in kernel as loadable module Kernel hacking->RCU Debugging->torture tests for RCU<M>

  2. load module and top

    
    > modprobe rcutorture
    > top
vineetgarc commented 3 years ago

Problem doesn't happen with latest 5.10-rc1 kernel

vineetgarc commented 3 years ago

Linux top utility ends up unwinding each process kernel mode stack. The issue looked like something might be erong with kernel stack unwinder. Added some debug and indeed it revealed infnite looping going on. This explained the "soft lockup" as in one 1 core running the unwinder was locked up - other cores had active scheduling and could handle ssh and other requests.

Mem: 25680K used, 1009640K free, 0K shrd, 0K buff, 14496K cached
CPU:  0.0% usr 61.4% sys  0.0% nic 38.5% idle  0.0% io  0.0% irq  0.0% sirq
Load average: 3.17 0.92 0.32 7/73 138
  PID  PPID USER     STAT   VSZ %VSZ CPU %CPU COMMAND
  132     2 root     RWN      0  0.0   2 18.0 [rcu_torture_rea]
  128     2 root     DWN      0  0.0   3 17.3 [rcu_torture_fak]
  133     2 root     RWN      0  0.0   0 12.7 [rcu_torture_rea]
  131     2 root     RWN      0  0.0   3 12.3 [rcu_torture_rea]
  126     2 root     RW       0  0.0   0  0.2 [rcu_torture_wri]
  129     2 root     DWN      0  0.0   0  0.2 [rcu_torture_fak]
  130     2 root     RWN      0  0.0   0  0.1 [rcu_torture_fak]
  137     2 root     RW       0  0.0   0  0.1 [rcu_torture_cbf]
  127     2 root     DWN      0  0.0   0  0.1 [rcu_torture_fak]
  138   114 root     R     1464  0.1   0  0.0 top
   67     2 root     IW       0  0.0   1  0.0 [kworker/1:2-eve]
  114     1 root     S     1472  0.1   3  0.0 -/bin/sh
  103     1 root     S     1464  0.1   0  0.0 inetd
    1     0 root     S     1456  0.1   1  0.0 init
   79     1 root     S     1456  0.1   2  0.0 syslogd -O /var/log/messages
  134     2 root     SW       0  0.0   2  0.0 [rcu_torture_sta]
   10     2 root     IW       0  0.0   1  0.0 [rcu_preempt]
   62     2 root     IW       0  0.0   1  0.0 [kworker/1:1-eve]
   29     2 root     IW       0  0.0   3  0.0 [kworker/3:0-rcu]
[33] unwinder looping too long, aborting PC 909eea20 blink 909eea20 SP bdcd3e3c frame
[34] unwinder looping too long, aborting PC 909eea20 blink 909eea20 SP bdcd3e3c frame
vineetgarc commented 3 years ago

The kernel stack unwinder arc_unwind_core() is a thin wrapper over dwarf frame info decoder. The dwarf decoder uses function call frame info (or lack thereof) to deduce end of call chain and signals to stack unwinder. So in theory, if the dwarf info was not consistent, the stack unwinder can loop forever.

So independent of this issue the stack unwinder needs to break the loop once it detects excessive looping (heuristic of say 128 unwind attempts). The proposed patch ARC: stack unwinding: avoid indefinite looping does that and potentially safeguards against corrupt dwarf info, incorrect dwarf register state etc.

And with this patch the original problem goes away, meaning everything else : hardware/software are just fine.

jzbydniewski commented 3 years ago

I can still see similar issue from time to time on 5.10-rc2 (with patch applied from https://github.com/foss-for-synopsys-dwc-arc-processors/linux/issues/32 to make it boot). When it reproduces with 5.10-rc2 the HSDK doesn't even respond to ping.

Sometimes it runs for hours or days without reproduction. I think it's easiest to reproduce by trying steps below:

  1. power-off HSDK
  2. power-on HSDK
  3. wait it for boot, then run 3.1 run "modprobe rcutorture" 3.2 run "top"
  4. If doesn't reproduce within a minute, go to (1)

Sometimes it hangs on step (3.1)

Logs:

reading uImage
4426745 bytes read in 192 ms (22 MiB/s)
## Booting kernel from Legacy Image at 82000000 ...
   Image Name:   Linux-5.10.0-rc2
   Image Type:   ARC Linux Kernel Image (gzip compressed)
   Data Size:    4426681 Bytes = 4.2 MiB
   Load Address: 90000000
   Entry Point:  90004000
   Verifying Checksum ... OK
   Uncompressing Kernel Image ... OK
CPU start mask is 0xf

Starting kernel ...

Linux version 5.10.0-rc2 (jzbydniewski@plkatselectra) (arc-buildroot-linux-uclibc-gcc.br_real (Buildroot 2020.08.1) 9.3.1 20200315, GNU ld (GNU Binutils) 2.34.50.20200307) #3 SMP PREEMPT Mon Nov 2 09:57:26 CET 2020
Memory @ 80000000 [1024M] 
OF: fdt: Machine model: snps,hsdk
earlycon: uart8250 at MMIO32 0xf0005000 (options '115200n8')
printk: bootconsole [uart8250] enabled
Failed to get possible-cpus from dtb, pretending all 4 cpus exist
archs-intc  : 2 priority levels (default 1) FIRQ (not used)

IDENTITY    : ARCVER [0x52] ARCNUM [0x0] CHIPID [ 0x0]
processor [0]   : HS38 R2.1 (ARCv2 ISA) 
Timers      : Timer0 Timer1 RTC [UP 64-bit] GFRC [SMP 64-bit] 
ISA Extn    : atomic ll64 unalign mpy[opt 9] div_rem 
BPU     : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]    : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used) 
I-Cache     : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache     : 64K, 2way/set, 64B Line, PIPT
SLC     : 512K, 128B Line
Peripherals : 0xf0000000, IO-Coherency (per-device) 
Vector Table    : 0x90000000
FPU     : SP DP 
DEBUG       : smaRT RTT ActionPoint 8/min
Extn [SMP]  : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
Zone ranges:
  Normal   [mem 0x0000000080000000-0x00000000bfffffff]
Movable zone start for each node
Early memory node ranges
  node   0: [mem 0x0000000080000000-0x00000000bfffffff]
Initmem setup node 0 [mem 0x0000000080000000-0x00000000bfffffff]
On node 0 totalpages: 131072
  Normal zone: 576 pages used for memmap
  Normal zone: 0 pages reserved
  Normal zone: 131072 pages, LIFO batch:31
percpu: Embedded 7 pages/cpu s23168 r8192 d25984 u57344
pcpu-alloc: s23168 r8192 d25984 u57344 alloc=7*8192
pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
Built 1 zonelists, mobility grouping on.  Total pages: 130496
Kernel command line: earlycon=uart8250,mmio32,0xf0005000,115200n8 console=ttyS0,115200n8 debug print-fatal-signals=1 root=/dev/mmcblk0p2 rootwait
Dentry cache hash table entries: 131072 (order: 6, 524288 bytes, linear)
Inode-cache hash table entries: 65536 (order: 5, 262144 bytes, linear)
mem auto-init: stack:off, heap alloc:off, heap free:off
Memory: 1033472K/1048576K available (5694K kernel code, 641K rwdata, 1312K rodata, 168K init, 302K bss, 15104K reserved, 0K cma-reserved)
rcu: Preemptible hierarchical RCU implementation.
rcu:    RCU event tracing is enabled.
    Trampoline variant of Tasks RCU enabled.
    Rude variant of Tasks RCU enabled.
    Tracing variant of Tasks RCU enabled.
rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
NR_IRQS: 512
MCIP: IDU supports 64 common irqs
sched_clock: 64 bits at 999MHz, resolution 1ns, wraps every 4398046511103ns
clocksource: ARConnect GFRC: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
Console: colour dummy device 80x25
Calibrating delay loop... 997.78 BogoMIPS (lpj=4988928)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 2048 (order: 0, 8192 bytes, linear)
Mountpoint-cache hash table entries: 2048 (order: 0, 8192 bytes, linear)
rcu: Hierarchical SRCU implementation.
smp: Bringing up secondary CPUs ...
Idle Task [1] (ptrval)
Trying to bring up CPU1 ...
archs-intc  : 2 priority levels (default 1) FIRQ (not used)

IDENTITY    : ARCVER [0x52] ARCNUM [0x1] CHIPID [ 0x0]
processor [1]   : HS38 R2.1 (ARCv2 ISA) 
Timers      : Timer0 Timer1 RTC [UP 64-bit] 
ISA Extn    : atomic ll64 unalign mpy[opt 9] div_rem 
BPU     : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]    : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used) 
I-Cache     : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache     : 64K, 2way/set, 64B Line, PIPT
SLC     : 512K, 128B Line
Peripherals : 0xf0000000, IO-Coherency (per-device) 
Vector Table    : 0x90000000
FPU     : SP DP 
DEBUG       : smaRT RTT ActionPoint 8/min
Extn [CCM]  : DCCM @ 60000000, 256 KB / ICCM: @ 60000000, 256 KB
Extn [SMP]  : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
## CPU1 LIVE ##: Executing Code...
Idle Task [2] (ptrval)
Trying to bring up CPU2 ...
archs-intc  : 2 priority levels (default 1) FIRQ (not used)

IDENTITY    : ARCVER [0x52] ARCNUM [0x2] CHIPID [ 0x0]
processor [2]   : HS38 R2.1 (ARCv2 ISA) 
Timers      : Timer0 Timer1 RTC [UP 64-bit] 
ISA Extn    : atomic ll64 unalign mpy[opt 9] div_rem 
BPU     : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]    : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used) 
I-Cache     : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache     : 64K, 2way/set, 64B Line, PIPT
SLC     : 512K, 128B Line
Peripherals : 0xf0000000, IO-Coherency (per-device) 
Vector Table    : 0x90000000
FPU     : SP DP 
DEBUG       : smaRT RTT ActionPoint 8/min
Extn [SMP]  : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
## CPU2 LIVE ##: Executing Code...
Idle Task [3] (ptrval)
Trying to bring up CPU3 ...
archs-intc  : 2 priority levels (default 1) FIRQ (not used)

IDENTITY    : ARCVER [0x52] ARCNUM [0x3] CHIPID [ 0x0]
processor [3]   : HS38 R2.1 (ARCv2 ISA) 
Timers      : Timer0 Timer1 RTC [UP 64-bit] 
ISA Extn    : atomic ll64 unalign mpy[opt 9] div_rem 
BPU     : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]    : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used) 
I-Cache     : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache     : 64K, 2way/set, 64B Line, PIPT
SLC     : 512K, 128B Line
Peripherals : 0xf0000000, IO-Coherency (per-device) 
Vector Table    : 0x90000000
FPU     : SP DP 
DEBUG       : smaRT RTT ActionPoint 8/min
Extn [CCM]  : DCCM @ 60000000, 256 KB / ICCM: @ 60000000, 256 KB
Extn [SMP]  : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
## CPU3 LIVE ##: Executing Code...
smp: Brought up 1 node, 4 CPUs
devtmpfs: initialized
random: get_random_u32 called from bucket_table_alloc.isra.0+0x4a/0x12c with crng_init=0
clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
futex hash table entries: 1024 (order: 4, 131072 bytes, linear)
NET: Registered protocol family 16
DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
thermal_sys: Registered thermal governor 'step_wise'
OF: /soc/gpio@3000/gpio-controller@0: could not find phandle
OF: /soc/gpio@3000/gpio-controller@0: could not find phandle
reg-fixed-voltage regulator-5v0: use noncoherent DMA ops
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
pps_core: LinuxPPS API ver. 1 registered
pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
PTP clock support registered
clocksource: Switched to clocksource ARConnect GFRC
NET: Registered protocol family 2
tcp_listen_portaddr_hash hash table entries: 1024 (order: 0, 12288 bytes, linear)
TCP established hash table entries: 8192 (order: 2, 32768 bytes, linear)
TCP bind hash table entries: 8192 (order: 3, 65536 bytes, linear)
TCP: Hash tables configured (established 8192 bind 8192)
UDP hash table entries: 512 (order: 1, 16384 bytes, linear)
UDP-Lite hash table entries: 512 (order: 1, 16384 bytes, linear)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
arc-pct pct: use noncoherent DMA ops
ARC perf    : 8 counters (48 bits), 113 conditions
workingset: timestamp_bits=30 max_order=17 bucket_order=0
random: fast init done
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
io scheduler mq-deadline registered
io scheduler kyber registered
snps-creg-gpio f00014b0.gpio: use noncoherent DMA ops
snps-creg-gpio f00014b0.gpio: GPIO controller with 2 gpios probed
gpio-dwapb f0003000.gpio: use noncoherent DMA ops
gpio-dwapb f0003000.gpio: no IRQ for port0
dw_axi_dmac_platform f0080000.dmac: use noncoherent DMA ops
dw_axi_dmac_platform f0080000.dmac: DesignWare AXI DMA Controller, 4 channels
hsdk-reset f00008a0.reset-controller: use noncoherent DMA ops
Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
dw-apb-uart f0005000.serial: use noncoherent DMA ops
printk: console [ttyS0] disabled
f0005000.serial: ttyS0 at MMIO 0xf0005000 (irq = 6, base_baud = 2083125) is a 16550A
printk: console [ttyS0] enabled
printk: console [ttyS0] enabled
printk: bootconsole [uart8250] disabled
printk: bootconsole [uart8250] disabled
usbcore: registered new interface driver udl
etnaviv-gpu f0090000.gpu: use noncoherent DMA ops
 (null): use noncoherent DMA ops
etnaviv etnaviv: bound f0090000.gpu (ops 0x905e617c)
etnaviv-gpu f0090000.gpu: model: GC880, revision: 5124
[drm] Initialized etnaviv 1.3.0 20151214 for etnaviv on minor 0
brd: module loaded
dw_spi_mmio f0020000.spi: use noncoherent DMA ops
spi-nor spi0.0: sst26wf016b (2048 Kbytes)
libphy: Fixed MDIO Bus: probed
stmmaceth f0008000.ethernet: use coherent DMA ops
stmmaceth f0008000.ethernet: IRQ eth_wake_irq not found
stmmaceth f0008000.ethernet: IRQ eth_lpi not found
stmmaceth f0008000.ethernet: PTP uses main clock
stmmaceth f0008000.ethernet: User ID: 0x10, Synopsys ID: 0x37
stmmaceth f0008000.ethernet:    DWMAC1000
stmmaceth f0008000.ethernet: DMA HW capability register supported
stmmaceth f0008000.ethernet: RX Checksum Offload Engine supported
stmmaceth f0008000.ethernet: COE Type 2
stmmaceth f0008000.ethernet: TX Checksum insertion supported
stmmaceth f0008000.ethernet: Normal descriptors
stmmaceth f0008000.ethernet: Ring mode enabled
stmmaceth f0008000.ethernet: Enable RX Mitigation via HW Watchdog Timer
stmmaceth f0008000.ethernet: device MAC address ee:30:ee:01:bb:e5
libphy: stmmac: probed
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ehci-platform: EHCI generic platform driver
ehci-platform f0040000.ehci: use coherent DMA ops
ehci-platform f0040000.ehci: EHCI Host Controller
ehci-platform f0040000.ehci: new USB bus registered, assigned bus number 1
ehci-platform f0040000.ehci: irq 15, io mem 0xf0040000
ehci-platform f0040000.ehci: USB 2.0 started, EHCI 1.00
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 1 port detected
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
ohci-platform: OHCI generic platform driver
ohci-platform f0060000.ohci: use coherent DMA ops
ohci-platform f0060000.ohci: Generic Platform OHCI controller
ohci-platform f0060000.ohci: new USB bus registered, assigned bus number 2
ohci-platform f0060000.ohci: irq 15, io mem 0xf0060000
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 1 port detected
usbcore: registered new interface driver usb-storage
sdhci: Secure Digital Host Controller Interface driver
sdhci: Copyright(c) Pierre Ossman
Synopsys Designware Multimedia Card Interface Driver
dw_mmc f000a000.mmc: use coherent DMA ops
sdhci-pltfm: SDHCI platform and OF driver helper
dw_mmc f000a000.mmc: IDMAC supports 32-bit address mode.
usbcore: registered new interface driver usbhid
dw_mmc f000a000.mmc: Using internal DMA controller.
usbhid: USB HID core driver
dw_mmc f000a000.mmc: Version ID is 290a
NET: Registered protocol family 10
dw_mmc f000a000.mmc: DW MMC controller at irq 12,32 bit host data width,16 deep fifo
Segment Routing with IPv6
sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
NET: Registered protocol family 17
dw-apb-uart f0005000.serial: forbid DMA for kernel console
mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 400000Hz, actual 396825HZ div = 63)
Waiting for root device /dev/mmcblk0p2...
mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 25000000Hz, actual 25000000HZ div = 1)
mmc0: new SDHC card at address aaaa
blk_queue_max_segment_size: set to minimum 8192
mmcblk0: mmc0:aaaa SC16G 14.8 GiB 
 mmcblk0: p1 p2
EXT4-fs (mmcblk0p2): recovery complete
EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
usb 1-1: new high-speed USB device number 2 using ehci-platform
VFS: Mounted root (ext4 filesystem) on device 179:2.
devtmpfs: mounted
Freeing unused kernel memory: 168K
This architecture does not have kernel memory protection.
Run /sbin/init as init process
  with arguments:
    /sbin/init
  with environment:
    HOME=/
    TERM=linux
EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Starting syslogd: OK
Starting klogd: OK
Running sysctl: OK
Initializing random number generator: OK
Saving random seed: random: dd: uninitialized urandom read (512 bytes read)
hub 1-1:1.0: USB hub found
OK
hub 1-1:1.0: 2 ports detected
Starting network: stmmaceth f0008000.ethernet eth0: PHY [stmmac-0:00] driver [Micrel KSZ9031 Gigabit PHY] (irq=POLL)
stmmaceth f0008000.ethernet eth0: No Safety Features support found
stmmaceth f0008000.ethernet eth0: PTP not supported by HW
stmmaceth f0008000.ethernet eth0: configuring for phy/rgmii-id link mode
udhcpc: started, v1.31.1
random: mktemp: uninitialized urandom read (6 bytes read)
udhcpc: sending discover
usb 1-1.2: new high-speed USB device number 3 using ehci-platform
udhcpc: sending discover
stmmaceth f0008000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
udhcpc: sending discover
udhcpc: sending select for 192.168.49.75
udhcpc: lease of 192.168.49.75 obtained, lease time 10800
deleting routers
random: mktemp: uninitialized urandom read (6 bytes read)
adding dns 192.168.48.1
adding dns 192.168.48.211
OK

Welcome to the HSDK Platform

hsdk login: root
modprobe rcutorture
rcu-torture:--- Start of test: nreaders=3 nfakewriters=4 stat_interval=60 verbose=1 test_no_idle_hz=1 shuffle_interval=3 stutter=5 irqreader=1 fqs_duration=0 fqs_holdoff=0 fqs_stutter=3 test_boost=1/0 test_boost_interval=7 test_boost_duration=4 shutdown_secs=0 stall_cpu=0 stall_cpu_holdoff=10 stall_cpu_irqsoff=0 stall_cpu_block=0 n_barrier_cbs=0 onoff_interval=0 onoff_holdoff=0 read_exit_delay=13 read_exit_burst=16
rcu:  Start-test grace-period state: g-859 f0x0
rcu-torture: Creating rcu_torture_writer task
rcu-torture: Creating rcu_torture_fakewriter task
rcu-torture: rcu_torture_writer task started
rcu-torture: Creating rcu_torture_fakewriter task
rcu_torture_writer: Testing conditional GPs.
rcu_torture_writer: Testing expedited GPs.
rcu_torture_writer: Testing asynchronous GPs.
rcu_torture_writer: Testing normal GPs.
rcu-torture: rcu_torture_fakewriter task started

When freezed trying to ping it:

> ping 192.168.49.75
Pinging 192.168.49.75 with 32 bytes of data:
Reply from 192.168.49.197: Destination host unreachable.
vineetgarc commented 3 years ago

To rule out unwinder shenanigans, can you please try the following hack. This removes stack unwinder from the picture (when top is invoked). In the mean time I'll try to reproduce it here as well.

diff --git a/fs/proc/array.c b/fs/proc/array.c
index 65ec2029fa80..48d1ac64deac 100644
--- a/fs/proc/array.c
+++ b/fs/proc/array.c
@@ -519,8 +519,6 @@ static int do_task_stat(struct seq_file *m, struct pid_namespace *ns,
                unlock_task_sighand(task, &flags);
        }

-       if (permitted && (!whole || num_threads < 2))
-               wchan = get_wchan(task);
vineetgarc commented 3 years ago

So far I can't hit the issue - with and w/o the above hack. Can you please upload your $BR/images/uImage and $BR/build/linux-5.10*/vmlinux here !

jzbydniewski commented 3 years ago

5.10-rc2.zip

vineetgarc commented 3 years ago

Thx, can u please also upload the sdcard.img as well for me to get the exact rootfs too - sorry should have asked for it previously.

vineetgarc commented 3 years ago

I've scripted this so top + rcutorture runs automatically after boot

/etc/inittab # remove login prompt

-console::respawn:/sbin/getty -L  console 0 vt100 # GENERIC_SERIAL
+::respawn:-/bin/sh

/etc/init.d/S50rcutorture # add new rcs script

#!/bin/sh
modprobe rcutorture && top
jzbydniewski commented 3 years ago

sdcard.zip

vineetgarc commented 3 years ago

To rule out unwinder shenanigans, can you please try the following hack. This removes stack unwinder from the picture (when top is invoked). In the mean time I'll try to reproduce it here as well.

diff --git a/fs/proc/array.c b/fs/proc/array.c
index 65ec2029fa80..48d1ac64deac 100644
--- a/fs/proc/array.c
+++ b/fs/proc/array.c
@@ -519,8 +519,6 @@ static int do_task_stat(struct seq_file *m, struct pid_namespace *ns,
                unlock_task_sighand(task, &flags);
        }

-       if (permitted && (!whole || num_threads < 2))
-               wchan = get_wchan(task);

I can't hit the issue on 2 of the boards I have, even with your sdcard.img. Guess this will need to be debugged on your board. Did you try adding this patch to kernel and rerun ?

jzbydniewski commented 3 years ago

I can see still this issue even with patch from the comment above. @vineetgarc , can you please provide some instructions how to debug the freeze once I see it ? Or any debug features I should add first to the linux build ?

vineetgarc commented 3 years ago

@jzbydniewski I was wondering if your board could be running at higher core or DDR clock which could cause some instability. HSDK has 2 modes of operation Slow mode: cpu @ 500 MHz, DDR @ 666 MHz Fast mode: cpu @ 1GHz, DDR @ 800 MHz

At board startup, prebootloader prints out the various clocks and PLLs. e.g. My board's output is

********************************
**       Synopsys, Inc.       **
**   ARC HS Development Kit   **
********************************
** IC revision: Rev 1.0
Bootloader revision: Jun 12 2016, 08:54:06
Bootloader location: 0x1 (internal ROM)
Bootloader aux: 0x9 (sg15E,4Gb,x8,2r)
Bootloader speedmode: Slow
Bootloader multicore: 0x0 (Single-core)
** Bootloader verbosity: Debug
** Starting HS Core 1
\(��KT��: 500 MHz
ARC-PLL idiv:
 ARC: 1
SYS-PLL: 400 MHz
SYS-PLL idiv:
 APB: 2
 AXI: 1
 ETH: 1
 USB: 1
 SDIO: 1
 HDMI: 1
 GFXCORE: 1
 GFXDMA: 1
 GFXCFG: 2
 DMACCORE: 1
 DMACCFG: 2
 SDIOREF: 4
 SPIREF: 12
 I2CREF: 2
 UARTREF: 12
 EBIREF: 8
TUNNEL-PLL: 150 MHz
TUNNEL-PLL idiv:
 TUNNEL: 3
 ROM: 1
 PWM: 2
HDMI-PLL: Bypass
HDMI-PLL idiv:
 HDMI: 1
I2S idiv:
 I2S-TX: 1
 I2S-RX: 1
DDR-PLL: 666 MHz
** HS Core running @ 500 MHz

FYI: Note that when running Linux, even if started in slow mode, core clk (only) gets bumped to 1 GHz by pll/clk driver.

vineetgarc commented 3 years ago

In parallel, it would make sense to prepare to debug this with Synopsys Metaware Debugger (using digilent tools to do the low level jtag interfacing). In a debugging setup instead of booting the autobooting into uboot and kernel uImage, you would download the kernel elf binary (vmlinux) directly onto the target and run (after which it is same as original setup). You could halt yhe target, setup breakpoints, enable smART tracing etc.

abrodkin commented 3 years ago

@jzbydniewski also it would be interesting to see you U-Boot settings. To get it you need to stop U-Boot by pressing any key in the serial console while U-Boot is counting down and then execute printenv command. Its output please paste here for our review.

jzbydniewski commented 3 years ago

U-Boot settings and clocks below:

hsdk# printenv axi_freq=400 baudrate=115200 bootargs=root=/dev/mmcblk0p2 rootwait bootcmd=fatload mmc 0:1; bootm bootdelay=2 bootfile=uImage cpu_freq=500 fdtcontroladdr=bffaa170 loadaddr=0x82000000 stderr=serial0@f0005000 stdin=serial0@f0005000 stdout=serial0@f0005000 tun_freq=50

hsdk# hsdk_clock print_all HSDK: clock 'cpu-pll' rate 500 MHz HSDK: clock 'cpu-clk' rate 500 MHz

HSDK: clock 'sys-pll' rate 400 MHz HSDK: clock 'apb-clk' rate 200 MHz HSDK: clock 'axi-clk' rate 400 MHz HSDK: clock 'eth-clk' rate 400 MHz HSDK: clock 'usb-clk' rate 400 MHz HSDK: clock 'sdio-clk' rate 400 MHz HSDK: clock 'gfx-core-clk' rate 400 MHz HSDK: clock 'gfx-dma-clk' rate 400 MHz HSDK: clock 'gfx-cfg-clk' rate 200 MHz HSDK: clock 'dmac-core-clk' rate 400 MHz HSDK: clock 'dmac-cfg-clk' rate 200 MHz HSDK: clock 'sdio-ref-clk' rate 100 MHz HSDK: clock 'spi-clk' rate 34 MHz HSDK: clock 'i2c-clk' rate 200 MHz HSDK: clock 'uart-clk' rate 34 MHz

HSDK: clock 'ddr-clk' rate 334 MHz

HSDK: clock 'tun-pll' rate 150 MHz HSDK: clock 'tun-clk' rate 50 MHz HSDK: clock 'rom-clk' rate 150 MHz HSDK: clock 'pwm-clk' rate 75 MHz

hsdk# hsdk_clock print_all - Print all clock values to console HSDK: clock 'cpu-pll' rate 500 MHz HSDK: clock 'cpu-clk' rate 500 MHz

HSDK: clock 'sys-pll' rate 400 MHz HSDK: clock 'apb-clk' rate 200 MHz HSDK: clock 'axi-clk' rate 400 MHz HSDK: clock 'eth-clk' rate 400 MHz HSDK: clock 'usb-clk' rate 400 MHz HSDK: clock 'sdio-clk' rate 400 MHz HSDK: clock 'gfx-core-clk' rate 400 MHz HSDK: clock 'gfx-dma-clk' rate 400 MHz HSDK: clock 'gfx-cfg-clk' rate 200 MHz HSDK: clock 'dmac-core-clk' rate 400 MHz HSDK: clock 'dmac-cfg-clk' rate 200 MHz HSDK: clock 'sdio-ref-clk' rate 100 MHz HSDK: clock 'spi-clk' rate 34 MHz HSDK: clock 'i2c-clk' rate 200 MHz HSDK: clock 'uart-clk' rate 34 MHz

HSDK: clock 'ddr-clk' rate 334 MHz

HSDK: clock 'tun-pll' rate 150 MHz HSDK: clock 'tun-clk' rate 50 MHz HSDK: clock 'rom-clk' rate 150 MHz HSDK: clock 'pwm-clk' rate 75 MHz

After Linux boot cat /proc/cpuinfo shows CPU running @1GHz.

cat /proc/cpuinfo

IDENTITY : ARCVER [0x52] ARCNUM [0x0] CHIPID [ 0x0] processor [0] : HS38 R2.1 (ARCv2 ISA) Timers : Timer0 Timer1 RTC [UP 64-bit] GFRC [SMP 64-bit] ISA Extn : atomic ll64 unalign mpy[opt 9] div_rem BPU : full match, cache:2048, Predict Table:16384 Return stk: 8 CPU speed : 999.99 Mhz Bogo MIPS : 997.78 MMU [v4] : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used) I-Cache : 64K, 4way/set, 64B Line, VIPT aliasing D-Cache : 64K, 2way/set, 64B Line, PIPT SLC : 512K, 128B Line Peripherals : 0xf0000000, IO-Coherency (per-device) Vector Table : 0x90000000 FPU : SP DP DEBUG : smaRT RTT ActionPoint 8/min Extn [SMP] : ARConnect (v2): 4 cores with IPI IDU DEBUG GFR [...]

evgeniy-paltsev commented 3 years ago

Note that when running Linux, even if started in slow mode, core clk (only) gets bumped to 1 GHz by pll/clk driver.

To avoid changing clock to 1GHz while booting kernel we can tweak clock rate in HSDK dts. Here is the patch:

diff --git a/arch/arc/boot/dts/hsdk.dts b/arch/arc/boot/dts/hsdk.dts
index 9acbeba832c0..0bc764f778d1 100644
--- a/arch/arc/boot/dts/hsdk.dts
+++ b/arch/arc/boot/dts/hsdk.dts
@@ -130,7 +130,7 @@
                         * on early boot.
                         */
                        assigned-clocks = <&core_clk>;
-                       assigned-clock-rates = <1000000000>;
+                       assigned-clock-rates = <500000000>;
                };

                serial: serial@5000 {

@jzbydniewski could you please test if the issue reproduces with 500MHz CPU clock?

It require to rebuild kernel (as we have dts built-in), however as you have previous buildroot build you can tweak clock rate in kernel sources (output/build/linux-x.xx directory) and run make linux && make from buildroot top directory.

vineetgarc commented 3 years ago

Changed the title to reflect the fact that this happens on latest 5.10-rcX kernels too.

jzbydniewski commented 3 years ago

I changed the CPU clock to 500MHz and couldn't reproduce the issue (tried several times to power off/on board). Going back to 1GHz and after few times of power off/on I can see it's stuck at boot:

reading uImage
4426621 bytes read in 192 ms (22 MiB/s)
## Booting kernel from Legacy Image at 82000000 ...
   Image Name:   Linux-5.10.0-rc2
   Image Type:   ARC Linux Kernel Image (gzip compressed)
   Data Size:    4426557 Bytes = 4.2 MiB
   Load Address: 90000000
   Entry Point:  90004000
   Verifying Checksum ... OK
   Uncompressing Kernel Image ... OK
CPU start mask is 0xf

Starting kernel ...

Linux version 5.10.0-rc2 (jzbydniewski@plkatselectra) (arc-buildroot-linux-uclibc-gcc.br_real (Buildroot 2020.08.1) 9.3.1 20200315, GNU ld (GNU Binutils) 2.34.50.20200307) #7 SMP PREEMPT Wed Nov 25 08:09:01 CET 2020
Memory @ 80000000 [1024M]
OF: fdt: Machine model: snps,hsdk
earlycon: uart8250 at MMIO32 0xf0005000 (options '115200n8')
printk: bootconsole [uart8250] enabled
Failed to get possible-cpus from dtb, pretending all 4 cpus exist
archs-intc      : 2 priority levels (default 1) FIRQ (not used)

IDENTITY        : ARCVER [0x52] ARCNUM [0x0] CHIPID [ 0x0]
processor [0]   : HS38 R2.1 (ARCv2 ISA)
Timers          : Timer0 Timer1 RTC [UP 64-bit] GFRC [SMP 64-bit]
ISA Extn        : atomic ll64 unalign mpy[opt 9] div_rem
BPU             : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]        : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used)
I-Cache         : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache         : 64K, 2way/set, 64B Line, PIPT
SLC             : 512K, 128B Line
Peripherals     : 0xf0000000, IO-Coherency (per-device)
Vector Table    : 0x90000000
FPU             : SP DP
DEBUG           : smaRT RTT ActionPoint 8/min
Extn [SMP]      : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
Zone ranges:
  Normal   [mem 0x0000000080000000-0x00000000bfffffff]
Movable zone start for each node
Early memory node ranges
  node   0: [mem 0x0000000080000000-0x00000000bfffffff]
Initmem setup node 0 [mem 0x0000000080000000-0x00000000bfffffff]
On node 0 totalpages: 131072
  Normal zone: 576 pages used for memmap
  Normal zone: 0 pages reserved
  Normal zone: 131072 pages, LIFO batch:31
percpu: Embedded 7 pages/cpu s23168 r8192 d25984 u57344
pcpu-alloc: s23168 r8192 d25984 u57344 alloc=7*8192
pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
Built 1 zonelists, mobility grouping on.  Total pages: 130496
Kernel command line: earlycon=uart8250,mmio32,0xf0005000,115200n8 console=ttyS0,115200n8 debug print-fatal-signals=1 root=/dev/mmcblk0p2 rootwait
Dentry cache hash table entries: 131072 (order: 6, 524288 bytes, linear)
Inode-cache hash table entries: 65536 (order: 5, 262144 bytes, linear)
mem auto-init: stack:off, heap alloc:off, heap free:off
Memory: 1033472K/1048576K available (5693K kernel code, 641K rwdata, 1312K rodata, 168K init, 302K bss, 15104K reserved, 0K cma-reserved)
rcu: Preemptible hierarchical RCU implementation.
rcu:    RCU event tracing is enabled.
        Trampoline variant of Tasks RCU enabled.
        Rude variant of Tasks RCU enabled.
        Tracing variant of Tasks RCU enabled.
rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
NR_IRQS: 512
MCIP: IDU supports 64 common irqs
sched_clock: 64 bits at 999MHz, resolution 1ns, wraps every 4398046511103ns
clocksource: ARConnect GFRC: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
Console: colour dummy device 80x25
Calibrating delay loop... 997.78 BogoMIPS (lpj=4988928)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 2048 (order: 0, 8192 bytes, linear)
Mountpoint-cache hash table entries: 2048 (order: 0, 8192 bytes, linear)
rcu: Hierarchical SRCU implementation.
smp: Bringing up secondary CPUs ...
Idle Task [1] (ptrval)
Trying to bring up CPU1 ...
archs-intc      : 2 priority levels (default 1) FIRQ (not used)

IDENTITY        : ARCVER [0x52] ARCNUM [0x1] CHIPID [ 0x0]
processor [1]   : HS38 R2.1 (ARCv2 ISA)
Timers          : Timer0 Timer1 RTC [UP 64-bit]
ISA Extn        : atomic ll64 unalign mpy[opt 9] div_rem
BPU             : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]        : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used)
I-Cache         : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache         : 64K, 2way/set, 64B Line, PIPT
SLC             : 512K, 128B Line
Peripherals     : 0xf0000000, IO-Coherency (per-device)
Vector Table    : 0x90000000
FPU             : SP DP
DEBUG           : smaRT RTT ActionPoint 8/min
Extn [CCM]      : DCCM @ 60000000, 256 KB / ICCM: @ 60000000, 256 KB
Extn [SMP]      : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
## CPU1 LIVE ##: Executing Code...
Idle Task [2] (ptrval)
Trying to bring up CPU2 ...
archs-intc      : 2 priority levels (default 1) FIRQ (not used)

IDENTITY        : ARCVER [0x52] ARCNUM [0x2] CHIPID [ 0x0]
processor [2]   : HS38 R2.1 (ARCv2 ISA)
Timers          : Timer0 Timer1 RTC [UP 64-bit]
ISA Extn        : atomic ll64 unalign mpy[opt 9] div_rem
BPU             : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]        : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used)
I-Cache         : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache         : 64K, 2way/set, 64B Line, PIPT
SLC             : 512K, 128B Line
Peripherals     : 0xf0000000, IO-Coherency (per-device)
Vector Table    : 0x90000000
FPU             : SP DP
DEBUG           : smaRT RTT ActionPoint 8/min
Extn [SMP]      : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
## CPU2 LIVE ##: Executing Code...
Idle Task [3] (ptrval)
Trying to bring up CPU3 ...
archs-intc      : 2 priority levels (default 1) FIRQ (not used)

IDENTITY        : ARCVER [0x52] ARCNUM [0x3] CHIPID [ 0x0]
processor [3]   : HS38 R2.1 (ARCv2 ISA)
Timers          : Timer0 Timer1 RTC [UP 64-bit]
ISA Extn        : atomic ll64 unalign mpy[opt 9] div_rem
BPU             : full match, cache:2048, Predict Table:16384 Return stk: 8
MMU [v4]        : 8k PAGE, 2M Super Page (not used) JTLB 1024 (256x4), uDTLB 8, uITLB 4, PAE40 (not used)
I-Cache         : 64K, 4way/set, 64B Line, VIPT aliasing
D-Cache         : 64K, 2way/set, 64B Line, PIPT
SLC             : 512K, 128B Line
Peripherals     : 0xf0000000, IO-Coherency (per-device)
Vector Table    : 0x90000000
FPU             : SP DP
DEBUG           : smaRT RTT ActionPoint 8/min
Extn [CCM]      : DCCM @ 60000000, 256 KB / ICCM: @ 60000000, 256 KB
Extn [SMP]      : ARConnect (v2): 4 cores with IPI IDU DEBUG GFRC
## CPU3 LIVE ##: Executing Code...
smp: Brought up 1 node, 4 CPUs
devtmpfs: initialized
random: get_random_u32 called from bucket_table_alloc.isra.0+0x4a/0x12c with crng_init=0
clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
futex hash table entries: 1024 (order: 4, 131072 bytes, linear)
NET: Registered protocol family 16
DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
thermal_sys: Registered thermal governor 'step_wise'
OF: /soc/gpio@3000/gpio-controller@0: could not find phandle
OF: /soc/gpio@3000/gpio-controller@0: could not find phandle
reg-fixed-voltage regulator-5v0: use noncoherent DMA ops
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
pps_core: LinuxPPS API ver. 1 registered
pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
PTP clock support registered
clocksource: Switched to clocksource ARConnect GFRC
NET: Registered protocol family 2
tcp_listen_portaddr_hash hash table entries: 1024 (order: 0, 12288 bytes, linear)
TCP established hash table entries: 8192 (order: 2, 32768 bytes, linear)
TCP bind hash table entries: 8192 (order: 3, 65536 bytes, linear)
TCP: Hash tables configured (established 8192 bind 8192)
UDP hash table entries: 512 (order: 1, 16384 bytes, linear)
UDP-Lite hash table entries: 512 (order: 1, 16384 bytes, linear)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
arc-pct pct: use noncoherent DMA ops
ARC perf        : 8 counters (48 bits), 113 conditions
workingset: timestamp_bits=30 max_order=17 bucket_order=0
random: fast init done
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
io scheduler mq-deadline registered
io scheduler kyber registered
snps-creg-gpio f00014b0.gpio: use noncoherent DMA ops
snps-creg-gpio f00014b0.gpio: GPIO controller with 2 gpios probed
gpio-dwapb f0003000.gpio: use noncoherent DMA ops
gpio-dwapb f0003000.gpio: no IRQ for port0
dw_axi_dmac_platform f0080000.dmac: use noncoherent DMA ops
dw_axi_dmac_platform f0080000.dmac: DesignWare AXI DMA Controller, 4 channels
hsdk-reset f00008a0.reset-controller: use noncoherent DMA ops
Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
dw-apb-uart f0005000.serial: use noncoherent DMA ops
printk: console [ttyS0] disabled
f0005000.serial: ttyS0 at MMIO 0xf0005000 (irq = 6, base_baud = 2083125) is a 16550A
printk: console [ttyS0] enabled
printk: console [ttyS0] enabled
printk: bootconsole [uart8250] disabled
printk: bootconsole [uart8250] disabled
usbcore: registered new interface driver udl
etnaviv-gpu f0090000.gpu: use noncoherent DMA ops
 (null): use noncoherent DMA ops
etnaviv etnaviv: bound f0090000.gpu (ops 0x905e617c)
etnaviv-gpu f0090000.gpu: model: GC880, revision: 5124
[drm] Initialized etnaviv 1.3.0 20151214 for etnaviv on minor 0
brd: module loaded
dw_spi_mmio f0020000.spi: use noncoherent DMA ops
spi-nor spi0.0: sst26wf016b (2048 Kbytes)
libphy: Fixed MDIO Bus: probed
stmmaceth f0008000.ethernet: use coherent DMA ops
stmmaceth f0008000.ethernet: IRQ eth_wake_irq not found
stmmaceth f0008000.ethernet: IRQ eth_lpi not found
stmmaceth f0008000.ethernet: PTP uses main clock
stmmaceth f0008000.ethernet: User ID: 0x10, Synopsys ID: 0x37
stmmaceth f0008000.ethernet:    DWMAC1000
stmmaceth f0008000.ethernet: DMA HW capability register supported
stmmaceth f0008000.ethernet: RX Checksum Offload Engine supported
stmmaceth f0008000.ethernet: COE Type 2
stmmaceth f0008000.ethernet: TX Checksum insertion supported
stmmaceth f0008000.ethernet: Normal descriptors
stmmaceth f0008000.ethernet: Ring mode enabled
stmmaceth f0008000.ethernet: Enable RX Mitigation via HW Watchdog Timer
stmmaceth f0008000.ethernet: device MAC address ae:6b:ef:24:57:aa
libphy: stmmac: probed
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ehci-platform: EHCI generic platform driver
ehci-platform f0040000.ehci: use coherent DMA ops
ehci-platform f0040000.ehci: EHCI Host Controller
ehci-platform f0040000.ehci: new USB bus registered, assigned bus number 1
ehci-platform f0040000.ehci: irq 15, io mem 0xf0040000
ehci-platform f0040000.ehci: USB 2.0 started, EHCI 1.00
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 1 port detected
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
ohci-platform: OHCI generic platform driver
ohci-platform f0060000.ohci: use coherent DMA ops
ohci-platform f0060000.ohci: Generic Platform OHCI controller
ohci-platform f0060000.ohci: new USB bus registered, assigned bus number 2
ohci-platform f0060000.ohci: irq 15, io mem 0xf0060000
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 1 port detected
usbcore: registered new interface driver usb-storage
sdhci: Secure Digital Host Controller Interface driver
sdhci: Copyright(c) Pierre Ossman
Synopsys Designware Multimedia Card Interface Driver
dw_mmc f000a000.mmc: use coherent DMA ops
sdhci-pltfm: SDHCI platform and OF driver helper
dw_mmc f000a000.mmc: IDMAC supports 32-bit address mode.
usbcore: registered new interface driver usbhid
dw_mmc f000a000.mmc: Using internal DMA controller.
usbhid: USB HID core driver
dw_mmc f000a000.mmc: Version ID is 290a
NET: Registered protocol family 10
dw_mmc f000a000.mmc: DW MMC controller at irq 12,32 bit host data width,16 deep fifo
Segment Routing with IPv6
sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
NET: Registered protocol family 17
dw-apb-uart f0005000.serial: forbid DMA for kernel console
mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 400000Hz, actual 396825HZ div = 63)
Waiting for root device /dev/mmcblk0p2...
mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 25000000Hz, actual 25000000HZ div = 1)
mmc0: new SDHC card at address aaaa
blk_queue_max_segment_size: set to minimum 8192
mmcblk0: mmc0:aaaa SC16G 14.8 GiB
 mmcblk0: p1 p2
EXT4-fs (mmcblk0p2): recovery complete
usb 1-1: new high-speed USB device number 2 using ehci-platform
EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
VFS: Mounted root (ext4 filesystem) on device 179:2.
devtmpfs: mounted
Freeing unused kernel memory: 168K
This architecture does not have kernel memory protection.
Run /sbin/init as init process
  with arguments:
    /sbin/init
  with environment:
    HOME=/
    TERM=linux
EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Starting syslogd: OK
Starting klogd: OK
Running sysctl: OK
Initializing random number generator: OK
Saving random seed: random: dd: uninitialized urandom read (512 bytes read)
OK
hub 1-1:1.0: USB hub found
hub 1-1:1.0: 2 ports detected
Starting network:
vineetgarc commented 3 years ago

Can we close this issue with workaround to run board @ 500 MHz ?