AM62A7: Streaming issue using SDK-11 component for Custom board

Hi Jay, 

Has there been any change to the memory map or firmwares for the remote cores (Mcu1_0, which runs VPAC/ISP and C7x_1, which runs deep learning acceleration)?

This carveout for the core-heaps of each of these remote cores is much smaller than what we use in the SDK, and is my first cause for concern

Yours:
[    0.000000] OF: reserved mem: 0x00000000adc00000..0x00000000b27fffff (77824 KiB) nomap non-reusable edgeai-core-heap-memory@adc00000


TI SDK: 
[    0.000000] OF: reserved mem: 0x00000000adc00000..0x00000000bfffffff (299008 KiB) nomap non-reusable edgeai-core-heap-memory@adc00000

logs for media-ctl, tiovxisp-pipeline, remote-core look fine. This is strange, given the hang you experience.  

For your Yocto build, did you start from an 11.1 baseline and add your custom layers from there? I'm curious if there can be some build artifact or conflicting version hanging around from past. 

While your program is hung, I am curious if dma buffers have been allocated from the edgeai_shared-memories aka DDR_SHARED_MEM. Can you `cat /sys/kernel/debug/dma_buf/bufinfo` and share the log while this program is hanging?

BR,
Reese

Hi Reese,

Thank you for your reply.

Reese Grimsley said:

This carveout for the core-heaps of each of these remote cores is much smaller than what we use in the SDK, and is my first cause for concern

We have tried to use the "edgeai-core-heap" same as SDK-11 EVM 304MiB. But in that as well, we have the same issue.

When stream hung up, below is the output of file "/sys/kernel/debug/dma_buf/bufinfo":

~ # cat /sys/kernel/debug/dma_buf/bufinfo

Dma-buf Objects:
size            flags           mode            count           exp_name        ino             name
03457024        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000025        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

03457024        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000024        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00028672        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000023        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00004096        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000022        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00012288        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000018        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00057344        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000017        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00057344        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000016        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00036864        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000015        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00004096        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000014        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00004096        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000013        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00212992        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000012        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00004096        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000011        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00008192        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000010        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00016384        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000008        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

00004096        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000007        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

04608000        00000002        00080007        00000004        carveout_edgeai_shared-memories 00000006        <none>
        Attached Devices:
        4e230000.dma-controller
        remoteproc0
Total 2 devices attached

04608000        00000002        00080007        00000004        carveout_edgeai_shared-memories 00000005        <none>
        Attached Devices:
        4e230000.dma-controller
        remoteproc0
Total 2 devices attached

04608000        00000002        00080007        00000004        carveout_edgeai_shared-memories 00000004        <none>
        Attached Devices:
        4e230000.dma-controller
        remoteproc0
Total 2 devices attached

04608000        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000003        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

04608000        00000002        00080007        00000003        carveout_edgeai_shared-memories 00000002        <none>
        Attached Devices:
        remoteproc0
Total 1 devices attached

04608000        00000002        00080007        00000004        carveout_edgeai_shared-memories 00000001        <none>
        Attached Devices:
        4e230000.dma-controller
        remoteproc0
Total 2 devices attached


Total 21 objects, 35012608 bytes

Reese Grimsley said:

For your Yocto build, did you start from an 11.1 baseline and add your custom layers from there? I'm curious if there can be some build artifact or conflicting version hanging around from past. 

Yes, We have started with sdk-11 and added minimum packages from SDK-11 for streaming. 

Let us know any other information required.

Regards,
Jay

Hi Jay,

The bufinfo logs look fine. They have clearly allocated the data needed (happens in TIOVX portions under the hood)

Jay Kaneria said:

We have tried to use the "edgeai-core-heap" same as SDK-11 EVM 304MiB. But in that as well, we have the same issue.

So this means you have tried the same pipeline with your yocto build with the default memory map and still observe the same issue?

Has the same pipeline worked in your past builds? In a stock 11.1 SDK version? I am trying to find out what minimal changes lead to this issue you observe. I am wondering if anything related to the interface between v4l2 to TIOVX is an issue, or TIOVX overall.

• I haven't seen logs that indicate obvious TIOVX failure, so I'm expecting an issue somewhere near that interface. 

Can you run an example pipeline with other TIOVX plugins, like tiovxmultiscaler? You can use a videotestsrc or decode from an image file.  

I also notice you have one pipeline set to run at 30 FPS and the other at 60. Probably a small detail, but worth confirming that doesn't impact this behavior

Hi Reese, 

Reese Grimsley said:

So this means you have tried the same pipeline with your yocto build with the default memory map and still observe the same issue?

Yes, with default memory map, still observe the issue.

Reese Grimsley said:

Has the same pipeline worked in your past builds? In a stock 11.1 SDK version?

With stock 11.01.07 SDK version, pipeline is working fine without any issue.

Reese Grimsley said:

Can you run an example pipeline with other TIOVX plugins, like tiovxmultiscaler?

We have tried to use the multiscaler plugin with videotestsrc  and working properly. pipeline is as below:

gst-launch-1.0 videotestsrc ! video/x-raw,width=1920,height=1200 !  tiovxmultiscaler ! video/x-raw, format=NV12, width=640, height=380, framerate=30/1 ! fakesink

Same way, we have tried with the tiovxisp pipeline with videotestsrc and in that, we are seeing same hang issue. pipeline is as below:

gst-launch-1.0 videotestsrc ! video/x-bayer,width=1920,height=1200, format=rggb ! tiovxisp sensor-name=SENSOR_SONY_IMX219_RPI dcc-isp-file=/opt/imaging/imx219/linear/dcc_viss_1920x1080.bin sink_0::dcc-2a-file=/opt/imaging/imx219/linear/dcc_2a_1920x1080.bin sink_0::device=/dev/v4l-subdev2 ! video/x-raw,format=NV12 ! fakesink

Reese Grimsley said:

I also notice you have one pipeline set to run at 30 FPS and the other at 60. Probably a small detail, but worth confirming that doesn't impact this behavior

Yes, we have tried changing the fps (30fps and 60fps) but that didn't work as well.

we have noticed one issue when we execute the pipeline. Device creates 4 new /dev/rpmsgX character device whenever we run the pipeline and character devices still exist even after stopping pipeline. So, Every time 4 new /dev/rpmsgX devices are created when pipeline is executed on board. 

Our build setup:

U-boot(tiboot3.bin, tispl.bin, u-boot.img), linux kernel (linux-ti-staging-rt), entire "/lib/firmware" binaries and "meta-edgeai" layer are from SDK-11 and there is no change in this.

We are using the custom rootfs packages and those are not from SDK-11.

---------------------------------------------------------------------------------------------------

Can you provide us steps to debug the ISP (tiovxisp)? So, we can check from where streaming pipeline can be breaking.

Regards,
Jay

That's useful information, thanks Jay. 

The fact that multiscaler is working tells me TIOVX and the overall communication to that core running MSC (and VISS (ISP)... and LDC) is working. I wonder if there is any AEWB or similar feedback to the sensor that might not be working correctly. There is no activity in dmesg logs, right? I didn't see anything in what you originally sent, but the log looks like it cutoff after you finished botting. Can you please add dmesg log that starts when you start your application / pipeline?

Jay Kaneria said:

Our build setup:

U-boot(tiboot3.bin, tispl.bin, u-boot.img), linux kernel (linux-ti-staging-rt), entire "/lib/firmware" binaries and "meta-edgeai" layer are from SDK-11 and there is no change in this.

If there is no memory map change, then this should be fine. Please be certain you are pulling in /lib/firmware and other changes for SDK 11.1. There is no 11.0 or 11.2, so this may be a moot point. Are you grabbing these manually from the SDK or is it happening within the yocto build?

Jay Kaneria said:

Can you provide us steps to debug the ISP (tiovxisp)? So, we can check from where streaming pipeline can be breaking.

Give me a day or two to provide a recommendation. Perhaps the pipeline with GST_DEBUG set to logging INFO for all plugins would be informative, but i havne't seen much from tiovxisp that tells the issue.

Hi Reese,

Reese Grimsley said:

There is no activity in dmesg logs, right? I didn't see anything in what you originally sent, but the log looks like it cutoff after you finished botting. Can you please add dmesg log that starts when you start your application / pipeline?

Yes, there is no dmesg logs when we run the pipeline. Only the streaming start and streaming stop logs from the camera sensor driver that we enabled for debugging.

~ # [  199.101978] ar0235 2-0036: width - 1920, height - 1200
[  199.101995] ar0235 2-0036: width - 1920, height - 5
[  199.103237] ar0235 2-0036: In ar0235_sd_enable_streams
[  199.349560] ar0235 2-0036: CIT value = 1498
[  199.352037] ar0235 2-0036: out ar0235_sd_enable_streams

~ #
~ #
~ # [  221.147829] ar0235 2-0036: In ar0235_sd_disable_streams
[  221.348130] ar0235 2-0036: Out ar0235_sd_disable_streams

So, when streaming start, sensor's start stream api gets called and when I hit CTRL + C, sensor's stop stream api are called as well.

Reese Grimsley said:

Are you grabbing these manually from the SDK or is it happening within the yocto build?

Currently we are grabbing it manually from already build stock SDK-11.01.07 yocto SDK. We will create/add the necessary recipes once this issue is solved. I am guessing there main three firmware we are used and it doesn't associate with other package at build time. Is my understanding correct? 

wave521c_k3_codec_fw.bin  => JPEG encoder firmware

 am62a-c71_0-fw => C7x DSP firmware

am62a-mcu-r5f0_0-fw => MCU R5F firmware (application layer)

Reese Grimsley said:

Give me a day or two to provide a recommendation. Perhaps the pipeline with GST_DEBUG set to logging INFO for all plugins would be informative, but i havne't seen much from tiovxisp that tells the issue.

I have set logging  to INFO for all plugins and capture the logs. We didn't see any obvious failure but let us know if there is any failure which could be the cause.

GST_DEBUG=4 gst-launch-1.0 -v v4l2src device=/dev/video2 io-mode=dmabuf-import ! video/x-bayer, width=1920, height=1200, framerate=60/1, format=rggb10 ! tiovxisp sink
_0::device=/dev/v4l-subdev2 dcc-isp-file=/opt/imaging/ar0235/dcc_viss_10bit_1920x1200.bin sink_0::dcc-2a-file=/opt/imaging/ar0235/dcc_2a_10bit_1920x1200.bin format-msb=9
sink_0::ae-mode=2 ! video/x-raw, format=NV12, width=1920, height=1200, framerate=60/1 ! fakesink sync=false
0:00:00.000429290  1190     0x35a6aa00 INFO                GST_INIT gst.c:576:init_pre: Initializing GStreamer Core Library version 1.22.0
0:00:00.000547800  1190     0x35a6aa00 INFO                GST_INIT gst.c:577:init_pre: Using library installed in /usr/lib
0:00:00.000598635  1190     0x35a6aa00 INFO                GST_INIT gst.c:595:init_pre: Linux am62ax 6.12.35-00947-gb990e18ef092-dirty #1 SMP PREEMPT_RT Tue Jul 22 20:20:40 UTC 2025 aarch64
0:00:00.001475250  1190     0x35a6aa00 INFO                GST_INIT gstmessage.c:129:_priv_gst_message_initialize: init messages
0:00:00.002996595  1190     0x35a6aa00 INFO                GST_INIT gstcontext.c:86:_priv_gst_context_initialize: init contexts
0:00:00.003687025  1190     0x35a6aa00 INFO      GST_PLUGIN_LOADING gstplugin.c:324:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.004058530  1190     0x35a6aa00 INFO      GST_PLUGIN_LOADING gstplugin.c:232:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.004110955  1190     0x35a6aa00 INFO      GST_PLUGIN_LOADING gstplugin.c:234:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.004299030  1190     0x35a6aa00 INFO            GST_REGISTRY gstregistry.c:1836:ensure_current_registry: reading registry cache: /home/root/.cache/gstreamer-1.0/registry.aarch64.bin
0:00:00.030890425  1190     0x35a6aa00 INFO            GST_REGISTRY gstregistrybinary.c:683:priv_gst_registry_binary_read_cache: loaded /home/root/.cache/gstreamer-1.0/registry.aarch64.bin in 0.026392 seconds
0:00:00.031150530  1190     0x35a6aa00 INFO            GST_REGISTRY gstregistry.c:1703:scan_and_update_registry: Validating plugins from registry cache: /home/root/.cache/gstreamer-1.0/registry.aarch64.bin
0:00:00.040811645  1190     0x35a6aa00 INFO            GST_REGISTRY gstregistry.c:1795:scan_and_update_registry: Registry cache has not changed
0:00:00.040892795  1190     0x35a6aa00 INFO            GST_REGISTRY gstregistry.c:1871:ensure_current_registry: registry reading and updating done
0:00:00.040940155  1190     0x35a6aa00 INFO                GST_INIT gst.c:805:init_post: GLib runtime version: 2.74.6
0:00:00.040970705  1190     0x35a6aa00 INFO                GST_INIT gst.c:807:init_post: GLib headers version: 2.74.6
0:00:00.040993245  1190     0x35a6aa00 INFO                GST_INIT gst.c:809:init_post: initialized GStreamer successfully
0:00:00.041178835  1190     0x35a6aa00 INFO            GST_PIPELINE gstparse.c:344:gst_parse_launch_full: parsing pipeline description 'v4l2src device=/dev/video2 io-mode=dmabuf-import ! video/x-bayer, width=1920, height=1200, framerate=60/1, format=rggb10 ! tiovxisp sink_0::device=/dev/v4l-subdev2 dcc-isp-file=/opt/imaging/ar0235/dcc_viss_10bit_1920x1200.bin sink_0::dcc-2a-file=/opt/imaging/ar0235/dcc_2a_10bit_1920x1200.bin format-msb=9 sink_0::ae-mode=2 ! video/x-raw, format=NV12, width=1920, height=1200, framerate=60/1 ! fakesink sync=false '
0:00:00.054233620  1190     0x35a6aa00 INFO      GST_PLUGIN_LOADING gstplugin.c:987:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/gstreamer-1.0/libgstvideo4linux2.so" loaded
0:00:00.060220600  1190     0x35a6aa00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "v4l2src"
0:00:00.060439715  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseSrc@0x35b51b60> adding pad 'src'
0:00:00.090936195  1190     0x35a6aa00 INFO      GST_PLUGIN_LOADING gstplugin.c:987:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/gstreamer-1.0/libgsttiovx.so" loaded
0:00:00.091716830  1190     0x35a6aa00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "tiovxisp"
0:00:00.091910990  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstAggregator@0x35c19160> adding pad 'src'
0:00:00.092003440  1190     0x35a6aa00 INFO            tiovxcontext gsttiovxcontext.c:141:gst_tiovx_context_init: Calling appInit() from GST!
APP: Init ... !!!
  1647.747886 s: MEM: Init ... !!!
  1647.747936 s: MEM: Initialized DMA HEAP (fd=5) !!!
  1647.748069 s: MEM: Init ... Done !!!
  1647.748090 s: IPC: Init ... !!!
  1647.768015 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
  1647.772586 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
  1647.772842 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
  1647.772883 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
  1647.772894 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
  1647.773574 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-0
  1647.773814 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-1
  1647.773964 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-2
  1647.774073 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-3
  1647.774143 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initialization Done !!!
  1647.774164 s:  VX_ZONE_INFO: Globally Disabled VX_ZONE_INFO
0:00:00.121149365  1190     0x35a6aa00 INFO          tiovxallocator gsttiovxallocator.c:128:gst_tiovx_allocator_init:<GstTIOVXAllocator@0x35bbab50> New TIOVX allocator
0:00:00.121361800  1190     0x35a6aa00 INFO                 default gstchildproxy.c:281:gst_child_proxy_lookup: Looking for property ae-mode in sink_0
0:00:00.121447900  1190     0x35a6aa00 INFO                 default gstchildproxy.c:108:gst_child_proxy_get_child_by_name_recurse: Unable to find child sink_0
0:00:00.121477550  1190     0x35a6aa00 INFO                 default gstchildproxy.c:287:gst_child_proxy_lookup: Child not found
0:00:00.121513260  1190     0x35a6aa00 INFO                 default gstchildproxy.c:108:gst_child_proxy_get_child_by_name_recurse: Unable to find child sink_0
0:00:00.121591145  1190     0x35a6aa00 INFO                 default gstchildproxy.c:281:gst_child_proxy_lookup: Looking for property dcc-2a-file in sink_0
0:00:00.121629385  1190     0x35a6aa00 INFO                 default gstchildproxy.c:108:gst_child_proxy_get_child_by_name_recurse: Unable to find child sink_0
0:00:00.121699620  1190     0x35a6aa00 INFO                 default gstchildproxy.c:287:gst_child_proxy_lookup: Child not found
0:00:00.121741030  1190     0x35a6aa00 INFO                 default gstchildproxy.c:108:gst_child_proxy_get_child_by_name_recurse: Unable to find child sink_0
0:00:00.121791990  1190     0x35a6aa00 INFO                 default gstchildproxy.c:281:gst_child_proxy_lookup: Looking for property device in sink_0
0:00:00.121820130  1190     0x35a6aa00 INFO                 default gstchildproxy.c:108:gst_child_proxy_get_child_by_name_recurse: Unable to find child sink_0
0:00:00.121839440  1190     0x35a6aa00 INFO                 default gstchildproxy.c:287:gst_child_proxy_lookup: Child not found
0:00:00.121865925  1190     0x35a6aa00 INFO                 default gstchildproxy.c:108:gst_child_proxy_get_child_by_name_recurse: Unable to find child sink_0
0:00:00.124695120  1190     0x35a6aa00 INFO      GST_PLUGIN_LOADING gstplugin.c:987:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:00.125898210  1190     0x35a6aa00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "fakesink"
0:00:00.126045155  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseSink@0x35c217a0> adding pad 'sink'
0:00:00.126164440  1190     0x35a6aa00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "pipeline"
0:00:00.126719855  1190     0x35a6aa00 INFO            GST_PIPELINE grammar.y:996:gst_parse_perform_link: linking some pad of GstV4l2Src named v4l2src0 to some pad of GstTIOVXISP named tiovxisp0 (0/0) with caps "video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10"
0:00:00.126793350  1190     0x35a6aa00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "capsfilter"
0:00:00.127140610  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseTransform@0x35c26140> adding pad 'sink'
0:00:00.127210900  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseTransform@0x35c26140> adding pad 'src'
0:00:00.127279760  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2069:gst_bin_get_state_func:<pipeline0> getting state
0:00:00.127455435  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter0> completed state change to NULL
0:00:00.127536205  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.127596670  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstutils.c:1816:gst_element_link_pads_full: trying to link element v4l2src0:(any) to element capsfilter0:sink
0:00:00.127637670  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:1016:gst_element_get_static_pad: found pad capsfilter0:sink
0:00:00.127670450  1190     0x35a6aa00 INFO                GST_PADS gstutils.c:1632:prepare_link_maybe_ghosting: v4l2src0 and capsfilter0 in same bin, no need for ghost pads
0:00:00.127730685  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2387:gst_pad_link_prepare: trying to link v4l2src0:src and capsfilter0:sink
0:00:00.127791095  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:4367:gst_pad_peer_query:<capsfilter0:src> pad has no peer
0:00:00.127868370  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2595:gst_pad_link_full: linked v4l2src0:src and capsfilter0:sink, successful
0:00:00.127896450  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.127924035  1190     0x35a6aa00 INFO               GST_EVENT gstpad.c:5985:gst_pad_send_event_unchecked:<v4l2src0:src> Received event on flushing pad. Discarding
0:00:00.127985850  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstutils.c:1816:gst_element_link_pads_full: trying to link element capsfilter0:src to element tiovxisp0:(any)
0:00:00.128013335  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:1016:gst_element_get_static_pad: found pad capsfilter0:src
0:00:00.128419300  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<tiovxisp0> adding pad 'sink_0'
0:00:00.128514500  1190     0x35a6aa00 INFO                 default gstchildproxy.c:281:gst_child_proxy_lookup: Looking for property ae-mode in sink_0
0:00:00.128652875  1190     0x35a6aa00 INFO                 default gstchildproxy.c:281:gst_child_proxy_lookup: Looking for property dcc-2a-file in sink_0
0:00:00.128733960  1190     0x35a6aa00 INFO                 default gstchildproxy.c:281:gst_child_proxy_lookup: Looking for property device in sink_0
0:00:00.128825930  1190     0x35a6aa00 INFO                GST_PADS gstutils.c:1632:prepare_link_maybe_ghosting: capsfilter0 and tiovxisp0 in same bin, no need for ghost pads
0:00:00.128892990  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2387:gst_pad_link_prepare: trying to link capsfilter0:src and tiovxisp0:sink_0
0:00:00.129027505  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2595:gst_pad_link_full: linked capsfilter0:src and tiovxisp0:sink_0, successful
0:00:00.129058035  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.129088235  1190     0x35a6aa00 INFO               GST_EVENT gstpad.c:5985:gst_pad_send_event_unchecked:<capsfilter0:src> Received event on flushing pad. Discarding
0:00:00.129201830  1190     0x35a6aa00 INFO            GST_PIPELINE grammar.y:996:gst_parse_perform_link: linking some pad of GstTIOVXISP named tiovxisp0 to some pad of GstFakeSink named fakesink0 (0/0) with caps "video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1"
0:00:00.129249380  1190     0x35a6aa00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "capsfilter"
0:00:00.129375740  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseTransform@0x35c26480> adding pad 'sink'
0:00:00.129447660  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseTransform@0x35c26480> adding pad 'src'
0:00:00.129503435  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2069:gst_bin_get_state_func:<pipeline0> getting state
0:00:00.129600495  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter1> completed state change to NULL
0:00:00.129649885  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.129699865  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstutils.c:1816:gst_element_link_pads_full: trying to link element tiovxisp0:(any) to element capsfilter1:sink
0:00:00.129733730  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:1016:gst_element_get_static_pad: found pad capsfilter1:sink
0:00:00.129766320  1190     0x35a6aa00 INFO                GST_PADS gstutils.c:1632:prepare_link_maybe_ghosting: tiovxisp0 and capsfilter1 in same bin, no need for ghost pads
0:00:00.129823355  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2387:gst_pad_link_prepare: trying to link tiovxisp0:src and capsfilter1:sink
0:00:00.129881290  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:4367:gst_pad_peer_query:<capsfilter1:src> pad has no peer
0:00:00.129946295  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2595:gst_pad_link_full: linked tiovxisp0:src and capsfilter1:sink, successful
0:00:00.129972955  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.130001865  1190     0x35a6aa00 INFO               GST_EVENT gstpad.c:5985:gst_pad_send_event_unchecked:<tiovxisp0:src> Received event on flushing pad. Discarding
0:00:00.130055285  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstutils.c:1816:gst_element_link_pads_full: trying to link element capsfilter1:src to element fakesink0:(any)
0:00:00.130087570  1190     0x35a6aa00 INFO        GST_ELEMENT_PADS gstelement.c:1016:gst_element_get_static_pad: found pad capsfilter1:src
0:00:00.130127790  1190     0x35a6aa00 INFO                GST_PADS gstutils.c:1079:gst_pad_check_link: trying to link capsfilter1:src and fakesink0:sink
0:00:00.130211025  1190     0x35a6aa00 INFO                GST_PADS gstutils.c:1632:prepare_link_maybe_ghosting: capsfilter1 and fakesink0 in same bin, no need for ghost pads
0:00:00.130258135  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2387:gst_pad_link_prepare: trying to link capsfilter1:src and fakesink0:sink
0:00:00.130352615  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:2595:gst_pad_link_full: linked capsfilter1:src and fakesink0:sink, successful
0:00:00.130383995  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.130433105  1190     0x35a6aa00 INFO               GST_EVENT gstpad.c:5985:gst_pad_send_event_unchecked:<capsfilter1:src> Received event on flushing pad. Discarding
Setting pipeline to PAUSED ...
0:00:00.132283270  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<fakesink0> current NULL pending VOID_PENDING, desired next READY
0:00:00.132371745  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<fakesink0> completed state change to READY
0:00:00.132412430  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.132503085  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully
0:00:00.132557670  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter1> current NULL pending VOID_PENDING, desired next READY
0:00:00.132593160  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter1> completed state change to READY
0:00:00.132624635  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.132672075  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter1' changed state to 2(READY) successfully
0:00:00.132716690  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<tiovxisp0> current NULL pending VOID_PENDING, desired next READY
0:00:00.132749640  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<tiovxisp0> completed state change to READY
0:00:00.132780500  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<tiovxisp0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.132823935  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'tiovxisp0' changed state to 2(READY) successfully
0:00:00.132864615  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter0> current NULL pending VOID_PENDING, desired next READY
0:00:00.132895925  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter0> completed state change to READY
0:00:00.132926820  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.132967150  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter0' changed state to 2(READY) successfully
0:00:00.133003990  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<v4l2src0> current NULL pending VOID_PENDING, desired next READY
0:00:00.133235530  1190     0x35a6aa00 INFO                    v4l2 v4l2_calls.c:588:gst_v4l2_open:<v4l2src0:src> Opened device 'j721e-csi2rx' (/dev/video2) successfully
0:00:00.133310310  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<v4l2src0> completed state change to READY
0:00:00.133367460  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<v4l2src0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.133423640  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'v4l2src0' changed state to 2(READY) successfully
0:00:00.133487840  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2788:gst_element_continue_state:<pipeline0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.133524910  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.133656345  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2796:gst_element_continue_state:<pipeline0> continue state change READY to PAUSED, final PAUSED
0:00:00.133745050  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.133819590  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2942:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PAUSED
0:00:00.133863265  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.133912890  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter1> completed state change to PAUSED
0:00:00.133944915  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.133990925  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter1' changed state to 3(PAUSED) successfully
0:00:00.134031850  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<tiovxisp0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.136208700  1190     0x35a6aa00 INFO              aggregator gstaggregator.c:2550:gst_aggregator_src_pad_activate_mode_func:<tiovxisp0:src> Activating pad!
0:00:00.136269795  1190     0x35a6aa00 INFO              aggregator gstaggregator.c:1540:gst_aggregator_start_srcpad_task:<tiovxisp0> Starting srcpad task
0:00:00.136470550  1190     0x35a6aa00 INFO                    task gsttask.c:516:gst_task_set_lock: setting stream lock 0x35a7fed0 on task 0x35c2b050
0:00:00.136518020  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:6330:gst_pad_start_task:<tiovxisp0:src> created task 0x35c2b050
0:00:00.136845485  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<tiovxisp0> completed state change to PAUSED
0:00:00.136906285  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<tiovxisp0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.136972095  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'tiovxisp0' changed state to 3(PAUSED) successfully
0:00:00.137033470  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.137096050  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter0> completed state change to PAUSED
0:00:00.137114610  1190     0x35be7460 WARN                 v4l2src gstv4l2src.c:1013:gst_v4l2src_query:<v4l2src0> Can't give latency since framerate isn't fixated !
0:00:00.137131570  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.137176645  1190     0x35be7460 WARN              aggregator gstaggregator.c:2146:gst_aggregator_query_latency_unlocked:<tiovxisp0> Latency query failed
0:00:00.137214165  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter0' changed state to 3(PAUSED) successfully
0:00:00.137256335  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<v4l2src0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.137394230  1190     0x35a6aa00 INFO                 basesrc gstbasesrc.c:1435:gst_base_src_do_seek:<v4l2src0> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.137498815  1190     0x35a6aa00 INFO                    task gsttask.c:516:gst_task_set_lock: setting stream lock 0x35bfe1a0 on task 0x35c2b170
0:00:00.137535450  1190     0x35a6aa00 INFO                GST_PADS gstpad.c:6330:gst_pad_start_task:<v4l2src0:src> created task 0x35c2b170
0:00:00.137804175  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<v4l2src0> completed state change to PAUSED
0:00:00.137858935  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<v4l2src0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.137944450  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2978:gst_bin_change_state_func:<pipeline0> child 'v4l2src0' changed state to 3(PAUSED) successfully without preroll
0:00:00.137989575  1190     0x35be74c0 INFO        GST_ELEMENT_PADS gstelement.c:1013:gst_element_get_static_pad: no such pad 'sink' in element "v4l2src0"
0:00:00.138005300  1190     0x35a6aa00 INFO                pipeline gstpipeline.c:533:gst_pipeline_change_state:<pipeline0> pipeline is live
0:00:00.138068735  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<pipeline0> completed state change to PAUSED
0:00:00.138103480  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.138226570  1190     0x35be74c0 INFO                 v4l2src gstv4l2src.c:708:gst_v4l2src_query_preferred_size:<v4l2src0> Detect input 0 as `30102000.ticsi2rx context 0`
Pipeline is live and does not need PREROLL ...
0:00:00.138242630  1190     0x35be7460 WARN                 v4l2src gstv4l2src.c:1013:gst_v4l2src_query:<v4l2src0> Can't give latency since framerate isn't fixated !
0:00:00.138297295  1190     0x35be74c0 WARN                    v4l2 gstv4l2object.c:4621:gst_v4l2_object_get_crop_rect:<v4l2src0:src> VIDIOC_CROPCAP failed
0:00:00.138362615  1190     0x35be7460 WARN              aggregator gstaggregator.c:2146:gst_aggregator_query_latency_unlocked:<tiovxisp0> Latency query failed
0:00:00.138829535  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1261:gst_v4l2_object_fill_format_list:<v4l2src0:src> got 31 format(s):
0:00:00.138874335  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   YUYV
0:00:00.138900150  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   UYVY
0:00:00.138932575  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   XB24
0:00:00.138959070  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   XR24
Pipeline is PREROLLED ...
0:00:00.139159250  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   Y10
Setting pipeline to PLAYING ...
0:00:00.139200480  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   RGBR
0:00:00.139226825  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   Y10
0:00:00.139253465  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   RG12
0:00:00.139279990  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   BA12
0:00:00.139549075  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GB12
0:00:00.139627810  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   BG12
0:00:00.139704235  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   IGB0
0:00:00.139767925  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GIB0
0:00:00.139634440  1190     0x35a6aa00 INFO               GST_EVENT gstevent.c:1557:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.139807950  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   IGR0
0:00:00.139871930  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GIR0
0:00:00.139906685  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GBI0
0:00:00.139908615  1190     0x35a6aa00 INFO                     bin gstbin.c:2766:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:00.139945905  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   BGI0
0:00:00.139984955  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GRI0
0:00:00.140017705  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   RGI0
0:00:00.140046445  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<fakesink0> current READY pending PAUSED, desired next PLAYING
0:00:00.140052700  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   RG10
0:00:00.140084080  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2942:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PLAYING
0:00:00.140103070  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   BA10
0:00:00.140122470  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.140135995  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GB10
0:00:00.140175870  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter1> completed state change to PLAYING
0:00:00.140192020  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   BG10
0:00:00.140210035  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.140219655  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   RGGB
0:00:00.140268835  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GRBG
0:00:00.140272600  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter1' changed state to 4(PLAYING) successfully
0:00:00.140349895  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GBRG
0:00:00.140393955  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   BA81
0:00:00.140414435  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<tiovxisp0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.140426530  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   GREY
0:00:00.140474995  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   Y16
0:00:00.140508045  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   VYUY
0:00:00.140529840  1190     0x35be7460 WARN                 v4l2src gstv4l2src.c:1013:gst_v4l2src_query:<v4l2src0> Can't give latency since framerate isn't fixated !
0:00:00.140540690  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:1265:gst_v4l2_object_fill_format_list:<v4l2src0:src>   YVYU
0:00:00.140581715  1190     0x35be7460 WARN              aggregator gstaggregator.c:2146:gst_aggregator_query_latency_unlocked:<tiovxisp0> Latency query failed
0:00:00.140625155  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<tiovxisp0> completed state change to PLAYING
0:00:00.140661245  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<tiovxisp0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.140718380  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'tiovxisp0' changed state to 4(PLAYING) successfully
0:00:00.140772940  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.140814115  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter0> completed state change to PLAYING
0:00:00.140850990  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.140905230  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter0' changed state to 4(PLAYING) successfully
0:00:00.140960810  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<v4l2src0> completed state change to PLAYING
0:00:00.140998800  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<v4l2src0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.141046880  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'v4l2src0' changed state to 4(PLAYING) successfully
New clock: GstSystemClock
0:00:00.142011625  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:4868:gst_v4l2_object_probe_caps:<v4l2src0:src> probed caps: video/x-raw, format=(string)YUY2, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)YUY2, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate; video/x-raw, format=(string)UYVY, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)UYVY, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate; video/x-raw, format=(string)RGBx, width=(int)[ 1, 4096 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)RGBx, width=(int)[ 1, 4096 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate; video/x-raw, format=(string)BGRx, width=(int)[ 1, 4096 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)BGRx, width=(int)[ 1, 4096 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate; video/x-bayer, format=(string)rggb12, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)grbg12, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)gbrg12, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)bggr12, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)iggb10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)gibg10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)iggr10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)girg10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)gbig10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)bggi10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)grig10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)rggi10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)rggb10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)grbg10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)gbrg10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)bggr10, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)rggb, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)grbg, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)gbrg, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-bayer, format=(string)bggr, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw, format=(string)GRAY8, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)GRAY8, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate; video/x-raw, format=(string)GRAY16_LE, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)GRAY16_LE, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate; video/x-raw, format=(string)YVYU, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw(format:Interlaced), format=(string)YVYU, width=(int)[ 1, 8192 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], interlace-mode=(string)alternate
0:00:00.142536005  1190     0x35be74c0 INFO                 v4l2src gstv4l2src.c:854:gst_v4l2src_negotiate:<v4l2src0> fixated to: video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
0:00:00.142610865  1190     0x35be74c0 INFO               GST_EVENT gstevent.c:918:gst_event_new_caps: creating caps event video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
0:00:00.142888855  1190     0x35be74c0 INFO           basetransform gstbasetransform.c:1326:gst_base_transform_setcaps:<capsfilter0> reuse caps
/GstPipeline:pipeline0/GstV4l2Src:v4l2src0.GstPad:src: caps = video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
0:00:00.142976745  1190     0x35be74c0 INFO               GST_EVENT gstevent.c:918:gst_event_new_caps: creating caps event video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
/GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0.GstTIOVXIspPad:sink_0: caps = video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
0:00:00.143410305  1190     0x35be7460 WARN                 v4l2src gstv4l2src.c:1013:gst_v4l2src_query:<v4l2src0> Can't give latency since framerate isn't fixated !
0:00:00.143460620  1190     0x35be7460 WARN              aggregator gstaggregator.c:2146:gst_aggregator_query_latency_unlocked:<tiovxisp0> Latency query failed
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-bayer, width=(int)1920, height=(int)1200, framerate=(fraction)60/1, format=(string)rggb10, interlace-mode=(string)progressive
0:00:00.143514180  1190     0x35be7460 INFO               tiovxmiso gsttiovxmiso.c:873:gst_tiovx_miso_propose_allocation:<tiovxisp0> Using temporary reference for configuration
0:00:00.143628050  1190     0x35be7460 INFO               tiovxmiso gsttiovxutils.c:773:gst_tiovx_get_exemplar_from_caps:<tiovxisp0> creating raw image with width: 1920  height: 1200     format: 0x101000
0:00:00.143763135  1190     0x35be7460 INFO               tiovxmiso gsttiovxbufferpoolutils.c:85:gst_tiovx_create_new_pool: Creating new pool
0:00:00.143790290  1190     0x35be7460 INFO               tiovxmiso gsttiovxbufferpoolutils.c:97:gst_tiovx_create_new_pool: Creating Raw Image buffer pool
0:00:00.144081785  1190     0x35be7460 INFO         tiovxbufferpool gsttiovxbufferpool.c:127:gst_tiovx_buffer_pool_init:<GstTIOVXBufferPool@0xffffa8007130> New TIOVX buffer pool
0:00:00.144211480  1190     0x35be7460 INFO          tiovxallocator gsttiovxallocator.c:128:gst_tiovx_allocator_init:<GstTIOVXAllocator@0x35bbaed0> New TIOVX allocator
0:00:00.144278840  1190     0x35be7460 INFO               tiovxmiso gsttiovxbufferpoolutils.c:144:gst_tiovx_add_new_pool: Adding new TIOVX pool with 2 buffers of 4608000 size
0:00:00.144437460  1190     0x35be7460 WARN                 v4l2src gstv4l2src.c:1013:gst_v4l2src_query:<v4l2src0> Can't give latency since framerate isn't fixated !
0:00:00.144468610  1190     0x35be74c0 WARN                    v4l2 gstv4l2object.c:4621:gst_v4l2_object_get_crop_rect:<v4l2src0:src> VIDIOC_CROPCAP failed
0:00:00.144489680  1190     0x35be7460 WARN              aggregator gstaggregator.c:2146:gst_aggregator_query_latency_unlocked:<tiovxisp0> Latency query failed
0:00:00.144717160  1190     0x35be74c0 INFO                    v4l2 gstv4l2object.c:3294:gst_v4l2_object_setup_pool:<v4l2src0:src> accessing buffers via mode 5
0:00:00.145096585  1190     0x35be74c0 INFO          v4l2bufferpool gstv4l2bufferpool.c:586:gst_v4l2_buffer_pool_set_config:<v4l2src0:pool0:src> increasing minimum buffers to 2
0:00:00.145129820  1190     0x35be74c0 INFO          v4l2bufferpool gstv4l2bufferpool.c:599:gst_v4l2_buffer_pool_set_config:<v4l2src0:pool0:src> reducing maximum buffers to 32
0:00:00.145249915  1190     0x35be74c0 INFO          v4l2bufferpool gstv4l2bufferpool.c:599:gst_v4l2_buffer_pool_set_config:<v4l2src0:pool0:src> reducing maximum buffers to 32
0:00:00.145502240  1190     0x35be74c0 INFO          tiovxallocator gsttiovxallocator.c:128:gst_tiovx_allocator_init:<GstTIOVXAllocator@0xffffa8008e00> New TIOVX allocator
0:00:00.431602100  1190     0x35be74c0 WARN          v4l2bufferpool gstv4l2bufferpool.c:1390:gst_v4l2_buffer_pool_dqbuf:<v4l2src0:pool0:src> Driver should never set v4l2_buffer.field to ANY
0:00:00.432505375  1190     0x35be74c0 INFO               GST_EVENT gstevent.c:998:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.432638940  1190     0x35be74c0 INFO                 basesrc gstbasesrc.c:3023:gst_base_src_loop:<v4l2src0> marking pending DISCONT
0:00:00.432849090  1190     0x35be7460 INFO              aggregator gstaggregator.c:633:gst_aggregator_push_mandatory_events:<tiovxisp0> pushing stream start
0:00:00.433089295  1190     0x35be7460 FIXME               basesink gstbasesink.c:3395:gst_base_sink_default_event:<fakesink0> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:00:00.433270840  1190     0x35be7460 INFO              aggregator gstaggregator.c:644:gst_aggregator_push_mandatory_events:<tiovxisp0> pushing caps: video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
0:00:00.433364390  1190     0x35be7460 INFO               GST_EVENT gstevent.c:918:gst_event_new_caps: creating caps event video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
0:00:00.433594715  1190     0x35be7460 INFO           basetransform gstbasetransform.c:1326:gst_base_transform_setcaps:<capsfilter1> reuse caps
0:00:00.433664495  1190     0x35be7460 INFO               GST_EVENT gstevent.c:918:gst_event_new_caps: creating caps event video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
/GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0.GstTIOVXMisoPad:src: caps = video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter1.GstPad:src: caps = video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
0:00:00.433983305  1190     0x35be7460 INFO                tiovxisp gsttiovxisp.c:1548:gst_tiovx_isp_init_module:<tiovxisp0> Input parameters:
        Width: 1920
        Height: 1200
        Num exposures: 1
        Lines interleaved: 0
        Format pixel container: 0x101000
        Format MSB: 9
        Meta height before: 0
        Meta height after: 0
/GstPipeline:pipeline0/GstFakeSink:fakesink0.GstPad:sink: caps = video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
0:00:00.434126690  1190     0x35be7460 INFO                tiovxisp gsttiovxisp.c:1640:gst_tiovx_isp_init_module:<tiovxisp0> Output parameters:
        Width: 1920
        Height: 1200

0:00:00.434177930  1190     0x35be7460 INFO                tiovxisp gsttiovxisp.c:1649:gst_tiovx_isp_init_module:<tiovxisp0> Initializing ISP object
/GstPipeline:pipeline0/GstCapsFilter:capsfilter1.GstPad:sink: caps = video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1200, framerate=(fraction)60/1
0:00:00.436061315  1190     0x35be7460 INFO                tiovxisp gsttiovxisp.c:1711:gst_tiovx_isp_init_module:<tiovxisp0:sink_0> TI 2A parameters:
        Sensor DCC ID: 219
        Sensor Image Format: 0
        Sensor Image Phase: 3
        Sensor AWB Mode: 0
        Sensor AE Mode: 2
        Sensor AWB number of skipped frames: 0
        Sensor AE number of skipped frames: 0







^Chandling interrupt.
Interrupt: Stopping pipeline ...
Execution ended after 0:00:56.753299080
Setting pipeline to NULL ...
0:00:56.892689090  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<fakesink0> current READY pending PAUSED, desired next PAUSED
0:00:56.892737540  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2604:gst_bin_element_set_state:<fakesink0> skipping transition from READY to  PAUSED
0:00:56.892772640  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 3(PAUSED) successfully
0:00:56.892819630  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter1> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:56.892855125  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter1> completed state change to PAUSED
0:00:56.892888670  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:56.892964690  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter1' changed state to 3(PAUSED) successfully
0:00:56.893010305  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<tiovxisp0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:56.893047045  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<tiovxisp0> completed state change to PAUSED
0:00:56.893079845  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<tiovxisp0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:56.893126755  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'tiovxisp0' changed state to 3(PAUSED) successfully
0:00:56.893168885  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:56.893200560  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter0> completed state change to PAUSED
0:00:56.893232520  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:56.893274380  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter0' changed state to 3(PAUSED) successfully
0:00:56.893333085  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<v4l2src0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:56.893379830  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<v4l2src0> completed state change to PAUSED
0:00:56.893411505  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<v4l2src0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:56.893454165  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2978:gst_bin_change_state_func:<pipeline0> child 'v4l2src0' changed state to 3(PAUSED) successfully without preroll
0:00:56.893496830  1190     0x35a6aa00 INFO                pipeline gstpipeline.c:533:gst_pipeline_change_state:<pipeline0> pipeline is live
0:00:56.893535520  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2788:gst_element_continue_state:<pipeline0> committing state from PAUSED to PAUSED, pending NULL, next READY
0:00:56.893567835  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PAUSED (NULL pending)
0:00:56.893668485  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2796:gst_element_continue_state:<pipeline0> continue state change PAUSED to READY, final NULL
0:00:56.893745520  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<fakesink0> current READY pending PAUSED, desired next READY
0:00:56.893845675  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<fakesink0> completed state change to READY
0:00:56.893881285  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed READY to READY (VOID_PENDING pending)
0:00:56.893923360  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully
0:00:56.893965090  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<capsfilter1> current PAUSED pending VOID_PENDING, desired next READY
0:00:56.894039110  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2816:gst_element_continue_state:<capsfilter1> completed state change to READY
0:00:56.894072735  1190     0x35a6aa00 INFO              GST_STATES gstelement.c:2716:_priv_gst_element_state_changed:<capsfilter1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:56.894116875  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2935:gst_bin_change_state_func:<pipeline0> child 'capsfilter1' changed state to 2(READY) successfully
0:00:56.894157135  1190     0x35a6aa00 INFO              GST_STATES gstbin.c:2479:gst_bin_element_set_state:<tiovxisp0> current PAUSED pending VOID_PENDING, desired next READY
0:00:56.894193120  1190     0x35a6aa00 INFO              aggregator gstaggregator.c:2563:gst_aggregator_src_pad_activate_mode_func:<tiovxisp0> Deactivating srcpad
0:00:56.894221980  1190     0x35a6aa00 INFO              aggregator gstaggregator.c:1520:gst_aggregator_stop_srcpad_task:<tiovxisp0> Stopping srcpad task

Regards,

Jay

Hi Jay, Thanks for supplying these logs. 

I wonder if the issue is related to the 2A DCC (for auto exposure and auto white balance, which entails feedback to the sensor itself).

This would be related to the tiovxisp sink_0  mentions for the "sink_0::dcc-2a-file=/opt/imaging/imx219/linear/dcc_2a_1920x1080.bin sink_0::device=/dev/v4l-subdev2"

You should keep the dcc-isp-file and format-msb settings. 

So try removing those sink_0:: portions and let's see if that is related to the hang issue. If those subdev entries are not present/functional, then that may be the cause for hang

Jay Kaneria said:

wave521c_k3_codec_fw.bin  => JPEG encoder firmware

 am62a-c71_0-fw => C7x DSP firmware

am62a-mcu-r5f0_0-fw => MCU R5F firmware (application layer)

That is correct, although the mcu R5 firmware is for an additional R5 that is typically used as system / safety monitor. That does not play a role in vision applications, by default. 

The R5 that runs the ISP (and VPAC) is called a WKUP or DM R5 because it manages overall processor state. This firmware is loaded as part of the boot loader, and the associated remoteproc will show as 'attached' since it came up before Linux. 

The c71 file will be a softlink to the actual firmware binary that you would update. 

Jay Kaneria said:

Currently we are grabbing it manually from already build stock SDK-11.01.07 yocto SDK. We will create/add the necessary recipes once this issue is solved. I am guessing there main three firmware we are used and it doesn't associate with other package at build time. Is my understanding correct? 

Correct, those files are standalone. Only the C7x should be sensitive to memory-map changes. Using default is fine as long as you are similarly using default memory map for /usr/lib/libtivision_apps.so and for the DM-R5 firmware that exists in the bootloader (tiboot3.bin)

BR,

Reese

Hi Reese,

Reese Grimsley said:

So try removing those sink_0:: portions and let's see if that is related to the hang issue. If those subdev entries are not present/functional, then that may be the cause for hang

We have tried removing the "sink0::" from property dcc-2a-file and device, but it is not able to recognize the property. Also added the "format-msb" property in the pipeline. Please check below logs:

gst-launch-1.0 videotestsrc ! video/x-bayer,width=1920,height=1200, format=rggb ! tiovxisp sensor-name=SENSOR_SONY_IMX219_RPI dcc-isp-file=/opt/imaging/imx219/linear/dcc_viss_1920x1080.bin dcc-2a-file=/opt/imaging/imx219/linear/dcc_2a_1920x1080.bin device=/dev/v4l-subdev2 format-msb=7 ! video/x-raw,format=NV12 ! fakesink
WARNING: erroneous pipeline: no property "dcc-2a-file" in element "tiovxisp"

Also, tried with removing the entire property, "sink_0::dcc-2a-file" and "sink_0::device" from pipeline but that didn't work as well. Please check below logs:

gst-launch-1.0 videotestsrc ! video/x-bayer,width=1920,height=1200, format=rggb ! tiovxisp sensor-name=SENSOR_SONY_IMX219_RPI dcc-isp-file=/opt/imaging/imx219/linear/dcc_viss_1920x1080.bin  format-msb=7 ! video/x-raw,format=NV12 ! fakesink
APP: Init ... !!!
 59634.762331 s: MEM: Init ... !!!
 59634.762392 s: MEM: Initialized DMA HEAP (fd=5) !!!
 59634.762525 s: MEM: Init ... Done !!!
 59634.762551 s: IPC: Init ... !!!
 59634.781672 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
 59634.786277 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
 59634.786428 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
 59634.786450 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
 59634.786524 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
 59634.787312 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-0
 59634.787524 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-1
 59634.787687 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-2
 59634.787821 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-3
 59634.787846 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initialization Done !!!
 59634.787858 s:  VX_ZONE_INFO: Globally Disabled VX_ZONE_INFO
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
ERROR: from element /GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0: Unable to init TIOVX module
Additional debug info:
/usr/src/debug/edgeai-gst-plugins/1.0.0-r0_edgeai_0/gst-libs/gst/tiovx/gsttiovxmiso.c(1541): gst_tiovx_miso_negotiated_src_caps (): /GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
Freeing pipeline ...
 59634.848594 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff86200a90 of type 00000816 at external count 1, internal count 0, releasing it
 59634.848641 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=user_data_object_88) now as a part of garbage collection
 59634.848752 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff86200cd8 of type 00000816 at external count 1, internal count 0, releasing it
 59634.848773 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=user_data_object_89) now as a part of garbage collection
 59634.848833 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff862c5e98 of type 00000813 at external count 1, internal count 0, releasing it
 59634.848853 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=object_array_91) now as a part of garbage collection
 59634.848882 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff86201168 of type 00000816 at external count 1, internal count 0, releasing it
 59634.848899 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=user_data_object_92) now as a part of garbage collection
 59634.848979 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff862c6050 of type 00000813 at external count 1, internal count 0, releasing it
 59634.849002 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=object_array_93) now as a part of garbage collection
 59634.849029 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff8620f050 of type 00000817 at external count 1, internal count 0, releasing it
 59634.849046 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=raw_image_94) now as a part of garbage collection
 59634.849077 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff862c6208 of type 00000813 at external count 1, internal count 0, releasing it
 59634.849102 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=object_array_95) now as a part of garbage collection
 59634.849127 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff862013b0 of type 00000816 at external count 1, internal count 0, releasing it
 59634.849143 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=user_data_object_96) now as a part of garbage collection
 59634.849168 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff862c63c0 of type 00000813 at external count 1, internal count 0, releasing it
 59634.849184 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=object_array_97) now as a part of garbage collection
 59634.849209 s:  VX_ZONE_WARNING: [vxReleaseContext:1439] Found a reference 0xffff862355e8 of type 0000080f at external count 1, internal count 0, releasing it
 59634.849226 s:  VX_ZONE_WARNING: [vxReleaseContext:1441] Releasing reference (name=image_98) now as a part of garbage collection
APP: Deinit ... !!!
REMOTE_SERVICE: Deinit ... !!!
REMOTE_SERVICE: Deinit ... Done !!!
 59634.854514 s: IPC: Deinit ... !!!
 59634.855152 s: IPC: DeInit ... Done !!!
 59634.855202 s: MEM: Deinit ... !!!
 59634.855212 s: DDR_SHARED_MEM: Alloc's: 5 alloc's of 4625477 bytes
 59634.855223 s: DDR_SHARED_MEM: Free's : 5 free's  of 4625477 bytes
 59634.855232 s: DDR_SHARED_MEM: Open's : 0 allocs  of 0 bytes
 59634.855246 s: MEM: Deinit ... Done !!!
APP: Deinit ... Done !!!

Board creates 4 new /dev/rpmsgX character device nodes whenever we run the pipeline and character devices still exist even after stopping pipeline (rpmsg endpoints are not getting closed properly and creating new 4 nodes every time). As per our findings, these node used for communication between R5F core A53 core. Could there be any issue with it?

Regards,
Jay

Hi Jay,

Hmm, no change by removing the AEWB/2A portions, then.  

Jay Kaneria said:

Also, tried with removing the entire property, "sink_0::dcc-2a-file" and "sink_0::device" from pipeline but that didn't work as well. Please check below logs:

Yes, this was what I intended with my comment. 

It is simply failing to initialize that plugin. Is there any activity in /opt/vx_app_arm_remote_log.out when you run this pipeline? I didn't see the following in your past printouts

ERROR: from element /GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0: Unable to init TIOVX module

I'm unsure if this is related to a lack of buffer-pool / dma-import from the prior node. It could also be that you'r eusing a 1920x1200 input with 1920x1080 DCC file from IMX219

Jay Kaneria said:

Board creates 4 new /dev/rpmsgX character device nodes whenever we run the pipeline and character devices still exist even after stopping pipeline (rpmsg endpoints are not getting closed properly and creating new 4 nodes every time). As per our findings, these node used for communication between R5F core A53 core. Could there be any issue with it?

My gut feeling is this is a symptom of the issue rather than the cause. Those RPMSG interfaces are probably not getting de-initialized whenever you stop the pipeline and they are left hanging. The fact that tiovxmultiscaler node worked proves that the general communication to that core is functional. 

We'll need to dig a bit deeper to root cause this. 

Let's try these diagnostics for TIOVX, which handles all the IPC to R5F core. Please share the printout with me for each. 

cd /opt/vision_apps

source ./vision_apps_init.sh # set some env variables and run TIOVX logger in the background

./vx_app_heap_stats.out #print all the heap allocations for remote cores

./vx_app_arm_ipc.out # test IPC to the remote cores, including basic memory allocation and a timer test

././vx_app_arm_mem.out # test memory allocation into the DDR_SHARED_MEM region. I expect this one is not the problem

• See [1] for another VISS basic test that we can use to clarify which layer is failing here. 

A question I should have asked earlier: In your build, are you using the stock libraries / build for edgeai-app-stack or have you rebuilt the components yourself? If you did rebuild, can you confirm the repo version/release tag you were on when doing so? I assume this was through Yocto, but please correct if I am mistaken.

[1] https://software-dl.ti.com/jacinto7/esd/processor-sdk-rtos-j722s/latest/exports/docs/vision_apps/docs/user_guide/group_apps_utilities_app_thermal_load_viss.html 

BR,
Reese

Hi Reese,

Below are my response:

Reese Grimsley said:

Is there any activity in /opt/vx_app_arm_remote_log.out when you run this pipeline?

There is no activity when running the pipeline. 

Reese Grimsley said:

I didn't see the following in your past printouts

Fullscreen

1

ERROR: from element /GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0: Unable to init TIOVX module

XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

ERROR: from element /GstPipeline:pipeline0/GstTIOVXISP:tiovxisp0: Unable to init TIOVX module

I'm unsure if this is related to a lack of buffer-pool / dma-import from the prior node. It could also be that you'r eusing a 1920x1200 input with 1920x1080 DCC file from IMX219

This error is due to the removing the property "sink_0::dcc-2a-file" and "sink_0::device". Even EVM flashed with stock image is giving same error.

Reese Grimsley said:

Let's try these diagnostics for TIOVX, which handles all the IPC to R5F core. Please share the printout with me for each. 

Below are the logs for each command you mentioned:

/opt/vision_apps # source ./vision_apps_init.sh
/opt/vision_apps # [MCU1_0]   1210.051935 s: CIO: Init ... Done !!!
[MCU1_0]   1210.051999 s: APP: Init ... !!!
[MCU1_0]   1210.052018 s: UDMA: Init ... !!!
[MCU1_0]   1210.052145 s: UDMA: Init ... Done !!!
[MCU1_0]   1210.052172 s: MEM: Init ... !!!
[MCU1_0]   1210.052192 s: MEM: Created heap (DDR_LOCAL_MEM, id=0, flags=0x00000004) @ af000000 of size 16777216 bytes !!!
[MCU1_0]   1210.052249 s: MEM: Created heap (DDR_CACHE_WT_ME, id=7, flags=0x00000000) @ adc00000 of size 4194304 bytes !!!
[MCU1_0]   1210.052288 s: MEM: Init ... Done !!!
[MCU1_0]   1210.052316 s: IPC: Init ... !!!
[MCU1_0]   1210.052336 s: IPC: 3 CPUs participating in IPC !!!
[MCU1_0]   1210.052645 s: IPC: Waiting for HLOS to be ready ... !!!
[MCU1_0]   1210.057163 s: Sciserver Version: v2025.07.0.0-REL.MCUSDK.K3.11.01.00.16+
[MCU1_0]   1210.059937 s: ##RM_PM_HAL Version: v11.01.02
[MCU1_0]   1210.062883 s: ##Starting Sciserver..... PASSED
[MCU1_0]   1233.233581 s: IPC: HLOS is ready !!!
[MCU1_0]   1233.233678 s: IPC: Init ... Done !!!
[MCU1_0]   1233.233704 s: APP: Syncing with 2 CPUs ... !!!
[MCU1_0]   1233.233727 s: APP: Syncing with 2 CPUs ... Done !!!
[MCU1_0]   1233.233748 s: REMOTE_SERVICE: Init ... !!!
[MCU1_0]   1233.233894 s: REMOTE_SERVICE: Init ... Done !!!
[MCU1_0]   1233.233928 s: FVID2: Init ... !!!
[MCU1_0]   1233.233959 s: FVID2: Init ... Done !!!
[MCU1_0]   1233.233978 s: VHWA: VPAC Init ... !!!
[MCU1_0]   1233.233994 s: SCICLIENT: Sciclient_pmSetModuleState module=219 state=2
[MCU1_0]   1233.234087 s: SCICLIENT: Sciclient_pmSetModuleState success
[MCU1_0]   1233.234156 s: VHWA: LDC Init ... !!!
[MCU1_0]   1233.234343 s: VHWA: LDC Init ... Done !!!
[MCU1_0]   1233.234374 s: VHWA: MSC Init ... !!!
[MCU1_0]   1233.234913 s: VHWA: MSC Init ... Done !!!
[MCU1_0]   1233.234935 s: VHWA: VISS Init ... !!!
[MCU1_0]   1233.236652 s: VHWA: VISS Init ... Done !!!
[MCU1_0]   1233.236691 s: VHWA: FC Init ... !!!
[MCU1_0]   1233.236734 s: VHWA: FC Init ... Done !!!
[MCU1_0]   1233.236753 s: VHWA: VPAC Init ... Done !!!
[MCU1_0]   1233.236780 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
[MCU1_0]   1233.236804 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
[MCU1_0]   1233.236828 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
[MCU1_0]   1233.237338 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.cmd_timeout_test on target MCU1-
0
[MCU1_0]   1233.237420 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.tiovx_overhead on target MCU1-0
[MCU1_0]   1233.237486 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_sink on target MCU1-0
[MCU1_0]   1233.237544 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_source on target MCU1-0
[MCU1_0]   1233.237607 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_sink2 on target MCU1-0
[MCU1_0]   1233.237669 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_source2 on target MCU1-0
[MCU1_0]   1233.237730 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_intermediate on target MCU1-0
[MCU1_0]   1233.237792 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_intermediate_2 on target
MCU1-0
[MCU1_0]   1233.237853 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_source_error on target MC
U1-0
[MCU1_0]   1233.237916 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_source_obj_array on targe
t MCU1-0
[MCU1_0]   1233.237976 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_sink_obj_array on target
MCU1-0
[MCU1_0]   1233.238036 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.pyramid_intermediate on target M
CU1-0
[MCU1_0]   1233.238095 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.pyramid_source on target MCU1-0
[MCU1_0]   1233.238153 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.pyramid_sink on target MCU1-0
[MCU1_0]   1233.238212 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.test_target on target MCU1-0
[MCU1_0]   1233.238269 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.image_intermediate on target MCU1-0
[MCU1_0]   1233.238331 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.ext.obj_array_split on target MCU1-0
[MCU1_0]   1233.238453 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MCU1-0
[MCU1_0]   1233.238542 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target VPAC_LDC1
[MCU1_0]   1233.238622 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target VPAC_MSC1
[MCU1_0]   1233.238698 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target VPAC_MSC2
[MCU1_0]   1233.238772 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target VPAC_VISS1
[MCU1_0]   1233.238847 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target VPAC_FC
[MCU1_0]   1233.238882 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initialization Done !!!
[MCU1_0]   1233.238910 s:  VX_ZONE_INFO: Globally Disabled VX_ZONE_INFO
[MCU1_0]   1233.238930 s: APP: OpenVX Target kernel init ... !!!
[MCU1_0]   1233.244571 s: APP: OpenVX Target kernel init ... Done !!!
[MCU1_0]   1233.244690 s: VISS REMOTE SERVICE: Init ... !!!
[MCU1_0]   1233.244742 s: VISS REMOTE SERVICE: Init ... Done !!!
[MCU1_0]   1233.244763 s: APP: Init ... Done !!!
[MCU1_0]   1233.244780 s: APP: Run ... !!!
[MCU1_0]   1233.244795 s: IPC: Starting echo test ...
[MCU1_0]   1233.244894 s: APP: Run ... Done !!!
[MCU1_0]   1233.369762 s: IPC: Echo status: a530-0[.] r5f0-0[s] c75ss0[P]
[C7x_1 ]   1233.354525 s: CIO: Init ... Done !!!
[C7x_1 ]   1233.354545 s: APP: Init ... !!!
[C7x_1 ]   1233.354558 s: SCICLIENT: Init ... !!!
[C7x_1 ]   1233.354622 s: SCICLIENT: DMSC FW version [11.1.5--v11.01.05 (Fancy Rat)]
[C7x_1 ]   1233.354642 s: SCICLIENT: DMSC FW revision 0xb
[C7x_1 ]   1233.354657 s: SCICLIENT: DMSC FW ABI revision 4.0
[C7x_1 ]   1233.354674 s: SCICLIENT: Init ... Done !!!
[C7x_1 ]   1233.354689 s: UDMA: Init ... !!!
[C7x_1 ]   1233.354738 s: UDMA: Init ... Done !!!
[C7x_1 ]   1233.354754 s: MEM: Init ... !!!
[C7x_1 ]   1233.354769 s: MEM: Created heap (DDR_LOCAL_MEM, id=0, flags=0x00000004) @ b2000000 of size 117440512 bytes !!!
[C7x_1 ]   1233.354798 s: MEM: Init ... Done !!!
[C7x_1 ]   1233.354826 s: IPC: Init ... !!!
[C7x_1 ]   1233.354840 s: IPC: 3 CPUs participating in IPC !!!
[C7x_1 ]   1233.355056 s: IPC: Waiting for HLOS to be ready ... !!!
[C7x_1 ]   1233.365900 s: IPC: HLOS is ready !!!
[C7x_1 ]   1233.366056 s: Main task for LPM Suspend
[C7x_1 ]   1233.366084 s: IPC: Init ... Done !!!
[C7x_1 ]   1233.366099 s: APP: Syncing with 2 CPUs ... !!!
[C7x_1 ]   1233.366115 s: APP: Syncing with 2 CPUs ... Done !!!
[C7x_1 ]   1233.366131 s: REMOTE_SERVICE: Init ... !!!
[C7x_1 ]   1233.366286 s: REMOTE_SERVICE: Init ... Done !!!
[C7x_1 ]   1233.366314 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
[C7x_1 ]   1233.366338 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
[C7x_1 ]   1233.366360 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
[C7x_1 ]   1233.367023 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel vx_tutorial_graph.phase_rgb on target DSP_C7-1
[C7x_1 ]   1233.367076 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_sink on target DSP_C7-1
[C7x_1 ]   1233.367127 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_source on target DSP_C7-1
[C7x_1 ]   1233.367176 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_sink2 on target DSP_C7-1
[C7x_1 ]   1233.367225 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_source2 on target DSP_C7-1
[C7x_1 ]   1233.367275 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.scalar_intermediate on target DSP_C7-
1
[C7x_1 ]   1233.367326 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_intermediate_2 on target
DSP_C7-1
[C7x_1 ]   1233.367376 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_source_error on target DS
P_C7-1
[C7x_1 ]   1233.367428 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_source_obj_array on targe
t DSP_C7-1
[C7x_1 ]   1233.367479 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.scalar_sink_obj_array on target
DSP_C7-1
[C7x_1 ]   1233.367531 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.pyramid_intermediate on target D
SP_C7-1
[C7x_1 ]   1233.367581 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.pyramid_source on target DSP_C7-
1
[C7x_1 ]   1233.367630 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.pyramid_sink on target DSP_C7-1
[C7x_1 ]   1233.367680 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.test_target on target DSP_C7-1
[C7x_1 ]   1233.367731 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.capture.image_intermediate on target DSP_C7-1
[C7x_1 ]   1233.367781 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.multi_in_out on target DSP_C7-1
[C7x_1 ]   1233.367842 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.test_target on target DSP_C7-1
[C7x_1 ]   1233.367892 s:  VX_ZONE_INFO: [ownAddTargetKernelInternal:189] registered kernel com.ti.test_kernels.tiovx_overhead on target DSP_C7-
1
[C7x_1 ]   1233.368024 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1
[C7x_1 ]   1233.368123 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_2
[C7x_1 ]   1233.368219 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_3
[C7x_1 ]   1233.368315 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_4
[C7x_1 ]   1233.368413 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_5
[C7x_1 ]   1233.368509 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_6
[C7x_1 ]   1233.368605 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_7
[C7x_1 ]   1233.368700 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target DSP_C7-1_PRI_8
[C7x_1 ]   1233.368729 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initialization Done !!!
[C7x_1 ]   1233.368754 s:  VX_ZONE_INFO: Globally Disabled VX_ZONE_INFO
[C7x_1 ]   1233.368771 s: APP: OpenVX Target kernel init ... !!!
[C7x_1 ]   1233.369005 s: APP: OpenVX Target kernel init ... Done !!!
[C7x_1 ]   1233.369024 s: APP: Init ... Done !!!
[C7x_1 ]   1233.369037 s: APP: Run ... !!!
[C7x_1 ]   1233.369050 s: IPC: Starting echo test ...
[C7x_1 ]   1233.369218 s: APP: Run ... Done !!!
[C7x_1 ]   1233.369696 s: IPC: Echo status: a530-0[.] r5f0-0[P] c75ss0[s]



/opt/vision_apps # ./vx_app_heap_stats.out
APP: Init ... !!!
  1393.295126 s: MEM: Init ... !!!
  1393.295246 s: MEM: Initialized DMA HEAP (fd=5) !!!
  1393.295463 s: MEM: Init ... Done !!!
  1393.295498 s: IPC: Init ... !!!
  1393.315723 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
  1393.321785 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!

Detailed CPU memory statistics,
===============================

CPU: mcu1_0: HEAP:    DDR_LOCAL_MEM: size =   16777216 B, free =   16777152 B ( 99 % unused)
CPU: mcu1_0: HEAP:  DDR_CACHE_WT_ME: size =    4194304 B, free =    4194240 B ( 99 % unused)

CPU:  c7x_1: HEAP:    DDR_LOCAL_MEM: size =  117440512 B, free =  117440448 B ( 99 % unused)
CPU:  c7x_1: HEAP:           L3_MEM: size =    1048576 B, free =    1048576 B (100 % unused)
CPU:  c7x_1: HEAP:           L2_MEM: size =     245760 B, free =     245760 B (100 % unused)
CPU:  c7x_1: HEAP:           L1_MEM: size =      16384 B, free =      16384 B (100 % unused)
CPU:  c7x_1: HEAP:  DDR_SCRATCH_MEM: size =  117440512 B, free =  117440512 B (100 % unused)
CPU:  c7x_1: HEAP:  DDR_NON_CACHE_M: size =   16777216 B, free =   16777216 B (100 % unused)
CPU:  c7x_1: HEAP:  DDR_SCRATCH_NON: size =   16777216 B, free =   16777216 B (100 % unused)



Detailed CPU OS memory statistics,
==================================

CPU: mcu1_0
  semaphore:  cnt=      0
  mutex:      cnt=      0
  queue:      cnt=      0
  event:      cnt=      0
  heap:       cnt=      0
  mailbox:    cnt=      0
  task:       cnt=      0
  clock:      cnt=      0
  hwi:        cnt=      0
  timer:      cnt=      0

CPU:  c7x_1
  semaphore:  cnt=      0
  mutex:      cnt=      0
  queue:      cnt=      0
  event:      cnt=      0
  heap:       cnt=      0
  mailbox:    cnt=      0
  task:       cnt=      0
  clock:      cnt=      0
  hwi:        cnt=      4
  timer:      cnt=      0


APP: Deinit ... !!!
REMOTE_SERVICE: Deinit ... !!!
REMOTE_SERVICE: Deinit ... Done !!!
  1393.326222 s: IPC: Deinit ... !!!
  1393.326787 s: IPC: DeInit ... Done !!!
  1393.326840 s: MEM: Deinit ... !!!
  1393.326862 s: DDR_SHARED_MEM: Alloc's: 0 alloc's of 0 bytes
  1393.326892 s: DDR_SHARED_MEM: Free's : 0 free's  of 0 bytes
  1393.326915 s: DDR_SHARED_MEM: Open's : 0 allocs  of 0 bytes
  1393.326939 s: MEM: Deinit ... Done !!!
APP: Deinit ... Done !!!
APP HEAP STATS: Done !!!




/opt/vision_apps # ./vx_app_arm_ipc.out
APP: Init ... !!!
  2296.318167 s: MEM: Init ... !!!
  2296.318329 s: MEM: Initialized DMA HEAP (fd=5) !!!
  2296.318526 s: MEM: Init ... Done !!!
  2296.318558 s: IPC: Init ... !!!
  2296.338614 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
  2296.343504 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
  2296.345112 s:  VX[  304.250225] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
  2296.345191 s:  VX[  304.250225] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
  2296.345281 s:  [  304.250242] platform 78000000.r5f: failed to send mailbox message, status = -105
VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
  2296.347672 s:  V[  304.250242] platform 78000000.r5f: failed to send mailbox message, status = -105
X_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-0[  304.250256] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN

  2296.348002 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:1[  304.250260] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250267] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
69] Added target MPU-1
  2296.348178 s:  VX_ZONE_INFO: [tivxPl[  304.250271] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250274] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
atformCreateTargetId:169] Added target MPU-2
  2296.348551 s: [  304.250278] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250279] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250283] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250291] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250295] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250519] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
 VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU[  304.250535] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250555] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
-3
  2296.348651 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initial[  304.250560] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250576] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
ization Done !!!
  2296.348709 s:  VX_ZONE_INFO: Globally Disab[  304.250588] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250599] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250603] platform 78000000.r5f: failed to send mailbox message, status = -105
led VX_ZONE_INFO
  2296.350299 s: IPC: RX: mcu1_0 -> mpu1_0 (po[  304.250622] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250631] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
rt 13) msg = 0xdead0000
  2296.350392 s: IPC: RX: mcu1_0 -> mpu[  304.250634] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250635] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250645] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250649] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250652] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250656] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250665] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
1_0 (port 13) msg = 0xdead0001
  2296.350450 s: IPC: RX: mcu1_0[  304.250669] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250673] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.350471 s: IPC: RX:[  304.250677] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250713] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250716] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250729] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250733] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250740] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
 c7x_1 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.350543 s: IP[  304.250744] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250747] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250751] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250754] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250767] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250768] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250772] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250777] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250781] platform 78000000.r5f: failed to send mailbox message, status = -105
C: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.35056[  304.250785] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
3 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0001
  2296[  304.250789] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250791] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250795] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250803] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250805] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250807] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250809] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250816] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250820] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250821] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250825] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250828] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250832] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250841] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN

  2296.350599 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdea[  304.250841] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
d0002
  2296.350624 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg [  304.250845] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250845] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250858] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250862] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250877] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250881] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250894] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250898] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250906] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250910] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250912] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250916] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250917] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250922] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250928] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250931] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250932] platform 78000000.r5f: failed to send mailbox message, status = -105
= 0xdead0005
  2296.350639 s: IPC: RX: c7x_1 -> mpu1_0 (port 13[  304.250935] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250943] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250943] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250946] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250947] platform 78000000.r5f: failed to send mailbox message, status = -105
) msg = 0xdead0003
  2296.350668 s: IPC: RX: mcu1_0 -> mpu1_0 ([  304.250956] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.250960] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.250989] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
port 13) msg = 0xdead0006
  2296.350684 s: IPC: RX: c7x_1 -> mp[  304.250993] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251002] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251006] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251014] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251018] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251027] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251031] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251039] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
u1_0 (port 13) msg = 0xdead0004
  2296.350715 s: IPC: RX: mcu1_[  304.251043] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251051] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251055] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251341] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251347] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251370] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251374] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251387] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251391] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251407] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251410] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251423] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251427] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251454] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
0 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.350730 s: IPC: RX[  304.251458] platform 78000000.r5f: failed to send mailbox message, status = -105
[  304.251475] omap-mailbox 29000000.mailbox: Try increasing MBOX_TX_QUEUE_LEN
[  304.251479] platform 78000000.r5f: failed to send mailbox message, status = -105
: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.350809 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.350832 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.350861 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.350886 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.350911 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.350931 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.350946 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.350961 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.350976 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.351001 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.351026 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0001
  2296.351047 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.351072 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.351097 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0004
  2296.351109 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.351134 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.351147 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.351163 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.351175 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.351190 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0007
APP IPC: Waiting for all messages to get echoed from remote core...
  2296.351205 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.351276 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.351291 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.351316 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.351335 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.351351 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.351363 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.351381 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.351393 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.351408 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.351423 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.351441 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.351455 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.351470 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0001
  2296.351484 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.351499 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.351513 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0004
  2296.351528 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.351542 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.351556 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.351571 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.351585 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.351600 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.351615 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.351629 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.351644 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.351659 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.351673 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.351685 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.351699 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.351710 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.351725 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0001
  2296.351736 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.351751 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.351763 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0001
  2296.351778 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.351789 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.351804 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0004
  2296.351815 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.351829 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.351841 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0004
  2296.351856 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.351868 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.351882 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.351894 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.351908 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.351920 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.351934 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.351946 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.351960 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.351972 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.351986 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.351997 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.352012 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.352023 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.352037 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.352049 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.352063 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.352075 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.352089 s: IPC: RX: mcu1_0 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.352101 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.352120 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.352136 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.352151 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0001
  2296.352166 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.352181 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.352196 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0004
  2296.352211 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.352248 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.352266 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.352281 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.352296 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.352311 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.352326 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.352341 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.352356 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.352370 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.352385 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000f
  2296.352400 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0000
  2296.352415 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0001
  2296.352429 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0002
  2296.352444 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0003
  2296.352458 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0004
  2296.352473 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0005
  2296.352488 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0006
  2296.352503 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0007
  2296.352518 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0008
  2296.352533 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead0009
  2296.352547 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000a
  2296.352562 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000b
  2296.352577 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000c
  2296.352594 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000d
  2296.352609 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000e
  2296.352624 s: IPC: RX: c7x_1 -> mpu1_0 (port 13) msg = 0xdead000f

APP IPC: Waiting for all messages to get echoed ... Done.
APP IPC: Running remote service test ...
  2306.352463 s: REMOTE_SERVICE_TEST: Running test for CPU mcu1_0 !!!
  2306.352931 s: REMOTE_SERVICE_TEST: Test passed !!!
  2306.353159 s: REMOTE_SERVICE_TEST: Running test @ 0xa3000000 of 1024 bytes size for CPU mcu1_0 !!!
  2306.353931 s: REMOTE_SERVICE_TEST: Test passed !!!
  2306.353967 s: REMOTE_SERVICE_TEST: Running test for timer of 10000 msecs for CPU mcu1_0 !!!
  2316.354018 s: REMOTE_SERVICE_TEST: Timer test of 10000 msecs for CPU mcu1_0 ... DONE !!!
  2316.354074 s: REMOTE_SERVICE_TEST: Test passed !!!
  2316.354095 s: REMOTE_SERVICE_TEST: Running test for CPU c7x_1 !!!
  2316.354604 s: REMOTE_SERVICE_TEST: Test passed !!!
  2316.354781 s: REMOTE_SERVICE_TEST: Running test @ 0xa3000000 of 1024 bytes size for CPU c7x_1 !!!
  2316.355430 s: REMOTE_SERVICE_TEST: Test passed !!!
  2316.355460 s: REMOTE_SERVICE_TEST: Running test for timer of 10000 msecs for CPU c7x_1 !!!
[MCU1_0]   2316.353897 s: REMOTE_SERVICE_TEST: delay = 10000 ms, elapsed time global = 9999 ms

  2326.355697 s: REMOTE_SERVICE_TEST: Timer test of 10000 msecs for CPU c7x_1 ... DONE !!!
  2326.355753 s: REMOTE_SERVICE_TEST: Test passed !!!
APP IPC: Running remote service test ... Done.
[C7x_1 ]   2326.355601 s: REMOTE_SERVICE_TEST: delay = 10000 ms, elapsed time global = 10000 ms
APP: Deinit ... !!!
REMOTE_SERVICE: Deinit ... !!!
REMOTE_SERVICE: Deinit ... Done !!!
  2326.361087 s: IPC: Deinit ... !!!
  2326.361655 s: IPC: DeInit ... Done !!!
  2326.361704 s: MEM: Deinit ... !!!
  2326.361722 s: DDR_SHARED_MEM: Alloc's: 2 alloc's of 2048 bytes
  2326.361737 s: DDR_SHARED_MEM: Free's : 2 free's  of 2048 bytes
  2326.361751 s: DDR_SHARED_MEM: Open's : 0 allocs  of 0 bytes
  2326.361770 s: MEM: Deinit ... Done !!!
APP: Deinit ... Done !!!
APP IPC: Done !!!



/opt/vision_apps # ././vx_app_arm_mem.out
APP: Init ... !!!
  2357.356185 s: MEM: Init ... !!!
  2357.356316 s: MEM: Initialized DMA HEAP (fd=5) !!!
  2357.356508 s: MEM: Init ... Done !!!
  2357.356548 s: IPC: Init ... !!!
  2357.376652 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
  2357.381454 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
APP_MEM: 0: Allocated memory @ 0xffffb128d000 of size 131072 bytes
APP_MEM: 0: Translated virtual addr = 0xffffb128d000 -> phyical addr = a3000000
APP_MEM: 0: Exported dmaBufId 11 with offset 0
APP_MEM: 1: Allocated memory @ 0xffffb126d000 of size 131072 bytes
APP_MEM: 1: Translated virtual addr = 0xffffb126d000 -> phyical addr = a3020000
APP_MEM: 1: Exported dmaBufId 13 with offset 0
APP_MEM: 2: Allocated memory @ 0xffffb124d000 of size 131072 bytes
APP_MEM: 2: Translated virtual addr = 0xffffb124d000 -> phyical addr = a3040000
APP_MEM: 2: Exported dmaBufId 15 with offset 0
APP_MEM: 3: Allocated memory @ 0xffffb122d000 of size 131072 bytes
APP_MEM: 3: Translated virtual addr = 0xffffb122d000 -> phyical addr = a3060000
APP_MEM: 3: Exported dmaBufId 17 with offset 0
APP_MEM: 4: Allocated memory @ 0xffffb120d000 of size 131072 bytes
APP_MEM: 4: Translated virtual addr = 0xffffb120d000 -> phyical addr = a3080000
APP_MEM: 4: Exported dmaBufId 19 with offset 0
APP_MEM: 5: Allocated memory @ 0xffffb11ed000 of size 131072 bytes
APP_MEM: 5: Translated virtual addr = 0xffffb11ed000 -> phyical addr = a30a0000
APP_MEM: 5: Exported dmaBufId 21 with offset 0
APP_MEM: 6: Allocated memory @ 0xffffb11cd000 of size 131072 bytes
APP_MEM: 6: Translated virtual addr = 0xffffb11cd000 -> phyical addr = a30c0000
APP_MEM: 6: Exported dmaBufId 23 with offset 0
APP_MEM: 7: Allocated memory @ 0xffffb11ad000 of size 131072 bytes
APP_MEM: 7: Translated virtual addr = 0xffffb11ad000 -> phyical addr = a30e0000
APP_MEM: 7: Exported dmaBufId 25 with offset 0
APP_MEM: 8: Allocated memory @ 0xffffb118d000 of size 131072 bytes
APP_MEM: 8: Translated virtual addr = 0xffffb118d000 -> phyical addr = a3100000
APP_MEM: 8: Exported dmaBufId 27 with offset 0
APP_MEM: 9: Allocated memory @ 0xffffb116d000 of size 131072 bytes
APP_MEM: 9: Translated virtual addr = 0xffffb116d000 -> phyical addr = a3120000
APP_MEM: 9: Exported dmaBufId 29 with offset 0
APP_MEM: 10: Allocated memory @ 0xffffb114d000 of size 131072 bytes
APP_MEM: 10: Translated virtual addr = 0xffffb114d000 -> phyical addr = a3140000
APP_MEM: 10: Exported dmaBufId 31 with offset 0
APP_MEM: 11: Allocated memory @ 0xffffb112d000 of size 131072 bytes
APP_MEM: 11: Translated virtual addr = 0xffffb112d000 -> phyical addr = a3160000
APP_MEM: 11: Exported dmaBufId 33 with offset 0
APP_MEM: 12: Allocated memory @ 0xffffb110d000 of size 131072 bytes
APP_MEM: 12: Translated virtual addr = 0xffffb110d000 -> phyical addr = a3180000
APP_MEM: 12: Exported dmaBufId 35 with offset 0
APP_MEM: 13: Allocated memory @ 0xffffb10ed000 of size 131072 bytes
APP_MEM: 13: Translated virtual addr = 0xffffb10ed000 -> phyical addr = a31a0000
APP_MEM: 13: Exported dmaBufId 37 with offset 0
APP_MEM: 14: Allocated memory @ 0xffffb10cd000 of size 131072 bytes
APP_MEM: 14: Translated virtual addr = 0xffffb10cd000 -> phyical addr = a31c0000
APP_MEM: 14: Exported dmaBufId 39 with offset 0
APP_MEM: 15: Allocated memory @ 0xffffb10ad000 of size 131072 bytes
APP_MEM: 15: Translated virtual addr = 0xffffb10ad000 -> phyical addr = a31e0000
APP_MEM: 15: Exported dmaBufId 41 with offset 0
APP_MEM: elasped time for data processing is 6814 usecs
APP_MEM: 0: Free'ed memory @ 0xffffb128d000 of size 131072 bytes
APP_MEM: 1: Free'ed memory @ 0xffffb126d000 of size 131072 bytes
APP_MEM: 2: Free'ed memory @ 0xffffb124d000 of size 131072 bytes
APP_MEM: 3: Free'ed memory @ 0xffffb122d000 of size 131072 bytes
APP_MEM: 4: Free'ed memory @ 0xffffb120d000 of size 131072 bytes
APP_MEM: 5: Free'ed memory @ 0xffffb11ed000 of size 131072 bytes
APP_MEM: 6: Free'ed memory @ 0xffffb11cd000 of size 131072 bytes
APP_MEM: 7: Free'ed memory @ 0xffffb11ad000 of size 131072 bytes
APP_MEM: 8: Free'ed memory @ 0xffffb118d000 of size 131072 bytes
APP_MEM: 9: Free'ed memory @ 0xffffb116d000 of size 131072 bytes
APP_MEM: 10: Free'ed memory @ 0xffffb114d000 of size 131072 bytes
APP_MEM: 11: Free'ed memory @ 0xffffb112d000 of size 131072 bytes
APP_MEM: 12: Free'ed memory @ 0xffffb110d000 of size 131072 bytes
APP_MEM: 13: Free'ed memory @ 0xffffb10ed000 of size 131072 bytes
APP_MEM: 14: Free'ed memory @ 0xffffb10cd000 of size 131072 bytes
APP_MEM: 15: Free'ed memory @ 0xffffb10ad000 of size 131072 bytes
APP: Deinit ... !!!
REMOTE_SERVICE: Deinit ... !!!
REMOTE_SERVICE: Deinit ... Done !!!
  2357.393749 s: IPC: Deinit ... !!!
  2357.394538 s: IPC: DeInit ... Done !!!
  2357.395009 s: MEM: Deinit ... !!!
  2357.395046 s: DDR_SHARED_MEM: Alloc's: 16 alloc's of 2097152 bytes
  2357.395061 s: DDR_SHARED_MEM: Free's : 16 free's  of 2097152 bytes
  2357.395076 s: DDR_SHARED_MEM: Open's : 0 allocs  of 0 bytes
  2357.395102 s: MEM: Deinit ... Done !!!
APP: Deinit ... Done !!!

There can be issue with "./vx_app_arm_ipc.out" command.

Reese Grimsley said:

In your build, are you using the stock libraries / build for edgeai-app-stack or have you rebuilt the components yourself? If you did rebuild, can you confirm the repo version/release tag you were on when doing so? I assume this was through Yocto, but please correct if I am mistaken.

edgeai-app-stack libraries are not stock one and we rebuild component ourself. we have used meta-edgeai layer from sdk-11.01.07 and commit is "2f3ea75ca6733035d5a60fc2a3fc7d15af9e9851 (HEAD, tag: 11.01.07.05)".

Reese Grimsley said:

See [1] for another VISS basic test that we can use to clarify which layer is failing here. 

When we run the command on our device, it stuck after below prints. But on the EVM with stock sdk, it is exiting successfully after few seconds.

/opt/vision_apps # ./vx_app_viss.out 90 10
The number of args is 3
The arguments are 90 and 10
APP: Init ... !!!
 12192.538211 s: MEM: Init ... !!!
 12192.538300 s: MEM: Initialized DMA HEAP (fd=5) !!!
 12192.538499 s: MEM: Init ... Done !!!
 12192.538541 s: IPC: Init ... !!!
 12192.558801 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
 12192.563725 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
 12192.563916 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
 12192.563936 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
 12192.563947 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
 12192.564791 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-0
 12192.565068 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-1
 12192.565259 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-2
 12192.565468 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-3
 12192.565492 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initialization Done !!!
 12192.565512 s:  VX_ZONE_INFO: Globally Disabled VX_ZONE_INFO
Test data path is NULL. Defaulting to current folder
Cannot open File .//psdkra/app_single_cam/IMX390_001/input2.raw

Regards,

Jay

Hi Jay,

This is helping narrow it down. Thanks for running those diagnostics. It looks like the root issue is closer to IPC 

Do you see similar behavior while running these basic RPMsg tests as well?

rpmsg_char_simple  -r 15 -n 10
rpmsg_char_simple  -r 8 -n 10
rpmsg_char_simple  -r 0 -n 10

• Possibly relevant thread [1], but that was for memory map modification.
  • You have stated mem-map is entirely unchanged, meaning default /usr/lib/libtivision_apps.so and firmware for C7x and R5F and device-tree. Please confirm, as I suspect the issue is closer to this. 

Jay Kaneria said:

edgeai-app-stack libraries

Which libraries have updated on your side? Nothing in edgeai-app-stack should have caused a change that will break IPC

Jay Kaneria said:

When we run the command on our device, it stuck after below prints. But on the EVM with stock sdk, it is exiting successfully after few seconds.

This expects you have extracted the test_data (a tarball on the SecureResources firmware-builder files) under /opt/vision_apps and source'd the vision_apps_init.sh script (`source` is important as the script will set some ENV variables). 

[1]  AM62A7-Q1: [AM62A] Custom memory map issue: Algorithm fails when adjust shared_memory and c7x memory  

• https://dev.ti.com/tirex/explore/content/am62ax_academy_11_01_00_00/_build_am62ax_academy_11_01_00_00/source/linux/ch-eval/eval-tour-ipc.html#eval-tour-ipc 

Hi Reese,

Thank for you reply.

Reese Grimsley said:

Do you see similar behavior while running these basic RPMsg tests as well?

Fullscreen

We don't see error when used above basic rpmsg command. Commands run successfully. See below output:

~ # rpmsg_char_simple  -r 15 -n 10
Created endpt device rpmsg-char-15-960, fd = 3 port = 1026
Exchanging 10 messages with rpmsg device rpmsg-char-15-960 on rproc id 15 ...

Sending message #0: hello there 0!
Received message #0: round trip delay(usecs) = 96790
hello there 0!
Sending message #1: hello there 1!
Received message #1: round trip delay(usecs) = 107235
hello there 1!
Sending message #2: hello there 2!
Received message #2: round trip delay(usecs) = 71395
hello there 2!
Sending message #3: hello there 3!
Received message #3: round trip delay(usecs) = 69810
hello there 3!
Sending message #4: hello there 4!
Received message #4: round trip delay(usecs) = 69690
hello there 4!
Sending message #5: hello there 5!
Received message #5: round trip delay(usecs) = 68230
hello there 5!
Sending message #6: hello there 6!
Received message #6: round trip delay(usecs) = 71770
hello there 6!
Sending message #7: hello there 7!
Received message #7: round trip delay(usecs) = 89275
hello there 7!
Sending message #8: hello there 8!
Received message #8: round trip delay(usecs) = 71500
hello there 8!
Sending message #9: hello there 9!
Received message #9: round trip delay(usecs) = 115685
hello there 9!

Communicated 10 messages successfully on rpmsg-char-15-960

TEST STATUS: PASSED
~ #
~ #
~ #
~ # rpmsg_char_simple  -r 8 -n 10
Created endpt device rpmsg-char-8-962, fd = 3 port = 1026
Exchanging 10 messages with rpmsg device rpmsg-char-8-962 on rproc id 8 ...

Sending message #0: hello there 0!
Received message #0: round trip delay(usecs) = 124380
hello there 0!
Sending message #1: hello there 1!
Received message #1: round trip delay(usecs) = 84725
hello there 1!
Sending message #2: hello there 2!
Received message #2: round trip delay(usecs) = 88505
hello there 2!
Sending message #3: hello there 3!
Received message #3: round trip delay(usecs) = 91330
hello there 3!
Sending message #4: hello there 4!
Received message #4: round trip delay(usecs) = 83090
hello there 4!
Sending message #5: hello there 5!
Received message #5: round trip delay(usecs) = 83795
hello there 5!
Sending message #6: hello there 6!
Received message #6: round trip delay(usecs) = 118955
hello there 6!
Sending message #7: hello there 7!
Received message #7: round trip delay(usecs) = 83635
hello there 7!
Sending message #8: hello there 8!
Received message #8: round trip delay(usecs) = 79165
hello there 8!
Sending message #9: hello there 9!
Received message #9: round trip delay(usecs) = 84120
hello there 9!

Communicated 10 messages successfully on rpmsg-char-8-962

TEST STATUS: PASSED
~ #
~ #
~ #
~ #
~ #
~ # rpmsg_char_simple  -r 0 -n 10
Created endpt device rpmsg-char-0-971, fd = 3 port = 1028
Exchanging 10 messages with rpmsg device rpmsg-char-0-971 on rproc id 0 ...

Sending message #0: hello there 0!
Received message #0: round trip delay(usecs) = 111235
h
Sending message #1: hello there 1!
Received message #1: round trip delay(usecs) = 130860
h
Sending message #2: hello there 2!
Received message #2: round trip delay(usecs) = 84940
h
Sending message #3: hello there 3!
Received message #3: round trip delay(usecs) = 83760
h
Sending message #4: hello there 4!
Received message #4: round trip delay(usecs) = 129615
h
Sending message #5: hello there 5!
Received message #5: round trip delay(usecs) = 86450
h
Sending message #6: hello there 6!
Received message #6: round trip delay(usecs) = 81900
h
Sending message #7: hello there 7!
Received message #7: round trip delay(usecs) = 77365
h
Sending message #8: hello there 8!
Received message #8: round trip delay(usecs) = 80340
h
Sending message #9: hello there 9!
Received message #9: round trip delay(usecs) = 83515
h

Communicated 10 messages successfully on rpmsg-char-0-971

TEST STATUS: PASSED

Reese Grimsley said:

Possibly relevant thread [1], but that was for memory map modification.

• You have stated mem-map is entirely unchanged, meaning default /usr/lib/libtivision_apps.so and firmware for C7x and R5F and device-tree. Please confirm, as I suspect the issue is closer to this. 

We are using the 1GB RAM instead of 4GB RAM. So, we have to modify the 2 memory region: 1) edgeai_core_heaps 2) linux,cma. 
But using this modified region, streaming works fine if we use rootfs from SDK-11. So, We think that memory region size modification shouldn't be the problem. Below is the changes reserved memory map from our dts file:

    reserved-memory {
        #address-cells = <2>;
        #size-cells = <2>;
        ranges;

        /* global cma region */
        linux,cma {
            compatible = "shared-dma-pool";
            reusable;
            size = <0x00 0xc800000>;
            alloc-ranges = <0x00 0xb2800000 0x00 0xc800000>;
            linux,cma-default;
        };

        c7x_0_dma_memory_region: c7x-dma-memory@99800000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x99800000 0x00 0x100000>;
            no-map;
        };

        c7x_0_memory_region: c7x-memory@99900000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x99900000 0x00 0xf00000>;
            no-map;
        };

        mcu_r5fss0_core0_dma_memory_region: r5f-dma-memory@9b800000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9b800000 0x00 0x100000>;
            no-map;
        };

        mcu_r5fss0_core0_memory_region: r5f-dma-memory@9b900000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9b900000 0x00 0xf00000>;
            no-map;
        };

        wkup_r5fss0_core0_dma_memory_region: r5f-dma-memory@9c800000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9c800000 0x00 0x100000>;
            no-map;
        };

        wkup_r5fss0_core0_memory_region: r5f-dma-memory@9c900000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9c900000 0x00 0x1e00000>;
            no-map;
        };

        secure_tfa_ddr: tfa@9e780000 {
            reg = <0x00 0x9e780000 0x00 0x80000>;
            alignment = <0x1000>;
            no-map;
        };

        secure_ddr: optee@9e800000 {
            reg = <0x00 0x9e800000 0x00 0x01800000>; /* for OP-TEE */
            alignment = <0x1000>;
            no-map;
        };

        rtos_ipc_memory_region: ipc-memories@a0000000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0xa0000000 0x00 0x01000000>;
            no-map;
        };
    };


/* k3-am62a7-sk-edgeai.dtso change */
&{/reserved-memory} {
    #address-cells = <2>;
    #size-cells = <2>;
    ranges;

    edgeai_memory_region: edgeai-dma-memory@a1000000 {
        compatible = "shared-dma-pool";
        reg = <0x00 0xa1000000 0x00 0x02000000>;
        no-map;
    };

    edgeai_shared_region: edgeai_shared-memories {
        compatible = "dma-heap-carveout";
        reg = <0x00 0xa3000000 0x00 0x0ac00000>;
    };

    edgeai_core_heaps: edgeai-core-heap-memory@adc00000 {
        compatible = "shared-dma-pool";
        reg = <0x00 0xadc00000 0x00 0x4c00000>;
        no-map;
    };
};

Reese Grimsley said:

Which libraries have updated on your side? Nothing in edgeai-app-stack should have caused a change that will break IPC

Most of the libraries for base linux are changed (apart from edgeai-app-stack). Below are the few packages name that could impact the streaming:

systemd, glibc, glib-2.0, base-files, gstreamer-1.0 and it's plugins, busybox, ffmpeg, v4l2-utils, util-linux etc.

Can there be any role of the package "ti-librpmsg-dma" in the streaming issue?

Can we have a call to debug this issue remotely?

Regards,

Jay

Hi Jay,

Jay Kaneria said:

We don't see error when used above basic rpmsg command. Commands run successfully. See below output:

You're right; no issues here. Could still have some relation to memory map, but probably not for the basic IPC since those regions are untouched, based on your DTS.

Jay Kaneria said:

We are using the 1GB RAM instead of 4GB RAM. So, we have to modify the 2 memory region: 1) edgeai_core_heaps 2) linux,cma. 
But using this modified region, streaming works fine if we use rootfs from SDK-11. So, We think that memory region size modification shouldn't be the problem.

I'm almost in agreement here, but let me speak to the following on memory map still: 

Have you modified these in DTS without changing the firmwares or libtivision_apps.so? Linux-CMA is fine to modify only from DTS, but core heaps should not only be a DTS modification.

I can see how this may have worked for a simple application (v4l2->ISP->fakesink)  -- the default DDR map for those core heaps is covered by the DTS you show. Linux does not touch core heaps but the R5/VPAC firmware and C7x firmware will. Linux just needs to not touch that memory and the remote cores will just need that physical memory to exist. C7x memory is on the higher side of that overall carveout. 

Starting your CMA from 0xb280 0000 will probably conflict with what the C7x heap. See in the TIOVX logs:

[C7x_1 ]   1233.354769 s: MEM: Created heap (DDR_LOCAL_MEM, id=0, flags=0x00000004) @ b2000000 of size 117440512 bytes !!!

That heap size (and a DDR_C7X_1_SCRATCH that didn't print in the log) will conflict with your CMA pool starting a 0xb280 0000. I'm not sure if this is related to the problem at hand, that heap will have only small allocations until a TIDL / AI model is loaded to C7. There are some allocations by default, and it's possible there's a conflict. I'm not sure if CMA will have any allocations for the pipeline you show. 

Edit: Gstreamer could be using CMA pool for some of its allocations. Can you check before and after the hang for the output of `cat /proc/meminfo | grep -i cma` ? A conflict on this region is relevant. Still, you say that rootfs and yocto build have different behavior on the same pipeline, even for same DTS...

More pertinently, you say that the same DTS memory mapping works with rootfs... while the above comments are relevant, they may be tangential and more important for later.

Jay Kaneria said:

Most of the libraries for base linux are changed (apart from edgeai-app-stack). Below are the few packages name that could impact the streaming:

systemd, glibc, glib-2.0, base-files, gstreamer-1.0 and it's plugins, busybox, ffmpeg, v4l2-utils, util-linux etc.

It is a good idea to replace some of these libraries in your Yocto build with those from the SDK build, starting with those closest to gstreamer and v4l2 (so v4l2 utils, gstreamer-1.0, plugins (start from TI plugins). I may need to pull in some additional help here -- I have lesser knowledge on Yocto.

Jay Kaneria said:

Can there be any role of the package "ti-librpmsg-dma" in the streaming issue?

Worth investigating, yes. I'd suggest replacing this component as well

Jay Kaneria said:

Can we have a call to debug this issue remotely?

Let's go with the above approach for now, and we can schedule a call to dig into details - I think it would need to be next week. Let me identify another engineer who could assist where my knowledge gaps are. I am more accustomed to memory map, TIOVX itself, and remote-core build system... less so on Yocto

BR,
Reese

Hi Reese,

Thank you for your reply.

Reese Grimsley said:

Have you modified these in DTS without changing the firmwares or libtivision_apps.so? Linux-CMA is fine to modify only from DTS, but core heaps should not only be a DTS modification.

I can see how this may have worked for a simple application (v4l2->ISP->fakesink)  -- the default DDR map for those core heaps is covered by the DTS you show. Linux does not touch core heaps but the R5/VPAC firmware and C7x firmware will. Linux just needs to not touch that memory and the remote cores will just need that physical memory to exist. C7x memory is on the higher side of that overall carveout. 

Starting your CMA from 0xb280 0000 will probably conflict with what the C7x heap. See in the TIOVX logs:

[C7x_1 ]   1233.354769 s: MEM: Created heap (DDR_LOCAL_MEM, id=0, flags=0x00000004) @ b2000000 of size 117440512 bytes !!!

That heap size (and a DDR_C7X_1_SCRATCH that didn't print in the log) will conflict with your CMA pool starting a 0xb280 0000. I'm not sure if this is related to the problem at hand, that heap will have only small allocations until a TIDL / AI model is loaded to C7. There are some allocations by default, and it's possible there's a conflict. I'm not sure if CMA will have any allocations for the pipeline you show. 

Thank you for pointing out this. I have read the reserved memory modification from FIRMWARE BUILDER SDK documents. As you said, core heap memory could still overlap the CMA memory as i have only did change in the dts file and not in the firmwares as mentioned in FIRMWARE BUILDER SDK. So, What i did is that i have reversed change of heap core memory (made same as default dts file) and allocated CMA memory at different location. Please check below device tree and dmesg log for memory allocation:

    reserved-memory {
        #address-cells = <2>;
        #size-cells = <2>;
        ranges;

        /* global cma region */
        linux,cma {
            compatible = "shared-dma-pool";
            reusable;
            size = <0x00 0x6400000>;
            alloc-ranges = <0x00 0x93400000 0x00 0x6400000>;
            linux,cma-default;
        };

        c7x_0_dma_memory_region: c7x-dma-memory@99800000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x99800000 0x00 0x100000>;
            no-map;
        };

        c7x_0_memory_region: c7x-memory@99900000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x99900000 0x00 0xf00000>;
            no-map;
        };

        mcu_r5fss0_core0_dma_memory_region: r5f-dma-memory@9b800000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9b800000 0x00 0x100000>;
            no-map;
        };

        mcu_r5fss0_core0_memory_region: r5f-dma-memory@9b900000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9b900000 0x00 0xf00000>;
            no-map;
        };

        wkup_r5fss0_core0_dma_memory_region: r5f-dma-memory@9c800000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9c800000 0x00 0x100000>;
            no-map;
        };

        wkup_r5fss0_core0_memory_region: r5f-dma-memory@9c900000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0x9c900000 0x00 0x1e00000>;
            no-map;
        };

        secure_tfa_ddr: tfa@9e780000 {
            reg = <0x00 0x9e780000 0x00 0x80000>;
            alignment = <0x1000>;
            no-map;
        };

        secure_ddr: optee@9e800000 {
            reg = <0x00 0x9e800000 0x00 0x01800000>; /* for OP-TEE */
            alignment = <0x1000>;
            no-map;
        };

        rtos_ipc_memory_region: ipc-memories@a0000000 {
            compatible = "shared-dma-pool";
            reg = <0x00 0xa0000000 0x00 0x01000000>;
            no-map;
        };
    };
    
&{/reserved-memory} {
    #address-cells = <2>;
    #size-cells = <2>;
    ranges;

    edgeai_memory_region: edgeai-dma-memory@a1000000 {
        compatible = "shared-dma-pool";
        reg = <0x00 0xa1000000 0x00 0x02000000>;
        no-map;
    };

    edgeai_shared_region: edgeai_shared-memories {
        compatible = "dma-heap-carveout";
        reg = <0x00 0xa3000000 0x00 0x0ac00000>;
    };

    edgeai_core_heaps: edgeai-core-heap-memory@adc00000 {
        compatible = "shared-dma-pool";
        reg = <0x00 0xadc00000 0x00 0x12400000>;
        no-map;
    };
};


/* dmesg logs for reserved memory */
    0.000000] Reserved memory: created CMA memory pool at 0x0000000093400000, size 100 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x0000000093400000..0x00000000997fffff (102400 KiB) map reusable linux,cma
[    0.000000] OF: reserved mem: 0x000000009e800000..0x000000009fffffff (24576 KiB) nomap non-reusable optee@9e800000
[    0.000000] OF: reserved mem: 0x0000000080000000..0x000000008007ffff (512 KiB) nomap non-reusable tfa@80000000
[    0.000000] Reserved memory: created DMA memory pool at 0x00000000adc00000, size 292 MiB
[    0.000000] OF: reserved mem: initialized node edgeai-core-heap-memory@adc00000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x00000000adc00000..0x00000000bfffffff (299008 KiB) nomap non-reusable edgeai-core-heap-memory@adc00000
[    0.000000] OF: reserved mem: initialized node edgeai_shared-memories, compatible id dma-heap-carveout
[    0.000000] OF: reserved mem: 0x00000000a3000000..0x00000000adbfffff (176128 KiB) map non-reusable edgeai_shared-memories
[    0.000000] Reserved memory: created DMA memory pool at 0x00000000a1000000, size 32 MiB
[    0.000000] OF: reserved mem: initialized node edgeai-dma-memory@a1000000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x00000000a1000000..0x00000000a2ffffff (32768 KiB) nomap non-reusable edgeai-dma-memory@a1000000
[    0.000000] Reserved memory: created DMA memory pool at 0x0000000099800000, size 1 MiB
[    0.000000] OF: reserved mem: initialized node c7x-dma-memory@99800000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x0000000099800000..0x00000000998fffff (1024 KiB) nomap non-reusable c7x-dma-memory@99800000
[    0.000000] Reserved memory: created DMA memory pool at 0x0000000099900000, size 15 MiB
[    0.000000] OF: reserved mem: initialized node c7x-memory@99900000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x0000000099900000..0x000000009a7fffff (15360 KiB) nomap non-reusable c7x-memory@99900000
[    0.000000] Reserved memory: created DMA memory pool at 0x000000009b800000, size 1 MiB
[    0.000000] OF: reserved mem: initialized node r5f-dma-memory@9b800000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x000000009b800000..0x000000009b8fffff (1024 KiB) nomap non-reusable r5f-dma-memory@9b800000
[    0.000000] Reserved memory: created DMA memory pool at 0x000000009b900000, size 15 MiB
[    0.000000] OF: reserved mem: initialized node r5f-dma-memory@9b900000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x000000009b900000..0x000000009c7fffff (15360 KiB) nomap non-reusable r5f-dma-memory@9b900000
[    0.000000] Reserved memory: created DMA memory pool at 0x000000009c800000, size 1 MiB
[    0.000000] OF: reserved mem: initialized node r5f-dma-memory@9c800000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x000000009c800000..0x000000009c8fffff (1024 KiB) nomap non-reusable r5f-dma-memory@9c800000
[    0.000000] Reserved memory: created DMA memory pool at 0x000000009c900000, size 30 MiB
[    0.000000] OF: reserved mem: initialized node r5f-dma-memory@9c900000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x000000009c900000..0x000000009e6fffff (30720 KiB) nomap non-reusable r5f-dma-memory@9c900000
[    0.000000] Reserved memory: created DMA memory pool at 0x00000000a0000000, size 16 MiB
[    0.000000] OF: reserved mem: initialized node ipc-memories@a0000000, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x00000000a0000000..0x00000000a0ffffff (16384 KiB) nomap non-reusable ipc-memories@a0000000
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000080000000-0x00000000bfffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000080000000-0x000000008007ffff]
[    0.000000]   node   0: [mem 0x0000000080080000-0x00000000997fffff]
[    0.000000]   node   0: [mem 0x0000000099800000-0x000000009a7fffff]
[    0.000000]   node   0: [mem 0x000000009a800000-0x000000009b7fffff]
[    0.000000]   node   0: [mem 0x000000009b800000-0x000000009e6fffff]
[    0.000000]   node   0: [mem 0x000000009e700000-0x000000009e7fffff]
[    0.000000]   node   0: [mem 0x000000009e800000-0x00000000a2ffffff]
[    0.000000]   node   0: [mem 0x00000000a3000000-0x00000000adbfffff]
[    0.000000]   node   0: [mem 0x00000000adc00000-0x00000000bfffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x00000000bfffffff]

With default memory map (except CMA memory), we are having the same issue. Also, I have confirmed that pipeline hardly use the 10MiB of CMA memory when running(when pipeline get stuck). Please check the below CMA memory before and during the pipeline is running.

CMA memory befor running pipeline

~ # cat /proc/meminfo | grep -i cma
CmaTotal:         102400 kB
CmaFree:           91024 kB


CMA memory while running pipeline

~ # cat /proc/meminfo | grep -i cma
CmaTotal:         102400 kB
CmaFree:           84540 kB

So, Now it doesn't look like that pipeline is failing due to the reserved memory changes. But let us know if you observe anything unusual from above logs.

Reese Grimsley said:

It is a good idea to replace some of these libraries in your Yocto build with those from the SDK build, starting with those closest to gstreamer and v4l2 (so v4l2 utils, gstreamer-1.0, plugins (start from TI plugins). I may need to pull in some additional help here -- I have lesser knowledge on Yocto.

OK. We will check on this point.

Also, we have also checked that "ti-librpmsg-dma" library has no role in the streaming with ISP. We have delete the library on the working board and streaming was still working.

Regards,

Jay

Hi Jay,

Thanks for the continued effort and patience here. I think we can rule out CMA as the root cause at this point. The general memory map looks fine to me in DTS. 

• One change in 11.1 was an additional DDR carveout / heap for DDR_DM_R5F_VISS_CONFIG_HEAP, but that looks to be accounted for in your system. I see that second heap entry for the vx_app_heap_stats.out utility, and the start of your core heaps in DTS also reflects where that heap (the first of several) starts

And since you are using the default tiboot3.bin (which has that R5 firmware that manages ISP), the memory map on that core should also be correct. For fair comparisons, I want to be sure that is the same binary (and other portions of the BOOT partition) as what's in stock 11.1 SDK from TI. Then we can rule out any differences in firmware, and focus on Linux/Yocto only

It is interesting that VISS / ISP fails, but multiscaler / MSC does not...

Jay Kaneria said:

Also, we have also checked that "ti-librpmsg-dma

Okay, we can look beyond that one too then.

Two requests for more info now: 

Can you run `gst-inspect-1.0 tiovxisp` and report the output to me? I want to compare this exactly to the printout for the SDK

Can you provide your modified yocto layers or otherwise relevant recipes? Please inform if that is an edited version of meta-edgeai or something entirely custom

I think it is also worthwhile to run the TIOVX conformance tests, especially for the /opt/vision_apps/vx_app_conformance_hwa.out. You will need that test dataset extracted and source vision_apps_init.sh before running conformance. 

./vx_app_conformance_hwa.out --filter=*VISS*

We can also replace the VISS with "MSC" or "LDC" to test the other relevant accelerators on the same core

Hi Reese, 

Thank you for your support on this case.

Reese Grimsley said:

And since you are using the default tiboot3.bin (which has that R5 firmware that manages ISP), the memory map on that core should also be correct. For fair comparisons, I want to be sure that is the same binary (and other portions of the BOOT partition) as what's in stock 11.1 SDK from TI. Then we can rule out any differences in firmware, and focus on Linux/Yocto only

Yes, we are using the tiboot3, tispl, u-boot and related firmware from stock SDK-11(Also Linux kernel is from stock SDK-11). Only change in the bootloaders is related to DDR. We are using 1GB DDR. So, those changes has to be done in bootloaders. Apart from this, there is not change and bootloaders are from stock SDK-11.

Reese Grimsley said:

Can you run `gst-inspect-1.0 tiovxisp` and report the output to me? I want to compare this exactly to the printout for the SDK

Below is the output of "gst-inspect-1.0 tiovxisp":

PP: Init ... !!!
  2118.160817 s: MEM: Init ... !!!
  2118.160849 s: MEM: Initialized DMA HEAP (fd=5) !!!
  2118.160975 s: MEM: Init ... Done !!!
  2118.160981 s: IPC: Init ... !!!
  2118.180919 s: IPC: Init ... Done !!!
REMOTE_SERVICE: Init ... !!!
REMOTE_SERVICE: Init ... Done !!!
  2118.186025 s: GTC Frequency = 200 MHz
APP: Init ... Done !!!
  2118.186190 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_ERROR
  2118.186200 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_WARNING
  2118.186205 s:  VX_ZONE_INFO: Globally Enabled VX_ZONE_INFO
  2118.186883 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-0
  2118.187041 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-1
  2118.187258 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-2
  2118.187391 s:  VX_ZONE_INFO: [tivxPlatformCreateTargetId:169] Added target MPU-3
  2118.187399 s:  VX_ZONE_INFO: [tivxInitLocal:202] Initialization Done !!!
  2118.187405 s:  VX_ZONE_INFO: Globally Disabled VX_ZONE_INFO
Factory Details:
  Rank                     none (0)
  Long-name                TIOVX ISP
  Klass                    Filter
  Description              Image Signal Processing using the TIOVX Modules API
  Author                   RidgeRun <support@ridgerun.com>

Plugin Details:
  Name                     tiovx
  Description              GStreamer plugin for TIOVX
  Filename                 /usr/lib/gstreamer-1.0/libgsttiovx.so
  Version                  0.7.0
  License                  Proprietary
  Source module            GstTIOVX
  Binary package           GstTIOVX source release
  Origin URL               http://ti.com

GObject
 +----GInitiallyUnowned
       +----GstObject
             +----GstElement
                   +----GstAggregator
                         +----GstTIOVXMiso
                               +----GstTIOVXISP

Implemented Interfaces:
  GstChildProxy

Pad Templates:
  SINK template: 'sink_%u'
    Availability: On request
    Capabilities:
      video/x-bayer
                 format: { (string)bggr, (string)gbrg, (string)grbg, (string)rggb, (string)bggr10, (string)gbrg10, (string)grbg10, (string)rggb10, (string)rggi10, (string)grig10, (string)bggi10, (string)gbig10, (string)girg10, (string)iggr10, (string)gibg10, (string)iggb10, (string)bggr12, (string)gbrg12, (string)grbg12, (string)rggb12, (string)bggr16, (string)gbrg16, (string)grbg16, (string)rggb16 }
                  width: [ 1, 8192 ]
                 height: [ 1, 8192 ]
    Type: GstTIOVXIspPad
    Pad Properties:

      ae-mode             : Flag to set if the auto exposure algorithm mode.
                            flags: readable, writable, controllable, changeable only in NULL or READY state
                            Enum "GstTIOVXISPAEModes" Default: 0, "AE_MODE_AUTO"
                               (0): AE_MODE_AUTO     - AE mode auto
                               (1): AE_MODE_MANUAL   - AE mode manual
                               (2): AE_MODE_DISABLED - AE mode disabled

      ae-num-skip-frames  : To indicate the AE algorithm how often to process frames, 0 means every frame.
                            flags: readable, writable, controllable, changeable only in NULL or READY state
                            Unsigned Integer. Range: 0 - 4294967295 Default: 0

      awb-mode            : Flag to set if the auto white balance algorithm mode.
                            flags: readable, writable, controllable, changeable only in NULL or READY state
                            Enum "GstTIOVXISPAWBModes" Default: 0, "AWB_MODE_AUTO"
                               (0): AWB_MODE_AUTO    - AWB mode auto
                               (1): AWB_MODE_MANUAL  - AWB mode manual
                               (2): AWB_MODE_DISABLED - AWB mode disabled

      awb-num-skip-frames : To indicate the AWB algorithm how often to process frames, 0 means every frame.
                            flags: readable, writable, controllable, changeable only in NULL or READY state
                            Unsigned Integer. Range: 0 - 4294967295 Default: 0

      dcc-2a-file         : TIOVX DCC tuning binary file for the given image sensor.
                            flags: readable, writable, changeable only in NULL or READY state
                            String. Default: null

      device              : Device location, e.g, /dev/v4l-subdev1.Required by the user to use the sensor IOCTL support
                            flags: readable, writable, changeable only in NULL or READY state
                            String. Default: null

      emit-signals        : Send signals to signal data consumption
                            flags: readable, writable
                            Boolean. Default: false

      pool-size           : Pool size of the internal buffer pool
                            flags: readable, writable, controllable
                            Integer. Range: 2 - 16 Default: 2

      repeat-after-eos    : Flag to indicate if the pad will repeat the last buffer after an EOS is received. Only valid for sink pads
                            flags: readable, writable, controllable
                            Boolean. Default: true


  SRC template: 'src'
    Availability: Always
    Capabilities:
      video/x-raw
                 format: { (string)NV12, (string)GRAY8 }
                  width: [ 1, 8192 ]
                 height: [ 1, 8192 ]
      video/x-raw(memory:batched)
                 format: { (string)NV12, (string)GRAY8 }
                  width: [ 1, 8192 ]
                 height: [ 1, 8192 ]
           num-channels: [ 2, 16 ]
    Type: GstTIOVXMisoPad
    Pad Properties:

      emit-signals        : Send signals to signal data consumption
                            flags: readable, writable
                            Boolean. Default: false

      pool-size           : Pool size of the internal buffer pool
                            flags: readable, writable, controllable
                            Integer. Range: 2 - 16 Default: 2

      repeat-after-eos    : Flag to indicate if the pad will repeat the last buffer after an EOS is received. Only valid for sink pads
                            flags: readable, writable, controllable
                            Boolean. Default: true


Element has no clocking capabilities.
Element has no URI handling capabilities.

Pads:
  SRC: 'src'
    Pad Template: 'src'

Element Properties:

  bypass-cac          : Set to bypass chromatic aberation correction (CAC)
                        flags: readable, writable, changeable only in NULL or READY state
                        Boolean. Default: true

  bypass-dwb          : Set to bypass dynamic white balance (DWB)
                        flags: readable, writable, changeable only in NULL or READY state
                        Boolean. Default: true

  bypass-nsf4         : Set to bypass Noise Filtering
                        flags: readable, writable, changeable only in NULL or READY state
                        Boolean. Default: false

  dcc-isp-file        : TIOVX DCC tuning binary file for the given image sensor.
                        flags: readable, writable, changeable only in NULL or READY state
                        String. Default: null

  ee-mode             : Flag to set Edge Enhancement mode.
                        flags: readable, writable, controllable, changeable only in NULL or READY state
                        Enum "GstTIOVXISPEEModes" Default: 0, "EE_MODE_OFF"
                           (0): EE_MODE_OFF      - EE mode off
                           (1): EE_MODE_Y12      - Edge Enhancer is enabled on Y12 output (output0)
                           (2): EE_MODE_Y8       - Edge Enhancer is enabled on Y8 output (output2)

  emit-signals        : Send signals
                        flags: readable, writable
                        Boolean. Default: false

  format-msb          : Flag indicating which is the most significant bit that still has data.
                        flags: readable, writable, controllable, changeable only in NULL or READY state
                        Integer. Range: 1 - 16 Default: 7

  latency             : Additional latency in live mode to allow upstream to take longer to produce buffers for the current position (in nanoseconds)
                        flags: readable, writable
                        Unsigned Integer64. Range: 0 - 18446744073709551615 Default: 0

  lines-interleaved   : Flag to indicate if lines are interleaved.
                        flags: readable, writable, controllable, changeable only in NULL or READY state
                        Boolean. Default: false

  min-upstream-latency: When sources with a higher latency are expected to be plugged in dynamically after the aggregator has started playing, this allows overriding the minimum latency reported by the initial source(s). This is only taken into account when larger than the actually reported minimum latency. (nanoseconds)
                        flags: readable, writable
                        Unsigned Integer64. Range: 0 - 18446744073709551615 Default: 0

  name                : The name of the object
                        flags: readable, writable
                        String. Default: "tiovxisp0"

  num-exposures       : Number of exposures for the incoming raw image.
                        flags: readable, writable, controllable, changeable only in NULL or READY state
                        Integer. Range: 1 - 4 Default: 1

  parent              : The parent of the object
                        flags: readable, writable
                        Object of type "GstObject"

  sensor-name         : TIOVX camera sensor string ID. Below are the supported sensors
                                   SENSOR_SONY_IMX390_UB953_D3
                                   SENSOR_ONSEMI_AR0820_UB953_LI
                                   SENSOR_ONSEMI_AR0233_UB953_MARS
                                   SENSOR_SONY_IMX219_RPI
                                   SENSOR_SONY_IMX728_UB971_D3
                                   SENSOR_OX05B1S
                                   SENSOR_OV2312_UB953_LI
                        flags: readable, writable, changeable only in NULL or READY state
                        String. Default: "SENSOR_SONY_IMX219_RPI"

  start-time          : Start time to use if start-time-selection=set
                        flags: readable, writable
                        Unsigned Integer64. Range: 0 - 18446744073709551615 Default: 18446744073709551615

  start-time-selection: Decides which start time is output
                        flags: readable, writable
                        Enum "GstAggregatorStartTimeSelection" Default: 0, "zero"
                           (0): zero             - GST_AGGREGATOR_START_TIME_SELECTION_ZERO
                           (1): first            - GST_AGGREGATOR_START_TIME_SELECTION_FIRST
                           (2): set              - GST_AGGREGATOR_START_TIME_SELECTION_SET

  target              : TIOVX target to use by this element.
                        flags: readable, writable, controllable, changeable only in NULL or READY state
                        Enum "GstTIOVXISPTarget" Default: 0, "VPAC_VISS1"
                           (0): VPAC_VISS1       - VPAC VISS1

  wdr-enabled         : Set if Camera wdr mode is enabled
                        flags: readable, writable, changeable only in NULL or READY state
                        Boolean. Default: false


Element Signals:

  "samples-selected" :  void user_function (GstElement * object,
                                            GstSegment * arg0,
                                            guint64 arg1,
                                            guint64 arg2,
                                            guint64 arg3,
                                            GstStructure * arg4,
                                            gpointer user_data);

  2118.208223 s:  VX_ZONE_ERROR: [vxGetStatus:1250] Reference is NULL
APP: Deinit ... !!!
REMOTE_SERVICE: Deinit ... !!!
REMOTE_SERVICE: Deinit ... Done !!!
  2118.213183 s: IPC: Deinit ... !!!
  2118.213596 s: IPC: DeInit ... Done !!!
  2118.213607 s: MEM: Deinit ... !!!
  2118.213611 s: DDR_SHARED_MEM: Alloc's: 0 alloc's of 0 bytes
  2118.213616 s: DDR_SHARED_MEM: Free's : 0 free's  of 0 bytes
  2118.213620 s: DDR_SHARED_MEM: Open's : 0 allocs  of 0 bytes
  2118.213630 s: MEM: Deinit ... Done !!!
APP: Deinit ... Done !!!

Reese Grimsley said:

Can you provide your modified yocto layers or otherwise relevant recipes? Please inform if that is an edited version of meta-edgeai or something entirely custom

Below are the packages which are different from the SDK11. These package are from debian releases. We are using the "meta-edgeai" layer (entire layer) from SDK-11 without modifying any recipes.

iniparser
gstreamer1.0
libssh2-1
gstreamer1.0-plugins-bad
glib-2.0
glibc
ltrace
zlib
iproute2/			
util-linux			
libacl1/			
libjson-c5			
iperf3/				
libcjson1/			
stress-ng/			
gstreamer1.0-plugins-good
rpcbind/			
curl/				
base-passwd/		
libubootenv/		
libnettle8/			
zstd/				
iptables/			
libtirpc3/			
boot-complete/		
glibc-locale/		
mosquitto/			
openssh-server/		
libgpiod/			
libconfig9/			
systemd/			
m4/					
sqlite3/			
file/				
libdaemon/			
swupdate/			
expat/				
uthash/				
libaio1/			
libevent/			
lvm2/				
avahi/				
mtd-utils/			
tzdata/				
libffi/				
lua5.3/				
libattr1/			
liblz4-1/			
bridge-utils/		
liblzo2-2/			
libgmp/				
libarchive13/		
kexec-tools/		
libgpg-error0/		
libcap2/			
libev4/				
libnsl2/			
libmnl0/			
nss-mdns/			
i2c-tools/			
libpciaccess0/		
libiberty/			
xz-utils/			
can-utils/			
mmc-utils/			
libpcap0.8/			
passwordless-root/	
libuv1/				
tcpdump/			
haproxy/			
dosfstools/			
linuxptp/			
v4l-utils/			
apparmor/			
busybox/			
util-linux-libuuid/	
nano/				
shadow/				
e2fsprogs/			
libxml2/			
libpthread-stubs0/	
xutils-dev/			
gstreamer1.0-plugins-base
libncurses6/		
ti-rpmsg-char/0.6.9+
libc-ares2/			
libwebsockets/		
libpcre2
elfutils
spi-tools
bash
bzip2
valgrind			
ethtool			
openssl			
dbus			
base-files		
uboot-image
glib-2.0-native
genimage-native
openssl-native
libncurses6-native
e2fsprogs-native
sqlite3-native
libgpg-error0-native
libgcrypt20-native
libc-ares2-native
cross-localedef-native
gettext-native
libpcre2-native
zlib-native
util-linux-libuuid-native
xutils-dev-native
xxd-native
gperf-native
flex-native
libconfuse-native
zstd-native
libgmp-native
libffi-native
libssh2-1-native
rsync-native
curl-native
shadow-native
libnsl2-native
elfutils-native
file-native
expat-native
util-linux-native

Reese Grimsley said:

I think it is also worthwhile to run the TIOVX conformance tests, especially for the /opt/vision_apps/vx_app_conformance_hwa.out. You will need that test dataset extracted and source vision_apps_init.sh before running conformance. 

I have performed the conformance test with VISS, MSC and LDC. Below are the logs of the same.

comformance_test_VISS.txt

conformance_test_log_LDC.txt

conformance_test_log_MSC.txt

Let us know if any additional information is required from our side.

Regards,

Jay

Hi Jay, 

I will do some analysis on what you provided and get back tomorrow or early next week. 

On the conformance tests, I see several pass, but generally failures come from missing input files. Are those present in the fileystem under /opt/vision_apps/test_data, like "/opt/vision_apps/test_data/output/viss_out.yuv"? 

The dataset is in my secure (and a repo in TI's CGIT), but I'll also just attach to this thread for convenience.

psdk_rtos_ti_data_set_11_01_00.tar.gz

Hi Jay,

I don't see anything in the tiovxisp gst-inspect that tips me off to an issue. That seems fine...

Jay Kaneria said:

I have performed the conformance test with VISS, MSC and LDC. Below are the logs of the same.

comformance_test_VISS.txt

conformance_test_log_LDC.txt

conformance_test_log_MSC.txt

Let us know if any additional informat

I'm not so worried about MSC or LDC (not tested, but should be same story as MSC), moreso VISS. Most test cases require test-data, but at least the simplest tests requiring no file IO are behaving as normal (first test and NegativeGraph tests). It's also possible the test data is present but the right ENV variable is not set. 

$ source /opt/vision_apps/vision_apps_init.sh
$ env | grep DATA
TIAP_DATABASE_PATH=/opt/vision_apps/test_data_ptk
VX_TEST_DATA_PATH=/opt/vision_apps/test_data

What is the gstreamer version you are using? I would suggest make an image with your build, but replace all the gstreamer libraries with SDK rootfs version. You may start with replacing the TI library /usr/lib/gstreamer-1.0/libgsttiovx.so (and libgstti.so, but non-tiovx plugins aren't the problematic ones)

I'd like to see some logging from gst-launch-1.0 with much higher debug level, like 6=LOG, which should show per-frame logging. Could you run something like the following? Let's limit to just a few frames; it will likely hang before that in your system. 

GST_DEBUG=2,*tiovx*:6 gst-launch-1.0 videotestsrc num-buffers=10 ! \
video/x-bayer,width=1920,height=1200, format=rggb ! \
tiovxisp sensor-name=SENSOR_SONY_IMX219_RPI dcc-isp-file=/opt/imaging/imx219/linear/dcc_viss_1920x1080.bin sink_0::dcc-2a-file=/opt/imaging/imx219/linear/dcc_2a_1920x1080.bin sink_0::device=/dev/v4l-subdev2 format-msb=7 ! \
video/x-raw,format=NV12 ! fakesink

BR,
Reese

Yes, Gstreamer plugin "tiovxisp" supports changing ee-mode to Y8 in SDK 11.1:

root@am62axx-evm:/opt/edgeai-gst-apps# gst-inspect-1.0 tiovxisp
...
...
  ee-mode             : Flag to set Edge Enhancement mode.
                        flags: readable, writable, controllable, changeable only in NULL or READY state
                        Enum "GstTIOVXISPEEModes" Default: 0, "EE_MODE_OFF"
                           (0): EE_MODE_OFF      - EE mode off
                           (1): EE_MODE_Y12      - Edge Enhancer is enabled on Y12 output (output0)
                           (2): EE_MODE_Y8       - Edge Enhancer is enabled on Y8 output (output2)

Hi Reese, 

We have added this patch on our side as we were adding this in SDK9 and SDK10. But as Jianzhong mentioned, SDK11 has this support bydefault.

Regards,

Jay