IMX715 via GMSL "General error queue is out of sync with frame queue."

[manthey]

We use a Jetson Orin Nano 8GB. We try to connect an IMX715 sensor with the Orin Nano via GMSL. While we receive images the frame rate unfortunately is very low.

The trace log we get is here:
trace.txt (269.9 KB)

The error we see in the kernel log is:

[  561.475414] imx715 10-001a: probing v4l2 sensor
[  561.475501] imx715 10-001a: initializing mipi...
[  561.476060] imx715 10-001a: tegracam sensor driver:imx715_v2.0.6
[  561.509523] tegra-camrtc-capture-vi tegra-capture-vi: subdev imx715 10-001a bound
[  561.512879] imx715 10-001a: Detected imx715 sensor
[  593.340344] bwmgr API not supported
[  593.388435] imx715 10-001a: imx715_set_mclk: enable MCLK with 24000000 Hz
[  593.405867] imx715 10-001a: imx715_set_data_rate: Data rate: 4
[  593.620576] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 20000h
[  593.653879] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 40000h
[  596.195940] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  596.196209] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  596.196982] (NULL device *): vi_capture_control_message: NULL VI channel received
[  596.197188] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=1, csi_port=1
[  596.197470] (NULL device *): vi_capture_control_message: NULL VI channel received
[  596.197674] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 1 vc- 0
[  596.198174] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  596.222002] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 40000h
[  596.254149] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: flags 2, err_data 0h
[  596.275784] [RCE] ERROR: camera-ip/vi5/vi5.c:745 [vi5_handle_eof] "General error queue is out of sync with frame queue. ts=626455101344 sof_ts=626455650720 gerror_code=2 gerror_data=a1 notify_bits=0"
[  598.755784] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  598.756058] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  598.757182] (NULL device *): vi_capture_control_message: NULL VI channel received
[  598.757386] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=1, csi_port=1
[  598.757673] (NULL device *): vi_capture_control_message: NULL VI channel received
[  598.757867] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 1 vc- 0
[  598.758697] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  598.842428] bwmgr API not supported
[  693.040143] bwmgr API not supported

Example image received with v4l-ctl

[ShaneCCC]

Boost the clocks to get check and get the trace log again.

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

[manthey]

We tried but could not notice any different behavior
trace.txt (271.8 KB)

[55787.485092] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[55787.485361] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[55787.485921] (NULL device *): vi_capture_control_message: NULL VI channel received
[55787.486137] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=1, csi_port=1
[55787.486417] (NULL device *): vi_capture_control_message: NULL VI channel received
[55787.486617] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 1 vc- 0
[55787.487103] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[55787.518425] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 40000h
[55787.550886] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: flags 2, err_data 0h
[55787.589100] [RCE] ERROR: camera-ip/vi5/vi5.c:745 [vi5_handle_eof] "General error queue is out of sync with frame queue. ts=55817719504256 sof_ts=55817720053600 gerror_code=2 gerror_data=a1 notify_bits=200000"
[55790.301101] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[55790.301376] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[55790.301933] (NULL device *): vi_capture_control_message: NULL VI channel received
[55790.302154] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=1, csi_port=1
[55790.302427] (NULL device *): vi_capture_control_message: NULL VI channel received
[55790.302635] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 1 vc- 0
[55790.303119] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[55790.318109] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 40000h
[55790.349886] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: flags 2, err_data 0h
[55790.389096] [RCE] ERROR: camera-ip/vi5/vi5.c:745 [vi5_handle_eof] "General error queue is out of sync with frame queue. ts=55820519180832 sof_ts=55820519730208 gerror_code=2 gerror_data=a1 notify_bits=200000"

[ShaneCCC]

It could be the embedded_metadata_height incorrect in the device tree.
Or the output line less than expected. Please check the output size configure.

 kworker/2:1-3739    [002] .... 55633.613100: rtcpu_vinotify_event: tstamp:1739493794240 cch:0 vi:0 tag:CHANSEL_SHORT_FRAME channel:0x02 frame:0 vi_tstamp:55663799510944 data:0x0000200000000000

[manthey]

Ok. You have a description what this means?

tag:CHANSEL_NOMATCH channel:0x02 frame:0 vi_tstamp:55663968035712 data:0x0000000000000249

According to here data = 0x249 (0b0010010 0100 1) means
no_match= ON
DTYPE=18 = ? not defined
CTYPE=4 = LS = LineStart

[ShaneCCC]

It could be user define data that don’t support it.

@manthey

DTYPE=18 = ? not defined

[manthey]

Uhhh…
Datatype 18 = 0x12 = Embedded 8-bit non Image Data
Looking at the image I see a Embedded Footer instead of Embedded_Header Line.

Are embedded footer lines supported in the devicetree?

[ShaneCCC]

Should be support it. Confirm the embedded_metadata_height in correct configure.

[manthey]

Seems like the root cause was a duplicate start of frame (SOF) and end of frame (EOF) package caused by the GMSL deserializer configuration.