FPGA capture on r35.2.1, VIFALC_TDSTATE

Hello all,
Im porting drivers from TX2 to Xavier NX, however I encountered the following error early on. I’ve read other forum questions on similar topic, but I could not make use of these answers.
Im not sure where’s the problem.

It seems to me as if the signal would not reach the ports electrically, but the electrical connection seems ok (checked with multimeter). Port binding seems correct (I expect signal on CAM0, so => tegra_sinterface_a => port_index = 0 am I right?)

1. Background info:

a. Video information:
YUV 422 8-bit 1920x1080@30

b. I expanded the supported formats in sensor_common.c (any other file I do not know of?):

	else if (strncmp(pixel_t, "yuv_uyvy8", size) == 0)
		*format = V4L2_PIX_FMT_UYVY;

c. L4T version: r35.2.1
d. I tried to disable ECC error checking in csi5_fops.c, with no results (I manually typed patch from previous L4T versions though)
e. I tried different values for pix_clk_hz and serdes_pix_clk_hz
f. Camera has no I2C, so it is streaming on power-on (with discontinuous clock)

2. Error info:
a. The tracing looks like this:

[001] ....   449.004047: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/2:3-112     [002] ....   449.051114: rtcpu_vinotify_event: tstamp:14808926640 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:473882738208 data:0xcd9ce50010000000
     kworker/2:3-112     [002] ....   449.051117: rtcpu_vinotify_event: tstamp:14808926802 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:473882749984 data:0x0000000031000001
     kworker/2:3-112     [002] ....   449.107133: rtcpu_vinotify_event: tstamp:14809944119 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:473918060736 data:0xcd9ce20010000000
     kworker/2:3-112     [002] ....   449.107135: rtcpu_vinotify_event: tstamp:14809944284 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:473918072704 data:0x0000000031000002

b. Debug logs in dmesg:

[  435.887171] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=0, csi=0)
[  435.887183] [RCE] MIPI clock = 297000 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0
[  435.887189] [RCE] ===== NVCSI Stream Configuration =====
[  435.887211] [RCE] stream_id: PP 0, csi_port: PORT A
[  435.887219] [RCE] Brick: PHY 0, Mode: D-PHY
[  435.887225] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2
[  435.887230] [RCE] Clock information:
[  435.887235] [RCE] MIPI clock rate: 297.00 MHz
[  435.887240] [RCE] T_HS settle: 0, T_CLK settle: 0
[  435.887245] [RCE] ======================================
[  435.887250] [RCE] tegra_nvcsi_stream_open(vm0, stream=0, csi=0)
[  435.887255] [RCE] nvcsi_calc_ths_settle ths_settle 20
[  435.887260] [RCE] nvcsi_calc_ths_settle ths_settle 20
[  435.887265] [RCE] nvcsi_calc_tclk_settle tclk_settle 33
[  438.495153] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  438.495411] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  438.496056] (NULL device *): vi_capture_control_message: NULL VI channel received
[  438.496203] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[  438.496394] (NULL device *): vi_capture_control_message: NULL VI channel received
[  438.496546] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[  438.497024] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  441.311138] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  441.311366] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  441.312070] (NULL device *): vi_capture_control_message: NULL VI channel received
[  441.312223] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[  441.312420] (NULL device *): vi_capture_control_message: NULL VI channel received
[  441.312573] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[  441.313049] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  443.871120] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  443.871334] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  443.872050] (NULL device *): vi_capture_control_message: NULL VI channel received
[  443.872206] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[  443.872398] (NULL device *): vi_capture_control_message: NULL VI channel received
[  443.872535] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0

DTB configuration:

/ {
	tegra-capture-vi {
		num-channels = <1>;
		ports {
			#address-cells = <1>;
			#size-cells = <0>;
			vi_port0: port@0 {
				reg = <0>;
				vi_in0: endpoint {
					//vc-id = <0>;
					port-index = <0>;
					bus-width = <2>;
					remote-endpoint = <&imx219_csi_out0>;
				};
			};
			/*
			vi_port1: port@1 {
				reg = <1>;
				vi_in1: endpoint {
					//vc-id = <0>;
					port-index = <4>;
					bus-width = <2>;
					remote-endpoint = <&imx219_csi_out1>;
				};
			};*/
		};
	};

	host1x@13e00000 {
		nvcsi@15a00000 {
			num-channels = <1>;
			#address-cells = <1>;
			#size-cells = <0>;
			channel@0 {
				reg = <0>;
				ports {
					#address-cells = <1>;
					#size-cells = <0>;
					port@0 {
						reg = <0>;
						imx219_csi_in0: endpoint@0 {
							port-index = <0>;
							bus-width = <2>;
							remote-endpoint = <&imx219_phy_out0>;
						};
					};
					port@1 {
						reg = <1>;
						imx219_csi_out0: endpoint@1 {
							remote-endpoint = <&vi_in0>;
						};
					};
				};
			};
			/*
			channel@1 {
				reg = <1>;
				ports {
					#address-cells = <1>;
					#size-cells = <0>;
					port@0 {
						reg = <0>;
						imx219_csi_in1: endpoint@0 {
							port-index = <4>;
							bus-width = <2>;
							remote-endpoint = <&imx219_phy_out1>;
						};
					};
					port@1 {
						//status = "okay";
						reg = <1>;
						imx219_csi_out1: endpoint@1 {
							//status = "okay";
							remote-endpoint = <&vi_in1>;
						};
					};
				};
			};*/
		};//nvcsi end
	}; //host2x end


	cam_i2cmux {
		i2c_0:i2c@0 {
			vendorname_fhd@10 {
				#address-cells = <1>;
				#size-cells = <0>;
				status="okay";
				devnode = "video0";
				compatible = "vendorname,vendorname_fhd";
				reg = <0x10>;
				physical_w = "5.095";
				physical_h = "4.930";
				post_crop_frame_drop = "0";
				use_sensor_mode_id = "true";
				sensor_model ="Vendorname_FHD";
				set_mode_delay_ms = "3000";

				mode0 {
					mclk_khz = "24000";
					num_lanes = "2";
					tegra_sinterface = "serial_a";
					vc_id = "0";
					discontinuous_clk = "yes";
					dpcm_enable = "false";
					cil_settletime = "0";
					dynamic_pixel_bit_depth = "8";
					//------------------------------ 
					mode_type = "yuv";//
					csi_pixel_bit_depth = "8";//
					pixel_phase = "uyvy";//
					//------------------------------
	


					active_w = "1920";
					active_h = "1080";
					readout_orientation = "0";
					line_length = "2200";//
					inherent_gain = "1";
					pix_clk_hz =        "148500000";
					serdes_pix_clk_hz = "148500000";
					gain_factor = "10";
					min_gain_val = "0"; // dB 
					max_gain_val = "300"; // dB 
					step_gain_val = "3"; // 0.3
					default_gain = "0";
					min_hdr_ratio = "1";
					max_hdr_ratio = "1";
					framerate_factor = "1000000";
					min_framerate = "30000000";
					max_framerate = "30000000";
					step_framerate = "1";
					default_framerate = "30000000";
					exposure_factor = "1000000";
					min_exp_time = "59"; //us, 2 lines
					max_exp_time = "33333";
					step_exp_time = "1";
					default_exp_time = "59";// us 
					embedded_metadata_height = "0";
				};


				ports {
					#address-cells = <1>;
					#size-cells = <0>;
					port@0 {
						reg = <0>;
						imx219_phy_out0: endpoint {
							 port-index = <0>;
							 bus-width = <2>;
							 remote-endpoint = <&imx219_csi_in0>;
						 };
					};
				};
			};
		};
// tegra camera platform:
		compatible = "nvidia, tegra-camera-platform";
		num_csi_lanes = <1>;
		max_lane_speed = <4000000>;///
		min_bits_per_pixel = <8>;//
		isp_peak_byte_per_pixel = <5>;
		isp_bw_margin_pct = <25>;
		max_pixel_rate = <240000>;

hello jaglaz,

according to those error logs, there’s no validate frame signals received by VI engine.

could you please also share device tree settings within tegra-camera-platform {...}
I’ve seen there’s erroneous here,
for example,

whereas num_csi_lanes should be 2 since you’ve specify num_lanes and bus-width as 2-lane configure,
please have a try, thanks

This is the entire tegra camera platform scope:
(To clarify: I disabled second camera and its port bindings to narrow down possible errors).

/ {
	tegra-camera-platform {
		/**
		 * Physical settings to calculate max ISO BW
		 *
		 * num_csi_lanes = <>;
		 * Total number of CSI lanes when all cameras are active
		 *
		 * max_lane_speed = <>;
		 * Max lane speed in Kbit/s
		 *
		 * min_bits_per_pixel = <>;
		 * Min bits per pixel
		 *
		 * vi_peak_byte_per_pixel = <>;
		 * Max byte per pixel for the VI ISO case
		 *
		 * vi_bw_margin_pct = <>;
		 * Vi bandwidth margin in percentage
		 *
		 * max_pixel_rate = <>;
		 * Max pixel rate in Kpixel/s for the ISP ISO case
		 *
		 * isp_peak_byte_per_pixel = <>;
		 * Max byte per pixel for the ISP ISO case
		 *
		 * isp_bw_margin_pct = <>;
		 * Isp bandwidth margin in percentage
		 */
		compatible = "nvidia, tegra-camera-platform";
		num_csi_lanes = <1>;
		max_lane_speed = <4000000>;///
		min_bits_per_pixel = <8>;//
		isp_peak_byte_per_pixel = <5>;
		isp_bw_margin_pct = <25>;
		max_pixel_rate = <240000>;

		modules {
			module0 {
				status = "okay";
				badge = "e3326_bottom_P5V27C";
				position = "front";
				orientation = "0";
				drivernode0 {
					status = "okay";
					pcl_id = "v4l2_sensor";
					devname = "Vendorname";
					proc-device-tree = "/proc/device-tree/cam_i2cmux/i2c@0/Vendorname_FHD@10";
				};
			};
			/*
 			 module1 {
 				badge = "jakku_rear_RBP194";
 				position = "front";
 				orientation = "1";
 				drivernode0 {
 					pcl_id = "v4l2_sensor";
 					devname = "IR_CSI";
 					proc-device-tree = "/proc/device-tree/cam_i2cmux/i2c@1/IR_CSI@10";
 				};
 			};
			*/
		};

	};

EDIT: I eliminated the error in num_csi_lanes = <1>; and switched it to 2. The error persists, I will do some testing and tweaks in the meantime.

EDIT2: The camera does not send validate frame signal by design, I applied the patch in post How to disable ECC check - #6. Similar solution worked for TX2 systems, this time it does not. It is worth mentioning that the patch seems to be for previous version of L4T and there might be some code changes I do not know of.

hello jaglaz,

to clarify, num_csi_lanes in tegra-camera-platform {} is the total lane settings you’re used in your system.
for example, if you’re using dual camera with 2-lane configuration, you’ll need to configure num_lanes and bus-width as 2 for each video node, and, num_csi_lanes should be 4.

so, what exactly the signal looks like?

Hello JerryChang,
thank you for the clarification, and sorry for misleading you, the num_csi_lanes was just a typo on my side and has no bearing on the current problem.

As for the signal: I’m not FPGA dev and I have no insight into camera inner workings, but based on my scope observations and consultations, it just sends image data and that’s it (no embedded metadata or anything). As far as CSI-2 specific details I am not sure, please let me know if you want specific details, I will reach out to the camera vendors.

hello jaglaz,

could you please enable camera use-case with below commands to boost all the VI/CSI/ISP clocks. please also gather the latest VI tracing logs for reference,
thanks

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

Hello Jerry,
I will do this and post the information as soon as I get replacement camera that I ordered (I gave away the one suspect of faulty behavior).

Hello,
status update:

  1. I’m afraid boosting clocks did not achieve anything.
  2. The tracing is as follows: (fmt 13 = I422-8bit ?)
     kworker/0:4-155     [000] ....    63.038330: rtcpu_string: tstamp:2744266264 id:0x04010000 str:"VM0 deactivating."
  gst-launch-1.0-2133    [001] ....    76.528882: tegra_channel_open: vi-output, vendorname_fhd 9-0010
  gst-launch-1.0-2133    [001] ....    76.528946: tegra_channel_close: vi-output, vendorname_fhd 9-0010
  gst-launch-1.0-2133    [000] ....    76.546990: tegra_channel_open: vi-output, vendorname_fhd 9-0010
    v4l2src0:src-2134    [003] ....    76.555679: tegra_channel_set_power: vendorname_fhd 9-0010 : 0x1
    v4l2src0:src-2134    [003] ....    76.555694: camera_common_s_power: status : 0x1
    v4l2src0:src-2134    [003] ....    76.578919: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1
    v4l2src0:src-2134    [003] ....    76.578922: csi_s_power: enable : 0x1
    v4l2src0:src-2134    [003] ....    76.579510: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
    v4l2src0:src-2134    [002] ....    76.587104: tegra_channel_set_stream: enable : 0x1
    v4l2src0:src-2134    [002] ....    76.589315: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1
    v4l2src0:src-2134    [002] ....    76.589317: csi_s_stream: enable : 0x1
    v4l2src0:src-2134    [002] ....    76.589905: tegra_channel_set_stream: vendorname_fhd 9-0010 : 0x1
     kworker/0:3-123     [000] ....    76.613795: rtcpu_string: tstamp:3168156417 id:0x04010000 str:"VM0 activating."
     kworker/0:3-123     [000] ....    76.613798: rtcpu_string: tstamp:3168227797 id:0x04010000 str:"NVCSILP clock rate = 204000000 Hz.
"
     kworker/0:3-123     [000] ....    76.613822: rtcpu_string: tstamp:3168357921 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=0, csi"
     kworker/0:3-123     [000] ....    76.613825: rtcpu_string: tstamp:3168358042 id:0x04010000 str:"=0)
"
     kworker/0:3-123     [000] ....    76.613833: rtcpu_string: tstamp:3168358584 id:0x04010000 str:"MIPI clock = 148500 kHz, tHS-SETTLE = 0, tCLK-SE"
     kworker/0:3-123     [000] ....    76.613835: rtcpu_string: tstamp:3168358691 id:0x04010000 str:"TTLE = 0
"
     kworker/0:3-123     [000] ....    76.613842: rtcpu_string: tstamp:3168358974 id:0x04010000 str:"===== NVCSI Stream Configuration =====
"
     kworker/0:3-123     [000] ....    76.613850: rtcpu_string: tstamp:3168359297 id:0x04010000 str:"stream_id: PP 0, csi_port: PORT A
"
     kworker/0:3-123     [000] ....    76.613856: rtcpu_string: tstamp:3168359626 id:0x04010000 str:"Brick: PHY 0, Mode: D-PHY
"
     kworker/0:3-123     [000] ....    76.613863: rtcpu_string: tstamp:3168360015 id:0x04010000 str:"Partition: CIL A, LP bypass: Enabled, Lanes: 2
"
     kworker/0:3-123     [000] ....    76.613870: rtcpu_string: tstamp:3168360233 id:0x04010000 str:"Clock information:
"
     kworker/0:3-123     [000] ....    76.613877: rtcpu_string: tstamp:3168360645 id:0x04010000 str:"MIPI clock rate: 148.50 MHz
"
     kworker/0:3-123     [000] ....    76.613884: rtcpu_string: tstamp:3168360968 id:0x04010000 str:"T_HS settle: 0, T_CLK settle: 0
"
     kworker/0:3-123     [000] ....    76.613890: rtcpu_string: tstamp:3168361260 id:0x04010000 str:"======================================
"
     kworker/0:3-123     [000] ....    76.613897: rtcpu_string: tstamp:3168364735 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=0, csi=0)
"
     kworker/0:3-123     [000] ....    76.613904: rtcpu_string: tstamp:3168371461 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 23
"
     kworker/0:3-123     [000] ....    76.613910: rtcpu_string: tstamp:3168371820 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 23
"
     kworker/0:3-123     [000] ....    76.613917: rtcpu_string: tstamp:3168372165 id:0x04010000 str:"nvcsi_calc_tclk_settle tclk_settle 33
"
     kworker/0:3-123     [000] ....    76.613925: rtcpu_vinotify_event: tstamp:3168607860 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:101385147584 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....    76.613926: rtcpu_vinotify_event: tstamp:3168608008 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:101385159328 data:0x0000000031000001
     kworker/0:3-123     [000] ....    76.613926: rtcpu_vinotify_event: tstamp:3168608171 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:101385215168 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....    76.613927: rtcpu_vinotify_event: tstamp:3168608313 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:101385227136 data:0x0000000031000002
 vi-output, vend-2137    [003] ....    79.332303: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....    79.361689: rtcpu_vinotify_event: tstamp:3254397112 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:104130817472 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....    79.361693: rtcpu_vinotify_event: tstamp:3254397257 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:104130829248 data:0x0000000031000001
     kworker/0:4-155     [000] ....    79.361719: rtcpu_vinotify_event: tstamp:3254397419 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:104130875392 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....    79.361720: rtcpu_vinotify_event: tstamp:3254397559 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:104130887328 data:0x0000000031000002
 vi-output, vend-2137    [003] ....    81.891258: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....    81.937487: rtcpu_vinotify_event: tstamp:3334082688 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:106689641728 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....    81.937491: rtcpu_vinotify_event: tstamp:3334082837 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:106689653472 data:0x0000000031000001
     kworker/0:4-155     [000] ....    81.937492: rtcpu_vinotify_event: tstamp:3334082999 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:106689699616 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....    81.937493: rtcpu_vinotify_event: tstamp:3334083139 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:106689711584 data:0x0000000031000002
 vi-output, vend-2137    [001] ....    84.451507: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....    84.457406: rtcpu_vinotify_event: tstamp:3414064110 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109249944768 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....    84.457410: rtcpu_vinotify_event: tstamp:3414064271 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109249956544 data:0x0000000031000001
     kworker/0:4-155     [000] ....    84.457411: rtcpu_vinotify_event: tstamp:3414064437 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109250011648 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....    84.457412: rtcpu_vinotify_event: tstamp:3414064577 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109250023616 data:0x0000000031000002
 vi-output, vend-2137    [001] ....    87.011349: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....    87.041239: rtcpu_vinotify_event: tstamp:3494131950 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:111811279296 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....    87.041280: rtcpu_vinotify_event: tstamp:3494132109 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:111811291104 data:0x0000000031000001
     kworker/0:3-123     [000] ....    87.041281: rtcpu_vinotify_event: tstamp:3494132271 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:111811346880 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....    87.041283: rtcpu_vinotify_event: tstamp:3494132413 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:111811358816 data:0x0000000031000002
 vi-output, vend-2137    [001] ....    89.571239: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....    89.617158: rtcpu_vinotify_event: tstamp:3574156737 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:114369743264 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....    89.617162: rtcpu_vinotify_event: tstamp:3574156898 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:114369755008 data:0x0000000031000001
     kworker/0:3-123     [000] ....    89.617163: rtcpu_vinotify_event: tstamp:3574157060 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:114369801152 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....    89.617164: rtcpu_vinotify_event: tstamp:3574157200 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:114369813088 data:0x0000000031000002
 vi-output, vend-2137    [001] ....    92.131290: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....    92.137131: rtcpu_vinotify_event: tstamp:3654181270 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:116929751104 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....    92.137135: rtcpu_vinotify_event: tstamp:3654181434 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:116929762848 data:0x0000000031000001
     kworker/0:4-155     [000] ....    92.137137: rtcpu_vinotify_event: tstamp:3654181596 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:116929808992 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....    92.137138: rtcpu_vinotify_event: tstamp:3654181737 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:116929820960 data:0x0000000031000002
 vi-output, vend-2137    [001] ....    94.691218: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....    94.712980: rtcpu_vinotify_event: tstamp:3734058034 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:119489758720 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....    94.712984: rtcpu_vinotify_event: tstamp:3734058179 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:119489770496 data:0x0000000031000001
     kworker/0:4-155     [000] ....    94.712985: rtcpu_vinotify_event: tstamp:3734058341 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:119489817344 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....    94.712986: rtcpu_vinotify_event: tstamp:3734058481 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:119489829312 data:0x0000000031000002
 vi-output, vend-2137    [001] ....    97.251206: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....    97.288966: rtcpu_vinotify_event: tstamp:3814061129 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:122049764704 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....    97.288970: rtcpu_vinotify_event: tstamp:3814061273 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:122049776480 data:0x0000000031000001
     kworker/0:3-123     [000] ....    97.288971: rtcpu_vinotify_event: tstamp:3814061435 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:122049831584 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....    97.288972: rtcpu_vinotify_event: tstamp:3814061575 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:122049843520 data:0x0000000031000002
 vi-output, vend-2137    [000] ....    99.811233: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....    99.864868: rtcpu_vinotify_event: tstamp:3894085691 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:124609622752 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....    99.864871: rtcpu_vinotify_event: tstamp:3894085850 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:124609642848 data:0x0000000031000001
     kworker/0:3-123     [000] ....    99.864873: rtcpu_vinotify_event: tstamp:3894086012 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:124609688992 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....    99.864874: rtcpu_vinotify_event: tstamp:3894086154 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:124609700928 data:0x0000000031000002
 vi-output, vend-2137    [000] ....   102.371245: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....   102.384853: rtcpu_vinotify_event: tstamp:3974110491 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:127169647360 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....   102.384856: rtcpu_vinotify_event: tstamp:3974110648 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:127169659136 data:0x0000000031000001
     kworker/0:3-123     [000] ....   102.384858: rtcpu_vinotify_event: tstamp:3974110810 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:127169705280 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....   102.384859: rtcpu_vinotify_event: tstamp:3974110950 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:127169717216 data:0x0000000031000002
 vi-output, vend-2137    [000] ....   104.931256: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....   104.960785: rtcpu_vinotify_event: tstamp:4054055081 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:129729664192 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....   104.960788: rtcpu_vinotify_event: tstamp:4054055232 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:129729676000 data:0x0000000031000001
     kworker/0:3-123     [000] ....   104.960791: rtcpu_vinotify_event: tstamp:4054055408 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:129729722816 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....   104.960792: rtcpu_vinotify_event: tstamp:4054055548 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:129729734720 data:0x0000000031000002
 vi-output, vend-2137    [000] ....   107.491169: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:3-123     [000] ....   107.536867: rtcpu_vinotify_event: tstamp:4134058184 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:132289598560 data:0xcd9ce50010000000
     kworker/0:3-123     [000] ....   107.536871: rtcpu_vinotify_event: tstamp:4134058331 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:132289611040 data:0x0000000031000001
     kworker/0:3-123     [000] ....   107.536872: rtcpu_vinotify_event: tstamp:4134058493 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:132289666144 data:0xcd9ce20010000000
     kworker/0:3-123     [000] ....   107.536874: rtcpu_vinotify_event: tstamp:4134058633 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:132289678080 data:0x0000000031000002
 vi-output, vend-2137    [000] ....   110.051243: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....   110.056801: rtcpu_vinotify_event: tstamp:4214082680 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:134849641664 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....   110.056805: rtcpu_vinotify_event: tstamp:4214082841 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:134849653472 data:0x0000000031000001
     kworker/0:4-155     [000] ....   110.056806: rtcpu_vinotify_event: tstamp:4214083004 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:134849708544 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....   110.056807: rtcpu_vinotify_event: tstamp:4214083144 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:134849720480 data:0x0000000031000002
 vi-output, vend-2137    [000] ....   112.611176: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....   112.632723: rtcpu_vinotify_event: tstamp:4294107487 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:137409560032 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....   112.632726: rtcpu_vinotify_event: tstamp:4294107637 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:137409571808 data:0x0000000031000001
     kworker/0:4-155     [000] ....   112.632728: rtcpu_vinotify_event: tstamp:4294107799 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:137409617952 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....   112.632729: rtcpu_vinotify_event: tstamp:4294107939 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:137409629888 data:0x0000000031000002
 vi-output, vend-2137    [000] ....   115.171251: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
     kworker/0:4-155     [000] ....   115.208722: rtcpu_vinotify_event: tstamp:4374055619 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:139969673120 data:0xcd9ce50010000000
     kworker/0:4-155     [000] ....   115.208726: rtcpu_vinotify_event: tstamp:4374055766 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:139969684928 data:0x0000000031000001
     kworker/0:4-155     [000] ....   115.208727: rtcpu_vinotify_event: tstamp:4374055928 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:139969740032 data:0xcd9ce20010000000
     kworker/0:4-155     [000] ....   115.208728: rtcpu_vinotify_event: tstamp:4374056068 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:139969751936 data:0x0000000031000002
  1. Dmesg logs:
[   76.613816] [RCE] VM0 deactivating.VM0 activating.NVCSILP clock rate = 204000000 Hz.
[   76.613830] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=0, csi=0)
[   76.613839] [RCE] MIPI clock = 148500 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0
[   76.613846] [RCE] ===== NVCSI Stream Configuration =====
[   76.613853] [RCE] stream_id: PP 0, csi_port: PORT A
[   76.613860] [RCE] Brick: PHY 0, Mode: D-PHY
[   76.613867] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 2
[   76.613873] [RCE] Clock information:
[   76.613880] [RCE] MIPI clock rate: 148.50 MHz
[   76.613887] [RCE] T_HS settle: 0, T_CLK settle: 0
[   76.613894] [RCE] ======================================
[   76.613900] [RCE] tegra_nvcsi_stream_open(vm0, stream=0, csi=0)
[   76.613907] [RCE] nvcsi_calc_ths_settle ths_settle 23
[   76.613914] [RCE] nvcsi_calc_ths_settle ths_settle 23
[   76.613921] [RCE] nvcsi_calc_tclk_settle tclk_settle 33
[   79.329640] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[   79.329921] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[   79.331335] (NULL device *): vi_capture_control_message: NULL VI channel received
[   79.331542] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[   79.331751] (NULL device *): vi_capture_control_message: NULL VI channel received
[   79.331950] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[   79.332636] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
  1. As explained in first post, I attempted to disable CRC/ECC, please keep that in mind. I do not know how to verify I disabled it correctly - setting the error mask flags especially raises my eyebrow due to L4T versions mismatch. Fragment of csi5_stream_set_config() from the mentioned patch:
	/* ecc error config*/
	memset(&error_config, 0, sizeof(error_config));
	error_config.host1x_intr_mask_lic= 0x3; // <- where does the mask go?
	error_config.status2vi_notify_mask = 0xFFFF;
  1. In csi5_stream_open() there is a comment which leads me to belive there is some pre-existing problem in the signal or some kernel configuration is missing (hence my frequent mentions of crc/ecc). We the checked the camera on another som (iMX6), and it is able to capture video.
	/* If the tegra_vi_channel is NULL it means that is PCL TPG usecase where fusa UMD opens the
	 * VI channel and sends channel messages but for CSI messages it uses this V4L2 path.
	 * In such a case query fusacapture KMD for the tegra_vi_channel associated with the
	 * current stream id/vc id combination.
	 * If still NULL, we are in erroroneous state, exit with error.
	 */

hello jaglaz,

if CSI encounter CRC error, it’ll report failures to VI tracing logs. it’ll report by CSIMUX_FRAME follow by CSI fault code in data fields.
it may not related to CRC since I don’t see relevant errors there. or… you may try revert those kernel changes to have confirmation.


BTW,
could you please try code snippet as below to return EPROBE_DEFER to requests probe retry.
for example,

diff --git a/drivers/platform/tegra/rtcpu/device-group.c b/drivers/platform/tegra/rtcpu/device-group.c
index fadae24d9..74cdb0ffa 100644

@@ -51,7 +51,7 @@ static int get_grouped_device(struct camrtc_device_group *grp,
 
        if (pdev == NULL) {
                dev_warn(dev, "%s[%u] node has no device\n", name, index);
-               return 0;
+               return -EPROBE_DEFER;
        }

Hello Jerry,
turns out I’m a massive dum-dum - I’ve misread the schematic and mistook CAM0/CAM1 labels on the pcb as the same as CAM0/CAM1 i2c pin designations in the schematic and was connected to the wrong port the entire time. After swapping the port_numbert properties and some tweaks in pipeline I’m able to capture the image. Thank you for your patience (:

regards,
JG

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