AM5728: IPC trace logging issue

Thomas N.

Part Number: AM5728

Hi TI community,

I posted for a few months a similiar problem. I would like to log persistently the IPC trace of a slave core. For example: On DSP1 an application is running which prints some logging information with the help of System_printf (or Log_infoX()). On the host core (A15) an operating system such as Linux or QNX is running which shall save the logging information (stored in /dev/ipc-trace/DSP1) persistently on the filesystem. To save the logging information persistently I can use the ipc_trace_daemon (or something else such a cyclic cat command on the file device).

Now, my problem is described as followed: My log is strange because everytime my log mechanism on host CPU reads the trace, it receives the entire trace (instead of new (unread) traces). I have described the problem already here. My log looks like:

Msg 1

Msg 1

Msg 2

Msg 1

Msg 2

Msg 3

Msg 1

Msg 2

Msg 3

Msg 4

...

Instead of:

Msg 1

Msg 2

Msg 3

Msg 4

Here and there, I thought I solved the problem, because the log looks correctly. But I can't reproduce it anymore. Maybe I reconfigured my TI-RTOS wrong, did an unwitting package update, had a special use case which suppresses the issue or I miss something else. But it seems that the ipc resource manager reads the entire log again because it may start at the beginning (read index = 0) everytime.

Let's have a look into my system environment. Since the IPC communiction is running, I will try to focus on the concerned regions (this will retain the overview, too):

I use the Sitara IDK-AM5728 board. For the IPC communication I use the TI package ipc_3_47_01_00 (SDK: processor_sdk_rtos_am57xx_4_03_00_05, XDC: xdctools_3_50_03_33_core, BIOS: bios_6_52_00_12).

Timing: My DSP logs every 10 ms a message with System_printf(). The host reads every 500ms on /dev/ipc-trace/DSP1.

My DSP1 is configured as followed:

The important parts of my config file are:

var Resource = xdc.useModule('ti.ipc.remoteproc.Resource');
/* Override the default resource table to add SR0 */
Resource.customTable = true;
/* Enable Memory Translation module that operates on the BIOS Resource Table */
Resource.loadSegment = "EXT_CODE";

var SysMin = xdc.useModule('ti.trace.SysMin');        
Program.sectMap[".tracebuf"] = "TRACE_BUF";
Program.sectMap[".errorbuf"] = "EXC_DATA";

/* Idle function that periodically flushes the unicache (used for trace buffer) */
Idle.addFunc('&VirtQueue_cacheWb');

/* 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);

SysMin.bufSize  = 0x8000;
var System = xdc.useModule('xdc.runtime.System');
System.SupportProxy = SysMin;

The corresponding resource table looks like (snippet):

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

#pragma DATA_SECTION(".resource_table")
#pragma DATA_ALIGN(4096)
struct my_resource_table ti_ipc_remoteproc_ResourceTable = {
    1,      /* we're the first version that implements this */
    22,     /* number of entries in the table */
    0, 0,   /* reserved, must be zero */
    /* offsets to entries */
{
..
{
   TYPE_CARVEOUT,
   DSP_MEM_IPC_DATA, 0,
   DSP_MEM_IPC_DATA_SIZE, 0, 0, "DSP_MEM_IPC_DATA",
},
{
   TYPE_TRACE, TRACEBUFADDR, 0x8000, 0, "trace:dsp",
},
{
   TYPE_DEVMEM,
   DSP_MEM_IPC_VRING, PHYS_MEM_IPC_VRING,
   DSP_MEM_IPC_VRING_SIZE, 0, 0, "DSP_MEM_IPC_VRING",
},
...

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

#pragma DATA_SECTION(".resource_table")
#pragma DATA_ALIGN(4096)

struct my_resource_table ti_ipc_remoteproc_ResourceTable = {
    1,      /* we're the first version that implements this */
    22,     /* number of entries in the table */
    0, 0,   /* reserved, must be zero */
    /* offsets to entries */
    {
...
    {
        TYPE_CARVEOUT,
        DSP_MEM_IPC_DATA, 0,
        DSP_MEM_IPC_DATA_SIZE, 0, 0, "DSP_MEM_IPC_DATA",
    },

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

    {
        TYPE_DEVMEM,
        DSP_MEM_IPC_VRING, PHYS_MEM_IPC_VRING,
        DSP_MEM_IPC_VRING_SIZE, 0, 0, "DSP_MEM_IPC_VRING",
    },

My memory layout for Trace buffer is:

TRACE_BUF: {
        name: "TRACE_BUF",
        base: 0x95E00000,
        len: 0x00060000,
        space: "data",
        access: "RW"
    },

On the host side, I use a QNX (I know, TI does not support third party software ;-) but TI provides software for QNX in the IPC package, for example the important read driver (ipc_read()). I think the problem is not on QNX side, so the TI community can help).

On host, I actually use the ipc_trace_daemon. But I will have the same troubles, when I use a bash file which makes a cyclic cat command on /dev/ipc-trace/DSP1. So I can minimize the scope of error sources when I use the bash file.

In my oppinion, the problem is not on host side (not ipc_trace_daemon or HLOS) but rather on ipc resource manager or DSP application. Thus, I did a deep dive into the SysMin module and the TI's resource manager on QNX side.The SysMin module writes only in the buffer and may reset the write/out index if the buffer is full. But SysMin does not reset the read index.

After some additional debug prints in ipc_read()(file: <ipc install dir>\qnx\src\ipc3x_dev\ti\syslink\build\Qnx\resmgr\syslink_main.c) on host side, I recognized, that the read index (*proc_traces[procid].ridx) is 0 (but I don't know why and which instance sets it to 0. The ipc resource manager doesn't do it) after each write of new messages on DSP. This would explain why I get everytime the entire log buffer. But I cannot explain why this strange behaviour happens.

Can someome suport me to solve this issues?

Thanks for your help.

Best regards

Thomas

over 6 years ago