Cannot get frame from custom camera

[kingkong]

Platform: P3668 + P3509
OS: Jetpack 4.6.1
Current status: Camera sensor is streaming, and I can find mipi data signal from oscilloscope.
Kernel error:

[ 5681.504435] tegra194-vi5 15c10000.vi: no reply from camera processor
[ 5681.504634] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[ 5681.504776] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[ 5681.504915] 382: tegra194-vi5 15c10000.vi: vi_channel_power_off_vi_device
[ 5681.505920] 185: tegra194-vi5 15c10000.vi: vi_capture_shutdown--
[ 5681.505938] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 0 msg_id 18
[ 5681.506347] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 0 msg_id 19
[ 5681.506359] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[ 5681.507313] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[ 5681.507418] 325: t194-nvcsi 15a00000.nvcsi: csi5_stop_streaming: csi_pt=0, st_id=0, vc_id=0, pg_mode=0x0
[ 5681.507425] 116: t194-nvcsi 15a00000.nvcsi: csi5_stream_close: stream_id=0, csi_port=0
[ 5681.507434] 293: t194-nvcsi 15a00000.nvcsi: csi5_start_streaming: csi_pt=0, st_id=0, vc_id=0, pg_mode=0x0
[ 5681.507440] 111: t194-nvcsi 15a00000.nvcsi: settle time reading from props
[ 5681.507446] 142: t194-nvcsi 15a00000.nvcsi: discontinuous_clk = 1 reading from props
[ 5681.507451] 145: t194-nvcsi 15a00000.nvcsi: csi5_stream_set_config: stream_id=0, csi_port=0
[ 5681.507457] 93: t194-nvcsi 15a00000.nvcsi: csi5_stream_open: stream_id=0, csi_port=0
[ 5681.507465] 140: tegra194-vi5 15c10000.vi: vi_capture_init++
[ 5681.507523] 363: tegra194-vi5 15c10000.vi: vi_channel_power_on_vi_device
[ 5681.507571] 400: tegra194-vi5 15c10000.vi: chan flags 4163
[ 5681.507578] 401: tegra194-vi5 15c10000.vi: chan mask ffffffffffffffff
[ 5681.507583] 402: tegra194-vi5 15c10000.vi: queue depth 2
[ 5681.507588] 403: tegra194-vi5 15c10000.vi: request size 704
[ 5681.507638] 475: tegra194-vi5 15c10000.vi: 6 GoS tables configured.
[ 5681.507644] 479: tegra194-vi5 15c10000.vi: gos[0] = 0xc2100000
[ 5681.507649] 479: tegra194-vi5 15c10000.vi: gos[1] = 0xc2101000
[ 5681.507656] 479: tegra194-vi5 15c10000.vi: gos[2] = 0xc2102000
[ 5681.507661] 479: tegra194-vi5 15c10000.vi: gos[3] = 0xc2103000
[ 5681.507666] 479: tegra194-vi5 15c10000.vi: gos[4] = 0xc2104000
[ 5681.507671] 479: tegra194-vi5 15c10000.vi: gos[5] = 0xc2105000
[ 5681.507676] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 93 msg_id 16
[ 5681.507870] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 93 msg_id 17
[ 5681.507882] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[ 5681.507899] 1070: tegra194-vi5 15c10000.vi: vi_capture_request: sending chan_id 0 msg_id 1 buf:0
[ 5681.507909] 1070: tegra194-vi5 15c10000.vi: vi_capture_request: sending chan_id 0 msg_id 1 buf:1
[ 5681.508050] 1103: tegra194-vi5 15c10000.vi: vi_capture_status: waiting for status, timeout:2500 ms
[ 5681.510929] 293: <mmc0: starting CMD23 arg 00000018 flags 00000015>
[ 5681.510939] 298: mmc0: starting CMD25 arg 00d1e1a8 flags 000000b5
[ 5681.510945] 306: mmc0:     blksz 512 blocks 24 flags 00000100 tsac 3000 ms nsac 0
[ 5681.510950] 312: mmc0:     CMD12 arg 00000000 flags 0000049d
[ 5681.513781] 193: mmc0: req done <CMD23>: 0: 00000000 00000000 00000000 00000000
[ 5681.513811] 199: mmc0: req done (CMD25): 0: 00000900 00000000 00000000 00000000
[ 5681.513822] 204: mmc0:     12288 bytes transferred: 0
[ 5681.513830] 226: mmc0:     (CMD12): 0: 00000000 00000000 00000000 00000000
[ 5681.513867] 298: mmc0: starting CMD13 arg aaaa0000 flags 00000195
[ 5681.513899] 199: mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
[ 5681.514076] 293: <mmc0: starting CMD23 arg 00000008 flags 00000015>
[ 5681.514081] 298: mmc0: starting CMD25 arg 00d1e1c0 flags 000000b5
[ 5681.514085] 306: mmc0:     blksz 512 blocks 8 flags 00000100 tsac 3000 ms nsac 0
[ 5681.514089] 312: mmc0:     CMD12 arg 00000000 flags 0000049d
[ 5681.517259] 193: mmc0: req done <CMD23>: 0: 00000000 00000000 00000000 00000000
[ 5681.517294] 199: mmc0: req done (CMD25): 0: 00000900 00000000 00000000 00000000
[ 5681.517302] 204: mmc0:     4096 bytes transferred: 0
[ 5681.517308] 226: mmc0:     (CMD12): 0: 00000000 00000000 00000000 00000000
[ 5681.517329] 298: mmc0: starting CMD13 arg aaaa0000 flags 00000195
[ 5681.517355] 199: mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
[ 5684.032420] tegra194-vi5 15c10000.vi: no reply from camera processor
[ 5684.032576] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[ 5684.032708] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[ 5684.032847] 382: tegra194-vi5 15c10000.vi: vi_channel_power_off_vi_device
[ 5684.033806] 185: tegra194-vi5 15c10000.vi: vi_capture_shutdown--
[ 5684.033818] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 0 msg_id 18
[ 5684.034371] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 0 msg_id 19
[ 5684.034384] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[ 5684.035322] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[ 5684.035398] 325: t194-nvcsi 15a00000.nvcsi: csi5_stop_streaming: csi_pt=0, st_id=0, vc_id=0, pg_mode=0x0
[ 5684.035404] 116: t194-nvcsi 15a00000.nvcsi: csi5_stream_close: stream_id=0, csi_port=0
[ 5684.035413] 293: t194-nvcsi 15a00000.nvcsi: csi5_start_streaming: csi_pt=0, st_id=0, vc_id=0, pg_mode=0x0
[ 5684.035419] 111: t194-nvcsi 15a00000.nvcsi: settle time reading from props
[ 5684.035425] 142: t194-nvcsi 15a00000.nvcsi: discontinuous_clk = 1 reading from props
[ 5684.035431] 145: t194-nvcsi 15a00000.nvcsi: csi5_stream_set_config: stream_id=0, csi_port=0
[ 5684.035437] 93: t194-nvcsi 15a00000.nvcsi: csi5_stream_open: stream_id=0, csi_port=0
[ 5684.035444] 140: tegra194-vi5 15c10000.vi: vi_capture_init++
[ 5684.035500] 363: tegra194-vi5 15c10000.vi: vi_channel_power_on_vi_device
[ 5684.035525] 400: tegra194-vi5 15c10000.vi: chan flags 4163
[ 5684.035533] 401: tegra194-vi5 15c10000.vi: chan mask ffffffffffffffff
[ 5684.035538] 402: tegra194-vi5 15c10000.vi: queue depth 2
[ 5684.035543] 403: tegra194-vi5 15c10000.vi: request size 704
[ 5684.035595] 475: tegra194-vi5 15c10000.vi: 6 GoS tables configured.
[ 5684.035601] 479: tegra194-vi5 15c10000.vi: gos[0] = 0xc2100000
[ 5684.035606] 479: tegra194-vi5 15c10000.vi: gos[1] = 0xc2101000
[ 5684.035611] 479: tegra194-vi5 15c10000.vi: gos[2] = 0xc2102000
[ 5684.035616] 479: tegra194-vi5 15c10000.vi: gos[3] = 0xc2103000
[ 5684.035621] 479: tegra194-vi5 15c10000.vi: gos[4] = 0xc2104000
[ 5684.035626] 479: tegra194-vi5 15c10000.vi: gos[5] = 0xc2105000
[ 5684.035632] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 94 msg_id 16
[ 5684.035774] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 94 msg_id 17
[ 5684.035783] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[ 5684.035994] 350: addi9036 9-0010: stream 0
[ 5684.036005] 325: t194-nvcsi 15a00000.nvcsi: csi5_stop_streaming: csi_pt=0, st_id=0, vc_id=0, pg_mode=0x0
[ 5684.036012] 116: t194-nvcsi 15a00000.nvcsi: csi5_stream_close: stream_id=0, csi_port=0
[ 5684.046228] 228: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: sending chan_id 0 msg_id 20
[ 5684.047339] 265: tegra194-vi5 15c10000.vi: vi_capture_ivc_send_control: response chan_id 0 msg_id 21
[ 5684.047413] 382: tegra194-vi5 15c10000.vi: vi_channel_power_off_vi_device
[ 5684.048156] 185: tegra194-vi5 15c10000.vi: vi_capture_shutdown--
[ 5684.048701] 907: addi9036 9-0010: camera_common_dpd_enable: csi 0
[ 5684.048707] 844: addi9036 9-0010: camera_common_mclk_disable: disable MCLK
[ 5684.048799] 78: t194-nvcsi 15a00000.nvcsi: csi5_power_off

[JerryChang]

hello kingkong,

it looks tegra194-vi5 15c10000.vi: no reply from camera processor is reported by VI engine.

what did you mean camera is streaming, are you saying there’s high speed signaling but you cannot see camera preview frames on display side?
please share the commands you’re using. please also check Applications Using V4L2 IOCTL Directly to use V4L2 IOCTL to verify basic functionality.
thanks

[kingkong]

Yes, the camera is streaming, I can find the signal by oscilloscope.
Test command:
v4l2-ctl --stream-mmap

Could you suggest how to debug VI engine not report?

Thanks!

[JerryChang]

hello kingkong,

please dump the formats as below…
$ v4l2-ctl -d /dev/video0 --list-formats-ext

then, please assign the sensor supported formats into v4l pipeline to test again,
for example,
$ v4l2-ctl -d /dev/video0 --set-fmt-video=width=1920,height=1080,pixelformat=RG10 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=100

it might be incorrect sensor pixel clock rate, please check developer guide for Sensor Pixel Clock session to review your pixel_clk_hz property settings.

or,
please have a try to boost all the VI/CSI/ISP clocks.
you may follow below commands to configure them.

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