• State TI Thinks Resolved
  • Locked Locked
  • Replies 21 replies
  • Answers 1 answer
  • Subscribers 97 subscribers
  • Views 1235 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.

TDA4VM: detailed logs during TIDL model inference

Aleksandr Groznykh
Prodigy 31 points

Part Number: TDA4VM

Hello, please advise, how can I collect more detailed logs during a custom onnx model TIDL-accelerated inference on the development board?

Specifically, I have encountered 2 issues, where model inference works fine in the x86 docker container simulator (dockerfile is bundled with TIDL), but fails on the devboard:

1. inference fails with the following error message:

 

 91692.403482 s:  VX_ZONE_INIT:[tivxHostInitLocal:93] Initialization Done for HOST !!!

 91692.444839 s:  VX_ZONE_ERROR:[ownContextSendCmd:802] Command ack message returned failure cmd_status: -1

 91692.444869 s:  VX_ZONE_ERROR:[ownContextSendCmd:838] tivxEventWait() failed.

 91692.444903 s:  VX_ZONE_ERROR:[ownNodeKernelInit:525] Target kernel, TIVX_CMD_NODE_CREATE failed for node TIDLNode

 91692.444923 s:  VX_ZONE_ERROR:[ownNodeKernelInit:526] Please be sure the target callbacks have been registered for this core

 91692.444941 s:  VX_ZONE_ERROR:[ownNodeKernelInit:527] If the target callbacks have been registered, please ensure no errors are occurring within the create callback of this kernel

 91692.444959 s:  VX_ZONE_ERROR:[ownGraphNodeKernelInit:583] kernel init for node 0, kernel com.ti.tidl:1:1 ... failed !!!

 91692.444980 s:  VX_ZONE_ERROR:[vxVerifyGraph:2055] Node kernel init failed

 91692.444999 s:  VX_ZONE_ERROR:[vxVerifyGraph:2109] Graph verify failed

TIDL_RT_OVX: ERROR: Verifying TIDL graph ... Failed !!!

TIDL_RT_OVX: ERROR: Verify OpenVX graph failed

2. devboard hangs indefinitely with the following messages in log:


libtidl_onnxrt_EP loaded 0xd6b3350
Final number of subgraphs created are : 1, - Offloaded Nodes - 404, Total Nodes - 404
APP: Init ... !!!
MEM: Init ... !!!
MEM: Initialized DMA HEAP (fd=4) !!!
MEM: Init ... Done !!!
IPC: Init ... !!!
IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
953960.137830 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
953960.141201 s:  VX_ZONE_INIT:Enabled
953960.141213 s:  VX_ZONE_ERROR:Enabled
953960.141221 s:  VX_ZONE_WARNING:Enabled
953960.141965 s:  VX_ZONE_INIT:[tivxInitLocal:130] Initialization Done !!!
953960.142953 s:  VX_ZONE_INIT:[tivxHostInitLocal:93] Initialization Done for HOST !!!

(hangs)

 

Could you please advise on how I can extract more logs in order to understand and troubleshoot such errors?

(the above was tried with tidl_tools tags 08_06_00_02 and 08_06_00_03 on SDK versions 08_06_00_38 and 08_06_00_11 accordingly,

and changing `debug_level` compilation option in TIDL does not make a difference)

)

Regards,

Aleksandr

 

 

  • 0
    TI__Mastermind 24041 points

    Hi,

    Could you share complete error log as text file ? 

    How are you inferencing the model ? (gst apps flow or tidl tools ?)

    Please elaborate more on the your compilation flow, have you used benchmark repos or tidl tools or import tools from sdk ?

    On which SDK version you have compiled the model and which SDK version you are inferencing ?

    Could you verify the ARM only mode inference is running fine ?

    Please elaborate on which model you are using here (Custom model or standard supported model ?) please share the model in case.

    --

    Pratik

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Hello, thank you for the reply, half of your questions are already answered in the original post, but I'll re-iterate for you:

    Inference was tried with tidl_tools tags 08_06_00_02 and 08_06_00_03 on SDK versions 08_06_00_38 and 08_06_00_11 accordingly.

    I used https://github.com/TexasInstruments/edgeai-tidl-tools/ to compile and inference the model.

    ARM-only mode works fine. Running "accelerated" model in x86 Docker simulator also works fine.

    I'm using a custom onnx model, and can not share it on a public forum.

    I don't have original logs in the text file format, but all relevant log lines are in the original post.

    I'm mainly interested in learning how to obtain more logs from the devboard, and would be grateful if you provide some guidance on this.

    Thanks a lot!

    ----

    Aleksandr

  • 0 in reply to Aleksandr Groznykh
    TI__Mastermind 24041 points

    Hi,

    You can understand more about debug level flags from our official documentations.

    Complete console log of both model compilation and inference with  debug_level=1 and  debug_level=3

    Refer https://github.com/TexasInstruments/edgeai-tidl-tools/blob/master/docs/tidl_osr_debug.md

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Thank you for the reply, I did try those flags of course.
    As far as I understand, debug_level=3 is for generating binary traces during model inference.

    As you can see in the OP post, model is failing during the graph verification phase, so no traces are generated.

    Please elaborate further

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Thank you for the reply, I did collect those logs, but it is not obvious from them what the problem is. I'll attach the log file. Can you please tell, h

    Fullscreen libtidl_onnxrt_EP_vx.log Download 
    libtidl_onnxrt_EP loaded 0x229d3b10 
artifacts_folder                                = custom-artifacts/onnx/custom_new 
debug_level                                     = 2 
target_priority                                 = 0 
max_pre_empt_delay                              = 340282346638528859811704183484516925440.000000 
Final number of subgraphs created are : 1, - Offloaded Nodes - 404, Total Nodes - 404 
In TIDL_createStateInfer 
Compute on node : TIDLExecutionProvider_TIDL_0_0
************ in TIDL_subgraphRtCreate ************ 
 APP: Init ... !!!
MEM: Init ... !!!
MEM: Initialized DMA HEAP (fd=5) !!!
MEM: Init ... Done !!!
IPC: Init ... !!!
IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
 75598.445775 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
 75598.446876 s:  VX_ZONE_INIT:Enabled
 75598.446892 s:  VX_ZONE_ERROR:Enabled
 75598.446898 s:  VX_ZONE_WARNING:Enabled
 75598.447594 s:  VX_ZONE_INIT:[tivxInitLocal:130] Initialization Done !!!
 75598.447743 s:  VX_ZONE_INIT:[tivxHostInitLocal:96] Initialization Done for HOST !!!
[C7x_1 ]  75598.552280 s: PREEMPTION: Requesting memory of size 57344 for targetPriority = 512
[C7x_1 ]  75598.552305 s: 
[C7x_1 ]  75598.552323 s: --------------------------------------------
[C7x_1 ]  75598.552348 s: TIDL Memory size requiement (record wise):
[C7x_1 ]  75598.552377 s: MemRecNum   , Space       , Attribute   , Size(KBytes) 
[C7x_1 ]  75598.552410 s: 0           , DDR Cacheable, Persistent  , 15.18    
[C7x_1 ]  75598.552440 s: 1           , DDR Cacheable, Persistent  , 0.63     
[C7x_1 ]  75598.552470 s: 2           , L1D         , Scratch     , 16.00    
[C7x_1 ]  75598.552499 s: 3           , L2          , Scratch     , 4.00     
[C7x_1 ]  75598.552528 s: 4           , L3/MSMC     , Scratch     , 56.00    
[C7x_1 ]  75598.552557 s: 5           , DDR Cacheable, Persistent  , 1165.82  
[C7x_1 ]  75598.552587 s: 6           , DDR Cacheable, Scratch     , 23964.70 
[C7x_1 ]  75598.552616 s: 7           , DDR Cacheable, Persistent  , 0.13     
[C7x_1 ]  75598.552644 s: 8           , DDR Cacheable, Scratch     , 0.13     
[C7x_1 ]  75598.552673 s: 9           , DDR Cacheable, Scratch     , 3.13     
[C7x_1 ]  75598.552708 s: 10          , DDR Cacheable, Persistent  , 3186.63  
[C7x_1 ]  75598.552740 s: 11          , DDR Cacheable, Scratch     , 512.25   
[C7x_1 ]  75598.552770 s: 12          , DDR Cacheable, Persistent  , 56.00    
[C7x_1 ]  75598.552799 s: 13          , DDR Cacheable, Persistent  , 3446.53  
[C7x_1 ]  75598.552828 s: 14          , DDR Cacheable, Persistent  , 0.13     
[C7x_1 ]  75598.552853 s: --------------------------------------------
[C7x_1 ]  75598.552876 s: Total memory size requirement (space wise):
[C7x_1 ]  75598.552895 s: Mem Space , Size(KBytes)
[C7x_1 ]  75598.552911 s: L1D       , 16.00   
[C7x_1 ]  75598.552928 s: L2        , 4.00    
[C7x_1 ]  75598.552944 s: L3/MSMC   , 56.00   
[C7x_1 ]  75598.552961 s: DDR Cacheable, 32351.24
[C7x_1 ]  75598.552983 s: --------------------------------------------
[C7x_1 ]  75598.553017 s: NOTE: Memory requirement in host emulation can be different from the same on EVM
[C7x_1 ]  75598.553055 s:       To get the actual TIDL memory requirement make sure to run on EVM with 
[C7x_1 ]  75598.553077 s:       debugTraceLevel = 2
[C7x_1 ]  75598.553086 s: 
[C7x_1 ]  75598.553105 s: --------------------------------------------
[C7x_1 ]  75598.553219 s: TIDL init call from ivision API 
[C7x_1 ]  75598.553333 s:  VX_ZONE_ERROR:[tivxAlgiVisionCreate:335] Calling ialg.algInit failed with status = -1111
[C7x_1 ]  75598.553386 s: Error: handle (11ee33000) doesn't exist in priority table
[C7x_1 ]  75598.553413 s:  VX_ZONE_ERROR:[tivxKernelTIDLCreate:813] tivxAlgiVisionCreate returned NULL
 75598.555437 s:  VX_ZONE_ERROR:[ownContextSendCmd:822] Command ack message returned failure cmd_status: -1
 75598.555490 s:  VX_ZONE_ERROR:[ownContextSendCmd:862] tivxEventWait() failed.
 75598.555534 s:  VX_ZONE_ERROR:[ownNodeKernelInit:527] Target kernel, TIVX_CMD_NODE_CREATE failed for node TIDLNode
 75598.555579 s:  VX_ZONE_ERROR:[ownNodeKernelInit:528] Please be sure the target callbacks have been registered for this core
 75598.555621 s:  VX_ZONE_ERROR:[ownNodeKernelInit:529] If the target callbacks have been registered, please ensure no errors are occurring within the create callback of this kernel
 75598.555666 s:  VX_ZONE_ERROR:[ownGraphNodeKernelInit:583] kernel init for node 0, kernel com.ti.tidl:1:2 ... failed !!!
 75598.555718 s:  VX_ZONE_ERROR:[vxVerifyGraph:2055] Node kernel init failed
 75598.555794 s:  VX_ZONE_ERROR:[vxVerifyGraph:2109] Graph verify failed
TIDL_RT_OVX: ERROR: Verifying TIDL graph ... Failed !!!
TIDL_RT_OVX: ERROR: Verify OpenVX graph failed
************ TIDL_subgraphRtCreate done ************ 
RUN
 *******   In TIDL_subgraphRtInvoke  ******** 
 75598.691380 s:  VX_ZONE_ERROR:[ownContextSendCmd:822] Command ack message returned failure cmd_status: -1
 75598.691409 s:  VX_ZONE_ERROR:[ownContextSendCmd:862] tivxEventWait() failed.
 75598.691421 s:  VX_ZONE_ERROR:[ownNodeKernelInit:527] Target kernel, TIVX_CMD_NODE_CREATE failed for node TIDLNode
 75598.691431 s:  VX_ZONE_ERROR:[ownNodeKernelInit:528] Please be sure the target callbacks have been registered for this core
 75598.691439 s:  VX_ZONE_ERROR:[ownNodeKernelInit:529] If the target callbacks have been registered, please ensure no errors are occurring within the create callback of this kernel
 75598.691450 s:  VX_ZONE_ERROR:[ownGraphNodeKernelInit:583] kernel init for node 0, kernel com.ti.tidl:1:2 ... failed !!!
 75598.691464 s:  VX_ZONE_ERROR:[vxVerifyGraph:2055] Node kernel init failed
 75598.691472 s:  VX_ZONE_ERROR:[vxVerifyGraph:2109] Graph verify failed
 75598.691611 s:  VX_ZONE_ERROR:[ownGraphScheduleGraphWrapper:799] graph is not in a state required to be scheduled
 75598.691620 s:  VX_ZONE_ERROR:[vxProcessGraph:734] schedule graph failed
 75598.691628 s:  VX_ZONE_ERROR:[vxProcessGraph:739] wait graph failed
ERROR: Running TIDL graph ... Failed !!!
Sub Graph Stats 2455.000000 59427.000000 18446744073709528.000000 
*******  TIDL_subgraphRtInvoke done  ******** 
[C7x_1 ]  75598.689750 s: PREEMPTION: Requesting memory of size 57344 for targetPriority = 512
[C7x_1 ]  75598.689774 s: 
[C7x_1 ]  75598.689792 s: --------------------------------------------
[C7x_1 ]  75598.689815 s: TIDL Memory size requiement (record wise):
[C7x_1 ]  75598.689844 s: MemRecNum   , Space       , Attribute   , Size(KBytes) 
[C7x_1 ]  75598.689876 s: 0           , DDR Cacheable, Persistent  , 15.18    
[C7x_1 ]  75598.689906 s: 1           , DDR Cacheable, Persistent  , 0.63     
[C7x_1 ]  75598.689936 s: 2           , L1D         , Scratch     , 16.00    
[C7x_1 ]  75598.689966 s: 3           , L2          , Scratch     , 4.00     
[C7x_1 ]  75598.689994 s: 4           , L3/MSMC     , Scratch     , 56.00    
[C7x_1 ]  75598.690024 s: 5           , DDR Cacheable, Persistent  , 1165.82  
[C7x_1 ]  75598.690053 s: 6           , DDR Cacheable, Scratch     , 23964.70 
[C7x_1 ]  75598.690082 s: 7           , DDR Cacheable, Persistent  , 0.13     
[C7x_1 ]  75598.690110 s: 8           , DDR Cacheable, Scratch     , 0.13     
[C7x_1 ]  75598.690139 s: 9           , DDR Cacheable, Scratch     , 3.13     
[C7x_1 ]  75598.690169 s: 10          , DDR Cacheable, Persistent  , 3186.63  
[C7x_1 ]  75598.690198 s: 11          , DDR Cacheable, Scratch     , 512.25   
[C7x_1 ]  75598.690227 s: 12          , DDR Cacheable, Persistent  , 56.00    
[C7x_1 ]  75598.690255 s: 13          , DDR Cacheable, Persistent  , 3446.53  
[C7x_1 ]  75598.690284 s: 14          , DDR Cacheable, Persistent  , 0.13     
[C7x_1 ]  75598.690309 s: --------------------------------------------
[C7x_1 ]  75598.690333 s: Total memory size requirement (space wise):
[C7x_1 ]  75598.690351 s: Mem Space , Size(KBytes)
[C7x_1 ]  75598.690367 s: L1D       , 16.00   
[C7x_1 ]  75598.690383 s: L2        , 4.00    
[C7x_1 ]  75598.690398 s: L3/MSMC   , 56.00   
[C7x_1 ]  75598.690415 s: DDR Cacheable, 32351.24
[C7x_1 ]  75598.690437 s: --------------------------------------------
[C7x_1 ]  75598.690471 s: NOTE: Memory requirement in host emulation can be different from the same on EVM
[C7x_1 ]  75598.690508 s:       To get the actual TIDL memory requirement make sure to run on EVM with 
[C7x_1 ]  75598.690530 s:       debugTraceLevel = 2
[C7x_1 ]  75598.690539 s: 
[C7x_1 ]  75598.690558 s: --------------------------------------------
[C7x_1 ]  75598.690671 s: TIDL init call from ivision API 
[C7x_1 ]  75598.690778 s:  VX_ZONE_ERROR:[tivxAlgiVisionCreate:335] Calling ialg.algInit failed with status = -1111
[C7x_1 ]  75598.690829 s: Error: handle (11f5e3800) doesn't exist in priority table
[C7x_1 ]  75598.690855 s:  VX_ZONE_ERROR:[tivxKernelTIDLCreate:813] tivxAlgiVisionCreate returned NULL
    ow to debug it further?

    --
    Aleksandr

  • 0 in reply to Aleksandr Groznykh
    TI__Mastermind 24041 points

    Can you share, on which sdk version you have compiled model and on sdk version you are doing inference ?

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Hello, you have already asked this, and it is answered twice in this thread (in OP post and in comments).

    I'll copy-paste the answer for you:

    Inference was tried with tidl_tools tags 08_06_00_02 and 08_06_00_03 on SDK versions 08_06_00_38 and 08_06_00_11 accordingly.

    I kindly request another engineer to look at this thread, if possible.

    PS since then it was also tried on the new version 09_00_00_06 on Processor SDK LINUX 09.00.00.08

    --

    Alex

  • 0 in reply to Aleksandr Groznykh
    Prodigy 151 points

    export TIDL_RT_DEBUG=3

    I just saw your question while searching for my own issue, did you give this export flag a try?

  • 0 in reply to Abdulkadir Beytorun
    Prodigy 31 points

    Hello, thanks for reply!


    If this env variable that you've mentioned does the same thing as debug_level = 3, flag in tidl.TIDLCompiler, then yes.
    As far as I understand, debug_level=3 generates layer level fixed point traces during execution. But in my case (1), the model fails during Verifying TIDL graph stage.

  • 0 in reply to Aleksandr Groznykh
    Prodigy 151 points

    To be honest I am not sure if they do exactly the same thing, it is not very well documented.

    I just had some issues with my model as well and recently solved them. I would suggest converting your models to tidl through dlr and you will have more flexibility on solving your issue. For example in my case I identified the issue by moving some layers from tidl to tvm during conversion, then did experiments for each case until I found the issue.
    TIDL is unfortunately quite buggy and not well documented, but this tvm wrapper gives flexibility to us at least.

  • 0 in reply to Abdulkadir Beytorun
    Prodigy 31 points

    Thanks, that is exactly what I'm going to do!

  • 0 in reply to Aleksandr Groznykh
    TI__Mastermind 24041 points

    Hi,

    From the arm remote core log shared by you above, it seems like there is issue in TIDL_DATA_FLOW, as the TIDL_E_DATAFLOW_INFO_NULL flag is being set.

    Reference : [C7x_1 ]  75598.553333 s:  VX_ZONE_ERROR:[tivxAlgiVisionCreate:335] Calling ialg.algInit failed with status = -1111 (line 59)

    This seems to be issue from model compiler side, could you share you model compilation log with us ?

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Hello, thank you for the reply! The full compilation log is in the attachment.

    lines_and_boundaires_compile.log

  • 0 in reply to Aleksandr Groznykh
    TI__Mastermind 24041 points

    Hi,

    From the logs its seems like the custom model you are tying to compile has most of the layers which are not supported from TIDL side.

    Furthermore, there are layers whose dimensions greater than 4, as result the numbers are subgraphs created are more in number, from the error logs it appears that the issue is in one specific graph.

    From out side we have not validated the TIDL overall layer support on OSRT with dims > 4, and don't claim the same until its been validated from our side.

    For the current situation we recommend to look into our model zoo models, which has validated examples in it.

    https://github.com/TexasInstruments/edgeai-modelzoo

    Is it possible to share internals of model architecture in this forum ? 

    Disclaimer : Please note that this is public forum.

    --

    Pratik

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Please disregard the previous log, here is the correct log: 0880.lines_and_boundaires_compile.log

    The model I'm working with was already shared on this forum, in this topic: https://e2e.ti.com/support/processors-group/processors/f/processors-forum/1257415/tda4vm-err_mmeory_overlap

  • 0 in reply to Aleksandr Groznykh
    TI__Mastermind 24041 points

    Sure,

    I will have to check this with our TIDL experts.

    I will get back to you on this.

  • 0 in reply to Pratik Kedar
    TI__Mastermind 24041 points

    Hi,

    After RCA we have found that there are few issues from model compiler side.

    I have file the JIRA to address this issue as fix.

    Adding JIRA link for TI's internal tracking purpose.

    https://jira.itg.ti.com/browse/TIDL-3600

  • 0 in reply to Pratik Kedar
    Prodigy 31 points

    Hello, thank you.

    Unfortunately I cannot view the JIRA link. Is there a workaround, or an estimate when this will be resolved?

    ----

    Regards,
    Aleksandr

  • 0 in reply to Aleksandr Groznykh
    TI__Mastermind 24041 points

    Hi,

    This issue has been raised, i will get back to you on tentative fix timeline.

  • 0 in reply to Pratik Kedar
    TI__Mastermind 24041 points

    Hi,

    This fix will be available as part of our 9.1 SDK release tentatively. 

    Closing the thread.