raspberrypi / firmware

This repository contains pre-compiled binaries of the current Raspberry Pi kernel and modules, userspace libraries, and bootloader/GPU firmware.
5.18k stars 1.68k forks source link

MMAL: mmal_vc_port_info_set: failed to set port info (2:0): EINVAL on H.264 input #1762

Open dr-m opened 1 year ago

dr-m commented 1 year ago

Is this the right place for my bug report? I believe yes.

Describe the bug zillevdr/vdr-plugin-softhddevice-drm compiled with MMAL=1 crashes on interlaced H.264 input (DVB-T2 channel). MPEG-2 DVB-T streams work fine.

This seems to be a regression somewhere between 518ee7c871aaa9aaa88116953d57e73787ee6e43 and 4877a7d918be6fab22ce5d345feefd9c43200a90.

To reproduce Compile or sudo apt install vdr and compile zillevdr/vdr-plugin-softhddevice-drm for it. Try to play back a H.264 recording. Expected behaviour The interlaced H.264 video recording should play back with GPU acceleration.

Actual behaviour You may see the on-screen display (OSD) to indicate that the channel was changed or the playback started. Before any image is displayed, the process will crash with SIGSEGV as noted in zillevdr/vdr-plugin-softhddevice-drm#11.

System This is with 518ee7c871aaa9aaa88116953d57e73787ee6e43 and not an affected version like 4877a7d918be6fab22ce5d345feefd9c43200a90 or 74c4307951701f93bd94b4fd37e6adc44910d6e0:

System Information
------------------

Raspberry Pi 2 Model B Rev 1.1
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2022-09-22
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, a17501d7c91a584085cd794ab9c007c9d1b9b435, stage2

Linux raspberrypi 5.10.17-v7+ #1414 SMP Fri Apr 30 13:18:35 BST 2021 armv7l GNU/Linux
Revision    : a01041
Serial      : 00000000d2444097
Model       : Raspberry Pi 2 Model B Rev 1.1
Throttled flag  : throttled=0x0
Camera          : supported=0 detected=0

Videocore information
---------------------

Apr 30 2021 13:47:07 
Copyright (c) 2012 Broadcom
version d7f29d96450abfc77cd6cf011af1faf1e03e5e56 (clean) (release) (start)

alloc failures:     0
compactions:        0
legacy block fails: 0

Filesystem information
----------------------
Filesystem     1K-blocks     Used Available Use% Mounted on
/dev/root       29441852 10632328  17585364  38% /
devtmpfs          348568        0    348568   0% /dev
tmpfs             381848        0    381848   0% /dev/shm
tmpfs             381848     9928    371920   3% /run
tmpfs               5120        4      5116   1% /run/lock
tmpfs             381848        0    381848   0% /sys/fs/cgroup
/dev/mmcblk0p1    258095    49126    208969  20% /boot
tmpfs              76368        0     76368   0% /run/user/1000

Filename                Type        Size        Used        Priority
/var/swap                               file        102396      0       -2

Package version information
---------------------------
raspberrypi-ui-mods:
  Installed: (none)
raspberrypi-sys-mods:
  Installed: 20211005
openbox:
  Installed: (none)
lxpanel:
  Installed: (none)
pcmanfm:
  Installed: (none)
rpd-plym-splash:
  Installed: (none)

Networking Information
----------------------

eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 1394  bytes 80461 (78.5 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 1266  bytes 242844 (237.1 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet x.x.x.x  netmask x.x.x.x
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

USB Information
---------------

/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/5p, 480M
        |__ Port 1: Dev 3, If 0, Class=Vendor Specific Class, Driver=smsc95xx, 480M

config.txt
----------

aphy_params_current=819
arm_freq=900
arm_freq_min=600
audio_pwm_mode=514
config_hdmi_boost=5
disable_auto_turbo=1
disable_commandline_tags=2
disable_l2cache=1
display_hdmi_rotate=-1
display_lcd_rotate=-1
dphy_params_current=547
dvfs=2
enable_tvout=1
enable_uart=1
force_eeprom_read=1
force_pwm_open=1
framebuffer_ignore_alpha=1
framebuffer_swap=1
init_uart_clock=0x2dc6c00
lcd_framerate=60
max_framebuffers=-1
over_voltage_avs=0x1b774
pause_burst_frames=1
program_serial_random=1
sdram_freq=450
total_mem=1024
hdmi_force_cec_address:0=65535
hdmi_force_cec_address:1=65535
hdmi_pixel_freq_limit:0=0x9a7ec80
device_tree=-
overlay_prefix=overlays/
hdmi_cvt:0=
hdmi_cvt:1=
hdmi_edid_filename:0=
hdmi_edid_filename:1=
hdmi_timings:0=
hdmi_timings:1=

cmdline.txt
-----------
coherent_pool=1M snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=tty1 root=PARTUUID=061fad79-02 rootfstype=ext4 fsck.repair=yes rootwait

raspi-gpio settings
-------------------

BANK0 (GPIO 0 to 27):
GPIO 0: level=1 fsel=0 func=INPUT
GPIO 1: level=1 fsel=0 func=INPUT
GPIO 2: level=1 fsel=0 func=INPUT
GPIO 3: level=1 fsel=0 func=INPUT
GPIO 4: level=1 fsel=0 func=INPUT
GPIO 5: level=1 fsel=0 func=INPUT
GPIO 6: level=1 fsel=0 func=INPUT
GPIO 7: level=1 fsel=1 func=OUTPUT
GPIO 8: level=1 fsel=1 func=OUTPUT
GPIO 9: level=0 fsel=4 alt=0 func=SPI0_MISO
GPIO 10: level=0 fsel=4 alt=0 func=SPI0_MOSI
GPIO 11: level=0 fsel=4 alt=0 func=SPI0_SCLK
GPIO 12: level=0 fsel=0 func=INPUT
GPIO 13: level=0 fsel=0 func=INPUT
GPIO 14: level=1 fsel=4 alt=0 func=TXD0
GPIO 15: level=1 fsel=4 alt=0 func=RXD0
GPIO 16: level=0 fsel=0 func=INPUT
GPIO 17: level=0 fsel=0 func=INPUT
GPIO 18: level=1 fsel=0 func=INPUT
GPIO 19: level=0 fsel=0 func=INPUT
GPIO 20: level=0 fsel=0 func=INPUT
GPIO 21: level=0 fsel=0 func=INPUT
GPIO 22: level=0 fsel=0 func=INPUT
GPIO 23: level=0 fsel=0 func=INPUT
GPIO 24: level=0 fsel=0 func=INPUT
GPIO 25: level=0 fsel=0 func=INPUT
GPIO 26: level=0 fsel=0 func=INPUT
GPIO 27: level=0 fsel=0 func=INPUT
BANK1 (GPIO 28 to 45):
GPIO 28: level=1 fsel=0 func=INPUT
GPIO 29: level=1 fsel=0 func=INPUT
GPIO 30: level=0 fsel=0 func=INPUT
GPIO 31: level=1 fsel=1 func=OUTPUT
GPIO 32: level=0 fsel=1 func=OUTPUT
GPIO 33: level=0 fsel=0 func=INPUT
GPIO 34: level=1 fsel=0 func=INPUT
GPIO 35: level=1 fsel=0 func=INPUT
GPIO 36: level=1 fsel=0 func=INPUT
GPIO 37: level=0 fsel=0 func=INPUT
GPIO 38: level=1 fsel=1 func=OUTPUT
GPIO 39: level=0 fsel=0 func=INPUT
GPIO 40: level=0 fsel=4 alt=0 func=PWM0
GPIO 41: level=0 fsel=1 func=OUTPUT
GPIO 42: level=1 fsel=1 func=OUTPUT
GPIO 43: level=1 fsel=0 func=INPUT
GPIO 44: level=0 fsel=4 alt=0 func=GPCLK1
GPIO 45: level=0 fsel=4 alt=0 func=PWM1
BANK2 (GPIO 46 to 53):
GPIO 46: level=0 fsel=0 func=INPUT
GPIO 47: level=0 fsel=1 func=OUTPUT
GPIO 48: level=0 fsel=4 alt=0 func=SD0_CLK
GPIO 49: level=1 fsel=4 alt=0 func=SD0_CMD
GPIO 50: level=1 fsel=4 alt=0 func=SD0_DAT0
GPIO 51: level=1 fsel=4 alt=0 func=SD0_DAT1
GPIO 52: level=1 fsel=4 alt=0 func=SD0_DAT2
GPIO 53: level=1 fsel=4 alt=0 func=SD0_DAT3

vcdbg log messages
------------------

001464.121: brfs: File read: /mfs/sd/config.txt
001465.186: brfs: File read: 1856 bytes
001546.051: brfs: File read: /mfs/sd/config.txt
001547.028: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
001566.654: brfs: File read: 1856 bytes
001571.803: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
001571.829: gpioman: gpioman_get_pin_num: pin BT_ON not defined
001571.850: gpioman: gpioman_get_pin_num: pin WL_ON not defined
001746.528: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
001747.838: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
001747.893: *** Restart logging
001780.674: HDMI0: hdmi_pixel_encoding: 162000000
001797.384: dtb_file 'bcm2709-rpi-2-b.dtb'
001801.696: brfs: File read: /mfs/sd/bcm2709-rpi-2-b.dtb
001801.718: Loading 'bcm2709-rpi-2-b.dtb' to 0x100 size 0x6879
001814.393: brfs: File read: 26745 bytes
001828.867: brfs: File read: /mfs/sd/overlays/overlay_map.dtb
001903.442: brfs: File read: 1523 bytes
001906.894: brfs: File read: /mfs/sd/config.txt
001908.082: brfs: File read: 1856 bytes
001918.718: brfs: File read: /mfs/sd/overlays/rpi-tv.dtbo
001926.170: Loaded overlay 'rpi-tv'
001926.180: Loaded HAT overlay
001940.968: brfs: File read: 567 bytes
001946.731: brfs: File read: /mfs/sd/overlays/gpio-ir.dtbo
001952.834: Loaded overlay 'gpio-ir'
001952.851: dtparam: gpio_pin=18
001954.371: dtparam: audio=on
001993.270: brfs: File read: 1259 bytes
001995.141: brfs: File read: /mfs/sd/cmdline.txt
001995.180: Read command line from file 'cmdline.txt':
001995.195: 'console=tty1 root=PARTUUID=061fad79-02 rootfstype=ext4 fsck.repair=yes rootwait'
003782.510: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
003830.173: gpioman: gpioman_get_pin_num: pin WL_ON not defined
003846.942: brfs: File read: 80 bytes
004284.282: brfs: File read: /mfs/sd/kernel7.img
004284.305: Loading 'kernel7.img' to 0x8000 size 0x6072f8
004284.336: Device tree loaded to 0x2eff9100 (size 0x6eae)
004290.939: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
008319.656: vchiq_core: vchiq_init_state: slot_zero = 0xead80000, is_master = 1
008324.291: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
008330.328: TV service:host side not connected, dropping notification 0x00000002, 0x00000001, 0x00000010

dmesg log
---------

[    0.000000] Booting Linux on physical CPU 0xf00
[    0.000000] Linux version 5.10.17-v7+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1414 SMP Fri Apr 30 13:18:35 BST 2021
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 2 Model B Rev 1.1
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x2ac00000, size 64 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x000000002fffffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000002fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000002fffffff]
[    0.000000] On node 0 totalpages: 196608
[    0.000000]   DMA zone: 1728 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000] percpu: Embedded 20 pages/cpu s50700 r8192 d23028 u81920
[    0.000000] pcpu-alloc: s50700 r8192 d23028 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 194880
[    0.000000] Kernel command line: coherent_pool=1M snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=tty1 root=PARTUUID=061fad79-02 rootfstype=ext4 fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 697140K/786432K available (9216K kernel code, 1311K rwdata, 2940K rodata, 1024K init, 860K bss, 23756K reserved, 65536K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 31910 entries in 63 pages
[    0.000000] ftrace: allocated 63 pages with 6 groups
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000]  Rude variant of Tasks RCU enabled.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] random: get_random_bytes called from start_kernel+0x3ac/0x580 with crng_init=0
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000010] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000034] Switching to timer-based delay loop, resolution 52ns
[    0.000386] Console: colour dummy device 80x30
[    0.001320] printk: console [tty1] enabled
[    0.001411] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001486] pid_max: default: 32768 minimum: 301
[    0.001782] LSM: Security Framework initializing
[    0.002107] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002177] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.004294] Disabling memory control group subsystem
[    0.004511] CPU: Testing write buffer coherency: ok
[    0.005252] CPU0: update cpu_capacity 1024
[    0.005304] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
[    0.007089] Setting up static identity map for 0x100000 - 0x10003c
[    0.007405] rcu: Hierarchical SRCU implementation.
[    0.008725] smp: Bringing up secondary CPUs ...
[    0.010534] CPU1: update cpu_capacity 1024
[    0.010547] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
[    0.012403] CPU2: update cpu_capacity 1024
[    0.012418] CPU2: thread -1, cpu 2, socket 15, mpidr 80000f02
[    0.014195] CPU3: update cpu_capacity 1024
[    0.014209] CPU3: thread -1, cpu 3, socket 15, mpidr 80000f03
[    0.014444] smp: Brought up 1 node, 4 CPUs
[    0.014630] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.014668] CPU: All CPU(s) started in HYP mode.
[    0.014702] CPU: Virtualization extensions available.
[    0.016023] devtmpfs: initialized
[    0.037292] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.037726] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.037807] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.042054] pinctrl core: initialized pinctrl subsystem
[    0.043760] NET: Registered protocol family 16
[    0.048795] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.056273] audit: initializing netlink subsys (disabled)
[    0.057000] audit: type=2000 audit(0.050:1): state=initialized audit_enabled=0 res=1
[    0.057940] thermal_sys: Registered thermal governor 'step_wise'
[    0.059029] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.059113] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.059482] Serial: AMBA PL011 UART driver
[    0.082307] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.094411] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-04-30T13:47:07, variant start
[    0.104434] raspberrypi-firmware soc:firmware: Firmware hash is d7f29d96450abfc77cd6cf011af1faf1e03e5e56
[    0.165529] bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1
[    0.168512] SCSI subsystem initialized
[    0.168986] usbcore: registered new interface driver usbfs
[    0.169110] usbcore: registered new interface driver hub
[    0.169237] usbcore: registered new device driver usb
[    0.171744] clocksource: Switched to clocksource arch_sys_counter
[    1.919529] VFS: Disk quotas dquot_6.6.0
[    1.919739] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.920057] FS-Cache: Loaded
[    1.920480] CacheFiles: Loaded
[    1.936594] NET: Registered protocol family 2
[    1.938064] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.938339] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    1.938512] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    1.938736] TCP: Hash tables configured (established 8192 bind 8192)
[    1.939009] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.939120] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.939893] NET: Registered protocol family 1
[    1.941067] RPC: Registered named UNIX socket transport module.
[    1.941118] RPC: Registered udp transport module.
[    1.941155] RPC: Registered tcp transport module.
[    1.941191] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.943204] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    1.948425] Initialise system trusted keyrings
[    1.948916] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    1.961101] zbud: loaded
[    1.964067] FS-Cache: Netfs 'nfs' registered for caching
[    1.965337] NFS: Registering the id_resolver key type
[    1.965454] Key type id_resolver registered
[    1.965493] Key type id_legacy registered
[    1.965742] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.967406] Key type asymmetric registered
[    1.967461] Asymmetric key parser 'x509' registered
[    1.967562] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    1.967614] io scheduler mq-deadline registered
[    1.967652] io scheduler kyber registered
[    1.971089] bcm2708_fb soc:fb: FB found 1 display(s)
[    2.043733] Console: switching to colour frame buffer device 228x61
[    2.076627] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 1824x984
[    2.084148] bcm2835-rng 3f104000.rng: hwrng registered
[    2.084899] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    2.086434] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    2.105829] brd: module loaded
[    2.123989] loop: module loaded
[    2.126428] Loading iSCSI transport class v2.0-870.
[    2.129053] libphy: Fixed MDIO Bus: probed
[    2.129657] usbcore: registered new interface driver lan78xx
[    2.129947] usbcore: registered new interface driver smsc95xx
[    2.130180] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.858907] Core Release: 2.80a
[    2.859106] Setting default values for core params
[    2.859323] Finished setting default values for core params
[    3.059986] Using Buffer DMA mode
[    3.060136] Periodic Transfer Interrupt Enhancement - disabled
[    3.060344] Multiprocessor Interrupt Enhancement - disabled
[    3.060549] OTG VER PARAM: 0, OTG VER FLAG: 0
[    3.060795] Dedicated Tx FIFOs mode

[    3.061782] WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = aad14000 dma = 0xead14000 len=9024
[    3.062210] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    3.071010] dwc_otg: Microframe scheduler enabled

[    3.071122] WARN::hcd_init_fiq:457: FIQ on core 1

[    3.087324] WARN::hcd_init_fiq:458: FIQ ASM at 807be568 length 36

[    3.103276] WARN::hcd_init_fiq:497: MPHI regs_base at b0810000
[    3.119203] dwc_otg 3f980000.usb: DWC OTG Controller
[    3.127257] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    3.135311] dwc_otg 3f980000.usb: irq 89, io mem 0x00000000
[    3.143415] Init: Port Power? op_state=1
[    3.151427] Init: Power Port (0)
[    3.159977] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    3.168161] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    3.176325] usb usb1: Product: DWC OTG Controller
[    3.184370] usb usb1: Manufacturer: Linux 5.10.17-v7+ dwc_otg_hcd
[    3.192499] usb usb1: SerialNumber: 3f980000.usb
[    3.201695] hub 1-0:1.0: USB hub found
[    3.209844] hub 1-0:1.0: 1 port detected
[    3.219231] dwc_otg: FIQ enabled
[    3.219252] dwc_otg: NAK holdoff enabled
[    3.219267] dwc_otg: FIQ split-transaction FSM enabled
[    3.219292] Module dwc_common_port init
[    3.219864] usbcore: registered new interface driver usb-storage
[    3.228371] mousedev: PS/2 mouse device common for all mice
[    3.238271] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    3.249654] sdhci: Secure Digital Host Controller Interface driver
[    3.257878] sdhci: Copyright(c) Pierre Ossman
[    3.266937] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    3.275469] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.284788] ledtrig-cpu: registered to indicate activity on CPUs
[    3.293430] hid: raw HID events driver (C) Jiri Kosina
[    3.301794] usbcore: registered new interface driver usbhid
[    3.309989] usbhid: USB HID core driver
[    3.325380] Initializing XFRM netlink socket
[    3.333620] NET: Registered protocol family 17
[    3.341906] Key type dns_resolver registered
[    3.350222] Registering SWP/SWPB emulation handler
[    3.358286] registered taskstats version 1
[    3.366033] Loading compiled-in X.509 certificates
[    3.375118] Key type ._fscrypt registered
[    3.382869] Key type .fscrypt registered
[    3.390528] Key type fscrypt-provisioning registered
[    3.413486] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    3.421531] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2
[    3.432979] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    3.443723] Indeed it is in host mode hprt0 = 00021501
[    3.512152] sdhost: log_buf @ (ptrval) (ead13000)
[    3.538930] random: fast init done
[    3.572941] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    3.585630] of_cfs_init
[    3.594161] of_cfs_init: OK
[    3.603627] Waiting for root device PARTUUID=061fad79-02...
[    3.671802] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.680119] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.688322] Indeed it is in host mode hprt0 = 00001101
[    3.760856] mmc0: new high speed SDHC card at address aaaa
[    3.770341] mmcblk0: mmc0:aaaa SL32G 28.8 GiB
[    3.782144]  mmcblk0: p1 p2
[    3.837156] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.845740] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    3.865124] devtmpfs: mounted
[    3.882605] Freeing unused kernel memory: 1024K
[    3.892307] Run /sbin/init as init process
[    3.900453]   with arguments:
[    3.900469]     /sbin/init
[    3.900484]   with environment:
[    3.900498]     HOME=/
[    3.900512]     TERM=linux
[    3.932314] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
[    3.940925] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.950654] hub 1-1:1.0: USB hub found
[    3.959441] hub 1-1:1.0: 5 ports detected
[    4.281839] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    4.412438] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
[    4.421115] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.433282] smsc95xx v2.0.0
[    4.561494] systemd[1]: System time before build time, advancing clock.
[    4.650280] libphy: smsc95xx-mdiobus: probed
[    4.660580] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, m.m.m.m
[    4.732479] NET: Registered protocol family 10
[    4.743758] Segment Routing with IPv6
[    4.819421] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[    4.846400] systemd[1]: Detected architecture arm.
[    4.950010] systemd[1]: Set hostname to <raspberrypi>.
[    6.034419] random: systemd: uninitialized urandom read (16 bytes read)
[    6.063114] random: systemd: uninitialized urandom read (16 bytes read)
[    6.073972] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    6.096133] random: systemd: uninitialized urandom read (16 bytes read)
[    6.107307] systemd[1]: Listening on Journal Socket (/dev/log).
[    6.129568] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    6.152276] systemd[1]: Listening on initctl Compatibility Named Pipe.
[    6.175587] systemd[1]: Listening on Syslog Socket.
[    6.203066] systemd[1]: Created slice system-getty.slice.
[    6.227204] systemd[1]: Listening on Journal Socket.
[    7.488307] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    7.647728] systemd-journald[112]: Received request to flush runtime journal from PID 1
[    8.398666] Registered IR keymap rc-rc6-mce
[    8.432698] IR RC6 protocol handler initialized
[    8.472861] rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@12/rc/rc0
[    8.474642] rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter
[    8.475540] input: gpio_ir_recv as /devices/platform/ir-receiver@12/rc/rc0/input0
[    8.510918] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    8.514505] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    8.514550] [vc_sm_connected_init]: start
[    8.526769] [vc_sm_connected_init]: installed successfully
[    8.530114] mc: Linux media interface: v0.10
[    8.595409] videodev: Linux video capture interface: v2.00
[    8.633149] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    8.679713] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    8.702022] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    8.703355] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    8.717466] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    8.718530] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    8.719323] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    8.725102] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    8.725173] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    8.725219] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    8.725250] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    8.725556] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    8.726142] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    8.755297] bcm2835_audio bcm2835_audio: card created with 4 channels
[    8.766788] bcm2835_audio bcm2835_audio: card created with 4 channels
[    8.889029] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    8.903808] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    8.903935] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    8.909532] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    8.909630] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    8.959098] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    8.959304] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    9.575643] IR RC5(x/sz) protocol handler initialized
[    9.887875] dvbdev: DVB: registering new adapter (CXD2880)
[    9.936724] cxd2880: cxd2880_attach: CXD2880 driver version: Ver 1.4.1 - 1.0.5
[    9.936786] cxd2880 spi0.0: DVB: registering adapter 0 frontend 0 (Sony CXD2880)...
[    9.940491] cxd2880_spi: cxd2880_spi_probe: Sony CXD2880 has successfully attached.
[   12.881029] random: crng init done
[   12.881092] random: 7 urandom warning(s) missed due to ratelimiting
[   13.285777] 8021q: 802.1Q VLAN Support v1.8
[   13.381933] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[   13.446926] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[   13.566332] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[   13.885149] SMSC LAN8700 usb-001:003:01: attached PHY driver [SMSC LAN8700] (mii_bus:phy_addr=usb-001:003:01, irq=POLL)
[   13.885827] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   13.903535] smsc95xx 1-1.1:1.0 eth0: Link is Down
[   15.993469] smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off
[   15.993551] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   36.421152] cxd2880: cxd2880_set_frontend: sys:3 freq:562000000 bw:8
[   37.450202] cxd2880: cxd2880_set_frontend: tune result 0
[   45.321846] rc rc0: two consecutive events of type space
[   58.101423] cxd2880: cxd2880_set_frontend: sys:16 freq:658000000 bw:8
[   59.137223] cxd2880: cxd2880_set_frontend: tune result 0

Logs

mmal: mmal_vc_port_info_set: failed to set port info (2:0): EINVAL
mmal: mmal_vc_port_set_format: mmal_vc_port_info_set failed 0x6131e720 (EINVAL)
Failed to commit deinterlace intput format (status=3 EINVAL)
mmal: mmal_vc_port_enable: failed to enable port vc.ril.image_fx:in:0(OPQV): EINVAL
mmal: mmal_port_enable: failed to enable port vc.ril.image_fx:in:0(OPQV)(0x6131e720) (EINVAL)
Failed to enable deinterlace input port vc.ril.image_fx:in:0(OPQV) (3, EINVAL)
mmal: mmal_vc_port_info_set: failed to set port info (3:0): EINVAL
mmal: mmal_vc_port_set_format: mmal_vc_port_info_set failed 0x6131eae0 (EINVAL)
Failed to commit deinterlace output format (status=3 EINVAL)
mmal: mmal_vc_port_enable: failed to enable port vc.ril.image_fx:out:0(OPQV): EINVAL
mmal: mmal_port_enable: failed to enable port vc.ril.image_fx:out:0(OPQV)(0x6131eae0) (EINVAL)
Failed to enable deinterlacer output port vc.ril.image_fx:out:0(OPQV) (3, EINVAL)
Failed send buffer to deinterlacer output port (3, EINVAL)
Failed send buffer to deinterlacer output port (3, EINVAL)
Failed send buffer to deinterlacer output port (3, EINVAL)

Thread 15 "softhddev video" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x612ff400 (LWP 2379)]
VideoRenderFrame (render=0x2ea2e0, video_ctx=<optimized out>, 
    frame=<optimized out>) at video_mmal.c:889
889     memcpy(qbuffer->data, buffer->data, buffer->length);
(gdb) bt
#0  VideoRenderFrame (render=0x2ea2e0, video_ctx=<optimized out>, 
    frame=<optimized out>) at video_mmal.c:889
#1  0x76454fe4 in CodecVideoReceiveFrame (decoder=0x309328, 
    no_deint=no_deint@entry=0) at codec.c:376
#2  0x7644e9d0 in VideoDecodeInput (stream=0x7646a858 <MyVideoStream>)
    at softhddev.c:1117
#3  0x76450498 in DisplayHandlerThread (arg=0x2ea2e0) at video_mmal.c:723
#4  0x76f4f494 in start_thread (arg=0x612ff400) at pthread_create.c:486
#5  0x76bb0dd8 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:73
   from /lib/arm-linux-gnueabihf/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Additional context MPEG-2 and H.264 video playback works fine via the OMX interface (https://github.com/reufer/rpihddevice/).

dr-m commented 1 year ago

The H.264 playback fails also with the currently latest available firmware according to sudo rpi-update: raspberrypi/rpi-firmware@bcd35b7abb058b210b33922ba60efc1cc93f533d (5.15.79). MPEG-2 and H.264 via OMX using rpihddevice works fine also with this kernel.

6by9 commented 1 year ago

Presumably there are no errors when running on the older firmware?

Failed to commit deinterlace intput format (status=3 EINVAL) what was the format that you attempted to commit? Easiest to use mmal_log_dump_port, but you'll need to set VC_LOGLEVEL=mmal:trace first. https://github.com/raspberrypi/userland/blob/master/interface/mmal/util/mmal_util.c#L324

FWIW:

The future appears to be V4L2 M2M, but it is unclear to me if that interface is supported on the Raspberry Pi 2.

It is supported on all variants of Raspberry Pi, and under both 32 and 64 bit OSes.

dr-m commented 1 year ago

I added a few mmal_log_dump_port() calls and set the environment variable. Here is the output for raspberrypi/rpi-firmware@bcd35b7abb058b210b33922ba60efc1cc93f533d starting a little before the first EINVAL:

mmal: mmal_vc_component_create:  handle 48
mmal: mmal_vc_port_info_get: get port info (1:0)
mmal: mmal_vc_port_info_get: get port info (2:0)
mmal: mmal_vc_port_info_get: get port info (3:0)
mmal: mmal_pool_create_with_allocator: allocating 48 + 24 + 472 * 4 bytes for pool
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 0/4
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 1/4
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 2/4
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 3/4
mmal: mmal_component_create_core: created 'vc.ril.image_fx' 8 0x63421280
mmal: mmal_port_parameter_set: vc.ril.image_fx(3:0) port 0x63421d40, param 0x612fbd30 (10032,40)
mmal: mmal_port_enable: vc.ril.image_fx:ctr:0 port 0x63421670, cb 0x7644f7d0, buffers (4/0/4,740/0/740)
mmal: mmal_port_format_commit: vc.ril.image_fx(2:0) port 0x63421980 format 3:OPQV
mmal: mmal_vc_port_info_set: set port info (2:0)
mmal: mmal_vc_port_info_set: failed to set port info (2:0): EINVAL
mmal: mmal_vc_port_set_format: mmal_vc_port_info_set failed 0x63421980 (EINVAL)
Failed to commit deinterlace intput format (status=3 EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:ctr:0(0x63421670)
mmal: mmal_log_dump_format: type: unknown, fourcc:     
mmal: mmal_log_dump_format:  bitrate: 0, framed: 0
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_port:  buffers num: 4(opt 0, min 4), size: 740(opt 0, min: 740), align: 0
mmal: mmal_log_dump_port: vc.ril.image_fx:in:0(OPQV)(0x63421980)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0
mmal: mmal_port_parameter_set: vc.ril.image_fx(2:0) port 0x63421980, param 0x612fbd0c (20013,12)
mmal: mmal_port_enable: vc.ril.image_fx:in:0(OPQV) port 0x63421980, cb 0x764500d4, buffers (1/1/1,3840/3840/3840)
mmal: mmal_vc_port_enable: failed to enable port vc.ril.image_fx:in:0(OPQV): EINVAL
mmal: mmal_port_enable: failed to enable port vc.ril.image_fx:in:0(OPQV)(0x63421980) (EINVAL)
Failed to enable deinterlace input port vc.ril.image_fx:in:0(OPQV) (3, EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:ctr:0(0x63421670)
mmal: mmal_log_dump_format: type: unknown, fourcc:     
mmal: mmal_log_dump_format:  bitrate: 0, framed: 0
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_port:  buffers num: 4(opt 0, min 4), size: 740(opt 0, min: 740), align: 0
mmal: mmal_log_dump_port: vc.ril.image_fx:in:0(OPQV)(0x63421980)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0
mmal: mmal_port_format_commit: vc.ril.image_fx(3:0) port 0x63421d40 format 3:OPQV
mmal: mmal_vc_port_info_set: set port info (3:0)
mmal: mmal_vc_port_info_set: failed to set port info (3:0): EINVAL
mmal: mmal_vc_port_set_format: mmal_vc_port_info_set failed 0x63421d40 (EINVAL)
Failed to commit deinterlace output format (status=3 EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:ctr:0(0x63421670)
mmal: mmal_log_dump_format: type: unknown, fourcc:     
mmal: mmal_log_dump_format:  bitrate: 0, framed: 0
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_port:  buffers num: 4(opt 0, min 4), size: 740(opt 0, min: 740), align: 0
mmal: mmal_log_dump_port: vc.ril.image_fx:in:0(OPQV)(0x63421980)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0
mmal: mmal_component_enable: vc.ril.image_fx 8
mmal: mmal_port_enable: vc.ril.image_fx:out:0(OPQV) port 0x63421d40, cb 0x7644fc78, buffers (1/1/1,3840/3840/3840)
mmal: mmal_vc_port_enable: failed to enable port vc.ril.image_fx:out:0(OPQV): EINVAL
mmal: mmal_port_enable: failed to enable port vc.ril.image_fx:out:0(OPQV)(0x63421d40) (EINVAL)
Failed to enable deinterlacer output port vc.ril.image_fx:out:0(OPQV) (3, EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:out:0(OPQV)(0x63421d40)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0
mmal: mmal_log_dump_port: vc.ril.image_fx:ctr:0(0x63421670)
mmal: mmal_log_dump_format: type: unknown, fourcc:     
mmal: mmal_log_dump_format:  bitrate: 0, framed: 0
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_port:  buffers num: 4(opt 0, min 4), size: 740(opt 0, min: 740), align: 0
mmal: mmal_pool_create_with_allocator: allocating 48 + 8 + 472 * 1 bytes for pool
mmal: mmal_pool_initialise_buffer_headers: allocating 3840 bytes for payload 0/1
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x63421980, size 3840
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 3840 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x6341c790
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x63421980), refcount 0
Failed send buffer to deinterlacer output port (3, EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:out:0(OPQV)(0x63421d40)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0
Failed send buffer to deinterlacer output port (3, EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:out:0(OPQV)(0x63421d40)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0
Failed send buffer to deinterlacer output port (3, EINVAL)
mmal: mmal_log_dump_port: vc.ril.image_fx:out:0(OPQV)(0x63421d40)
mmal: mmal_log_dump_format: type: video, fourcc: OPQV
mmal: mmal_log_dump_format:  bitrate: 0, framed: 1
mmal: mmal_log_dump_format:  extra data: 0, (nil)
mmal: mmal_log_dump_format:  width: 1920, height: 1080, (0,0,1920,1080)
mmal: mmal_log_dump_format:  pixel aspect ratio: 1/1, frame rate: 1571292/65536
mmal: mmal_log_dump_port:  buffers num: 1(opt 1, min 1), size: 3840(opt 3840, min: 3840), align: 0

Thread 15 "softhddev video" received signal SIGSEGV, Segmentation fault.
6by9 commented 1 year ago

There is a commit in that time frame relating to the padded height (port->format->es->video.height) on image_fx. The deinterlacing algorithm needs the frame to be padded to at least a multiple of 16 lines above the height.

When using opaque buffers the format is slightly redundant as the buffers include the full geometry, but I suspect is still being validated. Can you try adding render->deint->input[0]->format->es->video.height = VCOS_ALIGN_UP(render->deint->input[0]->format->es->video.height, 16); after the mmal_port_format_copy at in https://github.com/zillevdr/vdr-plugin-softhddevice-drm/blob/drm/video_mmal.c#L427

dr-m commented 1 year ago

Thank you, I will try your suggestion later.

I just downgraded to 518ee7c871aaa9aaa88116953d57e73787ee6e43. Here is the corresponding output (with no crash). Both were from a live DVB-T2 stream, so some parameters might be different:

mmal: mmal_vc_component_create:  handle 48
mmal: mmal_vc_port_info_get: get port info (1:0)
mmal: mmal_vc_port_info_get: get port info (2:0)
mmal: mmal_vc_port_info_get: get port info (3:0)
mmal: mmal_pool_create_with_allocator: allocating 48 + 24 + 472 * 4 bytes for pool
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 0/4
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 1/4
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 2/4
mmal: mmal_pool_initialise_buffer_headers: allocating 740 bytes for payload 3/4
mmal: mmal_component_create_core: created 'vc.ril.image_fx' 8 0x6341f230
mmal: mmal_port_parameter_set: vc.ril.image_fx(3:0) port 0x6341fcf0, param 0x612fbd30 (10032,40)
mmal: mmal_port_enable: vc.ril.image_fx:ctr:0 port 0x6341f620, cb 0x7644f7d0, buffers (4/0/4,740/0/740)
mmal: mmal_port_format_commit: vc.ril.image_fx(2:0) port 0x6341f930 format 3:OPQV
mmal: mmal_vc_port_info_set: set port info (2:0)
mmal: mmal_vc_port_info_get: get port info (2:0)
mmal: mmal_vc_port_info_get: get port info (3:0)
mmal: mmal_port_parameter_set: vc.ril.image_fx(2:0) port 0x6341f930, param 0x612fbd0c (20013,12)
mmal: mmal_port_enable: vc.ril.image_fx:in:0(OPQV) port 0x6341f930, cb 0x764500d4, buffers (10/10/3,128/128/128)
mmal: mmal_port_format_commit: vc.ril.image_fx(3:0) port 0x6341fcf0 format 3:OPQV
mmal: mmal_vc_port_info_set: set port info (3:0)
mmal: mmal_vc_port_info_get: get port info (3:0)
mmal: mmal_component_enable: vc.ril.image_fx 8
mmal: mmal_port_enable: vc.ril.image_fx:out:0(OPQV) port 0x6341fcf0, cb 0x7644fc78, buffers (10/10/3,128/128/128)
mmal: mmal_pool_create_with_allocator: allocating 48 + 48 + 472 * 10 bytes for pool
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 0/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x634216d0
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 0
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 1/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63421770
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 1
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 2/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63421820
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 2
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 3/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x634218c0
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 3
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 4/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63421970
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 4
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 5/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63421a10
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 5
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 6/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63421ac0
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 6
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 7/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63426780
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 7
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 8/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x63426830
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 8
mmal: mmal_pool_initialise_buffer_headers: allocating 128 bytes for payload 9/10
mmal: mmal_port_payload_alloc: vc.ril.image_fx(2:0) port 0x6341f930, size 128
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocating 128 bytes, format OPQV, is_zero_copy 0
mmal: mmal_vc_port_payload_alloc: vc.ril.image_fx:in:0(OPQV): allocated at 0x634268d0
mmal: mmal_port_acquire: port vc.ril.image_fx:in:0(OPQV)(0x6341f930), refcount 9
dr-m commented 1 year ago

There are two mmal_port_format_copy() calls in the file. I first added the call to the wrong place, and it did not stop the crashes.

After I added the suggested tweak to both call sites, it stopped crashing on raspberrypi/rpi-firmware@bcd35b7abb058b210b33922ba60efc1cc93f533d, but I did not get any H.264 video either (only audio); the initial DVB-T MPEG-2 live stream was playing fine. I then reverted my changes and applied only your suggested fix, to see if it would be better. Same thing: the video disappeared but audio continued playing, with some interruptions. Even after I switched back to a DVB-T channel, the video remained absent and the audio was choppy. (Initially, the DVB-T output was playing fine).

Here is my reduced patch against zillevdr/vdr-plugin-softhddevice@cbccef7cc37c3122c75f58000a50227fe468ca45:

diff --git a/Makefile b/Makefile
index 93391b5..f51e21b 100644
--- a/Makefile
+++ b/Makefile
@@ -12,7 +12,7 @@ PLUGIN = softhddevice-drm
 ### Configuration (edit this for your needs)

    # enable this for MMAL (RaspberryPi 2)
-MMAL ?= 0
+MMAL ?= 1

 CONFIG := #-DDEBUG                 # enable debug output+functions
 #CONFIG += -DAV_SYNC_DEBUG     # enable debug messages AV_SYNC
diff --git a/video_mmal.c b/video_mmal.c
index 5b9dd65..7c5181c 100644
--- a/video_mmal.c
+++ b/video_mmal.c
@@ -425,6 +425,7 @@ static void MmalChangeResolution(VideoRender * render,
                render->vout->control->name, status, mmal_status_to_string(status));

        mmal_format_copy(render->deint->input[0]->format, render->vout->input[0]->format);
+render->deint->input[0]->format->es->video.height = VCOS_ALIGN_UP(render->deint->input[0]->format->es->video.height, 16);
        status = mmal_port_format_commit(render->deint->input[0]);
        if (status != MMAL_SUCCESS)
            printf("Failed to commit deinterlace intput format (status=%"PRIx32" %s)\n",
dr-m commented 1 year ago

On b324aea801f669b6ab18441f970e74a5a7346684 the playback continues fine even with the above patch.