Accessing DSP BIOS logs without JTAG

Bandeg

Expert 1140 points

This is a very nice article.

http://processors.wiki.ti.com/index.php/Accessing_DSP_BIOS_logs_without_JTAG

I have implemented some host-side code to access user logs from the DSP.

In the CCS IDE, the DSP/BIOS Message (LOG) viewer also includes a LOG named "Execution Graph Details"

Here is a sample from this LOG.

353108 PRD: tick count = 63439 (0x0000f7cf)
353109 SWI: post KNL_swi (TSK scheduler) (0x853abfa8)
353110 SWI: begin KNL_swi (TSK scheduler) (0x853abfa8)
353111 SWI: end KNL_swi (TSK scheduler) (0x853abfa8) state = done
353112 PRD: tick count = 63440 (0x0000f7d0)
353113 SWI: post PRD_swi (0x853abfd4)
353114 SWI: post KNL_swi (TSK scheduler) (0x853abfa8)
353115 SWI: begin PRD_swi (0x853abfd4)
353116 PRD: begin PRD0 (0x853ac93c)

Is there a way to access this information too? If so what is its buffer / symbol name?

I am interested in this log because I have seen seg fault messages reported in this LOG.

Regards,

--B

over 15 years ago

0 Chris McCormick over 15 years ago

TI__Expert 4095 points

The address of the buffer is given by 'LOG_system$buf' and the size is 'LOG_system$size'.

Unfortunately, there is no tool provided for decoding this data outside of CCS. One approach I've heard others mention is to save the data, then load it to the target later at LOG_system$buf and use the tools in CCS to decode it.

If you want to try decoding it yourself, I can at least give you a few pointers. The records have the following format:

struct LOG_Event {

UInt32 seqnum;

UInt32 val1;

UInt32 val2;

UInt32 val3;

}

'val3' stores an event id which is used to decode the meaning of the event, and val1 and val2 are arguments that have different interpretations depending on the event.

The following JavaScript code, which creates the formatted message for the record 'rec', can serve as a sort of reference for decoding each of the 16 different event types.

/* Decode the event based on rec.val3 */

switch (Number(rec.val3)) {

case 0:

* _log.h: #define _LOG_PRDBEGIN 0 // handle = prd, arg0 = 0

* _VSM_systemFormats[_LOG_PRDBEGIN] = "PRD: begin %s (0x%04x)%s";

* example: "PRD: begin prdClock0 (0x13de8)"

* PRD doesn't have dynamic name.

var addr = Number(rec.val2);

var nickName = ROV.getNickName(ROV.getStaticName(addr), addr);

return("PRD: begin " + nickName);

case 1:

* _log.h: #define _LOG_PRDEND 1 // handle = 0, arg0 = 0

* _VSM_systemFormats[_LOG_PRDEND] = "PRD: end";

* example: "PRD: end"

return("PRD: end");

case 2:

* _log.h: #define _LOG_SWIPOST 2 // handle = swi, arg0 = 0

* _VSM_systemFormats[_LOG_SWIPOST] = "SWI: post %s (0x%04x)%s";

* example: "SWI: post PRD_swi (0x13a4c)"

var addr = Number(rec.val2);

return("SWI: post " + SWI.getNickName(addr));

case 3:

* _log.h: #define _LOG_SWIBEGIN 3 // handle = swi, arg0 = 0

* _VSM_systemFormats[_LOG_SWIBEGIN] = "SWI: begin %s (0x%04x)%s";

* example: SWI: begin KNL_swi (TSK scheduler) (0x13a20)

var handle = SWI.fxnToHandle(Number(rec.val2));

return("SWI: begin " + SWI.getNickName(handle));

case 4:

* _log.h: #define _LOG_SWIEND 4 // handle = swi, arg0 = swi->lock

* _VSM_systemFormats[_LOG_SWIEND] = "SWI: end %s (0x%04x) state = %s";

* example: SWI: end PRD_swi (0x13a4c) state = done

* From vsm.c:

* elem->arg2 = (Arg)(event->asa.system.asa.thread.arg0 == 0 ? "still ready" : "done");

var handle = SWI.fxnToHandle(Number(rec.val2));

var state = (rec.val1 == 0) ? "still ready" : "done";

return("SWI: end " + SWI.getNickName(handle) + " state = " + state);

case 5:

* _log.h: #define _LOG_PRDTICK 5 // tick.high = PRD_D_timh, tick.low = PRD_D_timl

* _VSM_systemFormats[_LOG_PRDTICK] = "PRD: tick count = %d (0x%08x)%s";

* example: PRD: tick count = 5 (0x00000005)

var tickCount;

/* 28x and 55x are 16-bit value in rec.val2 */

if ((ROV.getISA() == '55') || (ROV.getISA() == '28')) {

tickCount = Number(rec.val2);

}

/* 6x is 32-bit value in rec.val1 */

else {

tickCount = Number(rec.val1);

}

return("PRD: tick count = " + tickCount + " (" + countToHex(tickCount) + ")");

case 6:

* _log.h: #define _LOG_CLKINT 6 // tick.high = CLK_R_timh, tick.low = CLK_R_timl

* _VSM_systemFormats[_LOG_CLKINT] = "CLK: current time = %d (0x%08x)%s";

* example: CLK: current time = 6 (0x00000006)

var tickCount;

/* 28x and 55x are 16-bit value in rec.val2 */

if ((ROV.getISA() == '55') || (ROV.getISA() == '28')) {

tickCount = Number(rec.val2);

}

/* 6x is 32-bit value in rec.val1 */

else {

tickCount = Number(rec.val1);

}

return("CLK: current time = " + tickCount + " (" + countToHex(tickCount) + ")");

case 7:

* This event does not appear to be implemented in BIOS 5.

* _log.h: #define _LOG_HWIBEGIN 7 // handle = hwi id, arg0 = 0

* _VSM_systemFormats[_LOG_HWIBEGIN] = "HWI: begin";

return("HWI: begin");

case 8:

* _log.h: #define _LOG_USRMSG 8 // user message (format arg0)

* exmple:

var args = [Number(rec.val1)];

var msg = getMessage(rec.val2, args);

return(msg);

case 9:

* _log.h: #define _LOG_USRERR 9 // user error (format arg0)

* example: SYS_error called: error id = 0x1

var args = [Number(rec.val1)];

var msg = getMessage(rec.val2, args);

return(msg);

case 10:

* _log.h: #define _LOG_TSKBLOCKED 10 // handle = tsk, arg0 = 0

* _VSM_systemFormats[_LOG_TSKBLOCKED] = "TSK: blocked %s (0x%08x) on %s";

* example: TSK: blocked task1 (0x000137b0) on <unknown handle> SEM

var addr = Number(rec.val2)

return("TSK: blocked " + TSK.getNickName(addr));

case 11:

* _log.h: #define _LOG_TSKDONE 11 // handle = tsk, arg0 = 0

* _VSM_systemFormats[_LOG_TSKDONE] = "TSK: terminated %s (0x%08x)%s";

* example: TSK: terminated task0 (0x0001170c)

var addr = Number(rec.val2);

return ("TSK: terminated " + TSK.getNickName(addr));

case 12:

* _log.h: #define _LOG_TSKRUNNING 12 // handle = tsk, arg0 = 0

* _VSM_systemFormats[_LOG_TSKRUNNING] = "TSK: running %s (0x%08x)%s";

* example: TSK: running task1 (0x000137b0)

return("TSK: running " + TSK.getNickName(Number(rec.val2)));

case 13:

* _log.h: #define _LOG_TSKREADY 13 // handle = tsk, arg0 = 0

* _VSM_systemFormats[_LOG_TSKREADY] = "TSK: ready %s (0x%08x)%s";

* example: TSK: ready task1 (0x000137b0)

return ("TSK: ready " + TSK.getNickName(Number(rec.val2)));

case 14:

* _log.h: #define _LOG_SEMPOST 14 // handle = sem, arg0 = sem count

* _VSM_systemFormats[_LOG_SEMPOST] = "SEM: post %s (0x%04x) count = %d";

* example: SEM: post <unknown handle> (0x13dc8) count = 0

var addr = Number(rec.val2);

return ("SEM: post " + SEM.getNickName(addr));

case 15:

* _log.h: #define _LOG_TSKYIELD 15 // handle = tsk, arg0 = 0

* _VSM_systemFormats[_LOG_TSKYIELD] = "TSK: yield %s (0x%08x)%s";

* example: TSK: yield task0 (0x0001170c)

var addr = Number(rec.val2);

return ("TSK: yield " + TSK.getNickName(addr));

case 16:

* This event does not appear to be handled by VBD.

* _log.h: #define _LOG_PWRMRSRCCHNG 16 // arg0 = id, arg1 = 0(off) or 1(on)

* example:

var off = (rec.val2 == 0) ? "off" : "on";

return ("PWRM: Source Change id: " + rec.val1 + " " + off);

default:

return ("Unknown event id " + rec.val3);

}

0 Chris McCormick over 15 years ago in reply to Chris McCormick

TI__Expert 4095 points

FYI, I've update the article with this information.

http://processors.wiki.ti.com/index.php/Accessing_DSP/BIOS_Logs_Without_JTAG

Thanks,

Chris

Processors

Processors forum

Accessing DSP BIOS logs without JTAG