Gstreamer and v4l2 does not work when running to cameras concurrently at the same DPHY

Hi JerryChang

Continuing the discussion from Gstreamer does not work with more then 2 nvarguscamerasrc's:

Do to the work load I had to put this topic by side for a while. But now I’m back :-)

I have compared the tegra234-camera-e3333-a00.dtsi and the nv_ov5693.c kernel driver (six 2-lane camera setup) whit my sources. Couldn’t find any helpfully differences between them.

The trace log with enhanced debug enabled does not response any helpfully information. I doesn’t have any idea where else I should look to dig deeper to the root cause of my problem.

Trace Log:

# tracer: nop
#
# entries-in-buffer/entries-written: 691/691   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
     kworker/1:8-166     [001] ....  1793.086861: rtcpu_string: tstamp:56514048035 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-1900    [003] ....  1808.580797: tegra_channel_open: vi-output, ar0234 30-0018
        v4l2-ctl-1900    [003] ....  1808.589949: tegra_channel_set_power: ar0234 30-0018 : 0x1
        v4l2-ctl-1900    [003] ....  1808.589961: camera_common_s_power: status : 0x1
        v4l2-ctl-1900    [003] ....  1808.603295: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-1900    [003] ....  1808.603298: csi_s_power: enable : 0x1
        v4l2-ctl-1900    [003] ....  1808.603960: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1200 fmt c4
        v4l2-ctl-1900    [003] ....  1808.623433: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-1900    [003] ....  1808.646627: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-1900    [003] ....  1808.646630: csi_s_stream: enable : 0x1
        v4l2-ctl-1900    [003] ....  1808.647037: tegra_channel_set_stream: ar0234 30-0018 : 0x1
     kworker/1:8-166     [001] ....  1808.654847: rtcpu_string: tstamp:56999532429 id:0x04010000 str:"VM0 activating."
     kworker/1:8-166     [001] ....  1808.654849: rtcpu_string: tstamp:56999662836 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
     kworker/1:8-166     [001] ....  1808.654858: rtcpu_vinotify_event: tstamp:57000264299 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1823993209376 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1808.654859: rtcpu_vinotify_event: tstamp:57000264506 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1823993215808 data:0x0000000031000001
     kworker/1:8-166     [001] ....  1808.654859: rtcpu_vinotify_event: tstamp:57000264706 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1823993276640 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1808.654859: rtcpu_vinotify_event: tstamp:57000264877 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1823993283232 data:0x0000000031000002
     kworker/1:8-166     [001] ....  1808.654860: rtcpu_string: tstamp:57000536647 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=2, csi"
     kworker/1:8-166     [001] ....  1808.654861: rtcpu_string: tstamp:57000536752 id:0x04010000 str:"=2)
"
     kworker/1:8-166     [001] ....  1808.654865: rtcpu_string: tstamp:57000537139 id:0x04010000 str:"MIPI clock = 750000 kHz, tHS-SETTLE = 130, tCLK-"
     kworker/1:8-166     [001] ....  1808.654866: rtcpu_string: tstamp:57000537241 id:0x04010000 str:"SETTLE = 0
"
     kworker/1:8-166     [001] ....  1808.654870: rtcpu_string: tstamp:57000537452 id:0x04010000 str:"===== NVCSI Stream Configuration =====
"
     kworker/1:8-166     [001] ....  1808.654874: rtcpu_string: tstamp:57000537700 id:0x04010000 str:"stream_id: PP 2, csi_port: PORT C
"
     kworker/1:8-166     [001] ....  1808.654878: rtcpu_string: tstamp:57000537958 id:0x04010000 str:"Brick: PHY 1, Mode: D-PHY
"
     kworker/1:8-166     [001] ....  1808.654881: rtcpu_string: tstamp:57000538240 id:0x04010000 str:"Partition: CIL A, LP bypass: Enabled, Lanes: 2
"
     kworker/1:8-166     [001] ....  1808.654885: rtcpu_string: tstamp:57000538420 id:0x04010000 str:"Clock information:
"
     kworker/1:8-166     [001] ....  1808.654888: rtcpu_string: tstamp:57000538719 id:0x04010000 str:"MIPI clock rate: 750.00 MHz
"
     kworker/1:8-166     [001] ....  1808.654891: rtcpu_string: tstamp:57000538971 id:0x04010000 str:"T_HS settle: 130, T_CLK settle: 0
"
     kworker/1:8-166     [001] ....  1808.654893: rtcpu_string: tstamp:57000539194 id:0x04010000 str:"======================================
"
     kworker/1:8-166     [001] ....  1808.654896: rtcpu_string: tstamp:57000540922 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=2, csi=2)
"
     kworker/1:8-166     [001] ....  1808.654898: rtcpu_string: tstamp:57000547491 id:0x04010000 str:"nvcsi_calc_tclk_settle tclk_settle 75
"
 vi-output, ar02-1902    [006] ....  1809.270060: tegra_channel_capture_frame: sof:1824.607533824
 vi-output, ar02-1902    [006] ....  1809.270063: tegra_channel_capture_frame: eof:1824.640168832
     kworker/1:8-166     [001] ....  1809.270854: rtcpu_vinotify_event: tstamp:57019252866 cch:0 vi:1 tag:FS channel:0x00 frame:1 vi_tstamp:1824607531136 data:0x0000000100000012
     kworker/1:8-166     [001] ....  1809.270857: rtcpu_vinotify_event: tstamp:57019253004 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1824607531200 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1809.270857: rtcpu_vinotify_event: tstamp:57019253159 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:1 vi_tstamp:1824607533824 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1809.270858: rtcpu_vinotify_event: tstamp:57019253295 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:1 vi_tstamp:1824607572576 data:0x0000000008020001
     kworker/1:8-166     [001] ....  1809.326837: rtcpu_vinotify_event: tstamp:57020338009 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:1 vi_tstamp:1824640167808 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1809.326839: rtcpu_vinotify_event: tstamp:57020338150 cch:0 vi:1 tag:FE channel:0x00 frame:1 vi_tstamp:1824640168576 data:0x0000000100000022
     kworker/1:8-166     [001] ....  1809.326840: rtcpu_vinotify_event: tstamp:57020338307 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1824640168672 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1809.326841: rtcpu_vinotify_event: tstamp:57020338439 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:1 vi_tstamp:1824640168832 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1809.326841: rtcpu_vinotify_event: tstamp:57020338591 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:1 vi_tstamp:1824640221088 data:0x0000000002020001
     kworker/1:8-166     [001] ....  1809.326842: rtcpu_vinotify_event: tstamp:57020338727 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:1 vi_tstamp:1824640237504 data:0x0000000000020001
 vi-output, ar02-1902    [006] ....  1809.370194: tegra_channel_capture_frame: sof:1824.707520992
 vi-output, ar02-1902    [006] ....  1809.370197: tegra_channel_capture_frame: eof:1824.740156064
    .
    .
    .
    .
    
 vi-output, ar02-1902    [006] ....  1809.970157: tegra_channel_capture_frame: sof:1825.307444192
 vi-output, ar02-1902    [006] ....  1809.970159: tegra_channel_capture_frame: eof:1825.340079232
     kworker/1:8-166     [001] ....  1809.998855: rtcpu_vinotify_event: tstamp:57041884963 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:8 vi_tstamp:1825340078208 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1809.998857: rtcpu_vinotify_event: tstamp:57041885095 cch:0 vi:1 tag:FE channel:0x00 frame:8 vi_tstamp:1825340078976 data:0x0000000800000022
     kworker/1:8-166     [001] ....  1809.998857: rtcpu_vinotify_event: tstamp:57041885248 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:8 vi_tstamp:1825340079072 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1809.998858: rtcpu_vinotify_event: tstamp:57041885379 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:8 vi_tstamp:1825340079232 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1809.998858: rtcpu_vinotify_event: tstamp:57042393106 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:8 vi_tstamp:1825340139712 data:0x0000000002020008
     kworker/1:8-166     [001] ....  1809.998859: rtcpu_vinotify_event: tstamp:57042393240 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:8 vi_tstamp:1825340156416 data:0x0000000000020008
        v4l2-ctl-1903    [007] ....  1810.030921: tegra_channel_open: vi-output, ar0234 31-0018
        v4l2-ctl-1903    [007] ....  1810.035337: tegra_channel_set_power: ar0234 31-0018 : 0x1
        v4l2-ctl-1903    [007] ....  1810.035344: camera_common_s_power: status : 0x1
        v4l2-ctl-1903    [007] ....  1810.048672: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-1903    [007] ....  1810.048674: csi_s_power: enable : 0x1
        v4l2-ctl-1903    [007] ....  1810.048775: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1200 fmt c4
        v4l2-ctl-1903    [007] ....  1810.049102: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-1903    [007] ....  1810.050746: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-1903    [007] ....  1810.050747: csi_s_stream: enable : 0x1
        v4l2-ctl-1903    [007] ....  1810.050913: tegra_channel_set_stream: ar0234 31-0018 : 0x1
     kworker/1:8-166     [001] ....  1810.054842: rtcpu_vinotify_event: tstamp:57044020093 cch:0 vi:1 tag:FS channel:0x00 frame:9 vi_tstamp:1825407428736 data:0x0000000900000012
     kworker/1:8-166     [001] ....  1810.054843: rtcpu_vinotify_event: tstamp:57044020231 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:9 vi_tstamp:1825407428800 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1810.054843: rtcpu_vinotify_event: tstamp:57044020383 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:9 vi_tstamp:1825407431424 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1810.054843: rtcpu_vinotify_event: tstamp:57044020514 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:9 vi_tstamp:1825407470208 data:0x0000000008020009
     kworker/1:8-166     [001] ....  1810.054843: rtcpu_vinotify_event: tstamp:57044020663 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1825407708704 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1810.054844: rtcpu_vinotify_event: tstamp:57044020799 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1825407752096 data:0x000000003100000a
     kworker/1:8-166     [001] ....  1810.054845: rtcpu_string: tstamp:57044415259 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=3, csi"
     kworker/1:8-166     [001] ....  1810.054845: rtcpu_string: tstamp:57044415364 id:0x04010000 str:"=3)
"



     kworker/1:8-166     [001] ....  1810.054850: rtcpu_string: tstamp:57044418218 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=3, csi=3)
"
 vi-output, ar02-1902    [006] ....  1810.069929: tegra_channel_capture_frame: sof:1825.407431424
 vi-output, ar02-1902    [006] ....  1810.069930: tegra_channel_capture_frame: eof:1825.440066432
     kworker/1:8-166     [001] ....  1810.110841: rtcpu_vinotify_event: tstamp:57044563315 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1825419810080 data:0x759e2a0010000000
     kworker/1:8-166     [001] ....  1810.110842: rtcpu_vinotify_event: tstamp:57044563452 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1825419853344 data:0x0000000031000001
     kworker/1:8-166     [001] ....  1810.110842: rtcpu_vinotify_event: tstamp:57044563605 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1825419870976 data:0x759e270010000000
     kworker/1:8-166     [001] ....  1810.110843: rtcpu_vinotify_event: tstamp:57044563740 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1825419931904 data:0x0000000031000002
     kworker/1:8-166     [001] ....  1810.110843: rtcpu_vinotify_event: tstamp:57045009606 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:9 vi_tstamp:1825440065408 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1810.110844: rtcpu_vinotify_event: tstamp:57045009741 cch:0 vi:1 tag:FE channel:0x00 frame:9 vi_tstamp:1825440066176 data:0x0000000900000022
     kworker/1:8-166     [001] ....  1810.110844: rtcpu_vinotify_event: tstamp:57045009897 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:9 vi_tstamp:1825440066272 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1810.110845: rtcpu_vinotify_event: tstamp:57045010032 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:9 vi_tstamp:1825440066432 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1810.110845: rtcpu_vinotify_event: tstamp:57045539859 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:9 vi_tstamp:1825440126912 data:0x0000000002020009
     kworker/1:8-166     [001] ....  1810.110845: rtcpu_vinotify_event: tstamp:57045539997 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:9 vi_tstamp:1825440143584 data:0x0000000000020009
     kworker/1:8-166     [001] ....  1810.166837: rtcpu_vinotify_event: tstamp:57047166882 cch:0 vi:1 tag:FS channel:0x00 frame:10 vi_tstamp:1825507415904 data:0x0000000a00000012
     kworker/1:8-166     [001] ....  1810.166837: rtcpu_vinotify_event: tstamp:57047167023 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:10 vi_tstamp:1825507416032 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1810.166837: rtcpu_vinotify_event: tstamp:57047167175 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:10 vi_tstamp:1825507418592 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1810.166837: rtcpu_vinotify_event: tstamp:57047167306 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:10 vi_tstamp:1825507457440 data:0x000000000802000a
     kworker/1:8-166     [001] ....  1810.166837: rtcpu_vinotify_event: tstamp:57047167456 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1825507703584 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1810.166838: rtcpu_vinotify_event: tstamp:57047167589 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1825507747520 data:0x000000003100000b
 vi-output, ar02-1902    [006] ....  1810.169881: tegra_channel_capture_frame: sof:1825.507418592
 vi-output, ar02-1902    [006] ....  1810.169882: tegra_channel_capture_frame: eof:1825.540053632
     kworker/1:8-166     [001] ....  1810.222848: rtcpu_vinotify_event: tstamp:57048251728 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:10 vi_tstamp:1825540052608 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1810.222849: rtcpu_vinotify_event: tstamp:57048251861 cch:0 vi:1 tag:FE channel:0x00 frame:10 vi_tstamp:1825540053376 data:0x0000000a00000022
     kworker/1:8-166     [001] ....  1810.222850: rtcpu_vinotify_event: tstamp:57048252015 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:10 vi_tstamp:1825540053472 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1810.222851: rtcpu_vinotify_event: tstamp:57048252146 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:10 vi_tstamp:1825540053632 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1810.222851: rtcpu_vinotify_event: tstamp:57048252303 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:10 vi_tstamp:1825540105888 data:0x000000000202000a
     kworker/1:8-166     [001] ....  1810.222852: rtcpu_vinotify_event: tstamp:57048252438 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:10 vi_tstamp:1825540122336 data:0x000000000002000a
 vi-output, ar02-1902    [006] ....  1810.270080: tegra_channel_capture_frame: sof:1825.607405824
 vi-output, ar02-1902    [006] ....  1810.270082: tegra_channel_capture_frame: eof:1825.640040800
     kworker/1:8-166     [001] ....  1810.278854: rtcpu_vinotify_event: tstamp:57050239286 cch:0 vi:1 tag:FS channel:0x00 frame:11 vi_tstamp:1825607403104 data:0x0000000b00000012
     kworker/1:8-166     [001] ....  1810.278857: rtcpu_vinotify_event: tstamp:57050239423 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:11 vi_tstamp:1825607403200 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1810.278857: rtcpu_vinotify_event: tstamp:57050748054 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:11 vi_tstamp:1825607405824 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1810.278858: rtcpu_vinotify_event: tstamp:57050748189 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:11 vi_tstamp:1825607456992 data:0x000000000802000b
     kworker/1:8-166     [001] ....  1810.278859: rtcpu_vinotify_event: tstamp:57050748342 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1825607747488 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1810.278859: rtcpu_vinotify_event: tstamp:57050748474 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1825607791424 data:0x000000003100000c
     kworker/1:8-166     [001] ....  1810.278860: rtcpu_vinotify_event: tstamp:57051289877 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:11 vi_tstamp:1825640039808 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1810.278861: rtcpu_vinotify_event: tstamp:57051290013 cch:0 vi:1 tag:FE channel:0x00 frame:11 vi_tstamp:1825640040576 data:0x0000000b00000022
     kworker/1:8-166     [001] ....  1810.278861: rtcpu_vinotify_event: tstamp:57051290170 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:11 vi_tstamp:1825640040672 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1810.278862: rtcpu_vinotify_event: tstamp:57051290310 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:11 vi_tstamp:1825640040800 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1810.278862: rtcpu_vinotify_event: tstamp:57051290466 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:11 vi_tstamp:1825640093056 data:0x000000000202000b
     kworker/1:8-166     [001] ....  1810.278863: rtcpu_vinotify_event: tstamp:57051290598 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:11 vi_tstamp:1825640109504 data:0x000000000002000b
.
.
.
.
.
.
.
     kworker/1:8-166     [001] ....  1812.518848: rtcpu_vinotify_event: tstamp:57120518137 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:33 vi_tstamp:1827839836352 data:0x0000000000020021
 vi-output, ar02-1902    [006] ....  1812.569784: tegra_channel_capture_frame: sof:1827.907111424
 vi-output, ar02-1902    [006] ....  1812.569786: tegra_channel_capture_frame: eof:1827.939746400
     kworker/1:8-166     [001] ....  1812.574858: rtcpu_vinotify_event: tstamp:57122146306 cch:0 vi:1 tag:FS channel:0x00 frame:34 vi_tstamp:1827907108736 data:0x0000002200000012
     kworker/1:8-166     [001] ....  1812.574860: rtcpu_vinotify_event: tstamp:57122146445 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:34 vi_tstamp:1827907108800 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.574861: rtcpu_vinotify_event: tstamp:57122146598 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:34 vi_tstamp:1827907111424 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1812.574861: rtcpu_vinotify_event: tstamp:57122146730 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:34 vi_tstamp:1827907150208 data:0x0000000008020022
     kworker/1:8-166     [001] ....  1812.574862: rtcpu_vinotify_event: tstamp:57122146882 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1827907370656 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1812.574863: rtcpu_vinotify_event: tstamp:57122147014 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1827907414592 data:0x0000000031000023
     kworker/1:8-166     [001] ....  1812.574864: rtcpu_vinotify_event: tstamp:57123231052 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:34 vi_tstamp:1827939745408 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1812.574865: rtcpu_vinotify_event: tstamp:57123231218 cch:0 vi:1 tag:FE channel:0x00 frame:34 vi_tstamp:1827939746176 data:0x0000002200000022
     kworker/1:8-166     [001] ....  1812.574865: rtcpu_vinotify_event: tstamp:57123231375 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:34 vi_tstamp:1827939746272 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.574866: rtcpu_vinotify_event: tstamp:57123231508 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:34 vi_tstamp:1827939746400 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1812.574866: rtcpu_vinotify_event: tstamp:57123231663 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:34 vi_tstamp:1827939798688 data:0x0000000002020022
     kworker/1:8-166     [001] ....  1812.574867: rtcpu_vinotify_event: tstamp:57123231796 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:34 vi_tstamp:1827939815104 data:0x0000000000020022
 vi-output, ar02-1902    [006] ....  1812.669605: tegra_channel_capture_frame: sof:1828.7098592
 vi-output, ar02-1902    [006] ....  1812.669607: tegra_channel_capture_frame: eof:1828.39733632
     kworker/1:8-166     [001] ....  1812.686835: rtcpu_vinotify_event: tstamp:57125229636 cch:0 vi:1 tag:FS channel:0x00 frame:35 vi_tstamp:1828007095904 data:0x0000002300000012
     kworker/1:8-166     [001] ....  1812.686835: rtcpu_vinotify_event: tstamp:57125229776 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:35 vi_tstamp:1828007096032 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.686836: rtcpu_vinotify_event: tstamp:57125727419 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:35 vi_tstamp:1828007098592 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1812.686836: rtcpu_vinotify_event: tstamp:57125727555 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:35 vi_tstamp:1828007149792 data:0x0000000008020023
     kworker/1:8-166     [001] ....  1812.686836: rtcpu_vinotify_event: tstamp:57125727705 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828007412672 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1812.686836: rtcpu_vinotify_event: tstamp:57125727838 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828007456608 data:0x0000000031000024
     kworker/1:8-166     [001] ....  1812.686837: rtcpu_vinotify_event: tstamp:57126269168 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:35 vi_tstamp:1828039732608 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1812.686837: rtcpu_vinotify_event: tstamp:57126269304 cch:0 vi:1 tag:FE channel:0x00 frame:35 vi_tstamp:1828039733376 data:0x0000002300000022
     kworker/1:8-166     [001] ....  1812.686837: rtcpu_vinotify_event: tstamp:57126269460 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:35 vi_tstamp:1828039733472 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.686837: rtcpu_vinotify_event: tstamp:57126269592 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:35 vi_tstamp:1828039733632 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1812.686837: rtcpu_vinotify_event: tstamp:57126269742 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:35 vi_tstamp:1828039785888 data:0x0000000002020023
     kworker/1:8-166     [001] ....  1812.686837: rtcpu_vinotify_event: tstamp:57126269875 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:35 vi_tstamp:1828039802336 data:0x0000000000020023
 vi-output, ar02-1905    [000] ....  1812.727046: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1200 fmt c4
     kworker/1:8-166     [001] ....  1812.742836: rtcpu_vinotify_event: tstamp:57128354241 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1828097909248 data:0x759e2a0010000000
     kworker/1:8-166     [001] ....  1812.742836: rtcpu_vinotify_event: tstamp:57128354377 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1828097952736 data:0x0000000031000001
     kworker/1:8-166     [001] ....  1812.742837: rtcpu_vinotify_event: tstamp:57128354528 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1828097970336 data:0x759e270010000000
     kworker/1:8-166     [001] ....  1812.742837: rtcpu_vinotify_event: tstamp:57128354661 cch:1 vi:1 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:1828098031552 data:0x0000000031000002
     kworker/1:8-166     [001] ....  1812.742837: rtcpu_vinotify_event: tstamp:57128354815 cch:0 vi:1 tag:FS channel:0x00 frame:36 vi_tstamp:1828107083104 data:0x0000002400000012
     kworker/1:8-166     [001] ....  1812.742837: rtcpu_vinotify_event: tstamp:57128354951 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:36 vi_tstamp:1828107083200 data:0x0000000800000000
 vi-output, ar02-1902    [006] ....  1812.769719: tegra_channel_capture_frame: sof:1828.107085824
 vi-output, ar02-1902    [006] ....  1812.769721: tegra_channel_capture_frame: eof:1828.139720832
     kworker/1:8-166     [001] ....  1812.798835: rtcpu_vinotify_event: tstamp:57128874086 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:36 vi_tstamp:1828107085824 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1812.798836: rtcpu_vinotify_event: tstamp:57128874225 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:36 vi_tstamp:1828107137024 data:0x0000000008020024
     kworker/1:8-166     [001] ....  1812.798836: rtcpu_vinotify_event: tstamp:57128874377 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828107418752 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1812.798837: rtcpu_vinotify_event: tstamp:57128874509 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828107462656 data:0x0000000031000025
     kworker/1:8-166     [001] ....  1812.798837: rtcpu_vinotify_event: tstamp:57129415986 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:36 vi_tstamp:1828139719808 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1812.798837: rtcpu_vinotify_event: tstamp:57129416153 cch:0 vi:1 tag:FE channel:0x00 frame:36 vi_tstamp:1828139720576 data:0x0000002400000022
     kworker/1:8-166     [001] ....  1812.798838: rtcpu_vinotify_event: tstamp:57129416310 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:36 vi_tstamp:1828139720672 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.798840: rtcpu_vinotify_event: tstamp:57129416445 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:36 vi_tstamp:1828139720832 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1812.798840: rtcpu_vinotify_event: tstamp:57129416598 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:36 vi_tstamp:1828139773088 data:0x0000000002020024
     kworker/1:8-166     [001] ....  1812.798841: rtcpu_vinotify_event: tstamp:57129416730 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:36 vi_tstamp:1828139789536 data:0x0000000000020024
     kworker/1:8-166     [001] ....  1812.854835: rtcpu_vinotify_event: tstamp:57131483903 cch:0 vi:1 tag:FS channel:0x00 frame:37 vi_tstamp:1828207070304 data:0x0000002500000012
     kworker/1:8-166     [001] ....  1812.854836: rtcpu_vinotify_event: tstamp:57131484046 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:37 vi_tstamp:1828207070432 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.854836: rtcpu_vinotify_event: tstamp:57131484202 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:37 vi_tstamp:1828207072992 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1812.854837: rtcpu_vinotify_event: tstamp:57131484334 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:37 vi_tstamp:1828207111808 data:0x0000000008020025
     kworker/1:8-166     [001] ....  1812.854837: rtcpu_vinotify_event: tstamp:57131484484 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828207352512 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1812.854838: rtcpu_vinotify_event: tstamp:57131484615 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828207396416 data:0x0000000031000026
 vi-output, ar02-1902    [006] ....  1812.869749: tegra_channel_capture_frame: sof:1828.207072992
 vi-output, ar02-1902    [006] ....  1812.869751: tegra_channel_capture_frame: eof:1828.239708064
     kworker/1:8-166     [001] ....  1812.910847: rtcpu_vinotify_event: tstamp:57132508181 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:37 vi_tstamp:1828239707008 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1812.910849: rtcpu_vinotify_event: tstamp:57132508313 cch:0 vi:1 tag:FE channel:0x00 frame:37 vi_tstamp:1828239707776 data:0x0000002500000022
     kworker/1:8-166     [001] ....  1812.910850: rtcpu_vinotify_event: tstamp:57132508469 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:37 vi_tstamp:1828239707872 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.910850: rtcpu_vinotify_event: tstamp:57132508600 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:37 vi_tstamp:1828239708064 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1812.910851: rtcpu_vinotify_event: tstamp:57132508749 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:37 vi_tstamp:1828239760256 data:0x0000000002020025
     kworker/1:8-166     [001] ....  1812.910852: rtcpu_vinotify_event: tstamp:57132508880 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:37 vi_tstamp:1828239776704 data:0x0000000000020025
     kworker/1:8-166     [001] ....  1812.967007: rtcpu_vinotify_event: tstamp:57134678966 cch:0 vi:1 tag:FS channel:0x00 frame:38 vi_tstamp:1828307057504 data:0x0000002600000012
     kworker/1:8-166     [001] ....  1812.967008: rtcpu_vinotify_event: tstamp:57134679103 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:38 vi_tstamp:1828307057600 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1812.967009: rtcpu_vinotify_event: tstamp:57134679256 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:38 vi_tstamp:1828307060224 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1812.967009: rtcpu_vinotify_event: tstamp:57134679387 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:38 vi_tstamp:1828307099008 data:0x0000000008020026
     kworker/1:8-166     [001] ....  1812.967010: rtcpu_vinotify_event: tstamp:57134679556 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828307328448 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1812.967010: rtcpu_vinotify_event: tstamp:57134679688 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828307372352 data:0x0000000031000027
 vi-output, ar02-1902    [006] ....  1812.969766: tegra_channel_capture_frame: sof:1828.307060224
 vi-output, ar02-1902    [006] ....  1812.969768: tegra_channel_capture_frame: eof:1828.339695232
     kworker/1:8-166     [001] ....  1813.023007: rtcpu_vinotify_event: tstamp:57135623010 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:38 vi_tstamp:1828339694208 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.023008: rtcpu_vinotify_event: tstamp:57135623142 cch:0 vi:1 tag:FE channel:0x00 frame:38 vi_tstamp:1828339694976 data:0x0000002600000022
     kworker/1:8-166     [001] ....  1813.023009: rtcpu_vinotify_event: tstamp:57135623298 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:38 vi_tstamp:1828339695072 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.023009: rtcpu_vinotify_event: tstamp:57135623430 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:38 vi_tstamp:1828339695232 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.023010: rtcpu_vinotify_event: tstamp:57136143477 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:38 vi_tstamp:1828339755680 data:0x0000000002020026
     kworker/1:8-166     [001] ....  1813.023011: rtcpu_vinotify_event: tstamp:57136143618 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:38 vi_tstamp:1828339772384 data:0x0000000000020026
 vi-output, ar02-1902    [006] ....  1813.069721: tegra_channel_capture_frame: sof:1828.407047392
 vi-output, ar02-1902    [006] ....  1813.069723: tegra_channel_capture_frame: eof:1828.439682400
        v4l2-ctl-1903    [001] ....  1813.077223: tegra_channel_close: vi-output, ar0234 31-0018
     kworker/1:8-166     [001] ....  1813.078837: rtcpu_vinotify_event: tstamp:57137771751 cch:0 vi:1 tag:FS channel:0x00 frame:39 vi_tstamp:1828407044736 data:0x0000002700000012
     kworker/1:8-166     [001] ....  1813.078838: rtcpu_vinotify_event: tstamp:57137771888 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:39 vi_tstamp:1828407044800 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.078838: rtcpu_vinotify_event: tstamp:57137772040 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:39 vi_tstamp:1828407047392 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1813.078838: rtcpu_vinotify_event: tstamp:57137772171 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:39 vi_tstamp:1828407086240 data:0x0000000008020027
     kworker/1:8-166     [001] ....  1813.078838: rtcpu_vinotify_event: tstamp:57137772320 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828407312864 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1813.078839: rtcpu_vinotify_event: tstamp:57137772451 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828407356800 data:0x0000000031000028
     kworker/1:8-166     [001] ....  1813.078839: rtcpu_vinotify_event: tstamp:57138856480 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:39 vi_tstamp:1828439681408 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.078839: rtcpu_vinotify_event: tstamp:57138856616 cch:0 vi:1 tag:FE channel:0x00 frame:39 vi_tstamp:1828439682176 data:0x0000002700000022
     kworker/1:8-166     [001] ....  1813.078839: rtcpu_vinotify_event: tstamp:57138856773 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:39 vi_tstamp:1828439682272 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.078839: rtcpu_vinotify_event: tstamp:57138856905 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:39 vi_tstamp:1828439682400 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.078839: rtcpu_vinotify_event: tstamp:57138857058 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:39 vi_tstamp:1828439734688 data:0x0000000002020027
     kworker/1:8-166     [001] ....  1813.078840: rtcpu_vinotify_event: tstamp:57138857192 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:39 vi_tstamp:1828439751136 data:0x0000000000020027
 vi-output, ar02-1902    [006] ....  1813.169752: tegra_channel_capture_frame: sof:1828.507034624
 vi-output, ar02-1902    [006] ....  1813.169754: tegra_channel_capture_frame: eof:1828.539669632
     kworker/1:8-166     [001] ....  1813.190855: rtcpu_vinotify_event: tstamp:57140852630 cch:0 vi:1 tag:FS channel:0x00 frame:40 vi_tstamp:1828507031904 data:0x0000002800000012
     kworker/1:8-166     [001] ....  1813.190857: rtcpu_vinotify_event: tstamp:57140852768 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:40 vi_tstamp:1828507032000 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.190857: rtcpu_vinotify_event: tstamp:57141351747 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:40 vi_tstamp:1828507034624 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1813.190858: rtcpu_vinotify_event: tstamp:57141351882 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:40 vi_tstamp:1828507085792 data:0x0000000008020028
     kworker/1:8-166     [001] ....  1813.190858: rtcpu_vinotify_event: tstamp:57141352035 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828507354976 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1813.190859: rtcpu_vinotify_event: tstamp:57141352168 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828507398880 data:0x0000000031000029
     kworker/1:8-166     [001] ....  1813.190860: rtcpu_vinotify_event: tstamp:57141894637 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:40 vi_tstamp:1828539668608 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.190861: rtcpu_vinotify_event: tstamp:57141894774 cch:0 vi:1 tag:FE channel:0x00 frame:40 vi_tstamp:1828539669376 data:0x0000002800000022
     kworker/1:8-166     [001] ....  1813.190861: rtcpu_vinotify_event: tstamp:57141894930 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:40 vi_tstamp:1828539669472 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.190862: rtcpu_vinotify_event: tstamp:57141895064 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:40 vi_tstamp:1828539669632 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.190862: rtcpu_vinotify_event: tstamp:57141895213 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:40 vi_tstamp:1828539721888 data:0x0000000002020028
     kworker/1:8-166     [001] ....  1813.190863: rtcpu_vinotify_event: tstamp:57141895344 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:40 vi_tstamp:1828539738336 data:0x0000000000020028
     kworker/1:8-166     [001] ....  1813.246831: rtcpu_vinotify_event: tstamp:57143982053 cch:0 vi:1 tag:FS channel:0x00 frame:41 vi_tstamp:1828607019136 data:0x0000002900000012
     kworker/1:8-166     [001] ....  1813.246831: rtcpu_vinotify_event: tstamp:57143982192 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:41 vi_tstamp:1828607019232 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.246832: rtcpu_vinotify_event: tstamp:57143982353 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:41 vi_tstamp:1828607021792 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1813.246832: rtcpu_vinotify_event: tstamp:57143982486 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:41 vi_tstamp:1828607060608 data:0x0000000008020029
     kworker/1:8-166     [001] ....  1813.246833: rtcpu_vinotify_event: tstamp:57143982640 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828607290208 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1813.246833: rtcpu_vinotify_event: tstamp:57143982774 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828607336992 data:0x000000003100002a
 vi-output, ar02-1902    [006] ....  1813.269699: tegra_channel_capture_frame: sof:1828.607021792
 vi-output, ar02-1902    [006] ....  1813.269701: tegra_channel_capture_frame: eof:1828.639656864
     kworker/1:8-166     [001] ....  1813.302848: rtcpu_vinotify_event: tstamp:57145041708 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:41 vi_tstamp:1828639655808 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.302849: rtcpu_vinotify_event: tstamp:57145041843 cch:0 vi:1 tag:FE channel:0x00 frame:41 vi_tstamp:1828639656576 data:0x0000002900000022
     kworker/1:8-166     [001] ....  1813.302850: rtcpu_vinotify_event: tstamp:57145042001 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:41 vi_tstamp:1828639656672 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.302850: rtcpu_vinotify_event: tstamp:57145042136 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:41 vi_tstamp:1828639656864 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.302851: rtcpu_vinotify_event: tstamp:57145042292 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:41 vi_tstamp:1828639709088 data:0x0000000002020029
     kworker/1:8-166     [001] ....  1813.302852: rtcpu_vinotify_event: tstamp:57145042426 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:41 vi_tstamp:1828639725536 data:0x0000000000020029
     kworker/1:8-166     [001] ....  1813.358835: rtcpu_vinotify_event: tstamp:57147211112 cch:0 vi:1 tag:FS channel:0x00 frame:42 vi_tstamp:1828707006304 data:0x0000002a00000012
     kworker/1:8-166     [001] ....  1813.358836: rtcpu_vinotify_event: tstamp:57147211252 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:42 vi_tstamp:1828707006400 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.358836: rtcpu_vinotify_event: tstamp:57147211406 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:42 vi_tstamp:1828707009024 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1813.358837: rtcpu_vinotify_event: tstamp:57147211538 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:42 vi_tstamp:1828707047776 data:0x000000000802002a
     kworker/1:8-166     [001] ....  1813.358837: rtcpu_vinotify_event: tstamp:57147211690 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828707304704 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1813.358838: rtcpu_vinotify_event: tstamp:57147211822 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828707348640 data:0x000000003100002b
 vi-output, ar02-1902    [006] ....  1813.369719: tegra_channel_capture_frame: sof:1828.707009024
 vi-output, ar02-1902    [006] ....  1813.369720: tegra_channel_capture_frame: eof:1828.739644032
     kworker/1:8-166     [001] ....  1813.415009: rtcpu_vinotify_event: tstamp:57148121344 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:42 vi_tstamp:1828739643008 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.415011: rtcpu_vinotify_event: tstamp:57148121477 cch:0 vi:1 tag:FE channel:0x00 frame:42 vi_tstamp:1828739643776 data:0x0000002a00000022
     kworker/1:8-166     [001] ....  1813.415011: rtcpu_vinotify_event: tstamp:57148121634 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:42 vi_tstamp:1828739643872 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.415011: rtcpu_vinotify_event: tstamp:57148121768 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:42 vi_tstamp:1828739644032 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.415012: rtcpu_vinotify_event: tstamp:57148622179 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:42 vi_tstamp:1828739704512 data:0x000000000202002a
     kworker/1:8-166     [001] ....  1813.415013: rtcpu_vinotify_event: tstamp:57148622341 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:42 vi_tstamp:1828739721184 data:0x000000000002002a
 vi-output, ar02-1902    [006] ....  1813.469673: tegra_channel_capture_frame: sof:1828.806996192
 vi-output, ar02-1902    [006] ....  1813.469675: tegra_channel_capture_frame: eof:1828.839631232
     kworker/1:8-166     [001] ....  1813.470835: rtcpu_vinotify_event: tstamp:57150249447 cch:0 vi:1 tag:FS channel:0x00 frame:43 vi_tstamp:1828806993536 data:0x0000002b00000012
     kworker/1:8-166     [001] ....  1813.470836: rtcpu_vinotify_event: tstamp:57150249584 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:43 vi_tstamp:1828806993600 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.470838: rtcpu_vinotify_event: tstamp:57150249736 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:43 vi_tstamp:1828806996192 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1813.470838: rtcpu_vinotify_event: tstamp:57150249868 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:43 vi_tstamp:1828807035008 data:0x000000000802002b
     kworker/1:8-166     [001] ....  1813.470839: rtcpu_vinotify_event: tstamp:57150250019 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828807253408 data:0x759e2d0010000000
     kworker/1:8-166     [001] ....  1813.470839: rtcpu_vinotify_event: tstamp:57150250152 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828807297344 data:0x000000003100002c
        v4l2-ctl-1900    [003] ....  1813.485022: tegra_channel_close: vi-output, ar0234 30-0018
     kworker/1:8-166     [001] ....  1813.526838: rtcpu_vinotify_event: tstamp:57151335236 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:43 vi_tstamp:1828839630208 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.526840: rtcpu_vinotify_event: tstamp:57151335371 cch:0 vi:1 tag:FE channel:0x00 frame:43 vi_tstamp:1828839630976 data:0x0000002b00000022
     kworker/1:8-166     [001] ....  1813.526840: rtcpu_vinotify_event: tstamp:57151335527 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:43 vi_tstamp:1828839631072 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.526840: rtcpu_vinotify_event: tstamp:57151335658 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:43 vi_tstamp:1828839631232 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.526841: rtcpu_vinotify_event: tstamp:57151335812 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:43 vi_tstamp:1828839683488 data:0x000000000202002b
     kworker/1:8-166     [001] ....  1813.526841: rtcpu_vinotify_event: tstamp:57151335943 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:43 vi_tstamp:1828839699936 data:0x000000000002002b
 vi-output, ar02-1902    [006] ....  1813.569653: tegra_channel_capture_frame: sof:1828.906983424
 vi-output, ar02-1902    [006] ....  1813.569655: tegra_channel_capture_frame: eof:1828.939618432
        v4l2-ctl-1900    [003] ....  1813.569828: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-1900    [003] ....  1813.569831: tegra_channel_set_stream: ar0234 30-0018 : 0x0
        v4l2-ctl-1900    [003] ....  1813.570146: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-1900    [003] ....  1813.570148: csi_s_stream: enable : 0x0
        v4l2-ctl-1900    [003] ....  1813.573179: tegra_channel_set_power: ar0234 30-0018 : 0x0
        v4l2-ctl-1900    [003] ....  1813.573189: camera_common_s_power: status : 0x0
        v4l2-ctl-1900    [003] ....  1813.576899: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-1900    [003] ....  1813.576901: csi_s_power: enable : 0x0
     kworker/1:8-166     [001] ....  1813.582839: rtcpu_vinotify_event: tstamp:57153351069 cch:0 vi:1 tag:FS channel:0x00 frame:44 vi_tstamp:1828906980704 data:0x0000002c00000012
     kworker/1:8-166     [001] ....  1813.582840: rtcpu_vinotify_event: tstamp:57153351208 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:44 vi_tstamp:1828906980800 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.582840: rtcpu_vinotify_event: tstamp:57153885047 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:44 vi_tstamp:1828906983424 data:0x0000000000000001
     kworker/1:8-166     [001] ....  1813.582840: rtcpu_vinotify_event: tstamp:57153885182 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:44 vi_tstamp:1828907034592 data:0x000000000802002c
     kworker/1:8-166     [001] ....  1813.582841: rtcpu_vinotify_event: tstamp:57153885335 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828907296256 data:0x759e300010000000
     kworker/1:8-166     [001] ....  1813.582841: rtcpu_vinotify_event: tstamp:57153885468 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1828907340224 data:0x000000003100002d
     kworker/1:8-166     [001] ....  1813.582843: rtcpu_string: tstamp:57154394753 id:0x04010000 str:"ISR PHY 1 CIL_A 0x1
"
     kworker/1:8-166     [001] ....  1813.582855: rtcpu_nvcsi_intr: tstamp:57154394514 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000001
     kworker/1:8-166     [001] ....  1813.582856: rtcpu_string: tstamp:57154395150 id:0x04010000 str:"ISR1 PHY 1 CIL_A status 125
"
     kworker/1:8-166     [001] ....  1813.582860: rtcpu_nvcsi_intr: tstamp:57154394514 class:GLOBAL type:PHY_INTR1 phy:1 cil:0 st:0 vc:0 status:0x00000125
     kworker/1:8-166     [001] ....  1813.582861: rtcpu_string: tstamp:57154396660 id:0x04010000 str:"tegra_nvcsi_stream_close(vm0, stream=2, csi=2)
"
     kworker/1:8-166     [001] ....  1813.582864: rtcpu_vinotify_event: tstamp:57154427028 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:44 vi_tstamp:1828939617408 data:0x0000000004af0002
     kworker/1:8-166     [001] ....  1813.582865: rtcpu_vinotify_event: tstamp:57154427167 cch:0 vi:1 tag:FE channel:0x00 frame:44 vi_tstamp:1828939618176 data:0x0000002c00000022
     kworker/1:8-166     [001] ....  1813.582865: rtcpu_vinotify_event: tstamp:57154427327 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:44 vi_tstamp:1828939618272 data:0x0000000800000000
     kworker/1:8-166     [001] ....  1813.582866: rtcpu_vinotify_event: tstamp:57154427464 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:44 vi_tstamp:1828939618432 data:0x0000000000000000
     kworker/1:8-166     [001] ....  1813.582866: rtcpu_vinotify_event: tstamp:57154427621 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:44 vi_tstamp:1828939670688 data:0x000000000202002c
     kworker/1:8-166     [001] ....  1813.582867: rtcpu_vinotify_event: tstamp:57154427755 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:44 vi_tstamp:1828939687136 data:0x000000000002002c
 vi-output, ar02-1905    [000] ....  1815.542905: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1200 fmt c4
        v4l2-ctl-1903    [001] ....  1815.552498: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-1903    [001] ....  1815.552499: tegra_channel_set_stream: ar0234 31-0018 : 0x0
        v4l2-ctl-1903    [001] ....  1815.552816: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-1903    [001] ....  1815.552819: csi_s_stream: enable : 0x0
        v4l2-ctl-1903    [001] ....  1815.564212: tegra_channel_set_power: ar0234 31-0018 : 0x0
        v4l2-ctl-1903    [001] ....  1815.564218: camera_common_s_power: status : 0x0
        v4l2-ctl-1903    [001] ....  1815.567936: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-1903    [001] ....  1815.567940: csi_s_power: enable : 0x0


There is only one thing where I could find more information. If I would have the source code (cpp file) of the ICaptureSession class. There happens the error described at post Gstreamer does not work with more then 2 nvarguscamerasrc's - #16 by wyss.

I didn’t find the sources at tmp/Linux_for_Tegra/source/public/. But I did find the .h file at Jetson Linux API Reference: Argus/CaptureSession.h Source File | NVIDIA Docs.
Can you provide me the source code of ICaptureSession?

Thanks for your help.

BR
Kris

From your title does v4l2-ctl didn’t work? If yes suppose you don’t need source of ICaptureSession

Hi ShaneCCC

As mentioned in the past discussion and my new post I have no other idea to figure out where the error comes from.

Have you any idea how to debug this without the source code? Thanks for any help.

BR
Kris

Does v4l2-ctl working for multiple cameras simultaneously?
If don’t you can debug by kernel driver that full source public.

Hi ShaneCCC

No it does not.

I enabled the logs for v4l with this cmd:

echo 0x1f > /sys/class/video4linux/video1/dev_debug 

First Step: run only the camera /dev/video1
Second Step: run /dev/video0 and /dev/video1 concurrently

The comparison of this two logs doesn’t show any differences during the setup process for the video1 logs.
Second Step: Log:

videodev: v4l2_open: video1: open (0)
video1: VIDIOC_QUERYCAP: driver=tegra-video, card=vi-output, ar0234 31-0018, bus=platform:tegra-capture-vi:3, version=0x00050a78, capabilities=0x84200001, device_caps=0x04200001
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a0001, type=6, name=Camera Controls, min/max=0/0, step=0, default=0, flags=0x00000044, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_TRY_EXT_CTRLS: which=0x0, count=0, error_idx=0, request_fd=0
video1: VIDIOC_QUERYCTRL: id=0x9a0001, type=6, name=Camera Controls, min/max=0/0, step=0, default=0, flags=0x00000044
video1: VIDIOC_G_SELECTION: error -25: type=vid-cap, target=0, flags=0x0, wxh=0x0, x,y=0,0
video1: VIDIOC_QUERYCAP: driver=tegra-video, card=vi-output, ar0234 31-0018, bus=platform:tegra-capture-vi:3, version=0x00050a78, capabilities=0x84200001, device_caps=0x04200001
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a0001, type=6, name=Camera Controls, min/max=0/0, step=0, default=0, flags=0x00000044, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a0001, type=6, name=Camera Controls, min/max=0/0, step=0, default=0, flags=0x00000044, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2003, type=2, name=Group Hold, min/max=0/1, step=1, default=0, flags=0x00000200, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2004, type=9, name=HDR enable, min/max=0/1, step=1, default=0, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2008, type=5, name=Sensor Mode, min/max=0/2, step=1, default=0, flags=0x00000020, elem_size=8, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2009, type=5, name=Gain, min/max=169/1600, step=2, default=200, flags=0x00000020, elem_size=8, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a200a, type=5, name=Exposure, min/max=19/33333, step=2, default=8330, flags=0x00000020, elem_size=8, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a200b, type=5, name=Frame Rate, min/max=10000000/10000000, step=1, default=10000000, flags=0x00000020, elem_size=8, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a200c, type=5, name=Exposure Short, min/max=20/33333, step=2, default=8330, flags=0x00000020, elem_size=8, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2032, type=258, name=Sensor configuration, min/max=0/4294967295, step=1, default=0, flags=0x00000184, elem_size=4, elems=22, nr_of_dims=1, dims=22,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2033, type=258, name=Sensor mode I2C packet, min/max=0/4294967295, step=1, default=0, flags=0x00000184, elem_size=4, elems=1026, nr_of_dims=1, dims=1026,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2034, type=258, name=Sensor control I2C packet, min/max=0/4294967295, step=1, default=0, flags=0x00000184, elem_size=4, elems=1026, nr_of_dims=1, dims=1026,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2064, type=9, name=Bypass Mode, min/max=0/1, step=1, default=0, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2065, type=9, name=Override Enable, min/max=0/1, step=1, default=0, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2066, type=1, name=Height Align, min/max=1/16, step=1, default=1, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2067, type=9, name=Size Align, min/max=0/2, step=1, default=0, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2068, type=1, name=Write ISP format, min/max=1/1, step=1, default=1, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2069, type=258, name=Sensor Signal Properties, min/max=0/4294967295, step=1, default=0, flags=0x00000104, elem_size=4, elems=36, nr_of_dims=2, dims=30,18,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a206a, type=258, name=Sensor Image Properties, min/max=0/4294967295, step=1, default=0, flags=0x00000104, elem_size=4, elems=32, nr_of_dims=2, dims=30,16,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a206b, type=258, name=Sensor Control Properties, min/max=0/4294967295, step=1, default=0, flags=0x00000104, elem_size=4, elems=72, nr_of_dims=2, dims=30,36,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a206c, type=258, name=Sensor DV Timings, min/max=0/4294967295, step=1, default=0, flags=0x00000104, elem_size=4, elems=32, nr_of_dims=2, dims=30,16,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a206d, type=2, name=Low Latency Mode, min/max=0/1, step=1, default=0, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a206e, type=1, name=Preferred Stride, min/max=0/65535, step=1, default=0, flags=0x00000000, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: id=0x9a2082, type=1, name=Sensor Modes, min/max=0/30, step=1, default=30, flags=0x00000004, elem_size=4, elems=1, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_QUERY_EXT_CTRL: error -22: id=0xc09a2082, type=0, name=, min/max=0/0, step=0, default=0, flags=0x00000000, elem_size=0, elems=0, nr_of_dims=0, dims=0,0,0,0
video1: VIDIOC_S_EXT_CTRLS: which=0x9a0000, count=1, error_idx=0, request_fd=0, id/val=0x9a2064/0x0
video1: VIDIOC_G_FMT: type=vid-cap, width=1920, height=1200, pixelformat=BA10, field=none, bytesperline=3840, sizeimage=4608000, colorspace=8, flags=0x0, ycbcr_enc=0, quantization=0, xfer_func=0
video1: VIDIOC_ENUM_FMT: index=0, type=vid-cap, flags=0x0, pixelformat=BA10, mbus_code=0x0000, description='10-bit Bayer GRGR/BGBG'
video1: VIDIOC_S_FMT: type=vid-cap, width=1920, height=1200, pixelformat=BA10, field=none, bytesperline=3840, sizeimage=4608000, colorspace=8, flags=0x0, ycbcr_enc=0, quantization=0, xfer_func=0
video1: VIDIOC_ENUM_FMT: index=0, type=vid-cap, flags=0x0, pixelformat=BA10, mbus_code=0x0000, description='10-bit Bayer GRGR/BGBG'
video1: VIDIOC_CROPCAP: error -25: type=vid-cap, bounds wxh=0x0, x,y=0,0, defrect wxh=0x0, x,y=0,0, pixelaspect 0/0
video1: VIDIOC_CROPCAP: error -25: type=vid-out, bounds wxh=0x0, x,y=0,0, defrect wxh=0x0, x,y=0,0, pixelaspect 0/0
video1: VIDIOC_SUBSCRIBE_EVENT: error -22: type=0x2, id=0x0, flags=0x0
video1: VIDIOC_G_INPUT: value=0
video1: VIDIOC_ENUMINPUT: index=0, name=Camera 3, type=2, audioset=0x0, tuner=0, std=0x00000000, status=0x0, capabilities=0x0
video1: VIDIOC_REQBUFS: count=4, type=vid-cap, memory=mmap
video1: VIDIOC_QUERYBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002000, field=any, sequence=0, memory=mmap, bytesused=0, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QUERYBUF: 00:00:00.000000000 index=1, type=vid-cap, request_fd=0, flags=0x00002000, field=any, sequence=0, memory=mmap, bytesused=0, offset/userptr=0x465000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QUERYBUF: 00:00:00.000000000 index=2, type=vid-cap, request_fd=0, flags=0x00002000, field=any, sequence=0, memory=mmap, bytesused=0, offset/userptr=0x8ca000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QUERYBUF: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002000, field=any, sequence=0, memory=mmap, bytesused=0, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
videodev: v4l2_mmap: video1: mmap (0)
videodev: v4l2_mmap: video1: mmap (0)
videodev: v4l2_mmap: video1: mmap (0)
videodev: v4l2_mmap: video1: mmap (0)
video1: VIDIOC_QBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002003, field=any, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=1, type=vid-cap, request_fd=0, flags=0x00002003, field=any, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x465000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=2, type=vid-cap, request_fd=0, flags=0x00002003, field=any, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x8ca000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002003, field=any, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_G_FMT: type=vid-cap, width=1920, height=1200, pixelformat=BA10, field=none, bytesperline=3840, sizeimage=4608000, colorspace=8, flags=0x0, ycbcr_enc=0, quantization=0, xfer_func=0
ar0234 31-0018: ar0234_power_on:
bwmgr API not supported
ar0234 31-0018: ar0234_set_mode: Set mode 0 at CAM0
ar0234 31-0018: ar0234_write_table: start write table CAM0
[RCE] tegra_nvcsi_stream_set_config(vm0, stream=3, csi=3)
[RCE] tegra_nvcsi_stream_open(vm0, stream=3, csi=3)
ar0234 31-0018: ar0234_start_streaming: Start stream CAM0
ar0234 31-0018: ar0234_write_table: start write table CAM0
video1: VIDIOC_STREAMON: type=vid-cap
video1: VIDIOC_G_FMT: type=vid-cap, width=1920, height=1200, pixelformat=BA10, field=none, bytesperline=3840, sizeimage=4608000, colorspace=8, flags=0x0, ycbcr_enc=0, quantization=0, xfer_func=0
videodev: v4l2_poll: video1: poll: 00000000

tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1:
(NULL device *): vi_capture_control_message: NULL VI channel received
t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=3, csi_port=3
VIDIOC_DQBUF:
(NULL device *): vi_capture_control_message: NULL VI channel received
t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 3 vc- 0
tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=1, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=1, memory=mmap, bytesused=4608000, offset/userptr=0x465000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=1, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x465000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=2, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=2, memory=mmap, bytesused=4608000, offset/userptr=0x8ca000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=2, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x8ca000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=3, memory=mmap, bytesused=4608000, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000

tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
(NULL device *): vi_capture_control_message: NULL VI channel received
video1: VIDIOC_DQBUF
t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=3, csi_port=3
:
(NULL device *): vi_capture_control_message: NULL VI channel received
t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 3 vc- 0
00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=0, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x0, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=1, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=1, memory=mmap, bytesused=4608000, offset/userptr=0x465000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=1, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x465000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=2, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=2, memory=mmap, bytesused=4608000, offset/userptr=0x8ca000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=2, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0x8ca000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_DQBUF: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002041, field=none, sequence=3, memory=mmap, bytesused=4608000, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
video1: VIDIOC_QBUF: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

video1: VIDIOC_DQBUF: error -512: 00:00:00.000000000 index=3, type=vid-cap, request_fd=0, flags=0x00002003, field=none, sequence=0, memory=mmap, bytesused=4608000, offset/userptr=0xd2f000, length=4608000
timecode=00:00:00 type=0, flags=0x00000000, frames=0, userbits=0x00000000
tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
(NULL device *): vi_capture_control_message: NULL VI channel received
t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=3, csi_port=3
(NULL device *): vi_capture_control_message: NULL VI channel received
t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 3 vc- 0
tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
ar0234 31-0018: ar0234_stop_streaming: Stop stream CAM0
ar0234 31-0018: ar0234_write_table: start write table CAM0
bwmgr API not supported
ar0234 31-0018: ar0234_power_off:
videodev: v4l2_release: video1: release

But what I see is that the following logs are not appearing at the Second Step log.

[RCE] NVCSILP clock rate = 408000000 Hz.
[RCE] MIPI clock = 750000 kHz, tHS-SETTLE = 130, tCLK-SETTLE = 0
[RCE] ===== NVCSI Stream Configuration =====
[RCE] stream_id: PP 3, csi_port: PORT D
[RCE] Brick: PHY 1, Mode: D-PHY
[RCE] Partition: CIL B, LP bypass: Enabled, Lanes: 2
[RCE] Clock information:
[RCE] MIPI clock rate: 750.00 MHz
[RCE] T_HS settle: 130, T_CLK settle: 0
[RCE] ======================================
[RCE] nvcsi_calc_tclk_settle tclk_settle 75

Should they appear? And if yes, what could be the root cause that they not appear?

What’s the v4l2-ctl command?

Terminal 1:

v4l2-ctl -d /dev/video0 --set-ctrl bypass_mode=0 --stream-mmap --set-fmt-video=width=1920,height=1200,pixelformat=BA10 --verbose

Terminal 2:

v4l2-ctl -d /dev/video1 --set-ctrl bypass_mode=0 --stream-mmap --set-fmt-video=width=1920,height=1200,pixelformat=BA10 --verbose

Hi Shane

After some further debugging it’s getting clear that v4l framework doesn’t report any error. After the starting up process of the second camera sensor v4l2 on dev/video1 does block in poll until tegra-capture-vi does report the timeout error. See from above mentioned log:

For me it seems that no data are past to V4L2 framework within 2500ms:
Screenshot from 2023-11-30 14-03-40

I enabled some DYNAMIC_DEBUG for VI kernel driver:

cd /sys/kernel/debug/dynamic_debug/
echo file vi.c +p > control
echo file capture-vi.c +p > control
echo file vi5_fops.c +p > control
echo file vi4_fops.c +p > control

DYNAMIC_DEBUG VI Log:

[  235.272695] ar0234 30-0018: ar0234_power_on:
[  235.299915] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  235.300032] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan flags 4163
[  235.300036] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan mask ffffffffffffffff
[  235.300038] tegra194-vi5 13e40000.host1x:vi1@14c00000: queue depth 4
[  235.300040] tegra194-vi5 13e40000.host1x:vi1@14c00000: request size 384
[  235.300041] tegra194-vi5 13e40000.host1x:vi1@14c00000: csi_stream_id 2
[  235.300043] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi unit id 1
[  235.300045] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi2 chan mask ffffffffffffffff
[  235.320940] tegra194-vi5 13e40000.host1x:vi1@14c00000: 0 GoS tables configured.
[  235.320948] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 76 msg_id 30
[  235.321504] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 76 msg_id 17
[  235.321652] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  235.321677] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  235.321685] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  235.321692] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  235.321923] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  235.357061] bwmgr API not supported
[  235.365488] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 64
[  235.366387] [RCE] NVCSILP clock rate = 408000000 Hz.
[  235.369269] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 65
[  235.369279] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 54
[  235.369559] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 55
[  235.369580] ar0234 30-0018: ar0234_set_mode: Set mode 0 at CAM1
[  235.369585] ar0234 30-0018: ar0234_write_table: start write table CAM1
[  235.422409] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=2, csi=2)
[  235.422416] [RCE] MIPI clock = 750000 kHz, tHS-SETTLE = 130, tCLK-SETTLE = 0
[  235.422421] [RCE] ===== NVCSI Stream Configuration =====
[  235.422424] [RCE] stream_id: PP 2, csi_port: PORT C
[  235.422427] [RCE] Brick: PHY 1, Mode: D-PHY
[  235.422430] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2
[  235.422433] [RCE] Clock information:
[  235.422437] [RCE] MIPI clock rate: 750.00 MHz
[  235.422439] [RCE] T_HS settle: 130, T_CLK settle: 0
[  235.422442] [RCE] ======================================
[  235.422445] [RCE] tegra_nvcsi_stream_open(vm0, stream=2, csi=2)
[  235.422448] [RCE] nvcsi_calc_tclk_settle tclk_settle 75
[  235.946395] ar0234 30-0018: ar0234_start_streaming: Start stream CAM1
[  235.946402] ar0234 30-0018: ar0234_write_table: start write table CAM1
[  235.981417] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  235.981440] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  235.981727] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  236.081398] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.081564] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.081861] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  236.181383] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.181550] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.181849] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  236.281371] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.281539] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.281840] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  236.381354] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.381527] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.381842] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  236.481346] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.481513] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.481828] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1


[  236.492127] ar0234 31-0018: ar0234_power_on:
[  236.505923] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  236.505981] (NULL device *): vi_capture_shutdown--
[  236.505991] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  236.506033] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan flags 4163
[  236.506035] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan mask ffffffffffffffff
[  236.506036] tegra194-vi5 13e40000.host1x:vi1@14c00000: queue depth 4
[  236.506038] tegra194-vi5 13e40000.host1x:vi1@14c00000: request size 384
[  236.506040] tegra194-vi5 13e40000.host1x:vi1@14c00000: csi_stream_id 3
[  236.506041] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi unit id 1
[  236.506042] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi2 chan mask ffffffffffffffff
[  236.506062] tegra194-vi5 13e40000.host1x:vi1@14c00000: 0 GoS tables configured.
[  236.506065] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 77 msg_id 30
[  236.506131] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 77 msg_id 17
[  236.506221] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:0
[  236.506229] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:1
[  236.506232] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:2
[  236.506235] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:3
[  236.506240] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.508136] bwmgr API not supported
[  236.508240] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 1 msg_id 64
[  236.511908] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 1 msg_id 65
[  236.511911] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 1 msg_id 54
[  236.511978] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 1 msg_id 55
[  236.511986] ar0234 31-0018: ar0234_set_mode: Set mode 0 at CAM0
[  236.511987] ar0234 31-0018: ar0234_write_table: start write table CAM0
[  236.546380] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=3, csi=3)
[  236.546382] [RCE] tegra_nvcsi_stream_open(vm0, stream=3, csi=3)


[  236.581328] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.581351] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.581659] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  236.681484] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.681654] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.681949] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  236.781314] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.781481] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.782002] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  236.881300] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.881465] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.881972] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  236.981281] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  236.981451] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  236.981982] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  237.081431] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.081449] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.081966] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  237.094404] ar0234 31-0018: ar0234_start_streaming: Start stream CAM0
[  237.094411] ar0234 31-0018: ar0234_write_table: start write table CAM0


[  237.181420] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.181588] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.182095] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  237.281239] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.281410] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.281869] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  237.381394] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.381564] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.382071] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  237.481376] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.481401] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.481890] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  237.581365] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.581533] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.582015] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  237.681353] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.681522] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.682032] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  237.781341] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.781508] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.782020] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  237.881179] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.881346] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.881656] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  237.981316] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  237.981484] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  237.981791] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  238.081305] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.081475] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.081778] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  238.181141] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.181158] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.181613] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  238.281128] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.281156] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.281656] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  238.381262] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.381429] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.381932] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  238.481102] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.481269] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.481725] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  238.581239] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.581408] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.581702] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  238.681074] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.681240] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.681535] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  238.781216] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.781234] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.781528] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  238.881037] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.881207] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.881501] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  238.981189] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  238.981359] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  238.981651] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  239.081012] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.081031] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.081326] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3


[  239.110401] tegra194-vi5 13e40000.host1x:vi1@14c00000: capture status timed out
[  239.110408] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  239.119553] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  239.129154] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 1 msg_id 20
[  239.129865] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 1 msg_id 21
[  239.129889] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_shutdown--
[  239.129897] (NULL device *): vi_capture_control_message: NULL VI channel received
[  239.137609] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=3, csi_port=3
[  239.148267] (NULL device *): vi_capture_control_message: NULL VI channel received
[  239.155977] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 3 vc- 0
[  239.166556] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  239.166597] (NULL device *): vi_capture_shutdown--
[  239.166604] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  239.166628] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan flags 4163
[  239.166630] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan mask ffffffffffffffff
[  239.166632] tegra194-vi5 13e40000.host1x:vi1@14c00000: queue depth 4
[  239.166633] tegra194-vi5 13e40000.host1x:vi1@14c00000: request size 384
[  239.166634] tegra194-vi5 13e40000.host1x:vi1@14c00000: csi_stream_id 3
[  239.166636] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi unit id 1
[  239.166637] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi2 chan mask ffffffffffffffff
[  239.166651] tegra194-vi5 13e40000.host1x:vi1@14c00000: 0 GoS tables configured.
[  239.166653] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 78 msg_id 30
[  239.166709] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 78 msg_id 17
[  239.166716] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  239.166719] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:0
[  239.176203] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:1
[  239.176206] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:2
[  239.176208] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 1 msg_id 1 buf:3
[  239.176213] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.181106] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.181110] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.181479] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  239.281153] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.281337] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.281867] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  239.381134] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.381304] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.381794] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  239.480967] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.481137] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.481574] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  239.581110] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.581281] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.581453] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  239.681103] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.681273] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.681753] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  239.781083] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.781101] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.781428] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:2
[  239.881072] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.881241] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.881352] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:3
[  239.981064] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  239.981233] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  239.981298] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[  240.081048] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  240.081217] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_status: waiting for status, timeout:2500 ms
[  240.081493] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[  240.181036] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_status_callback: status chan_id 0 msg_id 2
[  240.181222] ar0234 30-0018: ar0234_stop_streaming: Stop stream CAM1
[  240.181229] ar0234 30-0018: ar0234_write_table: start write table CAM1
[  240.181533] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 56
[  240.181633] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 57
[  240.183941] bwmgr API not supported
[  240.184080] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[  240.187880] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[  240.187925] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_shutdown--
[  240.187951] ar0234 30-0018: ar0234_power_off:
[  240.190384] [RCE] ISR PHY 1 CIL_A 0x1
[  240.190390] [RCE] ISR1 PHY 1 CIL_A status 125
[  240.190393] [RCE] tegra_nvcsi_stream_close(vm0, stream=2, csi=2)
[  241.702395] tegra194-vi5 13e40000.host1x:vi1@14c00000: capture status timed out
[  241.702404] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  241.711537] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  241.721133] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 1 msg_id 20
[  241.722000] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 1 msg_id 21
[  241.722039] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_shutdown--
[  241.722048] (NULL device *): vi_capture_control_message: NULL VI channel received
[  241.729759] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=3, csi_port=3
[  241.740417] (NULL device *): vi_capture_control_message: NULL VI channel received
[  241.748133] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 3 vc- 0
[  241.758722] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  241.758784] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan flags 4163
[  241.758786] tegra194-vi5 13e40000.host1x:vi1@14c00000: chan mask ffffffffffffffff
[  241.758787] tegra194-vi5 13e40000.host1x:vi1@14c00000: queue depth 4
[  241.758789] tegra194-vi5 13e40000.host1x:vi1@14c00000: request size 384
[  241.758790] tegra194-vi5 13e40000.host1x:vi1@14c00000: csi_stream_id 3
[  241.758791] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi unit id 1
[  241.758792] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi2 chan mask ffffffffffffffff
[  241.758810] tegra194-vi5 13e40000.host1x:vi1@14c00000: 0 GoS tables configured.
[  241.758812] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 79 msg_id 30
[  241.758871] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 79 msg_id 17
[  241.758874] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  241.768392] ar0234 31-0018: ar0234_stop_streaming: Stop stream CAM0
[  241.768396] ar0234 31-0018: ar0234_write_table: start write table CAM0
[  241.768671] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_control_send_message: NVCSI stream is already closed for this VI channel
[  241.771813] bwmgr API not supported
[  241.779812] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[  241.783884] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[  241.783935] tegra194-vi5 13e40000.host1x:vi1@14c00000: vi_capture_shutdown--
[  241.784355] ar0234 31-0018: ar0234_power_off:

From the above log, when the second camera is starting up the following log is suspect:

[  236.505923] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++
[  236.505981] (NULL device *): vi_capture_shutdown--
[  236.505991] tegra-camrtc-capture-vi tegra-capture-vi: vi_capture_init++

Could that be the root cause? I gues not because after the NULL pointer detection vi_capture_init is called a second time and then the it seems that the init process succeed.

Thanks for any help…

BR
Kris

The reason is unable capture frame data from sensor.

  1. Please check if video0 and video1 is working individually.
  2. Check if terminal still working when terminal 2 start capture.
  3. What’s if start video1 first then start video0?

They work individually

if video0 start first and than video1 is started video0 still capture frames but video1 never does.

same behaviour

Could you probe the signal to compare the failed and working case.
Also boost the clocks to try.

sudo su
echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/isp/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/nvcsi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/emc/mrq_rate_locked
cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate |tee /sys/kernel/debug/bpmp/debug/clk/vi/rate
cat /sys/kernel/debug/bpmp/debug/clk/isp/max_rate | tee  /sys/kernel/debug/bpmp/debug/clk/isp/rate
cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate
cat /sys/kernel/debug/bpmp/debug/clk/emc/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/emc/rate


Hi Shane

Thanks for your help…

Clock boost didn’t helped.

Here some screenshots of the probed signals (10 FPS) captured with a 5GSa/s oscilloscope.

video0 → CSI2
video1 → CSI3

CH1: CSI3_CLK_P
CH2: CSI3_D0_P
CH3: CSI2_CLK_P
CH4: CSI2_DO_P

20ms/DIV

5us/DIV

CH3: video1 → CSI3_DO_N
500ns/DIV video1 running individual

500ns/DIV video1 start as second stream and running concurrently with video0

CH3: video1 → CSI3_DO_P

500ns/DIV video1 running individual

500ns/DIV video1 start as second stream and running concurrently with video0
Screenshot from 2023-12-01 13-57-14

The last screenshot shows an abnormal signal shape at LP-00 state. The voltage never comes up.
And in HS state the differential voltage is 600mV, that’s fare above the allowed 270mV.

First I thought that this behavior could be caused due to signal integrity. But if video0 stops streaming while video1 is still streaming, the signal shape does not change at LP-00 and HS state.

Could it be that the termination register in the PHY is not enabled?

Do you have any other suggestions where this comes from?

Thanks for supporting us.

BR
Kris

I would suggest disconnect the from the Orin Nano CSI if the voltage still the same I would suspect the sensor configure or HW problem cause that.

Hi Shane

Can I ask what do you mean with “disconnect the from Orin Nano CSI if the voltage still the same”?

The sensor configuration is the same for both cases (individual or concurrently) so i guess this isn’t the problem.

Is there a way to read and write the NVCSI_PHY_0_xxxx register from CLI?

BR
Kris

Suppose the MIPI output was control by sensor not Orin Nano.
That I would suspect it could be the sensor configure or HW problem.

Thanks for the answer.

The sensor acts as transmitter and the Orin Nano as receiver. On Receiver side the Termination Resistor should be enabled at the CIL as soon as the transmitter (Sensor) forces the LP sequence of LP-11, LP-01, and LP-00 (TRM Page. 552). It seems that the Termination Resistor is never enabled at the Receiver (Orin Nano). I would like to debug this behavior through the NVCSI_PHY_0_xxxx register values.

How can I read and write the NVCSI_PHY_0_xxxx register from the terminal?

You can use devmem to read it.
Below is disable the firewall to access the REG.

Hi Shane

After some days MIPI CSI PHY debugging, it isn’t possible to getting two cameras at the same PHY concurrently running. That’s why I will come back to my first post:

I know the source code isn’t open source, but could you please provide me a list with all reasons why the function
ICaptureSession::createCaptureSession(cameraDevices[cameraIndex])) return this ERROR?

Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, execute:762 Failed to create CaptureSession

That would help me to figure out the root cause.

Thanks allot…

BR
Kris

You may need nvargus-daemon log by below command to get more informaiton.

sudo journalctl -u nvargus-daemon

Hi

Here the nvargus log from starting camera at PHY0 CLIA:

Dec  8 11:28:40 tegra-ubuntu systemd[1]: jtop.service: Scheduled restart job, restart counter is at 241.
Dec  8 11:28:40 tegra-ubuntu systemd[1]: Stopped jtop service.
Dec  8 11:28:40 tegra-ubuntu systemd[1]: Started jtop service.
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.service - jetson_stats 4.2.3 - server loaded
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.hardware - Hardware detected aarch64
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.hardware - NVIDIA Jetson detected L4T=35.4.1
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: === gst-launch-1.0[4591]: CameraProvider destroyed (0xffff84f899a0)=== gst-launch-1.0[4591]: Connection closed (FFFF8B078900)=== gst-launch-1.0[4591]: Connection cleaned up (FFFF8B078900)=== gst-launch-1.0[4848]: Connection established (FFFF8B078900)OFParserListModules: module list: /proc/device-tree/tegra-camera-platform/modules/module0
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: OFParserListModules: module list: /proc/device-tree/tegra-camera-platform/modules/module1
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: OFParserListModules: module list: /proc/device-tree/tegra-camera-platform/modules/module2
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: OFParserListModules: module list: /proc/device-tree/tegra-camera-platform/modules/module3
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: WARNING: Could not map module to ISP config string
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: No module data found
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: WARNING: Could not map module to ISP config string
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: No module data found
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: WARNING: Could not map module to ISP config string
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: No module data found
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: WARNING: Could not map module to ISP config string
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: NvPclHwGetModuleList: No module data found
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: OFParserGetVirtualDevice: NVIDIA Camera virtual enumerator not found in proc device-tree
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: ---- imager: No override file found. ----
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: LSC: LSC surface is not based on full res!
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: ---- imager: No override file found. ----
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: LSC: LSC surface is not based on full res!
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: ---- imager: No override file found. ----
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: LSC: LSC surface is not based on full res!
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: ---- imager: No override file found. ----
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.service - Running on Python: 3.8.10
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.cpu - Found 8 CPU
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.gpu - GPU "ga10b" status in /sys/devices/platform/17000000.ga10b
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.gpu - GPU "ga10b" frq in /sys/devices/platform/17000000.ga10b/devfreq/17000000.ga10b
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.processes - Process service started
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: LSC: LSC surface is not based on full res!
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.memory - Found EMC!
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.memory - Memory service started
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.engine - Special Engine group found: [dlaX]
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.engine - Special Engine group found: [pvaX]
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.engine - Engines found: [APE DLA0 DLA1 NVDEC NVENC NVJPG PVA0 SE VIC]
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "CV0" in thermal_zone2
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "CPU" in thermal_zone0
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "SOC2" in thermal_zone7
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "SOC0" in thermal_zone5
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "CV1" in thermal_zone3
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "GPU" in thermal_zone1
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "tj" in thermal_zone8
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "SOC1" in thermal_zone6
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.temperature - Found thermal "CV2" in thermal_zone4
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.power - Alarms VDD_IN - {'crit_alarm': 0, 'max_alarm': 0}
Dec  8 11:28:40 tegra-ubuntu nvargus-daemon[1412]: === gst-launch-1.0[4848]: CameraProvider initialized (0xffff852b08a0)LSC: LSC surface is not based on full res!
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.power - Alarms VDD_CPU_GPU_CV - {'crit_alarm': 0, 'max_alarm': 0}
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.power - Alarms VDD_SOC - {'crit_alarm': 0, 'max_alarm': 0}
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [WARNING] jtop.core.power - Skipped "sum of shunt voltages" /sys/bus/i2c/devices/1-0040/hwmon/hwmon2/in7_label
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.power - Found I2C power monitor
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.fan - RPM pwm_tach found in /sys/class/hwmon/hwmon0
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.fan - Found nvfancontrol.service
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [WARNING] jtop.core.fan - No fan found
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: [INFO] jtop.core.jetson_clocks - jetson_clocks found in /usr/bin/jetson_clocks
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2539.841362] bwmgr API not supported
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.354822] ar0234 32-0018: ar0234_power_on:
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.375155] bwmgr API not supported
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.382946] ar0234 32-0018: ar0234_set_mode: Set mode 0 at CAM2
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.386543] ar0234 32-0018: ar0234_write_table: start write table CAM2
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: Traceback (most recent call last):
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:   File "/usr/local/bin/jtop", line 8, in <module>
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:     sys.exit(main())
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:   File "/usr/local/lib/python3.8/dist-packages/jtop/__main__.py", line 106, in main
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:     server = JtopServer(force=args.force)
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:   File "/usr/local/lib/python3.8/dist-packages/jtop/service.py", line 299, in __init__
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:     self.nvpmodel = NVPModelService(self.jetson_clocks)
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:   File "/usr/local/lib/python3.8/dist-packages/jtop/core/nvpmodel.py", line 439, in __init__
Dec  8 11:28:40 tegra-ubuntu jtop[4847]:     name=self._nvpmodel_now['name'],
Dec  8 11:28:40 tegra-ubuntu jtop[4847]: TypeError: 'NoneType' object is not subscriptable
Dec  8 11:28:40 tegra-ubuntu systemd[1]: jtop.service: Main process exited, code=exited, status=1/FAILURE
Dec  8 11:28:40 tegra-ubuntu systemd[1]: jtop.service: Failed with result 'exit-code'.
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.963106] ar0234 32-0018: ar0234_set_frame_rate: set frame rate 10 FPS
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.963114] ar0234 32-0018: ar0234_set_frame_rate: val: 10000000, , frame_length: 3671
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.963281] ar0234 32-0018: ar0234_start_streaming: Start stream CAM2
Dec  8 11:28:40 tegra-ubuntu kernel: [ 2548.963285] ar0234 32-0018: ar0234_write_table: start write table CAM2
Dec  8 11:28:41 tegra-ubuntu kernel: [ 2548.963753] bwmgr API not supported
Dec  8 11:28:41 tegra-ubuntu kernel: [ 2549.226819] bwmgr API not supported

And the nvargus log when starting the second camera at PHY0 CILB while the first camera is still running:

Dec  8 11:28:55 tegra-ubuntu nvargus-daemon: Module_id 30 Severity 2 : (fusa) Error: BadParameter  propagating from:/capture/src/fusaCsiStreamHandler.cpp 248
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon: Module_id 30 Severity 2 : (fusa) Error: BadParameter  propagating from:/capture/src/fusaViHandler.cpp 328
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon: Module_id 30 Severity 2 : (fusa) Error: BadParameter  propagating from:/capture/src/fusaViHandler.cpp 124
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon: Module_id 30 Severity 2 : (fusa) Error: BadParameter  propagating from:/capture/src/core.cpp 76
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: === gst-launch-1.0[4923]: Connection established (FFFF559ED900)=== gst-launch-1.0[4923]: CameraProvider initialized (0xfffefc000df0)SCF: Error BadParameter:  (propagating from src/services/capture/FusaCaptureViCsiHw.cpp, function openViCsi(), line 390)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: SCF: Error BadParameter:  (propagating from src/services/capture/CaptureServiceDeviceViCsi.cpp, function open(), line 336)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: SCF: Error BadParameter:  (propagating from src/services/capture/CaptureServiceDevice.cpp, function openSource(), line 398)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: SCF: Error BadParameter:  (propagating from src/services/capture/CaptureService.cpp, function openSource(), line 501)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: SCF: Error BadParameter:  (propagating from src/api/Session.cpp, function initialize(), line 294)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: SCF: Error BadParameter:  (propagating from src/api/CameraDriver.cpp, function createSession(), line 645)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: (Argus) Error BadParameter:  (propagating from src/api/CaptureSessionImpl.cpp, function initialize(), line 177)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: (Argus) Error BadParameter:  (propagating from src/api/CameraProviderImpl.cpp, function createCaptureSessionInternal(), line 305)
Dec  8 11:28:55 tegra-ubuntu nvargus-daemon[1412]: (Argus) Error InvalidState: Element not found (in /dvs/git/dirty/git-master_linux/camera/utils/nvcamerautils/inc/Vector.h, function remove(), line 172)

Any suggestions what could be the reason? It’s hard to debug when the sources are not open.

BR
Kris