OMAP4460 cpufreq crashes

* OMAP4460 cpufreq crashes
@ 2021-05-06 15:35 Florian Boor
  2021-05-07  5:47 ` Tony Lindgren
  0 siblings, 1 reply; 5+ messages in thread
From: Florian Boor @ 2021-05-06 15:35 UTC (permalink / raw)
  To: linux-omap

[-- Attachment #1: Type: text/plain, Size: 1437 bytes --]

Hi all,

I recently spent some time with an OMAP4460 based Variscite VAR-STK-OM44 and
latest Linux releases and latest linux-omap Git. The evaluation kit runs pretty
well unless I try to enable cpufeq. This causes a crash with quite random
backtraces right on boot within a few seconds after entering userspace.

It turned out that this happens when the board switches to 920MHz. Commenting
out this operating point in the devicetree fixes this issue... but limits
performance quite a lot.

I did some research and I'd say its related to problems with voltage regulation.
I can watch the scaling driver changing the clock but for some reason the
voltage does not seem to get adjusted.
Might this behaviour be related to the OMAP infrastructure changes?

There are some messages at boot which might be related:

twl: not initialized
[    2.148742] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs
max 1316660
[    2.156799] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs
max 1316660
...

There is a little patch around that changes the initialisation order which makes
this messages go away but does not fix the odd behaviour. So maybe this is just
a cosmetic issue and the actual problem is somewhere else.

I have some kernel experience but not that much with the latest OMAP development
and therefore would be happy about some pointers what might be wrong. A boot log
is attached.

Greetings

Florian

[-- Attachment #2: log-fixes.txt --]
[-- Type: text/plain, Size: 18040 bytes --]

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.12.0-rc2 (fuchs@corey) (arm-poky-linux-gnueabi-gcc (GCC) 8.3.0, GNU ld (GNU Bin
utils) 2.32.0.20190204) #36 SMP Wed May 5 16:54:13 CEST 2021
[    0.000000] CPU: ARMv7 Processor [412fc09a] revision 10 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Variscite VAR-DVK-OM44
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 16 MiB at 0xbf000000
[    0.000000] OMAP4: Map 0xafe00000 to (ptrval) for dram barrier
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000080000000-0x00000000afdfffff]
[    0.000000]   HighMem  [mem 0x00000000afe00000-0x00000000bfffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000080000000-0x00000000afdfffff]
[    0.000000]   node   0: [mem 0x00000000b0000000-0x00000000bfffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x00000000bfffffff]
[    0.000000] OMAP4460 ES1.1
[    0.000000] percpu: Embedded 20 pages/cpu s49612 r8192 d24116 u81920
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 259908
[    0.000000] Kernel command line: rootwait root=/dev/mmcblk0p3 mem=1G@0x80000000 rw console=ttyO2,115200n8 f
bcon=map:0 vt.global_cursor_default=0 splash plymouth.ignore-serial-consoles consoleblank=0 omapfb.vram=0:4M f
bcon=rotate:3 loglevel=7
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 1005028K/1046528K available (9216K kernel code, 1028K rwdata, 2224K rodata, 1024K init,
 246K bss, 25116K reserved, 16384K cma-reserved, 245760K highmem)
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] L2C: platform modifies aux control register: 0x0e070000 -> 0x3e470000
[    0.000000] L2C: DT/platform modifies aux control register: 0x0e070000 -> 0x3e470000
[    0.000000] L2C-310 enabling early BRESP for Cortex-A9
[    0.000000] OMAP L2C310: ROM does not support power control setting
[    0.000000] L2C-310 dynamic clock gating disabled, standby mode disabled
[    0.000000] L2C-310 cache controller enabled, 16 ways, 1024 kB
[    0.000000] L2C-310: CACHE_ID 0x410000c7, AUX_CTRL 0x4e470000
[    0.000000] random: get_random_bytes called from start_kernel+0x340/0x58c with crng_init=0
[    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000000] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 
ns
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 65535999984741ns
[    0.001190] TI gptimer clockevent: always-on 32768 Hz at /ocp/interconnect@4a300000/segment@10000/target-mo
dule@8000
[    0.004425] Console: colour dummy device 80x30
[    0.004455] WARNING: Your 'console=ttyO2' has been replaced by 'ttyS2'
[    0.004486] This ensures that you still see kernel messages. Please
[    0.004486] update your kernel commandline.
[    0.004516] Calibrating delay loop... 1397.55 BogoMIPS (lpj=6987776)
[    0.089874] pid_max: default: 32768 minimum: 301
[    0.090057] LSM: Security Framework initializing
[    0.090148] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.090179] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.091094] CPU: Testing write buffer coherency: ok
[    0.091156] CPU0: Spectre v2: using BPIALL workaround
[    0.091339] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.091979] Setting up static identity map for 0x80100000 - 0x80100078
[    0.092163] rcu: Hierarchical SRCU implementation.
[    0.092651] smp: Bringing up secondary CPUs ...
[    0.179840] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.179870] CPU1: Spectre v2: using BPIALL workaround
[    0.180053] smp: Brought up 1 node, 2 CPUs
[    0.180053] SMP: Total of 2 processors activated (2795.11 BogoMIPS).
[    0.180084] CPU: All CPU(s) started in SVC mode.
[    0.180633] devtmpfs: initialized
[    0.197998] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[    0.198303] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 n
s
[    0.198333] futex hash table entries: 512 (order: 3, 32768 bytes, linear)
[    0.199798] pinctrl core: initialized pinctrl subsystem
[    0.201049] NET: Registered protocol family 16
[    0.203857] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.205505] omap_hwmod: l3_main_3 using broken dt data from ocp
[    0.206817] omap_hwmod: l3_main_2 using broken dt data from ocp
[    0.216949] audit: initializing netlink subsys (disabled)
[    0.217163] audit: type=2000 audit(0.210:1): state=initialized audit_enabled=0 res=1
[    0.217773] thermal_sys: Registered thermal governor 'fair_share'
[    0.217773] thermal_sys: Registered thermal governor 'step_wise'
[    0.217803] thermal_sys: Registered thermal governor 'user_space'
[    0.218414] cpuidle: using governor menu
[    0.273864] No ATAGs?
[    0.273956] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
[    0.273986] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.284484] Kprobes globally optimized
[    0.294738] iommu: Default domain type: Translated 
[    0.296386] vgaarb: loaded
[    0.296813] SCSI subsystem initialized
[    0.297607] pps_core: LinuxPPS API ver. 1 registered
[    0.297637] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.297668] PTP clock support registered
[    0.298858] clocksource: Switched to clocksource 32k_counter
[    0.333892] VFS: Disk quotas dquot_6.6.0
[    0.333984] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.343597] NET: Registered protocol family 2
[    1.085723] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.085754] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    1.085876] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    1.086029] TCP: Hash tables configured (established 8192 bind 8192)
[    1.086120] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.086212] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.086425] NET: Registered protocol family 1
[    1.087097] RPC: Registered named UNIX socket transport module.
[    1.087127] RPC: Registered udp transport module.
[    1.087127] RPC: Registered tcp transport module.
[    1.087158] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.087158] PCI: CLS 0 bytes, default 64
[    1.088470] hw perfevents: no interrupt-affinity property for /pmu, guessing.
[    1.088714] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
[    1.090423] Initialise system trusted keyrings
[    1.090637] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    1.091613] NFS: Registering the id_resolver key type
[    1.091644] Key type id_resolver registered
[    1.091674] Key type id_legacy registered
[    1.091705] jffs2: version 2.2. (NAND) (SUMMARY)  �© 2001-2006 Red Hat, Inc.
[    1.092010] Key type asymmetric registered
[    1.092041] Asymmetric key parser 'x509' registered
[    1.092102] bounce: pool size: 64 pages
[    1.092132] io scheduler mq-deadline registered
[    1.092163] io scheduler kyber registered
[    1.096710] OMAP GPIO hardware version 0.1
[    1.117218] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
[    1.156768] ti-sysc 480b2000.target-module: OCP softreset timed out
[    1.166900] ti-sysc 480b2000.target-module: OCP softreset timed out
[    1.176635] pinctrl-single 4a31e040.pinmux: 28 pins, size 56
[    1.177551] pinctrl-single 4a100040.pinmux: 203 pins, size 406
[    1.186523] Serial: 8250/16550 driver, 6 ports, IRQ sharing enabled
[    1.190185] 48020000.serial: ttyS2 at MMIO 0x48020000 (irq = 115, base_baud = 3000000) is a 8250
[    1.938537] printk: console [ttyS2] enabled
[    1.943878] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 126, base_baud = 3000000) is a 8250
[    1.953765] 4806c000.serial: ttyS1 at MMIO 0x4806c000 (irq = 127, base_baud = 3000000) is a 8250
[    1.973327] brd: module loaded
[    1.984527] loop: module loaded
[    1.990234] mtdoops: mtd device (mtddev=name/number) must be supplied
[    2.000793] libphy: Fixed MDIO Bus: probed
[    2.006042] ks8851 spi0.0: supply vdd-io not found, using dummy regulator
[    2.013092] ks8851 spi0.0: supply vdd not found, using dummy regulator
[    2.019744] ks8851 spi0.0: message enable is 0
[    2.025390] libphy: ks8851_eth_mii: probed
[    2.032318] ks8851 spi0.0 eth0: revision 1, MAC 8a:b7:37:b4:26:5a, IRQ 142, no EEPROM
[    2.042846] i2c /dev entries driver
[    2.050201] cpufreq: cpufreq_online: CPU0: Running at unlisted initial frequency: 699977 KHz, changing to: 
700000 KHz
[    2.062072] sdhci: Secure Digital Host Controller Interface driver
[    2.068298] sdhci: Copyright(c) Pierre Ossman
[    2.073516] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.079986] ledtrig-cpu: registered to indicate activity on CPUs
[    2.087066] omap_gpio 48059000.gpio: Could not set line 14 debounce to 200000 microseconds (-22)
[    2.095947] omap_hsmmc 480d5000.mmc: Got CD GPIO
[    2.102294] Initializing XFRM netlink socket
[    2.106719] NET: Registered protocol family 10
[    2.111999] Segment Routing with IPv6
[    2.115753] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    2.122222] NET: Registered protocol family 17
[    2.126678] NET: Registered protocol family 15
[    2.131225] Key type dns_resolver registered
[    2.135711] ThumbEE CPU extension supported.
[    2.140045] Registering SWP/SWPB emulation handler
[    2.145477] twl: not initialized
[    2.148742] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs max 1316660
[    2.156799] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs max 1316660
[    2.164886] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs max 1316660
[    2.172943] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs max 1316660
[    2.180999] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs max 1316660
[    2.189056] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1375000 Vs max 1316660
[    2.197082] twl6030_uv_to_vsel:OUT OF RANGE! non mapped vsel for 1410000 Vs max 1316660
[    2.205169] Power Management for TI OMAP4+ devices.
[    2.210083] OMAP4 PM: u-boot >= v2012.07 is required for full PM support
[    2.216918] SmartReflex Class3 initialized
[    2.221588] Loading compiled-in X.509 certificates
[    2.245117] smartreflex 4a0d9000.smartreflex: omap_sr_probe: SmartReflex driver initialized
[    2.254058] smartreflex 4a0db000.smartreflex: omap_sr_probe: SmartReflex driver initialized
[    2.262695] smartreflex 4a0dd000.smartreflex: omap_sr_probe: SmartReflex driver initialized
[    2.286987] omap-iommu 4a066000.mmu: 4a066000.mmu registered
[    2.295410] omap_i2c 48060000.i2c: bus 2 rev0.11 at 400 kHz
[    2.302673] Skipping twl internal clock init and using bootloader value (unknown osc rate)
[    2.347900] hw-breakpoint: Failed to enable monitor mode on CPU 0.
[    2.354705] hw-breakpoint: CPU 0 failed to disable vector catch
[    2.360717] twl 0-0048: PIH (irq 150) nested IRQs
[    2.373687] VUSIM: Bringing 1800000uV into 3000000-3000000uV
[    2.388641] omap_i2c 48070000.i2c: bus 0 rev0.11 at 400 kHz
[    2.395385] omap_i2c 48350000.i2c: bus 3 rev0.11 at 400 kHz
[    2.402099] omap-iommu 55082000.mmu: 55082000.mmu registered
[    2.421203] l4_secure_cm:clk:0038:0: failed to disable
[    2.509338] mmc0: host does not support reading read-only switch, assuming write-enable
[    2.523101] mmc0: new high speed SDHC card at address aaaa
[    2.523925] Waiting for root device /dev/mmcblk0p3...
[    2.534210] mmcblk0: mmc0:aaaa SC32G 29.7 GiB 
[    2.541137] omap_hsmmc 480d1000.mmc: card claims to support voltages below defined range
[    2.549743]  mmcblk0: p1 p2 p3 p4
[    2.558837] random: fast init done
[    2.564270] mmc3: new SDIO card at address 0001
[    2.569396] EXT4-fs (mmcblk0p3): mounting ext3 file system using the ext4 subsystem
[    2.712829] EXT4-fs (mmcblk0p3): recovery complete
[    2.720123] EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[    2.729949] VFS: Mounted root (ext3 filesystem) on device 179:3.
[    2.746856] devtmpfs: mounted
[    2.750061] Freeing unused kernel memory: 1024K
[    2.755645] Run /sbin/init as init process
Mount failed for selinuxfs on /sys/fs/selinux:  No such file or directory
[    3.062561] random: init: uninitialized urandom read (12 bytes read)
[    3.211273] 8<--- cut here ---
[    3.211273] Unable to handle kernel NULL pointer dereference at virtual address 00000010
[    3.222534] pgd = (ptrval)
[    3.222534] [00000010] *pgd=00000000
[    3.228881] Internal error: Oops: 5 [#1] SMP ARM
[    3.228942] Modules linked in:
[    3.228942] CPU: 0 PID: 71 Comm: kworker/0:1H Not tainted 5.12.0-rc2 #36
[    3.238891] Hardware name: Generic OMAP4 (Flattened Device Tree)
[    3.249420] Workqueue: kblockd blk_mq_run_work_fn
[    3.254150] PC is at arm_dma_unmap_sg+0x34/0x74
[    3.254150] LR is at arm_dma_unmap_sg+0x58/0x74
[    3.258850] pc : [<c01161bc>]    lr : [<c01161e0>]    psr: 80000113
[    3.269561] sp : c202fd88  ip : 00000000  fp : 00000000
[    3.274810] r10: 00000002  r9 : 00000004  r8 : c1487810
[    3.274810] r7 : c0a019b8  r6 : c01166ec  r5 : 00002e84  r4 : 00000000
[    3.274810] r3 : efdb5772  r2 : 40020891  r1 : efdb5770  r0 : 00000000
[    3.289031] Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none
[    3.289031] Control: 10c5387d  Table: 8207804a  DAC: 00000051
[    3.301025] Process kworker/0:1H (pid: 71, stack limit = 0x(ptrval))
[    3.308837] Stack: (0xc202fd88 to 0xc2030000)
[    3.316864] fd80:                   00000000 00000080 00000080 c17e6b7c 00000000 00000000
[    3.318847] fda0: c1364800 c1321800 c1364800 c1364800 00000002 c07acfbc 00000000 00000000
[    3.328857] fdc0: c1364800 c1321808 c17e6a00 c079ea5c c17e6ca8 c1321808 00000000 c1364800
[    3.338836] fde0: c1321800 c07a1998 20660000 00000001 c17e6a00 c0e051c8 0000000c c1321808
[    3.349731] fe00: c17e6c00 c1321810 c16ef000 00000000 c13218e0 c1364800 00000002 c07a22d4
[    3.349731] fe20: c07a21a0 c17e6c30 c202feac c1785c00 00000002 c1785c00 c1784a70 c17e6c00
[    3.358856] fe40: 00000000 c050287c 00000000 00000000 00000000 c17e6e00 c17e6e40 c04f24ec
[    3.368835] fe60: c17e6e00 c202fe64 c202fe64 c17e6c00 c1761600 c0e051c8 00000006 00000003
[    3.378845] fe80: c202feac c1785c00 00000000 c1784a70 c1785c04 00000000 00000000 c0507aa4
[    3.390808] fea0: ef49c5c0 00000080 c0f04b00 c17e7030 c17e6e30 c13778c0 c2164100 c0e051c8
[    3.393280] fec0: ef49c580 c1785c00 00000001 c1785c04 c202feec 00000000 00000000 c0efa0e0
[    3.406860] fee0: ffffe000 c0507eb8 00000000 c202feec c202feec c0e051c8 c1511c80 c1785c00
[    3.415466] ff00: c1785c00 ef49c380 ff7d9e00 c0508098 00000001 c04ffb5c c1785c40 c1511c80
[    3.423675] ff20: ef49c380 c0153480 c1377840 ef49c380 00000008 c1511c80 c1511c94 ef49c380
[    3.423675] ff40: 00000008 ef49c398 c0e03d00 ef49c380 ffffe000 c01537e8 ffffe000 c01537bc
[    3.438842] ff60: c1511c80 00000000 c17f3d00 c1370180 c202e000 c01537bc c1511c80 c1101ebc
[    3.438842] ff80: c17f3d24 c015b2b0 00000001 c1370180 c015b180 00000000 00000000 00000000
[    3.455474] ffa0: 00000000 00000000 00000000 c0100170 00000000 00000000 00000000 00000000
[    3.455474] ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    3.455474] ffe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
[    3.475616] [<c01161bc>] (arm_dma_unmap_sg) from [<c07acfbc>] (omap_hsmmc_post_req+0x58/0x64)
[    3.482055] [<c07acfbc>] (omap_hsmmc_post_req) from [<c079ea5c>] (mmc_blk_mq_post_req+0x30/0xb4)
[    3.495605] [<c079ea5c>] (mmc_blk_mq_post_req) from [<c07a1998>] (mmc_blk_mq_issue_rq+0x340/0x8ec)
[    3.498840] [<c07a1998>] (mmc_blk_mq_issue_rq) from [<c07a22d4>] (mmc_mq_queue_rq+0x134/0x284)
[    3.508850] [<c07a22d4>] (mmc_mq_queue_rq) from [<c050287c>] (blk_mq_dispatch_rq_list+0xf8/0x860)
[    3.525207] [<c050287c>] (blk_mq_dispatch_rq_list) from [<c0507aa4>] (__blk_mq_do_dispatch_sched+0x160/0x2a
4)
[    3.532470] [<c0507aa4>] (__blk_mq_do_dispatch_sched) from [<c0507eb8>] (__blk_mq_sched_dispatch_requests+0
x178/0x1b0)
[    3.545196] [<c0507eb8>] (__blk_mq_sched_dispatch_requests) from [<c0508098>] (blk_mq_sched_dispatch_reques
ts+0x34/0x5c)
[    3.556854] [<c0508098>] (blk_mq_sched_dispatch_requests) from [<c04ffb5c>] (__blk_mq_run_hw_queue+0x4c/0xa
4)
[    3.560852] [<c04ffb5c>] (__blk_mq_run_hw_queue) from [<c0153480>] (process_one_work+0x228/0x564)
[    3.560852] [<c0153480>] (process_one_work) from [<c01537e8>] (worker_thread+0x2c/0x5d0)
[    3.583892] [<c01537e8>] (worker_thread) from [<c015b2b0>] (kthread+0x130/0x144)
[    3.591339] [<c015b2b0>] (kthread) from [<c0100170>] (ret_from_fork+0x14/0x24)
[    3.591339] Exception stack(0xc202ffb0 to 0xc202fff8)
[    3.598846] ffa0:                                     00000000 00000000 00000000 00000000
[    3.608856] ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    3.618835] ffe0: 00000000 00000000 00000000 00000000 00000013 00000000
[    3.620117] Code: da00000f e1a04001 e1a0a003 e3a05000 (e5942010) 
[    3.632904] ---[ end trace 6007797f0442435a ]---

^ permalink raw reply	[flat|nested] 5+ messages in thread