Skip to content

RPI4 bcm2835-codec: Unable to use v4l2 h264 encoder #3974

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
walmis opened this issue Nov 27, 2020 · 24 comments
Closed

RPI4 bcm2835-codec: Unable to use v4l2 h264 encoder #3974

walmis opened this issue Nov 27, 2020 · 24 comments
Labels
Close within 30 days Issue will be closed within 30 days unless requested to stay open

Comments

@walmis
Copy link

walmis commented Nov 27, 2020

I'm trying to launch this simple pipeline using gstreamer
gst-launch-1.0 videotestsrc ! v4l2h264enc ! fakesink but it always fails.

gstreamer version is 1.18.0

Decoder seems to work.

Kernel is:
Linux ubuntu 5.4.72-v8 #3 SMP PREEMPT Fri Nov 27 10:52:11 EET 2020 aarch64 aarch64 aarch64 GNU/Linux

[    0.000000] Linux version 5.4.72-v8 (walmis@DEG-010) (gcc version 9.2.0 (Buildroot 2020.02-00059-g5bdab8ef58-dirty)) #3 SMP PREEMPT Fri Nov 27 10:52:11 EET 2020
[    0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.1
[    0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB
[    0.072217] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-10-22 13:59, variant start
[    0.076228] raspberrypi-firmware soc:firmware: Firmware hash is 74e754ff8947c58d2773253f77f6f68a303188f8
gst-launch-1.0 videotestsrc ! v4l2h264enc ! fakesink

[  107.150020] bcm2835_mmal_vchiq: >>> sync message type:COMPONENT_CREATE(4) length:160
[  107.150732] bcm2835_mmal_vchiq: <<< reply message type:COMPONENT_CREATE(4) length:44
[  107.150781] bcm2835_mmal_vchiq: Component handle:0x40 in:1 out:1 clock:0
[  107.150800] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_GET(8) length:36
[  107.150884] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_GET(8) length:316
[  107.150923] bcm2835_mmal_vchiq: received port info
[  107.150935] bcm2835_mmal_vchiq: port handle:0x0 enabled:0
[  107.150947] bcm2835_mmal_vchiq: buffer minimum num:4 size:740 align:0
[  107.150957] bcm2835_mmal_vchiq: buffer recommended num:0 size:0 align:0
[  107.150967] bcm2835_mmal_vchiq: buffer current values num:4 size:740 align:0
[  107.150977] bcm2835_mmal_vchiq: elementary stream: type:1 encoding:0x0 variant:0x0
[  107.150987] bcm2835_mmal_vchiq: 		    bitrate:0 flags:0x0
[  107.150998] bcm2835_mmal_vchiq: port_info_get:result:0 component:0x40 port:0
[  107.151017] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_GET(8) length:36
[  107.151088] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_GET(8) length:316
[  107.151122] bcm2835_mmal_vchiq: received port info
[  107.151133] bcm2835_mmal_vchiq: port handle:0x1 enabled:0
[  107.151142] bcm2835_mmal_vchiq: buffer minimum num:1 size:15360 align:0
[  107.151151] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.151160] bcm2835_mmal_vchiq: buffer current values num:1 size:15360 align:0
[  107.151171] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x30323449 variant:0x0
[  107.151179] bcm2835_mmal_vchiq: 		    bitrate:0 flags:0x0
[  107.151189] bcm2835_mmal_vchiq: es video format: width:160 height:64 colourspace:0x0
[  107.151199] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,160,64
[  107.151209] bcm2835_mmal_vchiq: 		 : framerate 1966080/65536  aspect 0/0
[  107.151219] bcm2835_mmal_vchiq: port_info_get:result:0 component:0x40 port:1
[  107.151236] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_GET(8) length:36
[  107.151308] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_GET(8) length:316
[  107.151342] bcm2835_mmal_vchiq: received port info
[  107.151353] bcm2835_mmal_vchiq: port handle:0x2 enabled:0
[  107.151362] bcm2835_mmal_vchiq: buffer minimum num:1 size:65536 align:0
[  107.151371] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.151380] bcm2835_mmal_vchiq: buffer current values num:1 size:65536 align:0
[  107.151390] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x34363248 variant:0x0
[  107.151399] bcm2835_mmal_vchiq: 		    bitrate:0 flags:0x0
[  107.151408] bcm2835_mmal_vchiq: es video format: width:160 height:64 colourspace:0x0
[  107.151417] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,160,64
[  107.151427] bcm2835_mmal_vchiq: 		 : framerate 0/65536  aspect 0/0
[  107.151437] bcm2835_mmal_vchiq: port_info_get:result:0 component:0x40 port:2
[  107.151454] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.151539] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.151576] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:1 parameter:4
[  107.151591] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.151673] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.151709] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:4
[  107.151724] bcm2835_mmal_vchiq: setting port info port 000000005d0cc24e
[  107.151733] bcm2835_mmal_vchiq: port handle:0x1 enabled:0
[  107.151742] bcm2835_mmal_vchiq: buffer minimum num:1 size:15360 align:0
[  107.151751] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.151761] bcm2835_mmal_vchiq: buffer current values num:1 size:153600 align:0
[  107.151770] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x56595559 variant:0x0
[  107.151779] bcm2835_mmal_vchiq: 		    bitrate:0 flags:0x0
[  107.151789] bcm2835_mmal_vchiq: es video format: width:320 height:240 colourspace:0x0
[  107.151798] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,320,240
[  107.151808] bcm2835_mmal_vchiq: 		 : framerate 30/1  aspect 0/0
[  107.151819] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_SET(9) length:304
[  107.151941] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_SET(9) length:316
[  107.151978] bcm2835_mmal_vchiq: port_info_set:result:0 component:0x40 port:1
[  107.151992] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_GET(8) length:36
[  107.153641] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_GET(8) length:316
[  107.153686] bcm2835_mmal_vchiq: received port info
[  107.153698] bcm2835_mmal_vchiq: port handle:0x1 enabled:0
[  107.153708] bcm2835_mmal_vchiq: buffer minimum num:1 size:153600 align:0
[  107.153717] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.153726] bcm2835_mmal_vchiq: buffer current values num:1 size:153600 align:0
[  107.153735] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x56595559 variant:0x0
[  107.153744] bcm2835_mmal_vchiq: 		    bitrate:0 flags:0x0
[  107.153753] bcm2835_mmal_vchiq: es video format: width:320 height:240 colourspace:0x0
[  107.153765] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,320,240
[  107.153775] bcm2835_mmal_vchiq: 		 : framerate 1966080/65536  aspect 0/0
[  107.153785] bcm2835_mmal_vchiq: port_info_get:result:0 component:0x40 port:1
[  107.153798] bcm2835_mmal_vchiq: setting port info port 00000000448091de
[  107.153807] bcm2835_mmal_vchiq: port handle:0x2 enabled:0
[  107.153816] bcm2835_mmal_vchiq: buffer minimum num:1 size:65536 align:0
[  107.153825] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.153834] bcm2835_mmal_vchiq: buffer current values num:1 size:524288 align:0
[  107.153843] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x34363248 variant:0x0
[  107.153852] bcm2835_mmal_vchiq: 		    bitrate:10000000 flags:0x0
[  107.153862] bcm2835_mmal_vchiq: es video format: width:320 height:240 colourspace:0x0
[  107.153871] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,320,240
[  107.153880] bcm2835_mmal_vchiq: 		 : framerate 30/1  aspect 0/0
[  107.153895] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_SET(9) length:304
[  107.154012] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_SET(9) length:316
[  107.154052] bcm2835_mmal_vchiq: port_info_set:result:0 component:0x40 port:2
[  107.154067] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_GET(8) length:36
[  107.154142] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_GET(8) length:316
[  107.154177] bcm2835_mmal_vchiq: received port info
[  107.154187] bcm2835_mmal_vchiq: port handle:0x2 enabled:0
[  107.154196] bcm2835_mmal_vchiq: buffer minimum num:1 size:65536 align:0
[  107.154205] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.154214] bcm2835_mmal_vchiq: buffer current values num:1 size:524288 align:0
[  107.154223] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x34363248 variant:0x0
[  107.154232] bcm2835_mmal_vchiq: 		    bitrate:10000000 flags:0x0
[  107.154242] bcm2835_mmal_vchiq: es video format: width:320 height:240 colourspace:0x0
[  107.154254] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,320,240
[  107.154263] bcm2835_mmal_vchiq: 		 : framerate 1966080/65536  aspect 0/0
[  107.154273] bcm2835_mmal_vchiq: port_info_get:result:0 component:0x40 port:2
[  107.154290] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.154391] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.154431] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:131076
[  107.154447] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.154541] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.154577] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:131114
[  107.154593] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.154681] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.154717] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:131075
[  107.154735] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_GET(15) length:40
[  107.154816] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_GET(15) length:44
[  107.154851] bcm2835_mmal_vchiq: port_parameter_get:result:0 component:0x40 port:2 parameter:131074
[  107.154871] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:48
[  107.154963] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.154999] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:131074
[  107.155017] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_GET(15) length:40
[  107.155091] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_GET(15) length:44
[  107.155126] bcm2835_mmal_vchiq: port_parameter_get:result:0 component:0x40 port:2 parameter:131074
[  107.155141] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:48
[  107.155301] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.155340] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:131074
[  107.155355] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.155446] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.155481] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:2 parameter:131120
[  107.155496] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.155583] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.155619] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:0 parameter:131126
[  107.155634] bcm2835_mmal_vchiq: >>> sync message type:PORT_PARAMETER_SET(14) length:44
[  107.155723] bcm2835_mmal_vchiq: <<< reply message type:PORT_PARAMETER_SET(14) length:28
[  107.155758] bcm2835_mmal_vchiq: port_parameter_set:result:0 component:0x40 port:0 parameter:131078
[  107.171498] bcm2835_mmal_vchiq: >>> sync message type:COMPONENT_ENABLE(6) length:28
[  107.171615] bcm2835_mmal_vchiq: <<< reply message type:COMPONENT_ENABLE(6) length:28
[  107.171664] bcm2835_mmal_vchiq: >>> sync message type:PORT_ACTION(10) length:100
[  107.171802] bcm2835_mmal_vchiq: <<< reply message type:PORT_ACTION(10) length:28
[  107.171843] bcm2835_mmal_vchiq: port_action_port:result:0 component:0x40 port:2 action:ENABLE(1)
[  107.171859] bcm2835_mmal_vchiq: >>> sync message type:PORT_INFO_GET(8) length:36
[  107.171934] bcm2835_mmal_vchiq: <<< reply message type:PORT_INFO_GET(8) length:316
[  107.171969] bcm2835_mmal_vchiq: received port info
[  107.171981] bcm2835_mmal_vchiq: port handle:0x2 enabled:1
[  107.171991] bcm2835_mmal_vchiq: buffer minimum num:1 size:65536 align:0
[  107.172005] bcm2835_mmal_vchiq: buffer recommended num:1 size:0 align:0
[  107.172015] bcm2835_mmal_vchiq: buffer current values num:5 size:524288 align:0
[  107.172068] bcm2835_mmal_vchiq: elementary stream: type:3 encoding:0x34363248 variant:0x0
[  107.172078] bcm2835_mmal_vchiq: 		    bitrate:10000000 flags:0x0
[  107.172087] bcm2835_mmal_vchiq: es video format: width:320 height:240 colourspace:0x0
[  107.172097] bcm2835_mmal_vchiq: 		 : crop xywh 0,0,320,240
[  107.172107] bcm2835_mmal_vchiq: 		 : framerate 1966080/65536  aspect 0/0
[  107.172124] bcm2835_mmal_vchiq: port_info_get:result:0 component:0x40 port:2
[  107.172583] bcm2835_mmal_vchiq: >>> sync message type:PORT_ACTION(10) length:100
[  107.178386] bcm2835_mmal_vchiq: <<< reply message type:PORT_ACTION(10) length:28
[  107.178443] bcm2835_mmal_vchiq: port_action_port:result:-3 component:0x40 port:1 action:ENABLE(1)
[  107.178458] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling i/p port, ret -3
[  107.188070] ------------[ cut here ]------------
[  107.188104] WARNING: CPU: 0 PID: 782 at drivers/media/common/videobuf2/videobuf2-core.c:1487 vb2_start_streaming+0xdc/0x150 [videobuf2_common]
[  107.188109] Modules linked in: dm_mod brcmfmac brcmutil sha256_generic libsha256 ch341 usbserial vc4 raspberrypi_hwmon v3d cec gpu_sched cfg80211 drm_kms_helper bcm2835_v4l2(C) rfkill bcm2835_codec(C) snd_soc_core videobuf2_vmalloc bcm2835_isp(C) v4l2_mem2mem videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common snd_compress snd_pcm_dmaengine videodev snd_pcm snd_timer mc snd rpivid_mem syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio sch_fq_codel drm drm_panel_orientation_quirks ip_tables x_tables ipv6
[  107.188201] CPU: 0 PID: 782 Comm: videotestsrc0:s Tainted: G         C        5.4.72-v8 #3
[  107.188206] Hardware name: Raspberry Pi 4 Model B Rev 1.1 (DT)
[  107.188214] pstate: 60000005 (nZCv daif -PAN -UAO)
[  107.188231] pc : vb2_start_streaming+0xdc/0x150 [videobuf2_common]
[  107.188247] lr : vb2_start_streaming+0x6c/0x150 [videobuf2_common]
[  107.188252] sp : ffffffc0121f3a50
[  107.188258] x29: ffffffc0121f3a50 x28: 0000000040045612 
[  107.188267] x27: 0000000000000000 x26: 0000000000000000 
[  107.188276] x25: ffffffc0121f3c78 x24: ffffff8078231e18 
[  107.188284] x23: ffffff8076b59dc0 x22: ffffffc0121f3c78 
[  107.188292] x21: ffffff80782e6c40 x20: ffffff80782e6a68 
[  107.188299] x19: 00000000fffffffd x18: 0000000000000010 
[  107.188307] x17: 0000000000000000 x16: 0000000000000000 
[  107.188315] x15: ffffff8076b5a2f8 x14: 652064656c696146 
[  107.188323] x13: 203a676e696d6165 x12: 7274735f74726174 
[  107.188330] x11: 735f6365646f635f x10: 353338326d636220 
[  107.188338] x9 : 3a6365646f632d35 x8 : 74726f7020702f69 
[  107.188346] x7 : 00000000000002c5 x6 : 0000000000000000 
[  107.188353] x5 : 0000000000000000 x4 : ffffff807dd85160 
[  107.188361] x3 : ffffffc06ce7e000 x2 : cec484bbf102d000 
[  107.188368] x1 : 0000000000000000 x0 : 0000000000000001 
[  107.188377] Call trace:
[  107.188393]  vb2_start_streaming+0xdc/0x150 [videobuf2_common]
[  107.188408]  vb2_core_streamon+0x98/0x190 [videobuf2_common]
[  107.188422]  vb2_streamon+0x30/0x80 [videobuf2_v4l2]
[  107.188437]  v4l2_m2m_streamon+0x30/0x80 [v4l2_mem2mem]
[  107.188450]  v4l2_m2m_ioctl_streamon+0x30/0x40 [v4l2_mem2mem]
[  107.188492]  v4l_streamon+0x3c/0x50 [videodev]
[  107.188531]  __video_do_ioctl+0x18c/0x3f0 [videodev]
[  107.188570]  video_usercopy+0x214/0x740 [videodev]
[  107.188609]  video_ioctl2+0x3c/0x80 [videodev]
[  107.188647]  v4l2_ioctl+0x64/0x90 [videodev]
[  107.188666]  do_vfs_ioctl+0x6d8/0xaf0
[  107.188675]  ksys_ioctl+0x84/0xc0
[  107.188684]  __arm64_sys_ioctl+0x28/0xd0
[  107.188696]  el0_svc_common.constprop.0+0x78/0x1b0
[  107.188705]  el0_svc_handler+0x34/0xa0
[  107.188713]  el0_svc+0x8/0x204
[  107.188720] ---[ end trace dbd884fd31d510f4 ]---

I've tried current kernel and firmware pair and also from the next branch. RPI is setup to boot from network using, rootfs is ext4 over network block device (nbd).

Steps I've tried:

  • use start_x firmware - no change
  • try various kernels from stable releases with matching firmware - no change
  • Increasing gpu_mem to 256MB

config.txt

kernel=Image
arm_64bit=1
hdmi_force_hotplug=1
hdmi_group=1
hdmi_mode=16
disable_splash=1
avoid_warnings=2
initramfs initrd.cpio.gz followkernel
disable_overscan=1
gpu_mem=128

dtoverlay=miniuart-bt
dtparam=watchdog=on
dtparam=i2c_arm=on,i2c_arm_baudrate=50000
dtoverlay=vc4-fkms-v3d

Full logs:
dmesg.txt
kconfig.txt

Am I missing something? I've googled a lot, but I haven't found any solutions. Any pointers how to debug this?

@6by9
Copy link
Contributor

6by9 commented Nov 27, 2020

I don't have a 5.4 64bit kernel to hand. It works fine on my 32bit 5.10.0-rc5 kernel with GStreamer 1.14.4.

Can you check whether it is 5.4 being old, using a 64bit kernel, or GStreamer 1.18 that is the issue please?

@walmis
Copy link
Author

walmis commented Nov 27, 2020

I suspect it might be the 64bit kernel. I've tried with 64bit kernel with 32bit stock raspbian userspace - same fault.
One interesting finding though if I start with omxh264enc (which works) inside 32bit userspace and later try with again v4l2h264enc - it starts to work. So there might be some initialization problem inside the 64bit kernel.

@6by9
Copy link
Contributor

6by9 commented Nov 27, 2020

Thanks for testing.

I wonder if it is nothing having called the equivalent of bcm_host_init. I looked into that one a while back and couldn't come up with a sensible answer over what was needed where. There isn't a bcm_host_exit, therefore once something has called _init other things don't care.

@walmis
Copy link
Author

walmis commented Nov 27, 2020

I've also just tried the same with a raspberry 3B+, but on the B+ this fails more spectacularly. vchiq throws timed out waiting for sync completion and then
bcm2835_codec_start_streaming: Failed enabling i/p port, ret -16
sometimes there is a
vchiq received invalid message context 11
and ethernet stops working. I can kill gstreamer, but kernel seems to get stuck, eventually hung task detector kicks in.

@walmis
Copy link
Author

walmis commented Dec 1, 2020

Just tried a 32bit custom built kernel 42aa6ae
Attached config.txt

Same issue as before

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.0-rc5+ (walmis@DEG-010) (arm-linux-gnueabihf-gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #4 SMP Tue Dec 1 14:25:33 EET 2020
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB
root@testpi:~# gst-launch-1.0 videotestsrc ! v4l2h264enc ! fakesink
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
Redistribute latency...
[  514.407173] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling i/p port, ret -3
ERROR: from element /GstPipeline:pipeline0/v4l2h264enc:v4l2h264enc0: Failed to process frame.
Additional debug info:
../sys/v4l2/gstv4l2videoenc.c(825): gst_v4l2_video_enc_handle_frame (): /GstPipeline:pipeline0/v4l2h264enc:v4l2h264enc0:
Maybe be due to not enough memory or failing driver
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
ERROR: from element /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0: Internal data stream error.
Additional debug info:
../libs/gst/base/gstbasesrc.c(3127): gst_base_src_loop (): /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0:
streaming stopped, reason error (-5)
ERROR: pipeline doesn't want to preroll.
Freeing pipeline ...
[   45.750417] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling i/p port, ret -3
[   45.759913] ------------[ cut here ]------------
[   45.759937] WARNING: CPU: 3 PID: 437 at drivers/media/common/videobuf2/videobuf2-core.c:1537 vb2_start_streaming+0xc8/0x150 [videobuf2_common]
[   45.759942] Modules linked in: bcm2835_isp(C) bcm2835_codec(C) bcm2835_v4l2(C) videobuf2_dma_contig v4l2_mem2mem videobuf2_vmalloc videobuf2_memops bcm2835_mmal_vchiq(C) vc_sm_cma(C) videobuf2_v4l2 videobuf2_common brcmfmac brcmutil v3d gpu_sched raspberrypi_hwmon iproc_rng200 rng_core vchiq(C) vc4 cec
[   45.760032] CPU: 3 PID: 437 Comm: videotestsrc0:s Tainted: G         C        5.10.0-rc5+ #4
[   45.760036] Hardware name: BCM2711
[   45.760041] Backtrace: 
[   45.760057] [<c0a5b13c>] (dump_backtrace) from [<c0a5b45c>] (show_stack+0x20/0x24)
[   45.760064]  r7:00000000 r6:60030013 r5:00000000 r4:c13175a4
[   45.760073] [<c0a5b43c>] (show_stack) from [<c0a5e93c>] (dump_stack+0xa4/0xcc)
[   45.760082] [<c0a5e898>] (dump_stack) from [<c0220314>] (__warn+0xd4/0x100)
[   45.760087]  r7:00000000 r6:00000000 r5:00000009 r4:bf0428e4
[   45.760094] [<c0220240>] (__warn) from [<c0a5bc98>] (warn_slowpath_fmt+0x88/0xcc)
[   45.760101]  r9:c0770c30 r8:00000000 r7:00000009 r6:bf0428e4 r5:00000601 r4:bf046cdb
[   45.760115] [<c0a5bc14>] (warn_slowpath_fmt) from [<bf0428e4>] (vb2_start_streaming+0xc8/0x150 [videobuf2_common])
[   45.760121]  r8:c29933e0 r7:40045612 r6:c2f94678 r5:fffffffd r4:c2f94578
[   45.760140] [<bf04281c>] (vb2_start_streaming [videobuf2_common]) from [<bf042a98>] (vb2_core_streamon+0x12c/0x154 [videobuf2_common])
[   45.760146]  r7:40045612 r6:00000001 r5:c2f94400 r4:c2f94578
[   45.760164] [<bf04296c>] (vb2_core_streamon [videobuf2_common]) from [<bf0c4d14>] (vb2_streamon+0x4c/0x5c [videobuf2_v4l2])
[   45.760169]  r5:c2f94400 r4:0000000a
[   45.760186] [<bf0c4cc8>] (vb2_streamon [videobuf2_v4l2]) from [<bf195a7c>] (v4l2_m2m_streamon+0x30/0x48 [v4l2_mem2mem])
[   45.760201] [<bf195a4c>] (v4l2_m2m_streamon [v4l2_mem2mem]) from [<bf195ab4>] (v4l2_m2m_ioctl_streamon+0x20/0x24 [v4l2_mem2mem])
[   45.760206]  r5:00000000 r4:bf195a94
[   45.760220] [<bf195a94>] (v4l2_m2m_ioctl_streamon [v4l2_mem2mem]) from [<c0770c5c>] (v4l_streamon+0x2c/0x30)
[   45.760229] [<c0770c30>] (v4l_streamon) from [<c0775fb0>] (__video_do_ioctl+0x2d0/0x40c)
[   45.760234]  r5:00000000 r4:c29930a0
[   45.760240] [<c0775ce0>] (__video_do_ioctl) from [<c0776234>] (video_usercopy+0x148/0x460)
[   45.760247]  r10:00000000 r9:00000000 r8:c3d15e24 r7:00000000 r6:c0775ce0 r5:40045612
[   45.760251]  r4:00000000
[   45.760257] [<c07760ec>] (video_usercopy) from [<c0776568>] (video_ioctl2+0x1c/0x24)
[   45.760264]  r10:00000036 r9:c3d14000 r8:0000000e r7:c33e1848 r6:00bec2a0 r5:40045612
[   45.760268]  r4:c307f840
[   45.760275] [<c077654c>] (video_ioctl2) from [<c076eed8>] (v4l2_ioctl+0x50/0x64)
[   45.760285] [<c076ee88>] (v4l2_ioctl) from [<c03a568c>] (vfs_ioctl+0x30/0x44)
[   45.760290]  r7:c33e1848 r6:c307f840 r5:00bec2a0 r4:40045612
[   45.760298] [<c03a565c>] (vfs_ioctl) from [<c03a5ddc>] (sys_ioctl+0xcc/0x6f0)
[   45.760306] [<c03a5d10>] (sys_ioctl) from [<c0200060>] (ret_fast_syscall+0x0/0x4c)
[   45.760311] Exception stack(0xc3d15fa8 to 0xc3d15ff0)
[   45.760317] 5fa0:                   b5b0a2e0 00000000 0000000e 40045612 00bec2a0 b6c2e0d1
[   45.760323] 5fc0: b5b0a2e0 00000000 00bec298 00000036 b6edf86c 00ee0190 00ee0280 00ee0340
[   45.760328] 5fe0: b66090c8 b6429944 b65d8821 b6c2e0d8
[   45.760335]  r10:00000036 r9:c3d14000 r8:c0200264 r7:00000036 r6:00bec298 r5:00000000
[   45.760339]  r4:b5b0a2e0
[   45.760344] ---[ end trace dd6ec8cfe4585c75 ]---

@MMucka
Copy link

MMucka commented Feb 22, 2021

Hi, I have got similar problem with gstreamer and v4l2h264enc. I tried aarch64 and armv7l 5.10.16 with same results. But there seems to be difference in gstreamer versions:

  • GStreamer 1.14.4 (debian stable) - v4l2 is working without problem, can decode and encode video
  • GStreamer 1.18.3 (debian testing) - error with STREAMON 3 (No such process)
  • GStreamer 1.19.0 (GIT) - error with STREAMON 3 (No such process)

https://gitlab.freedesktop.org/gstreamer/gst-plugins-good/-/issues/849#note_811828

Do you have more information for this issue?

@walmis
Copy link
Author

walmis commented Feb 23, 2021

Yes it appears something is broken when using gstreamer >=1.18 . 1.16 also appears to work.

@MMucka
Copy link

MMucka commented Feb 23, 2021

It looks like this commit changed it (applied from version 17.1) https://gitlab.freedesktop.org/gstreamer/gst-plugins-good/-/commit/6ce195e9d1139d109b4301812221dc74f986909b

In the commit description, there is info about change for profiles and levels advertised by the kernel. Maybe the kernel is not advertising actual state right. I haven't tried it with older kernel 4.x

@6by9
Copy link
Contributor

6by9 commented Feb 23, 2021

Levels and profiles are supported by the encoder as per the V4L2 controls

pi@raspberrypi:~ $ v4l2-ctl --list-ctrls-menu -d 11

Codec Controls

             video_bitrate_mode 0x009909ce (menu)   : min=0 max=1 default=0 value=0 flags=update
				0: Variable Bitrate
				1: Constant Bitrate
                  video_bitrate 0x009909cf (int)    : min=25000 max=25000000 step=25000 default=10000000 value=10000000
           sequence_header_mode 0x009909d8 (menu)   : min=0 max=1 default=1 value=1
				0: Separate Buffer
				1: Joined With 1st Frame
         repeat_sequence_header 0x009909e2 (bool)   : default=0 value=0
                force_key_frame 0x009909e5 (button) : flags=write-only, execute-on-write
            h264_i_frame_period 0x00990a66 (int)    : min=0 max=2147483647 step=1 default=60 value=60
                     h264_level 0x00990a67 (menu)   : min=0 max=13 default=11 value=11
				0: 1
				1: 1b
				2: 1.1
				3: 1.2
				4: 1.3
				5: 2
				6: 2.1
				7: 2.2
				8: 3
				9: 3.1
				10: 3.2
				11: 4
				12: 4.1
				13: 4.2
                   h264_profile 0x00990a6b (menu)   : min=0 max=4 default=4 value=4
				0: Baseline
				1: Constrained Baseline
				2: Main
				4: High

The encoder does validate the resolution & framerate vs the specified level restrictions when the port is enabled (triggered by STREAMON).

If you run vcgencmd set_logging level=0xc0 before trying GStreamer, then sudo vcdbg log msg to dump the GPU log is likely to include an error
video_encode:RIL: failed to open encoder: X
where X is an internal error number. That may give me more information. (Sorry I don't have a system with GStreamer 1.18 installed at present to test for myself).

Likewise setting /sys/class/video4linux/video11/dev_debug to 0x2f before running GStreamer will dump out a lot of kernel side debug from the V4L2 framework (you may need to filter it by setting to other than 0x2f - it's a bitmask based on the V4L2_DEV_DEBUG_* defines https://elixir.bootlin.com/linux/latest/source/include/media/v4l2-ioctl.h#L596). That may reveal what and why the codec is being configured in a way it objects to.

@MMucka
Copy link

MMucka commented Feb 23, 2021

root@raspberrypi:/home/pi# vcgencmd set_logging level=0xc0
level=192 
root@raspberrypi:/home/pi# gst-launch-1.0 videotestsrc ! v4l2h264enc ! fakesink
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
Redistribute latency...
ERROR: from element /GstPipeline:pipeline0/v4l2h264enc:v4l2h264enc0: Failed to process frame.
Additional debug info:
../sys/v4l2/gstv4l2videoenc.c(825): gst_v4l2_video_enc_handle_frame (): /GstPipeline:pipeline0/v4l2h264enc:v4l2h264enc0:
Maybe be due to not enough memory or failing driver
ERROR: pipeline doesn't want to preroll.
ERROR: from element /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0: Internal data stream error.
Additional debug info:
../libs/gst/base/gstbasesrc.c(3127): gst_base_src_loop (): /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0:
streaming stopped, reason error (-5)
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
Freeing pipeline ...
root@raspberrypi:/home/pi# sudo vcdbg log msg > vcdbg.log 2>&1

056849.731: video_encode:5:RIL: open encoder
056850.376: video_encode:5:RIL: failed to open encoder: -1073807358
056850.387: video_encode:5:RIL: could not go to EXECUTING

@6by9
Copy link
Contributor

6by9 commented Feb 23, 2021

Annoyingly -1073807358 (actually 0xBFFF0002) is just VIDEO_FAIL. A touch too generic to be able to narrow down the cause.

@MMucka
Copy link

MMucka commented Feb 23, 2021

I'm looking in dmesg and here it crash

[ 1469.280151] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling i/p port, ret -3
[ 1469.280159] ------------[ cut here ]------------
[ 1469.280187] WARNING: CPU: 3 PID: 2226 at drivers/media/common/videobuf2/videobuf2-core.c:1548 vb2_start_streaming+0x108/0x178 [videobuf2_common]
[ 1469.280265] Modules linked in: sha256_generic cfg80211 rfkill 8021q garp stp llc v3d bcm2835_codec(C) gpu_sched bcm2835_v4l2(C) bcm2835_isp(C) videobuf2_vmalloc bcm2835_mmal_vchiq(C) v4l2_mem2mem videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common raspberrypi_hwmon videodev mc vc_sm_cma(C) snd_bcm2835(C) vc4 cec drm_kms_helper snd_soc_core snd_compress snd_pcm_dmaengine rpivid_mem snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks backlight ip_tables x_tables ipv6
[ 1469.280624] CPU: 3 PID: 2226 Comm: videotestsrc0:s Tainted: G        WC        5.10.16-v7l+ #1402
[ 1469.280628] Hardware name: BCM2711
[ 1469.280632] Backtrace: 
[ 1469.280652] [<c0b5ea00>] (dump_backtrace) from [<c0b5ed94>] (show_stack+0x20/0x24)
[ 1469.280658]  r7:ffffffff r6:00000000 r5:60000013 r4:c12e69fc
[ 1469.280665] [<c0b5ed74>] (show_stack) from [<c0b63124>] (dump_stack+0xcc/0xf8)
[ 1469.280673] [<c0b63058>] (dump_stack) from [<c0220b8c>] (__warn+0xfc/0x114)
[ 1469.280679]  r10:bf3458dc r9:00000009 r8:bf3c81ec r7:0000060c r6:00000009 r5:bf3c81ec
[ 1469.280684]  r4:bf3ccf90 r3:c1205094
[ 1469.280691] [<c0220a90>] (__warn) from [<c0b5f504>] (warn_slowpath_fmt+0x70/0xd8)
[ 1469.280695]  r7:0000060c r6:bf3ccf90 r5:c1205048 r4:00000000
[ 1469.280711] [<c0b5f498>] (warn_slowpath_fmt) from [<bf3c81ec>] (vb2_start_streaming+0x108/0x178 [videobuf2_common])
[ 1469.280717]  r9:bf2de068 r8:c2fc33e0 r7:00000001 r6:c5793d78 r5:c5793e78 r4:fffffffd
[ 1469.280738] [<bf3c80e4>] (vb2_start_streaming [videobuf2_common]) from [<bf3c88c8>] (vb2_core_streamon+0x90/0x180 [videobuf2_common])
[ 1469.280743]  r7:00000001 r6:c1205048 r5:c5793c00 r4:c5793d78
[ 1469.280762] [<bf3c8838>] (vb2_core_streamon [videobuf2_common]) from [<bf23b044>] (vb2_streamon+0x24/0x64 [videobuf2_v4l2])
[ 1469.280767]  r5:c5793c00 r4:0000000a
[ 1469.280784] [<bf23b020>] (vb2_streamon [videobuf2_v4l2]) from [<bf2830dc>] (v4l2_m2m_streamon+0x30/0x60 [v4l2_mem2mem])
[ 1469.280801] [<bf2830ac>] (v4l2_m2m_streamon [v4l2_mem2mem]) from [<bf28312c>] (v4l2_m2m_ioctl_streamon+0x20/0x24 [v4l2_mem2mem])
[ 1469.280807]  r7:00000001 r6:c1205048 r5:40045612 r4:bf28310c
[ 1469.280850] [<bf28310c>] (v4l2_m2m_ioctl_streamon [v4l2_mem2mem]) from [<bf2de094>] (v4l_streamon+0x2c/0x30 [videodev])
[ 1469.280913] [<bf2de068>] (v4l_streamon [videodev]) from [<bf2e3114>] (__video_do_ioctl+0x234/0x460 [videodev])
[ 1469.281012]  r5:40045612 r4:c2fc30a0
[ 1469.281072] [<bf2e2ee0>] (__video_do_ioctl [videodev]) from [<bf2e3b28>] (video_usercopy+0x128/0x5ac [videodev])
[ 1469.281156]  r10:c55d5e3c r9:0215c3a0 r8:00000000 r7:c5488300 r6:c1205048 r5:40045612
[ 1469.281160]  r4:40045612
[ 1469.281219] [<bf2e3a00>] (video_usercopy [videodev]) from [<bf2e3fcc>] (video_ioctl2+0x20/0x24 [videodev])
[ 1469.281225]  r10:0000000e r9:c55d4000 r8:00000000 r7:c5488300 r6:c5488301 r5:c1205048
[ 1469.281229]  r4:bf2e3fac
[ 1469.281288] [<bf2e3fac>] (video_ioctl2 [videodev]) from [<bf2dc1f4>] (v4l2_ioctl+0x4c/0x60 [videodev])
[ 1469.281396] [<bf2dc1a8>] (v4l2_ioctl [videodev]) from [<c045171c>] (sys_ioctl+0x1d4/0x8ec)
[ 1469.281478]  r5:c1205048 r4:40045612
[ 1469.281485] [<c0451548>] (sys_ioctl) from [<c0200040>] (ret_fast_syscall+0x0/0x28)
[ 1469.281490] Exception stack(0xc55d5fa8 to 0xc55d5ff0)
[ 1469.281495] 5fa0:                   b4e0c338 00000000 0000000e 40045612 0215c3a0 b6c1b190
[ 1469.281501] 5fc0: b4e0c338 00000000 b59d4000 00000036 b6f7b874 021660c0 02166270 021661b0
[ 1469.281506] 5fe0: b59d40c8 b57a4a34 b599852c b6c1b19c
[ 1469.281512]  r10:00000036 r9:c55d4000 r8:c0200204 r7:00000036 r6:b59d4000 r5:00000000
[ 1469.281516]  r4:b4e0c338
[ 1469.281522] ---[ end trace fbf3ef9bbce7d6b5 ]---
[ 1469.281531] video11: VIDIOC_STREAMON: error -3: type=vid-out-mplane
[ 1469.282115] video11: VIDIOC_ENCODER_CMD: cmd=1, flags=0x0
[ 1469.282438] video11: VIDIOC_REQBUFS: count=0, type=vid-out-mplane, memory=mmap
[ 1469.284964] video11: VIDIOC_STREAMOFF: type=vid-cap-mplane
[ 1469.285085] video11: VIDIOC_REQBUFS: count=0, type=vid-cap-mplane, memory=mmap
[ 1469.286390] videodev: v4l2_release: video11: release

@6by9
Copy link
Contributor

6by9 commented Feb 23, 2021

The

WARNING: CPU: 3 PID: 2226 at drivers/media/common/videobuf2/videobuf2-core.c:1548 vb2_start_streaming+0x108/0x178 [videobuf2_common]

is on the list of things to look at. As per the comment in the source

	/*
	 * If you see this warning, then the driver isn't cleaning up properly
	 * after a failed start_streaming(). See the start_streaming()
	 * documentation in videobuf2-core.h for more information how buffers
	 * should be returned to vb2 in start_streaming().
	 */

So it's a question of working out which buffers and why they haven't been returned. videobuf2 cleans up afterwards anyway, so it can be ignored.

@6by9
Copy link
Contributor

6by9 commented Feb 23, 2021

It's the list of transactions prior to the STREAMON that are of interest to determine how GStreamer is trying to configure the codec.

@FantasyGmm
Copy link

i am runing latest Ubuntu Server 20.04
this is Kenrel

Linux ubuntu 5.4.0-1028-raspi #31-Ubuntu SMP PREEMPT Wed Jan 20 11:30:45 UTC 2021 aarch64 aarch64 aarch64 GNU/Linux
When I use the jellyfin-ffmpeg h264_v4l2m2m,its carsh,dmesg show the same info
[ 2920.490473] cma: cma_alloc: alloc failed, req-size: 1350 pages, ret: -12
[ 2920.497359] bcm2835-codec bcm2835-codec: dma_alloc_coherent of size 5529600 failed
[ 2920.506693] cma: cma_alloc: alloc failed, req-size: 192 pages, ret: -12
[ 2920.513902] cma: cma_alloc: alloc failed, req-size: 192 pages, ret: -12
[ 2920.533307] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling i/p port, ret -3
[ 2920.543048] ------------[ cut here ]------------
[ 2920.543075] WARNING: CPU: 3 PID: 5292 at drivers/media/common/videobuf2/videobuf2-core.c:1487 vb2_start_streaming+0xe4/0x158 [videobuf2_common]
[ 2920.543078] Modules linked in: md4 xt_nat xt_tcpudp veth xt_conntrack xt_MASQUERADE nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo xt_addrtype iptable_filter iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 bpfilter br_netfilter bridge stp llc aufs nls_utf8 cifs libdes libarc4 fscache overlay dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua btsdio bluetooth ecdh_generic ecc brcmfmac brcmutil cfg80211 bcm2835_v4l2(CE) bcm2835_codec(CE) bcm2835_isp(CE) v4l2_mem2mem bcm2835_mmal_vchiq(CE) snd_bcm2835(CE) videobuf2_vmalloc videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 snd_pcm videobuf2_common raspberrypi_hwmon snd_timer videodev snd mc vc_sm_cma(CE) rpivid_mem uio_pdrv_genirq uio tcp_bbr sch_fq drm ip_tables x_tables autofs4 btrfs zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor xor_neon raid6_pq libcrc32c raid1 raid0 multipath linear spidev crct10dif_ce phy_generic uas usb_storage aes_neon_bs aes_neon_blk crypto_simd cryptd
[ 2920.543154] CPU: 3 PID: 5292 Comm: ffmpeg Tainted: G WC E 5.4.0-1028-raspi #31-Ubuntu
[ 2920.543157] Hardware name: Raspberry Pi 4 Model B Rev 1.2 (DT)
[ 2920.543160] pstate: 60400005 (nZCv daif +PAN -UAO)
[ 2920.543167] pc : vb2_start_streaming+0xe4/0x158 [videobuf2_common]
[ 2920.543173] lr : vb2_start_streaming+0x74/0x158 [videobuf2_common]
[ 2920.543175] sp : ffff800011013a50
[ 2920.543177] x29: ffff800011013a50 x28: 0000000040045612
[ 2920.543181] x27: 0000000000000000 x26: 0000000000000000
[ 2920.543185] x25: ffff800011013c88 x24: ffff0000f5237e58
[ 2920.543188] x23: ffff0000f6e99dc0 x22: ffff800011013c88
[ 2920.543191] x21: ffff0000eb9a7c40 x20: ffff0000eb9a7a68
[ 2920.543194] x19: 00000000fffffffd x18: 0000000000000010
[ 2920.543197] x17: 0000000000000000 x16: ffffa08b10b6abdc
[ 2920.543200] x15: ffff0000f6e9a2f0 x14: 0720072007200720
[ 2920.543203] x13: 0720072007200720 x12: 0720072007200720
[ 2920.543206] x11: 0720072007200720 x10: 0720072007200720
[ 2920.543209] x9 : 0720072007200720 x8 : ffffa08b110da9a8
[ 2920.543212] x7 : 0000000000000000 x6 : 0000000000000000
[ 2920.543215] x5 : 0000000000000000 x4 : 0000000000000000
[ 2920.543218] x3 : 0000000000000000 x2 : 0000000000000000
[ 2920.543221] x1 : 0000000000000000 x0 : 0000000000000001
[ 2920.543225] Call trace:
[ 2920.543231] vb2_start_streaming+0xe4/0x158 [videobuf2_common]
[ 2920.543237] vb2_core_streamon+0x9c/0x188 [videobuf2_common]
[ 2920.543244] vb2_streamon+0x34/0x78 [videobuf2_v4l2]
[ 2920.543252] v4l2_m2m_streamon+0x34/0x80 [v4l2_mem2mem]
[ 2920.543257] v4l2_m2m_ioctl_streamon+0x34/0x40 [v4l2_mem2mem]
[ 2920.543283] v4l_streamon+0x40/0x50 [videodev]
[ 2920.543299] __video_do_ioctl+0x18c/0x3f0 [videodev]
[ 2920.543314] video_usercopy+0x230/0x5a8 [videodev]
[ 2920.543329] video_ioctl2+0x40/0xe8 [videodev]
[ 2920.543345] v4l2_ioctl+0x68/0x90 [videodev]
[ 2920.543355] do_vfs_ioctl+0x96c/0xb68
[ 2920.543358] ksys_ioctl+0x88/0xb8
[ 2920.543361] __arm64_sys_ioctl+0x2c/0xa0
[ 2920.543366] el0_svc_common.constprop.0+0x84/0x218
[ 2920.543368] el0_svc_handler+0x38/0xa0
[ 2920.543372] el0_svc+0x10/0x2d4
[ 2920.543375] ---[ end trace d9804d25cae25484 ]---

@MMucka
Copy link

MMucka commented Feb 24, 2021

It's the list of transactions prior to the STREAMON that are of interest to determine how GStreamer is trying to configure the codec.

There are some errors, mainly -22 and -25

[ 6202.290768] video11: VIDIOC_G_PARM: error -22: type=vid-cap-mplane, capability=0x0, capturemode=0x0, timeperframe=0/0, extendedmode=0, readbuffers=0
[ 6202.290810] video11: VIDIOC_EXPBUF: error -22: fd=0, type=vid-cap-mplane, index=4294967295, plane=4294967295, flags=0x00080002
[ 6202.290960] video11: VIDIOC_G_CTRL: error -22: name=Min Number of Capture Buffers, id=0x980927, value=0
[ 6283.626469] video11: VIDIOC_ENUMINPUT: error -25: index=0, name=, type=0, audioset=0x0, tuner=0, std=0x00000000, status=0x0, capabilities=0x0
[ 6283.626502] video11: VIDIOC_ENUMSTD: error -25: index=0, id=0x0, name=, fps=0/0, framelines=0
[ 6283.629029] video11: VIDIOC_ENUM_FRAMEINTERVALS: error -25: index=0, pixelformat=YUYV, wxh=1920x1920, type=0

@6by9
Copy link
Contributor

6by9 commented Mar 5, 2021

Gstreamer parameters issue, not kernel driver.

gst-launch-1.0 videotestsrc ! v4l2h264enc ! fakesink
sets the encoder to level 1.0, which is max 128×[email protected] or 176×[email protected], and max bitrate of 64kbit/s.
The encoder rejects that when the source is 320x240@30 and 10Mbit/s as it exceeds all those limits.

Set the level more sensibly, eg
gst-launch-1.0 videotestsrc ! v4l2h264enc ! 'video/x-h264,level=(string)3' ! fakesink
and it works fine.

Level 3 is required for 10Mbit/s. Drop the bitrate via
gst-launch-1.0 -vvv videotestsrc ! v4l2h264enc extra-controls="foo,video_bitrate=40000" ! 'video/x-h264,level=(string)2' ! fakesink
if you want a lower level.

@MMucka
Copy link

MMucka commented Mar 5, 2021

Thank you very much!
After setting suitable level from here https://en.wikipedia.org/wiki/Advanced_Video_Coding#Levels, the encoder is working.

For recording v4l2 camera 1280x720, this pipeline is working for me (if somebody would need to insiper).
gst-launch-1.0 v4l2src device=/dev/video0 ! 'video/x-raw,framerate=30/1,format=UYVY' ! v4l2h264enc ! 'video/x-h264,level=(string)4' ! filesink location = test_video.h264

@6by9
Copy link
Contributor

6by9 commented Mar 8, 2021

@walmis As the original reporter are you happy to close?

@6by9 6by9 added the Close within 30 days Issue will be closed within 30 days unless requested to stay open label Mar 8, 2021
@walmis
Copy link
Author

walmis commented Mar 8, 2021

Yes, thank you for solving this. Hopefully this information will get documented somewhere.

@mqudsi
Copy link

mqudsi commented Mar 25, 2021

It seems to not work at higher resolutions and framerates (that are supported by raspivid)?

pi@raspberrypi:~$ gst-launch-1.0 --gst-debug="*:2" v4l2src device=/dev/video0  ! 'video/x-raw,framerate=40/1,format=YUY2'
! v5l2h264enc ! 'video/x-h264,level=(string)4,profile=(string)high' ! progressreport ! testsink
Setting pipeline to PAUSED ...
0:00:00.186467652  3976  0x19aeae0 WARN                    v4l2
gstv4l2object.c:4186:gst_v4l2_object_probe_caps:<v4l2h264enc0:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP:
Invalid argument                                         Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
Redistribute latency...
0:00:01.177950225  3976  0x198c2f0 WARN          v4l2bufferpool
gstv4l2bufferpool.c:790:gst_v4l2_buffer_pool_start:<v4l2h264enc0:pool:src> Uncertain or not enough buffers, enabling copy
threshold                                                 0:00:01.208402136  3976  0x198c2f0 ERROR         v4l2bufferpool
gstv4l2bufferpool.c:677:gst_v4l2_buffer_pool_streamon:<v4l2h264enc0:pool:sink> error with STREAMON 3 (No such process)
0:00:01.208505005  3976  0x198c2f0 ERROR         v4l2bufferpool
gstv4l2bufferpool.c:1985:gst_v4l2_buffer_pool_process:<v4l2h264enc0:pool:sink> failed to start streaming
0:00:01.208589114  3976  0x198c2f0 WARN            v4l2videoenc
gstv4l2videoenc.c:803:gst_v4l2_video_enc_handle_frame:<v4l2h264enc0> error: Failed to process frame.
0:00:01.208652595  3976  0x198c2f0 WARN            v4l2videoenc
gstv4l2videoenc.c:803:gst_v4l2_video_enc_handle_frame:<v4l2h264enc0> error: Maybe be due to not enough memory or failing
driver                                                     ERROR: from element
/GstPipeline:pipeline0/v4l2h264enc:v4l2h264enc0: Failed to process frame.                             Additional debug
info:
gstv4l2videoenc.c(803): gst_v4l2_video_enc_handle_frame (): /GstPipeline:pipeline0/v4l2h264enc:v4l2h264enc0:
Maybe be due to not enough memory or failing driver
0:00:01.209046719  3976  0x198c2f0 WARN                 basesrc gstbasesrc.c:3055:gst_base_src_loop:<v4l2src0> error:
Internal data stream error.
Execution ended after 0:00:01.017805747
Setting pipeline to PAUSED ...
0:00:01.209259975  3976  0x198c2f0 WARN                 basesrc gstbasesrc.c:3055:gst_base_src_loop:<v4l2src0> error:
streaming stopped, reason error (-5)
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline ... 

@6by9
Copy link
Contributor

6by9 commented Mar 25, 2021

You've edited your comment. The original listed 1640x1232 @ 40fps.
When you run raspivid with those parameters you'll see it log a message
Too many macroblocks/s: Increasing H264 Level to 4.2

Level 4.2 has a limit of 522240 macroblocks/s, whilst level 4 is 245760. https://en.wikipedia.org/wiki/H.264/MPEG-4_AVC#Levels
1640x1232@40 is 317240 macroblocks/s, and therefore the encoder correctly throws it out as invalid.

Then again the V4L2 codec doesn't allow for levels above 4 at present. I'll sort a PR later (it's only missing case statements).

@mqudsi
Copy link

mqudsi commented Mar 25, 2021

Yeah, I had copy-and-pasted the wrong run, but it was always 1640x1232 (explicitly or implied). Glad to know it doesn't involve more than what you described.

leigh-johnson added a commit to bitsy-ai/printnanny-gst-plugin-rs that referenced this issue Oct 25, 2022
Software-based encoders seem to infer profile/level caps, but v4l2-based
encoder requires these to be set for bitrate

ref: raspberrypi/linux#3974 (comment)
leigh-johnson added a commit to bitsy-ai/printnanny-gst-plugin-rs that referenced this issue Oct 25, 2022
Software-based encoders seem to infer profile/level caps, but v4l2-based
encoder requires these to be set for bitrate

ref: raspberrypi/linux#3974 (comment)
@barneyman
Copy link

just in case anyone else ends up in this rabbit-hole ... being explicit about level and profile gets some results - i'm currently encoding 1080p reasonably well with a capsfilter of video/x-h264,level=(string)4,profile=main

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Close within 30 days Issue will be closed within 30 days unless requested to stay open
Projects
None yet
Development

No branches or pull requests

6 participants