Customized MIPI stream errors on v4l2 capture

Autonomous Machines Jetson & Embedded Systems Jetson AGX Xavier
1

Hi,

Following up from previous posts, we’ve managed to customize the ov5693 driver to operate a MIPI camera without i2c.
A signal check after the cable shows electrical signals are being transmitted, so when powered up, mipi data is already transmitted without any action from the jetson.

Please find here the clock and data outputs (respectively) as can be analyzed externally:

mipi-clock-signal
mipi-clock-signal1536×2048 315 KB

mipi-data-signal
mipi-data-signal1536×2048 310 KB

The fpga core is configured for 640x512 at raw12 format, with the following wiring scheme:

mipi-cable-wiring
mipi-cable-wiring912×322 21.4 KB

On the jetson side, here’s an excerpt from the relevant dtsi section (the i2c bus was set to the 40-pin header for testing purposes):

{
	host1x {
		vi@15c10000 {
			num-channels = <1>;
			ports {
				#address-cells = <1>;
				#size-cells = <0>;
				port@0 {
					reg = <0>;
					e3326_vi_in0: endpoint {
						port-index = <2>;
						bus-width = <4>;
						remote-endpoint = <&e3326_csi_out0>;
					};
				};
			};
		};

		nvcsi@15a00000 {
			num-channels = <1>;
			#address-cells = <1>;
			#size-cells = <0>;
            status = "okay";
			channel@0 {
				reg = <0>;
				ports {
					#address-cells = <1>;
					#size-cells = <0>;
					port@0 {
						reg = <0>;
						e3326_csi_in0: endpoint@0 {
							port-index = <2>;
							bus-width = <4>;
							remote-endpoint = <&e3326_ov5693_out0>;
						};
					};
					port@1 {
						reg = <1>;
						e3326_csi_out0: endpoint@1 {
							remote-endpoint = <&e3326_vi_in0>;
						};
					};
				};
			};
		};
	};

	i2c@31e0000 {
		ov5693_c@20 {
			compatible = "nvidia,ov5693";
			/* I2C device address */
			reg = <0x20>;

			/* V4L2 device node location */
			devnode = "video0";

			/* Physical dimensions of sensor */
			physical_w = "15.0";
			physical_h = "12.5";

			sensor_model ="mytester";

			post_crop_frame_drop = "0";

			use_decibel_gain = "false";

			delayed_gain = "false";

			use_sensor_mode_id = "true";

			limit_analog_gain = "true";

			mode0 {/*mode C4I_MODE_640X512_CROP_30FPS*/
				mclk_khz = "324000";
				num_lanes = "4";
				tegra_sinterface = "serial_a";
				phy_mode = "DPHY";
				discontinuous_clk = "no";
				dpcm_enable = "false";
				cil_settletime = "18";
				active_w = "640";
				active_h = "512";
				dynamic_pixel_bit_depth = "12";
				mode_type = "bayer";
				pixel_phase = "rggb";
				csi_pixel_bit_depth = "12";
				readout_orientation = "0";
				line_length = "640";
				inherent_gain = "1";
				pix_clk_hz = "54000000";
			};
			ports {
				#address-cells = <1>;
				#size-cells = <0>;

				port@0 {
					reg = <0>;
					e3326_ov5693_out0: endpoint {
						port-index = <0>;
						bus-width = <4>;
						remote-endpoint = <&e3326_csi_in0>;
					};
				};
			};
		};
	};

	tegra-camera-platform {
		compatible = "nvidia, tegra-camera-platform";
		num_csi_lanes = <4>;
		max_lane_speed = <1500000>;
		min_bits_per_pixel = <12>;
		vi_peak_byte_per_pixel = <2>;
		vi_bw_margin_pct = <25>;
		max_pixel_rate = <160000>;
		isp_peak_byte_per_pixel = <5>;
		isp_bw_margin_pct = <25>;

		modules {
			module0 {
				badge = "e3326_front_P5V27C";
				position = "rear";
				orientation = "1";
				drivernode0 {
					/* Declare PCL support driver (classically known as guid)  */
					pcl_id = "v4l2_sensor";
					/* Driver v4l2 device name */
					devname = "ov5693 8-0020";
					/* Declare the device-tree hierarchy to driver instance */
					proc-device-tree = "/proc/device-tree/i2c@31e0000/ov5693_c@20";
				};
			};
		};
	};
};

After enabling debug and tracing via:

# 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

# echo 1 > /sys/kernel/debug/tracing/tracing_on
# echo 30720 > /sys/kernel/debug/tracing/buffer_size_kb
# echo 1 > /sys/kernel/debug/tracing/events/tegra_rtcpu/enable
# echo 1 > /sys/kernel/debug/tracing/events/freertos/enable
# echo 2 > /sys/kernel/debug/camrtc/log-level
# echo 1 > /sys/kernel/debug/tracing/events/camera_common/enable
# echo > /sys/kernel/debug/tracing/trace

Running:

v4l2-ctl -d /dev/video0 --set-fmt-video=width=640,height=512,pixelformat=RG12 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=2 --stream-to=test.raw --verbose

Yields:

VIDIOC_QUERYCAP: ok
VIDIOC_S_EXT_CTRLS: ok
VIDIOC_G_FMT: ok
VIDIOC_S_FMT: ok
Format Video Capture:
	Width/Height      : 640/512
	Pixel Format      : 'RG12'
	Field             : None
	Bytes per Line    : 1280
	Size Image        : 655360
	Colorspace        : sRGB
	Transfer Function : Default (maps to sRGB)
	YCbCr/HSV Encoding: Default (maps to ITU-R 601)
	Quantization      : Default (maps to Full Range)
	Flags             : 
VIDIOC_REQBUFS: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_STREAMON: ok
	Index    : 0
	Type     : Video Capture
	Flags    : mapped, error
	Field    : None
	Sequence : 0
	Length   : 655360
	Bytesused: 655360
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

And the tracer (/sys/kernel/debug/tracing/trace) output is:

# tracer: nop
#
# entries-in-buffer/entries-written: 59/59   #P:8
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
        v4l2-ctl-9906  [002] ....   987.937282: tegra_channel_open: vi-output, ov5693 8-0020
        v4l2-ctl-9906  [000] ....   987.939882: tegra_channel_set_power: ov5693 8-0020 : 0x1
        v4l2-ctl-9906  [000] ....   987.939894: camera_common_s_power: status : 0x1
        v4l2-ctl-9906  [000] ....   987.940841: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-9906  [000] ....   987.940844: csi_s_power: enable : 0x1
        v4l2-ctl-9906  [000] ....   987.945330: tegra_channel_capture_setup: vnc_id 0 W 640 H 512 fmt c4
        v4l2-ctl-9906  [006] ....   987.950946: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-9906  [000] ....   987.952418: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-9906  [000] ....   987.952422: csi_s_stream: enable : 0x1
        v4l2-ctl-9906  [000] ....   987.952429: tegra_channel_set_stream: ov5693 8-0020 : 0x1
     kworker/0:0-9674  [000] ....   987.987355: rtos_queue_peek_from_isr_failed: tstamp:31329642480 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   987.987359: rtcpu_start: tstamp:31329643757
     kworker/0:0-9674  [000] ....   987.987361: rtos_queue_send_from_isr_failed: tstamp:31329690346 queue:0x0bcb2e38
     kworker/0:0-9674  [000] ....   987.987362: rtos_queue_send_from_isr_failed: tstamp:31329690483 queue:0x0bcb76a0
     kworker/0:0-9674  [000] ....   987.987363: rtos_queue_send_from_isr_failed: tstamp:31329690621 queue:0x0bcb9220
     kworker/0:0-9674  [000] ....   987.987364: rtos_queue_send_from_isr_failed: tstamp:31329690754 queue:0x0bcb9fe0
     kworker/0:0-9674  [000] ....   987.987366: rtos_queue_send_from_isr_failed: tstamp:31329690888 queue:0x0bcbada0
     kworker/0:0-9674  [000] ....   987.987367: rtcpu_string: tstamp:31329691291 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/0:0-9674  [000] ....   987.987394: rtcpu_string: tstamp:31329691471 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/0:0-9674  [000] ....   987.987402: rtcpu_string: tstamp:31329691712 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/0:0-9674  [000] ....   987.987410: rtcpu_string: tstamp:31329691943 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/0:0-9674  [000] ....   987.987416: rtcpu_string: tstamp:31329692161 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/0:0-9674  [000] ....   987.987422: rtcpu_string: tstamp:31329692437 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/0:0-9674  [000] ....   987.987428: rtcpu_string: tstamp:31329692660 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/0:0-9674  [000] ....   987.987434: rtcpu_string: tstamp:31329700150 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
     kworker/0:0-9674  [000] ....   987.987435: rtcpu_string: tstamp:31329700255 id:0x04010000 str:"on 2.2
"
     kworker/0:0-9674  [000] ....   987.987442: rtos_queue_send_from_isr_failed: tstamp:31329712426 queue:0x0bcb2e38
     kworker/0:0-9674  [000] ....   987.987442: rtos_queue_send_from_isr_failed: tstamp:31329712580 queue:0x0bcb76a0
     kworker/0:0-9674  [000] ....   987.987443: rtos_queue_send_from_isr_failed: tstamp:31329712724 queue:0x0bcb9220
     kworker/0:0-9674  [000] ....   987.987444: rtos_queue_send_from_isr_failed: tstamp:31329712856 queue:0x0bcb9fe0
     kworker/0:0-9674  [000] ....   987.987444: rtos_queue_send_from_isr_failed: tstamp:31329712988 queue:0x0bcbada0
     kworker/0:0-9674  [000] ....   987.987445: rtcpu_string: tstamp:31329713830 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
"
     kworker/0:0-9674  [000] ....   987.987451: rtos_queue_send_from_isr_failed: tstamp:31329760710 queue:0x0bcb2e38
     kworker/0:0-9674  [000] ....   987.987452: rtos_queue_send_from_isr_failed: tstamp:31329760846 queue:0x0bcb76a0
     kworker/0:0-9674  [000] ....   987.987452: rtos_queue_send_from_isr_failed: tstamp:31329760986 queue:0x0bcb9220
     kworker/0:0-9674  [000] ....   987.987453: rtos_queue_send_from_isr_failed: tstamp:31329761121 queue:0x0bcb9fe0
     kworker/0:0-9674  [000] ....   987.987453: rtos_queue_send_from_isr_failed: tstamp:31329761253 queue:0x0bcbada0
     kworker/0:0-9674  [000] ....   987.987455: rtcpu_nvcsi_intr: tstamp:31329763717 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000089
     kworker/0:0-9674  [000] ....   987.987455: rtcpu_nvcsi_intr: tstamp:31329763717 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x00000088
     kworker/0:0-9674  [000] ....   987.987457: rtcpu_vinotify_event: tstamp:31330012878 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:31888262304 data:0x10000000
     kworker/0:0-9674  [000] ....   987.987458: rtcpu_vinotify_event: tstamp:31330013008 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:31888266112 data:0x31000001
     kworker/0:0-9674  [000] ....   987.987458: rtcpu_vinotify_event: tstamp:31330013150 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:31888267104 data:0x07020001
     kworker/0:0-9674  [000] ....   987.987459: rtcpu_vinotify_event: tstamp:31330013274 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:31888302976 data:0x10000000
     kworker/0:0-9674  [000] ....   987.987460: rtcpu_vinotify_event: tstamp:31330013415 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:31888306816 data:0x31000002
     kworker/0:0-9674  [000] ....   988.155385: rtos_queue_peek_from_isr_failed: tstamp:31334642837 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   988.323343: rtos_queue_peek_from_isr_failed: tstamp:31339642841 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   988.435352: rtos_queue_peek_from_isr_failed: tstamp:31344642839 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   988.603346: rtos_queue_peek_from_isr_failed: tstamp:31349642841 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   988.771353: rtos_queue_peek_from_isr_failed: tstamp:31354642838 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   988.939361: rtos_queue_peek_from_isr_failed: tstamp:31359642839 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   989.107350: rtos_queue_peek_from_isr_failed: tstamp:31364642841 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   989.275342: rtos_queue_peek_from_isr_failed: tstamp:31369642841 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   989.443358: rtos_queue_peek_from_isr_failed: tstamp:31374642839 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   989.555346: rtos_queue_peek_from_isr_failed: tstamp:31379642839 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   989.723353: rtos_queue_peek_from_isr_failed: tstamp:31384642835 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   989.891344: rtos_queue_peek_from_isr_failed: tstamp:31389642841 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   990.059343: rtos_queue_peek_from_isr_failed: tstamp:31394642842 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   990.227349: rtos_queue_peek_from_isr_failed: tstamp:31399642839 queue:0x0bcbbbb8
     kworker/0:0-9674  [000] ....   990.395340: rtos_queue_peek_from_isr_failed: tstamp:31404642838 queue:0x0bcbbbb8

Any ideas on what might be the cause? (I know the reported format doesn’t match the desired one, but suppose it doesn’t explain lack of signals)
Several issues that come to mind and worth questioning:

  1. Is the wiring enough and correct?

  2. Does the dtsi definition suffices?

  3. The original ov5693 defines avdd and iovdd in the dtsi for controlling the power mode and activating regulators, while in our case they’re missing and the driver code was modified to bypass them (so no regulators are being changed, nor any gpio in addition).
    Should something be done on the jetson side to activate the mipi bus for receiving signals?

Many thanks,
Moti.

3

The error tell data lane and clock lane control error.
It could be the HW problem or sensor configure problem.
Make sure sensor output data by 4 lanes configure.

4

Thanks for such a prompt response!
We’ll look into that and keep updates.

5

@ShaneCCC where can we look into possible status/error codes as reported by the physical layer? To have better debugging info?

6

Current the only way is checking the trace log for sensor bring up.

Thanks

1 Like
7

Hi @ShaneCCC ,

The problem appears to be more inherent, might be connected.
We get the same status when the sensor is powered and also when off.

The kernel log for the session shows:

[  226.628845] [RCE] Configuring VI GoS.
[  226.628874] [RCE] VM GOS[#0] addr=0xc2100000
[  226.628893] [RCE] VM GOS[#1] addr=0xc2101000
[  226.628907] [RCE] VM GOS[#2] addr=0xc2102000
[  226.628919] [RCE] VM GOS[#3] addr=0xc2103000
[  226.628931] [RCE] VM GOS[#4] addr=0xc2104000
[  226.628943] [RCE] VM GOS[#5] addr=0xc2105000
[  226.628957] [RCE] vi5_hwinit: firmware CL2018101701 protocol version 2.2
[  226.628972] [RCE] VI GOS[#0] set to VM GOS[4] base 0xc2104000
[  229.212807] tegra194-vi5 15c10000.vi: no reply from camera processor
[  229.212962] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[  229.213109] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[  229.216172] Unable to handle kernel NULL pointer dereference at virtual address 00000010
[  229.216378] Mem abort info:
[  229.216435]   ESR = 0x96000006
[  229.216493]   Exception class = DABT (current EL), IL = 32 bits
[  229.216594]   SET = 0, FnV = 0
[  229.216652]   EA = 0, S1PTW = 0
[  229.216708] Data abort info:
[  229.216880]   ISV = 0, ISS = 0x00000006
[  229.216954]   CM = 0, WnR = 0
[  229.217021] user pgtable: 4k pages, 39-bit VAs, pgd = ffffffc7884a8000
[  229.217135] [0000000000000010] *pgd=00000008084a9003, *pud=00000008084a9003, *pmd=0000000000000000
[  229.217319] Internal error: Oops: 96000006 [#1] PREEMPT SMP
[  229.217421] Modules linked in: ov5693 bnep fuse xt_conntrack ipt_MASQUERADE nf_nat_masquerade_ipv4 nf_conntrack_netlink nfnetlink xt_addrtype iptable_filter iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack br_netfilter zram overlay bluedroid_pm userspace_alert binfmt_misc nvgpu ip_tables x_tables [last unloaded: ov5693]
[  229.233601] CPU: 4 PID: 9442 Comm: vi-output, ov56 Not tainted 4.9.253-tegra #1
[  229.240923] Hardware name: Jetson-AGX (DT)
[  229.245039] task: ffffffc7d7c08000 task.stack: ffffffc773724000
[  229.250907] PC is at _raw_write_lock+0x30/0x58
[  229.255107] LR is at destroy_buffer_table+0x40/0xd8
[  229.260089] pc : [<ffffff8008f6c6f0>] lr : [<ffffff8008b4d280>] pstate: 20c00045
[  229.267089] sp : ffffffc773727c70
[  229.270584] x29: ffffffc773727c70 x28: 0000000000000000 
[  229.275921] x27: 0000000000000000 x26: 0000000000000000 
[  229.281521] x25: 0000000000000010 x24: 0000000000000098 
[  229.287120] x23: 0000000000000018 x22: ffffff8009087458 
[  229.292197] x21: 0000000000000000 x20: ffffffc7aaa33080 
[  229.297620] x19: 0000000000000010 x18: 00000000000061fb 
[  229.303312] x17: 0000000000000002 x16: 0000000000000003 
[  229.308835] x15: 0000000000000387 x14: 0000000000000000 
[  229.314520] x13: 0000000000000000 x12: 0000000000000400 
[  229.320210] x11: 0000000000000400 x10: 0000000000000a10 
[  229.326145] x9 : ffffffc773727a80 x8 : 0000000000000000 
[  229.331923] x7 : ffffffc773692540 x6 : ffffffc7dc58a141 
[  229.337183] x5 : ffffff800852d904 x4 : ffffffbf1f716290 
[  229.342770] x3 : 0000000000000000 x2 : ffffffc7dc58a140 
[  229.347860] x1 : 0000000000000000 x0 : 0000000080000000 

[  229.354862] Process vi-output, ov56 (pid: 9442, stack limit = 0xffffffc773724000)
[  229.361847] Call trace:
[  229.364131] [<ffffff8008f6c6f0>] _raw_write_lock+0x30/0x58
[  229.369468] [<ffffff8008b4d280>] destroy_buffer_table+0x40/0xd8
[  229.374807] [<ffffff8008b3f58c>] vi_capture_shutdown+0xd4/0x130
[  229.380406] [<ffffff8008b3fbe4>] vi_channel_close_ex+0x34/0x88
[  229.386264] [<ffffff8008b410f0>] vi5_channel_error_recover+0x48/0x1c8
[  229.391957] [<ffffff8008b361c0>] tegra_channel_error_recover+0x58/0x90
[  229.398340] [<ffffff8008b419b0>] tegra_channel_kthread_capture_dequeue+0xf8/0x1c0
[  229.405253] [<ffffff80080db09c>] kthread+0xec/0xf0
[  229.409891] [<ffffff80080838a0>] ret_from_fork+0x10/0x30
[  229.414886] ---[ end trace 544aa6fd8e6497f9 ]---
[  229.431633] note: vi-output, ov56[9442] exited with preempt_count 1

Please note the line stating no reply from camera processor.
Is it expecting a certain handshake to happen? Something to preconfigure that we aren’t doing correctly?

Thanks,
Moti.

8

The kernel crash could be cause the NVCSI/VI unable capture data from sensor and went to unknow state and cause the kernel crash.

9

Thanks @ShaneCCC.
We’re investigating possible FPGA issues on the link.

Parallel to that, our sensor output monochrome (grayscale) pixels of 12 bits per pixel, something that should match RAW12.
What would be the correct settings to place in the dtsi?
Any necessary modifications to the driver/kernel source for support?

v3l2-ctl reports RG12 format, which doesn’t fit our configuration.

Moti.

10

Suppose RAW12 should be fine for your case.
But I think your problem are HW or signal problem due to NVCSI/VI didn’t receive any validate data yet.
Even the format error at least NVCSI/VI should receive FS/FE header.

Thanks

1 Like
11

Thanks for the quick response, now checking the fpga core again, seems like the issue we’re facing indeed.

13

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