Camera streaming issue with serdes

jpchae · January 26, 2022, 6:57am

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.

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

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,

ShaneCCC · January 26, 2022, 8:33am

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.

jpchae · January 26, 2022, 10:53am

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.

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

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
 };

ShaneCCC · January 26, 2022, 11:17am

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

jpchae · January 27, 2022, 1:15am

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

Topic		Replies	Views
Camera with serdes (MAX96705/MA9296) Jetson AGX Xavier camera	5	1183	October 18, 2021
Vi_capture_setup: control failed, errno 1 Jetson Xavier NX camera	10	1130	July 4, 2022
IMX415 Capture issue on NVIDIA AGX Xavier Jetson AGX Xavier camera	4	818	February 2, 2022
Tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms Jetson Xavier NX camera	52	82	December 16, 2024
Camera driver adaption issues Jetson Xavier NX camera , kernel , device-tree , linux-driver	3	865	September 20, 2023
4-lane CSI Camera Problems Jetson AGX Xavier	9	2672	October 18, 2021
No CSI traffic is received from CSI custom sensor Jetson AGX Xavier camera	13	881	December 22, 2021
Failed to stream video via HDMI to CSI chipset Jetson AGX Xavier	6	904	May 6, 2020
Add Support for new CSI camera Jetson Xavier NX camera	6	651	October 18, 2021
Capture issues on csi Jetson Xavier Nx Jetson AGX Xavier camera , board-design	14	814	November 9, 2022

Camera streaming issue with serdes

Related topics