Hi,
* H. Nikolaus Schaller hns@goldelico.com [180910 20:31]:
Now, I get something for further analysis, which indicates how the kernel is stumbling...
Oh that same old omap5 reboot clock issue. Adding Tero and Peter to Cc.
Can you please also set this up as a bug at bugzilla.kernel.org? We've already seen this before but I don't think there was any solution.
Regards,
Tony
root@letux:~# dmesg|fgrep early [ 0.000000] Malformed early option 'console' [ 0.000000] earlycon: omapserial0 at MMIO 0x48020000 (options '')
^^^ ok, earlycon is working :)
[ 0.000000] Kernel command line: console= root=PARTUUID=7d45bc20-02 rw rootfstype=ext4 rootwait console=ttyO2,115200n8 vram=12M omapfb.vram=0:8M,1:4M omapfb.rotate_type=0 omapdss.def_disp=lcd rootwait twl4030_charger.allow_usb=1 log_buf_len=8M ignore_loglevel earlyprintk earlycon [ 0.000000] early log buf free: 63696(97%) root@letux:~# reboot
Broadcast message from root@letux (console) (Mon Sep 10 20:05:16 2018):
The system is going down for reboot NOW!
....
[ 164.453708] reboot: Restarting system
U-Boot SPL 2016.11-00292-g12720df (Aug 12 2018 - 18:32:51) OMAP5432-GP ES2.0
....
## Booting kernel from Legacy Image at 82000000 ... Image Name: Linux-4.18.0-letux+ Image Type: ARM Linux Kernel Image (uncompressed) Data Size: 4901632 Bytes = 4.7 MiB Load Address: 80008000 Entry Point: 80008000 Verifying Checksum ... OK ## Flattened Device Tree blob at 88000000 Booting using the fdt blob at 0x88000000 Loading Kernel Image ... OK Loading Device Tree to 8ffed000, end 8fffff57 ... OK
Starting kernel ...
[ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 4.18.0-letux+ (hns@iMac.fritz.box) (gcc version 4.9.2 (GCC)) #2664 SMP PREEMPT Mon Sep 10 20:46:49 CEST 2018 [ 0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d [ 0.000000] CPU: div instructions available: patching division code [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache [ 0.000000] OF: fdt: Machine model: Pyra-Handheld-V5.1.2ff [ 0.000000] Malformed early option 'console' [ 0.000000] debug: ignoring loglevel setting. [ 0.000000] earlycon: omapserial0 at MMIO 0x48020000 (options '') [ 0.000000] bootconsole [omapserial0] enabled [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] cma: Reserved 16 MiB at 0xfd800000 [ 0.000000] OMAP4: Map 0xfee00000 to (ptrval) for dram barrier [ 0.000000] On node 0 totalpages: 519680 [ 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: 323072 pages, LIFO batch:31 [ 0.000000] OMAP5432 ES2.0 [ 0.000000] random: get_random_bytes called from start_kernel+0x80/0x470 with crng_init=0 [ 0.000000] percpu: Embedded 17 pages/cpu @(ptrval) s40320 r8192 d21120 u69632 [ 0.000000] pcpu-alloc: s40320 r8192 d21120 u69632 alloc=17*4096 [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 518144 [ 0.000000] Kernel command line: console= root=PARTUUID=7d45bc20-02 rw rootfstype=ext4 rootwait console=ttyO2,115200n8 vram=12M omapfb.vram=0:8M,1:4M omapfb.rotate_type=0 omapdss.def_disp=lcd rootwait twl4030_charger.allow_usb=1 log_buf_len=8M ignore_loglevel earlyprintk earlycon [ 0.000000] log_buf_len: 8388608 bytes [ 0.000000] early log buf free: 63696(97%) [ 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: 2025568K/2078720K available (6823K kernel code, 653K rwdata, 1824K rodata, 1024K init, 221K bss, 36768K reserved, 16384K cma-reserved, 1275904K 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 : 0x(ptrval) - 0x(ptrval) (7816 kB) [ 0.000000] .init : 0x(ptrval) - 0x(ptrval) (1024 kB) [ 0.000000] .data : 0x(ptrval) - 0x(ptrval) ( 654 kB) [ 0.000000] .bss : 0x(ptrval) - 0x(ptrval) ( 222 kB) [ 0.000000] Preemptible hierarchical RCU implementation. [ 0.000000] RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2. [ 0.000000] Tasks RCU enabled. [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2 [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] clock: dpll_abe_ck failed transition to 'locked' [ 0.000000] OMAP clockevent source: timer1 at 32768 Hz [ 0.000000] arch_timer: cp15 timer(s) running at 6.14MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16ac02862, max_idle_ns: 440795202218 ns [ 0.000005] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511085ns [ 0.008218] Switching to timer-based delay loop, resolution 162ns [ 0.015171] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns [ 0.025273] OMAP clocksource: 32k_counter at 32768 Hz [ 0.031722] Console: colour dummy device 80x30 [ 0.036209] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.28 BogoMIPS (lpj=61440) [ 0.046753] pid_max: default: 32768 minimum: 301 [ 0.051557] Security Framework initialized [ 0.055723] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.062482] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.070125] CPU: Testing write buffer coherency: ok [ 0.075087] CPU0: Spectre v2: firmware did not set auxiliary control register IBE bit, system vulnerable [ 0.084971] /cpus/cpu@0 missing clock-frequency property [ 0.090363] /cpus/cpu@1 missing clock-frequency property [ 0.095794] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.101610] smp: CPU1 parked within kernel, needs reset (0x0 0x801248a0) [ 0.161732] Setting up static identity map for 0x80100000 - 0x80100060 [ 0.168443] Hierarchical SRCU implementation. [ 0.212907] smp: Bringing up secondary CPUs ... [ 0.273213] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.273219] CPU1: Spectre v2: using ICIALLU workaround [ 0.284313] smp: Brought up 1 node, 2 CPUs [ 0.288434] SMP: Total of 2 processors activated (24.57 BogoMIPS). [ 0.294807] CPU: All CPU(s) started in HYP mode. [ 0.299509] CPU: Virtualization extensions available. [ 0.305759] devtmpfs: initialized [ 0.319718] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0 [ 0.327882] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.337934] futex hash table entries: 512 (order: 3, 32768 bytes) [ 0.344594] pinctrl core: initialized pinctrl subsystem [ 0.350243] really_probe: driver reg-dummy for reg-dummy bus platform [ 0.357023] really_probe: driver reg-dummy for reg-dummy bus platform ok (1) [ 0.364644] NET: Registered protocol family 16 [ 0.370796] DMA: preallocated 256 KiB pool for atomic coherent allocations [ 0.378566] omap_hwmod: l3_main_3 using broken dt data from ocp [ 0.385175] omap_hwmod: l3_main_2 using broken dt data from ocp [ 1.723766] clock: dpll_abe_ck failed transition to 'locked'
^^^ this seems to be different
[ 3.028640] clock: dpll_abe_ck failed transition to 'locked' [ 4.333541] clock: dpll_abe_ck failed transition to 'locked' [ 5.638412] clock: dpll_abe_ck failed transition to 'locked' [ 6.939455] clock: dpll_abe_ck failed transition to 'locked' [ 6.947796] ------------[ cut here ]------------ [ 6.952460] WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:814 clk_core_disable_lock+0x18/0x24 [ 6.961024] aess_fclk already disabled [ 6.964864] Modules linked in: [ 6.967995] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.18.0-letux+ #2664 [ 6.974954] Hardware name: Generic OMAP5 (Flattened Device Tree) [ 6.981136] [<c01112c8>] (unwind_backtrace) from [<c010c87c>] (show_stack+0x10/0x14) [ 6.989075] [<c010c87c>] (show_stack) from [<c078f894>] (dump_stack+0x7c/0x9c) [ 6.996489] [<c078f894>] (dump_stack) from [<c0132848>] (__warn+0xd8/0x108) [ 7.003632] [<c0132848>] (__warn) from [<c01328bc>] (warn_slowpath_fmt+0x44/0x6c) [ 7.011313] [<c01328bc>] (warn_slowpath_fmt) from [<c049d44c>] (clk_core_disable_lock+0x18/0x24) [ 7.020335] [<c049d44c>] (clk_core_disable_lock) from [<c01200b8>] (_disable_clocks+0x18/0x70) [ 7.029177] [<c01200b8>] (_disable_clocks) from [<c012116c>] (_enable+0x1ec/0x230) [ 7.036947] [<c012116c>] (_enable) from [<c012259c>] (_setup.part.16+0xc8/0x404) [ 7.044537] [<c012259c>] (_setup.part.16) from [<c01215c8>] (_setup+0x14/0x1c) [ 7.051949] [<c01215c8>] (_setup) from [<c01216b4>] (omap_hwmod_for_each+0x3c/0x64) [ 7.059810] [<c01216b4>] (omap_hwmod_for_each) from [<c0a0db90>] (__omap_hwmod_setup_all+0xa4/0xc0) [ 7.069099] [<c0a0db90>] (__omap_hwmod_setup_all) from [<c0102eb4>] (do_one_initcall+0xc0/0x268) [ 7.078121] [<c0102eb4>] (do_one_initcall) from [<c0a01050>] (kernel_init_freeable+0x220/0x36c) [ 7.087050] [<c0a01050>] (kernel_init_freeable) from [<c07a25dc>] (kernel_init+0x8/0x110) [ 7.095443] [<c07a25dc>] (kernel_init) from [<c01010e8>] (ret_from_fork+0x14/0x2c) [ 7.103207] Exception stack(0xed8adfb0 to 0xed8adff8) [ 7.108390] dfa0: 00000000 00000000 00000000 00000000 [ 7.116786] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 7.125180] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 7.131971] ---[ end trace 02345015e7dc8e1f ]--- [ 7.136720] omap_hwmod: aess: _wait_target_ready failed: -16 [ 7.142511] omap_hwmod: aess: cannot be enabled for reset (3) [ 8.447580] clock: dpll_abe_ck failed transition to 'locked' [ 9.752444] clock: dpll_abe_ck failed transition to 'locked'
--- and then everything hangs
If I enforce a warm RESET, the Pyra boots again up to the same point of failure. I have to power-off and on again through Palmas to get it booting again.
Searching for "clock: dpll_abe_ck failed transition to 'locked'" leads to:
https://e2e.ti.com/support/omap/f/885/t/328485?dpll-abe-ck-failed-transition...
And:
https://www.pyra-handheld.com/pipermail/kernel/2016-May/000877.html
So we had discussed this already a while ago but did not find a solution...
Maybe I should try to disable ABE/AESS for the next experiment (not today). An try the same on OMAP5EVM (to find out if there are hardware dependencies involved).
BR and thanks, Nikolaus