Partial debug/remoteproc trace0 output

Here is my changed cfg for logging.  I'll admit I don't completely understand all that, but it did seem to work previously.

/*
 *  ======== Instrumentation Configuration ========
 */
xdc.useModule('xdc.runtime.Assert');
xdc.useModule('xdc.runtime.Error');
xdc.useModule('xdc.runtime.Registry');

var Log     =   xdc.useModule('xdc.runtime.Log');

/*
** Sets up the exception log so you can read it with ROV in CCS
*/
var LoggerBuf = xdc.useModule('xdc.runtime.LoggerBuf');
var Exc = xdc.useModule('ti.sysbios.family.c64p.Exception');
Exc.common$.logger = LoggerBuf.create();
Exc.enablePrint = true; /* prints exception details to the CCS console */

/* system logger */
var LoggerSys = xdc.useModule('xdc.runtime.LoggerSys');
var LoggerSysParams = new LoggerSys.Params();
var Defaults = xdc.useModule('xdc.runtime.Defaults');
Defaults.common$.logger = LoggerSys.create(LoggerSysParams);

/* enable runtime Diags_setMask() for non-XDC spec'd modules */
var Diags = xdc.useModule('xdc.runtime.Diags');
Diags.setMaskEnabled = true;
/*Defaults.common$.diags_INFO = Diags.RUNTIME_ON;*/
Defaults.common$.diags_INFO = Diags.ALWAYS_OFF;
Defaults.common$.diags_ENTRY = Diags.RUNTIME_ON;
Defaults.common$.diags_EXIT = Diags.RUNTIME_ON;

/* override diags mask for selected modules */
xdc.useModule('xdc.runtime.Main');
Diags.setMaskMeta("xdc.runtime.Main",
    Diags.ENTRY | Diags.EXIT , Diags.RUNTIME_ON);
/*    Diags.ENTRY | Diags.EXIT | Diags.INFO, Diags.RUNTIME_ON);*/

var Registry = xdc.useModule('xdc.runtime.Registry');
Registry.common$.diags_ENTRY = Diags.RUNTIME_ON;
Registry.common$.diags_EXIT  = Diags.RUNTIME_ON;
/*Registry.common$.diags_INFO  = Diags.RUNTIME_ON;*/
Registry.common$.diags_INFO  = Diags.ALWAYS_OFF;
Registry.common$.diags_USER1 = Diags.RUNTIME_ON;
Registry.common$.diags_LIFECYCLE = Diags.RUNTIME_ON;
Registry.common$.diags_STATUS = Diags.RUNTIME_ON;

var Main = xdc.useModule('xdc.runtime.Main');
Main.common$.diags_ASSERT = Diags.ALWAYS_ON;
Main.common$.diags_INTERNAL = Diags.ALWAYS_ON;

I attempted to turn of diags_INFO, left the original lines in a commented.

The dump from Linux is the same:

[      0.000] [t=0x0002aacd] ti.sdo.utils.MultiProc: --> getClusterId: (0x4)
[      0.000] [t=0x00032051] ti.sdo.utils.MultiProc: <-- getClusterId: 0x4
[      0.000] 20 Resource entries at 0x80000000

Yes, the memory browser shows the entire log as does SysMin from the ROV tool.  See pic below.

Stuff from the Rsc_table:

// NOTE:  The IPC_DATA address and TRACE Buffer address must match.  The TRACE buffer address is setup in the platform config.
#define DSP_MEM_IPC_DATA        0x8CA20000  // This will be right before the FPGA region below.  It is in the
#define DSP_MEM_IPC_DATA_SIZE   SZ_1M       // Platform definition also, but unused.

extern char ti_trace_SysMin_Module_State_0_outbuf__A;
#define TRACEBUFADDR (UInt32)&ti_trace_SysMin_Module_State_0_outbuf__A

    {
        TYPE_TRACE, TRACEBUFADDR, 0x8000, 0, "trace:dsp",
    },

My platform file has this:

IPC_DATA 0x8c920000 0x00100000 code/data RWX

TRACE_BUF 0x8ca20000 0x00060000 code/data RWX

I'm not sure, don't recall, why I made the comment that the IPC_DATA and TRACE_BUF address must match.  However, I also note that it is not used in the Platform file.  So that is a bit confusing.

Here is the grep output.  It will take me longer to get the test project.  One point though, could this not be a Linux side issue.  The DSP appears to be putting the data into the buffer just fine.  It would seem like Linux has the problem pulling it out.  Like it does not know how much is there.  Maybe DSP and Linux disagree on the R/W pointers?

Binary file ./Bin/Test/TestDsp.xe66 matches
./Bin/Test/TestDsp.map:  8ca20000    8ca20000    00008004   00000000    rw- .tracebuf
./Bin/Test/TestDsp.map:                  84ee3980    00000008     (.cinit..tracebuf.load) [load image, compression = zero_ini
t]
./Bin/Test/TestDsp.map:.tracebuf
./Bin/Test/TestDsp.map:                  8ca20000    00008004     Test_pe66.oe66 (.tracebuf)
./Bin/Test/TestDsp.map:       .tracebuf: load addr=84ee3980, load size=00000008 bytes, run addr=8ca20000, run size=00008004 b
ytes, compression=zero_init
./Bin/UnitTest/TestDsp.map:  8ca20000    8ca20000    00008004   00000000    rw- .tracebuf
./Bin/UnitTest/TestDsp.map:                  84ed9f24    00000008     (.cinit..tracebuf.load) [load image, compression = zero
_init]
./Bin/UnitTest/TestDsp.map:.tracebuf
./Bin/UnitTest/TestDsp.map:                  8ca20000    00008004     Test_pe66.oe66 (.tracebuf)
./Bin/UnitTest/TestDsp.map:   .tracebuf: load addr=84ed9f24, load size=00000008 bytes, run addr=8ca20000, run size=00008004 b
ytes, compression=zero_init
Binary file ./Bin/UnitTest/TestDsp.xe66 matches
./Build/UnitTest/configPkg/package/cfg/Test_pe66.c:#pragma DATA_SECTION(ti_trace_SysMin_Module_State_0_outbuf__A, ".tracebuf"
);
./Build/UnitTest/configPkg/package/cfg/Test_pe66.c:#pragma DATA_SECTION(ti_trace_SysMin_Module_State_0_readidx__A, ".tracebuf
");
./Build/UnitTest/configPkg/package/cfg/Test_pe66.c:#pragma DATA_SECTION(ti_trace_SysMin_Module_State_0_writeidx__A, ".tracebu
f");
./Build/UnitTest/configPkg/package/cfg/Test_pe66.xdl:    .tracebuf: load > TRACE_BUF
./Build/UnitTest/configPkg/package/cfg/Test_pe66.cfg.xml:            <feature name="sectMap" type="object"><map id='xdc.cfg.P
rogram/sectMap'  length='26'><entry key='.resource_table'>xdc.services.intern.xsr.Value$Obj@14715d4::xdc.cfg.Program.SectionSpec#0</ent
ry><entry key='.vecs'>EXT_RAM</entry><entry key='.cinit'>EXT_RAM</entry><entry key='.init_array'>EXT_RAM</entry><entry key='.cio'>EXT_R
AM</entry><entry key='.rodata'>EXT_RAM</entry><entry key='.neardata'>EXT_RAM</entry><entry key='.far'>EXT_RAM</entry><entry key='.bss'>
EXT_RAM</entry><entry key='.const'>EXT_RAM</entry><entry key='.text'>EXT_RAM</entry><entry key='.switch'>EXT_RAM</entry><entry key='.st
ack'>EXT_RAM</entry><entry key='.fardata'>EXT_RAM</entry><entry key='.far:taskStackSection'>EXT_RAM</entry><entry key='systemHeap'>EXT_
RAM</entry><entry key='myHeapSection'>EXT_RAM</entry><entry key='.UnitTestData'>EXT_RAM</entry><entry key='.calibration_Data'>CAL_RAM</
entry><entry key='.fpga_Download'>FPGA_RAM</entry><entry key='.hpi_Log_Data'>HPI_RAM</entry><entry key='BOARD_IO_DELAY_DATA'>OCMC_RAM1<
/entry><entry key='BOARD_IO_DELAY_CODE'>OCMC_RAM1</entry><entry key='.tracebuf'>TRACE_BUF</entry><entry key='.noncached_Program_Data'>L
2SRAM</entry><entry key='.bionic_Data'>EXT_RAM</entry></map>
Binary file ./Build/UnitTest/configPkg/package/cfg/Test_pe66.oe66 matches
./Build/UnitTest/configPkg/linker.cmd:    .tracebuf: load > TRACE_BUF
./Build/UnitTest/TestDsp_linkInfo.xml:         <name>.cinit..tracebuf.load</name>
./Build/UnitTest/TestDsp_linkInfo.xml:         <name>.tracebuf</name>
./Build/UnitTest/TestDsp_linkInfo.xml:         <name>.tracebuf</name>
./Build/UnitTest/TestDsp_linkInfo.xml:            <name>.tracebuf</name>
./Build/Test/TestDsp_linkInfo.xml:         <name>.cinit..tracebuf.load</name>
./Build/Test/TestDsp_linkInfo.xml:         <name>.tracebuf</name>
./Build/Test/TestDsp_linkInfo.xml:         <name>.tracebuf</name>
./Build/Test/TestDsp_linkInfo.xml:            <name>.tracebuf</name>
./Build/Test/configPkg/package/cfg/Test_pe66.c:#pragma DATA_SECTION(ti_trace_SysMin_Module_State_0_outbuf__A, ".tracebuf");
./Build/Test/configPkg/package/cfg/Test_pe66.c:#pragma DATA_SECTION(ti_trace_SysMin_Module_State_0_readidx__A, ".tracebuf");
./Build/Test/configPkg/package/cfg/Test_pe66.c:#pragma DATA_SECTION(ti_trace_SysMin_Module_State_0_writeidx__A, ".tracebuf");

./Build/Test/configPkg/package/cfg/Test_pe66.xdl:    .tracebuf: load > TRACE_BUF
./Build/Test/configPkg/package/cfg/Test_pe66.cfg.xml:            <feature name="sectMap" type="object"><map id='xdc.cfg.Progr
am/sectMap'  length='26'><entry key='.resource_table'>xdc.services.intern.xsr.Value$Obj@1284c88::xdc.cfg.Program.SectionSpec#0</entry><
entry key='.vecs'>EXT_RAM</entry><entry key='.cinit'>EXT_RAM</entry><entry key='.init_array'>EXT_RAM</entry><entry key='.cio'>EXT_RAM</
entry><entry key='.rodata'>EXT_RAM</entry><entry key='.neardata'>EXT_RAM</entry><entry key='.far'>EXT_RAM</entry><entry key='.bss'>EXT_
RAM</entry><entry key='.const'>EXT_RAM</entry><entry key='.text'>EXT_RAM</entry><entry key='.switch'>EXT_RAM</entry><entry key='.stack'
>EXT_RAM</entry><entry key='.fardata'>EXT_RAM</entry><entry key='.far:taskStackSection'>EXT_RAM</entry><entry key='systemHeap'>EXT_RAM<
/entry><entry key='myHeapSection'>EXT_RAM</entry><entry key='.UnitTestData'>EXT_RAM</entry><entry key='.calibration_Data'>CAL_RAM</entr
y><entry key='.fpga_Download'>FPGA_RAM</entry><entry key='.hpi_Log_Data'>HPI_RAM</entry><entry key='BOARD_IO_DELAY_DATA'>OCMC_RAM1</ent
ry><entry key='BOARD_IO_DELAY_CODE'>OCMC_RAM1</entry><entry key='.tracebuf'>TRACE_BUF</entry><entry key='.noncached_Program_Data'>L2SRA
M</entry><entry key='.bionic_Data'>EXT_RAM</entry></map>
Binary file ./Build/Test/configPkg/package/cfg/Test_pe66.oe66 matches
./Build/Test/configPkg/linker.cmd:    .tracebuf: load > TRACE_BUF

Chris,

Have you checked dmesg on Linux side? If there is trace buffer size issue, the DSP image should have failed to bootup, and if there is trace buffer read pointer issue, I would expect the beginning log is skipped though.

IPC_DATA section should not have been used if you look into DSP map file, did you try to remove the IPC_DATA section from DSP config file, and define TRACE_BUF to 0x8c920000 to align with what is defined in rsc table "#define DSP_MEM_IPC_DATA 0x8c920000"? This would be matching with ex02_messageq Dsp1.cfg and default rsc table. (It seems you use different way to allocate .tracebuf to TRACE_BUF? I don't see your grep print Program.sectMap[".tracebuf"] = "TRACE_BUF";  )

Regards,
Garrett

The DSP is booting up and running correctly, so I don't think dmesg is going to have anything interesting in it.  I see the TRACE_BUF at the expected location and appears to be correct via the ROV Tool or direct memory display.

I did not quite grep all the cfg files for this project, sorry about that.  I can assure you I do have

Program.sectMap[".tracebuf"]               = "TRACE_BUF";

in the .cfg setup.

I did remove the IPC_DATA from the platform file and I changed the addressed of TRACE_BUF to 0x8c920000.  Same behavior.  Linux only shows the first three lines, ROV and Memory Browser shows it all. 

Stuff from Resource Table:

#define DSP_MEM_IPC_DATA        0x8C920000  // This will be right before the FPGA region below.  It is in the
#define DSP_MEM_IPC_DATA_SIZE   SZ_1M       // Platform definition also, but unused.

extern char ti_trace_SysMin_Module_State_0_outbuf__A;
#define TRACEBUFADDR (UInt32)&ti_trace_SysMin_Module_State_0_outbuf__A

    {
        TYPE_TRACE, TRACEBUFADDR, 0x8000, 0, "trace:dsp",
    },

From the .map file:

TRACE_BUF             8c920000   00060000  00008004  00057ffc  RW X

8c920000    8c920000    00008004   00000000    rw-
  8c920000    8c920000    00008004   00000000    rw- .tracebuf

From the .cfg file:

Program.sectMap[".tracebuf"]               = "TRACE_BUF";

From the platform file:

TRACE_BUF  0x8c920000 0x00060000 code/data RWX

Suppose it could be the size difference between 0x00060000 and 0x00008004?

The trace buffer size difference should not be the culprit of preventing trace printout. The same size configuration works for ex02_messageq on EVM. The trace buffer is allocated from CMA region, have you changed the CMA address/range recently as you didn't have such issue "on an older build"?

I will look into the remoteproc driver. And you may try to recreate the issue on EVM.

Regards,
Garrett