TDA4VM: rcu: INFO: rcu_preempt detected stalls on CPUs

Hi,

Can you please share the steps to reproduce the issue?

Also is it happening with TI EVM or with the custom board?

- Keerthy

hi Keerthy

   Theres is no steps to reproduce the issue, it's just to happen.

hi Keerthy

   I just power the board,and the system is abnormal at once.

U-Boot SPL 2021.01 (Feb 07 2023 - 08:55:48 +0000)
Model: Texas Instruments K3 J721E SoC
SYSFW ABI: 3.1 (firmware rev 0x0016 '22.1.1--v2022.01 (Terrific Llam')
** File not found apainfo **
Trying to boot from MMC1
init_env from device 17 not supported!
Starting ATF on ARM64 core...

NOTICE: BL31: v2.5(release):08.01.00.006-dirty
NOTICE: BL31: Built : 21:03:57, Mar 23 2022

U-Boot SPL 2021.01 (Feb 08 2023 - 06:08:08 +0000)
Model: Texas Instruments K3 J721E SoC
SYSFW ABI: 3.1 (firmware rev 0x0016 '22.1.1--v2022.01 (Terrific Llam')
Trying to boot from MMC1

U-Boot 2021.01 (Feb 08 2023 - 06:08:08 +0000)

SoC: J721E SR1.1
Model: Texas Instruments K3 J721E SoC
DRAM: 4 GiB
Flash: 0 Bytes
MMC: sdhci@4f80000: 0, sdhci@4fb0000: 1
In: serial@2800000
Out: serial@2800000
Err: serial@2800000
power lock set suc ...
switch to partitions #0, OK
mmc0(part 0) is current device
SD/MMC found on device 0
Failed to load 'boot.scr'
** Unrecognized filesystem type **
ab_boot: mmcdev = 0
ab_boot: boot_control_env size 4096
ab_boot: origin_mmc_hw_part 0
ab_boot: blk start 1DB0 cnt 8 result 8
ab_boot: boot_active_slot 1
ab_boot: boot_attempt_count 0
ab_boot: boot_slot1_priority 15
ab_boot: boot_slot1_success 1
ab_boot: boot_slot2_priority 15
ab_boot: boot_slot2_success 0
ab_boot: last active boot slot is 1
ab_boot: active slot can boot success, try count = 0
ab_boot: active slot 1, attemp count 0
ab_boot: set env bootpart(0:1) & active(1) success
k3_r5f_rproc r5f@41000000: Core 1 is already in use. No rproc commands work
k3_r5f_rproc r5f@41400000: Core 2 is already in use. No rproc commands work
867764 bytes read in 19 ms (43.6 MiB/s)
Load Remote Processor 2 with data@addr=0x82000000 867764 bytes: Success!
301996 bytes read in 14 ms (20.6 MiB/s)
Load Remote Processor 3 with data@addr=0x82000000 301996 bytes: Success!
203704 bytes read in 14 ms (13.9 MiB/s)
Load Remote Processor 4 with data@addr=0x82000000 203704 bytes: Success!
121752 bytes read in 11 ms (10.6 MiB/s)
Load Remote Processor 5 with data@addr=0x82000000 121752 bytes: Success!
1452820 bytes read in 25 ms (55.4 MiB/s)
Load Remote Processor 6 with data@addr=0x82000000 1452820 bytes: Success!
1452852 bytes read in 24 ms (57.7 MiB/s)
Load Remote Processor 7 with data@addr=0x82000000 1452852 bytes: Success!
13242432 bytes read in 155 ms (81.5 MiB/s)
Load Remote Processor 8 with data@addr=0x82000000 13242432 bytes: Success!
18071560 bytes read in 207 ms (83.3 MiB/s)
100623 bytes read in 10 ms (9.6 MiB/s)
11732 bytes read in 8 ms (1.4 MiB/s)
## Flattened Device Tree blob at 88000000
Booting using the fdt blob at 0x88000000
Loading Device Tree to 000000008fee4000, end 000000008fffffff ... OK

Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x411fd080]
[ 0.000000] Linux version 5.10.100-g7a7a3af903 (lifengying@hw226) (aarch64-none-linux-gnu-gcc (GNU Toolchain for the A-profile Architecture 9.2-2019.12 (arm-9.10)) 9.2.1 20191025, GNU ld (GNU Toolchain for the A-profile Architecture 9.2-2019.12 (arm-9.10)) 2.33.1.20191209) #1 SMP PREEMPT Tue Feb 7 08:53:46 UTC 2023
[ 0.000000] Machine model: Texas Instruments J721E SK
[ 0.000000] earlycon: ns16550a0 at MMIO32 0x0000000002800000 (options '')
[ 0.000000] printk: bootconsole [ns16550a0] enabled
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a0000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-dma-memory@a0000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a0100000, size 15 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-memory@a0100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a1000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-dma-memory@a1000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a1100000, size 15 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-memory@a1100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a2000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-dma-memory@a2000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a2100000, size 31 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-memory@a2100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a4000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-dma-memory@a4000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a4100000, size 31 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-memory@a4100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a6000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-dma-memory@a6000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a6100000, size 15 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-memory@a6100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a7000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-dma-memory@a7000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA mOmory pool at 0x00000000a7100000, size 15 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-memory@a7100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a8000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-c66-dma-memory@a8000000, compatible id shared-dma-pool
[ 0 0.000000] Reserved memory: created DMA memory pool at 0x00000000a8100000, size 15 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-c66-memory@a8100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a9000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-c66-dma-memory@a9000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000a9100000, size 15 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-c66-memory@a9100000, compatible id shared-dma-pool
[0 0.000000] Reserved memory: created DMA memory pool at 0x00000000aa000000, size 1 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-c71-dma-memory@aa000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000aa100000, size 79 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-c71-memory@aa100000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000b2000000, size 96 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-dma-memory@b2000000, compatible id shared-dma-pool
[ 0.000000] OF: reserved mem: initialized node vision_apps_shared-memories, compatible id dma-heap-carveout
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000d8000000, size 560 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-core-heap-memory-lo@d8000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000fb000000, size 8 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-virtual-eth-queues@fb000000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x00000000fb800000, size 24 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-r5f-virtual-eth-buffers@fb800000, compatible id shared-dma-pool
[ 0.000000] Reserved memory: created DMA memory pool at 0x0000000880000000, size 256 MiB
[ 0.000000] OF: reserved mem: initialized node vision-apps-core-heap-memory-hi@880000000, compatible id shared-dma-pool
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000080000000-0x00000000ffffffff]
[ 0.000000] DMA32 empty
[ 0.000000] Normal [mem 0x0000000100000000-0x00000008ffffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000080000000-0x000000009e7fffff]
[ 0.000000] node 0: [mem 0x000000009e800000-0x00000000aeffffff]
[ 0.000000] node 0: [mem 0x00000000af000000-0x00000000afffffff]
[ 0.000000] node 0: [mem 0x00000000b0000000-0x00000000b7ffffff]
[ 0.000000] node 0: [mem 0x00000000b8000000-0x00000000d7ffffff]
[ 0.000000] node 0: [mem 0x00000000d8000000-0x00000000fcffffff]
[ 0.000000] node 0: [mem 0x00000000fd000000-0x00000000ffffffff]
[ 0.000000] node 0: [mem 0x0000000880000000-0x000000088fffffff]
[ 0.000000] node 0: [mem 0x0000000890000000-0x00000008ffffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x00000008ffffffff]
[ 0.000000] cma: Failed to reserve 512 MiB
[ 0.000000] psci: probing for conduit method from DT.
[ 0.000000] psci: PSCIv1.1 detected in firmware.
[ 0.000000] psci: Using standard PSCI v0.2 function IDs
[ 0.000000] psci: Trusted OS migration not required
[ 0.000000] psci: SMC Calling Convention v1.2
[ 0.000000] percpu: Embedded 2 pages/cpu s49368 r8192 d73512 u131072
[ 0.000000] Detected PIPT I-cache on CPU0
[ 0.000000] CPU features: detected: GIC system register CPU interface
[ 0.000000] CPU features: detected: EL2 vector hardening
[ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 65472
[ 0.000000] Kernel command line: console=ttyS2,115200n8 earlycon=ns16550a,mmio32,0x02800000 mtdparts=47040000.spi.0:512k(ospi.tiboot3),2m(ospi.tispl),4m(ospi.u-boot),256k(ospi.env),1m(ospi.sysfw),256k(ospi.env.backup),57088k@8m(ospi.rootfs),256k(ospi.phypattern);47034000.hyperbus:512k(hbmc.tiboot3),2m(hbmc.tispl),4m(hbmc.u-boot),256k(hbmc.env),1m(hbmc.sysfw),-@8m(hbmc.rootfs) root=PARTUUID=d494d86d-ab81-bc42-a013-9dd19879d40d rw rootfstype=ext4 rootwait
[ 0.000000] Dentry cache hash table entries: 524288 (order: 6, 4194304 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 262144 (order: 5, 2097152 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x000000009a7c0000-0x000000009e7c0000] (64MB)
[ 0.000000] Memory: 2303744K/4194304K available (10366K kernel code, 1264K rwdata, 4032K rodata, 1600K init, 735K bss, 1890560K reserved, 0K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU event tracing is enabled.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=2.
[ 0.000000] Trampoline variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[ 0.000000] GICv3: GIC: Using split EOI/Deactivate mode
[ 0.000000] GICv3: 960 SPIs implemented
[ 0.000000] GICv3: 0 Extended SPIs implemented
[ 0.000000] GICv3: Distributor has no Range Selector support
[ 0.000000] GICv3: 16 PPIs implemented
[ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x0000000001900000
[ 0.000000] ITS [mem 0x01820000-0x0182ffff]
[ 0.000000] GIC: enabling workaround for ITS: Socionext Synquacer pre-ITS
[ 0.000000] ITS@0x0000000001820000: allocated 1048576 Devices @8a0800000 (flat, esz 8, psz 64K, shr 0)
[ 0.000000] ITS: using cache flushing for cmd queue
[ 0.000000] GICv3: using LPI property table @0x00000008a00b0000
[ 0.000000] GIC: using cache flushing for LPI property table
[ 0.000000] GICv3: CPU0: using allocated LPI pending table @0x00000008a00c0000
[ 0.000000] random: get_random_bytes called from start_kernel+0x31c/0x4cc with crng_init=0
[ 0.000000] arch_timer: cp15 timer(s) running at 200.00MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x2e2049d3e8, max_idle_ns: 440795210634 ns
[ 0.000002] sched_clock: 56 bits at 200MHz, resolution 5ns, wraps every 4398046511102ns
[ 0.008386] Console: colour dummy device 80x25
[ 0.012949] Calibrating delay loop (skipped), value calculated using timer frequency.. 400.00 BogoMIPS (lpj=800000)
[ 0.023620] pid_max: default: 32768 minimum: 301
[ 0.028370] LSM: Security Framework initializing
[ 0.033124] Mount-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
[ 0.040700] Mountpoint-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
[ 0.049904] rcu: Hierarchical SRCU implementation.
[ 0.055000] Platform MSI: msi-controller@1820000 domain created
[ 0.061415] smp: Bringing up secondary CPUs ...
[ 0.066746] Detected PIPT I-cache on CPU1
[ 0.066772] GICv3: CPU1: found redistributor 1 region 0:0x0000000001920000
[ 0.066783] GICv3: CPU1: using allocated LPI pending table @0xs0000008a00d0000
[ 0.066819] CPU1: Booted secondary processor 0x0000000001 [0x411fd080]
[ 0.066881] smp: Brought up 1 node, 2 CPUs
[ 0.096227] SMP: Total of 2 processors activated.
[ 0.101033] CPU features: detected: 32-bit EL0 Support
[ 0.106288] CPU features: detected: CRC32 instructions
[ 0.120958] CPU: All CPU(s) started at EL2
[ 0.125153] alternatives: patching kernel code
[ 0.130251] devtmpfs: initialized
[ 0.139027] KASLR disabled due to lack of seed
[ 0.143708] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.153671] futex hash table entries: 512 (order: -1, 32768 bytes, linear)
[ 0.160843] pinctrl core: initialized pinctrl subsystem
[ 0.166709] NET: Registered protocol family 16
[ 0.171507] DMA: preallocated 256 KiB GFP_KERNEL pool for atomic allocations
[ 0.178862] DMA: preallocated 256 KiB GFP_KERrEL|GFP_DMA pool for atomic allocations
[ 0.186846] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[ 0.194953] ramoops: using module parameters
[ 0.199358] ramoops ramoops: no room for dmesg mem region (0xffffffffffffe000@0x9e7c0000) in (0x40000@0x9e7c0000)
[ 0.209854] ramoops: probe of ramoops failed with error -12
[ 0.215671] thermal_sys: Registered thermal governor 'step_wise'
[ 0.215674] thermal_sys: Registered thermal governor 'power_allocator'
[ 0.222125] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.235757] ASID allocator initialised with 65536 entries
[ 0.242051] printk: console [ramoops-1] enabled
[ 0.246686] pstore: Registered ramoops as persistent store backend
[ 0.253001] ramoops: using 0x40000@0x9e7c0000, ecc: 0
[ 0.271034] HugeTLB registered 16.0 GiB page size, pre-allocated 0 pages
[ 0.277893] HugeTLB registered 512 MiB page size, pre-allocated 0 pages
[ 0.284656] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.292578] cryptd: max_cpu_qlen set to 1000
[ 0.298663] k3-chipinfo 43000014.chipid: Family:J721E rev:SR2.0 JTAGID[0x1bb6402f] Detected
[ 0.307432] vsys_3v3: supplied by vusb-main5v0
[ 0.312394] iommu: Default domain type: Translated
[ 0.317567] SCSI subsystem initialized
[ 0.321459] usbcore: registered new interface driver usbfs
[ 0.327078] usbcore: registered new interface driver hub
[ 0.332517] usbcore: registered new device driver usb
[ 0.337875] mc: Linux media interface: v0.10
[ 0.342247] videodev: Linux video capture interface: v2.00
[ 0.347874] pps_core: LinuxPPS API ver. 1 registered
[ 0.352947] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 0.362285] PTP clock support registered
[ 0.366310] EDAC MC: Ver: 3.0.0
[ 0.370453] clocksource: Switched to clocksource arch_sys_counter
[ 0.376979] VFS: Disk quotas dquot_6.6.0
[ 0.381036] VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes)
[ 0.390693] Carveout Heap: Exported 512 MiB at 0x00000000b8000000
[ 0.397006] NET: Registered protocol family 2
[ 0.401651] IP idents hash table entries: 65536 (order: 3, 524288 bytes, linear)
[ 0.410293] tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear)
[ 0.419073] TCP established hash table entries: 32768 (order: 2, 262144 bytes, linear)
[ 0.427277] TCP bind hash table entries: 32768 (order: 3, 524288 bytes, linear)
[ 0.435105] TCP: Hash tables configured (established 32768 bind 32768)
[ 0.441867] UDP hash table entries: 2048 (order: 0, 65536 bytes, linear)
[ 0.448761] UDP-Lite hash table entries: 2048 (order: 0, 65536 bytes, linear)
[ 0.456159] NET: Registered protocol family 1
[ 0.460916] RPC: Registered named UNIX socket transport module.
[ 0.466978] RPC: Registered udp transport module.
[ 0.471795] RPC: Registered tcp transport module.
[ 0.476600] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.483552] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[ 0.494143] Initialise system trusted keyrings
[ 0.498780] workingset: timestamp_bits=46 max_order=16 bucket_order=0
[ 0.507164] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.513401] NFS: Registering the id_resolver key type
[ 0.518584] Key type id_resolver registered
[ 0.522857] Key type id_legacy registered
[ 0.526985] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.533835] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 0.541515] 9p: Installing v9fs 9p2000 file system support
[ 0.566681] Key type asymmetric registered
[ 0.570872] Asymmetric key parser 'x509' registered
[ 0.575876] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243)
[ 0.583436] io scheduler mq-deadline registered
[ 0.588064] io scheduler kyber registered
[ 0.593303] pinctrl-single 4301c000.pinctrl: 94 pins, size 376
[ 0.599450] pinctrl-single 11c000.pinctrl: 173 pins, size 692
[ 0.606902] k3-ringacc 2b800000.ringacc: Failed to get MSI domain
[ 0.613167] k3-ringacc 3c000000.ringacc: Failed to get MSI domain
[ 0.621087] Serial: 8250/16550 driver, 10 ports, IRQ sharing enabled
[ 0.629115] arm-smmu-v3 36600000.iommu: ias 48-bit, oas 48-bit (features 0x00001f8f)
[ 0.639092] arm-smmu-v3 36600000.iommu: allocated 524288 entries for cmdq
[ 0.650070] arm-smmu-v3 36600000.iommu: allocated 524288 entries for evtq
[ 0.658269] arm-smmu-v3 36600000.iommu: msi_domain absent - falling back to wired irqs
[ 0.671634] brd: module loaded
[ 0.676771] loop: module loaded
[ 0.680319] sysfs: cannot create duplicate filename '/devices/platform/dma_buf_phys'
[ 0.688251] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.10.100-g7a7a3af903 #1
[ 0.695542] Hardware name: Texas Instruments J721E SK (DT)
[ 0.701144] Call trace:
[ 0.703648] dump_backtrace+0x0/0x1a0
[ 0.707385] show_stack+0x18/0x68
[ 0.710770] dump_stack+0xd0/0x12c
[ 0.714243] sysfs_warn_dup+0x60/0x80
[ 0.717980] sysfs_create_dir_ns+0xe0/0xf8
[ 0.722164] kobject_add_internal+0x98/0x288
[ 0.726522] kobject_add+0x94/0x100
[ 0.730082] device_add+0xe0/0x740
[ 0.733554] platform_device_add+0x100/0x238
[ 0.737913] platform_device_register_full+0xcc/0x150
[ 0.743074] dma_buf_phys_init+0x6c/0x9c
[ 0.747077] do_one_initcall+0x54/0x1b8
[ 0.750994] kernel_init_freeable+0x220/0x2a0
[ 0.755444] kernel_init+0x14/0x114
[ 0.759002] ret_from_fork+0x10/0x34
[ 0.762660] kobject_add_internal failed for dma_buf_phys with -EEXIST, don't try to register things with the same name in the same directory.
[ 0.777197] tun: Universal TUN/TAP device driver, 1.6
[ 0.783144] VFIO - User Level meta-driver version: 0.3
[ 0.788595] i2c /dev entries driver
[ 0.792465] Error: Driver 'k3-soc-thermal' is already registered, aborting...
[ 0.800053] sdhci: Secure Digital Host Controller Interface driver
[ 0.806369] sdhci: Copyright(c) Pierre Ossman
[ 0.810977] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.817153] SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping ....
[ 0.823876] ashmem: initialized
[ 0.827711] optee: probing for conduit method.
[ 0.832269] optee: revision 3.12 (3d47a131)
[ 0.832516] optee: initialized driver
[ 0.841346] NET: Registered protocol family 17
[ 0.845982] 9pnet: Installing 9P2000 support
[ 0.850374] Key type dns_resolver registered
[ 0.854831] registered taskstats version 1
[ 0.859019] Loading compiled-in X.509 certificates
[ 0.864559] pstore: Invalid compression size for deflate: 0
[ 0.873148] k3-ringacc 2b800000.ringacc: Failed to get MSI domain
[ 0.879485] k3-ringacc 3c000000.ringacc: Failed to get MSI domain
[ 0.887824] ti-sci 44083000.dmsc: ABI: 3.1 (firmware rev 0x0016 '22.1.1--v2022.01 (Terrific Llam')
[ 0.914041] random: fast init done
[ 0.929147] omap_i2c 40b00000.i2c: bus 0 rev0.12 at 100 kHz
[ 0.935269] omap_i2c 40b10000.i2c: bus 1 rev0.12 at 100 kHz
[ 0.941326] omap_i2c 42120000.i2c: bus 2 rev0.12 at 100 kHz
[ 0.947923] omap_i2c 2030000.i2c: bus 3 rev0.12 at 100 kHz
[ 0.954360] ti-sci-intr bus@100000:bus@28380000:interrupt-controller2: Interrupt Router 137 domain created
[ 0.964355] ti-sci-intr bus@100000:interrupt-controller0: Interrupt Router 131 domain created
[ 0.973168] ti-sci-intr bus@100000:main-navss:interrupt-controller1: Interrupt Router 213 domain created
[ 0.983019] ti-sci-inta 33d00000.interrupt-controller: Interrupt Aggregator domain 209 created
[ 1.000525] k3-ringacc 2b800000.ringacc: Ring Accelerator probed rings:286, gp-rings[96,20] sci-dev-id:235
[ 1.010417] k3-ringacc 2b800000.ringacc: dma-ring-reset-quirk: disabled
[ 1.017179] k3-ringacc 2b800000.ringacc: RA Proxy rev. 66346100, num_proxies:64
[ 1.026245] k3-ringacc 3c000000.ringacc: Ring Accelerator probed rings:1024, gp-rings[440,150] sci-dev-id:211
[ 1.036417] k3-ringacc 3c000000.ringacc: dma-ring-reset-quirk: disabled
[ 1.043179] k3-ringacc 3c000000.ringacc: RA Proxy rev. 66346100, num_proxies:64
[ 1.052703] remoteproc remoteproc0: b034000.pru is available
[ 1.058800] remoteproc remoteproc1: b004000.rtu is available
[ 1.064829] remoteproc remoteproc2: b00a000.txpru is available
[ 1.071058] remoteproc remoteproc3: b038000.pru is available
[ 1.077115] remoteproc remoteproc4: b006000.rtu is available
[ 1.083131] remoteproc remoteproc5: b00c000.txpru is available
[ 1.091184] remoteproc remoteproc6: b134000.pru is available
[ 1.097300] remoteproc remoteproc7: b104000.rtu is available
[ 1.103329] remoteproc remoteproc8: b10a000.txpru is available
[ 1.109555] remoteproc remoteproc9: b138000.pru is available
[ 1.115613] remoteproc remoteproc10: b106000.rtu is available
[ 1.121726] remoteproc remoteproc11: b10c000.txpru is available
[ 1.128312] 40a00000.serial: ttyS1 at MMIO 0x40a00000 (irq = 15, base_baud = 6000000) is a 8250
[ 1.137854] 2800000.serial: ttyS2 at MMIO 0x2800000 (irq = 26, base_baud = 3000000) is a 8250
[ 1.146622] printk: console [ttyS2] enabled
[ 1.146622] printk: console [ttyS2] enabled
[ 1.155067] printk: bootconsole [ns16550a0] disabled
[ 1.155067] printk: bootconsole [ns16550a0] disabled
[ 1.165621] 2810000.serial: ttyS3 at MMIO 0x2810000 (irq = 27, base_baud = 3000000) is a 8250
[ 1.174742] 2840000.serial: ttyS6 at MMIO 0x2840000 (irq = 28, base_baud = 3000000) is a 8250
[ 1.222459] davinci_mdio 46000f00.mdio: davinci mdio revision 9.7, bus freq 1000000
[ 1.230536] mdio_bus 46000f00.mdio: MDIO device at address 0 is missing.
[ 1.237266] am65-cpsw-nuss 46000000.ethernet: initializing am65 cpsw nuss version 0x6BA00101, cpsw version 0x6BA80100 Ports: 2 quirks:00000000
[ 1.251133] am65-cpts 310d0000.cpts: CPTS ver 0x4e8a010a, freq:200000000, add_val:4 pps:0
[ 1.259554] k3_bandgap_probe:522 : probe enter
[ 1.264019] WORKAROUND NOT NEEDED EFUSE0[31:30] = 0b11
[ 1.364763] mmc0: CQHCI version 5.10
[ 1.379124] vdd_mmc1: supplied by vsys_3v3
[ 1.383906] omap-mailbox 31f80000.mailbox: omap mailbox rev 0x66fc7100
[ 1.390767] omap-mailbox 31f81000.mailbox: omap mailbox rev 0x66fc7100
[ 1.397591] omap-mailbox 31f82000.mailbox: omap mailbox rev 0x66fc7100
[ 1.404418] omap-mailbox 31f83000.mailbox: omap mailbox rev 0x66fc7100
[ 1.411227] omap-mailbox 31f84000.mailbox: omap mailbox rev 0x66fc7100
[ 1.413837] mmc0: SDHCI controlle3 on 4f80000.mmc [4f80000.mmc] using ADMA 64-bit
[ 1.427923] ti-udma 285c0000.dma-controller: Channels: 26 (tchan: 13, rchan: 13, gp-rflow: 8)
[ 1.438127] ti-udma 31150000.dma-controller: Channels: 84 (tchan: 42, rchan: 42, gp-rflow: 16)
[ 1.490458] davinci_mdio 46000f00.mdio: davinci mdio revision 9.7, bus freq 1000000
[ 1.498534] mdio_bus 46000f00.mdio: MDIO device at address 0 is missing.
[ 1.498752] mmc0: Command Queue Engine enabled
[ 1.505271] am65-cpsw-nuss 46000000.ethernet: initializing am65 cpsw nuss version 0x6BA00101, cpsw version 0x6BA80100 Ports: 2 quirks:00000000
[ 1.509660] mmc0: new DDR MMC card at address 0001
[ 1.527521] mmcblk0: mmc0:0001 DG4016 14.7 GiB
[ 1.532212] mmcblk0boot0: mmc0:0001 DG4016 partition 1 4.00 MiB
[ 1.538201] am65-cpsw-nuss 46000000.ethernet: set new flow-id-base 48
[ 1.538287] mmcblk0boot1: mmc0:0001 DG4016 partition 2 4.00 MiB
[ 1.550645] mmcblk0rpmb: mmc0:0001 DG4016 partition 3 4.00 MiB, chardev (237:0)
[ 1.558215] am65-cpsw-nuss 46000000.ethernet: initialized cpsw ale version 1.4
[ 1.560680] mmcblk0: p1 p2 p3 p4 p5
[ 1.565440] am65-cpsw-nuss 46000000.ethernet: ALE Table size 64
[ 1.575422] am65-cpsw-nuss 46000000.ethernet: CPTS ver 0x4e8a010a, freq:500000000, add_val:1 pps:0
[ 1.586754] mmc1: CQHCI version 5.10
[ 1.591685] k3-dsp-rproc 4d80800000.dsp: assigned reserved memory node vision-apps-c66-dma-memory@a9000000
[ 1.601450] k3-dsp-rproc 4]80800000.dsp: configured DSP for IPC-only mode
[ 1.608279] remoteproc remoteproc12: 4d80800000.dsp is available
[ 1.614278] remoteproc remoteproc12: attaching to 4d80800000.dsp
[ 1.620372] k3-dsp-rproc 4d80800000.dsp: DSP initialized in IPC-only mode
[ 1.627150] remoteproc12#vdev0buffer: assigned reserved memory node vision-apps-c66-dma-memory@a9000000
[ 1.636931] virtio_rpmsg_bus virtio0: rpmsg host is online
[ 1.641262] virtio_rpmsg_bus virtio0: creating channel rpmsg_chrdev addr 0xd
[ 1.642609] remoteproc12#vdev0buffer: registered virtio0 (type 7)
[ 1.655646] remoteproc remoteproc12: remote processor 4d80800000.dsp is now attached
[ 1.664288] k3-dsp-rproc 4d81800000.dsp: assigned reserved memory node vision-apps-c66-dma-memory@a8000000
[ 1.674041] k3-dsp-rproc 4d81800000.dsp: configured DSP for IPC-only mode
[ 1.680847] remoteproc remoteproc13: 4d81800000.dsp is available
[ 1.686842] remoteproc remoteproc13: attaching to 4d81800000.dsp
[ 1.692903] k3-dsp-rproc 4d81800000.dsp: DSP initialized in IPC-only mode
[ 1.699680] remoteproc13#vdev0buffer: assigned reserved memory node vision-apps-c66-dma-memory@a8000000
[ 1.709419] virtio_rpmsg_bus virtio1: rpmsg host is online
[ 1.713350] virtio_rpmsg_bus virtio1: creating channel rpmsg_chrdev addr 0xd
[ 1.715124] remoteproc13#vdev0buffer: registered virtio1 (type 7)
[ 1.728127] remoteproc remoteproc13: remote processor 4d81800000.dsp is now attached
[ 1.736243] k3-dsp-rproc 64800000.dsp: assigned reserved memory node vision-apps-c71-dma-memory@aa000000
[ 1.745908] k3-dsp-rproc 64800000.dsp: configured DSP for IPC-only mode
[ 1.752544] remoteproc remoteproc14: 64800000.dsp is available
[ 1.758368] remoteproc remoteproc14: attaching to 64800000.dsp
[ 1.764218] remoteproc remoteproc14: unsupported resource 65538
[ 1.770182] k3-dsp-rproc 64800000.dsp: DSP initialized in IPC-only mode
[ 1.776788] remoteproc14#vdev0buffer: assigned reserved memory node vision-apps-c71-dma-memory@aa000000
[ 1.786551] virtio_rpmsg_bus virtio2: rpmsg host is online
[ 1.792059] virtio_rpmsg_bus virtio2: creating channel rpmsg_chrdev addr 0xd
[ 1.794695] remoteproc14#vdev0buffer: registered virtio2 (type 7)
[ 1.805311] remoteproc remoteproc14: remote processor 64800000.dsp is now attached
[ 1.814512] platform 41000000.r5f: R5F core may have been powered on by a different host, programmed state (0) != actual state (1)
[ 1.826406] platform 41000000.r5f: configured R5F for IPC-only mode
[ 1.832730] platform 41000000.r5f: assigned reserved memory node vision-apps-r5f-dma-memory@a0000000
[ 1.841900] remoteproc remoteproc15: 41000000.r5f is available
[ 1.847719] remoteproc remoteproc15: attaching to 41000000.r5f
[ 1.853611] platform 41000000.r5f: R5F core initialized in IPC-only mode
[ 1.860299] remoteproc15#vdev0buffer: assigned reserved memory node vision-apps-r5f-dma-memory@a0000000
[ 1.870038] virtio_rpmsg_bus virtio3: rpmsg host is online
[ 1.875758] remoteproc15#vdev0buffer: registered virtio3 (type 7)
[ 1.881967] remoteproc remoteproc15: remote processor 41000000.r5f is now attached
[ 1.891089] platform 5c00000.r5f: configured R5F for IPC-only mode
[ 1.895695] virtio_rpmsg_bus virtio3: creating channel rpmsg_chrdev addr 0xd
[ 1.897332] platform 5c00000.r5f: assigned reserved memory node vision-apps-r5f-dma-memory@a2000000
[ 1.913473] remoteproc remoteproc16: 5c00000.r5f is available
[ 1.919207] remoteproc remoteproc16: attaching to 5c00000.r5f
[ 1.925012] platform 5c00000.r5f: R5F core initialized in IPC-only mode
[ 1.931628] remoteproc16#vdev0buffer: assigned reserved memory node vision-apps-r5f-dma-memory@a2000000
[ 1.941349] virtio_rpmsg_bus virtio4: rpmsg host is online
[ 1.947050] remoteproc16#vdev0buffer: registered virtio4 (type 7)
[ 1.953254] remoteproc remoteproc16: remote processor 5c00000.r5f is now attached
[ 1.961059] platform 5d00000.r5f: configured R5F for IPC-only mode
[ 1.964471] virtio_rpmsg_bus virtio4: creating channel rpmsg_chrdev addr 0xd
[ 1.967287] platform 5d00000.r5f: assigned reserved memory node vision-apps-r5f-dma-memory@a4000000
[ 1.983395] remoteproc remoteproc17: 5d00000.r5f is available
[ 1.989130] remoteproc remoteproc17: attaching to 5d00000.r5f
[ 1.994919] platform 5d00000.r5f: R5F core initialized in IPC-only mode
[ 2.001522] remoteproc17#vdev0buffer: assigned reserved memory node vision-apps-r5f-dma-memory@a4000000
[ 2.011252] virtio_rpmsg_bus virtio5: rpmsg host is online
[ 2.016951] remoteproc17#vdev0buffer: registered virtio5 (type 7)
[ 2.023154] remoteproc remoteproc17: remote processor 5d00000.r5f is now attached
[ 2.032034] platform 5e00000.r5f: configured R5F for IPC-only mode
[ 2.034284] virtio_rpmsg_bus virtio5: creating channel rpmsg_chrdev addr 0xd
[ 2.038282] platform 5e00000.r5f: assigned reserved memory node vision-apps-r5f-dma-memory@a6000000
[ 2.054352] remoteproc remoteproc18: 5e00000.r5f is available
[ 2.060086] remoteproc remoteproc18: attaching to 5e00000.r5f
[ 2.065890] platform 5e00000.r5f: R5F core initialized in IPC-only mode
[ 2.072495] remoteproc18#vdev0buffer: assigned reserved memory node vision-apps-r5f-dma-memory@a6000000
[ 2.082211] virtio_rpmsg_bus virtio6: rpmsg host is online
[ 2.087912] remoteproc18#vdev0buffer: registered virtio6 (type 7)
[ 2.094113] remoteproc remoteproc18: remote processor 5e00000.r5f is now attached
[ 2.101884] platform 5f00000.r5f: configured R5F for IPC-only mode
[ 2.104875] virtio_rpmsg_bus virtio6: creating channel rpmsg_chrdev addr 0xd
[ 2.108111] platform 5f00000.r5f: assigned reserved memory node vision-apps-r5f-dma-memory@a7000000
[ 2.124195] remoteproc remoteproc19: 5f00000.r5f is available
[ 2.129929] remoteproc remoteproc19: attaching to 5f00000.r5f
[ 2.135714] platform 5f00000.r5f: R5F core initialized in IPC-only mode
[ 2.142315] remoteproc19#vdev0buffer: assigned reserved memory node vision-apps-r5f-dma-memory@a7000000
[ 2.152023] virtio_rpmsg_bus virtio7: rpmsg host is online
[ 2.157721] remoteproc19#vdev0buffer: registered virtio7 (type 7)
[ 2.163923] remoteproc remoteproc19: remote processor 5f00000.r5f is now attached
[ 2.174697] virtio_rpmsg_bus virtio7: creating channel rpmsg_chrdev addr 0xd
[ 2.662470] virtio_rpmsg_bus virtio0: creating channel rpmsg_chrdev addr 0x15
[ 2.726469] virtio_rpmsg_bus virtio1: creating channel rpmsg_chrdev addr 0x15
[ 2.822472] virtio_rpmsg_bus virtio2: creating channel rpmsg_chrdev addr 0x15
[ 2.918466] virtio_rpmsg_bus virtio3: creating channel rpmsg_chrdev addr 0x15
[ 2.982469] virtio_rpmsg_bus virtio4: creating channel rpmsg_chrdev addr 0x15
[ 3.078466] virtio_rpmsg_bus virtio5: creating channel rpmsg_chrdev addr 0x15
[ 3.106452] sdhci-am654 4fb0000.mmc: Power on failed
[ 3.142043] mmc1: SDHCI controller on 4fb0000.mmc [4fb0000.mmc] using ADMA 64-bit
[ 3.142464] virtio_rpmsg_bus virtio6: creating channel rpmsg_chrdev addr 0x15
[ 3.162083] EXT4-fs (mmcblk0p1): recovery complete
[ 3.166898] EXT4-fs (mmcblk0p1): mounted filesystem with ordered data mode. Opts: (null)
[ 3.175003] VFS: Mounted root (ext4 filesystem) on device 179:1.
[ 3.181377] devtmpfs: mounted
[ 3.184597] Freeing unused kernel memory: 1600K
[ 3.194473] Run /sbin/init as init process
[ 3.206477] virtio_rpmsg_bus virtio7: creating channel rpmsg_chrdev addr 0x15
[ 3.301699] systemd[1]: System time before build time, advancing clock.
[ 3.337595] NET: Registered protocol family 10
[ 3.342453] Segment Routing with IPv6
[ 3.357602] systemd[1]: systemd 244 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR -SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[ 3.379163] systemd[1]: Detected architecture arm64.

Welcome to Arago 2021.09!

[ 3.414875] systemd[1]: Set hostname to <j7-evm>.
[ 3.531066] systemd[1]: multi-user.target: Wants dependency dropin /etc/systemd/system/multi-user.target.wants/systemd-bmculog.service.1 is not a valid unit name, ignoring.
[ 3.546633] systemd[1]: multi-user.target: Wants dependency dropin /etc/systemd/system/multi-user.target.wants/systemd-kernellog.service.1 is not a valid unit name, ignoring.
t 3.575539] systemd[1]: Configuration file /etc/systemd/system/systemd-camera.service is marked executable. Please remove executable permission bits. Proceeding anyway.
[ 3.639288] random: systemd: uninitialized urandom read (16 bytes read)
[ 3.645993] systemd[1]: system-getty.slice: unit configures an IP firewall, but the local system does not support BPF/cgroup firewalling.
[ 3.658323] systemd[1]: (This warning is only shown for the first unit using IP firewalling.)
[ 3.667969] systemd[1]: Created slice system-getty.slice.
[ OK ] Created slice system-getty.slice.
[ 3.686472] virtio_rpmsg_bus virtio0: creating channel ti.ipc4.ping-pong addr 0xe
[ 3.694043] random: systemd: uninitialized urandom read (16 bytes read)
[ 3.701179] systemd[1]: Created slice system-serial\x2dgetty.slice.
[ OK ] Created slice system-serial\x2dgetty.slice.
[ 3.722525] random: systemd: uninitialized urandom read (16 bytes read)
[ 3.729500] systemd[1]: Created slice User and Session Slice.
[ OK ] Created slice User and Session Slice.
[ 3.750653] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ 3.754468] virtio_rpmsg_bus virtio1: creating channel ti.ipc4.ping-pong addr 0xe
[ OK ] Started Dispatch Password …ts to Console Directory Watch.
[ 3.782585] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ OK ] Started Forward Password R…uests to Wall Directory Watch.
[ 3.806568] systemd[1]: Reached target Remote File Systems.
[ OK ] Reached target Remote File Systems.
[ 3.826508] systemd[1]: Reached target Swap.
[ OK ] Reached target Swap.
[ 3.846474] virtio_rpmsg_bus virtio2: creating channel ti.ipc4.ping-pong addr 0xe
[ 3.854214] systemd[1]: Listening on RPCbind Server Activation Socket.
[ OK ] Listening on RPCbind Server Activation Socket.
[ 3.874529] systemd[1]: Reached target RPC Port Mapper.
[ OK ] Reached target RPC Port Mapper.
[ 3.901245] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[ 3.909556] systemd[1]: Listening on Journal Socket (/dev/log).
[ OK ] Listening on Journal Socket (/dev/log).
[ 3.930700] systemd[1]: Listening on Journal Socket.
[ OK ] Listening on Journal Socket.
[ 3.946477] virtio_rpmsg_bus virtio3: creating channel rpmsg_chrdev addr 0x27
[ 3.946700] systemd[1]: Listening on udev Control Socket.
[ OK ] Listening on udev Control Socket.
[ 3.974691] systemd[1]: Listening on udev Kernel Socket.
[ OK ] Listening on udev Kernel Socket.
[ 3.997197] systemd[1]: Mounting Huge Pages File System...
Mounting Huge Pages File System...
[ 4.016368] systemd[1]: Mounting POSIX Message Queue File System...
Mounting POSIX Message Queue File System...
[ 4.038694] systemd[1]: Condition check resulted in Kernel Debug File System being skipped.
[ 4.051085] systemd[1]: Mounting Temporary Directory (/tmp)...
Mounting Temporary Directory (/tmp)...
[ 4.068517] systemd[1]: Starting set ip bridge...
Starting set ip bridge...
[ 4.085012] systemd[1]: Starting roudi service...
Starting roudi service...
[ 4.098856] systemd[1]: Starting Create list of static device nodes for the current kernel...
[ 4.107584] virtio_rpmsg_bus virtio5: creating channel ti.ipc4.ping-pong addr 0xe
Starting Create list of st…odes for the current kernel...
[ 4.133464] systemd[1]: Starting RPC Bind...
Starting RPC Bind...
[ 4.152896] systemd[1]: Starting service manager...
Starting service manager...
[ 4.166500] virtio_rpmsg_bus virtio6: creating channel rpmsg_chrdev addr 0x14
[ 4.177219] systemd[1]: Starting logd...
Starting logd...
[ 4.198743] systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
[ 4.213441] systemd[1]: Starting Journal Service...
Starting Journal Service...
[ 4.223334] logd.auditd: start
[ . 4.230516] virtio_rpmsg_bus virtio7: creating channel ti.ipc4.ping-pong addr 0xe
[ 4.251714] systemd[1]: Starting Load Kernel Modules...
[ 4.263505] cryptodev: loading out-of-tree module taints kernel.
Starting Load Kernel Modules...[ 4.274303] cryptodev: driver 1.10 loaded.

[ 4.293251] systemd[1]: Starting mount_auto...
Starting mount_auto...
[ 4.308687] systemd[1]: Starting Remount Root and Kernel File Systems...
Starting Remount Root and Kernel File Systems...
[ 4.325035] systemd[1]: Starting udev Coldplug all Devices...
[ 4.328434] EXT4-fs (mmcblk0p1): re-mounted. Opts: (null)
Starting udev Coldplug all Devices...
[ 4.349642] EXT4-fs (mmcblk0p3): recovery complete
[ 4.355230] EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null)
[ 4.357601] systemd[1]: Started RPC Bind.
[ OK ] Started RPC Bind.
[ 4.387895] systemd[1]: Condition check resulted in /cache being skipped.
[ 4.395292] systemd[1]: Unnecessary job for /dev/mmcblk0p3 was removed.
[ 4.403668] systemd[1]: Started Journal Service.
[ OK ] Started Journal Service.[ 4.412454] EXT4-fs (mmcblk0p4): recovery complete

[ 4.418339] EXT4-fs (mmcblk0p4): mounted filesystem with ordered data mode. Opts: (null)
[ OK ] Mounted Huge Pages File System.
[ OK ] Mounted POSIX Message Queue File System.
[ OK ] Mounted Temporary Directory (/tmp) EXT4-fs (mmcblk0p5): recovery complete
[0m.
[ 4.474666] EXT4-fs (mmcblk0p5): mounted filesystem with ordered data mode. Opts: (null)
[ OK ] Started set ip bridge.
[ OK ] Started roudi service.
[ OK ] Started Create list of sta… nodes for the current kernel.
[ OK ] Started service manager.
[ OK ] Started logd.
[ OK ] Started mount_auto.
[ OK ] Started Remount Root and Kernel File Systems.
Starting logcat...
Starting auto service...
Starting Flush Journal to Persistent Storage 4.641579] systemd-journald[222]: Received client request to flush runtime journal.
0m...
Starting udev Kernel Device Manager...
Starting Load/Save Random Seed...
[ OK ] Started logcat.
[ OK ] Started auto service.
[ OK ] Started Flush Journal to Persistent Storage.
Starting dtc...
[ OK ] Started dtc.
Starting cameraservice...
[ OK ] Started cameraservice.
[ OK ] Started udev Coldplug all Devices.
[ OK ] Reached target Local File Systems (Pre).
[ OK ] Reached target Local File Systems.
Starting autovideo...
Starting Create Volatile Files and Directories...
[ OK ] Started udev Kernel Device Manager.
[ OK ] Started autovideo.
[ OK ] Started Create Volatile Files and Directories.
Starting Update UTMP about System Boot/Shutdown...
[ OK ] Started Update UTMP about System Boot/Shutdown.
[ OK ] Stopped auto service.
Starting auto service...
[ OK ] Started auto service.
[ 5.190525] virtio_rpmsg_bus virtio6: c2 99 00 00 0f 87
[ 5.196066] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.215485] virtio_rpmsg_bus virtio6: c3 99 00 00 0f 87
[ 5.226486] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.247735] virtio_rpmsg_bus virtio6: 0b 99 00 00 0f 87
[ 5.253298] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.269627] virtio_rpmsg_bus virtio6: 0c 99 00 00 0e 2d
[ 5.278525] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.286536] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 5.290475] virtio_rpmsg_bus virtio6: 0d 99 00 00 0e 2d
[ 5.296225] ti-sci 44083000.dmsc: Mbox send fail -110
[ 5.306649] max2008x_cam_probe started!
[ 5.312638] max2008x_cam 3-0029: probe end
[ 5.313258] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.324850] max2008x_radar_probe started!
[ 5.330509] max2008x_radar 3-0028: probeqend
[ 5.343626] [sw_id_check] cam_sw_id is low, tps4h000bq driver won't work
[ 5.350418] virtio_rpmsg_bus virtio6: 0e 99 00 00 0e 2d
[ 5.361812] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.375226] virtio_rpmsg_bus virtio6: 0f 99 00 00 0e 2d
[ OK ] Stopped auto service.
[ 5.389244] virtio_rpmsg_bus virtio6: msg received with no recipient
Starting auto service...[ 5.402855] virtio_rpmsg_bus virtio6: 10 99 00 00 0f 87

[ OK ] Started Load Kernel Modules.
[ 5.422649] virtio_rpmsg_bus virtio6: msg received with no recipient
[ OK ] Started auto service.
[ 5.436208] virtio_rpmsg_bus virtio6: 11 99 00 00 0f 87
[ 5.446584] virtio_rpmsg_bus virtio6: msg received with no recipient
Mounting Kernel Configuration File System...
Starting Apply Kernel Variables...
[ OK ] Mounted Kernel Configuration File System.
[ 5.502092] virtio_rpmsg_bus virtio6: 32 99 00 00 0f 87
[ 5.507667] virtio_rpmsg_bus virtio6: msg received with no recipient
[ OK ] Started Apply Kernel Variables.
[ OK ] Reached target System Initialization.
[ OK ] Reached target Basic System.
[ OK ] Listening on D-Bus System Message Bus Socket.
[ OK ] Started D-Bus System Message Bus.
Starting rc.pvr.service...
Starting service manager...
Starting crash log...
Starting factory aging test...
Starting Login Service...
Starting Network Service...
Starting ota service...
Starting Create Static Device Nodes in /dev...
[ OK ] Started service manager.
[FAILED] Failed to start crash log.
See 'systemctl status systemd-crashlog.service' for details.
[ OK ] Started Network Service.
[FAILED] Failed to start factory aging test.
See 'systemctl status systemd-factory.service' for details.
[ OK ] Started ota service.
[ OK ] Started Create Static Device Nodes in /dev.
[ OK ] Reached target Network.
[ OK ] Stopped auto service.
Starting auto service...
Starting Permit User Sessions...
[ OK ] Started auto service.
[ OK ] Started Permit User Sessions.
[ OK ] Started Getty on tty1.
[ OK ] Started Serial Getty on ttyS2.
[ OK ] Started Serial Getty on ttyS3.
[ OK ] Reached target Login Prompts.
[ OK ] Started Login Service.
[ 6.087022] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_recalc_rate+0x44/0xa0)
[ 6.100563] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 6.111127] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 6.124810] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 6.134728] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 6.152432] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.159388] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.165636] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.172041] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.177906] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.198032] ti-sci-clk 44083000.dmsc:clocks: recalc-rate failed for dev=252, clk=1, ret=-110
[ 6.214607] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 6.230529] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 6.260259] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.269262] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.292511] pvrsrvkm 4e20000000.gpu: adding gpu_0 device link failed!
ERROR: Unhandled External Abort received on 0x80000000 from S-EL1
ERROR: exception reason=0 syndrome=0xbf000000
Unhandled Exception from EL1
x0 = 0xffff800014700000
x1 = 0x0000000000000000
x2 = 0x0000000000000000
x3 = 0xffff800009450000
x4 = 0x0000000000000000
x5 = 0x8080808080808080
x6 = 0xffff80001308f607
x7 = 0xfefefefefefefeff
x8 = 0x7f7f7f7f7f7f7f7f
x9 = 0x b6860651f397224
x10 = 0x7f7f7f7f7f7f7f7f
x11 = 0x0101010101010101
x12 = 0x0000000000000000
x13 = 0xffff8000093779a0
x14 = 0x0000004e20080000
x15 = 0xffff800011170000
x16 = 0x00000badbad00bad
x17 = 0xffff00082522d000
x18 = 0x0140000000000000
x19 = 0xffff000828732800
x20 = 0xffff00082522c000
x21 = 0xffff000828732974
x22 = 0x0000000000000000
x23 = 0xffff000825827200
x24 = 0xffff800009460000
x25 = 0xffff800009457000
x26 = 0x0000000000000000
x27 = 0xffff8000093cf250
x28 = 0xffff000825af0000
x29 = 0xffff80001308f730
x30 = 0xffff80000937e6ec
scr_el3 = 0x000000000000073d
sctlr_el3 = 0x0000000030cd183f
cptr_el3 = 0x0000000000000000
tcr_el3 = 0x0000000080803520
daif = 0x00000000000002c0
mair_el3 = 0x00000000004404ff
spsr_el3 = 0x0000000080000005
elr_el3 = 0xffff80000937e754
ttbr0_el3 = 0x0000000070010c00
esr_el3 = 0x00000000bf000000
far_el3 = 0x0000000000000000
spsr_el1 = 0x0000000080000000
elr_el1 = 0x0000ffffa897dfb8
spsr_abt = 0x0000000 00000000
spsr_und = 0x0000000000000000
spsr_irq = 0x0000000000000000
spsr_fiq = 0x0000000000000000
sctlr_el1 = 0x0000000034d4d91d
actlr_el1 = 0x0000000000000000
cpacr_el1 = 0x0000000000300000
csselr_el1 = 0x0000000000000000
sp_el1 = 0xffff80001308f730
esr_el1 = 0x0000000056000000
ttbr0_el1 = 0x00000008a1a32800
ttbr1_el1 = 0x00f0000082e60000
mair_el1 = 0x000c0400bb44ffff
amair_el1 = 0x0000000000000000
tcr_el1 = 0x00000034f5d07590
tpidr_el1 = 0xffff80086eb80000
tpidr_el0 = 0x0000ffffb68767e0
tpidrro_el0 = 0x0000000000000000
par_el1 = 0x0000000000000000
mpidr_el1 = 0x0000000080000000
afsr0_el1 = 0x0000000000000000
afsr1_el1 = 0x0000000000000000
contextidr_el1 = 0x0000000000000000
vbar_el1 = 0xffff800010001000
cntp_ctl_el0 = 0x0000000000000005
cntp_cval_el0 = 0x000000006f89864e
cntv_ctl_el0 = 0x0000000000000000
cntv_cval_el0 = 0x0000000000000000
cntkctl_el1 = 0x00000000000000d6
sp_el0 = 0x000000007000a3d0
isr_el1 = 0x0000000000000040
dacr32_el2 = 0x0000000000000000
ifsr32_el2 = 0x0000000000000000
cpuectlr_el1 = 0x0000001b00000040
cpumerrsr_el1 = 0x0000000000000000
l2merrsr_el1 = 0x0000000000000000
[ 7.046466] random: crng init done
[ 7.049866] random: 7 urandom warning(s) missed due to ratelimiting
[ 7.334528] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_set_parent+0x34/0x40)
[ 7.352228] ti-sci 44083000.dmsc: Mbox send fail -110
[ 8.390497] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_recalc_rate+0x44/0xa0)
[ 8.406485] ti-sci 44083000.dmsc: Mbox send fail -110
[ 8.414955] ti-sci-clk 44083000.dmsc:clocks: recalc-rate failed for dev=252, clk=1, ret=-110
[ 8.438565] clk: failed to reparent clk:252:1 to clk:252:5: -110
[ 9.478520] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 9.504111] ti-sci 44083000.dmsc: Mbox send fail -110
[ 9.510499] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 9.535947] ti-sci 44083000.dmsc: Mbox send fail -110
[ 10.598471] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_recalc_rate+0x44/0xa0)
[ 10.607092] ti-sci 44083000.dmsc: Mbox send fail -110
[ 10.612897] ti-sci-clk 44083000.dmsc:clocks: recalc-rate failed for dev=253, clk=1, ret=-110
[ 11.622470] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_set_parent+0x34/0x40)
[ 11.631001] ti-sci 44083000.dmsc: Mbox send fail -110
[ 12.646470] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_recalc_rate+0x44/0xa0)
[ 12.655087] ti-sci 44083000.dmsc: Mbox send fail -110
[ 12.660852] ti-sci-clk 44083000.dmsc:clocks: recalc-rate failed for dev=253, clk=1, ret=-110
[ 12.669570] clk: failed to reparent clk:253:1 to clk:253:5: -110
[ 13.702469] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 13.712128] ti-sci 44083000.dmsc: Mbox send fail -110
[ 27.362450] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 27.368539] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=2621
[ 27.377476] (detected by 1, t=5252 jiffies, g=625, q=42841)
[ 27.383118] Task dump for CPU 0:
[ 27.386334] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002a
[ 27.396227] Call trace:
[ 27.398671] __switch_to+0xc0/0x118
[ 27.402148] 0xffff000825827200
[ 33.862585] vdd_mmc1: disabling
[ 90.382450] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 90.388539] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=10494
[ 90.397563] (detected by 1, t=21007 jiffies, g=625, q=77809)
[ 90.403293] Task dump for CPU 0:
[ 90.406509] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002a
[ 90.416403] Call trace:
[ 90.418846] __switch_to+0xc0/0x118
[ 90.422323] 0xffff000825827200
[ 153.402450] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 153.408538] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=18367
[ 153.417562] (detected by 1, t=36762 jiffies, g=625, q=112784)
[ 153.423378] Task dump for CPU 0:
[ 153.426594] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002a
[ 153.436487] Call trace:
[ 153.438930] __switch_to+0xc0/0x118
[ 153.442406] 0xffff000825827200
[ 216.422450] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 216.428539] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=26240
[ 216.437562] (detected by 1, t=52517 jiffies, g=625, q=147875)
[ 216.443378] Task dump for CPU 0:
[ 216.446592] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002a
[ 216.456486] Call trace:
[ 216.458930] __switch_to+0xc0/0x118
[ 216.462406] 0xffff000825827200
[ 279.442450] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 279.448537] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=34113
[ 279.457561] (detected by 1, t=68272 jiffies, g=625, q=173886)
[ 279.463377] Task dump for CPU 0:
[ 279.466593] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002a
[ 279.476487] Call trace:
[ 279.478931] __switch_to+0xc0/0x118
[ 279.482407] 0xffff000825827200
[ 342.462450] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 342.468538] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=41985
[ 342.477562] (detected by 1, t=84027 jiffies, g=625, q=174051)
[ 342.483377] Task dump for CPU 0:
[ 342.486593] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002a
[ 342.496487] Call trace:
[ 342.498929] __switch_to+0xc0/0x118
[ 342.502405] 0xffff000825827200
[ 405.482451] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 405.488538] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=44872
[ 405.497562] (detected by 1, t=99782 jiffies, g=625, q=174256)
[ 405.503377] Task dump for CPU 0:
[ 405.506593] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002b
[ 405.516487] Call trace:
[ 405.518930] __switch_to+0xc0/0x118
[ 405.522405] 0xffff000825827200
[ 405.525536] rcu: rcu_preempt kthread starved for 9973 jiffies! g625 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[ 405.535597] rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
[ 405.544705] rcu: RCU grace-period kthread stack dump:
[ 405.549739] task:rcu_preempt state:R running task stack: 0 pid: 11 ppid: 2 flags:0x00000028
[ 405.559631] Call trace:
[ 405.562067] __switch_to+0xc0/0x118
[ 405.565545] __schedule+0x32c/0x738
[ 405.569020] schedule+0x70/0x108
[ 405.572236] schedule_timeout+0x178/0x280
[ 405.576234] rcu_gp_kthread+0x4a0/0xa10
[ 405.580056] kthread+0x140/0x160
[ 405.583272] ret_from_fork+0x10/0x34
[ 468.502444] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 468.508524] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=44872
[ 468.517546] (detected by 1, t=115537 jiffies, g=625, q=174256)
[ 468.523446] Task dump for CPU 0:
[ 468.526660] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002b
[ 468.536552] Call trace:
[ 468.538988] __switch_to+0xc0/0x118
[ 468.542463] 0xffff000825827200
[ 468.545592] rcu: rcu_preempt kthread starved for 25728 jiffies! g625 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[ 468.555739] rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
[ 468.564847] rcu: RCU grace-period kthread stack dump:
[ 468.569880] task:rcu_preempt state:R running task stack: 0 pid: 11 ppid: 2 flags:0x00000028
[ 468.579772] Call trace:
[ 468.582207] __switch_to+0xc0/0x118
[ 468.585682] __schedule+0x32c/0x738
[ 468.589156] schedule+0x70/0x108
[ 468.592372] schedule_timeout+0x178/0x280
[ 468.596367] rcu_gp_kthread+0x4a0/0xa10
[ 468.600189] kthread+0x140/0x160
[ 468.603403] ret_from_fork+0x10/0x34
[ 531.522444] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 531.528522] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=44872
[ 531.537544] (detected by 1, t=131292 jiffies, g=625, q=174256)
[ 531.543444] Task dump for CPU 0:
[ 531.546659] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002b
[ 531.556551] Call trace:
[ 531.558986] __switch_to+0xc0/0x118
[ 531.562460] 0xffff000825827200
[ 531.565589] rcu: rcu_preempt kthread starved for 41483 jiffies! g625 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[ 531.575736] rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
[ 531.584844] rcu: RCU grace-period kthread stack dump:
[ 531.589878] task:rcu_preempt state:R running task stack: 0 pid: 11 ppid: 2 flags:0x00000028
[ 531.599770] Call trace:
[ 531.602205] __switch_to+0xc0/0x118
[ 531.605680] __schedule+0x32c/0x738
[ 531.609155] schedule+0x70/0x108
[ 531.612370] schedule_timeout+0x178/0x280
[ 531.616365] rcu_gp_kthread+0x4a0/0xa10
[ 531.620187] kthread+0x140/0x160
[ 531.623402] ret_from_fork+0x10/0x34
[ 594.542444] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 594.548521] rcu: 0-...0: (1 GPs behind) idle=ea2/1/0x4000000000000000 softirq=3186/3193 fqs=44872
[ 594.557543] (detected by 1, t=147047 jiffies, g=625, q=174256)
[ 594.563444] Task dump for CPU 0:
[ 594.566657] task:systemd-udevd state:R running task stack: 0 pid: 281 ppid: 262 flags:0x0000002b
[ 594.576549] Call trace:
[ 594.578985] __switch_to+0xc0/0x118
[ 594.582458] 0xffff000825827200
[ 594.585587] rcu: rcu_preempt kthread starved for 57238 jiffies! g625 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
[ 594.595734] rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
[ 594.604841] rcu: RCU grace-period kthread stack dump:
[ 594.609874] task:rcu_preempt state:R running task stack: 0 pid: 11 ppid: 2 flags:0x00000028
[ 594.619764] Call trace:
[ 594.622199] __switch_to+0xc0/0x118
[ 594.625674] __schedule+0x32c/0x738
[ 594.629149] schedule+0x70/0x108
[ 594.632364] schedule_timeout+0x178/0x280
[ 594.636360] rcu_gp_kthread+0x4a0/0xa10
[ 594.640182] kthread+0x140/0x160
[ 594.643396] ret_from_fork+0x10/0x34

Hi,

I will try to reproduce this on the latest 8.5 SDK & get back to you in a couple of days.

- Keerthy

Hi,

I have tried booting 8.5 SDK for almost 24 hours. Issue is not seen. Could you check with the 8.5 latest Linux SDK?

One more confirmation. I believe you are using TI EVM and not custom board. Could you confirm that as well?

Regards,

Keerthy

Hi, Keerthy

1）
I have tried booting 8.5 SDK for almost 24 hours. Issue is not seen. Could you check with the 8.5 latest Linux SDK?
>>>>> We are using the sdk8.2 version, and if we are using the sdk8.5 version, we have to do the baseline upgrade, which takes a long time.

2）
One more confirmation. I believe you are using TI EVM and not custom board. Could you confirm that as well?
>>>>> Our custom board is used, not the TI EVM board. And the problem occurred when we were powering off the board and then powering it back on.

3）In addition, we want to know what RCU is for? What happens to RCU errors in general? What could it have to do with, hardware? Software?

lify said:

[ 7.049866] random: 7 urandom warning(s) missed due to ratelimiting
[ 7.334528] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_set_parent+0x34/0x40)
[ 7.352228] ti-sci 44083000.dmsc: Mbox send fail -110
[ 8.390497] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_recalc_rate+0x44/0xa0)
[ 8.406485] ti-sci 44083000.dmsc: Mbox send fail -1

These are fatal. The communication is broken between the A72 and the M3. Are you using custom binaries?
If yes how are you generating the MCU1_0 tisci_server firmware?

- Keerthy

Hi, Keerthy
Thank you for your help and reply. I will continue to track this issue.
These are fatal. The communication is broken between the A72 and the M3. Are you using custom binaries?
>>>> You mean which part of the binary file? Linux A72 we just added some diagnostic related features. M3 you mean MCU1-0?

If yes how are you generating the MCU1_0 tisci_server firmware?
>>>> We added diagnostic, can, network and other functions in the ‘tda4/rtos-sdk/vision_apps/platform/j721e/rtos/mcu1_0/’ directory.
Related initialization, is added in the 'tda4 / rtos - SDK/vision_apps/platform/j721e/rtos/McU1_0 / main. C' file
But mcu1-0 tisci_server related code we did not make changes.

Hi,

Can you please try with the prebuilt images for booting? Under $sdk/board-support/prebuilt-images folder 

This will make it easier to root cause and isolate what additional changes cause the behaviour.

Regards,

Keerthy

Hi, Keerthy
Sorry for the late reply.
Do you mean using all prebuilt image validation or just using boot image validation in prebuilt?
Also, I'm worried that it might not boot up on our board.

Hi, Keerthy
The problem is urgent and the project is about to be mass-produced. Please help to deal with it with high priority. Thank you very much for your understanding and support.
Since there is no sd card on our board, and the prebuilt version cannot be started on our board, please help us to figure out how to investigate this problem next.

Hi Jia,

MCU1_0 runs the device manager binary. That is present in: $PSDK_Linux/board-support/prebuilt-images

The binary is: ipc_echo_testb_mcu1_0_release_strip.xer5f

Can you use the above binary to build the u-boot? I believe your mcu1_0 binary is not the default binary.
That is my first suspect.

- Keerthy

Hi, Keerthy

Ok, I will arrange test verification.
But what does this verification tell us? How do we investigate the problem next?

If this works well then we need to look at the changes you have done on the mcu1_0 firmware on top of the default binary.

Regards,

Keerthy

Hi, Keerthy
1. Through the following modifications, The "j7-Mmc-r5f0_0-fw soft" connection file in the /lib/firmware/ directory points to the default mcu1-0 firmware file pdk-ipc/ipc_echo_testb_mcu1_0_release_strip.xer5f

tda4/rtos-sdk/vision_apps$ git diff vision_apps_build_flags.mak
diff --git a/vision_apps/vision_apps_build_flags.mak b/vision_apps/vision_apps_build_flags.mak
index c136187478..2ad0ba51f1 100755
--- a/vision_apps/vision_apps_build_flags.mak
+++ b/vision_apps/vision_apps_build_flags.mak
@@ -11,7 +11,7 @@ include $(TIOVX_PATH)/build_flags.mak
# Build specific CPUs
ifeq ($(SOC),j721e)
BUILD_CPU_MPU1?=yes
-BUILD_CPU_MCU1_0?=yes
+BUILD_CPU_MCU1_0?=no
BUILD_CPU_MCU2_0?=yes
BUILD_CPU_MCU2_1?=yes
BUILD_CPU_MCU3_0?=yes

However, after the system is started, run the following command:
/opt/vision_apps
source ./vision_apps_init.sh

I do not see the log associated with MCU1-0. I am not sure if MCU1-0 is started.

Do you mean the above method? If not, would you like to elaborate on how to use ipc_echo_testb_mcu1_0_release_strip.xer5f?

2. Or, to use another way, in the "tda4 / rtos - SDK/vision_apps/platform/j721e/rtos McU1_0 / the main c files to our own related program initialization function are removed, so our program will not run, validation can be like this?

Vinter said:

I do not see the log associated with MCU1-0. I am not sure if MCU1-0 is started.

That is expected. As you have done "BUILD_CPU_MCU1_0?=no". So MCU1_0 will not participate in vision_apps.
This is also the default SDK behavior. MCU1_0 will not be part of vision_apps.

Can you tell me if the original issue is seen with the above build?

Vinter said:

2. Or, to use another way, in the "tda4 / rtos - SDK/vision_apps/platform/j721e/rtos McU1_0 / the main c files to our own related program initialization function are removed, so our program will not run, validation can be like this

This can be the next step if the above has NO issues. The default tda4 / rtos - SDK/vision_apps/platform/j721e/rtos McU1_0 / the main c file should have no issues as well.

- Keerthy

Hi, Keerthy
MCU1-0 integrates can, diagnosis, network and other functions. Once these functions are removed, we cannot power on or off the board on the vehicle, because it is controlled by can, and can function is closely related to diagnostic function and network function.
We have tried many ways, but the version with default ipc_echo_testb_mcu1_0_release_strip.xer5f you mentioned cannot be tested on the whole vehicle. Is there any other way to check?

Hi,

The basic issue is the mbox timeout. That will lead to all the forth coming errors.

lify said:

0e 2d
[ 5.278525] virtio_rpmsg_bus virtio6: msg received with no recipient
[ 5.286536] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 5.290475] virtio_rpmsg_bus virtio6: 0d 99 00 00 0e 2d
[ 5.296225] ti-sci 44083000.dmsc: Mbox send fail -110

 Regards,

Keerthy

Hi，Keerthy
Thanks for your help, we are still working on a way to test the "ipc_echo_testb_mcu1_0_release_strip.xer5f "file on the entire vehicle.
In addition, I would like to know what kind of program will cause mbox to time out, can you give me an example? For example, some IPC communication was added when we started up again. It was added recently. I suspect that it is caused by this.

Hi，Keerthy
We recently found a log almost identical to the following while working on another project:
[ 7.334528] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_set_parent+0x34/0x40)
[ 7.352228] ti-sci 44083000.dmsc: Mbox send fail -110
After investigation, it is because we changed IPC from compiling into module to compiling into kernel and starting it. Modify as follows:

diff --git a/board-support/linux/arch/arm64/configs/tisdk_j721s2-evm_defconfig b/board-support/linux/arch/arm64/configs/tisdk_j721s2-evm_defconfig
index 9a609e8..d96f957 100755
--- a/board-support/linux/arch/arm64/configs/tisdk_j721s2-evm_defconfig
+++ b/board-support/linux/arch/arm64/configs/tisdk_j721s2-evm_defconfig
@@ -6019,21 +6019,21 @@
#
CONFIG_REMOTEPROC=y
# CONFIG_REMOTEPROC_CDEV is not set
-CONFIG_PRU_REMOTEPROC=m
-CONFIG_TI_K3_DSP_REMOTEPROC=m
-CONFIG_TI_K3_R5_REMOTEPROC=m
-CONFIG_TI_K3_M4_REMOTEPROC=m
+CONFIG_PRU_REMOTEPROC=y
+CONFIG_TI_K3_DSP_REMOTEPROC=y
+CONFIG_TI_K3_R5_REMOTEPROC=y
+# CONFIG_TI_K3_M4_REMOTEPROC= is not set
# end of Remoteproc drivers

#
# Rpmsg drivers
#
CONFIG_RPMSG=y
-CONFIG_RPMSG_CHAR=m
+CONFIG_RPMSG_CHAR=y
CONFIG_RPMSG_QCOM_GLINK=y
CONFIG_RPMSG_QCOM_GLINK_RPM=y
-CONFIG_RPMSG_VIRTIO=m
-CONFIG_RPMSG_PRU=m
+CONFIG_RPMSG_VIRTIO=y
+CONFIG_RPMSG_PRU=y
# end of Rpmsg drivers

#
@@ -6042,7 +6042,7 @@
CONFIG_RPMSG_KDRV=y
# CONFIG_RPMSG_KDRV_DEMO is not set
CONFIG_RPMSG_KDRV_DISPLAY=y
-CONFIG_RPMSG_KDRV_ETH_SWITCH=m
+CONFIG_RPMSG_KDRV_ETH_SWITCH=y
# end of Rpmsg virtual device drivers

CONFIG_SOUNDWIRE=m
@@ -6093,7 +6093,7 @@
CONFIG_TI_SCI_PM_DOMAINS=y
CONFIG_TI_K3_RINGACC=y
CONFIG_TI_K3_SOCINFO=y
-CONFIG_TI_PRUSS=m
+CONFIG_TI_PRUSS=y
CONFIG_TI_SCI_INTA_MSI_DOMAIN=y

#
@@ -6632,7 +6632,7 @@
CONFIG_PARTITION_PERCPU=y
CONFIG_TI_SCI_INTR_IRQCHIP=y
CONFIG_TI_SCI_INTA_IRQCHIP=y
-CONFIG_TI_PRUSS_INTC=m
+CONFIG_TI_PRUSS_INTC=y
# end of IRQ chip support

# CONFIG_IPACK_BUS is not set
@@ -7578,7 +7578,7 @@
# CONFIG_SAMPLE_KOBJECT is not set
# CONFIG_SAMPLE_HW_BREAKPOINT is not set
# CONFIG_SAMPLE_KFIFO is not set
-CONFIG_SAMPLE_RPMSG_CLIENT=m
+# CONFIG_SAMPLE_RPMSG_CLIENT is not set
# CONFIG_SAMPLE_CONFIGFS is not set
# CONFIG_SAMPLE_VFIO_MDEV_MDPY_FB is not set
# CONFIG_SAMPLE_WATCHDOG is not set
diff --git a/board-support/linux/drivers/remoteproc/ti_k3_dsp_remoteproc.c b/board-support/linux/drivers/remoteproc/ti_k3_dsp_remoteproc.c
old mode 100644
new mode 100755
index d049102..4b1fb62
--- a/board-support/linux/drivers/remoteproc/ti_k3_dsp_remoteproc.c
+++ b/board-support/linux/drivers/remoteproc/ti_k3_dsp_remoteproc.c
@@ -919,7 +919,18 @@
},
};

-module_platform_driver(k3_dsp_rproc_driver);
+
+static int __init k3_dsp_rproc_init(void)
+{
+ return platform_driver_register(&k3_dsp_rproc_driver);
+}
+late_initcall(k3_dsp_rproc_init);
+
+static void __exit k3_dsp_rproc_exit(void)
+{
+ platform_driver_unregister(&k3_dsp_rproc_driver);
+}
+module_exit(k3_dsp_rproc_exit);

MODULE_AUTHOR("Suman Anna <s-anna@ti.com>");
MODULE_LICENSE("GPL v2");
diff --git a/board-support/linux/drivers/remoteproc/ti_k3_r5_remoteproc.c b/board-support/linux/drivers/remoteproc/ti_k3_r5_remoteproc.c
old mode 100644
new mode 100755
index 6188594..45e78da
--- a/board-support/linux/drivers/remoteproc/ti_k3_r5_remoteproc.c
+++ b/board-support/linux/drivers/remoteproc/ti_k3_r5_remoteproc.c
@@ -1800,7 +1800,18 @@
},
};

-module_platform_driver(k3_r5_rproc_driver);
+static int __init k3_r5_rproc_init(void)
+{
+ return platform_driver_register(&k3_r5_rproc_driver);
+}
+late_initcall(k3_r5_rproc_init);
+
+static void __exit k3_r5_rproc_exit(void)
+{
+ platform_driver_unregister(&k3_r5_rproc_driver);
+}
+module_exit(k3_r5_rproc_exit);
+

MODULE_LICENSE("GPL v2");
MODULE_DESCRIPTION("TI K3 R5F remote processor driver");

Based on the above, we want to know, is the current problem also caused by our IPC compilation into the kernel?
Can we compile IPC into the kernel?

Hi，Keerthy

Do you have any feedback?

Hi Jia,

The SciServer functionality provided by the MCU1_0 firmware is an core system functionality and the stability of this firmware is very critical for your system. How far along are you in your project, because you say it is "urgent and the project is about to be mass-produced", and this is one of the very basic core boot features. Did you start with SDK 8.2, or were you using an earlier SDK? If so, was your kernel boot all ok then? Were you using your own MCU1_0 firmware back then.

As Keerthy mentioned above, RCU stalls are secondary observations, and you need to find and root-cause the earlier errors seen in your boot log.

Vinter said:

Based on the above, we want to know, is the current problem also caused by our IPC compilation into the kernel?
Can we compile IPC into the kernel?

remoteproc drivers are not meant to be used as in-built modules. This will force that all your firmwares be in a initramfs, you will mostly run into issues with loading and booting the remoteprocs. You are mostly getting away with this because you are booting the remote processors in U-Boot.

Vinter said:

[ 7.334528] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: sci_clk_set_parent+0x34/0x40)

In anycase, the above timeout issue has nothing to do with remoteproc drivers being built in. The MCU1_0 processor is booted by R5 SPL after launching the A72 during the boot process, so MCU1_0 is running even by the time you reach the U-Boot prompt.

This is a classic symptom of your MCU1_0 firmware failing to respond to TI-SCI server messages from Linux (would see failures in your other firmwares as well).

----------

I notice a whole bunch of issues from your boot log above.

1. This is the first failure I see

lify said:

[ 0.199358] ramoops ramoops: no room for dmesg mem region (0xffffffffffffe000@0x9e7c0000) in (0x40000@0x9e7c0000)
[ 0.209854] ramoops: probe of ramoops failed with error -12

2. This is the second error I see.

lify said:

[ 5.190525] virtio_rpmsg_bus virtio6: c2 99 00 00 0f 87
[ 5.196066] virtio_rpmsg_bus virtio6: msg received with no recipient

One of your firmwares is sending a IPC message that no one is listening to, or the Rx end-point is not yet created.

3. The MCU1_0 is toast starting from here. It is no longer responding to TI-SCI messages. The boot will fail for various reasons starting from here until your MCU1_0 firmware is fixed to not throw any issues.

lify said:

[ 5.286536] ti-sci 44083000.dmsc: Mbox timedout in resp(caller: ti_sci_cmd_get_device_exclusive+0x18/0x28)
[ 5.290475] virtio_rpmsg_bus virtio6: 0d 99 00 00 0e 2d
[ 5.296225] ti-sci 44083000.dmsc: Mbox send fail -110

4. This will now result in various cascading errors including the following kernel crash, during the GPU probe.

lify said:

[ 6.269262] ti-sci 44083000.dmsc: Mbox send fail -110
[ 6.292511] pvrsrvkm 4e20000000.gpu: adding gpu_0 device link failed!
ERROR: Unhandled External Abort received on 0x80000000 from S-EL1
ERROR: exception reason=0 syndrome=0xbf000000

-----

You need to narrow down your issues with your MCU1_0 firmware first. Please try the following to eliminate all remoteprocs and GPUs from loading:

1. Eliminate booting of all remote processors except for MCU1_0 (the firmware will be included in tispl.bin, and booted by MCU R5 SPL; filesystem soft-links don't matter here). Stop booting all the processors in U-Boot, and stop booting them from kernel either (remove the firmware links from your filesystem).

2. Disable the kernel IPC remoteproc drivers in your kernel config

3. Remove the GPU module from being loaded.

regards

Suman

Hi Jia,

Please share details on your firmwares and whether you are running stock TI firmwares or customized them. The MCU1_0 is the most important.

What OS are you running? Is it running a MCAL stack or a regular RTOS stack? The ipc_echo_testb_mcu1_0_release_strip.xer5f firmware is our basic DM Server + IPC example firmware running FreeRTOS and is what is used in our default SDK.

regards

Suman

Hi Suman,
Sorry for the late reply.
Please share details on your firmwares and whether you are running stock TI firmwares or customized them. The MCU1_0 is the most important.
===>> We used sdk 8.02 (Linux & rtos) and we added can, networking and diagnostics related processes to MCU1-0.
What OS are you running? Is it running a MCAL stack or a regular RTOS stack? The ipc_echo_testb_mcu1_0_release_strip.xer5f firmware is our basic DM Server + IPC example firmware running FreeRTOS and is what is used in our default SDK.
===》》We use Linux+rtos, we do not use ipc_echo_testb_mcu1_0_release_strip.xer5f firmware.

In addition：
[ 5.190525] virtio_rpmsg_bus virtio6: c2 99 00 00 0f 87
[ 5.196066] virtio_rpmsg_bus virtio6: msg received with no recipient
==>> I don't quite understand why the failure of IPC communication will lead to problems with TI-SCI. In addition, we have asked our colleagues to investigate this problem again, and it does not seem to be a normal state.
regards

jiawentao

Hi Jia,

Vinter said:

===>> We used sdk 8.02 (Linux & rtos) and we added can, networking and diagnostics related processes to MCU1-0.

What is the base firmware you used before you added additional code. Your MCU1_0 firmware is suspect for sure.

The firmware has to be running the DM Server, and should be able to receive and serve the TI-SCI messages coming from various processors. The threads serving this typically should be one of the highest task priority threads. The TI-SCI message timeouts is an indication that your DM Server on MCU1_0 is not servicing the incoming requests, and results in the A72 getting timed out. You will have to debug your MCU1_0 firmware to find the root-cause. Please ensure that you have the appropriate cache settings for IPC memory regions, and the firmware memory-regions used by your MCU1_0 are all reserved properly in Linux.

Vinter said:

[ 5.196066] virtio_rpmsg_bus virtio6: msg received with no recipient

This message should not be seen, especially during boot. This implies that you are transmitting a message from MCU1_0 to no where on Linux, or your Cache settings are incorrect, and the message comes across as incorrect.

regards

Suman

Hi，Suman，

Sorry for the late reply. First of all, thank you for your help.

diagnostics related processes to MCU1-0.
What is the base firmware you used before you added additional code. Your MCU1_0 firmware is suspect for sure.
==>>Our code is added to tda4/rtos-sdk/vision_ apps/platform/j721e/rtos/mcu1_ 0 directory. There is no other code for this directory except the main. c file.

The firmware has to be running the DM Server, and should be able to receive and serve the TI-SCI messages coming from various processors. The threads serving this typically should be one of the highest task priority threads.

==>>If we add code with high thread priority, will it affect us?

Please ensure that you have the appropriate cache settings for IPC memory regions, and the firmware memory-regions used by your MCU1_0 are all reserved properly in Linux.

==>>The DDR we use is the same as ti evm, so no changes have been made to the IPC memory partition.

[ 5.196066] virtio_rpmsg_bus virtio6: msg received with no recipient
This message should not be seen, especially during boot. This implies that you are transmitting a message from MCU1_0 to no where on Linux, or your Cache settings are incorrect, and the message comes across as incorrect.
==>> Do you mean that this log file must be the IPC message sent by MCU 1-0? How to determine whether it must be the IPC message sent by MCU 1-0?

Hi Jia,

Vinter said:

==>>If we add code with high thread priority, will it affect us?

Yes. The SciServer threads are expected to be the highest priority threads, so that they don't starve any incoming requests. It requires a balancing act if you are adding your threads at highest priority -> it depends on the nature of your threads. Are they running continuously or very periodically, that it would starve the TI-SCI thread? If so, the DM Server would not work properly.

I would recommend that you create your threads at slightly lower priorrity than the SciServer thread.

Vinter said:

==>>The DDR we use is the same as ti evm, so no changes have been made to the IPC memory partition.

Are you also using the exact same memory map as the TI EVM?

Vinter said:

==>> Do you mean that this log file must be the IPC message sent by MCU 1-0? How to determine whether it must be the IPC message sent by MCU 1-0?

Based on your logs, virtio6 is associated with remoteproc18, which is 5e000000.r5f (MCU3_0).

[ 2.054352] remoteproc remoteproc18: 5e00000.r5f is available
[ 2.060086] remoteproc remoteproc18: attaching to 5e00000.r5f

[ 2.087912] remoteproc18#vdev0buffer: registered virtio6 (type 7)

regards

Suman

Hi Suman,

Suman said:
Yes. The SciServer threads are expected to be the highest priority threads, so that they don't starve any incoming requests. It requires a balancing act if you are adding your threads at highest priority -> it depends on the nature of your threads. Are they running continuously or very periodically, that it would starve the TI-SCI thread? If so, the DM Server would not work properly.

I would recommend that you create your threads at slightly lower priorrity than the SciServer thread.
==>>
I found that in "tda4/rtos-sdk/vision_apps/platform/j721e/rtos/mcu1_0/main.c" file，
/* Initialize SCI Client Server */
TaskP_Params_init(&sciserverInitTaskParams);
sciserverInitTaskParams.priority = INIT_SCISERVER_TASK_PRI;// ==>> 6
sciserverInitTaskParams.stack = gSciserverInitTskStack;
sciserverInitTaskParams.stacksize = sizeof (gSciserverInitTskStack);

sciserverInitTask = TaskP_create(appSciserverInit, &sciserverInitTaskParams);

1）The priority of the tisciserver task is 6. Can I set the priority of this task to the highest level?
2）At mcu 1-0, we use Osal_ RegisterInterrupt() has registered two can interrupts with the highest priority setting. Will these two high-priority interrupts affect the operation of tisciserver?

Suman said:
Are you also using the exact same memory map as the TI EVM?
==>> yes

regards
jiawentao