ERROR: NULL VI channel received on AGX Xavier

[alok.deshpande]

Hello,

I am facing an issue similar to:

ERROR: NULL VI channel received, VIFALC_TDSTATE. How can I deal with it?

Hi, I’m enabling a custom sensor which works on AGX Xavier. I’m trying to modify device tree and driver. But I got the errors. dmesg log [ 31.197978] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms [ 31.198238] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel [ 31.199019] (NULL device *): vi_capture_control_message: NULL VI channel received [ 31.199215] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_clo…

Jetpack 5.0.2 : vi_capture_control_message: NULL VI channel received

hello khang.l4es, may I know what’s the camera hardware connections? you’ll need to use serdes_pix_clk_hz for sensor modules that use serializer/deserializer chips (i.e. GMSL or FPD link), otherwise, please use pixel_clk_hzfor normal bayer camera sensors. camera firmware with debug flag enabled it helps for further investigation not only for deskew calibration but also for NVCSI configurations.

Jetson_Linux 34.1 : vi_capture_control_message: NULL VI channel received

we upgrade Jetson_Linux from 32.6.1 to 34.1 on xavier platform It can be displayed normally in version 32.6.1, but it can only be displayed successfully in 34.1 occasionally camera format # v4l2-ctl -d /dev/video0 --list-formats-ext ioctl: VIDIOC_ENUM_FMT Type: Video Capture [0]: 'AR24' (32-bit BGRA 8-8-8-8) Size: Discrete 400x400 Interval: Discrete 0.033s (30.000 fps) Size: Discrete 800x800 Inte…

ERROR: NULL VI channel received, VIFALC_TDSTATE. How can I deal with it?

Thank you for your reply. But I have succeeded to enable that sensor without firmware flash. I changed pix_clk_hz and serdes_pix_clk_hz to fix this problem. The values which are used in Xavier are not working on Orin. Is there any change about these vaules?

and others. In many cases, the solutions were different for the same error messages, so my case may be different.

My setup:

Jetson AGX Xavier, Jetpack 5.1.1
Custom carrier board (device-tree attached below, can provide some more info if required)
Camera: IMX462 sensor with GMSL serdes
ISP camera overrides (can provide if requested)

Full device-tree:
full.dts.txt (299.6 KB)

Partial device-tree with just camera subsystem:
tegra194-agx-eimx462-8cam.dtsi.txt (24.7 KB)
ecam_cuxvr_mode.dtsi.txt (8.5 KB)

I have updated nvargus-daemon.service to enable all debug messages and boost clocks. See attached bash scripts to confirm this: enable_sys_debug_logs.sh, max_isp_clk.sh
nvargus-daemon.service.txt (575 Bytes)
max_isp_clk.sh.txt (655 Bytes)
enable_sys_debug_logs.sh.txt (380 Bytes)

vi clock rate is: 998400000

isp clock rate is: 1190400000

nvcsi clock rate is: 400000000

emc clock rate is: 2133000000

I have also installed the RTCPU debug firmware: Camera failed with log:VIFALC_TDSTATE on Jetpack5.0.2 - #4 by JerryChang

====

I have verified that all 4 cameras are detected (when 4 out of 8 are connected):

e.g. in dmesg for video0 (i.e. eimx462 31-0043)…

[   11.907111] [IMX462]: probing v4l2 sensor.

[   11.907234] Current SIO ports is A

[   11.907331] no of mipi lanes 2

[   11.907425] eimx462 31-0043:  Issuing CHIP reset for Deserializer ... 

[   12.232909] eimx462 31-0043: SIOA Port I2C translated successfully

[   12.233154] eimx462 31-0043: reset_mcu ..... function 

[   12.512739] eimx462 31-0043: Same firmware in MCU & text file - (1_2_CU20_6_1_1_0_b56697c). Skipping FW Update...

[   12.714217] configuring SIOA serializer successful

[   12.820559] eimx462 31-0043: configuring Deserializer Successful

[   12.937246] eimx462 31-0043: Num of Controls - 9

[   12.990769] eimx462 31-0043: cam_init 1928MCU CMD ID CAM INIT Success !! 

[   13.005848] eimx462 31-0043: tegracam sensor driver:eimx462_v2.0.6

[   13.005857] e-imx462: cam_probe : Use_sensor_mode_id = 1

[   13.036934] Frame rate data : 0

[   13.043570] eimx462 31-0043: cam_fill_string_ctrl[418] Set!

[   13.065850] Frame rate data : 10485760

[   13.073716] tegra-camrtc-capture-vi tegra-capture-vi: subdev eimx462 31-0043 bound

[   13.074998] eimx462 31-0043:  ser_status=21

[   13.103371] loop: module loaded

[   13.182730] eimx462 31-0043: Detected IMX462 sensor

In v4l2-ctl:

user@tegra-ubuntu:~$ v4l2-ctl --list-devices

NVIDIA Tegra Video Input Device (platform:tegra-camrtc-ca):

	/dev/media0

vi-output, eimx462 31-0043 (platform:tegra-capture-vi:2):

	/dev/video0

vi-output, eimx462 33-0043 (platform:tegra-capture-vi:4):

	/dev/video2

	/dev/video3

vi-output, eimx462 32-0043 (platform:tegra-capture-vi:5):

	/dev/video1

=====

First, I checked v4l2-compliance with video0. Result:

…

Codec ioctls (Input 0):

	test VIDIOC_(TRY_)ENCODER_CMD: OK (Not Supported)

	test VIDIOC_G_ENC_INDEX: OK (Not Supported)

	test VIDIOC_(TRY_)DECODER_CMD: OK (Not Supported)

Buffer ioctls (Input 0):

		fail: v4l2-test-buffers.cpp(715): q.create_bufs(node, 1, &fmt) != EINVAL

	test VIDIOC_REQBUFS/CREATE_BUFS/QUERYBUF: FAIL

	test VIDIOC_EXPBUF: OK

	test Requests: OK (Not Supported)

Total for tegra-video device /dev/video0: 45, Succeeded: 44, Failed: 1, Warnings: 0

====

Then, I tested the following V4L2 pipeline with video0:

v4l2-ctl -v width=1920,height=1080,pixelformat=‘GB12’ --set-ctrl=bypass_mode=0 -c sensor_mode=0 --stream-mmap -d 0 --stream-to=video0.raw

Result in dmesg (see attached dmesg.log for full)

[ 3323.477088] mode settings - 0

[ 3323.490752] [RCE] VM0 deactivating.VM0 activating.NVCSILP clock rate = 204000000 Hz.

[ 3323.490762] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=2, csi=2)

[ 3323.490767] [RCE] MIPI clock = 750000 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0

[ 3323.490793] [RCE] ===== NVCSI Stream Configuration =====

[ 3323.490796] [RCE] stream_id: PP 2, csi_port: PORT C

[ 3323.490800] [RCE] Brick: PHY 1, Mode: D-PHY

[ 3323.490803] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2

[ 3323.490806] [RCE] Clock information:

[ 3323.490829] [RCE] MIPI clock rate: 750.00 MHz

[ 3323.490834] [RCE] T_HS settle: 0, T_CLK settle: 0

[ 3323.490837] [RCE] ======================================

[ 3323.490841] [RCE] tegra_nvcsi_stream_open(vm0, stream=2, csi=2)

[ 3323.490845] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_A_SW_RESET_0 = 00000003

[ 3323.490849] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_B_SW_RESET_0 = 00000000

[ 3323.490854] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_1_LM_SW_RESET_0 = 00000001

[ 3323.490858] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_1_LM_SW_RESET_0 = 00000000

[ 3323.490875] [RCE] nvcsi_calc_ths_settle ths_settle 19

[ 3323.490878] [RCE] nvcsi_calc_ths_settle ths_settle 19

[ 3323.490882] [RCE] nvcsi_calc_tclk_settle tclk_settle 33

[ 3323.490890] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_A_SW_RESET_0 = 00000000

[ 3323.490894] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_B_SW_RESET_0 = 00000000

[ 3323.611114] eimx462 31-0043:  cam_stream_config 633ISP GET CMD Status Succesfull !! 

[ 3323.798410] eimx462 31-0043:  cam_stream_on 1106MCU Stream On Success !! 

[ 3324.062852] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 131072

[ 3324.063179] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel

[ 3324.064442] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3324.064642] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2

[ 3324.064837] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3324.064983] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 1

[ 3324.065483] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

[ 3324.462836] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel

[ 3324.463504] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3324.463716] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2

[ 3324.463932] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3324.464127] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 1

[ 3324.464611] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

[ 3324.862841] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel

[ 3324.863499] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3324.863689] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2

[ 3324.863909] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3324.864073] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 1

[ 3324.864598] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

[ 3325.262809] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel

[ 3325.263498] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3325.263675] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2

[ 3325.263924] (NULL device *): vi_capture_control_message: NULL VI channel received

…

[ 3338.464015] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 1

[ 3338.464585] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

[ 3338.473066] eimx462 31-0043:  cam_stream_off 1178 MCU Get CMD Stream off Success !! 

[ 3338.473087] (NULL device *): vi_capture_control_message: NULL VI channel received

[ 3338.473324] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2

Result from trace (full trace in attached sys_trace.log)

        v4l2-ctl-7064    [001] ....  3323.456059: tegra_channel_open: vi-output, eimx462 31-0043

        v4l2-ctl-7064    [001] ....  3323.462525: tegra_channel_set_power: eimx462 31-0043 : 0x1

        v4l2-ctl-7064    [001] ....  3323.462541: camera_common_s_power: status : 0x1

        v4l2-ctl-7064    [001] ....  3323.462890: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1

        v4l2-ctl-7064    [001] ....  3323.462893: csi_s_power: enable : 0x1

        v4l2-ctl-7064    [001] ....  3323.463403: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt c4

        v4l2-ctl-7064    [001] ....  3323.470697: tegra_channel_set_stream: enable : 0x1

        v4l2-ctl-7064    [001] ....  3323.472230: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1

        v4l2-ctl-7064    [001] ....  3323.472232: csi_s_stream: enable : 0x1

        v4l2-ctl-7064    [001] ....  3323.472895: tegra_channel_set_stream: eimx462 31-0043 : 0x1

     kworker/2:3-124     [002] ....  3323.490742: rtcpu_string: tstamp:105005791419 id:0x04010000 str:"VM0 activating."

     kworker/2:3-124     [002] ....  3323.490745: rtcpu_string: tstamp:105005883206 id:0x04010000 str:"NVCSILP clock rate = 204000000 Hz.

"

     kworker/2:3-124     [002] ....  3323.490757: rtcpu_string: tstamp:105005980457 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=2, csi"

     kworker/2:3-124     [002] ....  3323.490760: rtcpu_string: tstamp:105005980571 id:0x04010000 str:"=2)

"

     kworker/2:3-124     [002] ....  3323.490764: rtcpu_string: tstamp:105005981111 id:0x04010000 str:"MIPI clock = 750000 kHz, tHS-SETTLE = 0, tCLK-SE"

     kworker/2:3-124     [002] ....  3323.490765: rtcpu_string: tstamp:105005981213 id:0x04010000 str:"TTLE = 0

"

     kworker/2:3-124     [002] ....  3323.490791: rtcpu_string: tstamp:105005981528 id:0x04010000 str:"===== NVCSI Stream Configuration =====

"

     kworker/2:3-124     [002] ....  3323.490795: rtcpu_string: tstamp:105005981847 id:0x04010000 str:"stream_id: PP 2, csi_port: PORT C

"

     kworker/2:3-124     [002] ....  3323.490799: rtcpu_string: tstamp:105005982170 id:0x04010000 str:"Brick: PHY 1, Mode: D-PHY

"

     kworker/2:3-124     [002] ....  3323.490802: rtcpu_string: tstamp:105005982548 id:0x04010000 str:"Partition: CIL A, LP bypass: Enabled, Lanes: 2

"

     kworker/2:3-124     [002] ....  3323.490806: rtcpu_string: tstamp:105005982758 id:0x04010000 str:"Clock information:

"

     kworker/2:3-124     [002] ....  3323.490809: rtcpu_string: tstamp:105005983163 id:0x04010000 str:"MIPI clock rate: 750.00 MHz

"

     kworker/2:3-124     [002] ....  3323.490833: rtcpu_string: tstamp:105005983479 id:0x04010000 str:"T_HS settle: 0, T_CLK settle: 0

"

     kworker/2:3-124     [002] ....  3323.490836: rtcpu_string: tstamp:105005983763 id:0x04010000 str:"======================================

"

     kworker/2:3-124     [002] ....  3323.490839: rtcpu_string: tstamp:105005987059 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=2, csi=2)

"

     kworker/2:3-124     [002] ....  3323.490843: rtcpu_string: tstamp:105005987841 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_A_"

     kworker/2:3-124     [002] ....  3323.490844: rtcpu_string: tstamp:105005987942 id:0x04010000 str:"SW_RESET_0 = 00000003

"

     kworker/2:3-124     [002] ....  3323.490847: rtcpu_string: tstamp:105005988431 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_B_"

     kworker/2:3-124     [002] ....  3323.490848: rtcpu_string: tstamp:105005988532 id:0x04010000 str:"SW_RESET_0 = 00000000

"

     kworker/2:3-124     [002] ....  3323.490852: rtcpu_string: tstamp:105005989173 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_1_LM_SW_RESET"

     kworker/2:3-124     [002] ....  3323.490853: rtcpu_string: tstamp:105005989271 id:0x04010000 str:"_0 = 00000001

"

     kworker/2:3-124     [002] ....  3323.490856: rtcpu_string: tstamp:105005995454 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_1_LM_SW_RESET"

     kworker/2:3-124     [002] ....  3323.490857: rtcpu_string: tstamp:105005995553 id:0x04010000 str:"_0 = 00000000

"

     kworker/2:3-124     [002] ....  3323.490860: rtcpu_string: tstamp:105005996069 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 19

"

     kworker/2:3-124     [002] ....  3323.490877: rtcpu_string: tstamp:105005996417 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 19

"

     kworker/2:3-124     [002] ....  3323.490881: rtcpu_string: tstamp:105005996757 id:0x04010000 str:"nvcsi_calc_tclk_settle tclk_settle 33

"

     kworker/2:3-124     [002] ....  3323.490888: rtcpu_string: tstamp:105005997321 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_A_"

     kworker/2:3-124     [002] ....  3323.490889: rtcpu_string: tstamp:105005997420 id:0x04010000 str:"SW_RESET_0 = 00000000

"

     kworker/2:3-124     [002] ....  3323.490892: rtcpu_string: tstamp:105005997918 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_B_"

     kworker/2:3-124     [002] ....  3323.490893: rtcpu_string: tstamp:105005998016 id:0x04010000 str:"SW_RESET_0 = 00000000

"

     kworker/2:3-124     [002] ....  3323.490898: rtcpu_vinotify_event: tstamp:105006229012 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360189755904 data:0xcd9ce50010000000

     kworker/2:3-124     [002] ....  3323.490898: rtcpu_vinotify_event: tstamp:105006229152 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360189761376 data:0x0000000031000001

     kworker/2:3-124     [002] ....  3323.490900: rtcpu_vinotify_event: tstamp:105006229306 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360189820192 data:0xcd9ce20010000000

     kworker/2:3-124     [002] ....  3323.490901: rtcpu_vinotify_event: tstamp:105006229440 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360189825760 data:0x0000000031000002

     kworker/2:3-124     [002] ....  3324.050736: rtcpu_vinotify_event: tstamp:105023757255 cch:0 vi:0 tag:FS channel:0x01 frame:0 vi_tstamp:3360751487808 data:0x0000000000000012

     kworker/2:3-124     [002] ....  3324.050739: rtcpu_vinotify_event: tstamp:105023757395 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:3360751487808 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3324.050741: rtcpu_vinotify_event: tstamp:105023757547 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:3360751517504 data:0x0000000000000001

     kworker/2:3-124     [002] ....  3324.050742: rtcpu_vinotify_event: tstamp:105023757679 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3360751518784 data:0x0000000008020001

 vi-output, eimx-7066    [000] ....  3324.063165: tegra_channel_capture_frame: sof:3360.751517504

 vi-output, eimx-7066    [000] ....  3324.063169: tegra_channel_capture_frame: eof:3360.781813408

 vi-output, eimx-7066    [000] ....  3324.065279: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt c4

     kworker/2:3-124     [002] ....  3324.106739: rtcpu_vinotify_event: tstamp:105024522986 cch:0 vi:0 tag:FE channel:0x01 frame:0 vi_tstamp:3360781806144 data:0x0000000000000022

     kworker/2:3-124     [002] ....  3324.106742: rtcpu_vinotify_event: tstamp:105024523142 cch:0 vi:0 tag:CHANSEL_SHORT_FRAME channel:0x44 frame:0 vi_tstamp:3360781806144 data:0x0000200001000000

     kworker/2:3-124     [002] ....  3324.106743: rtcpu_vinotify_event: tstamp:105024523296 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3360781813760 data:0x0000000001020001

     kworker/2:3-124     [002] ....  3324.106744: rtcpu_vinotify_event: tstamp:105024523438 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:3360781806144 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3324.106745: rtcpu_vinotify_event: tstamp:105024523592 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360781886752 data:0xcd9ce50010000000

     kworker/2:3-124     [002] ....  3324.106746: rtcpu_vinotify_event: tstamp:105024523723 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360781892320 data:0x0000000031000003

     kworker/2:3-124     [002] ....  3324.106747: rtcpu_vinotify_event: tstamp:105024523881 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360784656480 data:0xcd9ce50010000000

     kworker/2:3-124     [002] ....  3324.106748: rtcpu_vinotify_event: tstamp:105024524012 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360784661952 data:0x0000000031000001

     kworker/2:3-124     [002] ....  3324.106749: rtcpu_vinotify_event: tstamp:105024821394 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360784733152 data:0xcd9ce20010000000

     kworker/2:3-124     [002] ....  3324.106750: rtcpu_vinotify_event: tstamp:105024821530 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3360784738944 data:0x0000000031000002

     kworker/2:3-124     [002] ....  3324.442724: rtcpu_vinotify_event: tstamp:105036089585 cch:0 vi:0 tag:FS channel:0x01 frame:0 vi_tstamp:3361149671296 data:0x0000000000000012

     kworker/2:3-124     [002] ....  3324.442727: rtcpu_vinotify_event: tstamp:105036089725 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:3361149671296 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3324.442728: rtcpu_vinotify_event: tstamp:105036089876 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:3361149814432 data:0x0000000000000001

     kworker/2:3-124     [002] ....  3324.442729: rtcpu_vinotify_event: tstamp:105036090009 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3361149815680 data:0x0000000008020001

 vi-output, eimx-7066    [000] ....  3324.462820: tegra_channel_capture_frame: sof:3361.149814432

 vi-output, eimx-7066    [000] ....  3324.462823: tegra_channel_capture_frame: eof:3361.181791904

 vi-output, eimx-7066    [000] ....  3324.464449: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt c4

     kworker/2:3-124     [002] ....  3324.498794: rtcpu_vinotify_event: tstamp:105036996482 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:3361181791296 data:0x0000000004370002

     kworker/2:3-124     [002] ....  3324.498798: rtcpu_vinotify_event: tstamp:105036996622 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:3361181791744 data:0x0000000000000000

     kworker/2:3-124     [002] ....  3324.498799: rtcpu_vinotify_event: tstamp:105036996777 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3361181794208 data:0x0000000002020001

     kworker/2:3-124     [002] ....  3324.498800: rtcpu_vinotify_event: tstamp:105036996910 cch:0 vi:0 tag:FE channel:0x01 frame:0 vi_tstamp:3361181791904 data:0x0000000000000022

     kworker/2:3-124     [002] ....  3324.498801: rtcpu_vinotify_event: tstamp:105036997066 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:3361181791904 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3324.498802: rtcpu_vinotify_event: tstamp:105036997199 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3361181799424 data:0x0000000000020001

     kworker/2:3-124     [002] ....  3324.498803: rtcpu_vinotify_event: tstamp:105036997350 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3361183786976 data:0xcd9ce50010000000

     kworker/2:3-124     [002] ....  3324.498804: rtcpu_vinotify_event: tstamp:105036997482 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3361183792480 data:0x0000000031000001

     kworker/2:3-124     [002] ....  3324.498805: rtcpu_vinotify_event: tstamp:105036997631 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3361183846816 data:0xcd9ce20010000000

     kworker/2:3-124     [002] ....  3324.498806: rtcpu_vinotify_event: tstamp:105036997762 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3361183852384 data:0x0000000031000002

     kworker/2:3-124     [002] ....  3324.834705: rtcpu_vinotify_event: tstamp:105048453158 cch:0 vi:0 tag:FS channel:0x01 frame:0 vi_tstamp:3361549657376 data:0x0000000000000012

     kworker/2:3-124     [002] ....  3324.834709: rtcpu_vinotify_event: tstamp:105048453299 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:3361549657376 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3324.834711: rtcpu_vinotify_event: tstamp:105048453451 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:3361549800512 data:0x0000000000000001

     kworker/2:3-124     [002] ....  3324.834739: rtcpu_vinotify_event: tstamp:105048453584 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3361549801792 data:0x0000000008020001

 vi-output, eimx-7066    [000] ....  3324.862818: tegra_channel_capture_frame: sof:3361.549800512

 vi-output, eimx-7066    [000] ....  3324.862822: tegra_channel_capture_frame: eof:3361.581778016

 vi-output, eimx-7066    [000] ....  3324.864415: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt c4

…

 vi-output, eimx-7066    [000] ....  3338.062353: tegra_channel_capture_frame: sof:3374.749338464

 vi-output, eimx-7066    [000] ....  3338.062357: tegra_channel_capture_frame: eof:3374.781316000

 vi-output, eimx-7066    [000] ....  3338.064377: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt c4

     kworker/2:3-124     [002] ....  3338.074198: rtcpu_vinotify_event: tstamp:105460913339 cch:0 vi:0 tag:FS channel:0x01 frame:0 vi_tstamp:3374749195328 data:0x0000000000000012

     kworker/2:3-124     [002] ....  3338.074201: rtcpu_vinotify_event: tstamp:105460913483 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:3374749195328 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3338.074205: rtcpu_vinotify_event: tstamp:105461220927 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:3374749338464 data:0x0000000000000001

     kworker/2:3-124     [002] ....  3338.074206: rtcpu_vinotify_event: tstamp:105461221065 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3374749339744 data:0x0000000008020001

     kworker/2:3-124     [002] ....  3338.074208: rtcpu_vinotify_event: tstamp:105462159917 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:3374781315392 data:0x0000000004370002

     kworker/2:3-124     [002] ....  3338.074209: rtcpu_vinotify_event: tstamp:105462160056 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:3374781315840 data:0x0000000000000000

     kworker/2:3-124     [002] ....  3338.074211: rtcpu_vinotify_event: tstamp:105462160209 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3374781318304 data:0x0000000002020001

     kworker/2:3-124     [002] ....  3338.074212: rtcpu_vinotify_event: tstamp:105462160341 cch:0 vi:0 tag:FE channel:0x01 frame:0 vi_tstamp:3374781316000 data:0x0000000000000022

     kworker/2:3-124     [002] ....  3338.074213: rtcpu_vinotify_event: tstamp:105462160496 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:3374781316000 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3338.074214: rtcpu_vinotify_event: tstamp:105462160645 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3374781323520 data:0x0000000000020001

     kworker/2:3-124     [002] ....  3338.074215: rtcpu_vinotify_event: tstamp:105462160795 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3374783738816 data:0xcd9ce50010000000

     kworker/2:3-124     [002] ....  3338.074217: rtcpu_vinotify_event: tstamp:105462160927 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3374783744320 data:0x0000000031000001

     kworker/2:3-124     [002] ....  3338.074218: rtcpu_vinotify_event: tstamp:105462161076 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3374783798976 data:0xcd9ce20010000000

     kworker/2:3-124     [002] ....  3338.074219: rtcpu_vinotify_event: tstamp:105462161209 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3374783804544 data:0x0000000031000002

        v4l2-ctl-7064    [001] ....  3338.321880: tegra_channel_close: vi-output, eimx462 31-0043

 vi-output, eimx-7066    [001] ....  3338.462362: tegra_channel_capture_frame: sof:3375.149324320

 vi-output, eimx-7066    [001] ....  3338.462366: tegra_channel_capture_frame: eof:3375.181301792

 vi-output, eimx-7066    [001] ....  3338.464380: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt c4

        v4l2-ctl-7064    [000] ....  3338.465425: tegra_channel_set_stream: enable : 0x0

        v4l2-ctl-7064    [000] ....  3338.465428: tegra_channel_set_stream: eimx462 31-0043 : 0x0

     kworker/2:3-124     [002] ....  3338.466193: rtcpu_vinotify_event: tstamp:105473418518 cch:0 vi:0 tag:FS channel:0x01 frame:0 vi_tstamp:3375149181184 data:0x0000000000000012

     kworker/2:3-124     [002] ....  3338.466196: rtcpu_vinotify_event: tstamp:105473418658 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:3375149181184 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3338.466198: rtcpu_vinotify_event: tstamp:105473418809 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:3375149324320 data:0x0000000000000001

     kworker/2:3-124     [002] ....  3338.466199: rtcpu_vinotify_event: tstamp:105473418977 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3375149325568 data:0x0000000008020001

     kworker/2:3-124     [002] ....  3338.466200: rtcpu_vinotify_event: tstamp:105474429720 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:3375181301216 data:0x0000000004370002

     kworker/2:3-124     [002] ....  3338.466201: rtcpu_vinotify_event: tstamp:105474429856 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:3375181301632 data:0x0000000000000000

     kworker/2:3-124     [002] ....  3338.466202: rtcpu_vinotify_event: tstamp:105474430008 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3375181304064 data:0x0000000002020001

     kworker/2:3-124     [002] ....  3338.466203: rtcpu_vinotify_event: tstamp:105474430140 cch:0 vi:0 tag:FE channel:0x01 frame:0 vi_tstamp:3375181301760 data:0x0000000000000022

     kworker/2:3-124     [002] ....  3338.466204: rtcpu_vinotify_event: tstamp:105474430293 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:3375181301792 data:0x0000000800000000

     kworker/2:3-124     [002] ....  3338.466205: rtcpu_vinotify_event: tstamp:105474432338 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3375181309312 data:0x0000000000020001

        v4l2-ctl-7064    [001] ....  3338.473077: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x0

        v4l2-ctl-7064    [001] ....  3338.473082: csi_s_stream: enable : 0x0

        v4l2-ctl-7064    [001] ....  3338.475345: tegra_channel_set_power: eimx462 31-0043 : 0x0

        v4l2-ctl-7064    [001] ....  3338.475360: camera_common_s_power: status : 0x0

        v4l2-ctl-7064    [001] ....  3338.475371: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x0

        v4l2-ctl-7064    [001] ....  3338.475373: csi_s_power: enable : 0x0

     kworker/2:3-124     [002] ....  3344.737934: rtcpu_string: tstamp:105669059283 id:0x04010000 str:"VM0 deactivating."

sys_trace.log (113.0 KB)
dmesg.log (24.3 KB)

=====

Finally I tried the following gst argus pipeline with video1 (just to make sure it’s not just an issue with one camera):

GST_DEBUG=3 gst-launch-1.0 -v nvarguscamerasrc sensor-id=1 sensor-mode=0 ! “video/x-raw(memory:NVMM), width=(int)1920,height=(int)1080, format=(string)NV12, framerate=30/1” ! nvv4l2h265enc ! “video/x-h265, stream-format=(string)byte-stream” ! h265parse ! matroskamux ! queue ! filesink location=video0.mkv

Console result from gst-debug:

Setting pipeline to PAUSED ...

Opening in BLOCKING MODE 

Pipeline is live and does not need PREROLL ...

Setting pipeline to PLAYING ...

New clock: GstSystemClock

/GstPipeline:pipeline0/GstNvArgusCameraSrc:nvarguscamerasrc0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1

/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1

/GstPipeline:pipeline0/nvv4l2h265enc:nvv4l2h265enc0.GstPad:src: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2

/GstPipeline:pipeline0/GstCapsFilter:capsfilter1.GstPad:src: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2

/GstPipeline:pipeline0/GstH265Parse:h265parse0.GstPad:sink: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2

/GstPipeline:pipeline0/GstCapsFilter:capsfilter1.GstPad:sink: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2

Redistribute latency...

/GstPipeline:pipeline0/nvv4l2h265enc:nvv4l2h265enc0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1

/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1

GST_ARGUS: Creating output stream

CONSUMER: Waiting until producer is connected...

GST_ARGUS: Available Sensor modes :

GST_ARGUS: 1920 x 1080 FR = 29.999999 fps Duration = 33333334 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;



GST_ARGUS: 1920 x 1080 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;



GST_ARGUS: 1280 x 720 FR = 29.999999 fps Duration = 33333334 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;



GST_ARGUS: 1280 x 720 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;



GST_ARGUS: Running with following settings:

   Camera index = 1 

   Camera mode  = 0 

   Output Stream W = 1920 H = 1080 

   seconds to Run    = 0 

   Frame Rate = 29.999999 

GST_ARGUS: Setup Complete, Starting captures for 0 seconds

GST_ARGUS: Starting repeat capture requests.

CONSUMER: Producer has connected; continuing.

nvbuf_utils: dmabuf_fd -1 mapped entry NOT found

Execution ended after 0:00:01.312667880

Setting pipeline to NULL ...

Result in dmesg:

[ 4471.446131] fuse: init (API version 7.32)

[ 4472.278745] [RCE] VM0 deactivating.VM0 activating.NVCSILP clock rate = 204000000 Hz.

[ 4472.839161] falcon 154c0000.nvenc: Direct firmware load for nvhost_nvenc070.fw failed with error -2

[ 4472.839368] falcon 154c0000.nvenc: Falling back to sysfs fallback for: nvhost_nvenc070.fw

[ 4472.841888] falcon 154c0000.nvenc: looking for firmware in subdirectory

[ 4472.927007] falcon 15a80000.nvenc1: Direct firmware load for nvhost_nvenc070.fw failed with error -2

[ 4472.927245] falcon 15a80000.nvenc1: Falling back to sysfs fallback for: nvhost_nvenc070.fw

[ 4472.930076] falcon 15a80000.nvenc1: looking for firmware in subdirectory

[ 4473.181684] Frame rate data : 125829120

[ 4473.196600] mode settings - 0

[ 4473.202719] [RCE] tegra_nvcsi_stream_tpg_disable(vm0, stream=5, vc=1)

[ 4473.202747] [RCE] tegra_nvcsi_stream_tpg_disable: channel 1 is already disabled

[ 4473.329166] eimx462 32-0043:  cam_stream_config 633ISP GET CMD Status Succesfull !! 

[ 4473.516085] eimx462 32-0043:  cam_stream_on 1106MCU Stream On Success !! 

[ 4473.538647] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=5, csi=6)

[ 4473.538656] [RCE] MIPI clock = 750000 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0

[ 4473.538679] [RCE] ===== NVCSI Stream Configuration =====

[ 4473.538685] [RCE] stream_id: PP 5, csi_port: PORT G

[ 4473.538689] [RCE] Brick: PHY 3, Mode: D-PHY

[ 4473.538693] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2

[ 4473.538698] [RCE] Clock information:

[ 4473.538701] [RCE] MIPI clock rate: 750.00 MHz

[ 4473.538727] [RCE] T_HS settle: 0, T_CLK settle: 0

[ 4473.538731] [RCE] ======================================

[ 4473.538735] [RCE] tegra_nvcsi_stream_open(vm0, stream=5, csi=6)

[ 4473.538739] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_SW_RESET_0 = 00000003

[ 4473.538745] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_SW_RESET_0 = 00000000

[ 4473.538749] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET_0 = 00000001

[ 4473.538754] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET_0 = 00000000

[ 4473.538774] [RCE] nvcsi_calc_ths_settle ths_settle 19

[ 4473.538778] [RCE] nvcsi_calc_ths_settle ths_settle 19

[ 4473.538782] [RCE] nvcsi_calc_tclk_settle tclk_settle 33

[ 4473.538787] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_SW_RESET_0 = 00000000

[ 4473.538792] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_SW_RESET_0 = 00000000

[ 4474.239655] eimx462 32-0043:  cam_stream_off 1178 MCU Get CMD Stream off Success !! 

[ 4474.270638] [RCE] tegra_nvcsi_stream_tpg_disable(vm0, stream=5, vc=1)

[ 4474.270650] [RCE] tegra_nvcsi_stream_tpg_disable: error: stream 5 is configured for phy input

[ 4474.270661] [RCE] tegra_nvcsi_stream_close(vm0, stream=5, csi=6)

[ 4474.270666] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_SW_RESET_0 = 00000003

[ 4474.270671] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_SW_RESET_0 = 00000000

[ 4474.270677] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET_0 = 00000001

Result from nvargus-daemon logs: see attached nvargus-daemon.log. (It is long and I am unsure if it provides correct/useful information.)

nvargus-daemon.log (129.8 KB)

====

Important: I have verified the camera driver and this device tree HAVE worked with Jetpack 4.6 (with minimal changes). So I know that the hardware itself is correct. But the problem must be in changes required for Jetpack 5.

Would you please be able to help debug this issue? I am able to collect some oscilloscope readings during the next 3-4 days if required.

Thank you in advance.

[ShaneCCC]

Could modify the serdes_pix_clk_hz t0 249999999 to try.

					serdes_pix_clk_hz = "250000000";

[alok.deshpande]

Hello ShaneCCC, thanks for the suggestion. I will try that.

However, currently serdes_pix_clk_hz = "250000000”. Your suggested value is only 1Hz less. Is there a reason that might make a difference? Is the 1.5Gbps threshold so strict?

Additionally, I take it that the change also needs to be made in the driver for the MAX9296 register settings, correct?

[alok.deshpande]

I tested it, unfortunately there was no change.

Additionally, I am not able to make a 1-Hz change in the camera driver to the deserializer output rate according to the reference:

deser_output_data_rate = serdes_pix_clk_hz * num_bits_per_pix / num_csi_lanes

Because the output rate of MAX9296 changes in units of 100MHz according to the datasheet:

[ShaneCCC]

Looks like you are using E-CON’s camera.
Have you consult with them to get the driver?

[alok.deshpande]

Hello,

Yes, I am in discussion with e-con as well, in parallel with this conversation. I have updated their Jetpack 4 camera driver for my camera to Jetpack 5.

However, as I have yet to hear further from them about this issue, I considered reaching out for your support as well, since the problem may be with my updates to the kernel/DTB rather than their driver.

Hope that is fine. Would you have any suggestions in the meantime while I wait for them?

Thank you.

[ShaneCCC]

This issue will require our camera partner to do the support, let me add @JeslinPaul here to help you

[alok.deshpande]

Hello,

Just to provide an update, I did resolve the issue preventing me from collecting raw images. Specifically, the impact of the null pointer exceptions.

It appears there is an issue caused by the vi_channel_error_recover function in vi5_fops.c even as of R35.5.0. Whenever the CSI subdev is unable to close a stream due to the channel pointer becoming null, the channel capture_state remains in CAPTURE_ERROR, and the logic in vi5_fops.c prevents it from entering the CAPTURE_GOOD state.

This is probably intentional and needs to be resolved, but it seems that not closing an NVCSI stream upon one error does not prevent collecting additional frames. After making the workaround fix, I think I am able to collect raw frames using v4l2-ctl:

user@tegra-ubuntu:~$ v4l2-ctl -v width=1920,height=1080,pixelformat='GB12' --set-ctrl=bypass_mode=0,frame_rate=30000000 -c sensor_mode=0 --stream-mmap -d 0 --stream-to=video0.raw

<<<<<<<<<<<<<<< 13.55 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 21.64 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 24.40 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 25.79 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 26.62 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 27.18 fps
<<<<<<317440 != 4147200
<4096 != 4147200
...
<4096 != 4147200
< 27.58 fps
4096 != 4147200
<4096 != 4147200
...
<4096 != 4147200
< 27.89 fps
4096 != 4147200
...
<4096 != 4147200
< 30.00 fps
4096 != 4147200
<4096 != 4147200
< 30.00 fps
4096 != 4147200
<4096 != 4147200

And the trace is attached below.
trace.log (737.9 KB)
I am aware that there are CHANSEL_SHORT_FRAME errors even after boosting clocks, but that is minor for now.

At this point, I would like to be able to do the following:

1. Optionally, convert the raw capture into an encoded video, given the video format of the sensor

2. Use nvarguscamerasrc (with the econ provided ISP settings, camera_overrides.isp) to get an encoded video in gstreamer

I am trying the following reference , which has been tested in Jetpack 4.6 with these cameras and confirmed to work:

Unfortunately, I am still receiving the following error according to the Gstreamer console logs:

user@tegra-ubuntu:~$ DISPLAY=:0 GST_DEBUG=3 gst-launch-1.0 -v nvarguscamerasrc sensor-id=0 sensor-mode=0 ! "video/x-raw(memory:NVMM), width=(int)1920,height=(int)1080, format=(string)NV12, framerate=30/1" ! nvv4l2h265enc ! "video/x-h265, stream-format=(string)byte-stream" ! h265parse ! matroskamux ! queue ! filesink location=video0.mkv

No protocol specified
No EGL Display
nvbufsurftransform: Could not get EGL display connection
Setting pipeline to PAUSED …
No protocol specified
nvbuf_utils: Could not get EGL display connection
Opening in BLOCKING MODE
0:00:00.933197449 2616 0xaaaaead0b0a0 WARN v4l2 gstv4l2object.c:2398:gst_v4l2_object_add_interlace_mode:0xaaaaeace64f0 Failed to determine interlace mode
0:00:00.933303691 2616 0xaaaaead0b0a0 WARN v4l2 gstv4l2object.c:2398:gst_v4l2_object_add_interlace_mode:0xaaaaeace64f0 Failed to determine interlace mode
0:00:00.933360684 2616 0xaaaaead0b0a0 WARN v4l2 gstv4l2object.c:2398:gst_v4l2_object_add_interlace_mode:0xaaaaeace64f0 Failed to determine interlace mode
0:00:00.933415021 2616 0xaaaaead0b0a0 WARN v4l2 gstv4l2object.c:2398:gst_v4l2_object_add_interlace_mode:0xaaaaeace64f0 Failed to determine interlace mode
0:00:00.933549648 2616 0xaaaaead0b0a0 WARN v4l2 gstv4l2object.c:4512:gst_v4l2_object_probe_caps:nvv4l2h265enc0:src Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
Pipeline is live and does not need PREROLL …
0:00:00.935743257 2616 0xaaaaead14cc0 FIXME default gstutils.c:3980:gst_pad_create_stream_id_internal:nvarguscamerasrc0:src Creating random stream-id, consider implementing a deterministic way of creating a stream-id
Setting pipeline to PLAYING …
New clock: GstSystemClock
/GstPipeline:pipeline0/GstNvArgusCameraSrc:nvarguscamerasrc0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1
/GstPipeline:pipeline0/nvv4l2h265enc:nvv4l2h265enc0.GstPad:src: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
/GstPipeline:pipeline0/GstCapsFilter:capsfilter1.GstPad:src: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
/GstPipeline:pipeline0/GstH265Parse:h265parse0.GstPad:sink: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
/GstPipeline:pipeline0/GstCapsFilter:capsfilter1.GstPad:sink: caps = video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
Redistribute latency…
NvMMLiteOpen : Block : BlockType = 8
===== NVMEDIA: NVENC =====
NvMMLiteBlockCreate : Block : BlockType = 8
0:00:00.959353336 2616 0xaaaaead14cc0 WARN v4l2bufferpool gstv4l2bufferpool.c:1114:gst_v4l2_buffer_pool_start:nvv4l2h265enc0:pool:src Uncertain or not enough buffers, enabling copy threshold
/GstPipeline:pipeline0/nvv4l2h265enc:nvv4l2h265enc0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1
GST_ARGUS: Creating output stream
No protocol specified
CONSUMER: Waiting until producer is connected…
GST_ARGUS: Available Sensor modes :
GST_ARGUS: 1920 x 1080 FR = 29.999999 fps Duration = 33333334 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;

GST_ARGUS: 1920 x 1080 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;

GST_ARGUS: 1280 x 720 FR = 29.999999 fps Duration = 33333334 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;

GST_ARGUS: 1280 x 720 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 31.622776; Exposure Range min 450000, max 400000000;

GST_ARGUS: Running with following settings:
Camera index = 0
Camera mode = 0
Output Stream W = 1920 H = 1080
seconds to Run = 0
Frame Rate = 29.999999
GST_ARGUS: Setup Complete, Starting captures for 0 seconds
GST_ARGUS: Starting repeat capture requests.
CONSUMER: Producer has connected; continuing.
nvbuf_utils: dmabuf_fd -1 mapped entry NOT found
Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, threadExecute:694 NvBufSurfaceFromFd Failed.
Error generated. /dvs/git/dirty/git-master_linux/multimedia/nvgstreamer/gst-nvarguscamera/gstnvarguscamerasrc.cpp, threadFunction:247 (propagating)
ERROR: from element /GstPipeline:pipeline0/GstNvArgusCameraSrc:nvarguscamerasrc0: DISCONNECTED
Additional debug info:
Argus Error Status
Execution ended after 0:00:01.487375112
Setting pipeline to NULL …
(Argus) Error EndOfFile: Unexpected error in reading socket (in src/rpc/socket/client/ClientSocketManager.cpp, function recvThreadCore(), line 277)
(Argus) Error EndOfFile: Receiving thread terminated with error (in src/rpc/socket/client/ClientSocketManager.cpp, function recvThreadWrapper(), line 379)
(Argus) Error InvalidState: Receive thread is not running cannot send. (in src/rpc/socket/client/ClientSocketManager.cpp, function send(), line 96)
GST_ARGUS: Cleaning up
(Argus) Error InvalidState: (propagating from src/rpc/socket/client/SocketClientDispatch.cpp, function dispatch(), line 91)
(Argus) Error InvalidState: Receive thread is not running cannot send. (in src/rpc/socket/client/ClientSocketManager.cpp, function send(), line 96)
(Argus) Error InvalidState: (propagating from src/rpc/socket/client/SocketClientDispatch.cpp, function dispatch(), line 91)
(Argus) Error InvalidState: Receive thread is not running cannot send. (in src/rpc/socket/client/ClientSocketManager.cpp, function send(), line 96)
(Argus) Error InvalidState: (propagating from src/rpc/socket/client/SocketClientDispatch.cpp, function dispatch(), line 91)
Caught SIGSEGV
./test_gstargus.sh: line 4: 2616 Segmentation fault (core dumped) GST_DEBUG=3 gst-launch-1.0 -v nvarguscamerasrc sensor-id=0 sensor-mode=0 ! “video/x-raw(memory:NVMM), width=(int)1920,height=(int)1080, format=(string)NV12, framerate=30/1” ! nvv4l2h265enc ! “video/x-h265, stream-format=(string)byte-stream” ! h265parse ! matroskamux ! queue ! filesink location=video0.mkv

The dmesg log just shows:

[  317.539901] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 131072
[  317.641815] eimx462 33-0043:  cam_stream_on 1106MCU Stream On Success !! 
[  328.179367] eimx462 33-0043:  cam_stream_off 1178 MCU Get CMD Stream off Success !!

While we wait for econ you might be able to provide an update based on the above information.

Thank you.

[ShaneCCC]

This error could be the display driver didn’t load correctly.
Suppose you are running this command by connect to AGX by ssh.
Could you try it on AGX console directly.

@alok.deshpande

No protocol specified
No EGL Display
nvbufsurftransform: Could not get EGL display connection

[alok.deshpande]

I am actually running this with a remote X session (ssh -X) and I have set the DISPLAY variable (export DISPLAY=:0). However, there is no monitor connected to the custom carrier board.

Is it not possible to run the above pipeline in a remote session? Local session is not what my team would like to test in the end.

I also tried this pipeline as an alternative:

DISPLAY=:0 GST_DEBUG=3 gst-launch-1.0 nvarguscamerasrc sensor-id=1   ! "video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=30/1" ! queue ! fpsdisplaysink text-overlay=0 video-sink=fakesink  sync=false  -v

because it should not be using the display framework. However, I receive the same error (nvbuf_utils: dmabuf_fd -1 mapped entry NOT found). This makes me think that it should not be related to the display, no?

Please do clarify. I have encountered the EGL warning on Orin before (not Xavier) and the solution was to just set the DISPLAY variable as I have done.

[alok.deshpande]

@alok.deshpande

nvbufsurftransform: Could not get EGL display connection

I followed this and confirmed that I still receive the error nvbuf_utils: dmabuf_fd -1 mapped entry NOT found when DISPLAY is NOT set (and no X-forwarding).

In that case, the warning No EGL Display. nvbufsurftransform: Could not get EGL display connection disappears. So I guess it should not be related.

[ShaneCCC]

What’s the trace log for launch nvarguscamerasrc?

[alok.deshpande]

Attached is the trace for this pipeline (with X-forwarding to set DISPLAY):

DISPLAY=$DISPLAY GST_DEBUG=3 gst-launch-1.0 nvarguscamerasrc sensor-id=0   ! "video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=30/1" ! queue ! fpsdisplaysink text-overlay=0 video-sink=fakesink  sync=false

trace_gst-nvarguscamerasrc_fakesink.log (29.9 KB)

I am noticing that that my error is most similar to Nvarguscamerasrc jetpack-4.3, No cameras available, nvbuf_utils: Could not get EGL display connection, requirements - #38 by phdm where the problem was not loading the kernel module nvgpu.ko.

In my case, nvgpu.ko is loaded, could the problem be with nvdisplay? I notice there were changes to nvdisplay driver between R32 to R35 according to you. Are those applicable to AGX Xavier causing EGLStream issues in headless mode?

I am using the defaults in kernel_display_supplements.tar.gz, but should I be updating the following three kernel modules in some way for my custom carrier board?

• nvidia-drm.ko
• nvidia-modeset.ko
• nvidia.ko

Currently I am using the defaults located in the BSP.

[alok.deshpande]

I tried cross-compiling those three modules and received this error:

user@tegra-ubuntu:/lib/modules/5.10.104-tegra/extra/opensrc-disp$ sudo insmod nvidia.ko
insmod: ERROR: could not insert module nvidia.ko: No such device

Apparently those modules are not needed for Xavier according to @DaveYYY Insmod NVIDIA-kernel-module-source-TempVersion Failed - #9 by liwang54321

Currently, the last option I can think of is editing gst-nvargustcamerasrc to remove the dependency on EGLStreams and/or passing EGL_NO_DISPLAY. If there is something else you can suggest, please let me know.

[alok.deshpande]

The problem ended up not being related to EGL or display. I discovered it was due to a timeout time between sending a capture request and receiving the start-of-frame. See this thread for more details.

The investigation has been resolved for this thread, and any further details/discussion can be added the other one that I linked.

[JerryChang]

hello alok.deshpande,

thanks for status update, here’s quick takeaway for others.

note, internal timeout it’s 2500ms by default, it has configure to a larger amount (i.e. 4500ms) in the r35.5.0 release version.