MSGQ_get() appears to take an abnormally long time?

Just a quick one - you should only use CE_DEBUG to _debug_, not really profile.  CE_DEBUG adds extra overhead to collect the DSP-side trace during every process() call (so the ARM and DSP-side traces are interleaved somewhat rationally).  CE_DEBUG is inappropriate for profiling.

For a better dump of real overhead, you might try CE_TRACE (which only sets the ARM-side tracing, and doesn't interleave the ARM and DSP-side tracing).  For example, trace level '5' is 'benchmarking'.  To turn on just trace level 5, for _all_ modules in the system, you can set CE_TRACE="*=5".

Search the above trace output for "+5" to see the few [but good-for-benchmarking!] trace lines that enabling trace level 5 (benchmarking) would generate.  Note that the lines prefixed by "[DSP]" won't be shown when using CE_TRACE since it only affects/enables ARM-side tracing.

There's more [unfortunately, potentially confusing] details here - http://tiexpressdsp.com/index.php/Codec_Engine_Application_Developers_Guide#Trace_Mask_Values

And to your real problem, this article may help you understand where overhead in a CE-based system may lie - http://tiexpressdsp.com/index.php/Codec_Engine_Overhead

Chris

Hi Chris,

Thanks for the note on CE_DEBUG.  I actually had tracing on previously, but it only showed me that the VISA call from within VIDENC_process() was taking a long time.  I turned on CE_DEBUG in the hopes of getting some more fine granularity as to what, exactly, was taking so long.  I figured the times would be inflated, but had hopes that they would be inflated relatively uniformly so that the timing of one call relative to another would still be fairly accurate.  Specifically, I wanted to see if the DSP was really taking that long to encode a frame, or if there was some other issue.

Here is the trace output with CE_TRACE="*=5":

<snip>

App-> Start Encoding
ceapp_encodeBuf() extended VIDENC_OutArgs used (188/156).
ceapp_encodeBuf() extended VIDENC_InArgs used (16/4).
@0x000be055:[T:0x4001f000] CV - VISA_allocMsg> Allocating message for messageId=0x000267bc
@0x000be0ef:[T:0x4001f000] CV - VISA_call(visa=0x44c90, msg=0x41169c80): messageId=0x000267bc, command=0x0
@0x000c9cdb:[T:0x4001f000] CV - VISA_call Completed: messageId=0x000267bc, command=0x0, return(status=0)
@0x000c9dae:[T:0x4001f000] CV - VISA_freeMsg(0x44c90, 0x41169c80): Freeing message with messageId=0x000267bc

@0x000c9ede:[T:0x4001f000] CV - VISA_allocMsg> Allocating message for messageId=0x000267bd
@0x000c9f64:[T:0x4001f000] CV - VISA_call(visa=0x44c90, msg=0x41169c80): messageId=0x000267bd, command=0x1
@0x000ca0fa:[T:0x4001f000] CV - VISA_call Completed: messageId=0x000267bd, command=0x1, return(status=0)
@0x000ca1af:[T:0x4001f000] CV - VISA_freeMsg(0x44c90, 0x41169c80): Freeing message with messageId=0x000267bd

@0x000cf6bf:[T:0x4001f000] CV - VISA_allocMsg> Allocating message for messageId=0x
@0x000cf780:[T:0x4001f000] CV - VISA_call(visa=0x44c90, msg=0x41169c80): messageId=0x000267be, command=0x0
@0x000dd7d5:[T:0x4001f000] CV - VISA_call Completed: messageId=0x000267be, command=0x0, return(status=0)
@0x000dd8a7:[T:0x4001f000] CV - VISA_freeMsg(0x44c90, 0x41169c80): Freeing message with messageId=0x000267be

@0x000dd9de:[T:0x4001f000] CV - VISA_allocMsg> Allocating message for messageId=0x000267bf
@0x000dda69:[T:0x4001f000] CV - VISA_call(visa=0x44c90, msg=0x41169c80): messageId=0x000267bf, command=0x1
@0x000ddc06:[T:0x4001f000] CV - VISA_call Completed: messageId=0x000267bf, command=0x1, return(status=0)
@0x000ddcbc:[T:0x4001f000] CV - VISA_freeMsg(0x44c90, 0x41169c80): Freeing message with messageId=0x000267bf

@0x000e2f5f:[T:0x4001f000] CV - VISA_allocMsg> Allocating message for messageId=0x
@0x000e3023:[T:0x4001f000] CV - VISA_call(visa=0x44c90, msg=0x41169c80): messageId=0x000267c0, command=0x0
@0x000ef2a4:[T:0x4001f000] CV - VISA_call Completed: messageId=0x000267c0, command=0x0, return(status=0)
@0x000ef374:[T:0x4001f000] CV - VISA_freeMsg(0x44c90, 0x41169c80): Freeing message with messageId=0x000267c0

</snip>

 

As for the CodecEngine overhead issue, that Wiki seems to mostly address cache coherence.  While I understand the impact that cache coherence has on performance, it shouldn't even approach the amount of time it takes the DSP-side process() to do its work, much less appear to take twice as long.  What it looks like I'm seeing here is a call to MSGQ_get() taking twice as long as the time spent in the DSP, before the DSP is even invoked.  Am I interpreting the CE_DEBUG output correctly, even if it is being used slightly out of context?

Any more insight is greatly appreciated.

Thanks,

Ryan

So, I think I may have misinterpreted the CE_DEBUG=3 output.  Somebody please correct me if I'm off track. 

There appear to be two RPC calls (two sets of Comm_put/Comm_get) before the DSP debug info appears.  The first RPC call, the one that takes a while, is the actual call to VIDENC_process.  The second call pulls down the DSP trace info.  I noticed that if I'm not at CE_DEBUG=3, but level 2, there is only one RPC call, and no DSP trace.  Is this correct?

That being said, the DSP spends the majority of its time between Algorithm_activate and VISA_exit, if the trace is to be believed.  Makes sense.  However, the timing info is reported as ticks, and I'm not sure what the conversion from ticks to seconds is supposed to be.  According to http://wiki.davincidsp.com/index.php/Codec_Engine_Application_Developers_Guide#Trace_Mask_Values the DSP timing info is always reported as "cycles".  For our DSP running at 594MHz, that would mean the entire time spent in the DSP during an encode is on the order of hundreds of microseconds... I highly doubt that's the case.  I can't seem to find where the actual divider is set, though.  Would this be on the ARM side in a Linux kernel source file (I didn't see anything obvious in arch/arm/mach-davinci), or is this something set up by the DSP image itself?

 

Thanks again in advance for any insight.

I am having almost same problem.

My code is running well for the ARM version.But when I switch to  local = false in the app.cfg file, the code is set for DSP version.

For that it  building properly and I am getting the executables(.470MV) and libraries(.64P).But while running on the board it is getting hangfor infinite time.

I am running the command as CE_DEBUG=3 ./toc.470MV | tee log.txt

 

And the log.txt is as follows

 

*********************************************

@0,824,929us: [+4 T:0x402c6318 S:0xbefffc64] OG - Global_init> This program was built with the following packages:

@0,826,416us: [+4 T:0x402c6318 S:0xbefffc64] OG - package gnu.targets.rts470MV (/root/dvsdk_1_30_01_41/xdc_3_00_02/packages/gnu/targets/rts470MV/) [1,0,0,0,1193542866293]

@0,827,010us: [+4 T:0x402c6318 S:0xbefffc64] OG - package dsplink.gpp (/root/dvsdk_1_30_01_41/dsplink_140-05p1/packages/dsplink/gpp/) [1,1,0,0]

@0,827,722us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.xdais.dm (/root/dvsdk_1_30_01_41/xdais_6_00_01/packages/ti/xdais/dm/) [1,0,4,0]

@0,828,283us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.xdais (/root/dvsdk_1_30_01_41/xdais_6_00_01/packages/ti/xdais/) [1,2,1,0]

@0,828,841us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.utils.trace (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/utils/trace/) [1,0,0,0]

@0,829,456us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce.utils.xdm (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/utils/xdm/) [1,0,1,1200333457442]

@0,830,029us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.linuxutils.cmem (/root/dvsdk_1_30_01_41/cmem_2_00_01/packages/ti/sdo/linuxutils/cmem/) [2,0,0,0]

@0,830,701us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.fc.acpy3 (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/fc/acpy3/) [1,0,2,0]

@0,831,284us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.fc.dman3 (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/fc/dman3/) [1,0,3,0]

@0,831,865us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce.osal (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/osal/) [2,0,1,1200333329943]

@0,832,482us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce.alg (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/alg/) [1,0,0,1200332939285]

@0,833,057us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.catalog.c470 (/root/dvsdk_1_30_01_41/xdc_3_00_02/packages/ti/catalog/c470/) [1,0,1,0,1192229332845]

@0,833,664us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.catalog.c6000 (/root/dvsdk_1_30_01_41/xdc_3_00_02/packages/ti/catalog/c6000/) [1,0,0,0,1192229349164]

@0,834,244us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.platforms.evmDM6446 (/root/dvsdk_1_30_01_41/bios_5_31_08/packages/ti/platforms/evmDM6446/) [1,0,0,0]

@0,834,846us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/) [1,0,5,1200332924185]

@0,835,417us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce.video (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/video/) [1,0,2,1200333474655]

@0,836,005us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.codecs.TOC_video (/root/dvsdk_1_30_01_41/dm6446_dvsdk_combos_1_35_debabrataNew/packages-production/ti/sdo/codecs/TOC_video/) []

@0,836,650us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce.bioslog (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/bioslog/) [1,0,1,1200332966901]

@0,837,234us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.ce.utils.trace (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/utils/trace/) [1,0,1,1200333448031]

@0,837,859us: [+4 T:0x402c6318 S:0xbefffc64] OG - package ti.sdo.app (/root/dvsdk_1_30_01_41/dm6446_dvsdk_combos_1_35_debabrataNew/packages-production/ti/sdo/app/) []

@0,838,541us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0x15ea8)

@0,839,103us: [+0 T:0x402c6318 S:0xbefffc5c] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c41534f]

@0,839,764us: [+0 T:0x402c6318 S:0xbefffc5c] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x0]

@0,840,957us: [+0 T:0x402c6318 S:0xbefffc5c] OG - Global_atexit> enter (fxn=0x13fb8)

@0,841,591us: [+0 T:0x402c6318 S:0xbefffc5c] OG - Global_atexit> enter (fxn=0x16378)

@0,842,275us: [+0 T:0x402c6318 S:0xbefffc64] OG - Global_atexit> enter (fxn=0x14e48)

@0,842,936us: [+0 T:0x402c6318 S:0xbefffc3c] OT - Thread_create> Enter (fxn=0x1775c, attrs=0x0)

@0,844,181us: [+0 T:0x402c6318 S:0xbefffc3c] OT - Thread_create> Exit (task=0x39180)

@0,844,739us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0x172fc)

@0,845,299us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0x12d88)

@0,845,714us: [+2 T:0x402c6318 S:0xbefffc5c] ti.sdo.ce.osal.alg - ALG_init> Enter

@0,845,875us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415351 count: 1

@0,846,011us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@0,846,190us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x8001]

@0,846,469us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x10002 refCount: 1

@0,846,626us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x8001]

@0,846,762us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@0,846,873us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x392d8]

@0,846,982us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415352 count: 1

@0,847,104us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@0,847,230us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x18001]

@0,847,406us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x20003 refCount: 1

@0,847,565us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x18001]

@0,847,700us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@0,847,811us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x392e8]

@0,847,919us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415353 count: 1

@0,848,038us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@0,848,173us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x28001]

@0,848,348us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x30004 refCount: 1

@0,848,481us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x28001]

@0,848,605us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@0,848,715us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x392f8]

@0,848,821us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415354 count: 1

@0,848,937us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@0,849,103us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x38001]

@0,849,301us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x40005 refCount: 1

@0,849,436us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x38001]

@0,849,562us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@0,849,670us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39308]

@0,849,778us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415355 count: 1

@0,849,895us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@0,850,023us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x48001]

@0,850,198us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x50006 refCount: 1

@0,850,328us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x48001]

@0,850,491us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@0,850,687us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39318]

@0,850,821us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415356 count: 1

@0,850,951us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@0,851,087us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x58001]

@0,851,273us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x60007 refCount: 1

@0,851,407us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x58001]

@0,851,532us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,186,546us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39328]

@1,186,707us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415357 count: 1

@1,186,845us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,186,987us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x68001]

@1,187,173us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x70008 refCount: 1

@1,187,309us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x68001]

@1,187,436us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,187,587us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39338]

@1,187,702us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415358 count: 1

@1,187,822us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,187,952us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x78001]

@1,188,131us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x80009 refCount: 1

@1,188,260us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x78001]

@1,188,386us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,188,492us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39348]

@1,188,599us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415359 count: 1

@1,188,714us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,188,842us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x88001]

@1,189,062us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x9000a refCount: 1

@1,189,202us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x88001]

@1,189,350us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,189,460us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39358]

@1,189,568us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c41535a count: 1

@1,189,686us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,189,848us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x98001]

@1,190,038us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0xa000b refCount: 1

@1,190,177us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x98001]

@1,190,327us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,190,442us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39368]

@1,190,548us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c41535b count: 1

@1,193,928us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,194,097us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0xa8001]

@1,194,299us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0xb000c refCount: 1

@1,194,437us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0xa8001]

@1,194,599us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,194,718us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39378]

@1,194,829us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c41535c count: 1

@1,194,953us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,195,086us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0xb8001]

@1,195,275us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0xc000d refCount: 1

@1,195,414us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0xb8001]

@1,195,540us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,195,647us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39388]

@1,195,756us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c41535d count: 1

@1,195,873us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,196,028us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0xc8001]

@1,196,224us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0xd000e refCount: 1

@1,196,357us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0xc8001]

@1,196,480us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,196,586us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39398]

@1,196,692us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c41535e count: 1

@1,196,811us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,196,947us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0xd8001]

@1,197,131us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0xe000f refCount: 1

@1,197,264us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0xd8001]

@1,197,390us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,197,534us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x393a8]

@1,197,646us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c41535f count: 1

@1,197,765us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,197,897us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0xe8001]

@1,198,075us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0xf0010 refCount: 1

@1,198,215us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0xe8001]

@1,198,338us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,198,448us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x393b8]

@1,198,556us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415360 count: 1

@1,198,674us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,198,802us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0xf8001]

@1,199,025us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x100011 refCount: 1

@1,199,165us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0xf8001]

@1,199,291us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,199,396us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x393c8]

@1,537,422us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415361 count: 1

@1,537,595us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,537,744us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x108001]

@1,537,947us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x110012 refCount: 1

@1,538,086us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x108001]

@1,538,223us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,538,333us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x393d8]

@1,538,443us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415362 count: 1

@1,538,562us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,538,695us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x118001]

@1,538,920us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x120013 refCount: 1

@1,539,055us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x118001]

@1,539,187us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,539,295us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x393e8]

@1,539,401us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415363 count: 1

@1,539,519us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,539,649us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x128001]

@1,539,833us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x130014 refCount: 1

@1,539,967us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x128001]

@1,540,092us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,540,241us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x393f8]

@1,540,358us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> key: 0x4c415364 count: 1

@1,540,483us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c415350]

@1,541,493us: [+0 T:0x402c6318 S:0xbefffbfc] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x138001]

@1,541,789us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Sem_create> semId: 0x140015 refCount: 1

@1,541,937us: [+0 T:0x402c6318 S:0xbefffc04] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x138001]

@1,542,076us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,542,195us: [+0 T:0x402c6318 S:0xbefffc1c] ti.sdo.ce.osal.Sem - Leaving Sem_create> sem[0x39408]

@1,542,312us: [+0 T:0x402c6318 S:0xbefffc4c] OG - Global_atexit> enter (fxn=0x12570)

@1,542,432us: [+2 T:0x402c6318 S:0xbefffc74] ti.sdo.ce.osal.alg - ALG_init> Exit

@1,542,540us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0x12090)

@1,542,690us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0x14f98)

@1,543,698us: [+1 T:0x40ac7b60 S:0x40ac7524] OP - daemon> thread created.

@1,545,416us: [+6 T:0x402c6318 S:0xbefffc6c] CE - Engine_init> CE debugging on (CE_DEBUG=3; allowed CE_DEBUG levels: 1=min, 2=good, 3=max)

@1,545,596us: [+0 T:0x402c6318 S:0xbefffc5c] OG - Global_atexit> enter (fxn=0xfab8)

@1,545,927us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0xe960)

@1,546,233us: [+0 T:0x402c6318 S:0xbefffc6c] OG - Global_atexit> enter (fxn=0xccd0)

@1,546,401us: [+0 T:0x402c6318 S:0xbefffc74] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x0]

@1,546,544us: [+0 T:0x402c6318 S:0xbefffc8c] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,546,703us: [+2 T:0x402c6318 S:0xbefffc8c] ZZ - main> Welcome to app's main().

App-> Application started.

@1,551,120us: [+0 T:0x402c6318 S:0xbefffac4] ti.sdo.ce.osal.Sem - Entered Sem_enterCS> key[0x4c41534f]

@1,551,320us: [+0 T:0x402c6318 S:0xbefffac4] ti.sdo.ce.osal.Sem - Leaving Sem_enterCS> id[0x148000]

@1,551,471us: [+0 T:0x402c6318 S:0xbefffad4] OG - Global_atexit> enter (fxn=0x14f98)

@1,551,646us: [+0 T:0x402c6318 S:0xbefffadc] ti.sdo.ce.osal.Sem - Entered Sem_exitCS> id[0x148000]

@1,551,787us: [+0 T:0x402c6318 S:0xbefffaf4] ti.sdo.ce.osal.Sem - Leaving Sem_exitCS

@1,551,961us: [+0 T:0x402c6318 S:0xbefffa84] CE - Engine_open> Enter('Toc', 0x0, 0x388ac)

@1,552,118us: [+0 T:0x402c6318 S:0xbefffa84] CE - rserverOpen('./decodeCombo.x64P'), count = 0

@1,552,244us: [+0 T:0x402c6318 S:0xbefffa04] OP - Process_create> Enter(imageName='./decodeCombo.x64P', linkCfg='(null)', attrs=0xbefffad0)

@1,553,411us: [+0 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Enter(proc=0x399e8)

@1,553,594us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Initializing DSP PROC...

@1,553,738us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Using DspLink config data for entry #0 [server './decodeCombo.x64P']

@1,553,954us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Adding DSP segment #0 to Link configuration: name='DDR2', startAddress=0x8fa00000, sizeInBytes=0x400000, shared=1

@1,554,121us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Adding DSP segment #1 to Link configuration: name='DSPLINKMEM', startAddress=0x8fe00000, sizeInBytes=0x100000, shared=1

@1,554,262us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Adding DSP segment #2 to Link configuration: name='RESETCTRL', startAddress=0x8ff00000, sizeInBytes=0x80, shared=0

@1,554,431us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Adding DSP segment #3 to Link configuration: name='DDRALGHEAP', startAddress=0x88000000, sizeInBytes=0x7a00000, shared=0

@1,554,577us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> DOPOWERCONTROL was=0; now=0

@1,556,602us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Attaching to DSP PROC...

@1,574,174us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Opening MSGQ pool...

@1,574,874us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Loading ./decodeCombo.x64P on DSP (1 args)...

@1,746,693us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Starting DSP PROC...

@1,760,476us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> Opening remote transport...

@1,761,290us: [+2 T:0x40ac7b60 S:0x40ac7524] OP - Process_create_d> return (1)

@1,761,619us: [+0 T:0x402c6318 S:0xbefffa04] OP - Process_create> return (0x399e8)

@2,227,651us: [+0 T:0x402c6318 S:0xbefffa84] CE - rserverOpen('./decodeCombo.x64P'): 0x382f4 done.

@2,227,817us: [+0 T:0x402c6318 S:0xbefffa5c] OC - Comm_create> Enter(queueName='Toc', queue=0x399c8, attrs=0x0)

@2,228,332us: [+0 T:0x402c6318 S:0xbefffa5c] OC - Comm_create> return (0x39bb0)

@2,228,508us: [+0 T:0x402c6318 S:0xbefffa64] OC - Comm_alloc> Enter(poolId=0x0, msg=0x399d4, size=576)

@2,228,734us: [+0 T:0x402c6318 S:0xbefffa64] OC - Comm_alloc> msg=0x412d9c80, returning (0)

@2,228,867us: [+0 T:0x402c6318 S:0xbefffa44] OC - Comm_locate> Enter(queueName='rmsq', queue=0x399c4)

@2,239,463us: [+0 T:0x402c6318 S:0xbefffa44] OC - Comm_locate> return (0)

@2,239,643us: [+0 T:0x402c6318 S:0xbefffa84] CE - checkServer(0x399b8)

@2,239,794us: [+0 T:0x402c6318 S:0xbefffa54] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,240,026us: [+0 T:0x402c6318 S:0xbefffa54] OC - Comm_put> return (0)

@2,240,260us: [+0 T:0x402c6318 S:0xbefffa4c] OC - Comm_get> Enter(queue=0x10000, msg=0xbefffac8, timeout=-1)

@2,240,585us: [+0 T:0x402c6318 S:0xbefffa4c] OC - Comm_get> return (0)

@2,240,868us: [+0 T:0x402c6318 S:0xbefffa84] CE - rmsInit> RMS initialized(0x399b8); CE_DEBUG on, setting DSP trace mask to *+01234567,GT_prefix=12345,GT_time=3

@2,241,013us: [+0 T:0x402c6318 S:0xbefffa54] CE - Engine_setTrace> Enter(engine=0x399b8, mask='*+01234567,GT_prefix=12345,GT_time=3')

@2,241,165us: [+1 T:0x402c6318 S:0xbefffa54] CE - Engine_setTrace> Requesting DSP set trace ...

@2,241,272us: [+0 T:0x402c6318 S:0xbefffa24] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,241,494us: [+0 T:0x402c6318 S:0xbefffa24] OC - Comm_put> return (0)

@2,241,630us: [+0 T:0x402c6318 S:0xbefffa1c] OC - Comm_get> Enter(queue=0x10000, msg=0xbefffa8c, timeout=-1)

@2,242,854us: [+0 T:0x402c6318 S:0xbefffa1c] OC - Comm_get> return (0)

@2,243,029us: [+0 T:0x402c6318 S:0xbefffa54] CE - Engine_setTrace> return(0)

@2,243,192us: [+0 T:0x402c6318 S:0xbefff9e4] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,243,386us: [+0 T:0x402c6318 S:0xbefff9e4] OC - Comm_put> return (0)

@2,243,601us: [+0 T:0x402c6318 S:0xbefff9dc] OC - Comm_get> Enter(queue=0x10000, msg=0xbefffa70, timeout=-1)

@2,243,935us: [+0 T:0x402c6318 S:0xbefff9dc] OC - Comm_get> return (0)

[DSP] @1,014,785tk: [+0 T:0x8e00006c S:0x8e003fdc] OG - Global_setSpecialTrace> enter(mask='*+01234567,GT_prefix=12345,GT_time=3')

[DSP] @1,014,892tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - Global_setSpecialTrace> This program was built with the following packages:

[DSP] @1,014,970tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.targets.rts6000 (/root/dvsdk_1_30_01_41/xdc_3_00_02/packages/ti/targets/rts6000/) [1,0,0,0,1193543029447]

[DSP] @1,015,068tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.fc.dman3 (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/fc/dman3/) [1,0,3,0]

[DSP] @1,015,172tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.psl (/root/dvsdk_1_30_01_41/bios_5_31_08/packages/ti/psl/) [5,0,0,0]

[DSP] @1,015,252tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.rtdx (/root/dvsdk_1_30_01_41/bios_5_31_08/packages/ti/rtdx/) []

[DSP] @1,015,329tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.bios (/root/dvsdk_1_30_01_41/bios_5_31_08/packages/ti/bios/) [5,2,3,20,0]

[DSP] @1,015,411tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.fc.dskt2 (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/fc/dskt2/) [1,0,3,0]

[DSP] @1,015,508tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.xdais.dm (/root/dvsdk_1_30_01_41/xdais_6_00_01/packages/ti/xdais/dm/) [1,0,4,0]

[DSP] @1,015,593tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.xdais (/root/dvsdk_1_30_01_41/xdais_6_00_01/packages/ti/xdais/) [1,2,1,0]

[DSP] @1,015,676tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce.node (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/node/) [1,0,0,1200333318794]

[DSP] @1,015,774tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.utils.trace (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/utils/trace/) [1,0,0,0]

[DSP] @1,015,873tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce.utils.xdm (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/utils/xdm/) [1,0,1,1200333457442]

[DSP] @1,015,975tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.bios.utils (/root/dvsdk_1_30_01_41/biosutils_1_00_02/packages/ti/bios/utils/) [2,0,0,22,0]

[DSP] @1,016,066tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package dsplink.dsp (/root/dvsdk_1_30_01_41/dsplink_140-05p1/packages/dsplink/dsp/) [1,1,0,0]

[DSP] @1,016,152tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.fc.acpy3 (/root/dvsdk_1_30_01_41/framework_components_2_00_01/packages/ti/sdo/fc/acpy3/) [1,0,2,0]

[DSP] @1,016,248tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce.osal (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/osal/) [2,0,1,1200333329943]

[DSP] @1,016,346tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce.alg (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/alg/) [1,0,0,1200332939285]

[DSP] @1,016,442tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.catalog.c6000 (/root/dvsdk_1_30_01_41/xdc_3_00_02/packages/ti/catalog/c6000/) [1,0,0,0,1192229349164]

[DSP] @1,016,538tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.platforms.evmDM6446 (/root/dvsdk_1_30_01_41/bios_5_31_08/packages/ti/platforms/evmDM6446/) [1,0,0,0]

[DSP] @1,016,633tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/) [1,0,5,1200332924185]

[DSP] @1,016,725tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce.bioslog (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/bioslog/) [1,0,1,1200332966901]

[DSP] @1,016,825tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.ce.video (/root/dvsdk_1_30_01_41/codec_engine_2_00_01/packages/ti/sdo/ce/video/) [1,0,2,1200333474655]

[DSP] @1,016,924tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.codecs.TOC_video (/root/dvsdk_1_30_01_41/dm6446_dvsdk_combos_1_35_debabrataNew/packages-production/ti/sdo/codecs/TOC_video/) []

[DSP] @1,017,034tk: [+4 T:0x8e00006c S:0x8e003fdc] OG - package ti.sdo.servers.codec (/root/dvsdk_1_30_01_41/dm6446_dvsdk_combos_1_35_debabrataNew/packages-production/ti/sdo/servers/codec/) []

[DSP] @1,017,141tk: [+0 T:0x8e0@2,576,175us: [+0 T:0x402c6318 S:0xbefff9e4] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,576,407us: [+0 T:0x402c6318 S:0xbefff9e4] OC - Comm_put> return (0)

@2,576,632us: [+0 T:0x402c6318 S:0xbefff9dc] OC - Comm_get> Enter(queue=0x10000, msg=0xbefffa70, timeout=-1)

@2,576,989us: [+0 T:0x402c6318 S:0xbefff9dc] OC - Comm_get> return (0)

0006c S:0x8e003fdc] OG - Global_setSpecialTrace> return

[DSP] @1,018,739tk: [+0 T:0x8e00006c S:0x8e004024] CR - processRmsCmd(0x8fe05ca8, 4056): cmd = 5

[DSP] @1,018,804tk: [+0 T:0x8e00006c S:0x8e004024] CR - remote time = 0x0, trace buffer size = 4032

[DSP] @1,721,194tk: [+0 T:0x8e00006c S:0x8e004024] CR - processRmsCmd(0x8fe05ca8, 4056): cmd = 5

[DSP] @1,721,262tk: [+0 T:0x8e00006c S:0x8e004024] CR - remote time = 0x0, trace buffer size = 4032

@2,577,816us: [+0 T:0x402c6318 S:0xbefffa84] CE - Engine_open> return(235960)

after engine creation........ NEWENEWEWEW

TraceUtil_start> note: CE_DEBUG env. var is set, so TraceUtil is not active (unset CE_DEBUG if you need TraceUtil)

　

HERE before tov codec creation

　

　

Passing height and width@2,578,307us: [+0 T:0x402c6318 S:0xbefffad4] ti.sdo.ce.video.VIDENC - VIDENC_create> Enter (engine=0x399b8, name='tocvideo', params=0xbefffb20)

@2,578,611us: [+0 T:0x402c6318 S:0xbefffaa4] CV - VISA_create(0x399b8, 'tocvideo', 0xbefffb20, 0x828, 'ti.sdo.ce.video.IVIDENC')

@2,578,768us: [+0 T:0x402c6318 S:0xbefff9d4] CV - VISA_create2(0x399b8, 'tocvideo', 0xbefffb20, 0x54, 0x828, 'ti.sdo.ce.video.IVIDENC')

@2,578,937us: [+0 T:0x402c6318 S:0xbefff97c] CE - Engine_createNode(0x399b8, 'tocvideo', 828, 0xbefffb20, 0x54, 0xbefffad0)

@2,579,089us: [+0 T:0x402c6318 S:0xbefff954] OC - Comm_create> Enter(queueName='gppfromnode', queue=0x39c40, attrs=0x0)

@2,579,612us: [+0 T:0x402c6318 S:0xbefff954] OC - Comm_create> return (0x39c60)

@2,579,830us: [+0 T:0x402c6318 S:0xbefff95c] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,580,044us: [+0 T:0x402c6318 S:0xbefff95c] OC - Comm_put> return (0)

@2,580,185us: [+0 T:0x402c6318 S:0xbefff954] OC - Comm_get> Enter(queue=0x10000, msg=0xbefff9d4, timeout=-1)

@2,614,935us: [+0 T:0x402c6318 S:0xbefff954] OC - Comm_get> return (0)

@2,615,116us: [+0 T:0x402c6318 S:0xbefff95c] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,615,316us: [+0 T:0x402c6318 S:0xbefff95c] OC - Comm_put> return (0)

@2,615,572us: [+0 T:0x402c6318 S:0xbefff954] OC - Comm_get> Enter(queue=0x10000, msg=0xbefff9d4, timeout=-1)

@2,615,903us: [+0 T:0x402c6318 S:0xbefff954] OC - Comm_get> return (0)

@2,616,078us: [+4 T:0x402c6318 S:0xbefff97c] CE - Engine_createNode> created node(stdIn=0x2, stdOut=0x10001, msgq=0x39c60, algName='tocvideo', rmsNode=0x8fba3780, algHandle=0x8fba3858)

@2,616,254us: [+0 T:0x402c6318 S:0xbefff8dc] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@2,616,450us: [+0 T:0x402c6318 S:0xbefff8dc] OC - Comm_put> return (0)

@2,616,673us: [+0 T:0x402c6318 S:0xbefff8d4] OC - Comm_get> Enter(queue=0x10000, msg=0xbefff968, timeout=-1)

@2,617,036us: [+0 T:0x402c6318 S:0xbefff8d4] OC - Comm_get> return (0)

[DSP] @1,728,866tk: [+0 T:0x8e00006c S:0x8e004024] CR - processRmsCmd(0x8fe05ca8, 4056): cmd = 0

[DSP] @1,728,939tk: [+0 T:0x8e00006c S:0x8e003f14] OM - Memory_alloc> Enter(size=0x18)

[DSP] @1,729,000tk: [+0 T:0x8e00006c S:0x8e003f14] OM - Memory_alloc> return (0x8fba3780)

[DSP] @1,729,061tk: [+0 T:0x8e00006c S:0x8e003f14] OM - Memory_alloc> Enter(size=0x6)

[DSP] @1,729,116tk: [+0 T:0x8e00006c S:0x8e003f14] OM - Memory_alloc> return (0x8fba3798)

[DSP] @1,729,183tk: [+0 T:0x8e00006c S:0x8e003edc] OM - Memory_alloc> Enter(size=0x20)

[DSP] @1,729,239tk: [+0 T:0x8e00006c S:0x8e003edc] OM - Memory_alloc> return (0x8fba37a0)

[DSP] @1,729,300tk: [+0 T:0x8e00006c S:0x8e003eac] OM - Memory_alloc> Enter(size=0x24)

[DSP] @1,729,357tk: [+0 T:0x8e00006c S:0x8e003eac] OM - Memory_alloc> return (0x8fba37c0)

[DSP] @1,729,445tk: [+0 T:0x8e00006c S:0x8e003ec4] ti.sdo.ce.video.VIDENC - VIDENC_create> Enter (engine=0x0, name='toc', params=0x8fe05cc0)

[DSP] @1,729,540tk: [+0 T:0x8e00006c S:0x8e003e8c] CV - VISA_create(0x0, 'toc', 0x8fe05cc0, 0x828, 'ti.sdo.ce.video.IVIDENC')

[DSP] @1,729,625tk: [+0 T:0x8e00006c S:0x8e003d84] CV - VISA_create2(0x0, 'toc', 0x8fe05cc0, 0x54, 0x828, 'ti.sdo.ce.video.IVIDENC')

[DSP] @1,729,726tk: [+0 T:0x8e00006c S:0x8e003d1c] CE - Engine_open> Enter('local', 0x8e003d74, 0x33c)

[DSP] @1,729,795tk: [+0 T:0x8e00006c S:0x8e003cfc] OM - Memory_alloc> Enter(size=0x2c)

[DSP] @1,729,852tk: [+0 T:0x8e00006c S:0x8e003cfc] OM - Memory_alloc> return (0x8fba3828)

[DSP] @1,729,921tk: [+0 T:0x8e00006c S:0x8e003d1c] CE - Engine_open> return(-1883621336)

[DSP] @1,729,996tk: [+0 T:0x8e00006c S:0x8e003d64] OM - Memory_alloc> Enter(size=0x24)

[DSP] @1,730,054tk: [+0 T:0x8e00006c S:0x8e003d64] OM - Memory_alloc> return (0x8fba3858)

[DSP] @1,730,121tk: [+0 T:0x8e00006c S:0x8e003d3c] ti.sdo.ce.alg.Algorithm - Algorithm_create> Enter(fxns=0x8fb25008, idma3Fxns=0x0, params=0x8fe05cc0, attrs=0x8e003e88)

[DSP] @1,730,244tk: [+0 T:0x8e00006c S:0x8e003d1c] OM - Memory_alloc> Enter(size=0x10)

[DSP] @1,730,300tk: [+0 T:0x8e00006c S:0x8e003d1c] OM - Memory_alloc> return (0x8fba3880)

[DSP] @1,730,446tk: [+0 T:0x8e00006c S:0x8e003cbc] ti.sdo.ce.examples.codecs.TOC_video - TI_alloc

[DSP] @1,730,509tk: [+0 T:0x8e00006c S:0x8e003cbc] ti.sdo.ce.examples.codecs.TOC_video - TI_alloc end

[DSP] @1,753,392tk: [+0 T:0x8e00006c S:0x8e003cac] ti.sdo.ce.examples.codecs.TOC_video - TI_init obj_start

[DSP] @1,801,633tk: [+0 T:0x8e00006c S:0x8e003cac] ti.sdo.ce.examples.codecs.TOC_video - TI_init completed ^^^^^^^^^^^^^^^^^

[DSP] @1,801,743tk: [+0 T:0x8e00006c S:0x8e003d3c] ti.sdo.ce.alg.Algorithm - Algorithm_create> return (0x8fba3880)

[DSP] @1,801,831tk: [+0 T:0x8e00006c S:0x8e003ec4] ti.sdo.ce.video.VIDENC - VIDENC_create> return (0x8fba3858)

[DSP] @1,801,917tk: [+4 T:0x8e00006c S:0x8e003ebc] OT - Thread_create > name: "toc#0", pri: -1, stack size: 1024, stack seg: 0

[DSP] @1,803,328tk: [+0 T:0x8e00006c S:0x8e004024] CR - processRmsCmd(0x8fe05ca8, 4056): cmd = 1

[DSP] @1,805,663tk: [+0 T:0x8e00006c S:0x8e004024] CR - processRmsCmd(0x8fe05ca8, 4056): cmd = 5

[DSP] @1,805,731tk: [+0 T:0x8e00006c S:0x8e004024] CR - remote time = 0x0, trace buffer size = 4032

@3,269,532us: [+2 T:0x402c6318 S:0xbefff97c] CE - Engine_createNode> Returning 0x39c38

@3,269,734us: [+0 T:0x402c6318 S:0xbefff9b4] OC - Comm_alloc> Enter(poolId=0x0, msg=0x39c1c, size=828)

@3,269,916us: [+0 T:0x402c6318 S:0xbefff9b4] OC - Comm_alloc> msg=0x412dac80, returning (0)

@3,270,074us: [+5 T:0x402c6318 S:0xbefff9d4] CV - VISA_create> remote codec created (name='tocvideo', localQueueID=0x10001, remoteQueueID=0x0002)

@3,270,221us: [+0 T:0x402c6318 S:0xbefffad4] ti.sdo.ce.video.VIDENC - VIDENC_create> return (0x39c10)

after codec creation................ NEWEEWEEWE

　

　

After ceapp_init() status is ###### 0 #######

inpur argumrnts are 352 288 0 10000 1 32000 10 20 0 28

@3,271,516us: [+0 T:0x402c6318 S:0xbefff9e4] ti.sdo.ce.video.VIDENC - VIDENC_control> Enter (handle=0x39c10, id=0, params=0xbefffb38, status=0xbefffa80

@3,271,724us: [+5 T:0x402c6318 S:0xbefff9b4] CV - VISA_allocMsg> Allocating message for messageId=0x00020000

@3,271,864us: [+0 T:0x402c6318 S:0xbefff994] CV - VISA_call(visa=0x39c10, msg=0x412dac80): messageId=0x00020000, command=0x1

@3,271,999us: [+0 T:0x402c6318 S:0xbefff964] OC - Comm_put> Enter(queue=0x2, msg=0x412dac80)

@3,272,193us: [+0 T:0x402c6318 S:0xbefff964] OC - Comm_put> return (0)

@3,272,322us: [+0 T:0x402c6318 S:0xbefff95c] OC - Comm_get> Enter(queue=0x10001, msg=0xbefff9f4, timeout=-1)

@3,272,879us: [+0 T:0x402c6318 S:0xbefff95c] OC - Comm_get> return (0)

@3,273,073us: [+0 T:0x402c6318 S:0xbefff8e4] OC - Comm_put> Enter(queue=0x0, msg=0x412d9c80)

@3,273,286us: [+0 T:0x402c6318 S:0xbefff8e4] OC - Comm_put> return (0)

@3,273,507us: [+0 T:0x402c6318 S:0xbefff8dc] OC - Comm_get> Enter(queue=0x10000, msg=0xbefff970, timeout=-1)

@3,273,840us: [+0 T:0x402c6318 S:0xbefff8dc] OC - Comm_get> return (0)

[DSP] @3,188,875tk: [+5 T:0x8e50bc5c S:0x8e50c01c] CN - NODE> 0x8fba37a0(toc#0) call(algHandle=0x8fba3858, msg=0x8fe06c80); messageId=0x00020000

[DSP] @3,188,979tk: [+0 T:0x8e50bc5c S:0x8e50bf64] ti.sdo.ce.video.VIDENC - VIDENC_control> Enter (handle=0x8fba3858, id=0, params=0x8fe06cb4, status=0x8fe06d04

[DSP] @3,189,091tk: [+5 T:0x8e50bc5c S:0x8e50bf4c] CV - VISA_enter(visa=0x8fba3858): algHandle = 0x8fba3880

[DSP] @3,189,166tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(handle=0x8fba3880)

[DSP] @3,189,255tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.alg.Algorithm - Algorithm_activate> return

[DSP] @3,189,320tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.examples.codecs.TOC_video - Entered in to ITOCVIDEO_TCS_control

[DSP]

[DSP] @3,189,398tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.examples.codecs.TOC_video -

[DSP]

[DSP] height and width are data 288 352 @3,189,474tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.examples.codecs.TOC_video -

[DSP]

[DSP] height and width are 288 352 @3,189,550tk: [+5 T:0x8e50bc5c S:0x8e50bf4c] CV - VISA_exit(visa=0x8fba3858): algHandle = 0x8fba3880

[DSP] @3,189,624tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(handle=0x8fba3880)

[DSP] @3,189,703tk: [+0 T:0x8e50bc5c S:0x8e50bf2c] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> return

[DSP] @3,189,770tk: [+0 T:0x8e50bc5c S:0x8e50bf64] ti.sdo.ce.video.VIDENC - VIDENC_control> Exit (handle=0x8fba3858, retVal=0x0)

[DSP] @3,189,848tk: [+5 T:0x8e50bc5c S:0x8e50c01c] CN - NODE> returned from call(algHandle=0x8fba3858, msg=0x8fe06c80); messageId=0x00020000

[DSP] @3,191,178tk: [+0 T:0x8e00006c S:0x8e004024] CR - processRmsCmd(0x8fe05ca8, 4056): cmd = 5

[DSP] @3,191,245tk: [+0 T:0x8e00006c S:0x8e004024] CR - remote time = 0x0, trace buffer size = 4032

@3,276,578us: [+0 T:0x402c6318 S:0xbefff994] CV - VISA_call Completed: messageId=0x00020000, command=0x1, return(status=0)

@3,276,753us: [+5 T:0x402c6318 S:0xbefff9ac] CV - VISA_freeMsg(0x39c10, 0x412dac80): Freeing message with messageId=0x00020000

@3,276,887us: [+0 T:0x402c6318 S:0xbefff9e4] ti.sdo.ce.video.VIDENC - VIDENC_control> Exit (handle=0x39c10, retVal=0x0)

App-> Processing frame ...

CEapp-> Allocating contiguous buffer for 'input data' of size 152064...

after allocation

@3,277,855us: [+0 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> Enter(size=152064, align=-1, cached=FALSE, heap=FALSE)

@3,278,172us: [+4 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> CMEM_alloc(152064) = 0x4137b000.

@3,278,347us: [+4 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> CMEM_getPhys(0x4137b000) = 0x83b84000.

@3,278,475us: [+1 T:0x402c6318 S:0xbefffacc] OM - Memory__addContigBuf> Enter(virtAddr=0x4137b000, size=152064, physAddr=0x83b84000)

@3,278,595us: [+1 T:0x402c6318 S:0xbefffacc] OM - Memory__addContigBuf> creating new contigBuf object

@3,278,709us: [+1 T:0x402c6318 S:0xbefffacc] OM - Memory__addContigBuf> returning: cb->phys=0x83b84000, cb->size=152064, cb->virt=0x4137b000

@3,957,774us: [+0 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> return (0x4137b000)

CEapp-> Allocating contiguous buffer for 'output data' of size 3041280...

after allocation

@3,958,051us: [+0 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> Enter(size=3041280, align=-1, cached=FALSE, heap=FALSE)

@3,958,642us: [+4 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> CMEM_alloc(3041280) = 0x413a1000.

@3,958,825us: [+4 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> CMEM_getPhys(0x413a1000) = 0x8389d000.

@3,958,954us: [+1 T:0x402c6318 S:0xbefffacc] OM - Memory__addContigBuf> Enter(virtAddr=0x413a1000, size=3041280, physAddr=0x8389d000)

@3,959,076us: [+1 T:0x402c6318 S:0xbefffacc] OM - Memory__addContigBuf> creating new contigBuf object

@3,959,202us: [+1 T:0x402c6318 S:0xbefffacc] OM - Memory__addContigBuf> returning: cb->phys=0x8389d000, cb->size=3041280, cb->virt=0x413a1000

@3,959,323us: [+0 T:0x402c6318 S:0xbefffb0c] OM - Memory_contigAlloc> return (0x413a1000)

Reading started

Operation started

Processing for frams 0

Calling the VIDENC_process()

@4,003,609us: [+0 T:0x402c6318 S:0xbefff9cc] ti.sdo.ce.video.VIDENC - VIDENC_process> Enter (handle=0x39c10, inBufs=0xbefffb78, outBufs=0xbefffc98, inArgs=0xbefffa54, outArgs=0xbefffad8)

@4,003,781us: [+5 T:0x402c6318 S:0xbefff98c] CV - VISA_allocMsg> Allocating message for messageId=0x00020001

@4,003,911us: [+0 T:0x402c6318 S:0xbefff95c] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x4137b000, size=86652)

@4,004,029us: [+1 T:0x402c6318 S:0xbefff95c] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x4137b000, size=86652)

@4,004,148us: [+1 T:0x402c6318 S:0xbefff95c] OM - Memory__getPhysicalAddress> found in cb(Sc=0x4137b000, Ec=0x413a0200, Ss=0x4137b000, Es=0x4139027c, PSc=0x83b84000)

@4,004,270us: [+1 T:0x402c6318 S:0xbefff95c] OM - Memory__getPhysicalAddress> returning physAddr=0x83b84000

@4,004,378us: [+0 T:0x402c6318 S:0xbefff95c] OM - Memory_getBufferPhysicalAddress> return (0x83b84000)

@4,004,490us: [+0 T:0x402c6318 S:0xbefff95c] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x413a1000, size=3041280)

@4,004,602us: [+1 T:0x402c6318 S:0xbefff95c] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x413a1000, size=3041280)

@4,004,711us: [+1 T:0x402c6318 S:0xbefff95c] OM - Memory__getPhysicalAddress> found in cb(Sc=0x413a1000, Ec=0x41687800, Ss=0x413a1000, Es=0x41687800, PSc=0x8389d000)

@4,004,831us: [+1 T:0x402c6318 S:0xbefff95c] OM - Memory__getPhysicalAddress> returning physAddr=0x8389d000

@4,004,979us: [+0 T:0x402c6318 S:0xbefff95c] OM - Memory_getBufferPhysicalAddress> return (0x8389d000)

@4,005,097us: [+0 T:0x402c6318 S:0xbefff96c] CV - VISA_call(visa=0x39c10, msg=0x412dac80): messageId=0x00020001, command=0x0

@4,005,230us: [+0 T:0x402c6318 S:0xbefff93c] OC - Comm_put> Enter(queue=0x2, msg=0x412dac80)

@4,005,431us: [+0 T:0x402c6318 S:0xbefff93c] OC - Comm_put> return (0)

@4,005,562us: [+0 T:0x402c6318 S:0xbefff934] OC - Comm_get> Enter(queue=0x10001, msg=0xbefff9cc, timeout=-1)

HERE it is getting hang . It is not ble to call the process. That means the call from application to codec side is not happening.

What approach I need to follow to solve this problem.

Is it anyhing related to CMEM.ko or the .tcf file.

I am looking for your valuable suggestion.

 

 

 

 

Just to help clarify... what this trace is telling you is that the ARM is waiting (in essentially a Comm_get() call) for a reply from the DSP that's never happening.  This could be many things, including a DSP-side codec crash.

We don't have enough DSP-side insight from just this trace to tell whether the framework has gotten to your codec's process() call, whether the codec's process() call crashed, or whether the return trip from the DSP is failing.

Can you set a breakpoint on your DSP-side codec's process method?

http://tiexpressdsp.com/index.php/Debugging_the_DSP_side_of_a_CE_application_on_DaVinci_using_CCS

Chris

After trying some level I found these errors are coming.

I am passing two buffers in and out of size 152064.

 

Calling the VIDENC_process()

CMEM Error: getPhys: Failed to get physical address of 0x8239cf9f

@0x001123fd:[T:0x402c6318] OM - Memory_getBufferPhysicalAddress> ERROR: user buffer at addr=0x4237b000, size=1073880992 is NOT contiguous

Process called VIDENC_process()

CEapp-> VIDENC_process() failed, status = 0xfffffffe

Processing for frame 0 completed

 

Like this it is showing for all frames.

I checked the my loadmodule.sh

it is like this way

insmod cmemk.ko phys_start=0x83800000 phys_end=0x85000000 pools=4x4096,6x829440,2x9751756

insmod dsplinkk.ko

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

And this address 0x8239cf9f is unknown not even in the range of  phys_start=0x83800000 phys_end=0x85000000

What can be the problem !!!

 

Hi Frank,

iam running into the same problem, i have a Dm6467 davinci setup on which iam running H264 codec on the DSP side.

Every one and then i see the MSGQ_get ( ) takes 500msec.

 

Was wondering if you were able to fix this problem, - specifically was it an arm side problem or a dsp side problem.

Any pointers would be helpfull.

 

thanks in advance

Ashok

Hi Ashok,

We ended up having to revert to CodecEngine 2.21 from 2.23.  This brings the DSPLink version from 1.61 to 1.60.  I'm not sure what specifically fixed the problem, but reverting brought our performance back inline with our expectations.

Hope this helps.  If you uncover any additional insight, I'd be very interested to hear it.

Best of luck,

Frank

Hi Frank,

Thanks for the information, will try out the CodecEngine 2.21.

We have not yet pin pointed the problem yet, will keep you posted if  i uncover anything.

 

thanks

Ashok