Playback ends abruptly before the end of tracks

[khannurien]

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

[sentriz]

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?

[khannurien]

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...

[sentriz]

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

[khannurien]

Sure, will do. I cannot consistently reproduce the bug, so it might take a while before I get back to you :-)

[khannurien]

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?

[sentriz]

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

[khannurien]

I went with opus_192 and will report back if it happens again!

[brian-doherty]

@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.

[sentriz]

@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

[khannurien]

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.

[brian-doherty]

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.

[sentriz]

@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

[brian-doherty]

If you're feeding it the length yourself, then I don't think so, but I haven't tried it.

[sentriz]

oh right, but i mean how would gonic get the length itself? if not with bitrate estimation

[brian-doherty]

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.

[brian-doherty]

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.

[sentriz]

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

[brian-doherty]

@khannurien What is the ffprobe output for the original track in question? @sentriz It doesn't just estimate length from the audio feed itself?

[khannurien]

@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)

[brian-doherty]

@khannurien @sentriz Interesting -- duration is in the tags. I guess FFMpeg isn't trusting it or something?

[sentriz]

that is mighty strange

[khannurien]

@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?

[sentriz]

i just asked on the #ffmpeg irc

[khannurien]

I wonder how airsonic-advanced handles that quirk. I just remembered I had a somewhat similar problem there a few years ago: https://github.com/airsonic/airsonic/issues/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.

[brian-doherty]

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.

[sentriz]

sounds good. thanks for you help @brian-doherty @khannurien !

[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.

[khannurien]

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.

[sentriz]

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

[khannurien]

Done.

Maybe this is not a transcoding problem after all...

[sentriz]

@khannurien can't reproduce it unfortunately. which browser are you running?

[khannurien]

Firefox 121

[QDucasse]

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) with mp3_320 transcoding 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