Skip to content
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

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

Open
1 task done
Rudd-O opened this issue May 16, 2024 · 8 comments
Open
1 task done
Labels

Comments

@Rudd-O
Copy link

Rudd-O commented May 16, 2024

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?

  • Yes

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 Rudd-O added the triage label May 16, 2024
@Rudd-O
Copy link
Author

Rudd-O commented May 16, 2024

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
Copy link
Author

Rudd-O commented May 16, 2024

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
Copy link
Author

Rudd-O commented May 16, 2024

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 Rudd-O changed the title Ogg Vorbis: Invalid data found when processing input Ogg Vorbis: Invalid data found when processing input (most likely bad build options for ffmpeg shipped in container) May 16, 2024
@Rudd-O
Copy link
Author

Rudd-O commented May 16, 2024

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
Copy link
Author

Rudd-O commented May 16, 2024

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
Copy link
Author

Rudd-O commented May 16, 2024

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 Rudd-O changed the title Ogg Vorbis: Invalid data found when processing input (most likely bad build options for ffmpeg shipped in container) Ogg Vorbis: Invalid data found when processing input; certain Ogg Vorbis files created between 2017 and now, tagged with EasyTAG, cannot currently be used with Music Assistant May 17, 2024
@Rudd-O
Copy link
Author

Rudd-O commented May 17, 2024

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.

@OzGav OzGav changed the title Ogg Vorbis: Invalid data found when processing input; certain Ogg Vorbis files created between 2017 and now, tagged with EasyTAG, cannot currently be used with Music Assistant ffmpeg can’t play certain Ogg Vorbis files created between 2017 and now, tagged with EasyTAG May 29, 2024
@marcelveldt
Copy link
Member

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants