upstream unicam not returning any buffer

[Maxime Ripard <mripard@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 7907 bytes --]

Hi,

I've been trying to port a v4l2 application from the downstream unicam
driver (with the 6.6 kernel) to upstream (6.13.11) kernel.

While the application seemed to work ok with the downstream driver, the
same code will never get any buffer from the upstream unicode driver.
Either dqbuf will block forever (if it's blocking), or never return a
buffer (if it's non-blocking).

The media-controller topology after the application configured it is:

Media controller API version 6.13.11

Media device information
------------------------
driver          unicam
model           unicam
serial
bus info        platform:fe801000.csi
hw revision     0x0
driver version  6.13.11

Device topology
- entity 1: unicam (3 pads, 3 links, 0 routes)
            type V4L2 subdev subtype Unknown flags 0
            device node name /dev/v4l-subdev0
	pad0: SINK
		[stream:0 fmt:RGB888_1X24/1280x720 field:none colorspace:srgb xfer:srgb ycbcr:601 quantization:lim-range]
		<- "tc358743 5-000f":0 [ENABLED,IMMUTABLE]
	pad1: SOURCE
		[stream:0 fmt:RGB888_1X24/1280x720 field:none colorspace:srgb xfer:srgb ycbcr:601 quantization:lim-range]
		-> "unicam-image":0 [ENABLED,IMMUTABLE]
	pad2: SOURCE
		-> "unicam-embedded":0 [ENABLED,IMMUTABLE]

- entity 5: tc358743 5-000f (1 pad, 1 link, 0 routes)
            type V4L2 subdev subtype Unknown flags 0
            device node name /dev/v4l-subdev1
	pad0: SOURCE
		[stream:0 fmt:RGB888_1X24/1280x720 field:none colorspace:srgb]
		[dv.caps:BT.656/1120 min:640x350@13000000 max:1920x1200@165000000 stds:CEA-861,DMT,CVT,GTF caps:progressive,reduced-blanking,custom]
		[dv.detect:BT.656/1120 1280x720p60 (1650x750) stds: flags:]
		[dv.current:BT.656/1120 1280x720p60 (1650x750) stds: flags:]
		-> "unicam":0 [ENABLED,IMMUTABLE]

- entity 9: unicam-image (1 pad, 1 link)
            type Node subtype V4L flags 1
            device node name /dev/video0
	pad0: SINK
		<- "unicam":1 [ENABLED,IMMUTABLE]

- entity 15: unicam-embedded (1 pad, 1 link)
             type Node subtype V4L flags 0
             device node name /dev/video1
	pad0: SINK
		<- "unicam":2 [ENABLED,IMMUTABLE]

The interrupt count in /proc/interrupts increases with a somewhat
reasonable rate, so it looks like I'm getting interrupts.

Enabling the debug output of the unicam driver gives the following logs:

[ 2522.686656] unicam fe801000.csi: Starting stream on image device
[ 2522.687230] unicam fe801000.csi: Running with 2 data lanes, nodes 1
[ 2522.847079] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BE, sequence 0, lines done 0
[ 2522.847105] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2522.914545] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BC, sequence 0, lines done 819
[ 2522.914569] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2522.947477] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BE, sequence 0, lines done 1638
[ 2522.947499] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2522.964145] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BC, sequence 0, lines done 2457
[ 2522.964167] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2522.997077] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BE, sequence 0, lines done 3276
[ 2522.997100] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2523.013744] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BC, sequence 0, lines done 1059226
[ 2523.013764] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2523.064544] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BE, sequence 0, lines done 1059226
[ 2523.064566] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2523.081210] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BC, sequence 0, lines done 1059226
[ 2523.081230] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2523.130810] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BE, sequence 0, lines done 1059226
[ 2523.130833] unicam fe801000.csi: Scheduling dummy buffer for node 0
[ 2523.247880] unicam fe801000.csi: ISR: ISTA: 0x1, STA: 0x50BC, sequence 0, lines done 1059226
[ 2523.247902] unicam fe801000.csi: Scheduling dummy buffer for node 0

Do you know what could be going on? I tried to compare the upstream and
downstream unicam drivers, and the interrupt handler seems to be
slightly different, but I'm afraid I'm a bit out of my depth there.

Also, and while it seems unrelated (it happens when exiting the
application), I'm getting:

[  452.053788] ------------[ cut here ]------------
[  452.058502] WARNING: CPU: 3 PID: 734 at drivers/media/common/videobuf2/videobuf2-core.c:2222 __vb2_queue_cancel+0x260/0x2f0 [videobuf2_common]
[  452.071517] Modules linked in: vc4 hci_uart snd_soc_hdmi_codec btqca bcm2835_v4l2(C) snd_soc_core btrtl btbcm btsdio btintel brcmfmac_wcc bluetooth bcm2835_mmal_vchiq(C) ac97_bus snd_pcm_dmaengine videobuf2_vmalloc bcm2835_unicam snd_compress brcmfmac drm_dma_helper tc358743 v4l2_dv_timings videobuf2_v4l2 v4l2_fwnode videobuf2_dma_contig cpufreq_dt v4l2_async videodev brcmutil snd_bcm2835(C) drm_display_helper videobuf2_memops raspberrypi_cpufreq v3d snd_pcm videobuf2_common snd_timer pwrseq_core vfat fat snd soundcore mc cfg80211 bcm2711_thermal cec vchiq(C) broadcom bcm_phy_ptp bcm_phy_lib ledtrig_default_on gpu_sched i2c_mux_pinctrl leds_gpio genet pwm_bcm2835 iproc_rng200 i2c_mux mdio_bcm_unimac rfkill loop fuse nfnetlink reset_gpio gpio_raspberrypi_exp pwrseq_simple dwc2 crct10dif_ce raspberrypi_hwmon i2c_brcmstb clk_bcm2711_dvp udc_core sdhci_iproc bcm2835_wdt i2c_bcm2835 sdhci_pltfm bcm2835_dma sdhci phy_generic nvmem_rmem mmc_block rpmb_core mmc_core
[  452.157993] CPU: 3 UID: 0 PID: 734 Comm: dradis.bin Tainted: G         C         6.13.11 #252
[  452.166655] Tainted: [C]=CRAP
[  452.169663] Hardware name: raspberrypi Raspberry Pi 4 Model B Rev 1.1/Raspberry Pi 4 Model B Rev 1.1, BIOS 2024.10 10/01/2024
[  452.181140] pstate: 20400005 (nzCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  452.188207] pc : __vb2_queue_cancel+0x260/0x2f0 [videobuf2_common]
[  452.194503] lr : __vb2_queue_cancel+0x48/0x2f0 [videobuf2_common]
[  452.200707] sp : ffff800080e4bb30
[  452.204068] x29: ffff800080e4bb40 x28: 0000000000000009 x27: 0000000000000000
[  452.211321] x26: ffff40e6cda48b98 x25: 00000000400004d8 x24: 00000000000e001b
[  452.218573] x23: ffff40e6d064b280 x22: 0000000000000000 x21: ffff40e6d278c8b8
[  452.225824] x20: ffff40e6d278c630 x19: ffff40e6d278c738 x18: 00000000dbfbb796
[  452.233076] x17: 0000000000000000 x16: ffffc258986100e0 x15: 00000002d9a24a9e
[  452.240328] x14: 0000000000000000 x13: 00000002d9c4d651 x12: ffff40e6c08fa640
[  452.247578] x11: 0000000000000000 x10: 0000000000000000 x9 : 0000000100000000
[  452.254829] x8 : 0000000000000002 x7 : 0000000000008080 x6 : 00000000a6000004
[  452.262079] x5 : ffff800080e4b87a x4 : ffff40e6ff99a780 x3 : 0000000000000000
[  452.269329] x2 : 0000000000000001 x1 : 0000000000000000 x0 : 0000000000000000
[  452.276581] Call trace:
[  452.279061]  __vb2_queue_cancel+0x260/0x2f0 [videobuf2_common] (P)
[  452.285357]  vb2_core_queue_release+0x2c/0x88 [videobuf2_common]
[  452.291472]  vb2_fop_release+0x80/0xc0 [videobuf2_v4l2]
[  452.296791]  v4l2_release+0xa8/0x128 [videodev]
[  452.301474]  __fput+0xa0/0x318
[  452.304583]  ____fput+0x20/0x38
[  452.307775]  task_work_run+0xb8/0xe8
[  452.311410]  do_exit+0x220/0x9c0
[  452.314688]  do_group_exit+0x7c/0xb0
[  452.318317]  get_signal+0x76c/0x878
[  452.321860]  do_signal+0xa4/0x1d8
[  452.325227]  do_notify_resume+0x70/0x160
[  452.329209]  el0_svc+0x70/0xe0
[  452.332313]  el0t_64_sync_handler+0x78/0x108
[  452.336650]  el0t_64_sync+0x19c/0x1a0
[  452.340368] ---[ end trace 0000000000000000 ]---
[  452.345101] videobuf2_common: driver bug: stop_streaming operation is leaving buffer 1 in active state
[  452.354584] videobuf2_common: driver bug: stop_streaming operation is leaving buffer 2 in active state

Let me know if you need anything more,
Maxime

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 228 bytes --]