Custom MIPI Camera:- Gstremaer error: streaming stopped, reason not-negotiated (-4)

HI @JerryChang,

Got the same error in dmesg, however, some extra info on traces. I changed the timeout value to 500ms, was that enough? I made following modifications in vi4_fops.c

static int vi4_channel_start_streaming(struct vb2_queue *vq, u32 count)
...
chan->sequence = 0;
	chan->timeout = msecs_to_jiffies(500); /* Modified ovalue from 200 to 500 millisconds*/
	if (!chan->low_latency)
		tegra_channel_i`Preformatted text`nit_ring_buffer(chan);
 
	INIT_WORK(&chan->error_work, tegra_channel_error_worker);
	INIT_WORK(&chan->status_work, tegra_channel_status_worker);

Furhter, I added some debug logs in channel.c as below:

void free_ring_buffers(struct tegra_channel *chan, int frames)
{
	struct vb2_v4l2_buffer *vbuf;
	s64 frame_arrived_ts = 0;
 
        pr_debug("free_ring_buffers: entering function\n");
 
 
	spin_lock(&chan->buffer_lock);
 
	if (frames == 0)
		frames = chan->num_buffers;
 
 
        pr_debug("free_ring_buffers: freeing %d frames\n", frames);
 
 
	while (frames > 0) {
		vbuf = chan->buffers[chan->free_index];
 
		/* Skip updating the buffer sequence with channel sequence
		 * for interlaced captures and this instead will be updated
		 * with frame id received from CSI with capture complete
		 */
		if (!chan->is_interlaced)
			vbuf->sequence = chan->sequence++;
		else
			chan->sequence++;
		/* release one frame */
		vbuf->field = V4L2_FIELD_NONE;
		vb2_set_plane_payload(&vbuf->vb2_buf,
			0, chan->format.sizeimage);
 
		/*
		 * WAR to force buffer state if capture state is not good
		 * WAR - After sync point timeout or error frame capture
		 * the second buffer is intermittently frame of zeros
		 * with no error status or padding.
		 */
#if 0
		/* This will drop the first two frames. Disable for now. */
		if (chan->capture_state != CAPTURE_GOOD ||
			chan->released_bufs < 2)
			chan->buffer_state[chan->free_index] =
						VB2_BUF_STATE_REQUEUEING;
#endif
 
		if (chan->sequence == 1) {
			/*
			 * Evaluate the initial capture latency
			 * between videobuf2 queue and first captured
			 * frame release to user-space.
			 */
			frame_arrived_ts = ktime_to_ms(ktime_get());
			dev_dbg(&chan->video->dev,
				"%s: capture init latency is %lld ms\n",
				__func__, (frame_arrived_ts - queue_init_ts));
		}
		vb2_buffer_done(&vbuf->vb2_buf,
			chan->buffer_state[chan->free_index++]);
 
		if (chan->free_index >= chan->capture_queue_depth)
			chan->free_index = 0;
		chan->num_buffers--;
		chan->released_bufs++;
	        pr_debug("free_ring_buffers: freed frame %d\n", frames);
		frames--;
	}
 
        pr_debug("free_ring_buffers: exiting function\n");
 
	spin_unlock(&chan->buffer_lock);
}

Follwoing the modifications, please find below the dmesg and traces log.
dmesg:

[ 8002.914880] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8002.921337] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8003.458754] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8003.465241] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8004.002640] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8004.009085] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8004.546509] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8004.552965] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8005.090405] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8005.096901] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8005.634287] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8005.640743] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8006.178181] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8006.184632] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8006.722032] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8006.728482] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8007.489918] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8007.496438] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8007.506447] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8007.515296] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) INTR_STATUS 0x00000004
[ 8007.523176] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERR_INTR_STATUS 0x00000004
[ 8008.033782] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8008.040206] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8008.050323] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8008.577704] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8008.584198] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8008.594173] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8009.121592] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8009.128081] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8009.138013] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8009.665467] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8009.672014] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8009.682076] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8010.209537] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8010.216035] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8010.226077] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8010.753375] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8010.759878] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8010.769774] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8011.297296] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8011.303824] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8011.314011] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8011.841156] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8011.847696] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8011.858537] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8012.385138] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8012.391766] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8012.401781] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8012.929056] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8012.935567] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8012.945576] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8013.472984] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8013.479520] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8013.489565] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8014.016974] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8014.023428] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8014.033363] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8014.560870] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8014.567442] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8014.577636] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8015.104753] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8015.111291] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8015.121334] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8015.648799] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8015.655257] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8015.665375] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8016.192722] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8016.199174] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8016.211686] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8016.736624] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 8016.743063] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 8016.752951] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[ 8016.762188] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004

traces
traces.txt (580.4 KB)

 vi-output, ov56-28057 [005] ....  8006.969626: tegra_channel_capture_frame: sof:8006.611660938
     kworker/5:0-26992 [005] ....  8006.985978: rtcpu_vinotify_event: tstamp:250495586936 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:250495586458 data:0x00000000
     kworker/5:0-26992 [005] ....  8006.985982: rtcpu_vinotify_event: tstamp:250495587057 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:250495586496 data:0x00000001
     kworker/5:0-26992 [005] ....  8006.985985: rtcpu_vinotify_event: tstamp:250495591572 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:250495591233 data:0x08000000
     kworker/5:0-26992 [005] ....  8007.042002: rtcpu_vinotify_event: tstamp:250497018188 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:250497017521 data:0x099f0002
     kworker/5:0-26992 [005] ....  8007.042009: rtcpu_vinotify_event: tstamp:250497018312 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:250497017540 data:0x00400060
     kworker/5:0-26992 [005] ....  8007.042011: rtcpu_vinotify_event: tstamp:250497018496 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:250497017544 data:0x00000000
     kworker/5:0-26992 [005] ....  8007.097937: rtos_queue_peek_from_isr_failed: tstamp:250498735423 queue:0x0b4b6398
     kworker/5:0-26992 [005] ....  8007.265916: rtos_queue_peek_from_isr_failed: tstamp:250503735409 queue:0x0b4b6398
     kworker/5:0-26992 [005] ....  8007.433909: rtos_queue_peek_from_isr_failed: tstamp:250508735402 queue:0x0b4b6398
 vi-output, ov56-28057 [003] ....  8007.531720: tegra_channel_capture_setup: vnc_id 0 W 3264 H 2464 fmt 20
 vi-output, ov56-28057 [003] ....  8007.531748: tegra_channel_capture_frame: sof:8006.611660938
     kworker/5:0-26992 [005] ....  8007.549800: rtos_queue_send_from_isr_failed: tstamp:250512354642 queue:0x0b4a7698
     kworker/5:0-26992 [005] ....  8007.549805: rtos_queue_send_from_isr_failed: tstamp:250512354755 queue:0x0b4ab1a8
     kworker/5:0-26992 [005] ....  8007.549806: rtos_queue_send_from_isr_failed: tstamp:250512354864 queue:0x0b4acdd8
     kworker/5:0-26992 [005] ....  8007.549807: rtos_queue_send_from_isr_failed: tstamp:250512354972 queue:0x0b4ae958
     kworker/5:0-26992 [005] ....  8007.549808: rtos_queue_send_from_isr_failed: tstamp:250512355077 queue:0x0b4af718
     

In this setup, I again reset the stream.

How do I confirm this?