search

music-assistant / hass-music-assistant

Turn your Home Assistant instance into a jukebox, hassle free streaming of your favorite media to Home Assistant media players.
Apache License 2.0
1.39k stars 51 forks source link

ffmpeg can’t play certain Ogg Vorbis files created between 2017 and now, tagged with EasyTAG #2313

Closed Rudd-O closed 2 months ago

Rudd-O commented 6 months ago

What version of Music Assistant has the issue?

2.0.4

What version of the Home Assistant Integration have you got installed?

Latest

Have you tried everything in the Troubleshooting FAQ and reviewed the Open and Closed Issues and Discussions to resolve this yourself?

The problem

2024-05-14 10:19:15.629 ERROR (MainThread) [music_assistant.providers.filesystem_local] Error processing ...Queen/Live at Wembley'86, disc 2/Gimme some lovin'.ogg - Unable to retrieve info for ...Queen/Live at Wembley'86, disc 2/Gimme some lovin'.ogg: Invalid data found when processing input

in the log

How to reproduce

I would have to share one of these faulty files.

Music Providers

Filesystem.

Player Providers

This is a metadata scanning issue. Players are not involved.

Full log output

Really, it's only this, over an over again:

May 16 23:15:16 penny.dragonfear music-assistant[789294]: 2024-05-16 23:15:16.131 ERROR (MainThread) [music_assistant.providers.filesystem_local] Error processing Good/Albums and singles/Shakira/Laundry service/Ojos así.ogg - Unable to retrieve info for /media/Good/Albums and singles/Shakira/Laundry service/Ojos así.ogg: Invalid data found when processing input

Additional information

What I would like to see is a backtrace of this type of exception so I can reproduce it down to the exact byte of the file causing the issue and the exact line of code raising it, but it seems no matter what logging level I set, I cannot actually get a backtrace.

What version of Home Assistant Core are your running

2024.5.0

What type of installation are you running?

Home Assistant Core

On what type of hardware are you running?

Linux

Rudd-O commented 6 months ago

For the record, the track gets added to the library and is findable. I traced the issue somewhere into here https://github.com/music-assistant/server/blob/6b53fedb0662a389e05256d9a259d479c4806eb2/music_assistant/server/helpers/audio.py#L171 and it seems to be something ffmpeg is doing, but I'm not exactly sure what it is. Again, no traceback to debug.

I think it would be difficult to get a clean traceback though, given that this is async code running on a separate coroutine not actually aware of what ffmpeg command is running and who called it, so I think it best is probably to just store the traceback at the initialization of the FFMpeg class and dump it when these errors are logged (dump it only once per session, no more than that). Failing that, a record of the failed command line would be extremely useful.

Rudd-O commented 6 months ago

Update: I tried running several ffmpeg command lines mentioned in that file, and I couldn't get ffmpeg to produce an error output that contains "Invalid data found when processing input". Of course, I did not run the container's version of ffmpeg — I ran my own on the host running the container, so there may be a difference.

Update 2: ran in container, no error. Removed -log_level quiet and BOOM, error:

root@penny:/app# ffmpeg -hide_banner -i /media/'Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg' shit.wav
[ogg @ 0x55fe993b7680] Header processing failed: Invalid data found when processing input
/media/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg: Invalid data found when processing input
Rudd-O commented 6 months ago

It might (very unlikely) be the build options used to build ffmpeg. From https://stackoverflow.com/questions/45372501/ffmpeg-ogg-invalid-data-found-when-processing-input :

Yeah, you have --disable-demuxers but no --enable-demuxer=ogg after that. Depending on what the Oggs contain, your build may still be crippled.

It might not be that. Might just be a buggy version. The ffmpeg version shipped in the container is 6.0.1. The one on my system is 6.1.1.

Rudd-O commented 6 months ago

Container build options that fail to decode Ogg Vorbis files:

  configuration: --disable-decoder=amrnb --disable-decoder=libopenjpeg --disable-gnutls --disable-liblensfun --disable-libopencv --disable-podpages --disable-sndio --disable-stripping --enable-avfilter --enable-chromaprint --enable-frei0r --enable-gcrypt --enable-gpl --enable-ladspa --enable-libaom --enable-libaribb24 --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libdav1d --enable-libdavs2 --enable-libdc1394 --enable-libdrm --enable-libfdk-aac --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libglslang --enable-libgme --enable-libgsm --enable-libiec61883 --enable-libjack --enable-libkvazaar --enable-libmp3lame --enable-libmysofa --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenh264 --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librabbitmq --enable-librist --enable-librsvg --enable-librubberband --enable-libshine --enable-libsmbclient --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libsvtav1 --enable-libtesseract --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvo-amrwbenc --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs2 --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-libzvbi --enable-lv2 --enable-nonfree --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-openssl --enable-postproc --enable-pthreads --enable-shared --enable-version3 --enable-vulkan --incdir=/usr/include/x86_64-linux-gnu --libdir=/usr/lib/x86_64-linux-gnu --prefix=/usr --toolchain=hardened --enable-vaapi --enable-libvpl --enable-libvmaf --enable-libilbc --enable-libjxl --cc=x86_64-linux-gnu-gcc --cxx=x86_64-linux-gnu-g++ --disable-altivec --shlibdir=/usr/lib/x86_64-linux-gnu

Working FFMpeg build options that successfully decode the file:

  configuration: --prefix=/usr --bindir=/usr/bin --datadir=/usr/share/ffmpeg --docdir=/usr/share/doc/ffmpeg --incdir=/usr/include/ffmpeg --libdir=/usr/lib64 --mandir=/usr/share/man --arch=x86_64 --optflags='-O2 -flto=auto -ffat-lto-objects -fexceptions -g -grecord-gcc-switches -pipe -Wall -Wno-complain-wrong-lang -Werror=format-security -Wp,-U_FORTIFY_SOURCE,-D_FORTIFY_SOURCE=3 -Wp,-D_GLIBCXX_ASSERTIONS -specs=/usr/lib/rpm/redhat/redhat-hardened-cc1 -fstack-protector-strong -specs=/usr/lib/rpm/redhat/redhat-annobin-cc1 -m64 -mtune=generic -fasynchronous-unwind-tables -fstack-clash-protection -fcf-protection -fno-omit-frame-pointer -mno-omit-leaf-frame-pointer' --extra-ldflags='-Wl,-z,relro -Wl,--as-needed -Wl,-z,now -specs=/usr/lib/rpm/redhat/redhat-hardened-ld -specs=/usr/lib/rpm/redhat/redhat-annobin-cc1 -Wl,--build-id=sha1 ' --extra-cflags=' -I/usr/include/rav1e' --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libvo-amrwbenc --enable-version3 --enable-bzlib --enable-chromaprint --disable-crystalhd --enable-fontconfig --enable-frei0r --enable-gcrypt --enable-gnutls --enable-ladspa --enable-libaom --enable-libdav1d --enable-libass --enable-libbluray --enable-libbs2b --enable-libcodec2 --enable-libcdio --enable-libdrm --enable-libjack --enable-libjxl --enable-libfreetype --enable-libfribidi --enable-libgsm --enable-libilbc --enable-libmp3lame --enable-libmysofa --enable-nvenc --enable-openal --enable-opencl --enable-opengl --enable-libopenh264 --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-libplacebo --enable-librsvg --enable-librav1e --enable-librubberband --enable-libsmbclient --enable-version3 --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libssh --enable-libsvtav1 --enable-libtesseract --enable-libtheora --enable-libtwolame --enable-libvorbis --enable-libv4l2 --enable-libvidstab --enable-libvmaf --enable-version3 --enable-vapoursynth --enable-libvpx --enable-vulkan --enable-libshaderc --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxvid --enable-libxml2 --enable-libzimg --enable-libzmq --enable-libzvbi --enable-lv2 --enable-avfilter --enable-libmodplug --enable-postproc --enable-pthreads --disable-static --enable-shared --enable-gpl --disable-debug --disable-stripping --shlibdir=/usr/lib64 --enable-lto --enable-libvpl --enable-runtime-cpudetect

I inspected a diff of sorted build config options and did not spot anything that might explain it.

Rudd-O commented 6 months ago

Extra verbose run of container ffmpeg:

Splitting the commandline.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '48'.
Reading option '-hide_banner' ... matched as option 'hide_banner' (do not show program banner) with argument '1'.
Reading option '-i' ... matched as input url with argument '/media/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg'.
Reading option 'shit.wav' ... matched as output url.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option loglevel (set logging level) with argument 48.
Applying option hide_banner (do not show program banner) with argument 1.
Successfully parsed a group of options.
Parsing a group of options: input url /media/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg.
Successfully parsed a group of options.
Opening an input file: /media/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg.
[NULL @ 0x5600d14556c0] Opening '/media/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg' for reading
[file @ 0x5600d1455f40] Setting default whitelist 'file,crypto,data'
[ogg @ 0x5600d14556c0] Format ogg probed with size=2048 and score=100
[ogg @ 0x5600d14556c0] Header processing failed: Invalid data found when processing input
[AVIOContext @ 0x5600d145e380] Statistics: 32768 bytes read, 0 seeks
/media/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg: Invalid data found when processing input
Rudd-O commented 6 months ago

file data from file:

/srv/shared/Entertainment/Music/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg: Ogg data, Vorbis audio, stereo, 44100 Hz, ~128003 bps, created by: Xiph.Org libVorbis I (1.0)
Rudd-O commented 6 months ago

OK, mystery solved. I tracked it down to this https://gitlab.gnome.org/GNOME/easytag/-/issues/8 .

I used EasyTAG to tag my Vorbis files many years ago. It fucked with the files. ffmpeg from your container is refusing to read them, while my system's ffmpeg reads them fine without warning (they probably introduced a workaround). Ogginfo clearly shows a problem with the origin file:

$ ogginfo "/srv/shared/Entertainment/Music/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg"
Processing file "/srv/shared/Entertainment/Music/Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg"...

New logical stream (#1, serial: 00005382): type vorbis
WARNING: Vorbis stream 1 does not have headers correctly framed. Terminal header page contains additional packets or has non-zero granulepos
Vorbis headers parsed for stream 1, information follows...
Version: 0
Vendor: Xiph.Org libVorbis I 20020717 (1.0)

Reencoding the file with my own ffmpeg produces a clean file:

$ ffmpeg -loglevel verbose -i /srv/shared/Entertainment/Music/'Good/Albums and singles/Shakira/Laundry service/Moscas en la casa.ogg' -acodec copy shit.ogg
[...snip...]
$ ogginfo shit.ogg
Processing file "shit.ogg"...

New logical stream (#1, serial: 5526bc5c): type vorbis
Vorbis headers parsed for stream 1, information follows...
Version: 0
Vendor: Lavf60.16.100
Channels: 2
Rate: 44100

What an absolute disaster.

Please update ffmpeg. On my side I will work to render these files fixed using the workaround I found.

Leaving this ticket open for the ffmpeg update request.

marcelveldt commented 5 months ago

Our container is based on Debian - ffmpeg on debian is super outdated so we're already relying on the multimedia repo; https://github.com/music-assistant/server/blob/main/Dockerfile#L65

Looks like their version is also already lacking behind. I'm planning on switching our container to Alpine (the same as Home Assistant) for which we do have recent binaries for ffmpeg available.

OzGav commented 2 months ago

Switch to Alpine is complete in 2.3.0b16. @Rudd-O please check if this has been fixed.

OzGav commented 2 months ago

We will close this soon assuming fixed

klodeckl commented 1 month ago

Same problem here again on current Music assistant 2.2.7. How can this be fixed?

2024-10-06 09:25:40.145 WARNING (MainThread) [music_assistant.audio] Could not determine integrated loudness of spotify--LGpAHpS6://track/5F0fiSkDxZL5V3SlnTNhKh - [in#0 @ 0x7f90012b00] Error opening input: Invalid data found when processing input Error opening input file -. Error opening input files: Invalid data found when processing input

klodeckl commented 1 month ago

Donwgrade from 2.2.7 to 2.2.6 solves the problem.

Rudd-O commented 1 month ago

I've tried the latest beta, same issues. I have managed to "fix" most files MA had a problem with, but the problem persists on those that haven't been "fixed".

klodeckl commented 1 month ago

Update to 2.2.9 and problem was solved.