Playback ends abruptly before the end of tracks
Closed this issue · 33 comments
gonic version: v0.16.2
docker tag: sentriz/gonic:latest
When using airsonic-refix as a gonic client, I sometimes get abrupt playback stop before the end of tracks -- especially longer tracks (7 minutes and more).
I assume this is related to gonic, because this does not happen under airsonic-advanced with airsonic-refix as a client.
I wanted to open this issue so that more people can confirm if that happens for them too.
I'll be happy to share more details and help investigate further.
Thanks for the hard work,
Vincent
hm strange. i use airsonic-refix with gonic every day. do you have transcoding rules setup? any is there anything in the gonic logs when this happens?
Indeed, I use mp3_320 for * clients.
Nothing seems particularly relevant in the logs. Definitely no errors.
Maybe I should cross-post the issue at airsonix-refix...
could you leave the refix dev tools (F12) open and wait for the error to happen again? see if there are an errors in the Console tab
Sure, will do. I cannot consistently reproduce the bug, so it might take a while before I get back to you :-)
I just got it after playing 4 tracks. Here are the logs -- nothing interesting (except maybe for the empty Error box on refix side):
It seems the problem lies with the track length. The playback seems OK, as it goes to the "end" of the track. But the track length was "miscalculated" and shorter than in reality. Does that make sense?
hm. can you try a different codec? like opus_128? (much better codec anyway :D smaller files with greater fidelity) to see if the issue is with mp3
I went with opus_192 and will report back if it happens again!
@sentriz I wonder if a debug option to additionally route the transcoder output to a file in /tmp might help determine where the issue lies.
@brian-doherty oh good point, the caching transcoder does this by default
@khannurien maybe you could run ffprobe (from ffmpeg) on the most recent files in your gonic audio cache path? find the track that had the error and see what ffprobe says
Here it is:
/cache/audio # ffprobe 31cf0f5ed05f9f73190c3d5499e5d317
ffprobe version 6.0.1 Copyright (c) 2007-2023 the FFmpeg developers
built with gcc 12.2.1 (Alpine 12.2.1_git20220924-r10) 20220924
configuration: --prefix=/usr --disable-librtmp --disable-lzma --disable-static --disable-stripping --enable-avfilter --enable-gnutls --enable-gpl --enable-libaom --enable-libass --enable-libbluray --enable-libdav1d --enable-libdrm --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libmp3lame --enable-libopenmpt --enable-libopus --enable-libplacebo --enable-libpulse --enable-librist --enable-libsoxr --enable-libsrt --enable-libssh --enable-libtheora --enable-libv4l2 --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-lto --enable-pic --enable-postproc --enable-pthreads --enable-shared --enable-vaapi --enable-vdpau --enable-vulkan --optflags=-O3 --enable-libjxl --enable-libsvtav1 --enable-libvpl
libavutil 58. 2.100 / 58. 2.100
libavcodec 60. 3.100 / 60. 3.100
libavformat 60. 3.100 / 60. 3.100
libavdevice 60. 1.100 / 60. 1.100
libavfilter 9. 3.100 / 9. 3.100
libswscale 7. 1.100 / 7. 1.100
libswresample 5. 0.100 / 5. 0.100
libpostproc 57. 1.100 / 57. 1.100
[mp3 @ 0x7fe88ca27680] Estimating duration from bitrate, this may be inaccurate
Input #0, mp3, from '31cf0f5ed05f9f73190c3d5499e5d317':
Metadata:
date : 2023-11-09
title : Askungen
artist : Ray Ragnhild Adams
album : Allande
album_artist : Ray Ragnhild Adams
YEAR : 2023
genre : Pop
track : 05
disc : 01
TRACKTOTAL : 11
DISCTOTAL : 01
encoder : Lavf60.3.100
Duration: 00:05:07.72, start: 0.000000, bitrate: 320 kb/s
Stream #0:0: Audio: mp3, 44100 Hz, stereo, fltp, 320 kb/s
The duration (said to be estimated from bitrate) is on point.
Sounds like the bug is in airsonic-revix then. BUT it might be nice for Gonic to populate the MP3 LENGTH tag by adding "-metadata:t=length x:xx" when transcoding to MP3.
@brian-doherty i assume that would need to be a 2 stage encode then? since gonic streams the ffmpeg output in real time, and ffmpeg wont know the real duration until it's finished encoding
i also wonder why the bitrate is inacurate in the first place, since mp3 320 is fixed bitrate
If you're feeding it the length yourself, then I don't think so, but I haven't tried it.
oh right, but i mean how would gonic get the length itself? if not with bitrate estimation
In populateTrack you're pulling it from the tagReader and storing it in the DB, so you can just use that if non-zero, and omit if not. That's the best you can do until you calculate the length from the data as per the comment in populateTrack.
I wonder if the file being transcoded lacks the length in the tags and so that's why ffmpeg can't copy it over? In which case following that comment and using FFMpeg to provide the length and bitrate at scan time might be the answer to the whole issue. UPDATE: You would have to do both, actually.
yeah exactly the length isn't present in the tags at all, that's why ffprobe and refix had to resort to bitrate estimation. so -metadata:t=length <length from tags> is a no-op. but yeah as you say -metadata:t=length <real length> would fix it all
ah. ofc bitrate estimation could be way off when the file has a large embeddded artwork or something
@khannurien What is the ffprobe output for the original track in question?
@sentriz It doesn't just estimate length from the audio feed itself?
@sentriz here it is:
/music/Ray Ragnhild Adams - Allande｜2023｜WEB FLAC 16-44.1 # ffprobe 05\ -\ Askungen.flac
ffprobe version 6.0.1 Copyright (c) 2007-2023 the FFmpeg developers
built with gcc 12.2.1 (Alpine 12.2.1_git20220924-r10) 20220924
configuration: --prefix=/usr --disable-librtmp --disable-lzma --disable-static --disable-stripping --enable-avfilter --enable-gnutls --enable-gpl --enable-libaom --enable-libass --enable-libbluray --enable-libdav1d --enable-libdrm --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libmp3lame --enable-libopenmpt --enable-libopus --enable-libplacebo --enable-libpulse --enable-librist --enable-libsoxr --enable-libsrt --enable-libssh --enable-libtheora --enable-libv4l2 --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-lto --enable-pic --enable-postproc --enable-pthreads --enable-shared --enable-vaapi --enable-vdpau --enable-vulkan --optflags=-O3 --enable-libjxl --enable-libsvtav1 --enable-libvpl
libavutil 58. 2.100 / 58. 2.100
libavcodec 60. 3.100 / 60. 3.100
libavformat 60. 3.100 / 60. 3.100
libavdevice 60. 1.100 / 60. 1.100
libavfilter 9. 3.100 / 9. 3.100
libswscale 7. 1.100 / 7. 1.100
libswresample 5. 0.100 / 5. 0.100
libpostproc 57. 1.100 / 57. 1.100
Input #0, flac, from '05 - Askungen.flac':
Metadata:
encoder : Lavf60.3.100
TITLE : Askungen
ARTIST : Ray Ragnhild Adams
ALBUM : Allande
album_artist : Ray Ragnhild Adams
YEAR : 2023
GENRE : Pop
track : 05
disc : 01
TRACKTOTAL : 11
DISCTOTAL : 01
DATE : 2023-11-09
Duration: 00:05:07.68, start: 0.000000, bitrate: 858 kb/s
Stream #0:0: Audio: flac, 44100 Hz, stereo, s16
Stream #0:1: Video: mjpeg (Baseline), yuvj420p(pc, bt470bg/unknown/unknown), 250x250 [SAR 1:1 DAR 1:1], 90k tbr, 90k tbn (attached pic)
Metadata:
comment : Cover (front)
@khannurien @sentriz Interesting -- duration is in the tags. I guess FFMpeg isn't trusting it or something?
that is mighty strange
@brian-doherty @sentriz I'm really not familiar with this stuff, correct me if I'm wrong -- the Duration field is separate from Metadata and thus that value mustn't be found in the tags, right?
i just asked on the #ffmpeg irc
I wonder how airsonic-advanced handles that quirk. I just remembered I had a somewhat similar problem there a few years ago: airsonic/airsonic#1343
It seems that it has been fixed in the meantime though, as it does not occur when I use airsonic-advanced rather than gonic as a backend.
Looks like the LENGTH tag in MP3 exists but no one populates or reads it. Might just be best to let this dog lie and submit the bug to airsonic-refix.
sounds good. thanks for you help @brian-doherty @khannurien !
Just in case someone stumbles upon this issue looking for a solution: it most probably is a transcoding-related bug. The easiest way to solve it has been to switch from mp3 to opus transcoding profile in gonic's admin.
Damn it. Just as I typed this comment, the issue happened again.
Here is the ffprobe output for the file:
/cache/audio # ffprobe dde0263254984adb7c723a7f3e85b001
ffprobe version 6.0.1 Copyright (c) 2007-2023 the FFmpeg developers
built with gcc 12.2.1 (Alpine 12.2.1_git20220924-r10) 20220924
configuration: --prefix=/usr --disable-librtmp --disable-lzma --disable-static --disable-stripping --enable-avfilter --enable-gnutls --enable-gpl --enable-libaom --enable-libass --enable-libbluray --enable-libdav1d --enable-libdrm --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libmp3lame --enable-libopenmpt --enable-libopus --enable-libplacebo --enable-libpulse --enable-librist --enable-libsoxr --enable-libsrt --enable-libssh --enable-libtheora --enable-libv4l2 --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-lto --enable-pic --enable-postproc --enable-pthreads --enable-shared --enable-vaapi --enable-vdpau --enable-vulkan --optflags=-O3 --enable-libjxl --enable-libsvtav1 --enable-libvpl
libavutil 58. 2.100 / 58. 2.100
libavcodec 60. 3.100 / 60. 3.100
libavformat 60. 3.100 / 60. 3.100
libavdevice 60. 1.100 / 60. 1.100
libavfilter 9. 3.100 / 9. 3.100
libswscale 7. 1.100 / 7. 1.100
libswresample 5. 0.100 / 5. 0.100
libpostproc 57. 1.100 / 57. 1.100
Input #0, ogg, from 'dde0263254984adb7c723a7f3e85b001':
Duration: 00:06:16.63, start: 0.000000, bitrate: 221 kb/s
Stream #0:0: Audio: opus, 48000 Hz, stereo, fltp
Metadata:
encoder : Lavc60.3.100 libopus
ALBUM : Herself
album_artist : Console
ARTIST : Console
BARCODE : 880918015620
DATE : 2010-12-17
disc : 1
DISCTOTAL : 1
DURATION : 06:16
ISRC : DEK591035601
LABEL : Disko B
MEDIA : Digital Media
ORGANIZATION : Disko B
TITLE : She Saw
TOTALDISCS : 1
TOTALTRACKS : 11
track : 1
TRACKTOTAL : 11
UPC : 880918015620
YEAR : 2010
In airsonic-refix player, I saw the track length set at 4:34 (while it is 6:16 in reality, as stated by ffprobe). Playback stopped after 4:34 and skipped to the next track.
that's weird. where did 4:34 come from i wonder? it seems ffprobe says the duration is 06:16 both by the file itself and the metadata
@khannurien can you email me that dde0263254984adb7c723a7f3e85b001 file? and maybe the original too? email is on my profile
Done.
Maybe this is not a transcoding problem after all...
@khannurien can't reproduce it unfortunately. which browser are you running?
Firefox 121
Hello, I have the exact same issue as the one mentioned above, using the same setup of:
gonic- docker tag: sentriz/gonic:latest (v0.16.3) withmp3_320transcoding set up for*clients.airsonic-refix- docker tag: tamland/airsonic-refix:latest
through Firefox 123.
Will update if I find more relevant information or a stable reproducible case!
Thanks for the work <3