Hi NV TEAM，
I debug imx390 + max9295 + max9296a in TX2 NX platform， Soc can not capture image. dmesg show below log.
[ 594.384674] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000c
[ 594.393378] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0000000c
[ 594.401217] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0000000c
How to debug this error?
I capture trace log.
trace.log (126.8 KB)
hello a1ayin,
there’s an error with CHANSEL_FAULT.
kworker/0:1-1187 [000] .... 372.822701: rtcpu_vinotify_event: tstamp:11775720678 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:11775720152 data:0x00000001
kworker/0:1-1187 [000] .... 372.822702: rtcpu_vinotify_event: tstamp:11775720851 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:11775720169 data:0x00000000
kworker/0:1-1187 [000] .... 372.822703: rtcpu_vinotify_event: tstamp:11775723767 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:11775723391 data:0x08000000
kworker/0:1-1187 [000] .... 372.822704: rtcpu_vinotify_event: tstamp:11775724209 tag:CHANSEL_FAULT channel:0x00 frame:0 vi_tstamp:11775723847 data:0x00000200
kworker/0:1-1187 [000] .... 372.822704: rtcpu_vinotify_event: tstamp:11775724724 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:11775724350 data:0x08000000
kworker/0:1-1187 [000] .... 372.822704: rtcpu_vinotify_event: tstamp:11775725300 tag:CHANSEL_FAULT_FE channel:0x04 frame:0 vi_tstamp:11775724780 data:0x00000001
kworker/0:1-1187 [000] .... 372.822705: rtcpu_vinotify_event: tstamp:11775725444 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:11775724783 data:0x00000000
the error code shows there’s PIXEL_SHORT_LINE, which means the receiving lines is less than expectation.
since you’re working with a SerDes chip, please also check the configuration is correct.
Hi JerryChang,
It mean active_height larger than serder output actual height, right?
yes, please review the SerDes configurations.
Hi Jerry，
Soc can get image from serder after changing serder’s configuration, but kernel show below error log.
[ 2738.734454] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 2738.744982] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00000004
[ 2738.752836] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00000004
[ 2738.996090] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 2739.002445] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 2739.012151] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x00000006
[ 2739.020867] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00010006
[ 2739.028769] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00010006
[ 2739.760083] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 2739.766444] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 2739.984101] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 2739.990457] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 2740.000277] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x00000004
[ 2740.008997] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00010006
[ 2740.016830] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00010006
[ 2740.232074] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 2740.238445] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 2740.248908] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x00000004
[ 2740.257619] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00010006
[ 2740.265459] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00010006
I also catch trace log.
kworker/5:1-1192 [005] .... 2754.352076: rtcpu_vinotify_event: tstamp:86200653087 tag:CHANSEL_LOAD_FRAMED channel:
0x04 frame:0 vi_tstamp:86200652721 data:0x08000000
vi-output, imx3-27723 [005] … 2754.359134: tegra_channel_capture_frame: sof:2754.239005408
vi-output, imx3-27723 [005] … 2754.392462: tegra_channel_capture_frame: sof:2754.272339296
kworker/5:1-1192 [005] … 2754.408065: rtcpu_vinotify_event: tstamp:86201650530 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86201649847 data:0x04370002
kworker/5:1-1192 [005] … 2754.408066: rtcpu_vinotify_event: tstamp:86201650656 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86201649877 data:0x00000000
kworker/5:1-1192 [005] … 2754.408067: rtcpu_vinotify_event: tstamp:86201692541 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86201692037 data:0x00000001
kworker/5:1-1192 [005] … 2754.408067: rtcpu_vinotify_event: tstamp:86201692707 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86201692040 data:0x00000000
kworker/5:1-1192 [005] … 2754.408067: rtcpu_vinotify_event: tstamp:86201695518 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86201695154 data:0x08000000
kworker/5:1-1192 [005] … 2754.408069: rtos_queue_peek_from_isr_failed: tstamp:86202294717 queue:0x0b4b4500
kworker/5:1-1192 [005] … 2754.408070: rtcpu_vinotify_event: tstamp:86202692208 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86202691531 data:0x04370002
kworker/5:1-1192 [005] … 2754.408071: rtcpu_vinotify_event: tstamp:86202692339 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86202691561 data:0x00000000
kworker/5:1-1192 [005] … 2754.408071: rtcpu_vinotify_event: tstamp:86202734226 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86202733721 data:0x00000001
kworker/5:1-1192 [005] … 2754.408072: rtcpu_vinotify_event: tstamp:86202734392 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86202733725 data:0x00000000
kworker/5:1-1192 [005] … 2754.408072: rtcpu_vinotify_event: tstamp:86202736999 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86202736636 data:0x08000000
vi-output, imx3-27723 [005] … 2754.425797: tegra_channel_capture_frame: sof:2754.305673664
vi-output, imx3-27723 [005] … 2754.459128: tegra_channel_capture_frame: sof:2754.339008032
kworker/5:1-1192 [005] … 2754.464070: rtcpu_vinotify_event: tstamp:86203733900 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86203733224 data:0x04370002
kworker/5:1-1192 [005] … 2754.464071: rtcpu_vinotify_event: tstamp:86203734021 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86203733253 data:0x00000000
kworker/5:1-1192 [005] … 2754.464071: rtcpu_vinotify_event: tstamp:86203775931 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86203775420 data:0x00000001
kworker/5:1-1192 [005] … 2754.464072: rtcpu_vinotify_event: tstamp:86203776098 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86203775424 data:0x00000000
kworker/5:1-1192 [005] … 2754.464072: rtcpu_vinotify_event: tstamp:86203778712 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86203778347 data:0x08000000
kworker/5:1-1192 [005] … 2754.464073: rtcpu_vinotify_event: tstamp:86204775599 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86204774915 data:0x04370002
kworker/5:1-1192 [005] … 2754.464073: rtcpu_vinotify_event: tstamp:86204775714 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86204774946 data:0x00000000
kworker/5:1-1192 [005] … 2754.464073: rtcpu_vinotify_event: tstamp:86204817624 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86204817119 data:0x00000001
kworker/5:1-1192 [005] … 2754.464074: rtcpu_vinotify_event: tstamp:86204817791 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86204817123 data:0x00000000
kworker/5:1-1192 [005] … 2754.464074: rtcpu_vinotify_event: tstamp:86204820338 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86204819973 data:0x08000000
vi-output, imx3-27723 [005] … 2754.492458: tegra_channel_capture_frame: sof:2754.372342400
kworker/5:1-1192 [005] … 2754.520070: rtcpu_vinotify_event: tstamp:86205817293 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86205816614 data:0x04370002
kworker/5:1-1192 [005] … 2754.520071: rtcpu_vinotify_event: tstamp:86205817415 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86205816644 data:0x00000000
kworker/5:1-1192 [005] … 2754.520072: rtcpu_vinotify_event: tstamp:86205859326 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86205858818 data:0x00000001
kworker/5:1-1192 [005] … 2754.520072: rtcpu_vinotify_event: tstamp:86205859492 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86205858822 data:0x00000000
kworker/5:1-1192 [005] … 2754.520072: rtcpu_vinotify_event: tstamp:86205861891 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86205861527 data:0x08000000
vi-output, imx3-27723 [005] … 2754.525805: tegra_channel_capture_frame: sof:2754.405676320
vi-output, imx3-27723 [005] … 2754.559136: tegra_channel_capture_frame: sof:2754.439010176
kworker/5:1-1192 [005] … 2754.576074: rtcpu_vinotify_event: tstamp:86206858987 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86206858307 data:0x04370002
kworker/5:1-1192 [005] … 2754.576075: rtcpu_vinotify_event: tstamp:86206859104 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86206858336 data:0x00000000
kworker/5:1-1192 [005] … 2754.576076: rtcpu_vinotify_event: tstamp:86206901009 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86206900503 data:0x00000001
kworker/5:1-1192 [005] … 2754.576076: rtcpu_vinotify_event: tstamp:86206901176 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86206900507 data:0x00000000
kworker/5:1-1192 [005] … 2754.576076: rtcpu_vinotify_event: tstamp:86206903981 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86206903617 data:0x08000000
kworker/5:1-1192 [005] … 2754.576078: rtos_queue_peek_from_isr_failed: tstamp:86207294703 queue:0x0b4b4500
kworker/5:1-1192 [005] … 2754.576078: rtcpu_vinotify_event: tstamp:86207900673 tag:CHANSEL_PXL_EOF channel:0x00 frame:0 vi_tstamp:86207899991 data:0x04370002
kworker/5:1-1192 [005] … 2754.576079: rtcpu_vinotify_event: tstamp:86207900796 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:86207900020 data:0x00000000
kworker/5:1-1192 [005] … 2754.576079: rtcpu_vinotify_event: tstamp:86207942693 tag:CHANSEL_PXL_SOF channel:0x00 frame:0 vi_tstamp:86207942186 data:0x00000001
kworker/5:1-1192 [005] … 2754.576079: rtcpu_vinotify_event: tstamp:86207942864 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:86207942191 data:0x00000000
kworker/5:1-1192 [005] … 2754.576080: rtcpu_vinotify_event: tstamp:86207945596 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:0 vi_tstamp:86207945231 data:0x08000000
these logs indicate that there are still errors in the package，right？ how to debug these errors？
hello a1ayin,
it looks all normal according to VI tracing logs.
for example,
CHANSEL_PXL_SOF: this meant VI engine have received start-of-frame correctly.
CHANSEL_LOAD_FRAMED: this meant buffer write has done.
CHANSEL_PXL_EOF: this meant VI engine have received end-of-frame correctly.
please also check the frame-rate is streaming as expected.
you may try setting up a terminal for running $ dmesg --follow to catch the kernel logs simultaneously.
Hi Jerry,
I use v4l2-ctl tool to capture image,the frame rate is unstable and constantly changing .
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 30.09 fps
<<<<<<<<<<<<<<<<< 20.33 fps
<<<<<<<<<<<<<<<<<<< 22.33 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 24.25 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 25.40 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 26.16 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<< 25.98 fps
<<<<<<<<<<<<<<<<<<<<<<<<< 26.25 fps
<<<<<<<<<<<<<< 24.88 fps
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< 25.40 fps
kernel logs print below logs
[ 520.894276] camera_common_s_power is here1
[ 523.874653] camera_common_s_power is here0
[ 523.874659] imx390, imx390_power_on++
[ 523.874660] imx390, imx390_power_on–
[ 523.876579] imx390, imx390_g_input_status
[ 523.881883] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 523.887258] imx390, imx390_s_stream, enable=1
[ 525.676460] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 525.682829] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 525.692676] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 525.944445] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 525.950812] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 525.960642] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 526.212443] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 526.218805] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 526.229185] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x00000006
[ 526.237904] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00010006
[ 526.245740] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00010006
[ 526.253924] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 531.080454] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 531.086814] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 531.096511] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 532.244461] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 532.250823] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 532.260510] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00000004
[ 532.268361] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00000004
[ 532.276544] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 532.580473] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 532.586930] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 532.596691] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00000004
[ 532.604544] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00000004
[ 532.612728] nvcsi 150c0000.nvcsi: dayin csi4_stream_init
[ 534.508701] imx390, imx390_s_stream, enable=0
[ 534.508727] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x00000004
[ 534.516600] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x00000004
[ 534.527110] camera_common_s_power is here1
it makes sense now…
it’s sometime VI cannot wait start-of-frame to cause unstable frame-rate. and… it has recovered internally so that the capture pipeline won’t crash.
is this due to clock configuration?
please try commands as following to boost all the VI/CSI/ISP clocks.
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
Hi jerry,
The previously provided logs were all captured while boost all the VI/CSI/ISP clocks. If not boost all the VI/CSI/ISP clocks, soc cannot get image. I also think there is a problem with the clock. Which clocks do I need to check？
hello a1ayin,
please check device tree property, serdes_pix_clk_hz.
you may see-also developer guide for SerDes Pixel Clock section.
may I also confirm how many camera streams you’ve enabled with SerDes chip?
here’s developer guide, Jetson Virtual Channel with GMSL Camera Framework as reference for developing SerDes driver.
Hi Jerry，
soc can capture image stably after change serdes pixel clock. Now i want to configre gpio07 as pwm to sync camera, but i don’t know gpio07 belong to which pwmchip. I need your help.
hello a1ayin,
may I confirm the pin you’re using?
you may check pinmux spreadsheets, and please try using Jetson-IO for Configuring the 40-Pin Expansion Header.
Hi jerry，
I’m using CPIO3_PU.00, I had configured this pin as GP_PWM1 function in pinmux spreadsheets. how to output pwm next step?
hello a1ayin,
you may set PWM periods/duty_cycle configurations.
please populate the channel ID via sysfs. $ echo <channel_id> > /sys/class/pwm/<pwmchip instantiated>/export
for example, $ echo 0 > /sys/class/pwm/pwmchip4/export
a new channel-id will create under pwmchip4, path… /sys/class/pwm/pwmchip4/pwm0
then, please configure duty_cycle, period, and toggle enable to enable PWM.
This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.