• State Resolved
  • Locked Locked
  • Replies 7 replies
  • Subscribers 98 subscribers
  • Views 645 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.

VISA_freeMsg: Assertion

V.Faul
Intellectual 885 points

At random times, my 6467 Linux application is crashing giving the following message: "visa.c:561: VISA_freeMsg: Assertion `visa->cmd[visa->cmdFreeIndex] == ((void *)0)' failed."

Is this an error in the Linux application or the codec running on the DSP?  Any ideas how to track down the issue?

  • 0
    TI__Mastermind 18260 points

    The assertion

    V.Faul said:
    visa.c:561: VISA_freeMsg: Assertion `visa->cmd[visa->cmdFreeIndex] == ((void *)0)' failed

    indicates that there is unbalanced VISA_allocMsg()/VISA_freeMsg() calling.

    Are you using the "async process" APIs, e.g., VIDENC1_processAsync()?  If so, are you checking for successful return before doing the next "processAsync()" or "processWait()" calls?  Or perhaps calling the "control()" API with an outstanding "processAsync()" call that has not yet been "processWait()"ed on?

    If you're not using the async APIs, I'll have to think deeper on this, doesn't look like it should happen at all in the synchronous case.

    Regards,

    - Rob

  • 0 in reply to Robert Tivy
    Intellectual 885 points

    Are those functions used in a codec that runs on the 6467's DSP?  I am using a third-party codec.  I have a LINUX application on the ARM processor that interfaces with the codec and my code does not directly call those functions. 

  • 0 in reply to V.Faul
    TI__Mastermind 18260 points

    The *_processAsync()/*_processWait() functions are used in the Linux app.  Just to be sure about my question, I was asking about any of the VISA class functions, e.g., AUDDEC1_processAsync() or VIDENC1_processAsync().

    In order to evaluate your issue further, would you be able to turn on CE_DEBUG logging?  It is an environment variable, and setting it to 3 and reporting back here with the output would be helpful:
        % export CE_DEBUG=3
        % <run your app>

    Regards,

    - Rob

     

  • 0 in reply to Robert Tivy
    Intellectual 885 points

    I don't use any of those Linux functions in my code, however, the third-party codec has an interface library that may contain some of those functions.  I ran with CE_DEBUG=2 (3 caused the file to get too big too fast) and the last part of the log is shown below.  There seems to be a repeating pattern until "OP - doCmd> Enter" and then a thread is deleted and then the software watchdog reboots the system.

    @3867,834,152us: [+5 T:0x00024009] CV - VISA_allocMsg> Allocating message for messageId=0x0002bd7a
    @3867,834,386us: [+0 T:0x00024009] CV - VISA_call(visa=0x459b0, msg=0x45014880): messageId=0x0002bd7a, command=0x0
    [DSP] @1752,144,083tk: [+5 T:0x8d067cdc] CN - NODE> 0x8d067400(h264hdenc#0) call(algHandle=0x8d0674c0, msg=0x8e004880); messageId=0x0002bd7a
    [DSP] @1752,144,187tk: [+0 T:0x8d067cdc] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x8d0674c0, inBufs=0x8d06dbf0, outBufs=0x8d06dcc0, inArgs=0x8e004a04, outArgs=0x8e004a18)
    [DSP] @1752,144,311tk: [+5 T:0x8d067cdc] CV - VISA_enter(visa=0x8d0674c0): algHandle = 0x8d0674f0
    [DSP] @1752,144,378tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(handle=0x8d0674f0)
    [DSP] @1752,144,453tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_activate> return
    [DSP] @1752,177,840tk: [+5 T:0x8d067cdc] CV - VISA_exit(visa=0x8d0674c0): algHandle = 0x8d0674f0
    [DSP] @1752,177,935tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(handle=0x8d0674f0)
    [DSP] @1752,178,015tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> return
    [DSP] @1752,178,073tk: [+0 T:0x8d067cdc] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x8d0674c0, retVal=0x0)
    [DSP] @1752,178,170tk: [+5 T:0x8d067cdc] CN - NODE> returned from call(algHandle=0x8d0674c0, msg=0x8e004880); messageId=0x0002bd7a
    @3867,855,352us: [+0 T:0x00024009] CE - Engine_fwriteTrace> returning count [1194]
    @3867,855,553us: [+0 T:0x00024009] CV - VISA_call Completed: messageId=0x0002bd7a, command=0x0, return(status=0)
    @3867,855,765us: [+5 T:0x00024009] CV - VISA_freeMsg(0x459b0, 0x45014880): Freeing message with messageId=0x0002bd7a
    @3867,855,961us: [+0 T:0x00024009] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x459b0, retVal=0x0)
    @3867,856,439us: [+0 T:0x00024009] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x459b0, inBufs=0xbd9fe768, outBufs=0xbd9fe758, inArgs=0x40870438, outArgs=0x4087044c)
    @3867,856,731us: [+5 T:0x00024009] CV - VISA_allocMsg> Allocating message for messageId=0x0002bd7b
    @3867,856,949us: [+0 T:0x00024009] CV - VISA_call(visa=0x459b0, msg=0x45014880): messageId=0x0002bd7b, command=0x0
    [DSP] @1752,196,432tk: [+5 T:0x8d067cdc] CN - NODE> 0x8d067400(h264hdenc#0) call(algHandle=0x8d0674c0, msg=0x8e004880); messageId=0x0002bd7b
    [DSP] @1752,196,536tk: [+0 T:0x8d067cdc] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x8d0674c0, inBufs=0x8d06dbf0, outBufs=0x8d06dcc0, inArgs=0x8e004a04, outArgs=0x8e004a18)
    [DSP] @1752,196,660tk: [+5 T:0x8d067cdc] CV - VISA_enter(visa=0x8d0674c0): algHandle = 0x8d0674f0
    [DSP] @1752,196,731tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_activate> Enter(handle=0x8d0674f0)
    [DSP] @1752,196,807tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_activate> return
    [DSP] @1752,230,226tk: [+5 T:0x8d067cdc] CV - VISA_exit(visa=0x8d0674c0): algHandle = 0x8d0674f0
    [DSP] @1752,230,324tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> Enter(handle=0x8d0674f0)
    [DSP] @1752,230,404tk: [+0 T:0x8d067cdc] ti.sdo.ce.alg.Algorithm - Algorithm_deactivate> return
    [DSP] @1752,230,463tk: [+0 T:0x8d067cdc] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x8d0674c0, retVal=0x0)
    [DSP] @1752,230,545tk: [+5 T:0x8d067cdc] CN - NODE> returned from call(algHandle=0x8d0674c0, msg=0x8e004880); messageId=0x0002bd7b
    @3867,877,920us: [+0 T:0x00024009] CE - Engine_fwriteTrace> returning count [1194]
    @3867,878,100us: [+0 T:0x00024009] CV - VISA_call Completed: messageId=0x0002bd7b, command=0x0, return(status=0)
    @3867,878,315us: [+5 T:0x00024009] CV - VISA_freeMsg(0x459b0, 0x45014880): Freeing message with messageId=0x0002bd7b
    @3868,213,931us: [+0 T:0x00024009] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Exit (handle=0x459b0, retVal=0x0)
    @3868,214,630us: [+0 T:0x00024009] ti.sdo.ce.video1.VIDENC1 - VIDENC1_process> Enter (handle=0x459b0, inBufs=0xbd9fe768, outBufs=0xbd9fe758, inArgs=0x40870438, outArgs=0x4087044c)
    @3868,214,925us: [+5 T:0x00024009] CV - VISA_allocMsg> Allocating message for messageId=0x0002bd7c
    @3868,215,146us: [+0 T:0x00024009] CV - VISA_call(visa=0x459b0, msg=0x45014880): messageId=0x0002bd7c, command=0x0
    @3868,222,881us: [+0 T:0x00020008] OP - doCmd> Enter (cmdId=3, proc=0x0)
    @3868,223,167us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Entered Sem_post> sem[0x23298]
    @3868,223,734us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Leaving Sem_post> sem[0x23298]
    @3868,223,987us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Entered Sem_pend> sem[0x232b0] timeout[0xffffffff]
    @3868,229,623us: [+0 T:0x00014006] ti.sdo.ce.osal.Sem - Leaving Sem_pend> sem[0x23298] status[0]
    @3868,229,918us: [+0 T:0x00014006] OP - getCmd_d> Exit (result=3)
    @3868,230,076us: [+0 T:0x00014006] ti.sdo.ce.osal.Sem - Entered Sem_post> sem[0x232b0]
    @3868,230,661us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Leaving Sem_pend> sem[0x232b0] status[0]
    @3868,230,873us: [+0 T:0x00020008] OP - doCmd> Exit (result=1)
    @3868,231,014us: [+0 T:0x00020008] OT - Thread_delete> Enter (task=0x23318)
    @3868,231,325us: [+4 T:0x00020008] OT - Thread_delete> pthread_cancel (0x0)
    @3868,231,798us: [+4 T:0x00020008] OT - Thread_delete> pthread_join (0x0)
    @3868,231,993us: [+0 T:0x00020008] OT - Thread_delete> Exit (task=0x23318)
    @3868,232,148us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Entered Sem_delete> sem[0x23298]
    @3868,232,362us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Leaving Sem_delete>
    @3868,232,515us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Entered Sem_delete> sem[0x232b0]
    @3868,232,679us: [+0 T:0x00020008] ti.sdo.ce.osal.Sem - Leaving Sem_delete>
    SoftDog: Unexpected close, not stopping watchdog!
    SoftDog: Initiating system reboot.

  • 0 in reply to V.Faul
    TI__Mastermind 18260 points

    There's not enough info here to determine much.  Please set CE_DEBUG=3 and attach the .txt file to your post (attach instead of inline paste).

    Regards,

    - Rob

  • 0 in reply to Robert Tivy
    Intellectual 885 points

    I have determined the root cause of the application crash. In my Linux app, I have a thread that continually calls system("ping ..."). It appears the system() call has a leak of some sort. This would explain why a gdb backtrace gives strange results after the crash. I replaced the system() call with a custom ping function and now the app no longer crashes. It also fixed a couple other weird problems that I was having.

    I wonder if BusyBox version 1.01 (which came with the ramdisk file) is part of the problem. I see that there are many fixes to the hush shell in newer versions. I have not yet tried a newer BusyBox version.

  • 0 in reply to V.Faul
    TI__Mastermind 18260 points

    Very interesting, thankyou for sharing that.

    Since BusyBox contains pared-down implementations of basic commands then it's quite possible that there's a bug in there somewhere.  I doubt that anyone with BusyBox knowledge would still be reading this particular thread, so you if you want to get the attention of the right people, I would suggest you start a new thread for that.

    Regards,

    - Rob