• State
  • Locked Locked
  • Replies 4 replies
  • Subscribers 99 subscribers
  • Views 291 views
  • Users 0 members are here
Support feedback
Options
Options
Related

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.

How to trace the "OC" message in the application on the ARM-side

shilv shen
Prodigy 210 points
Other Parts Discussed in Thread: OMAP3530

 

I am debugging a ARM application call a DSP server  to encode video (h264), system always hangs in the fixed location.

The trace is printed with the "CE_DEBUG=3" command.

@90,814,361us: [+4 T:0x41400490 S:0x413ffa94] CV - VISA_getMaxMsgSize(0x58a58): returning 0x1000
@90,814,392us: [+5 T:0x41400490 S:0x413ffa9c] CV - VISA_allocMsg> Allocating message for messageId=0x000203cf
@90,814,453us: [+0 T:0x41400490 S:0x413ffab4] CV - VISA_call(visa=0x58a58, msg=0x424df880): messageId=0x000203cf, command=0x0
[DSP] @267,412,742tk: [+5 T:0x87f123ec S:0x87f176dc] CN - NODE> 0x87f11df0(h264enc#0) call(algHandle=0x87f11eb8, msg=0x87305880); messageId=0x000203cf
[DSP] @267,412,833tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> Enter(addr=0x86630000, sizeInBytes=614400)
[DSP] @267,413,562tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> return
[DSP] @267,413,607tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> Enter(addr=0x866fb000, sizeInBytes=614400)
[DSP] @267,414,334tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> return
[DSP] @267,414,381tk: [+0 T:0x87f123ec S:0x87f1756c] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x87f11eb8, inBufs=0x87f1760c, outBufs=0x87f176dc, inArgs=0x87305a04, outArgs=0x87305a10)
[DSP] @267,414,491tk: [+5 T:0x87f123ec S:0x87f1754c] CV - VISA_enter(visa=0x87f11eb8): algHandle = 0x87f11ef0
[DSP] @267,414,555tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(alg=0x87f11ef0)
[DSP] @267,414,625tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Exit
[DSP] @267,460,033tk: [+5 T:0x87f123ec S:0x87f1754c] CV - VISA_exit(visa=0x87f11eb8): algHandle = 0x87f11ef0
[DSP] @267,460,134tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(alg=0x87f11ef0)
[DSP] @267,460,205tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Exit
[DSP] @267,460,264tk: [+0 T:0x87f123ec S:0x87f1756c] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x87f11eb8, retVal=0x0)
[DSP] @267,460,339tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheWb> Enter(addr=0x866fb000, sizeInBytes=614400)
[DSP] @267,461,117tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheWb> return
[DSP] @267,461,167tk: [+5 T:0x87f123ec S:0x87f176dc] CN - NODE> returned from call(algHandle=0x87f11eb8, msg=0x87305880); messageId=0x000203cf
[DSP] @267,461,589tk: [+0 T:0x87f0d334 S:0x87f112f4] CR - processRmsCmd(0x873048a8, 4056): cmd = 5
[DSP] @267,461,650tk: [+0 T:0x87f0d334 S:0x87f112f4] CR - remote time = 0x0, trace buffer size = 4032
@90,831,451us: [+0 T:0x41400490 S:0x413ffab4] CV - VISA_call Completed: messageId=0x000203cf, command=0x0, return(status=0)
@90,831,481us: [+5 T:0x41400490 S:0x413ffaa4] CV - VISA_freeMsg(0x58a58, 0x424df880): Freeing message with messageId=0x000203cf

@90,896,087us: [+4 T:0x41400490 S:0x413ffa94] CV - VISA_getMaxMsgSize(0x58a58): returning 0x1000
@90,896,209us: [+5 T:0x41400490 S:0x413ffa9c] CV - VISA_allocMsg> Allocating message for messageId=0x000203d0
@90,896,270us: [+0 T:0x41400490 S:0x413ffab4] CV - VISA_call(visa=0x58a58, msg=0x424df880): messageId=0x000203d0, command=0x0
[DSP] @267,668,448tk: [+5 T:0x87f123ec S:0x87f176dc] CN - NODE> 0x87f11df0(h264enc#0) call(algHandle=0x87f11eb8, msg=0x87305880); messageId=0x000203d0
[DSP] @267,668,539tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> Enter(addr=0x86630000, sizeInBytes=614400)
[DSP] @267,669,268tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> return
[DSP] @267,669,314tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> Enter(addr=0x866fb000, sizeInBytes=614400)
[DSP] @267,670,038tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheInv> return
[DSP] @267,670,085tk: [+0 T:0x87f123ec S:0x87f1756c] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x87f11eb8, inBufs=0x87f1760c, outBufs=0x87f176dc, inArgs=0x87305a04, outArgs=0x87305a10)
[DSP] @267,670,197tk: [+5 T:0x87f123ec S:0x87f1754c] CV - VISA_enter(visa=0x87f11eb8): algHandle = 0x87f11ef0
[DSP] @267,670,260tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(alg=0x87f11ef0)
[DSP] @267,670,329tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Exit
[DSP] @267,713,985tk: [+5 T:0x87f123ec S:0x87f1754c] CV - VISA_exit(visa=0x87f11eb8): algHandle = 0x87f11ef0
[DSP] @267,714,094tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(alg=0x87f11ef0)
[DSP] @267,714,165tk: [+0 T:0x87f123ec S:0x87f1752c] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Exit
[DSP] @267,714,225tk: [+0 T:0x87f123ec S:0x87f1756c] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x87f11eb8, retVal=0x0)
[DSP] @267,714,300tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheWb> Enter(addr=0x866fb000, sizeInBytes=614400)
[DSP] @267,715,091tk: [+0 T:0x87f123ec S:0x87f175a4] OM - Memory_cacheWb> return
[DSP] @267,715,140tk: [+5 T:0x87f123ec S:0x87f176dc] CN - NODE> returned from call(algHandle=0x87f11eb8, msg=0x87305880); messageId=0x000203d0
[DSP] @267,715,568tk: [+0 T:0x87f0d334 S:0x87f112f4] CR - processRmsCmd(0x873048a8, 4056): cmd = 5
[DSP] @267,715,630tk: [+0 T:0x87f0d334 S:0x87f112f4] CR - remote time = 0x0, trace buffer size = 4032
@90,912,719us: [+0 T:0x41400490 S:0x413ffab4] CV - VISA_call Completed: messageId=0x000203d0, command=0x0, return(status=0)
@90,912,750us: [+5 T:0x41400490 S:0x413ffaa4] CV - VISA_freeMsg(0x58a58, 0x424df880): Freeing message with messageId=0x000203d0

@90,977,844us: [+4 T:0x41400490 S:0x413ffa94] CV - VISA_getMaxMsgSize(0x58a58): returning 0x1000
@90,977,905us: [+5 T:0x41400490 S:0x413ffa9c] CV - VISA_allocMsg> Allocating message for messageId=0x000203d1
@90,977,966us: [+0 T:0x41400490 S:0x413ffab4] CV - VISA_call(visa=0x58a58, msg=0x424df880): messageId=0x000203d1, command=0x0

Here is last message printed,I believe the message is regular,if it doesn't hang,it will print the messages begin with  [DSP] and CV - VISA_call Completed,CV - VISA_freeMsg.

In order to get more detail I read the source code:

(located in VISA.c)

VISA_Status VISA_call(VISA_Handle visa, VISA_Msg *msg)
{
    VISA_Status status = VISA_ERUNTIME;

    GT_4trace(curTrace, GT_ENTER | GT_5CLASS, "VISA_call"
        "(visa=0x%x, msg=0x%x): messageId=0x%08x, command=0x%x\n",
        visa, *msg, (*msg)->header.cmd.arg1, (*msg)->cmd);

    /* call remote function and wait for results */
    if (Engine_call(visa->node, (Comm_Msg *)msg) == Comm_EOK) {
        status = (*msg)->status; /* if call completed, copy remote status */
    }

    GT_3trace(curTrace, GT_ENTER | GT_5CLASS, "VISA_call "
        "Completed: messageId=0x%08x, command=0x%x, return(status=%d)\n",
        (*msg)->header.cmd.arg1, (*msg)->cmd, status);

    return (status);
}

located in Engine.c

 Int Engine_call(Engine_Node node, Comm_Msg *msg)
{
    Int status;

    /* ensure that the node simply passes message to exec/call fxn */
    NODE_Msg nodeMsg = (NODE_Msg)*msg;
    nodeMsg->cmd.id = NODE_CCALL;

    /* send the message */
    Comm_setSrcQueue(*msg, node->stdOut);
    status = Comm_put(node->stdIn, *msg);

    /* wait for the return message with the processed result */
    if (status == Comm_EOK) {
        status = Comm_get(node->stdOut, msg, Comm_FOREVER);
    }

    if (Engine_alwaysCollectDspTrace) {
        collectDspTrace( node->engine );
    }

    return (status);
}

There should be some traces in Comm_put and Comm_get ,such as GT_2trace(curTrace, GT_ENTER, "Comm_put> " "Enter(queue=0x%x, msg=0x%x)\n", queue, msg), known as the OC messages.

The thread:http://e2e.ti.com/support/dsp/davinci_digital_media_processors/f/99/p/140023/510914.aspx#510914 also shows that the OC messages are printed.

I check my .cfg file,I have added:

var TraceUtil = xdc.useModule('ti.sdo.ce.utils.trace.TraceUtil');
TraceUtil.attrs = TraceUtil.FULL_TRACING;

My DVSDK version is ti-dvsdk_dm3730-evm_4_00_00_22.

Why the OC message cannot be printed? Please help me.

Regards

Shenshilv

  • 0
    TI__Guru 65405 points

    Hi Shenshilv,

    As I see you are using old version of the DVSDK. Could you verify weather the problem presents with the last version of DVSDK 4.03.00.06 which could be downloaded from here:

    http://software-dl.ti.com/dsps/dsps_public_sw/sdo_sb/targetcontent/dvsdk/DVSDK_4_00/latest/index_FDS.html

    BR

    Tsvetolin Shulev

  • 0 in reply to Cvetolin Shulev-XID
    Prodigy 210 points

    :

    Thank for your advice,I have installed the new version DVSDK,but the kernel(v2.6.37) and the cross compile tool(integrated GCC 4.3-based toolchain built from Arago) is differant from the old version.I have to use new kernel and cross compile tool instead of the old one because of the cmem module,dsplink module and so on.

    I modified some part of the old kernel(v2.6.32) to adapt to my hardware before ,so it is difficult for me to copy the modification to the new kernel ,do you have any advice ?

    best regards

    shenshilv

     

  • 0 in reply to Cvetolin Shulev-XID
    Prodigy 210 points

    I use the new DVSDK (4.03.00.06), but the kernel source version is 2.6.32.

    The loadmodules.sh is OK, but when the application runs, it shows that and stop:

    Start address is covered by existing entry, can not create TLB entry for address: [0x86300000] size: [0x100000]

    DSP_init status [0x80008050]

    I google the TLB,find that the TLB means Translation Look-aside Buffer ,which is the cache in a CPU that contains parts of the page table which translate from virtual into real addresses.

    The total memory size of my system is 256M.

    The loadmodules.sh is :

    #!/bin/sh
    depmod -a

    #
    # Default Memory Map
    #
    # Start Addr Size Description
    # -------------------------------------------
    # 0x80000000 99 MB Linux
    # 0x86300000 15 MB CMEM
    # 0x87200000 13 MB CODEC SERVER


    # Allocate 15MB for CMEM
    modprobe cmemk phys_start=0x86300000 phys_end=0x87200000 pools=1x3000000,1x1429440,6x1048576,4x829440,1x327680,1x256000,7x131072,20x4096 allowOverlap=1

    # insert DSP/BIOS Link driver
    modprobe dsplinkk

    # make /dev/dsplink
    #rm -f /dev/dsplink
    #mknod /dev/dsplink c `awk "\\$2==\"dsplink\" {print \\$1}" /proc/devices` 0

    # insert Local Power Manager driver
    modprobe lpm_omap3530

    # insert SDMA driver
    modprobe sdmak

    Who can tell me the reason?

    BR

    Shenshilv

  • 0 in reply to shilv shen
    Intellectual 420 points

    Hi Shenshilv,

    Did you find an asnwer to your questions? 

    We are do almost the same use the dvsdk 04.03.00.06 in combination with a changed 2.6.32 kernel.

    We are having some stability issues in which the H.264 encoder hangs (after a few hours of work) on a msgqueue used by the dsplink module.

    Thanks,

    Robin