Xavier NX MIPI channel reset when streaming from IMX297 image sensor

Robotics & Edge Computing Jetson & Embedded Systems Jetson Xavier NX
1

Hello,

trying to get images from an IMX297 MIPI sensor (736x540 resolution, 40fps), I only get periodic channel resets, every 5 seconds.

TTY log:

[  859.066928] tegra194-vi5 15c10000.vi: no reply from camera processor                              
[  859.067444] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 5000 ms                                                                                          
[  859.067848] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel                                                                                     
[  859.080023] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel

Oddly, I get a correct image whenever a reset is triggered, as if the reset event could unlock the sensor’s transmitter. Then no frames at all until next reset.

Trace log included below

Many thanks in advance

Andrea

        v4l2-ctl-6161  [002] ....  2633.189859: tegra_channel_open: vi-output, vc_mipi 2-001a                                                                                                              
        v4l2-ctl-6161  [000] ....  2633.192082: tegra_channel_set_power: vc_mipi 2-001a : 0x1
        v4l2-ctl-6161  [000] ....  2633.192093: camera_common_s_power: status : 0x1
        v4l2-ctl-6161  [000] ....  2633.192124: tegra_channel_set_power: 15a00000.nvcsi--3 : 0x1
        v4l2-ctl-6161  [000] ....  2633.192127: csi_s_power: enable : 0x1
        v4l2-ctl-6161  [000] ....  2633.194071: tegra_channel_close: vi-output, vc_mipi 2-001a
        v4l2-ctl-6161  [000] ....  2633.194077: tegra_channel_set_power: vc_mipi 2-001a : 0x0
        v4l2-ctl-6161  [000] ....  2633.194082: camera_common_s_power: status : 0x0
        v4l2-ctl-6161  [000] ....  2633.194112: tegra_channel_set_power: 15a00000.nvcsi--3 : 0x0
        v4l2-ctl-6161  [000] ....  2633.194114: csi_s_power: enable : 0x0
        v4l2-ctl-6162  [005] ....  2633.200401: tegra_channel_open: vi-output, vc_mipi 2-001a
        v4l2-ctl-6162  [005] ....  2633.200411: tegra_channel_set_power: vc_mipi 2-001a : 0x1
        v4l2-ctl-6162  [005] ....  2633.200417: camera_common_s_power: status : 0x1
        v4l2-ctl-6162  [005] ....  2633.200484: tegra_channel_set_power: 15a00000.nvcsi--3 : 0x1
        v4l2-ctl-6162  [005] ....  2633.200487: csi_s_power: enable : 0x1
        v4l2-ctl-6162  [005] ....  2633.200872: tegra_channel_close: vi-output, vc_mipi 2-001a
        v4l2-ctl-6162  [005] ....  2633.200876: tegra_channel_set_power: vc_mipi 2-001a : 0x0
        v4l2-ctl-6162  [005] ....  2633.200880: camera_common_s_power: status : 0x0
        v4l2-ctl-6162  [005] ....  2633.200918: tegra_channel_set_power: 15a00000.nvcsi--3 : 0x0
        v4l2-ctl-6162  [005] ....  2633.200919: csi_s_power: enable : 0x0
    usb_cam_node-6164  [005] ....  2634.053792: tegra_channel_open: vi-output, vc_mipi 2-001a
    usb_cam_node-6164  [000] ....  2634.055100: tegra_channel_set_power: vc_mipi 2-001a : 0x1
    usb_cam_node-6164  [000] ....  2634.055111: camera_common_s_power: status : 0x1
    usb_cam_node-6164  [000] ....  2634.055141: tegra_channel_set_power: 15a00000.nvcsi--3 : 0x1
    usb_cam_node-6164  [000] ....  2634.055143: csi_s_power: enable : 0x1
    usb_cam_node-6164  [000] ....  2634.057968: tegra_channel_capture_setup: vnc_id 0 W 736 H 540 fmt c5
    usb_cam_node-6164  [001] ....  2634.068074: tegra_channel_set_stream: enable : 0x1
     kworker/0:2-6196  [000] ....  2634.073077: rtos_queue_peek_from_isr_failed: tstamp:82691794044 queue:0x0bcbbbb8
     kworker/0:2-6196  [000] ....  2634.073080: rtcpu_start: tstamp:82691795349
     kworker/0:2-6196  [000] ....  2634.073082: rtos_queue_send_from_isr_failed: tstamp:82691933497 queue:0x0bcb2e38
     kworker/0:2-6196  [000] ....  2634.073083: rtos_queue_send_from_isr_failed: tstamp:82691933648 queue:0x0bcb76a0
     kworker/0:2-6196  [000] ....  2634.073083: rtos_queue_send_from_isr_failed: tstamp:82691933799 queue:0x0bcb9220
     kworker/0:2-6196  [000] ....  2634.073084: rtos_queue_send_from_isr_failed: tstamp:82691933963 queue:0x0bcb9fe0
     kworker/0:2-6196  [000] ....  2634.073085: rtos_queue_send_from_isr_failed: tstamp:82691934109 queue:0x0bcbada0
     kworker/0:2-6196  [000] ....  2634.073086: rtcpu_string: tstamp:82691934568 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/0:2-6196  [000] ....  2634.073101: rtcpu_string: tstamp:82691934773 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/0:2-6196  [000] ....  2634.073106: rtcpu_string: tstamp:82691935026 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/0:2-6196  [000] ....  2634.073110: rtcpu_string: tstamp:82691935267 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/0:2-6196  [000] ....  2634.073114: rtcpu_string: tstamp:82691935499 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/0:2-6196  [000] ....  2634.073118: rtcpu_string: tstamp:82691935748 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/0:2-6196  [000] ....  2634.073121: rtcpu_string: tstamp:82691935980 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/0:2-6196  [000] ....  2634.073125: rtcpu_string: tstamp:82691944733 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
     kworker/0:2-6196  [000] ....  2634.073126: rtcpu_string: tstamp:82691944851 id:0x04010000 str:"on 2.2
"
     kworker/0:2-6196  [000] ....  2634.073130: rtos_queue_send_from_isr_failed: tstamp:82691957426 queue:0x0bcb2e38
     kworker/0:2-6196  [000] ....  2634.073131: rtos_queue_send_from_isr_failed: tstamp:82691957595 queue:0x0bcb76a0
     kworker/0:2-6196  [000] ....  2634.073131: rtos_queue_send_from_isr_failed: tstamp:82691957753 queue:0x0bcb9220
     kworker/0:2-6196  [000] ....  2634.073132: rtos_queue_send_from_isr_failed: tstamp:82691957898 queue:0x0bcb9fe0
     kworker/0:2-6196  [000] ....  2634.073133: rtos_queue_send_from_isr_failed: tstamp:82691958043 queue:0x0bcbada0
     kworker/0:2-6196  [000] ....  2634.073134: rtcpu_string: tstamp:82691958977 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
"
    usb_cam_node-6164  [000] ....  2634.073617: tegra_channel_set_stream: 15a00000.nvcsi--3 : 0x1
    usb_cam_node-6164  [000] ....  2634.073620: csi_s_stream: enable : 0x1
    usb_cam_node-6164  [000] ....  2634.073630: tegra_channel_set_stream: vc_mipi 2-001a : 0x1
 vi-output, vc_m-6282  [003] ....  2634.109437: tegra_channel_capture_frame: sof:2646.183859776
 vi-output, vc_m-6282  [003] ....  2634.109442: tegra_channel_capture_frame: eof:84677.883752448
     kworker/0:2-6196  [000] ....  2634.129112: rtos_queue_send_from_isr_failed: tstamp:82692131812 queue:0x0bcb2e38
     kworker/0:2-6196  [000] ....  2634.129118: rtos_queue_send_from_isr_failed: tstamp:82692131957 queue:0x0bcb76a0
     kworker/0:2-6196  [000] ....  2634.129120: rtos_queue_send_from_isr_failed: tstamp:82692132103 queue:0x0bcb9220
     kworker/0:2-6196  [000] ....  2634.129122: rtos_queue_send_from_isr_failed: tstamp:82692132242 queue:0x0bcb9fe0
     kworker/0:2-6196  [000] ....  2634.129125: rtos_queue_send_from_isr_failed: tstamp:82692132379 queue:0x0bcbada0
     kworker/0:2-6196  [000] ....  2634.129128: rtcpu_vinotify_event: tstamp:82692283798 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:82047249184 data:0x10000000
     kworker/0:2-6196  [000] ....  2634.129131: rtcpu_vinotify_event: tstamp:82692283934 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:82047257312 data:0x31000001
     kworker/0:2-6196  [000] ....  2634.129133: rtcpu_vinotify_event: tstamp:82692284087 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:82047259520 data:0x07020001
     kworker/0:2-6196  [000] ....  2634.129135: rtcpu_vinotify_event: tstamp:82692284216 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:82047299136 data:0x10000000
     kworker/0:2-6196  [000] ....  2634.129136: rtcpu_vinotify_event: tstamp:82692284365 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:82047307392 data:0x31000002
     kworker/0:2-6196  [000] ....  2634.129145: rtcpu_vinotify_event: tstamp:82693301010 tag:FS channel:0x00 frame:1 vi_tstamp:82693239672 data:0x00000010
     kworker/0:2-6196  [000] ....  2634.129147: rtcpu_vinotify_event: tstamp:82693301180 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:82693239673 data:0x00000000
     kworker/0:2-6196  [000] ....  2634.129149: rtcpu_vinotify_event: tstamp:82693301311 tag:CHANSEL_PXL_SOF channel:0x23 frame:1 vi_tstamp:82693245618 data:0x00000001
     kworker/0:2-6196  [000] ....  2634.129151: rtcpu_vinotify_event: tstamp:82693301460 tag:RESERVED_19 channel:0x23 frame:1 vi_tstamp:82088385152 data:0x08020001
     kworker/0:2-6196  [000] ....  2634.129153: rtcpu_vinotify_event: tstamp:82693301587 tag:CHANSEL_FAULT channel:0x23 frame:1 vi_tstamp:82693245714 data:0x00000100
     kworker/0:2-6196  [000] ....  2634.129154: rtcpu_vinotify_event: tstamp:82693301735 tag:RESERVED_19 channel:0x23 frame:1 vi_tstamp:82088391776 data:0x01020001
     kworker/0:2-6196  [000] ....  2634.129156: rtcpu_vinotify_event: tstamp:82693489419 tag:CHANSEL_FAULT channel:0x23 frame:1 vi_tstamp:82693488443 data:0x021b0182
     kworker/0:2-6196  [000] ....  2634.129158: rtcpu_vinotify_event: tstamp:82693489570 tag:RESERVED_19 channel:0x23 frame:1 vi_tstamp:82096156448 data:0x01020001
     kworker/0:2-6196  [000] ....  2634.129160: rtcpu_vinotify_event: tstamp:82693489699 tag:ATOMP_FRAME_DONE channel:0x23 frame:1 vi_tstamp:82693488457 data:0x00000000
     kworker/0:2-6196  [000] ....  2634.129162: rtcpu_vinotify_event: tstamp:82693489846 tag:RESERVED_19 channel:0x23 frame:1 vi_tstamp:82096157696 data:0x02020001
     kworker/0:2-6196  [000] ....  2634.129164: rtcpu_vinotify_event: tstamp:82693489978 tag:FE channel:0x00 frame:1 vi_tstamp:82693488705 data:0x00000020
     kworker/0:2-6196  [000] ....  2634.129166: rtcpu_vinotify_event: tstamp:82693809638 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:82693488706 data:0x00000000
     kworker/0:2-6196  [000] ....  2634.129168: rtcpu_vinotify_event: tstamp:82693809769 tag:FS channel:0x00 frame:2 vi_tstamp:82693743143 data:0x00000010
     kworker/0:2-6196  [000] ....  2634.129170: rtcpu_vinotify_event: tstamp:82693809918 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:82693743144 data:0x00000000
   kworker/0:2-6196  [000] ....  2634.129172: rtcpu_vinotify_event: tstamp:82693810052 tag:CHANSEL_PXL_SOF channel:0x23 frame:2 vi_tstamp:82693749089 data:0x00000001
     kworker/0:2-6196  [000] ....  2634.129174: rtcpu_vinotify_event: tstamp:82693810201 tag:RESERVED_19 channel:0x23 frame:2 vi_tstamp:82104496192 data:0x08020001
     kworker/0:2-6196  [000] ....  2634.129175: rtcpu_vinotify_event: tstamp:82693810327 tag:CHANSEL_FAULT channel:0x23 frame:2 vi_tstamp:82693749184 data:0x00000100
     kworker/0:2-6196  [000] ....  2634.129177: rtcpu_vinotify_event: tstamp:82693810473 tag:RESERVED_19 channel:0x23 frame:2 vi_tstamp:82104500160 data:0x01020001
     kworker/0:2-6196  [000] ....  2634.185149: rtcpu_vinotify_event: tstamp:82694148832 tag:CHANSEL_FAULT channel:0x23 frame:2 vi_tstamp:82693991913 data:0x021b0182
     kworker/0:2-6196  [000] ....  2634.185165: rtcpu_vinotify_event: tstamp:82694148987 tag:RESERVED_19 channel:0x23 frame:2 vi_tstamp:82112267520 data:0x01020001
     kworker/0:2-6196  [000] ....  2634.185173: rtcpu_vinotify_event: tstamp:82694149118 tag:ATOMP_FRAME_DONE channel:0x23 frame:2 vi_tstamp:82693991928 data:0x00000000
     kworker/0:2-6196  [000] ....  2634.185179: rtcpu_vinotify_event: tstamp:82694149266 tag:RESERVED_19 channel:0x23 frame:2 vi_tstamp:82112268768 data:0x02020001
     kworker/0:2-6196  [000] ....  2634.185185: rtcpu_vinotify_event: tstamp:82694149393 tag:FE channel:0x00 frame:2 vi_tstamp:82693992177 data:0x00000020
     kworker/0:2-6196  [000] ....  2634.185190: rtcpu_vinotify_event: tstamp:82694149541 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:82693992178 data:0x00000000
     kworker/0:2-6196  [000] ....  2634.185196: rtcpu_vinotify_error: tstamp:82694253413 tag:CHANSEL_NOMATCH channel:0x01 frame:3 vi_tstamp:82694252560 data:0x00000569
     kworker/0:2-6196  [000] ....  2634.185202: rtcpu_vinotify_event: tstamp:82694487763 tag:FS channel:0x00 frame:3 vi_tstamp:82694246614 data:0x00000010
     kworker/0:2-6196  [000] ....  2634.185207: rtcpu_vinotify_event: tstamp:82694487915 tag:CHANSEL_NOMATCH channel:0x01 frame:3 vi_tstamp:82694252560 data:0x00000569
3

Looks like the sensor driver CID function didn’t implement well cause the problem.
Modify them as dummy function to confirm it.

4

Hello, I found the problem is related to embedded_metadata_height not zero in camera device tree, as I am connecting to the real sensor through a CSI bridge. All working as expected after setting it to zero.

Thanks

Andrea

6

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.