Hi All,
We are facing a stability issue with out DM3730 based device, we are using a codec-engine with a H.264 and AAC encoder to continue create a mpegts video file.
In some conditions (avg. once a day) we have an issue where an ioctl call to the DSPlink driver (for a H.264 codec) never returns, we have been able to create a backtrace using GDB:
(gdb) bt
#0 0x4015e9ec in ioctl () from /lib/libc.so.6
#1 0x407b0cc0 in DRV_Invoke () from leaflets/patchbox/patchbox_c.so
#2 0x407b76b8 in MSGQ_get () from leaflets/patchbox/patchbox_c.so
#3 0x407a91f4 in Comm_get () from leaflets/patchbox/patchbox_c.so
#4 0x407a01c4 in Engine_call () from leaflets/patchbox/patchbox_c.so
#5 0x407a2ca8 in VISA_call () from leaflets/patchbox/patchbox_c.so
#6 0x40798d18 in process () from leaflets/patchbox/patchbox_c.so
#7 0x407983d0 in VIDENC1_process () from leaflets/patchbox/patchbox_c.so
#8 0x40793a5c in Venc1_process (hVe=0xaeee0, hInBuf=0x2cef60, hOutBuf=0xb2b08) at ce/Venc1.c:169
#9 0x4078c974 in fn_run (mod=0x3fcb50) at mod_enc_dsp.c:899
#10 0x4077a122 in do_mod (mod=<optimized out>, pb=<optimized out>) at patchbox.c:174
#11 check_mod (mod=<optimized out>, pb=<optimized out>) at patchbox.c:239
#12 pb_worker_thread (data=<optimized out>) at patchbox.c:282
#13 0x4024719a in start_thread () from /lib/libpthread.so.0
#14 0x40164b18 in clone () from /lib/libc.so.6
#15 0x40164b18 in clone () from /lib/libc.so.6
As you can see the code flows the normal path for a H.264 encode process using the DMAI API and stops and hangs in the ioctl() system call, this call will never return. The watchdog will fire in about a minute and the device is rebooted.
What could be the possible causes for this behavior?
Are there known issues with the software components we use which could explain this issues and are there software updates which fix these issues?
We are using:
biosutils_1_02_02
c6accel_1_01_00_07
c6run_0_98_03_03
cgt6x_6_1_14
codec-engine_2_26_02_11
codecs-omap3530_4_02_00_00
dmai_2_20_00_15
dspbios_5_41_03_17
dsplink_1_65_01_05_eng
framework-components_2_26_00_01
linuxutils_2_26_02_05
local-power-manager_1_24_03_10_eng
xdais_6_26_01_03
xdctools_3_16_03_36
The H.264 encoder we use is "H.264 Base Profile Encoder (01.00.02.00) on DM3730" at 1280x720 resolution avg. 15fps.
These components come from the ti-dvsdk_dm3730-evm_04_03_00_06 package, we are using an identical memory layout as the DM3730 EVK board.
Attached the CE logging in a zip file cause it's rather big, below is the last part of the CE_DEBUG log.
Thanks,
Robin
[DSP] @391,481,045tk: [+0 T:0x87c4faac S:0x87c55904] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x87c4e618, inBufs=0x87c559a4, outBufs=0x87c55a74, inArgs=0x85905a04, outArgs=0x85905a10)
[DSP] @391,481,164tk: [+5 T:0x87c4faac S:0x87c558e4] CV - VISA_enter(visa=0x87c4e618): algHandle = 0x87c4e650
[DSP] @391,481,234tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(alg=0x87c4e650)
[DSP] @391,481,385tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Exit
[DSP] @391,558,508tk: [+5 T:0x87c4faac S:0x87c558e4] CV - VISA_exit(visa=0x87c4e618): algHandle = 0x87c4e650
[DSP] @391,558,660tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(alg=0x87c4e650)
[DSP] @391,558,738tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Exit
[DSP] @391,558,797tk: [+0 T:0x87c4faac S:0x87c55904] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x87c4e618, retVal=0x0)
[DSP] @391,558,883tk: [+0 T:0x87c4faac S:0x87c5593c] OM - Memory_cacheWb> Enter(addr=0x83fca000, sizeInBytes=2104)
[DSP] @391,558,951tk: [+0 T:0x87c4faac S:0x87c5593c] OM - Memory_cacheWb> return
[DSP] @391,559,007tk: [+5 T:0x87c4faac S:0x87c55a74] CN - NODE> returned from call(algHandle=0x87c4e618, msg=0x85905880); messageId=0x00027ac9
[DSP] @391,560,349tk: [+0 T:0x87c49a94 S:0x87c4da54] CR - processRmsCmd(0x859048a8, 4056): cmd = 5
[DSP] @391,560,419tk: [+0 T:0x87c49a94 S:0x87c4da54] CR - remote time = 0x0, trace buffer size = 4032
@130,602,324us: [+0 T:0x4599b470 S:0x4599a6d4] CE - Engine_fwriteTrace> returning count [1699]
@130,602,385us: [+0 T:0x4599b470 S:0x4599a754] CV - VISA_call Completed: messageId=0x00027ac9, command=0x0, return(status=0)
@130,602,416us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x83fca000, size=2104)
@130,602,477us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x83fca000, size=2104)
@130,602,507us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> found in cb(Sc=0x83fca000, Ec=0x8418c000, Ss=0x83fca000, Es=0x83fca838)
@130,602,568us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x43250000
@130,602,599us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x43250000)
@130,602,629us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x85c75875, size=787680)
@130,602,660us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x85c75875, size=787680)
@130,602,690us: [+7 T:0x4599b470 S:0x4599a734] OM - Memory_getVirtualAddress> Error: buffer (physAddr=0x85c75875, size=0xc04e0) not found in translationcache
Ensure that you have registered this buffer with Memory_registerContigBuf()
@130,602,751us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x0
@130,602,782us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x0)
@130,602,904us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x85d3c1d3, size=196560)
@130,602,935us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x85d3c1d3, size=196560)
@130,602,996us: [+7 T:0x4599b470 S:0x4599a734] OM - Memory_getVirtualAddress> Error: buffer (physAddr=0x85d3c1d3, size=0x2ffd0) not found in translationcache
Ensure that you have registered this buffer with Memory_registerContigBuf()
@130,603,026us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x0
@130,603,057us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x0)
@130,603,118us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x85d6e853, size=196560)
@130,603,148us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x85d6e853, size=196560)
@130,603,179us: [+7 T:0x4599b470 S:0x4599a734] OM - Memory_getVirtualAddress> Error: buffer (physAddr=0x85d6e853, size=0x2ffd0) not found in translationcache
Ensure that you have registered this buffer with Memory_registerContigBuf()
@130,603,240us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x0
@130,603,270us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x0)
@130,603,301us: [+5 T:0x4599b470 S:0x4599a744] CV - VISA_freeMsg(0x4438e8, 0x46b01880): Freeing message with messageId=0x00027ac9
@130,603,331us: [+0 T:0x4599b470 S:0x4599a7b4] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x4438e8, retVal=0x0)
@130,603,362us: [+2 T:0x4599b470 S:0x4599a804] ti.sdo.dmai - [Venc1] VIDENC1_process() ret 0 inId 0 outID 1 generated 2104 bytes
@130,646,148us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> Enter (pStruct=0x4599a8f4, minSize=0xc, name=inArgs
@130,646,270us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> return (0x1)
@130,646,300us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> Enter (pStruct=0x4599a87c, minSize=0x78, name=outArgs
@130,646,331us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> return (0x1)
@130,646,361us: [+0 T:0x4599b470 S:0x4599a7b4] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x4438e8, inBufs=0x4599a910, outBufs=0x4599a904, inArgs=0x4599a8f4, outArgs=0x4599a87c)
@130,646,422us: [+0 T:0x4599b470 S:0x4599a794] XU - XdmUtils_validateSparseBufDesc> Enter (bufDesc=0x4599a904, name=outBufs
@130,646,483us: [+0 T:0x4599b470 S:0x4599a794] XU - XdmUtils_validateSparseBufDesc> return (0x1)
@130,646,514us: [+4 T:0x4599b470 S:0x4599a734] CV - VISA_getMaxMsgSize(0x4438e8): returning 0x1000
@130,646,544us: [+5 T:0x4599b470 S:0x4599a73c] CV - VISA_allocMsg> Allocating message for messageId=0x00027aca
@130,646,605us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x42986000, size=1843200)
@130,646,636us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x42986000, size=1843200)
@130,646,667us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> found in cb(Sc=0x42986000, Ec=0x42b48000, Ss=0x42986000, Es=0x42b48000, PSc=0x83700000)
@130,646,697us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> returning physAddr=0x83700000
@130,646,728us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> return (0x83700000)
@130,646,789us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x43250000, size=1843200)
@130,646,819us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x43250000, size=1843200)
@130,646,850us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> found in cb(Sc=0x43250000, Ec=0x43412000, Ss=0x43250000, Es=0x43412000, PSc=0x83fca000)
@130,646,880us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> returning physAddr=0x83fca000
@130,646,911us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> return (0x83fca000)
@130,646,941us: [+0 T:0x4599b470 S:0x4599a754] CV - VISA_call(visa=0x4438e8, msg=0x46b01880): messageId=0x00027aca, command=0x0
@130,647,002us: [+0 T:0x4599b470 S:0x4599a71c] OC - Comm_put> Enter(queue=0x2, msg=0x46b01880)
@130,647,063us: [+0 T:0x4599b470 S:0x4599a71c] OC - Comm_put> return (0)
@130,647,094us: [+0 T:0x4599b470 S:0x4599a714] OC - Comm_get> Enter(queue=0x10001, msg=0x4599a7cc, timeout=-1)
@130,672,149us: [+0 T:0x4599b470 S:0x4599a714] OC - Comm_get> MSGQ_get() status=0x8000, return (0)
@130,672,271us: [+0 T:0x4599b470 S:0x4599a6a4] OC - Comm_put> Enter(queue=0x0, msg=0x46b00880)
@130,672,332us: [+0 T:0x4599b470 S:0x4599a6a4] OC - Comm_put> return (0)
@130,672,393us: [+0 T:0x4599b470 S:0x4599a69c] OC - Comm_get> Enter(queue=0x10000, msg=0x4599a73c, timeout=-1)
@130,672,485us: [+0 T:0x4599b470 S:0x4599a69c] OC - Comm_get> MSGQ_get() status=0x8000, return (0)
[DSP] @391,705,494tk: [+5 T:0x87c4faac S:0x87c55a74] CN - NODE> 0x87c4e550(h264enc#0) call(algHandle=0x87c4e618, msg=0x85905880); messageId=0x00027aca
[DSP] @391,705,599tk: [+0 T:0x87c4faac S:0x87c55904] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x87c4e618, inBufs=0x87c559a4, outBufs=0x87c55a74, inArgs=0x85905a04, outArgs=0x85905a10)
[DSP] @391,705,716tk: [+5 T:0x87c4faac S:0x87c558e4] CV - VISA_enter(visa=0x87c4e618): algHandle = 0x87c4e650
[DSP] @391,705,786tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(alg=0x87c4e650)
[DSP] @391,705,869tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Exit
[DSP] @391,782,970tk: [+5 T:0x87c4faac S:0x87c558e4] CV - VISA_exit(visa=0x87c4e618): algHandle = 0x87c4e650
[DSP] @391,783,078tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(alg=0x87c4e650)
[DSP] @391,783,150tk: [+0 T:0x87c4faac S:0x87c558c4] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Exit
[DSP] @391,783,208tk: [+0 T:0x87c4faac S:0x87c55904] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x87c4e618, retVal=0x0)
[DSP] @391,783,289tk: [+0 T:0x87c4faac S:0x87c5593c] OM - Memory_cacheWb> Enter(addr=0x83fca000, sizeInBytes=3620)
[DSP] @391,783,359tk: [+0 T:0x87c4faac S:0x87c5593c] OM - Memory_cacheWb> return
[DSP] @391,783,410tk: [+5 T:0x87c4faac S:0x87c55a74] CN - NODE> returned from call(algHandle=0x87c4e618, msg=0x85905880); messageId=0x00027aca
[DSP] @391,784,457tk: [+0 T:0x87c49a94 S:0x87c4da54] CR - processRmsCmd(0x859048a8, 4056): cmd = 5
[DSP] @391,784,521tk: [+0 T:0x87c49a94 S:0x87c4da54] CR - remote time = 0x0, trace buffer size = 4032
@130,673,614us: [+0 T:0x4599b470 S:0x4599a6d4] CE - Engine_fwriteTrace> returning count [1699]
@130,673,675us: [+0 T:0x4599b470 S:0x4599a754] CV - VISA_call Completed: messageId=0x00027aca, command=0x0, return(status=0)
@130,673,705us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x83fca000, size=3620)
@130,673,736us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x83fca000, size=3620)
@130,673,797us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> found in cb(Sc=0x83fca000, Ec=0x8418c000, Ss=0x83fca000, Es=0x83fcae24)
@130,673,827us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x43250000
@130,673,858us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x43250000)
@130,673,888us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x85da4cf5, size=787680)
@130,673,919us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x85da4cf5, size=787680)
@130,673,949us: [+7 T:0x4599b470 S:0x4599a734] OM - Memory_getVirtualAddress> Error: buffer (physAddr=0x85da4cf5, size=0xc04e0) not found in translationcache
Ensure that you have registered this buffer with Memory_registerContigBuf()
@130,674,010us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x0
@130,674,041us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x0)
@130,674,071us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x85e6b653, size=196560)
@130,674,102us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x85e6b653, size=196560)
@130,674,163us: [+7 T:0x4599b470 S:0x4599a734] OM - Memory_getVirtualAddress> Error: buffer (physAddr=0x85e6b653, size=0x2ffd0) not found in translationcache
Ensure that you have registered this buffer with Memory_registerContigBuf()
@130,674,194us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x0
@130,674,224us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x0)
@130,674,255us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> Enter(physAddr=0x85e9dcd3, size=196560)
@130,674,316us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> Enter(physAddr=0x85e9dcd3, size=196560)
@130,674,346us: [+7 T:0x4599b470 S:0x4599a734] OM - Memory_getVirtualAddress> Error: buffer (physAddr=0x85e9dcd3, size=0x2ffd0) not found in translationcache
Ensure that you have registered this buffer with Memory_registerContigBuf()
@130,674,377us: [+1 T:0x4599b470 S:0x4599a734] OM - Memory__getVirtualAddress> returning virtAddr=0x0
@130,674,438us: [+0 T:0x4599b470 S:0x4599a734] OM - Memory_getBufferVirtualAddress> return (0x0)
@130,674,468us: [+5 T:0x4599b470 S:0x4599a744] CV - VISA_freeMsg(0x4438e8, 0x46b01880): Freeing message with messageId=0x00027aca
@130,674,499us: [+0 T:0x4599b470 S:0x4599a7b4] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x4438e8, retVal=0x0)
@130,674,529us: [+2 T:0x4599b470 S:0x4599a804] ti.sdo.dmai - [Venc1] VIDENC1_process() ret 0 inId 0 outID 1 generated 3620 bytes
@130,675,689us: [+0 T:0x4619b470 S:0x4619a9fc] XU - XdmUtils_validateExtendedStruct> Enter (pStruct=0x4619aae8, minSize=0x14, name=inArgs
@130,675,719us: [+0 T:0x4619b470 S:0x4619a9fc] XU - XdmUtils_validateExtendedStruct> return (0x1)
@130,675,780us: [+0 T:0x4619b470 S:0x4619a9fc] XU - XdmUtils_validateExtendedStruct> Enter (pStruct=0x4619aad4, minSize=0x14, name=outArgs
@130,675,811us: [+0 T:0x4619b470 S:0x4619a9fc] XU - XdmUtils_validateExtendedStruct> return (0x1)
@130,675,842us: [+0 T:0x4619b470 S:0x4619aa24] ti.sdo.ce.audio1.AUDENC1 - AUDENC1_process> Enter (handle=0x438968, inBufs=0x4619abc0, outBufs=0x4619aafc, inArgs=0x4619aae8, outArgs=0x4619aad4)
@130,675,872us: [+0 T:0x4619b470 S:0x4619aa04] XU - XdmUtils_validateSparseBufDesc1> Enter (bufDesc=0x4619abc0, name=inBufs
@130,675,903us: [+0 T:0x4619b470 S:0x4619aa04] XU - XdmUtils_validateSparseBufDesc1> return (0x1)
@130,675,964us: [+0 T:0x4619b470 S:0x4619aa04] XU - XdmUtils_validateSparseBufDesc1> Enter (bufDesc=0x4619aafc, name=outBufs
@130,675,994us: [+0 T:0x4619b470 S:0x4619aa04] XU - XdmUtils_validateSparseBufDesc1> return (0x1)
@130,676,025us: [+4 T:0x4619b470 S:0x4619a9ac] CV - VISA_getMaxMsgSize(0x438968): returning 0x1000
@130,678,374us: [+5 T:0x4619b470 S:0x4619a9b4] CV - VISA_allocMsg> Allocating message for messageId=0x00033d2f
@130,678,405us: [+0 T:0x4619b470 S:0x4619a984] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x461a5000, size=4096)
@130,678,466us: [+1 T:0x4619b470 S:0x4619a984] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x461a5000, size=4096)
@130,678,497us: [+1 T:0x4619b470 S:0x4619a984] OM - Memory__getPhysicalAddress> found in cb(Sc=0x461a5000, Ec=0x461a6000, Ss=0x461a5000, Es=0x461a6000, PSc=0x85321000)
@130,678,527us: [+1 T:0x4619b470 S:0x4619a984] OM - Memory__getPhysicalAddress> returning physAddr=0x85321000
@130,678,558us: [+0 T:0x4619b470 S:0x4619a984] OM - Memory_getBufferPhysicalAddress> return (0x85321000)
@130,678,588us: [+0 T:0x4619b470 S:0x4619a984] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x40026000, size=1536)
@130,678,649us: [+1 T:0x4619b470 S:0x4619a984] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x40026000, size=1536)
@130,678,680us: [+1 T:0x4619b470 S:0x4619a984] OM - Memory__getPhysicalAddress> found in cb(Sc=0x40026000, Ec=0x40026600, Ss=0x40026000, Es=0x40026600, PSc=0x85320000)
@130,678,710us: [+1 T:0x4619b470 S:0x4619a984] OM - Memory__getPhysicalAddress> returning physAddr=0x85320000
@130,678,741us: [+0 T:0x4619b470 S:0x4619a984] OM - Memory_getBufferPhysicalAddress> return (0x85320000)
@130,678,771us: [+0 T:0x4619b470 S:0x4619a9cc] CV - VISA_call(visa=0x438968, msg=0x46b03880): messageId=0x00033d2f, command=0x0
@130,678,832us: [+0 T:0x4619b470 S:0x4619a994] OC - Comm_put> Enter(queue=0x3, msg=0x46b03880)
@130,678,893us: [+0 T:0x4619b470 S:0x4619a994] OC - Comm_put> return (0)
@130,678,924us: [+0 T:0x4619b470 S:0x4619a98c] OC - Comm_get> Enter(queue=0x10003, msg=0x4619aa3c, timeout=-1)
@130,680,572us: [+0 T:0x4619b470 S:0x4619a98c] OC - Comm_get> MSGQ_get() status=0x8000, return (0)
@130,680,663us: [+0 T:0x4619b470 S:0x4619a91c] OC - Comm_put> Enter(queue=0x0, msg=0x46b02880)
@130,680,724us: [+0 T:0x4619b470 S:0x4619a91c] OC - Comm_put> return (0)
@130,680,755us: [+0 T:0x4619b470 S:0x4619a914] OC - Comm_get> Enter(queue=0x10002, msg=0x4619a9b4, timeout=-1)
@130,680,877us: [+0 T:0x4619b470 S:0x4619a914] OC - Comm_get> MSGQ_get() status=0x8000, return (0)
[DSP] @391,804,917tk: [+5 T:0x87c55cac S:0x87c5a474] CN - NODE> 0x87c55b28(aacheenc#1) call(algHandle=0x87c55ba0, msg=0x85907880); messageId=0x00033d2f
[DSP] @391,805,019tk: [+0 T:0x87c55cac S:0x87c5a29c] OM - Memory_cacheInv> Enter(addr=0x85321000, sizeInBytes=4096)
[DSP] @391,805,087tk: [+0 T:0x87c55cac S:0x87c5a29c] OM - Memory_cacheInv> return
[DSP] @391,805,133tk: [+0 T:0x87c55cac S:0x87c5a29c] OM - Memory_cacheInv> Enter(addr=0x85320000, sizeInBytes=1536)
[DSP] @391,805,198tk: [+0 T:0x87c55cac S:0x87c5a29c] OM - Memory_cacheInv> return
[DSP] @391,805,248tk: [+0 T:0x87c55cac S:0x87c5a254] ti.sdo.ce.audio1.AUDENC1 - AUDENC1_process> Enter (handle=0x87c55ba0, inBufs=0x87c5a304, outBufs=0x87c5a3c8, inArgs=0x85907a38, outArgs=0x85907a4c)
[DSP] @391,805,366tk: [+5 T:0x87c55cac S:0x87c5a234] CV - VISA_enter(visa=0x87c55ba0): algHandle = 0x87c55bd8
[DSP] @391,805,433tk: [+0 T:0x87c55cac S:0x87c5a214] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(alg=0x87c55bd8)
[DSP] @391,805,516tk: [+0 T:0x87c55cac S:0x87c5a214] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Exit
[DSP] @391,808,845tk: [+5 T:0x87c55cac S:0x87c5a234] CV - VISA_exit(visa=0x87c55ba0): algHandle = 0x87c55bd8
[DSP] @391,808,971tk: [+0 T:0x87c55cac S:0x87c5a214] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(alg=0x87c55bd8)
[DSP] @391,809,045tk: [+0 T:0x87c55cac S:0x87c5a214] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Exit
[DSP] @391,809,104tk: [+0 T:0x87c55cac S:0x87c5a254] ti.sdo.ce.audio1.AUDENC1 - AUDENC1_process> Exit (handle=0x87c55ba0, retVal=0x0)
[DSP] @391,809,185tk: [+0 T:0x87c55cac S:0x87c5a29c] OM - Memory_cacheWb> Enter(addr=0x85320000, sizeInBytes=1536)
[DSP] @391,809,261tk: [+0 T:0x87c55cac S:0x87c5a29c] OM - Memory_cacheWb> return
[DSP] @391,809,315tk: [+5 T:0x87c55cac S:0x87c5a474] CN - NODE> returned from call(algHandle=0x87c55ba0, msg=0x85907880); messageId=0x00033d2f
[DSP] @391,810,688tk: [+0 T:0x87c49a94 S:0x87c4da54] CR - processRmsCmd(0x859068a8, 4056): cmd = 5
[DSP] @391,810,753tk: [+0 T:0x87c49a94 S:0x87c4da54] CR - remote time = 0x0, trace buffer size = 4032
@130,682,433us: [+0 T:0x4619b470 S:0x4619a94c] CE - Engine_fwriteTrace> returning count [2096]
@130,682,464us: [+0 T:0x4619b470 S:0x4619a9cc] CV - VISA_call Completed: messageId=0x00033d2f, command=0x0, return(status=0)
@130,682,525us: [+5 T:0x4619b470 S:0x4619a9d4] CV - VISA_freeMsg(0x438968, 0x46b03880): Freeing message with messageId=0x00033d2f
@130,682,555us: [+0 T:0x4619b470 S:0x4619aa24] ti.sdo.ce.audio1.AUDENC1 - AUDENC1_process> Exit (handle=0x438968, retVal=0x0)
@130,682,586us: [+2 T:0x4619b470 S:0x4619aa7c] ti.sdo.dmai - [Aenc1] AUDENC1_process() ret 0,generated bytes 512,consumed 1024 samples
@130,682,739us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> Enter (pStruct=0x4599a8f4, minSize=0xc, name=inArgs
@130,682,800us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> return (0x1)
@130,682,830us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> Enter (pStruct=0x4599a87c, minSize=0x78, name=outArgs
@130,682,861us: [+0 T:0x4599b470 S:0x4599a78c] XU - XdmUtils_validateExtendedStruct> return (0x1)
@130,682,891us: [+0 T:0x4599b470 S:0x4599a7b4] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x4438e8, inBufs=0x4599a910, outBufs=0x4599a904, inArgs=0x4599a8f4, outArgs=0x4599a87c)
@130,682,922us: [+0 T:0x4599b470 S:0x4599a794] XU - XdmUtils_validateSparseBufDesc> Enter (bufDesc=0x4599a904, name=outBufs
@130,682,983us: [+0 T:0x4599b470 S:0x4599a794] XU - XdmUtils_validateSparseBufDesc> return (0x1)
@130,683,013us: [+4 T:0x4599b470 S:0x4599a734] CV - VISA_getMaxMsgSize(0x4438e8): returning 0x1000
@130,683,044us: [+5 T:0x4599b470 S:0x4599a73c] CV - VISA_allocMsg> Allocating message for messageId=0x00027acb
@130,683,074us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x42b48000, size=1843200)
@130,683,135us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x42b48000, size=1843200)
@130,683,166us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> found in cb(Sc=0x42b48000, Ec=0x42d0a000, Ss=0x42b48000, Es=0x42d0a000, PSc=0x838c2000)
@130,683,196us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> returning physAddr=0x838c2000
@130,683,227us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> return (0x838c2000)
@130,683,257us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> Enter(virtAddr=0x43250000, size=1843200)
@130,683,318us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> Enter(virtAddr=0x43250000, size=1843200)
@130,683,349us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> found in cb(Sc=0x43250000, Ec=0x43412000, Ss=0x43250000, Es=0x43412000, PSc=0x83fca000)
@130,683,379us: [+1 T:0x4599b470 S:0x4599a70c] OM - Memory__getPhysicalAddress> returning physAddr=0x83fca000
@130,683,410us: [+0 T:0x4599b470 S:0x4599a70c] OM - Memory_getBufferPhysicalAddress> return (0x83fca000)
@130,683,440us: [+0 T:0x4599b470 S:0x4599a754] CV - VISA_call(visa=0x4438e8, msg=0x46b01880): messageId=0x00027acb, command=0x0
@130,683,471us: [+0 T:0x4599b470 S:0x4599a71c] OC - Comm_put> Enter(queue=0x2, msg=0x46b01880)
@130,683,532us: [+0 T:0x4599b470 S:0x4599a71c] OC - Comm_put> return (0)
@130,683,593us: [+0 T:0x4599b470 S:0x4599a714] OC - Comm_get> Enter(queue=0x10001, msg=0x4599a7cc, timeout=-1)
After 60 seconds the watchdog fires.
