This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

Linux/AM5728: system boot failure caused by the dsp firmware

Part Number: AM5728

Tool/software: Linux

Hi guys

My system sometimes fails to boot, it seems like caused by the dsp firmware loading during the system boot process. please refer to the log below. 

some contexts

1.I have a custom dsp firmware for dsp1 and dsp2, which are based on the big data example 

2. Bind both dsp1 and dsp2 to the custom firmware, the system sometimes fails to boot

3. Only bind dsp2 to the custom firmware(remove the symbol link "dra7-dsp1-fw.xe66"), more likely to boot failure

4. Try the ex02_messageq example in the ipc_3_47_02_00, met the problem in 2, 3

5. However, it works well with the opencl firmware

the boot log 

U-Boot 2016.05-00020-g80a2486 (Mar 10 2017 - 08:48:44 +0800)

CPU  : DRA752-GP ES2.0
Model: TI AM5728 BeagleBoard-X15
Board: AM572x EVM REV A.30
I2C:   ready
DRAM:  1 GiB
MMC:   OMAP SD/MMC: 0, OMAP SD/MMC: 1
MMC: no card present
** Bad device mmc 0 **
Using default environment

SCSI:  SATA link 0 timeout.
AHCI 0001.0300 32 slots 1 ports 3 Gbps 0x1 impl SATA mode
flags: 64bit ncq stag pm led clo only pmp pio slum part ccc apst 
scanning bus for devices...
Found 0 device(s).
Net:   Could not get PHY for ethernet@48484000: addr 0

Warning: ethernet@48484000 using MAC address from ROM
eth0: ethernet@48484000
Hit any key to stop autoboot:  0 
MMC: no card present
MMC: no card present
MMC: no card present
MMC: no card present
switch to partitions #0, OK
mmc1(part 0) is current device
SD/MMC found on device 1
4444672 bytes read in 116 ms (36.5 MiB/s)
153814 bytes read in 12 ms (12.2 MiB/s)
Booting from mmc1 ...
Kernel image @ 0x82000000 [ 0x000000 - 0x43d200 ]
## Flattened Device Tree blob at 88000000
   Booting using the fdt blob at 0x88000000
   Loading Device Tree to 8ffd7000, end 8ffff8d5 ... OK

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.14.40-rt29-fitkits (kaven@kaven-ubuntu) (gcc version 7.2.1 20171011 (Linaro GCC 7.2-2017.11)) #1 SMP PREEMPT RT Fri Nov 23 14:59:22 CST 2018
[    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=30c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: TI AM57XX FITKITS BOARD
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] efi: Getting EFI parameters from FDT:
[    0.000000] efi: UEFI not found.
[    0.000000] Reserved memory: created CMA memory pool at 0x0000000095800000, size 56 MiB
[    0.000000] OF: reserved mem: initialized node ipu2-memory@95800000, compatible id shared-dma-pool
[    0.000000] Reserved memory: created CMA memory pool at 0x0000000099000000, size 64 MiB
[    0.000000] OF: reserved mem: initialized node dsp1-memory@99000000, compatible id shared-dma-pool
[    0.000000] Reserved memory: created CMA memory pool at 0x000000009d000000, size 32 MiB
[    0.000000] OF: reserved mem: initialized node ipu1-memory@9d000000, compatible id shared-dma-pool
[    0.000000] Reserved memory: created CMA memory pool at 0x000000009f000000, size 8 MiB
[    0.000000] OF: reserved mem: initialized node dsp2-memory@9f000000, compatible id shared-dma-pool
[    0.000000] cma: Reserved 24 MiB at 0x00000000be400000
[    0.000000] OMAP4: Map 0x00000000bfd00000 to fe600000 for dram barrier
[    0.000000] DRA752 ES2.0
[    0.000000] percpu: Embedded 16 pages/cpu @ef623000 s36128 r8192 d21216 u65536
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 210496
[    0.000000] Kernel command line: console=ttyO2,115200n8 root=PARTUUID=69899789-02 rw rootfstype=ext4 rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 633172K/848896K available (10240K kernel code, 716K rwdata, 2900K rodata, 2048K init, 361K bss, 27308K reserved, 188416K cma-reserved, 234496K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0c00000   (12256 kB)
[    0.000000]       .init : 0xc1000000 - 0xc1200000   (2048 kB)
[    0.000000]       .data : 0xc1200000 - 0xc12b3014   ( 717 kB)
[    0.000000]        .bss : 0xc12b5000 - 0xc130f60c   ( 362 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] ftrace: allocating 31494 entries in 93 pages
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000]  RCU priority boosting: priority 1 delay 500 ms.
[    0.000000]  No expedited grace period (rcu_normal_after_boot).
[    0.000000]  Tasks RCU enabled.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] OMAP clockevent source: timer1 at 32786 Hz
[    0.000000] arch_timer: cp15 timer(s) running at 6.14MHz (virt).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
[    0.000004] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
[    0.000010] Switching to timer-based delay loop, resolution 162ns
[    0.000342] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
[    0.000345] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000883] Console: colour dummy device 80x30
[    0.001003] WARNING: Your 'console=ttyO2' has been replaced by 'ttyS2'
[    0.001005] This ensures that you still see kernel messages. Please
[    0.001007] update your kernel commandline.
[    0.001022] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
[    0.001030] pid_max: default: 32768 minimum: 301
[    0.001144] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001153] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001793] CPU: Testing write buffer coherency: ok
[    0.002051] /cpus/cpu@0 missing clock-frequency property
[    0.002097] /cpus/cpu@1 missing clock-frequency property
[    0.002111] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.039929] Setting up static identity map for 0x80200000 - 0x80200060
[    0.079908] Hierarchical SRCU implementation.
[    0.140550] EFI services will not be available.
[    0.160072] smp: Bringing up secondary CPUs ...
[    0.260564] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.260707] smp: Brought up 1 node, 2 CPUs
[    0.260724] SMP: Total of 2 processors activated (24.59 BogoMIPS).
[    0.260734] CPU: All CPU(s) started in SVC mode.
[    0.261478] devtmpfs: initialized
[    0.304722] random: get_random_u32 called from bucket_table_alloc+0x14c/0x28c with crng_init=0
[    0.305055] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
[    0.305355] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.305378] futex hash table entries: 512 (order: 3, 32768 bytes)
[    0.309799] pinctrl core: initialized pinctrl subsystem
[    0.310883] DMI not present or invalid.
[    0.311406] NET: Registered protocol family 16
[    0.314852] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.316395] omap_hwmod: l3_main_2 using broken dt data from ocp
[    0.628119] OMAP GPIO hardware version 0.1
[    0.677525] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.677539] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.678022] omap4_sram_init:Unable to allocate sram needed to handle errata I688
[    0.678037] omap4_sram_init:Unable to get sram pool needed to handle errata I688
[    0.679787] OMAP DMA hardware revision 0.0
[    0.711865] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
[    0.715315] edma 43300000.edma: memcpy is disabled
[    0.722536] edma 43300000.edma: TI EDMA DMA engine driver
[    0.725104] evm_5v0: supplied by main_12v0
[    0.726040] com_3v6: supplied by evm_5v0
[    0.732726] omap-iommu 40d01000.mmu: 40d01000.mmu registered
[    0.733311] omap-iommu 40d02000.mmu: 40d02000.mmu registered
[    0.734006] omap-iommu 58882000.mmu: 58882000.mmu registered
[    0.734695] omap-iommu 55082000.mmu: 55082000.mmu registered
[    0.735620] omap-iommu 41501000.mmu: 41501000.mmu registered
[    0.736195] omap-iommu 41502000.mmu: 41502000.mmu registered
[    0.736873] iommu: Adding device 58820000.ipu to group 1
[    0.737161] iommu: Adding device 55020000.ipu to group 2
[    0.737688] iommu: Adding device 40800000.dsp to group 0
[    0.738563] iommu: Adding device 41000000.dsp to group 3
[    0.741888] palmas 0-0058: Irq flag is 0x00000008
[    0.773406] palmas 0-0058: Muxing GPIO 2f, PWM 0, LED 0
[    0.775406] SMPS12: supplied by regulator-dummy
[    0.777510] SMPS3: supplied by regulator-dummy
[    0.777951] smps3: Bringing 1500000uV into 1350000-1350000uV
[    0.780349] SMPS45: supplied by regulator-dummy
[    0.780777] smps45: Bringing 1080000uV into 1060000-1060000uV
[    0.783387] SMPS6: supplied by regulator-dummy
[    0.785466] SMPS7: supplied by regulator-dummy
[    0.787860] SMPS8: supplied by regulator-dummy
[    0.788289] smps8: Bringing 0uV into 1060000-1060000uV
[    0.790278] SMPS9: supplied by regulator-dummy
[    0.791446] LDO1: supplied by regulator-dummy
[    0.802792] LDO2: supplied by regulator-dummy
[    0.812688] LDO3: supplied by regulator-dummy
[    0.822719] LDO4: supplied by regulator-dummy
[    0.832751] LDO5: supplied by regulator-dummy
[    0.833921] LDO6: supplied by regulator-dummy
[    0.835113] LDO7: supplied by regulator-dummy
[    0.836312] LDO8: supplied by regulator-dummy
[    0.837521] LDO9: supplied by regulator-dummy
[    0.842816] LDOLN: supplied by regulator-dummy
[    0.852862] LDOUSB: supplied by regulator-dummy
[    0.867687] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
[    0.867810] omap_i2c 48060000.i2c: could not find pctldev for node /ocp/l4@4a000000/scm@2000/pinmux@1400/i2c3_pins_default, deferring probe
[    0.867881] omap_i2c 4807a000.i2c: could not find pctldev for node /ocp/l4@4a000000/scm@2000/pinmux@1400/i2c4_pins_default, deferring probe
[    0.868653] omap_i2c 4807c000.i2c: bus 4 rev0.12 at 400 kHz
[    0.869026] media: Linux media interface: v0.10
[    0.869086] Linux video capture interface: v2.00
[    0.869228] pps_core: LinuxPPS API ver. 1 registered
[    0.869239] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.869275] PTP clock support registered
[    0.869329] EDAC MC: Ver: 3.0.0
[    0.869774] dmi: Firmware registration failed.
[    0.870507] omap-mailbox 48840000.mailbox: omap mailbox rev 0x400
[    0.870986] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
[    0.871720] Advanced Linux Sound Architecture Driver Initialized.
[    0.873086] clocksource: Switched to clocksource arch_sys_counter
[    1.090327] NET: Registered protocol family 2
[    1.091379] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    1.091476] TCP bind hash table entries: 8192 (order: 5, 229376 bytes)
[    1.091738] TCP: Hash tables configured (established 8192 bind 8192)
[    1.091903] UDP hash table entries: 512 (order: 3, 32768 bytes)
[    1.091967] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes)
[    1.092327] NET: Registered protocol family 1
[    1.092941] RPC: Registered named UNIX socket transport module.
[    1.092956] RPC: Registered udp transport module.
[    1.092968] RPC: Registered tcp transport module.
[    1.092981] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.095014] hw perfevents: no interrupt-affinity property for /pmu, guessing.
[    1.095464] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[    1.098068] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    1.107553] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    1.108610] NFS: Registering the id_resolver key type
[    1.108658] Key type id_resolver registered
[    1.108671] Key type id_legacy registered
[    1.108767] ntfs: driver 2.1.32 [Flags: R/O].
[    1.111106] bounce: pool size: 64 pages
[    1.111175] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)
[    1.111192] io scheduler noop registered
[    1.111205] io scheduler deadline registered
[    1.111381] io scheduler cfq registered (default)
[    1.111397] io scheduler mq-deadline registered
[    1.111411] io scheduler kyber registered
[    1.121593] pinctrl-single 4a003400.pinmux: 282 pins at pa fc003400 size 1128
[    1.124868] omap-dmtimer-pwm dmtimer-pwm@16: dmtimer pdata structure NULL, deferring probe
[    1.139014] dra7-pcie 51000000.pcie: Linked as a consumer to phy-4a094000.pciephy.3
[    1.139604] OF: PCI: host bridge /ocp/axi@0/pcie@51000000 ranges:
[    1.139654] OF: PCI:    IO 0x20003000..0x20012fff -> 0x00000000
[    1.139689] OF: PCI:   MEM 0x20013000..0x2fffffff -> 0x20013000
[    2.140030] dra7-pcie 51000000.pcie: phy link never came up
[    2.140251] dra7-pcie 51000000.pcie: PCI host bridge to bus 0000:00
[    2.140275] pci_bus 0000:00: root bus resource [bus 00-ff]
[    2.140289] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[    2.140302] pci_bus 0000:00: root bus resource [mem 0x20013000-0x2fffffff]
[    2.140801] PCI: bus0: Fast back to back transfers disabled
[    2.140982] PCI: bus1: Fast back to back transfers enabled
[    2.141038] pci 0000:00:00.0: BAR 0: assigned [mem 0x20100000-0x201fffff 64bit]
[    2.141063] pci 0000:00:00.0: PCI bridge to [bus 01-ff]
[    2.141839] pcieport 0000:00:00.0: Signaling PME with IRQ 177
[    2.142184] pcieport 0000:00:00.0: AER enabled with IRQ 177
[    2.151476] vdd_3v3: supplied by regen1
[    2.151887] aic_dvdd_fixed: supplied by vdd_3v3
[    2.152088] vtt_fixed: supplied by smps3
[    2.245743] Serial: 8250/16550 driver, 10 ports, IRQ sharing disabled
[    2.251670] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 45, base_baud = 3000000) is a 8250
[    2.254043] 48020000.serial: ttyS2 at MMIO 0x48020000 (irq = 46, base_baud = 3000000) is a 8250
[    3.384510] console [ttyS2] enabled
[    3.390306] 48068000.serial: ttyS5 at MMIO 0x48068000 (irq = 47, base_baud = 3000000) is a 8250
[    3.401328] 48420000.serial: ttyS6 at MMIO 0x48420000 (irq = 48, base_baud = 3000000) is a 8250
[    3.412227] 48422000.serial: ttyS7 at MMIO 0x48422000 (irq = 49, base_baud = 3000000) is a 8250
[    3.423344] 4ae2b000.serial: ttyS9 at MMIO 0x4ae2b000 (irq = 50, base_baud = 3000000) is a 8250
[    3.435649] omap_rng 48090000.rng: Random Number Generator ver. 20
[    3.445858] DSS: OMAP DSS rev 6.1
[    3.449926] omapdss_dss 58000000.dss: bound 58001000.dispc (ops dispc_component_ops)
[    3.458883] omapdss_dss 58000000.dss: bound 58040000.encoder (ops hdmi5_component_ops)
[    3.489787] brd: module loaded
[    3.508142] loop: module loaded
[    3.541409] m25p80 spi0.0: found n25q256a, expected s25fl256s1
[    3.547707] m25p80 spi0.0: n25q256a (32768 Kbytes)
[    3.552633] 8 ofpart partitions found on MTD device spi0.0
[    3.558149] Creating 8 MTD partitions on "spi0.0":
[    3.562971] 0x0000009e0000-0x000002000000 : "QSPI.user-data"
[    3.570131] 0x0000001e0000-0x0000009e0000 : "QSPI.kernel"
[    3.576987] 0x0000001d0000-0x0000001e0000 : "QSPI.u-boot-env.backup1"
[    3.584861] 0x0000001c0000-0x0000001d0000 : "QSPI.u-boot-env"
[    3.592064] 0x000000140000-0x0000001c0000 : "QSPI.u-boot-spl-os"
[    3.599500] 0x000000040000-0x000000140000 : "QSPI.u-boot"
[    3.606337] 0x000000020000-0x000000040000 : "QSPI.SPL.backup1"
[    3.613631] 0x000000000000-0x000000020000 : "QSPI.SPL"
[    3.621448] libphy: Fixed MDIO Bus: probed
[    3.630927] i2c /dev entries driver
[    3.636542] IR NEC protocol handler initialized
[    3.641098] IR RC5(x/sz) protocol handler initialized
[    3.646178] IR RC6 protocol handler initialized
[    3.650734] IR JVC protocol handler initialized
[    3.655290] IR Sony protocol handler initialized
[    3.659933] IR SANYO protocol handler initialized
[    3.664664] IR Sharp protocol handler initialized
[    3.669392] IR MCE Keyboard/mouse protocol handler initialized
[    3.675256] IR XMP protocol handler initialized
[    3.684453] tmp102 0-0048: error reading config register
[    3.690262] tmp102: probe of 0-0048 failed with error -121
[    3.699680] sdhci: Secure Digital Host Controller Interface driver
[    3.705894] sdhci: Copyright(c) Pierre Ossman
[    3.711558] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.719635] sdhci-omap 4809c000.mmc: Got CD GPIO
[    3.726008] sdhci-omap 4809c000.mmc: no pinctrl state for ddr_1_8v mode
[    3.732661] sdhci-omap 4809c000.mmc: no pinctrl state for hs200_1_8v mode
[    3.794556] mmc0: SDHCI controller on 4809c000.mmc [4809c000.mmc] using ADMA
[    3.863197] mmc1: SDHCI controller on 480b4000.mmc [480b4000.mmc] using ADMA
[    3.886586] NET: Registered protocol family 10
[    3.892481] Segment Routing with IPv6
[    3.896272] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    3.903034] NET: Registered protocol family 17
[    3.908136] Key type dns_resolver registered
[    3.912591] omap_voltage_late_init: Voltage driver support not added
[    3.918994] Power Management for TI OMAP4+ devices.
[    3.922309] mmc1: new DDR MMC card at address 0001
[    3.922986] mmcblk1: mmc1:0001 Q2J54A 3.59 GiB 
[    3.933175] mmcblk1boot0: mmc1:0001 Q2J54A partition 1 16.0 MiB
[    3.933468] mmcblk1boot1: mmc1:0001 Q2J54A partition 2 16.0 MiB
[    3.933783] mmcblk1rpmb: mmc1:0001 Q2J54A partition 3 512 KiB
[    3.935321]  mmcblk1: p1 p2
[    3.954110] Registering SWP/SWPB emulation handler
[    4.010272] dmm 4e000000.dmm: workaround for errata i878 in use
[    4.019227] dmm 4e000000.dmm: initialized all PAT entries
[    4.026609] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    4.033260] [drm] No driver support for vblank timestamp query.
[    4.040609] [drm] Initialized omapdrm 1.0.0 20110917 for omapdrm.0 on minor 0
[    4.049591] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
[    4.056850] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
[    4.066848] input: gpio_keys as /devices/platform/gpio_keys/input/input0
[    4.074566] hctosys: unable to open rtc device (rtc0)
[    4.081257] vmmcwl_fixed: disabling
[    4.084785] aic_dvdd_fixed: disabling
[    4.088717] ldousb: disabling
[    4.092042] ALSA device list:
[    4.095029]   No soundcards found.
[    4.133837] EXT4-fs (mmcblk1p2): recovery complete
[    4.141763] EXT4-fs (mmcblk1p2): mounted filesystem with ordered data mode. Opts: (null)
[    4.149965] VFS: Mounted root (ext4 filesystem) on device 179:2.
[    4.156945] devtmpfs: mounted
[    4.165109] Freeing unused kernel memory: 2048K
[    4.316113] systemd[1]: System time before build time, advancing clock.
[    4.352040] systemd[1]: systemd 234 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -ID)
[    4.373860] systemd[1]: Detected architecture arm.

Welcome to Arago 2018.04!

[    4.403820] systemd[1]: Set hostname to <am57xx-evm>.
[    4.727986] random: systemd: uninitialized urandom read (16 bytes read)
[    4.734941] systemd[1]: Listening on udev Control Socket.
[  OK  ] Listening on udev Control Socket.
[    4.773347] random: systemd: uninitialized urandom read (16 bytes read)
[    4.780048] systemd[1]: Reached target Swap.
[  OK  ] Reached target Swap.
[    4.813309] random: systemd: uninitialized urandom read (16 bytes read)
[    4.820404] systemd[1]: Listening on Journal Socket.
[  OK  ] Listening on Journal Socket.
[    4.853389] systemd[1]: Reached target Remote File Systems.
[  OK  ] Reached target Remote File Systems.
[    4.883502] systemd[1]: Listening on udev Kernel Socket.
[  OK  ] Listening on udev Kernel Socket.
[    4.913544] systemd[1]: Listening on Journal Socket (/dev/log).
[  OK  ] Listening on Journal Socket (/dev/log).
[    4.943777] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[  OK  ] Started Dispatch Password Requests to Console Directory Watch.
[  OK  ] Listening on Network Service Netlink Socket.
[  OK  ] Listening on /dev/initctl Compatibility Named Pipe.
[  OK  ] Listening on Syslog Socket.
[  OK  ] Started Forward Password Requests to Wall Directory Watch.
[  OK  ] Created slice System Slice.
         Mounting Kernel Debug File System...
[  OK  ] Created slice system-serial\x2dgetty.slice.
[  OK  ] Created slice system-getty.slice.
         Mounting POSIX Message Queue File System...
[  OK  ] Created slice system-wpa_supplicant.slice.
[  OK  ] Listening on Process Core Dump Socket.
[  OK  ] Created slice system-can\x2dsetting.slice.
         Starting Load Kernel Modules...
[    5.431203] cmemk: loading out-of-tree module taints kernel.
[    5.438327] CMEMK module: reference Linux version 4.14.40
[    5.444792] allocated heap buffer 0x40500000 of size 0x100000
[    5.450630] cmemk initialized
         Starting Journal Service...
[    5.469661] cryptodev: driver 1.9 loaded.
[    5.477637] leds_camera_5728_init
[  OK  ] Reached target Paths.
         Starting Remount Root and Kernel File Systems...
[  OK  ] Created slice User and Session Slice.
[    5.598218] EXT4-fs (mmcblk1p2): re-mounted. Opts: (null)
[  OK  ] Reached target Slices.
         Mounting Temporary Directory (/tmp)...
[    5.663750] usbcore: registered new interface driver usbfs
[    5.669384] usbcore: registered new interface driver hub
[    5.679890] usbcore: registered new device driver usb
         Starting Create list of required st…ce nodes for the current kernel...
[    5.706832] usbcore: registered new interface driver mt7601u
[  OK  ] Mounted Kernel Debug File System.
[    5.756151] vip 48990000.vip: loading firmware vpdma-1b8.bin
[  OK  ] Mounted POSIX Message Queue File System.
[    5.793220] vip 48990000.vip: VPDMA firmware loaded
[    5.798254] vip2-s0: Port A: Using subdev mt9v032 2-0048 for capture
[    5.804946] vip2-s0: device registered as video0
[    5.809632] mt9v032 2-0048: Probing MT9V032 at address 0x48
[  OK  ] Mounted Temporary Directory (/tmp).
[  OK  [    5.846537] mt9v032 2-0048: MT9V024/MT9V034 rev1 detected at address 0x48
] Started Journal Service.
[    5.853811] vip2-s1: Port A: Using subdev mt9v032 3-0048 for capture
[    5.862749] vip2-s1: device registered as video1
[    5.867446] mt9v032 3-0048: Probing MT9V032 at address 0x48
[FAILED] Failed to start Load Kernel Modules.
[    5.904250] mt9v032 3-0048: MT9V024/MT9V034 rev1 detected at address 0x48
See 'systemctl status systemd-modules-load.service' for details.
[  OK  ] Started Remount Root and Kernel File Systems.
[  OK  ] Started Create list of required sta…vice nodes for the current kernel.
         Starting udev Coldplug all Devices...
         Starting Create Static Device Nodes in /dev...
         Starting Apply Kernel Variables...
         Mounting Kernel Configuration File System...
         Starting Flush Journal to Persistent Storage...
[  OK  ] Mounted Kernel Configuration File System.
[  OK  ] Started Create Static Device Nodes in /dev.
[FAILED] Failed to start Apply Kernel Variables.
See 'systemctl status systemd-sysctl.service' for details.
[    6.415750] systemd-journald[123]: Received request to flush runtime journal from PID 1
         Starting udev Kernel Device Manager...
[  OK  ] Reached target Local File Systems (Pre).
         Mounting /var/volatile...
         Mounting /media/ram...
[  OK  ] Mounted /var/volatile.
[  OK  ] Started udev Kernel Device Manager.
[  OK  ] Started Flush Journal to Persistent Storage.
[  OK  ] Mounted /media/ram.
         Starting Load/Save Random Seed...
[  OK  ] Reached target Local File Systems.
         Starting Create Volatile Files and Directories...
[  OK  ] Started Load/Save Random Seed.
[  OK  ] Started Create Volatile Files and Directories.
         Starting Network Time Synchronization...
         Starting Update UTMP about System Boot/Shutdown...
[  OK  ] Started Update UTMP about System Boot/Shutdown.
[  OK  ] Started Network Time Synchronization.
[  OK  ] Reached target System Time Synchronized.
[    8.472025] omap-rproc 58820000.ipu: assigned reserved memory node ipu1-memory@9d000000
[    8.531545] remoteproc remoteproc0: 58820000.ipu is available
[    8.537677] remoteproc remoteproc0: Direct firmware load for dra7-ipu1-fw.xem4 failed with error -2
[    8.546902] remoteproc remoteproc0: powering up 58820000.ipu
[    8.552626] remoteproc remoteproc0: Direct firmware load for dra7-ipu1-fw.xem4 failed with error -2
[    8.564078] omap-rproc 55020000.ipu: assigned reserved memory node ipu2-memory@95800000
[    8.564227] remoteproc remoteproc1: 55020000.ipu is available
[    8.591680] omap-rproc 40800000.dsp: assigned reserved memory node dsp1-memory@99000000
[    8.595298] remoteproc remoteproc2: 40800000.dsp is available
[    8.597711] omap-rproc 41000000.dsp: assigned reserved memory node dsp2-memory@9f000000
[    8.604454] remoteproc remoteproc3: 41000000.dsp is available
[    8.713156] remoteproc remoteproc0: request_firmware failed: -2
[    8.726538] remoteproc remoteproc1: Direct firmware load for dra7-ipu2-fw.xem4 failed with error -2
[    8.748014] remoteproc remoteproc1: powering up 55020000.ipu
[    8.761805] remoteproc remoteproc1: Direct firmware load for dra7-ipu2-fw.xem4 failed with error -2
[    8.782545] remoteproc remoteproc1: request_firmware failed: -2
[    8.803558] remoteproc remoteproc2: powering up 40800000.dsp
[    8.820071] remoteproc remoteproc3: powering up 41000000.dsp
[    8.820088] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 3865000
[    8.827309] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[    8.827355] omap-iommu 41501000.mmu: 41501000.mmu: version 3.0
** 73393 printk messages dropped ** [    9.503113] 44000000.ocp:L3 Custom Error: MASTER DSP2_DMA TARGET L4_PER3_P3 (Read): Data Access in User mode during Functional access
** 5695 printk messages dropped ** [    9.543699]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02512a4
** 1526 printk messages dropped ** [    9.554510]  r10:ef145b28 r9:c028faac r8:ef332980 r7:ef350000 r6:00000000 r5:ef3329c0
** 1523 printk messages dropped ** [    9.565436] [<c05ba5e0>] (l3_interrupt_handler) from [<c028f860>] (irq_forced_thread_fn+0x30/0x84)
** 1686 printk messages dropped ** [    9.577483]  r4:ef2f6080
** 778 printk messages dropped ** [    9.583053]  r10:ef145b28 r9:c028faac r8:ef332980 r7:ef350000 r6:00000000 r5:ef3329c0
** 1509 printk messages dropped ** [    9.593919] CPU: 0 PID: 28 Comm: irq/23-l3-app-i Tainted: G        W  O    4.14.40-rt29-fitkits #1
** 1679 printk messages dropped ** [    9.605945] CPU: 0 PID: 28 Comm: irq/23-l3-app-i Tainted: G        W  O    4.14.40-rt29-fitkits #1
** 1685 printk messages dropped ** [    9.618034] [<c09fb280>] (dump_stack) from [<c022f838>] (__warn+0xf8/0x110)
** 1392 printk messages dropped ** [    9.627969] [<c028faac>] (irq_thread) from [<c0251414>] (kthread+0x170/0x178)
** 4797 printk messages dropped ** [    9.661622]  r10:c028f830 r9:ef332980 r8:ef2e6600 r7:00000001 r6:00000000 r5:ef2e6600
** 14512 printk messages dropped ** [    9.763388]  r4:ef351e40 r3:00000000
** 941 printk messages dropped ** [    9.769943]  r10:ef145b28 r9:c028faac r8:ef332980 r7:ef350000 r6:00000000 r5:ef3329c0
** 5721 printk messages dropped ** [    9.810113]  r3:ef332480 r2:c0e1bac4
** 6722 printk messages dropped ** [    9.857846] [<c05ba5e0>] (l3_interrupt_handler) from [<c028f860>] (irq_forced_thread_fn+0x30/0x84)
** 16756 printk messages dropped ** [    9.974797] Hardware name: Generic DRA74X (Flattened Device Tree)
** 7052 printk messages dropped ** [   10.025842]  r7:c12aa2d8 r6:00000000 r5:60010113 r4:c12aa2d8
** 4855 printk messages dropped ** [   10.061483] CPU: 0 PID: 28 Comm: irq/23-l3-app-i Tainted: G        W  O    4.14.40-rt29-fitkits #1
** 8455 printk messages dropped ** [   10.123657]  r4:ef351e40 r3:00000000
** 876 printk messages dropped ** [   10.130495]  r10:c028f830 r9:ef332980 r8:ef2e6600 r7:00000001 r6:00000000 r5:ef2e6600
** 12145 printk messages dropped ** [   10.220477] [<c022f854>] (warn_slowpath_fmt) from [<c05ba83c>] (l3_interrupt_handler+0x25c/0x378)
** 10021 printk messages dropped ** [   10.295437]  r9:0000001b r8:ef332610 r7:c0e1be74 r6:00000002 r5:c0e1ba20 r4:c0e1bac4
** 5412 printk messages dropped ** [   10.336102]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02512a4
** 6592 printk messages dropped ** [   10.386100]  r4:ef332980
** 6222 printk messages dropped ** [   10.433379] Modules linked in: c_can_platform c_can can_dev omap_des des_generic crypto_engine omap_crypto extcon_palmas rtc_palmas snd_soc_tlv320aic3x omap_remotepr)
** 17319 printk messages dropped ** [   10.564731] [<c09fb280>] (dump_stack) from [<c022f838>] (__warn+0xf8/0x110)
** 5992 printk messages dropped ** [   10.610704] Modules linked in: rtc_omap c_can_platform c_can can_dev omap_des des_generic crypto_engine omap_crypto extcon_palmas rtc_palmas snd_soc_tlv320aic3x omap)
** 21215 printk messages dropped ** [   10.773701] [<c020c3a0>] (show_stack) from [<c09fb330>] (dump_stack+0xb0/0xdc)
** 7968 printk messages dropped ** [   10.834642]  r4:ef3329c0
** 716 printk messages dropped ** [   10.839906]  r4:ef2f6080
** 1988 printk messages dropped ** [   10.855212] CPU: 0 PID: 28 Comm: irq/23-l3-app-i Tainted: G        W  O    4.14.40-rt29-fitkits #1
** 10034 printk messages dropped ** [   10.931915]  r10:c028f830 r9:ef332980 r8:ef2e6600 r7:00000001 r6:00000000 r5:ef2e6600
** 6824 printk messages dropped ** [   10.983374] CPU: 0 PID: 28 Comm: irq/23-l3-app-i Tainted: G        W  O    4.14.40-rt29-fitkits #1
** 7149 printk messages dropped ** [   11.037182]  r9:0000001b r8:ef332610 r7:c0e1be74 r6:00000002 r5:c0e1ba20 r4:c0e1bac4
** 6443 printk messages dropped ** [   11.086219]  r7:c12aa2d8 r6:00000000 r5:60010113 r4:c12aa2d8
** 5132 printk messages dropped ** [   11.124645]  r10:f0880e00 r9:c05ba83c r8:00000093 r7:00000009 r6:c0e1baf4 r5:00000000
** 11666 printk messages dropped ** [   11.213595]  r7:c12aa2d8 r6:00000000 r5:60010113 r4:c12aa2d8
** 9287 printk messages dropped ** [   11.285792] [<c02512a4>] (kthread) from [<c0207d34>] (ret_from_fork+0x14/0x20)
** 5932 printk messages dropped ** [   11.330903]  r10:c028f830 r9:ef332980 r8:ef2e6600 r7:00000001 r6:00000000 r5:ef2e6600
** 10773 printk messages dropped ** [   11.411945] [<c028faac>] (irq_thread) from [<c0251414>] (kthread+0x170/0x178)
** 6730 printk messages dropped ** [   11.462058] CPU: 0 PID: 28 Comm: irq/23-l3-app-i Tainted: G        W  O    4.14.40-rt29-fitkits #1
** 10515 printk messages dropped ** [   11.542334]  r7:c12aa2d8 r6:00000000 r5:60010113 r4:c12aa2d8

 Thanks!

  • Hi, Rossihwang,

    3. Only bind dsp2 to the custom firmware(remove the symbol link "dra7-dsp1-fw.xe66"), more likely to boot failure

    What if only binding dsp1, would the boot be successful all the time or still happens but less likely?

    4. Try the ex02_messageq example in the ipc_3_47_02_00, met the problem in 2, 3

    Do you mean it also heppens to ex02_messageq example? Did you use the prebuilt ex02_messageq binaries in linux filesystem /usr/bin/ipc/examples/ex02_messageq/debug or you rebuilt them? If you didn't use the prebuilt images, could you try again using prebuilt images?

    [    9.503113] 44000000.ocp:L3 Custom Error: MASTER DSP2_DMA TARGET L4_PER3_P3 (Read): Data Access in User mode during Functional access

    This error means you have error in DSP2 DMA while doing a Read Data Access to L4_PER3_P3 memory. If only binding DSP1 doesn't cause boot failure, this error totally explains the root cause. You may want to check your data access in the DSP code

    Rex

  • Hi Rex

    Thanks for your reply

    Finally, After I compare this problem on two boards, I figure out the problem is the firmware broken after scp, now instead of directly scp the firmware, I tar the it first. Now the problem fixed

     

  • The problem occurs again! Still not solved
  • Hi, Rossi,

    Is it TI AM5728 GP EVM that you are running on? Have you tried the prebuilt images and see if it works for you?

    Rex
  • we are running on tronlong's core module(tronlong.com/.../30.html) with our peripheral board. we've tried the prebuilt firmware of messageQ(...../ti-processor-sdk-linux-rt-am57xx-evm-05.00.00.15/filesystem/tisdk-rootfs-image-am57xx-evm/usr/bin/ipc/examples/ex02_messageq/debug) and openvx(....../ti-processor-sdk-linux-rt-am57xx-evm-05.00.00.15/example-applications/tiovx-app-host-01.00.01.00) firmwares both have the same problem! But this problem doesn't occur on every reboots, its by chance.

  • Hi,

    To reproduce the issue, do you reboot the EVM repeatedly or just unbind/bind the DSP core? From the logs in your original post, it suggests that you reboot the board repeatedly, but in (2) of your description, you "bind" the dsp images. I just try to understand that you don't really mean "unbind/bind" the DSP core from debugfs.

    Could you reproduce the issue using a TI AM5728 GP EVM? We won't be able to look into the issue if it can't be reproduced on TI EVM.
    Please run ex02_messageq example on TI EVM and see if the issue happens.

    Rex
  • Hi Rex

    1. I reproduce the issue by rebooting repeatedly

    2. I have tmdxidk5728 on hand, I may try to reproduce the issue on this board later

  • Hi, Rossi,

    I see Vefone opened a duplicate one. I'll close this one and move to that thread.

    Rex
  • Hi Rex

    Would you put the link here?

  • Link both thread together:
    e2e.ti.com/.../2912904
  • Hi Rex:

    I don't think my problem is similar to the one above, however, this one is more likely caused by the same problem

    In addition, I test the official example(...../ti-processor-sdk-linux-rt-am57xx-evm-05.00.00.15/example-applications/big-data-ipc-demo-linux-01.01.00.00/host_linux/simple_buffer_example) which my custom firmware based on. It has the same problem. Only modification is the macro in rsc_table_dsp.h, define VAYU_DSP_1 for dsp1 or define VAYU_DSP_2 for dsp2. Would you test this on your board?

  • Hi, Rossi,

    The link you provided is totally different issue which is OpenVX issue and not related to IPC.

    I am not sure if Big Data example is designed for stress test like unbind/bind. It tries to show how to use CMEM and send big payload through.
    I can give it a try and see what I get.

    Rex
  • From my point of view, they are the same. First the log is the same. They both contains "L3 Custom Error: MASTER DSP2_DMA TARGET L4_PER3_P3 (Read): Data Access in User mode during Functional access". Second, the software structure are the same, they both use messageQ and sharedRegion/CMEM
  • Hi, Rossi,

    I rebooted the system using big data example overnight. I don't see any crash in the logs. You will need to check in your DSP code to see any possible data access violation reported by MMU.

    Rex