Capture framerate is reduced by half after porting driver to JetPack 4.3

Robotics & Edge Computing Jetson & Embedded Systems Jetson TX2
1

I have a setup with an IMX264 sensor connected to the TX2 via an FPGA which outputs images in the native resolution at 30FPS. Everything works just fine with JetPack 3.3 but after porting the driver to JetPack 4.3 the framerate is reduced to 15FPS when capturing with V4L2. However, the actual images look ok. I do get occasional “rtos_queue_peek_from_isr_failed” messages in the tracelog when capturing as seen below. VI/CSI clocks are already maxed out and i have executed jetson_clocks.sh. Can you help me identify the cause?

15FPS capture even though the FPGA outputs 30FPS

nvidia@localhost:~$ v4l2-ctl --set-fmt-video=width=2476,height=2066,pixelformat=RG12 --stream-mmap --stream-count=1000 -d /dev/video0 
<<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps
<<<<<<<<<<<<<<< 15.00 fps

TraceLog

#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
     kworker/2:1-785   [002] ....   175.347047: rtcpu_vinotify_event: tstamp:5753631420 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5753630630 data:0x08110002
     kworker/2:1-785   [002] ....   175.347078: rtcpu_vinotify_event: tstamp:5753631761 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5753630666 data:0x00000000
     kworker/2:1-785   [002] ....   175.347088: rtcpu_vinotify_event: tstamp:5754803809 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5754803275 data:0x00000001
     kworker/2:1-785   [002] ....   175.347096: rtcpu_vinotify_event: tstamp:5754804056 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5754803280 data:0x00000000
     kworker/2:1-785   [002] ....   175.347104: rtcpu_vinotify_event: tstamp:5754809188 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5754808778 data:0x08000000
     kworker/2:1-785   [002] ....   175.403042: rtcpu_vinotify_event: tstamp:5755714466 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5755713625 data:0x08110002
     kworker/2:1-785   [002] ....   175.403055: rtcpu_vinotify_event: tstamp:5755714777 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5755713661 data:0x00000000
     kworker/2:1-785   [002] ....   175.403064: rtcpu_vinotify_event: tstamp:5756887312 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5756886711 data:0x00000001
     kworker/2:1-785   [002] ....   175.403072: rtcpu_vinotify_event: tstamp:5756887699 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5756886717 data:0x00000000
     kworker/2:1-785   [002] ....   175.403080: rtcpu_vinotify_event: tstamp:5756893469 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5756893020 data:0x08000000
     kworker/2:1-785   [002] ....   175.459288: rtos_queue_peek_from_isr_failed: tstamp:5757087501 queue:0x0b4b4500
     kworker/2:1-785   [002] ....   175.459323: rtcpu_vinotify_event: tstamp:5757797758 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5757797061 data:0x08110002
     kworker/2:1-785   [002] ....   175.459331: rtcpu_vinotify_event: tstamp:5757797876 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5757797097 data:0x00000000
     kworker/2:1-785   [002] ....   175.515053: rtcpu_vinotify_event: tstamp:5758970766 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5758970148 data:0x00000001
     kworker/2:1-785   [002] ....   175.515066: rtcpu_vinotify_event: tstamp:5758971152 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5758970154 data:0x00000000
     kworker/2:1-785   [002] ....   175.515074: rtcpu_vinotify_event: tstamp:5758977098 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5758976649 data:0x08000000
     kworker/2:1-785   [002] ....   175.515083: rtcpu_vinotify_event: tstamp:5759881291 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5759880497 data:0x08110002
     kworker/2:1-785   [002] ....   175.515091: rtcpu_vinotify_event: tstamp:5759881580 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5759880534 data:0x00000000
     kworker/2:1-785   [002] ....   175.571059: rtcpu_vinotify_event: tstamp:5761054170 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5761053585 data:0x00000001
     kworker/2:1-785   [002] ....   175.571074: rtcpu_vinotify_event: tstamp:5761054557 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5761053591 data:0x00000000
     kworker/2:1-785   [002] ....   175.571082: rtcpu_vinotify_event: tstamp:5761059653 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5761059196 data:0x08000000
     kworker/2:1-785   [002] ....   175.571090: rtcpu_vinotify_event: tstamp:5761964814 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5761963935 data:0x08110002
     kworker/2:1-785   [002] ....   175.571099: rtcpu_vinotify_event: tstamp:5761965142 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5761963971 data:0x00000000
     kworker/2:1-785   [002] ....   175.571110: rtos_queue_peek_from_isr_failed: tstamp:5762087493 queue:0x0b4b4500
     kworker/2:1-785   [002] ....   175.627190: rtcpu_vinotify_event: tstamp:5763137607 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5763137020 data:0x00000001
     kworker/2:1-785   [002] ....   175.627200: rtcpu_vinotify_event: tstamp:5763137994 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5763137027 data:0x00000000
     kworker/2:1-785   [002] ....   175.627207: rtcpu_vinotify_event: tstamp:5763143938 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5763143450 data:0x08000000
     kworker/2:1-785   [002] ....   175.683042: rtcpu_vinotify_event: tstamp:5764048163 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5764047372 data:0x08110002
     kworker/2:1-785   [002] ....   175.683054: rtcpu_vinotify_event: tstamp:5764048454 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5764047408 data:0x00000000
     kworker/2:1-785   [002] ....   175.683062: rtcpu_vinotify_event: tstamp:5765221043 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5765220458 data:0x00000001
     kworker/2:1-785   [002] ....   175.683069: rtcpu_vinotify_event: tstamp:5765221424 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5765220463 data:0x00000000
     kworker/2:1-785   [002] ....   175.683078: rtcpu_vinotify_event: tstamp:5765227476 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5765227024 data:0x08000000
     kworker/2:1-785   [002] ....   175.739007: rtcpu_vinotify_event: tstamp:5766131652 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5766130809 data:0x08110002
     kworker/2:1-785   [002] ....   175.739018: rtcpu_vinotify_event: tstamp:5766131980 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5766130844 data:0x00000000
     kworker/2:1-785   [002] ....   175.739028: rtos_queue_peek_from_isr_failed: tstamp:5767087500 queue:0x0b4b4500
     kworker/2:1-785   [002] ....   175.739036: rtcpu_vinotify_event: tstamp:5767304056 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5767303453 data:0x00000001
     kworker/2:1-785   [002] ....   175.739044: rtcpu_vinotify_event: tstamp:5767304418 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5767303459 data:0x00000000
     kworker/2:1-785   [002] ....   175.739052: rtcpu_vinotify_event: tstamp:5767310074 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5767309603 data:0x08000000
     kworker/2:1-785   [002] ....   175.794961: rtcpu_vinotify_event: tstamp:5768214630 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5768213803 data:0x08110002
     kworker/2:1-785   [002] ....   175.794969: rtcpu_vinotify_event: tstamp:5768214921 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5768213840 data:0x00000000
     kworker/2:1-785   [002] ....   175.851056: rtcpu_vinotify_event: tstamp:5769387437 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5769386890 data:0x00000001
     kworker/2:1-785   [002] ....   175.851077: rtcpu_vinotify_event: tstamp:5769387682 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5769386896 data:0x00000000
     kworker/2:1-785   [002] ....   175.851085: rtcpu_vinotify_event: tstamp:5769392985 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5769392577 data:0x08000000
     kworker/2:1-785   [002] ....   175.851093: rtcpu_vinotify_event: tstamp:5770298066 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5770297239 data:0x08110002
     kworker/2:1-785   [002] ....   175.851101: rtcpu_vinotify_event: tstamp:5770298400 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5770297276 data:0x00000000
     kworker/2:1-785   [002] ....   175.907072: rtcpu_vinotify_event: tstamp:5771470946 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:5771470326 data:0x00000001
     kworker/2:1-785   [002] ....   175.907086: rtcpu_vinotify_event: tstamp:5771471333 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5771470333 data:0x00000000
     kworker/2:1-785   [002] ....   175.907094: rtcpu_vinotify_event: tstamp:5771476575 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:0 vi_tstamp:5771476126 data:0x08000000
     kworker/2:1-785   [002] ....   175.907112: rtos_queue_peek_from_isr_failed: tstamp:5772087532 queue:0x0b4b4500
     kworker/2:1-785   [002] ....   175.907120: rtcpu_vinotify_event: tstamp:5772381468 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:5772380676 data:0x08110002
     kworker/2:1-785   [002] ....   175.907128: rtcpu_vinotify_event: tstamp:5772381760 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5772380712 data:0x00000000
2

I have noticed that all frame numbers in the trace log above are reported as frame:0. Can the missing frame number have something to do with the issue?

3

Have a try to increase the Pixel_clk_hz or add serdes_pix_clk_hz

4

As mentioned, i have already maxed out the relevant clocks:

vi clock rate is:1036800000
isp clock rate is:1126400000
emc clock rate is:1866000000
nvcsi clock rate is:225000000

The serdes_pix_clk_hz is set to 225000000 via the device tree. What is the file handle to access the serdes_pix_clk_hz clock setting? (The equvalient to /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate).
When setting the sensor to HD-mode the framerate is also reduced by half i.e. 25FPS vs 50FPS in JetPack 3.3.

5

Here is the device tree for reference. I have also tried to double the ‘max_lane_speed’ from 1500000 to 3000000 even though the former value works in JetPack 3.3

Device Tree

mode0 {/*mode IMX 5MPIX*/
	mclk_khz = "37125"; //CSI driving high speed clock
	num_lanes = "4";
	tegra_sinterface = "serial_a";
	phy_mode = "DPHY";
	discontinuous_clk = "yes";// discontinuous clock on MIPI lanes.
	dpcm_enable = "false";// compression
	cil_settletime = "0";
	dynamic_pixel_bit_depth = "12";
	csi_pixel_bit_depth = "12";
	mode_type = "bayer";
	pixel_phase = "rggb";

	active_w = "2476";
	active_h = "2066";
	readout_orientation = "0";
	line_length = "2572";
	inherent_gain = "1";
	mclk_multiplier = "1";
	pix_clk_hz = "225000000";
	serdes_pix_clk = "225000000";

	gain_factor = "10";
	min_gain_val = "0"; /* 0dB */
	max_gain_val = "48"; /* 48dB */
	step_gain_val = "3"; /* 0.3 */
	default_gain = "0";
	min_hdr_ratio = "1";
	max_hdr_ratio = "1";
	framerate_factor = "1000000";
	min_framerate = "30000000"; /* 30*/
	max_framerate = "30000000"; /* 30 */
	step_framerate = "1";
	default_framerate = "30000000";
	exposure_factor = "1000000";
	min_exp_time = "30"; /* us */
	max_exp_time = "660000"; /* us */
	step_exp_time = "1";
	default_exp_time = "33334";/* us */
	embedded_metadata_height = "0";
};
6

Update: The error was in the Serial 2 MIPI bridge. Case closed.