AM5728: IPC examples issue in Yocto

Peter Smith48

Part Number: AM5728
Other Parts Discussed in Thread: DRA742

We build a custom Yocto distro (systemd based) using meta-ti & meta-processor-sdk. The commits of both layers used are those defined by the release of the Processor SDK 5.0. In a previous build of this distro we had no issues running the TI IPC Examples (specifically ex02_messageq) however the same example no longer operates (the app_host executable sits waiting in a loop forever). Things have no doubt changed on both the TI and our side so we are not sure exactly where the cause of the problem lies. To diagnose I followed the work flow in the TI Wiki and here are the results.

root@predixedge:~# dmesg | grep -i cma
[ 0.000000] Reserved memory: created CMA memory pool at 0x0000000095800000, size 56 MiB
[ 0.000000] Reserved memory: created CMA memory pool at 0x0000000099000000, size 64 MiB
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000009d000000, size 32 MiB
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000009f000000, size 8 MiB
[ 0.000000] cma: Reserved 24 MiB at 0x00000000fe400000
[ 0.000000] Memory: 1675628K/1897472K available (8192K kernel code, 357K rwdata, 2632K rodata, 2048K init, 301K bss, 33428K reserved, 188416K cma-reserved, 1283072K highmem)
root@predixedge:~#

root@predixedge:~# cat /proc/iomem
20013000-2fffffff : MEM
20100000-201fffff : 0000:00:00.0
40300000-4037ffff : 40300000.ocmcram
40500000-405fffff : CMEM
40800000-40847fff : l2ram
40d01000-40d010ff : /ocp/mmu@40d01000
40d02000-40d020ff : /ocp/mmu@40d02000
40e00000-40e07fff : l1pram
40f00000-40f07fff : l1dram
41000000-41047fff : l2ram
41501000-415010ff : /ocp/mmu@41501000
41502000-415020ff : /ocp/mmu@41502000
41600000-41607fff : l1pram
41700000-41707fff : l1dram
43300000-433fffff : edma3_cc
44000000-44ffffff : /ocp
45000000-45000fff : /ocp
48020000-4802001f : serial
48032000-4803207f : /ocp/timer@48032000
48034000-4803407f : /ocp/timer@48034000
48036000-4803607f : /ocp/timer@48036000
4803e000-4803e07f : /ocp/timer@4803e000
48051000-480511ff : /ocp/gpio@48051000
48053000-480531ff : /ocp/gpio@48053000
48055000-480551ff : /ocp/gpio@48055000
48057000-480571ff : /ocp/gpio@48057000
48059000-480591ff : /ocp/gpio@48059000
4805b000-4805b1ff : /ocp/gpio@4805b000
4805d000-4805d1ff : /ocp/gpio@4805d000
48070000-480700ff : /ocp/i2c@48070000
48086000-4808607f : /ocp/timer@48086000
48088000-4808807f : /ocp/timer@48088000
48090000-48091fff : /ocp/rng@48090000
4809c000-4809c3ff : /ocp/mmc@4809c000
480a5000-480a509f : /ocp/des@480a5000
480b4000-480b43ff : /ocp/mmc@480b4000
480b8000-480b81ff : /ocp/spi@480b8000
4844a000-4844ad1b : /ocp/padconf@4844a000
48484000-48484fff : /ocp/ethernet@48484000
48485000-484850ff : /ocp/ethernet@48484000/mdio@48485000
48485200-48487fff : /ocp/ethernet@48484000
48820000-4882007f : /ocp/timer@48820000
48822000-4882207f : /ocp/timer@48822000
48824000-4882407f : /ocp/timer@48824000
48826000-4882607f : /ocp/timer@48826000
48828000-4882807f : /ocp/timer@48828000
4882a000-4882a07f : /ocp/timer@4882a000
4882c000-4882c07f : /ocp/timer@4882c000
4882e000-4882e07f : /ocp/timer@4882e000
48838000-488380ff : /ocp/rtc@48838000
48840000-488401ff : /ocp/mailbox@48840000
48842000-488421ff : /ocp/mailbox@48842000
48880000-4888ffff : /ocp/omap_dwc3_1@48880000
48890000-48897fff : /ocp/omap_dwc3_1@48880000/usb@48890000
48890000-48897fff : /ocp/omap_dwc3_1@48880000/usb@48890000
4889c100-488a6fff : /ocp/omap_dwc3_1@48880000/usb@48890000
488c0000-488cffff : /ocp/omap_dwc3_2@488c0000
488dc100-488e6fff : /ocp/omap_dwc3_2@488c0000/usb@488d0000
48990000-48990113 : vip
48995500-489955d7 : parser0
48995700-48995717 : csc0
48995800-4899587f : sc0
48995a00-48995ad7 : parser1
48995c00-48995c17 : csc1
48995d00-48995d7f : sc1
489d0700-489d077f : sc
489d5700-489d5717 : csc
4a0021e0-4a0021eb : /ocp/bandgap@4a0021e0
4a00232c-4a002337 : /ocp/bandgap@4a0021e0
4a002380-4a0023ab : /ocp/bandgap@4a0021e0
4a0023c0-4a0023fb : /ocp/bandgap@4a0021e0
4a00246c-4a00246f : ldo-address
4a002470-4a002473 : ldo-address
4a002554-4a002557 : gmii-sel
4a002564-4a00256b : /ocp/bandgap@4a0021e0
4a002574-4a0025c3 : /ocp/bandgap@4a0021e0
4a002b78-4a002c73 : /ocp/l4@4a000000/scm@2000/dma-router@b78
4a002c78-4a002cf3 : /ocp/l4@4a000000/scm@2000/dma-router@c78
4a003400-4a003867 : pinctrl-single
4a056000-4a056fff : omap_dma_system.0
4a056000-4a056fff : /ocp/dma-controller@4a056000
4a080000-4a08001f : /ocp/ocp2scp@4a080000
4a084000-4a0843ff : /ocp/ocp2scp@4a080000/phy@4a084000
4a084c00-4a084c3f : pll_ctrl
4a085000-4a0853ff : /ocp/ocp2scp@4a080000/phy@4a085000
4a090000-4a09001f : /ocp/ocp2scp@4a090000
4a094000-4a09407f : phy_rx
4a094400-4a094463 : phy_tx
4a096800-4a09683f : pll_ctrl
4a140000-4a1410ff : /ocp/sata@4a141100
4ae07ddc-4ae07ddf : setup-address
4ae07de0-4ae07de3 : control-address
4ae07de4-4ae07de7 : setup-address
4ae07de8-4ae07deb : control-address
4ae07e20-4ae07e23 : control-address
4ae07e24-4ae07e27 : control-address
4ae07e30-4ae07e33 : setup-address
4ae07e34-4ae07e37 : setup-address
4ae0c154-4ae0c157 : ldo-address
4ae0c158-4ae0c15b : ldo-address
4ae10000-4ae101ff : /ocp/gpio@4ae10000
4ae14000-4ae1407f : /ocp/wdt@4ae14000
4ae20000-4ae2007f : /ocp/timer@4ae20000
4ae3c000-4ae3dfff : /ocp/can@481cc000
4b101000-4b1012ff : /ocp/sham@53100000
4b220000-4b221fff : intc
4b222000-4b2223ff : control
4b222400-4b2224ff : debug
4b224000-4b2243ff : control
4b224400-4b2244ff : debug
4b234000-4b236fff : iram
4b238000-4b23afff : iram
4b2a0000-4b2a1fff : intc
4b2a2000-4b2a23ff : control
4b2a2400-4b2a24ff : debug
4b2a4000-4b2a43ff : control
4b2a4400-4b2a44ff : debug
4b2b2400-4b2b248f : /ocp/pruss_soc_bus@4b2a6004/pruss@0/mdio@32400
4b2b4000-4b2b6fff : iram
4b2b8000-4b2bafff : iram
4b300000-4b3000ff : qspi_base
4b500000-4b50009f : /ocp/aes@4b500000
4b700000-4b70009f : /ocp/aes@4b700000
55020000-5502ffff : l2ram
55082000-550820ff : /ocp/mmu@55082000
58000000-5800007f : dss
58001000-58001fff : /ocp/dss@58000000/dispc@58001000
58004054-58004057 : pll1_clkctrl
58004300-5800431f : pll1
58009054-58009057 : pll2_clkctrl
58009300-5800931f : pll2
58040000-580401ff : wp
58040200-5804027f : pll
58040300-5804037f : phy
58060000-58078fff : core
58820000-5882ffff : l2ram
58882000-588820ff : /ocp/mmu@58882000
80000000-9fffffff : System RAM
80008000-80dfffff : Kernel code
81000000-810a644b : Kernel data
a0000000-abffffff : CMEM
ac000000-ffcfffff : System RAM
root@predixedge:~#

root@predixedge:~# cat /proc/cmem

Block 0: Pool 0: 1 bufs size 0xc000000 (0xc000000 requested)

Pool 0 busy bufs:

Pool 0 free bufs:
id 0: phys addr 0xa0000000
root@predixedge:~#

root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 40800000.dsp > unbind
[ 363.402943] remoteproc remoteproc2: releasing 40800000.dsp
root@predixedge:/sys/bus/platform/drivers/omap-rproc#

root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 40800000.dsp > bind
[ 402.333138] omap-rproc 40800000.dsp: assigned reserved memory node dsp1-memory@99000000
[ 402.341869] remoteproc remoteproc2: 40800000.dsp is available
root@predixedge:/sys/bus/platform/drivers/omap-rproc# [ 402.353969] remoteproc remoteproc2: powering up 40800000.dsp
[ 402.361095] remoteproc remoteproc2: Booting fw image dra7-dsp1-fw.xe66, size 4665540
[ 402.375912] omap_hwmod: mmu0_dsp1: _wait_target_disable failed
[ 402.381808] omap-iommu 40d01000.mmu: 40d01000.mmu: version 3.0
[ 402.387733] omap-iommu 40d02000.mmu: 40d02000.mmu: version 3.0
[ 402.401752] virtio_rpmsg_bus virtio0: rpmsg host is online
[ 402.407345] remoteproc remoteproc2: registered virtio0 (type 7)
[ 402.413308] remoteproc remoteproc2: remote processor 40800000.dsp is now up
[ 402.420723] virtio_rpmsg_bus virtio0: creating channel rpmsg-proto addr 0x3d
[ 402.434893] NET: Registered protocol family 44

root@predixedge:/sys/bus/platform/drivers/omap-rproc#

root@predixedge:/mnt/data/edgeos-data/ex02_messageq/debug# ./app_host DSP1
--> main:
--> Main_main:
--> App_create:

Sit there forever....

Here is the output from the LAD log...

root@predixedge:/tmp/LAD# cat lad.txt

[0.396536]
Initializing LAD... [0.396870] NameServer_setup: entered, refCount=0
[0.396919] NameServer_setup: creating listener thread
[0.397072] NameServer_setup: exiting, refCount=1
[0.397175] NameServer_create(): 'GateMP'
[0.397196]
opening FIFO: /tmp/LAD/LADCMDS
[0.400003] listener_cb: Entered Listener thread.
[0.400022] NameServer: waiting for unblockFd: 0, and socks: maxfd: 0
[364.945597] Retrieving command...
[364.945772]
LAD_CONNECT:
[364.945786] client FIFO name = /tmp/LAD/1825
[364.945796] client PID = 1825
[364.945806] assigned client handle = 0
[364.945842] FIFO /tmp/LAD/1825 created
[364.945975] FIFO /tmp/LAD/1825 opened for writing
[364.946016] sent response
[364.946027] DONE
[364.946036] Retrieving command...
[364.946058] Sending response...
[364.946078] Retrieving command...
[364.946123] LAD_MULTIPROC_GETCONFIG: calling MultiProc_getConfig()...
[364.946136] MultiProc_getConfig() - 5 procs
[364.946145] # processors in cluster: 5
[364.946153] cluster baseId: 0
[364.946161] ProcId 0 - "HOST"
[364.946170] ProcId 1 - "IPU2"
[364.946179] ProcId 2 - "IPU1"
[364.946187] ProcId 3 - "DSP2"
[364.946195] ProcId 4 - "DSP1"
[364.946203] status = 0
[364.946211] DONE
[364.946219] Sending response...
[364.946236] Retrieving command...
[364.946280] LAD_NAMESERVER_SETUP: calling NameServer_setup()...
[364.946292] NameServer_setup: entered, refCount=1
[364.946300] NameServer_setup: already setup
[364.946309] NameServer_setup: exiting, refCount=2
[364.946317] status = 1
[364.946326] DONE
[364.946333] Sending response...
[364.946351] Retrieving command...
[364.946392] LAD_MESSAGEQ_GETCONFIG: calling MessageQ_getConfig()...
[364.946404] status = 0
[364.946412] DONE
[364.946420] Sending response...
[364.946446] Retrieving command...
[364.946490] LAD_MESSAGEQ_SETUP: calling MessageQ_setup()...
[364.946501] MessageQ_setup: entered, refCount=0
[364.946511] NameServer_create(): 'MessageQ'
[364.946527] MessageQ_setup: exiting, refCount=1
[364.946537] status = 0
[364.946545] DONE
[364.946553] Sending response...
[364.946570] Retrieving command...
[364.946721] NameServer_attach: --> procId=1, refCount=0
[364.949583] NameServer_attach: socket failed: 97, Address family not supported by protocol
[364.949615] NameServer_attach: <-- refCount=0, status=-1
[364.949625] Sending response...
[364.949645] Retrieving command...
[364.949703] NameServer_attach: --> procId=2, refCount=0
[364.952280] NameServer_attach: socket failed: 97, Address family not supported by protocol
[364.952298] NameServer_attach: <-- refCount=0, status=-1
[364.952308] Sending response...
[364.952326] Retrieving command...
[364.952379] NameServer_attach: --> procId=3, refCount=0
[364.955305] NameServer_attach: socket failed: 97, Address family not supported by protocol
[364.955324] NameServer_attach: <-- refCount=0, status=-1
[364.955332] Sending response...
[364.955350] Retrieving command...
[364.955398] NameServer_attach: --> procId=4, refCount=0
[364.957608] NameServer_attach: socket failed: 97, Address family not supported by protocol
[364.957624] NameServer_attach: <-- refCount=0, status=-1
[364.957631] Sending response...
[364.957646] Retrieving command...
[364.957690] LAD_GATEMP_ISSETUP: calling GateMP_isSetup()...
[364.957700] status = 0
[364.957708] DONE
[364.957714] Sending response...
[364.957729] Retrieving command...
[364.957766] LAD_GATEHWSPINLOCK_GETCONFIG: calling GateHWSpinlock_getConfig()...
[364.957775] GateHWSpinlock_getConfig() baseAddr = 0x4a0f6000
[364.957784] size = 0x1000
offset = 0x800
[364.957791] status = 0
[364.957798] DONE
[364.957805] Sending response...
[364.957819] Retrieving command...
[364.957933] LAD_GATEMP_START: calling GateMP_start()...
[364.957943] status = 0
[364.957950] DONE
[364.957957] Sending response...
[364.957971] Retrieving command...
[364.958008] LAD_GATEMP_GETNUMRESOURCES: calling GateMP_getNumResources()...
[364.958017] status = 0
[364.958024] DONE
[364.958030] Sending response...
[364.958045] Retrieving command...
[364.958082] LAD_NAMESERVER_GET: calling NameServer_get(0x244b218, '_GateMP_TI_dGate'[364.958104] )...
[364.958117] NameServer_getLocal: entry key: '_GateMP_TI_dGate' not found!
[364.958126] NameServer_getRemote: no socket connection to processor 1
[364.958134] NameServer_getRemote: no socket connection to processor 2
[364.958142] NameServer_getRemote: no socket connection to processor 3
[364.958149] NameServer_getRemote: no socket connection to processor 4
[364.958157] value = 0x10
[364.958164] status = -5
[364.958171] DONE
[364.958178] Sending response...
[364.958192] Retrieving command...
[364.958262] LAD_MESSAGEQ_CREATE: calling MessageQ_create(0x4b5650, 0x4b5670)...
[364.958273] MessageQ_create: creating 'HOST:MsgQ:01'
[364.958283] MessageQ_create: returning obj=0x244d640, qid=0x80
[364.958292] status = 0
[364.958298] DONE
[364.958305] Sending response...
[364.958319] Retrieving command...
[364.958357] LAD_MESSAGEQ_ANNOUNCE: calling MessageQ_announce(0x4b5650, 0x244d640)...
[364.958368] MessageQ_announce: announcing 0x244d640
[364.958378] NameServer_add: Entered key: 'HOST:MsgQ:01', data: 0x80
[364.958387] status = 0
[364.958394] DONE
[364.958400] Sending response...
[364.958415] Retrieving command...
[364.958453] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[364.958465] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[364.958473] NameServer_getRemote: no socket connection to processor 1
[364.958480] NameServer_getRemote: no socket connection to processor 2
[364.958488] NameServer_getRemote: no socket connection to processor 3
[364.958495] NameServer_getRemote: no socket connection to processor 4
[364.958502] value = 0x80
[364.958509] status = -5
[364.958516] DONE
[364.958522] Sending response...
[364.958536] Retrieving command...
[365.958687] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[365.958713] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[365.958725] NameServer_getRemote: no socket connection to processor 1
[365.958734] NameServer_getRemote: no socket connection to processor 2
[365.958743] NameServer_getRemote: no socket connection to processor 3
[365.958752] NameServer_getRemote: no socket connection to processor 4
[365.958760] value = 0x80
[365.958768] status = -5
[365.958776] DONE
[365.958783] Sending response...
[365.958804] Retrieving command...
[366.958958] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[366.958979] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[366.958991] NameServer_getRemote: no socket connection to processor 1
[366.959000] NameServer_getRemote: no socket connection to processor 2
[366.959009] NameServer_getRemote: no socket connection to processor 3
[366.959018] NameServer_getRemote: no socket connection to processor 4
[366.959027] value = 0x80
[366.959035] status = -5
[366.959043] DONE
[366.959051] Sending response...
[366.959070] Retrieving command...
[367.959228] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[367.959251] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[367.959263] NameServer_getRemote: no socket connection to processor 1
[367.959272] NameServer_getRemote: no socket connection to processor 2
[367.959281] NameServer_getRemote: no socket connection to processor 3
[367.959289] NameServer_getRemote: no socket connection to processor 4
[367.959297] value = 0x80
[367.959306] status = -5
[367.959314] DONE
[367.959322] Sending response...
[367.959341] Retrieving command...
[368.959499] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[368.959520] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[368.959531] NameServer_getRemote: no socket connection to processor 1
[368.959541] NameServer_getRemote: no socket connection to processor 2
[368.959550] NameServer_getRemote: no socket connection to processor 3
[368.959559] NameServer_getRemote: no socket connection to processor 4
[368.959567] value = 0x80
[368.959576] status = -5
[368.959599] DONE
[368.959609] Sending response...
[368.959630] Retrieving command...
[369.959783] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[369.959803] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[369.959815] NameServer_getRemote: no socket connection to processor 1
[369.959824] NameServer_getRemote: no socket connection to processor 2
[369.959833] NameServer_getRemote: no socket connection to processor 3
[369.959842] NameServer_getRemote: no socket connection to processor 4
[369.959850] value = 0x80
[369.959859] status = -5
[369.959867] DONE
[369.959875] Sending response...
[369.959894] Retrieving command...
[370.960051] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[370.960074] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[370.960085] NameServer_getRemote: no socket connection to processor 1
[370.960094] NameServer_getRemote: no socket connection to processor 2
[370.960103] NameServer_getRemote: no socket connection to processor 3
[370.960111] NameServer_getRemote: no socket connection to processor 4
[370.960119] value = 0x80
[370.960128] status = -5
[370.960136] DONE
[370.960144] Sending response...
[370.960163] Retrieving command...
[371.960309] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[371.960333] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[371.960345] NameServer_getRemote: no socket connection to processor 1
[371.960355] NameServer_getRemote: no socket connection to processor 2
[371.960364] NameServer_getRemote: no socket connection to processor 3
[371.960373] NameServer_getRemote: no socket connection to processor 4
[371.960381] value = 0x80
[371.960389] status = -5
[371.960397] DONE
[371.960406] Sending response...
[371.960426] Retrieving command...
[372.960583] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[372.960604] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[372.960615] NameServer_getRemote: no socket connection to processor 1
[372.960625] NameServer_getRemote: no socket connection to processor 2
[372.960634] NameServer_getRemote: no socket connection to processor 3
[372.960642] NameServer_getRemote: no socket connection to processor 4
[372.960650] value = 0x80
[372.960659] status = -5
[372.960667] DONE
[372.960674] Sending response...
[372.960694] Retrieving command...
[373.960845] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[373.960866] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[373.960877] NameServer_getRemote: no socket connection to processor 1
[373.960887] NameServer_getRemote: no socket connection to processor 2
[373.960896] NameServer_getRemote: no socket connection to processor 3
[373.960904] NameServer_getRemote: no socket connection to processor 4
[373.960913] value = 0x80
[373.960921] status = -5
[373.960929] DONE
[373.960937] Sending response...
[373.960961] Retrieving command...
[374.961115] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[374.961135] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[374.961146] NameServer_getRemote: no socket connection to processor 1
[374.961155] NameServer_getRemote: no socket connection to processor 2
[374.961165] NameServer_getRemote: no socket connection to processor 3
[374.961173] NameServer_getRemote: no socket connection to processor 4
[374.961182] value = 0x80
[374.961190] status = -5
[374.961198] DONE
[374.961206] Sending response...
[374.961228] Retrieving command...
[375.961381] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[375.961401] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[375.961412] NameServer_getRemote: no socket connection to processor 1
[375.961422] NameServer_getRemote: no socket connection to processor 2
[375.961430] NameServer_getRemote: no socket connection to processor 3
[375.961439] NameServer_getRemote: no socket connection to processor 4
[375.961460] value = 0x80
[375.961472] status = -5
[375.961480] DONE
[375.961489] Sending response...
[375.961511] Retrieving command...
[376.961665] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[376.961687] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[376.961698] NameServer_getRemote: no socket connection to processor 1
[376.961708] NameServer_getRemote: no socket connection to processor 2
[376.961717] NameServer_getRemote: no socket connection to processor 3
[376.961725] NameServer_getRemote: no socket connection to processor 4
[376.961734] value = 0x80
[376.961742] status = -5
[376.961750] DONE
[376.961758] Sending response...
[376.961780] Retrieving command...
[377.961931] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[377.961953] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[377.961964] NameServer_getRemote: no socket connection to processor 1
[377.961974] NameServer_getRemote: no socket connection to processor 2
[377.961983] NameServer_getRemote: no socket connection to processor 3
[377.961992] NameServer_getRemote: no socket connection to processor 4
[377.962000] value = 0x80
[377.962008] status = -5
[377.962016] DONE
[377.962024] Sending response...
[377.962047] Retrieving command...
[378.962207] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[378.962227] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[378.962240] NameServer_getRemote: no socket connection to processor 1
[378.962250] NameServer_getRemote: no socket connection to processor 2
[378.962259] NameServer_getRemote: no socket connection to processor 3
[378.962267] NameServer_getRemote: no socket connection to processor 4
[378.962276] value = 0x80
[378.962285] status = -5
[378.962293] DONE
[378.962301] Sending response...
[378.962324] Retrieving command...
[379.962472] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[379.962491] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[379.962503] NameServer_getRemote: no socket connection to processor 1
[379.962513] NameServer_getRemote: no socket connection to processor 2
[379.962522] NameServer_getRemote: no socket connection to processor 3
[379.962530] NameServer_getRemote: no socket connection to processor 4
[379.962538] value = 0x80
[379.962547] status = -5
[379.962555] DONE
[379.962562] Sending response...
[379.962584] Retrieving command...
[380.962727] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[380.962746] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[380.962757] NameServer_getRemote: no socket connection to processor 1
[380.962766] NameServer_getRemote: no socket connection to processor 2
[380.962775] NameServer_getRemote: no socket connection to processor 3
[380.962784] NameServer_getRemote: no socket connection to processor 4
[380.962792] value = 0x80
[380.962801] status = -5
[380.962809] DONE
[380.962817] Sending response...
[380.962838] Retrieving command...
[381.962984] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[381.963006] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[381.963018] NameServer_getRemote: no socket connection to processor 1
[381.963028] NameServer_getRemote: no socket connection to processor 2
[381.963037] NameServer_getRemote: no socket connection to processor 3
[381.963045] NameServer_getRemote: no socket connection to processor 4
[381.963054] value = 0x80
[381.963063] status = -5
[381.963071] DONE
[381.963078] Sending response...
[381.963100] Retrieving command...
[382.963280] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[382.963309] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[382.963321] NameServer_getRemote: no socket connection to processor 1
[382.963332] NameServer_getRemote: no socket connection to processor 2
[382.963341] NameServer_getRemote: no socket connection to processor 3
[382.963365] NameServer_getRemote: no socket connection to processor 4
[382.963375] value = 0x80
[382.963385] status = -5
[382.963393] DONE
[382.963402] Sending response...
[382.963427] Retrieving command...
[383.963583] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[383.963606] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[383.963617] NameServer_getRemote: no socket connection to processor 1
[383.963627] NameServer_getRemote: no socket connection to processor 2
[383.963636] NameServer_getRemote: no socket connection to processor 3
[383.963645] NameServer_getRemote: no socket connection to processor 4
[383.963653] value = 0x80
[383.963662] status = -5
[383.963670] DONE
[383.963678] Sending response...
[383.963700] Retrieving command...
[384.963853] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[384.963873] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[384.963884] NameServer_getRemote: no socket connection to processor 1
[384.963894] NameServer_getRemote: no socket connection to processor 2
[384.963903] NameServer_getRemote: no socket connection to processor 3
[384.963911] NameServer_getRemote: no socket connection to processor 4
[384.963920] value = 0x80
[384.963928] status = -5
[384.963936] DONE
[384.963944] Sending response...
[384.963967] Retrieving command...
[385.964144] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[385.964173] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[385.964186] NameServer_getRemote: no socket connection to processor 1
[385.964197] NameServer_getRemote: no socket connection to processor 2
[385.964206] NameServer_getRemote: no socket connection to processor 3
[385.964214] NameServer_getRemote: no socket connection to processor 4
[385.964223] value = 0x80
[385.964232] status = -5
[385.964240] DONE
[385.964249] Sending response...
[385.964273] Retrieving command...
[386.964429] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[386.964451] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[386.964463] NameServer_getRemote: no socket connection to processor 1
[386.964472] NameServer_getRemote: no socket connection to processor 2
[386.964481] NameServer_getRemote: no socket connection to processor 3
[386.964489] NameServer_getRemote: no socket connection to processor 4
[386.964498] value = 0x80
[386.964506] status = -5
[386.964514] DONE
[386.964522] Sending response...
[386.964545] Retrieving command...
[387.964707] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[387.964728] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[387.964740] NameServer_getRemote: no socket connection to processor 1
[387.964749] NameServer_getRemote: no socket connection to processor 2
[387.964759] NameServer_getRemote: no socket connection to processor 3
[387.964767] NameServer_getRemote: no socket connection to processor 4
[387.964776] value = 0x80
[387.964784] status = -5
[387.964792] DONE
[387.964800] Sending response...
[387.964822] Retrieving command...
[388.964979] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[388.965000] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[388.965012] NameServer_getRemote: no socket connection to processor 1
[388.965021] NameServer_getRemote: no socket connection to processor 2
[388.965030] NameServer_getRemote: no socket connection to processor 3
[388.965039] NameServer_getRemote: no socket connection to processor 4
[388.965047] value = 0x80
[388.965055] status = -5
[388.965064] DONE
[388.965072] Sending response...
[388.965094] Retrieving command...
[389.965247] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[389.965267] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[389.965279] NameServer_getRemote: no socket connection to processor 1
[389.965303] NameServer_getRemote: no socket connection to processor 2
[389.965315] NameServer_getRemote: no socket connection to processor 3
[389.965324] NameServer_getRemote: no socket connection to processor 4
[389.965333] value = 0x80
[389.965342] status = -5
[389.965350] DONE
[389.965358] Sending response...
[389.965381] Retrieving command...
[390.965535] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[390.965555] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[390.965567] NameServer_getRemote: no socket connection to processor 1
[390.965577] NameServer_getRemote: no socket connection to processor 2
[390.965586] NameServer_getRemote: no socket connection to processor 3
[390.965594] NameServer_getRemote: no socket connection to processor 4
[390.965603] value = 0x80
[390.965611] status = -5
[390.965619] DONE
[390.965627] Sending response...
[390.965650] Retrieving command...
[391.965804] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[391.965827] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[391.965838] NameServer_getRemote: no socket connection to processor 1
[391.965849] NameServer_getRemote: no socket connection to processor 2
[391.965858] NameServer_getRemote: no socket connection to processor 3
[391.965867] NameServer_getRemote: no socket connection to processor 4
[391.965875] value = 0x80
[391.965884] status = -5
[391.965892] DONE
[391.965900] Sending response...
[391.965922] Retrieving command...
[392.966087] LAD_NAMESERVER_GETUINT32: calling NameServer_getUInt32(0x244d558, 'DSP1:MsgQ:01')...
[392.966113] NameServer_getLocal: entry key: 'DSP1:MsgQ:01' not found!
[392.966126] NameServer_getRemote: no socket connection to processor 1
[392.966136] NameServer_getRemote: no socket connection to processor 2
[392.966145] NameServer_getRemote: no socket connection to processor 3
[392.966154] NameServer_getRemote: no socket connection to processor 4
[392.966163] value = 0x80
[392.966172] status = -5
[392.966180] DONE
[392.966189] Sending response...
[392.966212] Retrieving command...
[393.933731] LAD_MESSAGEQ_DESTROY: calling MessageQ_destroy()...
[393.933753] MessageQ_destroy: entered, refCount=1
[393.933764] MessageQ_delete: deleting 0x244d640
[393.933786] MessageQ_delete: returning 0
[393.933798] MessageQ_destroy: exiting, refCount=0
[393.933807] status = 0
[393.933816] DONE
[393.933825] Sending response...
[393.933849] Retrieving command...
[393.933909] LAD_NAMESERVER_DESTROY: calling NameServer_destroy()...
[393.933921] NameServer_destroy: entered, refCount=2
[393.933931] NameServer_destroy(): refCount(1) > 0, exiting
[393.933940] NameServer_destroy: exiting, refCount=1
[393.933948] status = 0
[393.933956] DONE
[393.933963] Sending response...
[393.933982] Retrieving command...
[393.934052]
LAD_DISCONNECT: [393.934063]
client handle = 0[393.934072]
closing FIFO /tmp/LAD/1825 (filePtr=0x244c3e8)
[393.934104] done, unlinking /tmp/LAD/1825
[393.934148] DONE
[393.934160] Retrieving command...
[393.934902] EOF detected on FIFO, closing FIFO: /tmp/LAD/LADCMDS
[393.934933]
opening FIFO: /tmp/LAD/LADCMDS
root@predixedge:/tmp/LAD#

So it seems that the application can't locate a message queue.

Not being a TI IPC veteran I don't know how to go about working out where the problems lies and any clues will be gratefully received.

Thanks in advcance

over 8 years ago

0 Rex Chang over 8 years ago

TI__Guru 50170 points

Hi, Peter,

Is the DSP image from yocto 5.0 build or from older release? Can you also try the DSP2 image to see if it works. We had a known issue that the ex02_messageq example works for DSP2, but not DSP1, and DSP1 was working in 4.1 release, but failed in 4.2 and later. If the DSP1 image is from older release, that matches the behavior. The issue is the clock configuration, and the fix should be in 5.0 release. You can either take the dsp image from 5.0 yocto build, or rebuild it using ProcSDK RTOS 5.0. The e2e thread of this issue is discussed in e2e.ti.com/.../672327

Rex

0 Peter Smith48 over 8 years ago in reply to Rex Chang

Intellectual 310 points

Hi Rex,

All the images are built from the commit of meta-ti aligned with the Processor SDK 5.0 release, there is no mixing of Processor SDK versions, the development build of our distro includes the IPC examples in the root file system. I tried DSP2 but the act of loading the firmware into DSP2 crashes the kernel hard in this case (board needs to be power cycled to recover). The board I have is a AM5728 IDK Rev 1.2A if that is at all significant.

Out of interest is the IPC software/firmware sensitive to any kernel configuration items at all?

Peter

0 Peter Smith48 over 8 years ago in reply to Peter Smith48

Intellectual 310 points

Correction, the kernel crash only occurs if ./app_host DSP1 has been run previously. However I notice that the cma allocation fails

root@predixedge:/sys/bus/platform/drivers/omap-rproc# [ 152.367581] remoteproc remoteproc3: powering up 41000000.dsp
[ 152.373314] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4503864
[ 152.387975] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 152.393872] omap-iommu 41501000.mmu: 41501000.mmu: version 3.0
[ 152.399815] omap-iommu 41502000.mmu: 41502000.mmu: version 3.0
[ 152.410200] alloc_contig_range: [9f300, 9f600) PFNs busy
[ 152.415994] alloc_contig_range: [9f400, 9f700) PFNs busy
[ 152.422232] alloc_contig_range: [9f500, 9f800) PFNs busy
[ 152.427599] cma: cma_alloc: alloc failed, req-size: 768 pages, ret: -16
[ 152.434261] omap-rproc 41000000.dsp: failed to allocate dma memory: len 0x300000
[ 152.441687] remoteproc remoteproc3: Failed to process resources: -12
[ 152.454943] omap_hwmod: mmu0_dsp2: _wait_target_disable failed

0 Peter Smith48 over 8 years ago in reply to Peter Smith48

Intellectual 310 points

Hi Rex, I have tried upgrading all of the ipc recipes (in meta-ti/recipes-ti/ipc) to the latest versions on the rocko branch, but exactly the same behavior occurs. This should mean I am using the latest fixes (yes?). Peter

0 Rex Chang over 8 years ago in reply to Peter Smith48

TI__Guru 50170 points

HI, Peter,

Let me try the prebuilt IPC example images and get back to you.

Rex

0 Rex Chang over 8 years ago in reply to Rex Chang

TI__Guru 50170 points

Hi, Peter,

I tried the prebuilt images and don't see the issue. Could you try the prebuilt images in the released filesystem?
When you run the IPC examples, do you have OpenCL disabled? you can delete softlink /etc/systemd/system/basic.target.wants/ti-mct-daemon.service to prevent ti-mctd from running during the boot. OpenCL has a conflict to IPC in memory allocation. It may not show the symptom but we recommend to disable OpenCL daemon, ti-mctd. you can also dump dsp traces with "cat /sys/kernel/debug/remoteproc/remoteproc2/trace0". remoteproc2 is for DSP1, or dump the name sysfs to be sure it is the correct core.

Things in Kernel such as remoteproc and CMA reserved area changes may affect IPC. Others shouldn't.

Arago 2018.04 am57xx-evm ttyS2

am57xx-evm login: root
root@am57xx-evm:~#
root@am57xx-evm:~# uname -a
Linux am57xx-evm 4.14.40-g4796173fc5 #1 SMP PREEMPT Wed Jul 25 17:05:51 UTC 2018 armv7l GNU/Linux
root@am57xx-evm:~#
root@am57xx-evm:~# ls -l /lib/firmware/dra7-dsp*-fw.xe66
lrwxrwxrwx 1 root root 58 Jul 22 2018 /lib/firmware/dra7-dsp1-fw.xe66 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_dsp1.xe66
lrwxrwxrwx 1 root root 58 Jul 22 2018 /lib/firmware/dra7-dsp2-fw.xe66 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_dsp2.xe66
root@am57xx-evm:~#
root@am57xx-evm:~#
root@am57xx-evm:~# cd /usr/bin/ipc/examples/ex02_messageq/debug/
root@am57xx-evm:/usr/bin/ipc/examples/ex02_messageq/debug# ls
app_host server_dsp2.xe66 server_ipu2.xem4
server_dsp1.xe66 server_ipu1.xem4
root@am57xx-evm:/usr/bin/ipc/examples/ex02_messageq/debug# ./app_host DSP1
--> main:
--> Main_main:
--> App_create:
App_create: Host is ready
<-- App_create:
--> App_exec:
App_exec: sending message 1
App_exec: sending message 2
App_exec: sending message 3
App_exec: message received, sending message 4
App_exec: message received, sending message 5
App_exec: message received, sending message 6
App_exec: message received, sending message 7
App_exec: message received, sending message 8
App_exec: message received, sending message 9
App_exec: message received, sending message 10
App_exec: message received, sending message 11
App_exec: message received, sending message 12
App_exec: message received, sending message 13
App_exec: message received, sending message 14
App_exec: message received, sending message 15
App_exec: message received
App_exec: message received
App_exec: message received
<-- App_exec: 0
--> App_delete:
<-- App_delete:
<-- Main_main:
<-- main:
root@am57xx-evm:/usr/bin/ipc/examples/ex02_messageq/debug#
root@am57xx-evm:/usr/bin/ipc/examples/ex02_messageq/debug#
root@am57xx-evm:/usr/bin/ipc/examples/ex02_messageq/debug# dmesg | grep dsp
[ 0.000000] OF: reserved mem: initialized node dsp1-memory@99000000, compatible id shared-dma-pool
[ 0.000000] OF: reserved mem: initialized node dsp2-memory@9f000000, compatible id shared-dma-pool
[ 0.458778] iommu: Adding device 40800000.dsp to group 0
[ 0.459012] iommu: Adding device 41000000.dsp to group 3
[ 14.640163] omap-rproc 40800000.dsp: assigned reserved memory node dsp1-memory@99000000
[ 14.674823] remoteproc remoteproc2: 40800000.dsp is available
[ 14.682327] omap-rproc 41000000.dsp: assigned reserved memory node dsp2-memory@9f000000
[ 14.694531] remoteproc remoteproc3: 41000000.dsp is available
[ 15.418400] remoteproc remoteproc2: powering up 40800000.dsp
[ 15.424108] remoteproc remoteproc2: Booting fw image dra7-dsp1-fw.xe66, size 4692376
[ 15.438614] omap_hwmod: mmu0_dsp1: _wait_target_disable failed
[ 15.478366] remoteproc remoteproc2: remote processor 40800000.dsp is now up
[ 15.673618] remoteproc remoteproc3: powering up 41000000.dsp
[ 15.687175] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4529796
[ 15.693890] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 15.772221] remoteproc remoteproc3: remote processor 41000000.dsp is now up
root@am57xx-evm:/usr/bin/ipc/examples/ex02_messageq/debug#

0 Peter Smith48 over 8 years ago in reply to Rex Chang

Intellectual 310 points

Hi,

I will try the pre-built examples for sure as my next step and report back.

I can confirm that OpenCL is disabled and the daemon is not running.

I am however confused as to why I am getting memory allocation errors when I try and start DSP2

e.g.root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 41000000.dsp > bind
[ 1374.103736] omap-rproc 41000000.dsp: assigned reserved memory node dsp2-memory@9f000000
[ 1374.111889] remoteproc remoteproc3: 41000000.dsp is available
root@predixedge:/sys/bus/platform/drivers/omap-rproc# [ 1374.125402] remoteproc remoteproc3: powering up 41000000.dsp
[ 1374.134726] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4481184
[ 1374.149360] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 1374.155250] omap-iommu 41501000.mmu: 41501000.mmu: version 3.0
[ 1374.161182] omap-iommu 41502000.mmu: 41502000.mmu: version 3.0
[ 1374.169892] alloc_contig_range: [9f300, 9f600) PFNs busy
[ 1374.175603] alloc_contig_range: [9f400, 9f700) PFNs busy
[ 1374.181338] alloc_contig_range: [9f500, 9f800) PFNs busy
[ 1374.186831] cma: cma_alloc: alloc failed, req-size: 768 pages, ret: -16
[ 1374.193493] omap-rproc 41000000.dsp: failed to allocate dma memory: len 0x300000
[ 1374.200922] remoteproc remoteproc3: Failed to process resources: -12
[ 1374.214185] omap_hwmod: mmu0_dsp2: _wait_target_disable failed

Does this point to a bad DTS/DTB being loaded?

I have not altered any of the DTS files in meta-ti and I have RESERVE_CMEM="1" set in my local.conf (my understanding is that this controls the insertion of the cmem dtsi, the #include of the cmem.dtsi certainly seems to have been inserted at the end of am572x_evm.dts?

Peter

0 Rex Chang over 8 years ago in reply to Peter Smith48

TI__Guru 50170 points

Hi, Peter,

I suspect it has something to do with the following prints which I don't see in my run. Is it from running ex02_messageq example?

[ 1374.169892] alloc_contig_range: [9f300, 9f600) PFNs busy
[ 1374.175603] alloc_contig_range: [9f400, 9f700) PFNs busy
[ 1374.181338] alloc_contig_range: [9f500, 9f800) PFNs busy

When kernel first boot up, do you see cma error? By default, DSP1 reserved 64MB of CMA, but DSP2 only 8MB. Also, from the print, is there overlapping of memory allocation? Does your application make these allocate requests or has these memory reserved in DSP?

My logs are shown below:

am57xx-evm login: root
root@am57xx-evm:~# dmesg | grep remoteproc
[ 11.703707] remoteproc remoteproc0: 58820000.ipu is available
[ 11.724902] remoteproc remoteproc1: 55020000.ipu is available
[ 11.743445] remoteproc remoteproc2: 40800000.dsp is available
[ 11.765706] remoteproc remoteproc3: 41000000.dsp is available
[ 12.505596] remoteproc remoteproc1: powering up 55020000.ipu
[ 12.515073] remoteproc remoteproc1: Booting fw image dra7-ipu2-fw.xem4, size 3743076
[ 12.678737] remoteproc remoteproc1: registered virtio0 (type 7)
[ 12.687389] remoteproc remoteproc1: remote processor 55020000.ipu is now up
[ 13.167745] remoteproc remoteproc2: powering up 40800000.dsp
[ 13.181731] remoteproc remoteproc2: Booting fw image dra7-dsp1-fw.xe66, size 4692376
[ 13.260534] remoteproc remoteproc2: registered virtio1 (type 7)
[ 13.267543] remoteproc remoteproc2: remote processor 40800000.dsp is now up
[ 13.385841] remoteproc remoteproc0: powering up 58820000.ipu
[ 13.391651] remoteproc remoteproc0: Booting fw image dra7-ipu1-fw.xem4, size 6636332
[ 13.407327] remoteproc remoteproc3: powering up 41000000.dsp
[ 13.413197] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4529796
[ 13.481452] remoteproc remoteproc0: registered virtio2 (type 7)
[ 13.481456] remoteproc remoteproc0: remote processor 58820000.ipu is now up
[ 13.504509] remoteproc remoteproc3: registered virtio3 (type 7)
[ 13.504513] remoteproc remoteproc3: remote processor 41000000.dsp is now up
[ 14.155421] remoteproc remoteproc4: 4b234000.pru is available
[ 14.155700] remoteproc remoteproc5: 4b238000.pru is available
[ 14.155933] remoteproc remoteproc6: 4b2b4000.pru is available
[ 14.156182] remoteproc remoteproc7: 4b2b8000.pru is available
[ 20.256701] remoteproc remoteproc7: powering up 4b2b8000.pru
[ 20.311718] remoteproc remoteproc7: Booting fw image ti-pruss/am57xx-pru1-prueth-fw.elf, size 5060
[ 20.361329] remoteproc remoteproc7: remote processor 4b2b8000.pru is now up
[ 20.396333] remoteproc remoteproc6: powering up 4b2b4000.pru
[ 20.430912] remoteproc remoteproc6: Booting fw image ti-pruss/am57xx-pru0-prueth-fw.elf, size 5028
[ 20.457736] remoteproc remoteproc6: remote processor 4b2b4000.pru is now up

root@am57xx-evm:~# dmesg | grep omap-rproc
[ 11.678440] omap-rproc 58820000.ipu: assigned reserved memory node ipu1-memory@9d000000
[ 11.712952] omap-rproc 55020000.ipu: assigned reserved memory node ipu2-memory@95800000
[ 11.732221] omap-rproc 40800000.dsp: assigned reserved memory node dsp1-memory@99000000
[ 11.754007] omap-rproc 41000000.dsp: assigned reserved memory node dsp2-memory@9f000000

root@am57xx-evm:~# cd /sys/bus/platform/drivers/omap-rproc/
root@am57xx-evm:/sys/bus/platform/drivers/omap-rproc# echo 41000000.dsp > unbind
[ 760.955989] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 760.962798] remoteproc remoteproc3: stopped remote processor 41000000.dsp
[ 760.971046] remoteproc remoteproc3: releasing 41000000.dsp
root@am57xx-evm:/sys/bus/platform/drivers/omap-rproc#
root@am57xx-evm:/sys/bus/platform/drivers/omap-rproc#
root@am57xx-evm:/sys/bus/platform/drivers/omap-rproc# echo 41000000.dsp > bind
[ 765.011426] omap-rproc 41000000.dsp: assigned reserved memory node dsp2-memory@9f000000
[ 765.019566] remoteproc remoteproc3: 41000000.dsp is available
root@am57xx-evm:/sys/bus/platform/drivers/omap-rproc# [ 765.033889] remoteproc remoteproc3: powering up 41000000.dsp
[ 765.039584] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4529796
[ 765.054176] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 765.060066] omap-iommu 41501000.mmu: 41501000.mmu: version 3.0
[ 765.065985] omap-iommu 41502000.mmu: 41502000.mmu: version 3.0
[ 765.079585] virtio_rpmsg_bus virtio3: rpmsg host is online
[ 765.082050] virtio_rpmsg_bus virtio3: creating channel rpmsg-proto addr 0x3d
[ 765.092284] remoteproc remoteproc3: registered virtio3 (type 7)
[ 765.098229] remoteproc remoteproc3: remote processor 41000000.dsp is now up

root@am57xx-evm:/sys/bus/platform/drivers/omap-rproc# ls -l /lib/firmware/dra7-dsp*-fw.xe66
lrwxrwxrwx 1 root root 58 Jul 22 01:52 /lib/firmware/dra7-dsp1-fw.xe66 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_dsp1.xe66
lrwxrwxrwx 1 root root 58 Jul 22 01:37 /lib/firmware/dra7-dsp2-fw.xe66 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_dsp2.xe66

Rex

0 Peter Smith48 over 8 years ago in reply to Rex Chang

Intellectual 310 points

Hi,

I discovered an error in my (under development) Yocto layers.

I was not building the Processor SDK kernel, but the kernel from meta-ti (which I see are in different git repo's).

I was also not picking up version 3.47.02 of the IPC components, here is what I get now with bot these things in place.

I have NOT edited any .dts/.dtsi files, they are all being selected by the kernel build with the Yocto machine set to am57xx-evm

RESERVE_CMEM is set to "1" in my local.conf

root@predixedge:~# uname -a

Linux predixedge 4.14.40-g4796173fc5 #2 SMP PREEMPT Wed Sep 5 11:47:13 UTC 2018 armv7l GNU/Linux

root@predixedge:~# cat /proc/cmem

Block 0: Pool 0: 1 bufs size 0xc000000 (0xc000000 requested)

Pool 0 busy bufs:

Pool 0 free bufs:
id 0: phys addr 0xa0000000

root@predixedge:~# dmesg | grep -i cma
[ 0.000000] Reserved memory: created CMA memory pool at 0x0000000095800000, size 56 MiB
[ 0.000000] Reserved memory: created CMA memory pool at 0x0000000099000000, size 64 MiB
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000009d000000, size 32 MiB
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000009f000000, size 8 MiB
[ 0.000000] cma: Reserved 24 MiB at 0x00000000fe400000
[ 0.000000] Memory: 1673584K/1897472K available (10240K kernel code, 359K rwdata, 2668K rodata, 2048K init, 301K bss, 35472K reserved, 188416K cma-reserved, 1283072K highmem)

root@predixedge:~# dmesg | grep remoteproc
[ 6.079139] remoteproc remoteproc0: 58820000.ipu is available
[ 6.103667] remoteproc remoteproc1: 55020000.ipu is available
[ 6.129391] remoteproc remoteproc2: 40800000.dsp is available
[ 6.151562] remoteproc remoteproc3: 41000000.dsp is available
[ 6.718524] remoteproc remoteproc0: powering up 58820000.ipu
[ 6.724419] remoteproc remoteproc0: Booting fw image dra7-ipu1-fw.xem4, size 4442884
[ 6.755525] remoteproc remoteproc0: registered virtio0 (type 7)
[ 6.761512] remoteproc remoteproc0: remote processor 58820000.ipu is now up
[ 7.073671] remoteproc remoteproc1: powering up 55020000.ipu
[ 7.073682] remoteproc remoteproc1: Booting fw image dra7-ipu2-fw.xem4, size 4442884
[ 7.107299] remoteproc remoteproc2: powering up 40800000.dsp
[ 7.123719] remoteproc remoteproc2: Booting fw image dra7-dsp1-fw.xe66, size 4665540
[ 7.210635] remoteproc remoteproc1: registered virtio1 (type 7)
[ 7.218106] remoteproc remoteproc2: registered virtio2 (type 7)
[ 7.218110] remoteproc remoteproc2: remote processor 40800000.dsp is now up
[ 7.263840] remoteproc remoteproc1: remote processor 55020000.ipu is now up
[ 7.417570] remoteproc remoteproc3: powering up 41000000.dsp
[ 7.424518] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4503864
[ 7.476893] remoteproc remoteproc3: registered virtio3 (type 7)
[ 7.484143] remoteproc remoteproc3: remote processor 41000000.dsp is now up
[ 8.228885] remoteproc remoteproc4: 4b234000.pru is available
[ 8.234674] remoteproc remoteproc5: 4b238000.pru is available
[ 8.237141] remoteproc remoteproc6: 4b2b4000.pru is available
[ 8.237366] remoteproc remoteproc7: 4b2b8000.pru is available
[ 39.255163] remoteproc remoteproc6: powering up 4b2b4000.pru
[ 39.273561] remoteproc remoteproc6: Booting fw image ti-pruss/am57xx-pru0-prueth-fw.elf, size 5028
[ 39.294553] remoteproc remoteproc6: remote processor 4b2b4000.pru is now up
[ 39.335179] remoteproc remoteproc7: powering up 4b2b8000.pru
[ 39.356701] remoteproc remoteproc7: Booting fw image ti-pruss/am57xx-pru1-prueth-fw.elf, size 5060
[ 39.377935] remoteproc remoteproc7: remote processor 4b2b8000.pru is now up

As you can see there are no errors on boot up of the board, the firmware's linked below are loaded from the rootfs.

root@predixedge:~# ls -l /lib/firmware/
lrwxrwxrwx 1 root root 58 Sep 5 2018 dra7-dsp1-fw.xe66 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_dsp1.xe66
lrwxrwxrwx 1 root root 58 Sep 5 2018 dra7-dsp2-fw.xe66 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_dsp2.xe66
lrwxrwxrwx 1 root root 58 Sep 5 2018 dra7-ipu1-fw.xem4 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_ipu1.xem4
lrwxrwxrwx 1 root root 58 Sep 5 2018 dra7-ipu2-fw.xem4 -> /usr/bin/ipc/examples/ex02_messageq/debug/server_ipu2.xem4
-rw-r--r-- 1 root root 186 Sep 4 2018 goodix_9271_cfg.bin
drwxr-xr-x 6 root root 4096 Sep 5 2018 ipc
drwxr-xr-x 2 root root 4096 Sep 5 2018 ti-pruss
-rw-r--r-- 1 root root 4002 Sep 5 2018 vpdma-1b8.bin

root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 41000000.dsp > unbind
[ 546.616412] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 546.622572] remoteproc remoteproc3: stopped remote processor 41000000.dsp
[ 546.629700] remoteproc remoteproc3: releasing 41000000.dsp

root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 41000000.dsp > bind
[ 579.701658] omap-rproc 41000000.dsp: assigned reserved memory node dsp2-memory@9f000000
[ 579.713071] remoteproc remoteproc3: 41000000.dsp is available
root@predixedge:/sys/bus/platform/drivers/omap-rproc# [ 579.727788] remoteproc remoteproc3: powering up 41000000.dsp
[ 579.734876] remoteproc remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 4503864
[ 579.749774] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
[ 579.755674] omap-iommu 41501000.mmu: 41501000.mmu: version 3.0
[ 579.761596] omap-iommu 41502000.mmu: 41502000.mmu: version 3.0
[ 579.768069] alloc_contig_range: [9f000, 9f003) PFNs busy
[ 579.773927] alloc_contig_range: [9f004, 9f007) PFNs busy
[ 579.779557] alloc_contig_range: [9f000, 9f003) PFNs busy
[ 579.785508] alloc_contig_range: [9f004, 9f007) PFNs busy
[ 579.799223] virtio_rpmsg_bus virtio3: rpmsg host is online
[ 579.805094] remoteproc remoteproc3: registered virtio3 (type 7)
[ 579.811281] remoteproc remoteproc3: remote processor 41000000.dsp is now up
[ 579.818721] virtio_rpmsg_bus virtio3: creating channel rpmsg-proto addr 0x3d

root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 40800000.dsp > unbind
[ 616.146299] omap_hwmod: mmu0_dsp1: _wait_target_disable failed
[ 616.152832] remoteproc remoteproc2: stopped remote processor 40800000.dsp
[ 616.161310] remoteproc remoteproc2: releasing 40800000.dsp

root@predixedge:/sys/bus/platform/drivers/omap-rproc# echo 40800000.dsp > bind
[ 636.291603] omap-rproc 40800000.dsp: assigned reserved memory node dsp1-memory@99000000
[ 636.301534] remoteproc remoteproc2: 40800000.dsp is available
root@predixedge:/sys/bus/platform/drivers/omap-rproc# [ 636.314285] remoteproc remoteproc2: powering up 40800000.dsp
[ 636.320584] remoteproc remoteproc2: Booting fw image dra7-dsp1-fw.xe66, size 4665540
[ 636.335080] omap_hwmod: mmu0_dsp1: _wait_target_disable failed
[ 636.340969] omap-iommu 40d01000.mmu: 40d01000.mmu: version 3.0
[ 636.346883] omap-iommu 40d02000.mmu: 40d02000.mmu: version 3.0
[ 636.353120] alloc_contig_range: [99004, 99007) PFNs busy
[ 636.365781] virtio_rpmsg_bus virtio2: rpmsg host is online
[ 636.371384] remoteproc remoteproc2: registered virtio2 (type 7)
[ 636.377328] remoteproc remoteproc2: remote processor 40800000.dsp is now up
[ 636.384917] virtio_rpmsg_bus virtio2: creating channel rpmsg-proto addr 0x3d

root@predixedge:/usr/bin/ipc/examples/ex02_messageq/debug# ./app_host DSP1
--> main:
--> Main_main:
--> App_create:

Sad face....

I will now look closer into the CMEM aspect.

Peter

0 Peter Smith48 over 8 years ago in reply to Peter Smith48

Intellectual 310 points

This is the source of the DTS that is being loaded

In u-boot fdtfile = am572x-idk.dtb

/*
* Copyright (C) 2015-2016 Texas Instruments Incorporated - http://www.ti.com/
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License version 2 as
* published by the Free Software Foundation.
*/

/dts-v1/;

#include "dra74x.dtsi"
#include "am572x-idk-common.dtsi"
#include "dra74x-mmc-iodelay.dtsi"

/ {
model = "TI AM5728 IDK";
compatible = "ti,am5728-idk", "ti,am5728", "ti,dra742", "ti,dra74",
"ti,dra7";
};

&cpu0 {
vdd-supply = <&smps12_reg>;
};

&mmc1 {
pinctrl-names = "default", "hs", "sdr12", "sdr25", "sdr50", "ddr50", "sdr104";
pinctrl-0 = <&mmc1_pins_default>;
pinctrl-1 = <&mmc1_pins_hs>;
pinctrl-2 = <&mmc1_pins_sdr12>;
pinctrl-3 = <&mmc1_pins_sdr25>;
pinctrl-4 = <&mmc1_pins_sdr50>;
pinctrl-5 = <&mmc1_pins_ddr50 &mmc1_iodelay_ddr_rev20_conf>;
pinctrl-6 = <&mmc1_pins_sdr104 &mmc1_iodelay_sdr104_rev20_conf>;
};

&mmc2 {
pinctrl-names = "default", "hs", "ddr_1_8v";
pinctrl-0 = <&mmc2_pins_default>;
pinctrl-1 = <&mmc2_pins_hs>;
pinctrl-2 = <&mmc2_pins_ddr_rev20>;
};

&pruss2_mdio {
reset-gpios = <&gpio5 8 GPIO_ACTIVE_LOW>,
<&gpio5 9 GPIO_ACTIVE_LOW>;
reset-delay-us = <2>; /* PHY datasheet states 1uS min */
};

#include "am57xx-evm-cmem.dtsi"

Is that the right one???

0 Rex Chang over 8 years ago in reply to Peter Smith48

TI__Guru 50170 points

Hi, Peter,

The kernel version is ok. Building from meta-ti is fine. The meta-kernel in meta-processor-sdk is patches for TI core Linux. The DTB is fine. I don't think the issue is related to DTB or CMEM. However, I am curious why it didn't pull in IPC 3.47.02? If I am not mistaking, the release package is from Yocto build. Could you also run it for DSP2 when DSP1 fails? and dump both trace files from DSP1 and DSP2 before and after the run?

Rex

0 Peter Smith48 over 8 years ago in reply to Rex Chang

Intellectual 310 points

IPC 3.47.02 is pulled in by a .bbappend in meta-processor-sdk. It is not in the commit of meta-ti which corresponds to the Processor SDK 5.0 release (from the manifest file). It may be further along the rocko branch of course.

0 Peter Smith48 over 8 years ago in reply to Peter Smith48

Intellectual 310 points

I'm just doing a clean build now to make sure everything is good, will try DSP1 and DSP2 as suggested as soon as I can.

0 Peter Smith48 over 8 years ago in reply to Peter Smith48

Intellectual 310 points

Hi,

Still no joy.

Clean re-build with all correct commit's matching Processor SDK 5.0 manifest file.

Everything checks out as far as dmesg etc are concerned, no visible errors in any logs. app_host from ex02_messageq still hangs as before, nothing in the traces.

Tried the executable's from the shipped Processor SDK 5 root file system, same problem, app_host hangs just like the one's built by Ycoto.

Can't think of anything else to try now can you?

Could be anything to do with the fact that my AM5728 IDK is Rev 1.2A (which i'm told is old'ish). I don't have another one to try so I'm stuck on that front.

These examples did used to work (prior to me aligning everything with processor SDK 5.0 commits). I memory serves I used this commit of meta-ti (b42044aaf51323d6948e6837884327b182ef9022)

Peter

0 Peter Smith48 over 8 years ago in reply to Peter Smith48

Intellectual 310 points

Hi, more info. I have written the Processor SDK 5.0 SD Card Image onto my SDCARD i.e. booted the canned Processor SDK 5.0 images on my board and the ex02_messageq example works just fine. So this seems to rule out my particular IDK.

The question now is where to go next.

One thought I has was the tool chain used by Yocto to build the Linux side of the setup is different. Our distro specifies the GCC 7.3 toolchain, the recipes for which are provided by our layers, we also set the following in local conf:

# Define glibc version
GLIBCVERSION = "2.26"
# Define gcc version
GCCVERSION = "7.3%"

I assume that the tool chains used to build the DSP side of things must be correct as they are built from TI provided recipes yes?

I understand that TI use an external tool chain, using this would require big changes to our distro layers which I alone can't arrange.

0 Rex Chang over 8 years ago in reply to Peter Smith48

TI__Guru 50170 points

Peter,

This info is interesting. Our build is based on GCC 7.2 or I should say the images are verified with GCC 7.2. Could you use the Linaro toolchain included in the ProcSDK 5.0? It is under sdk/linux-devkit. Set the PATH to include sdk/linux-devkit/sysroots/x86_64-arago-linux/usr/bin.

Rex

0 Peter Smith48 over 8 years ago in reply to Rex Chang

Intellectual 310 points

Hi, I can't use the linaro tool chain without making significant changes to the distro (its complicated because the same layers are used for different CPU architectures) i.e. its possible but not quick for me to do. I am going to look into it later. One other thing I found that is different is that we enable some security features i.e. we pull in require "conf/distro/include/security_flags.inc" from the poky layer which I notice that the arago distribution does not. I am trying a build without these enabled.

0 Rex Chang over 8 years ago in reply to Peter Smith48

TI__Guru 50170 points

Peter,

I am a bit skeptical on GCC version, but never say never. With your test, we ruled out the EVM version. By the way, I am on v1.3B. I agree that removing security will be a good test.

Rex

0 Peter Smith48 over 7 years ago in reply to Rex Chang

Intellectual 310 points

Hi,

At last I report we have lift off!

I have disabled the application of our distro's security flags and the IPC example finally works. The flags we apply to the whole distro's compilation are as follows. The first line is picked up from poky.

require conf/distro/include/security_flags.inc

SECURITY_CFLAGS_pn-libconfig = "${SECURITY_NO_PIE_CFLAGS}"
SECURITY_CFLAGS_pn-docker = "${SECURITY_NO_PIE_CFLAGS}"
SECURITY_CFLAGS_pn-python3-cffi = "${SECURITY_NO_PIE_CFLAGS}"
SECURITY_CFLAGS_pn-python3-cryptography = "${SECURITY_NO_PIE_CFLAGS}"
SECURITY_CFLAGS_pn-python3-pyyaml = "${SECURITY_NO_PIE_CFLAGS}"
SECURITY_CFLAGS_pn-protobuf = "${SECURITY_NO_PIE_CFLAGS}"
SECURITY_CFLAGS_pn-apparmor = "${SECURITY_NO_PIE_CFLAGS}"

I have also removed all the layers that I do not need i.e. I am now building with only the meta-ti layer (from tag ti2018.02).

One thing I did notice is that we were not picking up the linux-libc-headers_4.14 recipe from meta-arago, do you think that could make any difference?

I will try re-enabling the security flags to see if that is the actual cause.

Peter

0 Rex Chang over 7 years ago in reply to Peter Smith48

TI__Guru 50170 points

Hi, Peter,

I am glad to hear that the root cause was found though need to understand further. Let me check internally to see why impact these security configuration have. I'll also need to find out why 4.14 libc-headers isn't picked up. It should in my opinion.

Rex

0 Peter Smith48 over 7 years ago in reply to Rex Chang

Intellectual 310 points

The linux-libc-headers recipe is in meta-arago. so if you use only meta-ti you don't pick it up. I'm not sure how important this is to be honest. For now I have copied the meta-arago (ti2018.02) .bb file into my customization layer.

0 Rex Chang over 7 years ago in reply to Peter Smith48

TI__Guru 50170 points

HI, Peter,

Not picking it up means using the different version or totally without? I would expect the build to fail without linux-libc-headers. If using different version, then using the right bitbake recipe should be the way.

If your issue is resolved, please click "resolved" button. For new issues, please submit a new thread. Thanks!

Rex

Processors

Processors forum

AM5728: IPC examples issue in Yocto