Camera streaming issue with serdes

Autonomous Machines Jetson & Embedded Systems Jetson AGX Xavier
1

Hi, All

I’m testing custom image sensor with SerDes.
An error similar to the previous error occurred when connecting only the camera without the serdes system.

  1. Serial Log message
 [   93.899983] tegra194-vi5 15c10000.vi: no reply from camera processor
[   93.900144] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[   93.900275] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[   93.902342] tegra-capture-ivc ivc-bc00000.rtcpu:ivccontrol@3: No callback found for msg id: 0x39
[   93.902509] tegra-capture-ivc ivc-bc00000.rtcpu:ivccontrol@3: No callback found for msg id: 0x41
[   93.902655] tegra-capture-ivc ivc-bc00000.rtcpu:ivccontrol@3: No callback found for msg id: 0x37
[   93.902820] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[   96.459995] tegra194-vi5 15c10000.vi: no reply from camera processor
[   96.460146] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[   96.460289] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[   96.462316] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[   99.019902] tegra194-vi5 15c10000.vi: no reply from camera processor
[   99.020070] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[   99.020219] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[   99.023358] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
  1. Trace Log Message
     kworker/0:0-4     [000] ....    98.945757: rtcpu_nvcsi_intr: tstamp:3408266328 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    98.945757: rtcpu_nvcsi_intr: tstamp:3408272186 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    98.945758: rtcpu_nvcsi_intr: tstamp:3408272186 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    98.945758: rtcpu_nvcsi_intr: tstamp:3408272186 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    98.945758: rtcpu_nvcsi_intr: tstamp:3408272186 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    98.945759: rtcpu_nvcsi_intr: tstamp:3408830855 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    98.945759: rtcpu_nvcsi_intr: tstamp:3408830855 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    98.945759: rtcpu_nvcsi_intr: tstamp:3408830855 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    98.945760: rtcpu_nvcsi_intr: tstamp:3408830855 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    98.945760: rtcpu_nvcsi_intr: tstamp:3408836710 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    98.945760: rtcpu_nvcsi_intr: tstamp:3408836710 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    98.945761: rtcpu_nvcsi_intr: tstamp:3408836710 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    98.945761: rtcpu_nvcsi_intr: tstamp:3408836710 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
 vi-output, imx4-8572  [000] ....    98.992952: tegra_channel_capture_setup: vnc_id 0 W 3840 H 2160 fmt c4
        v4l2-ctl-8570  [001] ....    98.993539: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-8570  [001] ....    98.993546: tegra_channel_set_stream: imx415 2-001a : 0x0
        v4l2-ctl-8570  [000] ....    98.995964: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x0
        v4l2-ctl-8570  [000] ....    98.995967: csi_s_stream: enable : 0x0
     kworker/0:0-4     [000] ....    99.001720: rtcpu_nvcsi_intr: tstamp:3409395381 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    99.001721: rtcpu_nvcsi_intr: tstamp:3409395381 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    99.001721: rtcpu_nvcsi_intr: tstamp:3409395381 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    99.001722: rtcpu_nvcsi_intr: tstamp:3409395381 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    99.001722: rtcpu_nvcsi_intr: tstamp:3409401239 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    99.001722: rtcpu_nvcsi_intr: tstamp:3409401239 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    99.001723: rtcpu_nvcsi_intr: tstamp:3409401239 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    99.001723: rtcpu_nvcsi_intr: tstamp:3409401239 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    99.001723: rtcpu_nvcsi_intr: tstamp:3409959903 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    99.001724: rtcpu_nvcsi_intr: tstamp:3409959903 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    99.001724: rtcpu_nvcsi_intr: tstamp:3409959903 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    99.001724: rtcpu_nvcsi_intr: tstamp:3409959903 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    99.001725: rtcpu_nvcsi_intr: tstamp:3409965763 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    99.001725: rtcpu_nvcsi_intr: tstamp:3409965763 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    99.001725: rtcpu_nvcsi_intr: tstamp:3409965763 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    99.001726: rtcpu_nvcsi_intr: tstamp:3409965763 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    99.001730: rtos_queue_send_from_isr_failed: tstamp:3410413644 queue:0x0bcb41f8
     kworker/0:0-4     [000] ....    99.001774: rtos_queue_send_from_isr_failed: tstamp:3410413809 queue:0x0bcb8a60
     kworker/0:0-4     [000] ....    99.001775: rtos_queue_send_from_isr_failed: tstamp:3410413971 queue:0x0bcba5e0
     kworker/0:0-4     [000] ....    99.001776: rtos_queue_send_from_isr_failed: tstamp:3410414128 queue:0x0bcbb3a0
     kworker/0:0-4     [000] ....    99.001777: rtos_queue_send_from_isr_failed: tstamp:3410414285 queue:0x0bcbc160
     kworker/0:0-4     [000] ....    99.001778: rtos_queue_send_from_isr_failed: tstamp:3410495785 queue:0x0bcb41f8
     kworker/0:0-4     [000] ....    99.001779: rtos_queue_send_from_isr_failed: tstamp:3410495947 queue:0x0bcb8a60
     kworker/0:0-4     [000] ....    99.001780: rtos_queue_send_from_isr_failed: tstamp:3410496108 queue:0x0bcba5e0
     kworker/0:0-4     [000] ....    99.001780: rtos_queue_send_from_isr_failed: tstamp:3410496265 queue:0x0bcbb3a0
     kworker/0:0-4     [000] ....    99.001781: rtos_queue_send_from_isr_failed: tstamp:3410496420 queue:0x0bcbc160
     kworker/0:0-4     [000] ....    99.001782: rtcpu_nvcsi_intr: tstamp:3410503373 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000110
     kworker/0:0-4     [000] ....    99.001782: rtcpu_nvcsi_intr: tstamp:3410503373 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x00000110
     kworker/0:0-4     [000] ....    99.001783: rtcpu_nvcsi_intr: tstamp:3410503373 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000110
     kworker/0:0-4     [000] ....    99.001783: rtcpu_nvcsi_intr: tstamp:3410503373 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000110
     kworker/0:0-4     [000] ....    99.001787: rtcpu_string: tstamp:3410504871 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/0:0-4     [000] ....    99.001811: rtcpu_string: tstamp:3410505062 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/0:0-4     [000] ....    99.001818: rtcpu_string: tstamp:3410505329 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/0:0-4     [000] ....    99.001824: rtcpu_string: tstamp:3410505624 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/0:0-4     [000] ....    99.001830: rtcpu_string: tstamp:3410505867 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/0:0-4     [000] ....    99.001837: rtcpu_string: tstamp:3410506109 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/0:0-4     [000] ....    99.001871: rtcpu_string: tstamp:3410506350 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/0:0-4     [000] ....    99.001876: rtcpu_nvcsi_intr: tstamp:3410524430 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/0:0-4     [000] ....    99.001876: rtcpu_nvcsi_intr: tstamp:3410524430 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x06000000
     kworker/0:0-4     [000] ....    99.001877: rtcpu_nvcsi_intr: tstamp:3410524430 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/0:0-4     [000] ....    99.001877: rtcpu_nvcsi_intr: tstamp:3410524430 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:1 st:0 vc:0 status:0x00000600
     kworker/0:0-4     [000] ....    99.001878: rtos_queue_send_from_isr_failed: tstamp:3410592316 queue:0x0bcb41f8
     kworker/0:0-4     [000] ....    99.001879: rtos_queue_send_from_isr_failed: tstamp:3410592480 queue:0x0bcb8a60
     kworker/0:0-4     [000] ....    99.001880: rtos_queue_send_from_isr_failed: tstamp:3410592641 queue:0x0bcba5e0
     kworker/0:0-4     [000] ....    99.001881: rtos_queue_send_from_isr_failed: tstamp:3410592800 queue:0x0bcbb3a0
     kworker/0:0-4     [000] ....    99.001882: rtos_queue_send_from_isr_failed: tstamp:3410592957 queue:0x0bcbc160
     kworker/0:0-4     [000] ....    99.001882: rtos_queue_send_from_isr_failed: tstamp:3410768753 queue:0x0bcb41f8
     kworker/0:0-4     [000] ....    99.001883: rtos_queue_send_from_isr_failed: tstamp:3410768980 queue:0x0bcb8a60
     kworker/0:0-4     [000] ....    99.001884: rtos_queue_send_from_isr_failed: tstamp:3410769203 queue:0x0bcba5e0
     kworker/0:0-4     [000] ....    99.001884: rtos_queue_send_from_isr_failed: tstamp:3410769422 queue:0x0bcbb3a0
     kworker/0:0-4     [000] ....    99.001885: rtos_queue_send_from_isr_failed: tstamp:3410769640 queue:0x0bcbc160
        v4l2-ctl-8570  [003] ....    99.012673: tegra_channel_set_power: imx415 2-001a : 0x0
        v4l2-ctl-8570  [003] ....    99.012702: camera_common_s_power: status : 0x0
        v4l2-ctl-8570  [001] ....    99.022085: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x0
        v4l2-ctl-8570  [001] ....    99.022094: csi_s_power: enable : 0x0
     kworker/0:0-4     [000] ....    99.057728: rtos_queue_peek_from_isr_failed: tstamp:3412311905 queue:0x0bcbcf78
     kworker/0:0-4     [000] ....    99.225738: rtos_queue_peek_from_isr_failed: tstamp:3417311907 queue:0x0bcbcf78
     kworker/0:0-4     [000] ....    99.393644: rtos_queue_peek_from_isr_failed: tstamp:3422311905 queue:0x0bcbcf78
     kworker/0:0-4     [000] ....    99.561671: rtos_queue_peek_from_isr_failed: tstamp:3427311905 queue:0x0bcbcf78
     kworker/0:0-4     [000] ....    99.729708: rtos_queue_peek_from_isr_failed: tstamp:3432311950 queue:0x0bcbcf78
     kworker/0:0-4     [000] ....    99.897643: rtos_queue_peek_from_isr_failed: tstamp:3437311909 queue:0x0bcbcf78
     kworker/0:0-4     [000] ....   100.065611: rtos_queue_peek_from_isr_failed: tstamp:3442311911 queue:0x0bcbcf78

I think it’s a timing problem, but I don’t know where to start.

thanks,

3

You trace log looks like intr_dphy_cil_lane_align_err_a/intr_dphy_cil_deskew_calib_err_ctrl_a/intr_dphy_cil_deskew_calib_err_lane1_a from the REG NVCSI_PHY_0_CILA_INTR_0_STATUS_CILA_0.
Have a check HW lane connection or the lane configure.

4

Hello ShaneCCC,

As per your advice, I checked the HW connection.
The connection is normal.
Please review the device tree and configuration information below to see if there is a problem with the camera settings.

  1. Configuration
 mipi D-PHY  4 lane    /  CSI- C port 
 main clock  37,125,000 Hz
 mipi clock   1,048Mbps 
 resolution   3840 x 2160 pixel 
 fps  55 fps
  1. Device tree
	host1x {
		vi@15c10000 {
			num-channels = <1>;
			ports {
				#address-cells = <1>;
				#size-cells = <0>;
			 	port@0 {
					reg = <0>;
					eimx415_vi_in0: endpoint {
						port-index = <2>;
						bus-width = <4>;
						remote-endpoint = <&eimx415_csi_out0>;
    					};
				};
			};
		};

		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>;
						status = "okay";
						eimx415_csi_in0: endpoint@0 {
							port-index = <2>;
							bus-width = <4>;
							remote-endpoint = <&eimx415_eimx415_out0>;
						};
					};
					port@1 {
						reg = <1>;
						eimx415_csi_out0: endpoint@1 {
							remote-endpoint = <&eimx415_vi_in0>;
						};
					};
				};
			};

		};
	};

	i2c@3180000 {

		status = "okay";
		#address-cells = <1>;
		#size-cells = <0>;

       		imx415_c@1a {
				compatible = "nvidia,imx415";
				reg = <0x1a>;
				devnode = "video0";

				sensor_model = "imx415";
				physical_w = "5.60";
				physical_h = "3.175";
				use_decibel_gain = "true";
				use_sensor_mode_id = "true";
				use_dol_wdr_mode = "false";
				limit_analog_gain = "true";
				avdd-reg = "vana";
				iovdd-reg = "vif";
				clocks = <&bpmp_clks  TEGRA194_CLK_EXTPERIPH1>,
				       <&bpmp_clks TEGRA194_CLK_PLLP_OUT0>;
				clock-names = "extperiph1", "pllp_grtba";
				mclk = "extperiph1";

				reset-gpios = <&tegra_main_gpio CAM0_RST_L GPIO_ACTIVE_HIGH>;
				pwdn-gpios = <&tegra_main_gpio CAM0_PWDN GPIO_ACTIVE_HIGH>;
			
				vana-supply = <&p2822_avdd_cam_2v8>;
				vif-supply = <&p2822_vdd_1v8_cvb>;

				mode0 {
					mclk_khz = "37125";
					num_lanes = "4";
					tegra_sinterface = "serial_c";
					phy_mode = "DPHY";
					discontinuous_clk = "no";
					dpcm_enable = "false";
					cil_settletime = "0";
					dynamic_pixel_bit_depth = "12";
					csi_pixel_bit_depth = "12";
					mode_type = "bayer";
					pixel_phase = "gbrg";

					active_w = "3840";
					active_h = "2160";
					readout_orientation = "0";
					line_length = "550";
					inherent_gain = "1";
					mclk_multiplier = "1";
					pix_clk_hz = "693000000"; //"693000000"   //"998400000"

					gain_factor = "10";
					min_gain_val = "1";
					max_gain_val = "300";
					step_gain_val = "3";
					default_gain = "1";
					min_hdr_ratio = " ";
					max_hdr_ratio = " ";
					framerate_factor = "1000000";
					min_framerate = "25000000";
					max_framerate = "55000000";
					step_framerate = "1";
					default_framerate = "55000000";
					exposure_factor = "1000000";
					min_exp_time = "450";
					max_exp_time = "400000";
					step_exp_time = "1";
					default_exp_time = "16667";
					embedded_metadata_height = "1";
				};




				ports {
					#address-cells = <1>;
					#size-cells = <0>;
					port@0 {
						reg = <0>;
						eimx415_eimx415_out0: endpoint {
							port-index = <2>;
							bus-width = <4>;
							remote-endpoint = <&eimx415_csi_in0>;
						};
					};
				};
		};//imx415@1a
		


	};  //i2c@3180000
 };
5

Did you boost the NVCSI/VI clocks to try?

sudo su
echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/isp/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/nvcsi/mrq_rate_locked
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
6

I’v been try to boost the NVCSI/VI .
It ocurred same error log message.

The values applied when the command is executed are shown below.

cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate |tee /sys/kernel/debug/bpmp/debug/clk/vi/rate
998400000
cat /sys/kernel/debug/bpmp/debug/clk/isp/max_rate | tee  /sys/kernel/debug/bpmp/debug/clk/isp/rate
1190400000
cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate
400000000