2.2.0 has strange issue with source.say_metadata

xogium commented 1 year ago

Describe the bug

When using source.say_metadata to speak the metadata of each song, the metadata will get spoken sooner than at the end of the currently playing song.

Let's say you have a song playing, and you're soon at the end, about 6 seconds from it. Your audio will suddenly cut out and the decoder (libflac, ffmpeg...) will decode and send the audio for the metadata to liquidsoap, which will then be played on icecast. After this, your song will then resume and finish its actual playback with the few seconds of it remaining. It will then jump to a new song, and do this all over again when this new song is close to ending. It appears this issue is easier to reproduce with ffmpeg decoder, at least during my testing.

To Reproduce

Simply create a script which loads a minimal playlist of files, and use source.say_metadata on your source. Forward the audio to some icecast instance.

Load the stream into your favorite music player and listen to a few songs.

Try it both with ffmpeg and without. My own testing shows this is easier to hit with ffmpeg, but it is still possible to manage it without (in my case libflac). Particularly in songs which seem to have no blank at the end.

Expected behavior

I'd expect the songs to fully finish decoding before the metadata file is ever sent out to liquidsoap for playback, as interrupting the current song is very jarring.

Version details

OS: Archlinux
Version: Liquidsoap rolling-release-v2.2.x-9-gc8e5a42+git@c8e5a42b8

Install method

Installed everything via opam.

joe-ms commented 1 year ago

I have the exact same problem, and it has been boggling me for months, at least. If I can help with any code examples, please let me know.

xogium commented 1 year ago

I can also provide a code example but really, in my case, it's as dead simple as it can be made:

mksafe a playlist of flac encoded files
setup source.say_metadata on this
stream the resulting content to icecast

Nothing fancy, no ladspa effect, no complicated or involved setup. It's as basic as I can make it.

toots commented 1 year ago

Reproduction script:

music = mksafe(playlist("/var/lib/liquidsoap/radio",reload_mode="watch"))

def append_album(m) =
        title = m["title"]
        artist = m["artist"]
        album = m["album"]
        [("artist","#{artist}"),("title","#{album} - #{title}")]
end

music = map_metadata(append_album, music)

radio = source.say_metadata(music)

output.icecast(%mp3.cbr(bitrate=192, samplerate=44100),
        host = "radio.domain.tld",
        port = 8443,
        mount = "/radio.mp3",
        password = "password",
        name = "Radio",
        url = "https://radio.domain.tld:8443/radio.mp3",
        radio
)

Jookia commented 1 year ago

If this only happens with FLAC files perhaps Liquidsoap is using two different measurements for track length somewhere? Or perhaps an error is accumulating between queued tasks and the real clock?

joe-ms commented 1 year ago

I have a local Liquidsoap instance making the radio feed from a mp3 library and mixing with an external TTS program for metadata announcements, and am sending with SRT to another remote liquidsoap which is making an AAC HLS stream. I am mainly sending over SRT with opus, but have tried with various containers and formats and the problem persists. The TTS will gradually start earlier and earlier as reported above. I am also using replaygain via metadatatag, and when the rest of the song is played it is without replaygain, so this can maybe indicate where in the process the bug is located.

xogium commented 1 year ago

That's interesting. So, the issue happens at the liquidsoap with ogg/opus audio, correct I'm confused though, I thought the tts was mixed in with the mp3 feed, before it ever reached the second liquidsoap instance??

If so that means it could be an issue with the ogg container handling itself...

Fwiw, I don't use replaygain at all over here.

I've tried mp3 instead of flac and as far as I could determine here, there were no such cut. Maybe I just got lucky?

joe-ms commented 1 year ago

Hereunder is an example script I am using where the TTS speaker will gradually start earlier and earlier when announcing the metadata of the last song played. After some hours it becomes noticeable. It does not matter which of the encoders or formats I use in OUTPUT SRT. The remaining part of the song is played without replaygain, so something like an error between queued tasks and the real clock in the first instance could sound likely.

Nevermind the intricate TTS code. It is a local docker TTS daemon which is fed curl and returns the output WAV filename, e.g. 10e2c4523ffcdf3db7638dfc07b79af6ea8ea616-8-1.wav which is then located at /home/dj/martha/10/e2/10e2c4523ffcdf3db7638dfc07b79af6ea8ea616-8-1.wav

First local instance:

#!/usr/local/bin/liquidsoap

# --- GL PLAYLIST DEFINE ---
GL = playlist("~/music/GL")

# --- GL RADIO PROGRAM ---
radioGL = GL

# --- TTS SPEAKER ---
def martha_protocol(~rlog, ~maxtime=_, arg) =
  rlog("GL Speaker #{arg}.")
    process.read.lines("curl -sS 'http://192.168.0.107:8000/?f=wav&n=1' --data-urlencode #{string.quote(arg)} | sed -e 's/^\(.\{4\}\).*/\1&/' -e 's/./&\\//4' -e 's/./&\\//2' -e 's#^#/home/dj/martha/#'")
end
protocol.add("martha", martha_protocol)

def insert_title(m)
  single("martha:t=Last song played was #{m['artist']} with #{m['title']}")
end
radioGL = append(radioGL, insert_title)

# --- EFFECTS ---
radioGL = amplify(1.,override="replaygain_track_gain", radioGL)

# --- OUTPUT SRT ---
output.srt(id="audio", host="X.X.X.X", port=9999, mode="caller", passphrase="mypassphrase", polling_delay=10., fallible=true,
  %opus(bitrate=192, samplerate=48000),
# %ffmpeg(format="mpegts",
#     %audio(codec="libfdk_aac", b="196k")),
  radioGL)

Second remote instance:

#!/usr/local/bin/liquidsoap

# --- INPUT SRT  ---
radioGL = input.srt(id="audio", port=9999, passphrase="mypassphrase", mode="listener")

# --- BUFFER ---
radioGL = buffer(fallible=true, max=3.0, radioGL)

# --- FALLBACK ---
emergency = single("~/mksafe.mp3")
radioGL = fallback(track_sensitive=false, [radioGL, emergency])

# --- CONFIG AUDIO ENCODER ---
aac_lo=
  %ffmpeg(format="mpegts",
    %audio(channels=2, samplerate=48000, codec="libfdk_aac", b="32k")
  )

aac_mi =
  %ffmpeg(format="mpegts",
    %audio(channels=2, samplerate=48000, codec="libfdk_aac", b="96k")
  )

aac_hi=
  %ffmpeg(format="mpegts",
    %audio(channels=2, samplerate=48000, codec="libfdk_aac", b="196k")
  )

# --- CONFIG HLS AUDIO ---
def segment_name(~position,~extname,stream_name) =
  timestamp = int_of_float(time())
  duration = 2
  "#{stream_name}_#{duration}_#{timestamp}_#{position}.#{extname}"
end

# --- OUTPUT HLS AUDIO ---
output.file.hls("/mnt/hls",
  playlist="gl.m3u8",
              segment_duration=5.0,
              segments=5,
              segments_overhead=5,
              segment_name=segment_name,
              #on_file_change=on_file_change,
              #persist_at="state.config",
  [("aac_lo",aac_lo),
   ("aac_mi",aac_mi),
   ("aac_hi",aac_hi)],
radioGL)

toots commented 1 year ago

It's most likely due to the new buffer code getting out of sync between audio and metadata. I would like to fix it before the release but I can't hold it up for too long for it. A full reproducible example (with files if needed) would really help. I'll have another pass at the the code tomorrow see if I can see anything obvious.

joe-ms commented 1 year ago

Don't hang me up on it, but I would say I have experienced the bug about half a year.

Jookia commented 1 year ago

Could this be git bisected?

On Thu, Jul 20, 2023 at 08:27:58PM -0700, Romain Beauxis wrote:

It's most likely due to the new buffer code getting out of sync between audio and metadata. I would like to fix it before the release but I can't hold it up for too long for it. A full reproducible example (with files if needed) would really help. I'll have another pass at the the code tomorrow see if I can see anything obvious.

-- Reply to this email directly or view it on GitHub: https://github.com/savonet/liquidsoap/issues/3181#issuecomment-1644933461 You are receiving this because you commented.

Message ID: @.***>

toots commented 12 months ago

@joe-ms I'm looking at this again. I'm gonna run a shorten version of your script to see if I can reproduce. Are you yourself in a position of trying to prune down that script? First thing would be to see if the delay still happens when doing a local output instead of srt.

joe-ms commented 12 months ago

@toots Yes, I've been trying a few times to reproduce locally in a single script without any luck yet. So perhaps the time slip could be related to the network stream e.g. srt or icecast. Mind in my experience it will take hours before the slip is audible.

If you wanna hear a live example of the bug try www.radioxound.com. I have just restarted, so it will gradually become more and more audible.

toots commented 11 months ago

@joe-ms I can definitely hear it. I haven't been able to figure out where/how this can happen yet but I'm actively looking at it.

toots commented 11 months ago

@joe-ms do you have logs to share around a transition that has the issue? Anything with log.level set to 4 would really help.

toots commented 11 months ago

@joe-ms I'm working on a scripted rewrite of append. You should be able to add this to your script and see if it helps:

# Append an extra track to every track. Set the metadata ‘liq_append’ to
# `false` to inhibit appending on one track.
# @category Source / Track processing
# @param f Given the metadata, build the source producing the track to append. This source is allowed to fail (produce nothing) if no relevant track is to be appended.
# @param ~insert_missing Treat track beginnings without metadata as having empty one.
# @param ~merge Merge the track with its appended track.
# @flag extra
def append(~id=null(), ~insert_missing=true, ~merge=false, s, f) =
  last_meta = ref(null())
  pending = ref(null())

  def f(m) =
    if m["liq_append"] == "false" then
      last_meta := null()
      pending := null()
    elsif last_meta() != m then
      last_meta := m
      pending := (f(m):source)
    end
  end

  s =
    if insert_missing then
      source.on_track(s, f)
    else
      s
    end

  s = source.on_metadata(s, f)

  def next() =
    p = pending()
    pending := null()
    if null.defined(p) then
      p = null.get(p)
      sequence(merge=merge, [p, s])
    else
      s
    end
  end

  s = source.dynamic(
    id=id,
    track_sensitive=true,
    next
  )

  s.{
    # Return the pending source
    pending = fun () -> pending(),
    # Set the pending source
    set_pending = fun (s) -> pending.set(s),
    # Cancel any pending appended source.
    cancel_pending = fun () -> pending.set(null()),
    # Skip the current track. Pending appended source are cancelled by default. Pass `cancel_pending=false` to keep it.
    skip = fun (~cancel_pending=true) -> begin
      if cancel_pending then pending.set(null()) end
      s.skip()
    end
  }
end

joe-ms commented 11 months ago

@toots Hereunder a log around a transition between two songs from a script similar to "first local instance" mentioned above.

Thanks, I will give your append rewrite a try. Btw, I have always been trying to get my TTS to use prepend in order to also announce some songs before the song will play. Would that be possible?

2023/08/05 03:18:32 [GL:4] Queued 1 requests
[mp3float @ 0x7f5154048740] Could not update timestamps for discarded samples.
2023/08/05 03:21:48 [decoder:2] Decoding "/home/dj/music/GL/Tamalaat/Tamalaat 10 - GR8504/11 Nuannertaqaaq Angalaartariuni.mp3" ended: Ffmpeg_decoder.End_of_file.
2023/08/05 03:21:48 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 827, characters 12-29
2023/08/05 03:21:48 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/05 03:21:48 [decoder:4] 
2023/08/05 03:21:48 [GL:4] Finished with "/home/dj/music/GL/Tamalaat/Tamalaat 10 - GR8504/11 Nuannertaqaaq Angalaartariuni.mp3".
2023/08/05 03:21:48 [GL:4] Remaining 0 requests
2023/08/05 03:21:48 [GL:3] Prepared "/home/dj/music/GL/Juaanna aamma Pavia Arnelu/GR8525/02 Ataatatut.mp3" (RID 17).
2023/08/05 03:21:48 [single.6:4] Remaining 0 requests
2023/08/05 03:21:48 [single.6:3] Prepared "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav" (RID 18).
2023/08/05 03:21:48 [amplify.2:4] End of the current overriding.
2023/08/05 03:21:48 [ogg.muxer:4] audio: Setting end of track 400c8c3.
2023/08/05 03:21:48 [ogg.muxer:4] audio: Every ogg logical tracks have ended: setting end of stream.
2023/08/05 03:21:48 [ogg.muxer:4] audio: Starting new sequentialized ogg stream.
2023/08/05 03:21:48 [ogg.muxer:4] audio: Starting all streams
2023/08/05 03:21:48 [decoder.ogg:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.ogg:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.mad:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.mad:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.midi:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.midi:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.srt:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.srt:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.aiff:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.aiff:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder:4] Available decoders: ffmpeg (priority: 10), image (priority: 1), wav (priority: 1)
2023/08/05 03:21:48 [decoder:4] Trying decoder "ffmpeg"
2023/08/05 03:21:48 [decoder.ffmpeg:3] Requested content-type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": {audio=pcm(stereo)}
2023/08/05 03:21:48 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav" as audio: {codec: pcm_s16le, 22050Hz, 1 channel(s)}
2023/08/05 03:21:48 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": {audio=pcm(mono)}
2023/08/05 03:21:48 [decoder:4] Selected decoder ffmpeg for file "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(mono)}
2023/08/05 03:21:48 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.ogg:4] Unsupported file extension for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav"!
2023/08/05 03:21:48 [decoder.ogg:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [decoder.taglib:4] Unsupported MIME type for "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav": audio/x-wav!
2023/08/05 03:21:48 [single.6:4] Queued 1 requests
2023/08/05 03:22:01 [decoder:2] Decoding "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav" ended: Ffmpeg_decoder.End_of_file.
2023/08/05 03:22:01 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 827, characters 12-29
2023/08/05 03:22:01 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/05 03:22:01 [decoder:4] 
2023/08/05 03:22:01 [single.6:4] Finished with "/home/dj/martha/94/4b/944b3aa690665c83028c1f98533ef6934c11250e-134.wav".
2023/08/05 03:22:01 [source:4] Source single.6 gets down.
2023/08/05 03:22:01 [single.6:4] Waiting for feeding task to stop...
2023/08/05 03:22:01 [single.6:4] Cleaning up request queue...
[mp3float @ 0x7f5154092400] Could not update timestamps for skipped samples.
2023/08/05 03:22:01 [source:4] Source single.7 gets up with content type: {audio=pcm(stereo)}.
2023/08/05 03:22:01 [single.7:3] Content type is {audio=pcm(stereo)}.
2023/08/05 03:22:01 [amplify.2:4] Overriding amplification: 1.520548.
2023/08/05 03:22:01 [ogg.muxer:4] audio: Setting end of track 2815de5d.
2023/08/05 03:22:01 [ogg.muxer:4] audio: Every ogg logical tracks have ended: setting end of stream.
2023/08/05 03:22:01 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:01 [ogg.muxer:4] audio: Starting new sequentialized ogg stream.
2023/08/05 03:22:01 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.midi:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.midi:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.srt:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.ogg:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.ogg:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.wav:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2023/08/05 03:22:02 [decoder:4] Trying decoder "ffmpeg"
2023/08/05 03:22:02 [decoder.mad:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.mad:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [ogg.muxer:4] audio: Starting all streams
2023/08/05 03:22:02 [decoder.midi:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.midi:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.srt:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.srt:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.aiff:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.aiff:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder:4] Available decoders: ffmpeg (priority: 10), image (priority: 1), wav (priority: 1)
2023/08/05 03:22:02 [decoder:4] Trying decoder "ffmpeg"
2023/08/05 03:22:02 [decoder.ffmpeg:3] Requested content-type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": {audio=pcm(stereo)}
2023/08/05 03:22:02 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3" as audio: {codec: mp3, 48000Hz, 2 channel(s)}
2023/08/05 03:22:02 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": {audio=pcm(stereo)}
2023/08/05 03:22:02 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/05 03:22:02 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.ffmpeg:3] Requested content-type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": {audio=pcm(stereo)}
2023/08/05 03:22:02 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav" as audio: {codec: pcm_s16le, 22050Hz, 1 channel(s)}
2023/08/05 03:22:02 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": {audio=pcm(mono)}
2023/08/05 03:22:02 [decoder:4] Selected decoder ffmpeg for file "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(mono)}
2023/08/05 03:22:02 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3"!
2023/08/05 03:22:02 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Arsarnerit/Kangersuatsiaq - GR8522/range8_Audio 1.mp3": audio/mpeg!
2023/08/05 03:22:02 [GL:4] Queued 1 requests
2023/08/05 03:22:02 [decoder.ogg:4] Unsupported file extension for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav"!
2023/08/05 03:22:02 [decoder.ogg:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [decoder.taglib:4] Unsupported MIME type for "/home/dj/martha/6b/d8/6bd80c214b96bd48d25aaf89dd920a81e31b9118-132.wav": audio/x-wav!
2023/08/05 03:22:02 [single.7:4] Queued 1 requests

toots commented 11 months ago

@joe-ms Should definitely be possible!

Actually you made me remember that prepend should also be moved to a script operator! It is included in the PR now!

Lastly, it would be better to try with the branch rather than dropping the append definition in your script unless you are directly calling append yourself in it. If you're not on the branch and use source.say_metadata and etc they would still call the old non-scripted operator since they are defined in the standard library.

xogium commented 11 months ago

FWIW, I'm still experiencing the issue, even with the append operator rewritten as a script.

I've been toying with the idea of making ls skip blanks to see what would happen, but I don't know if that would help trigger it faster or not.

My theory is it's inaudible on a lot of songs at first, because they happen to have blanks at the end. If there was no blank, maybe it would become audible faster. What do you think?

toots commented 11 months ago

@joe-ms have you had any luck with the new scripted operator?

joe-ms commented 11 months ago

@toots I have tried to let it run a few times overnight, and now the TTS append is played very seldom (but not time shifted), even though it should be called after each track.

joe-ms commented 11 months ago

Here a log. It jumps directly from the first song to the second song without TTS.

Warning at position at /home/dj/liquidsoap-daemon/script/script.liq, line 51, char 21-126: illegal backslash escape in string.
Warning at position at /home/dj/liquidsoap-daemon/script/script.liq, line 51, char 21-129: illegal backslash escape in string.
Warning at position at /home/dj/liquidsoap-daemon/script/script.liq, line 51, char 21-131: illegal backslash escape in string.
Warning at position at /home/dj/liquidsoap-daemon/script/script.liq, line 51, char 21-136: illegal backslash escape in string.
2023/08/11 03:15:14 >>> LOG START
2023/08/11 03:15:05 [main:3] Liquidsoap v2.2.0-29-gae38109+dev
2023/08/11 03:15:05 [main:3] Using: angstrom=0.15.0 asetmap=0.8.1 asn1-combinators=0.2.6 astring=0.8.5 base64=3.5.1 bigarray=[distributed with OCaml] bigarray-compat=1.1.0 bigstringaf=0.9.1 bos=0.2.1 bytes=[distributed with OCaml] ca-certs=v0.2.3 camlp-streams camomile.lib=2.0 cohttp=5.3.0 cohttp-lwt=5.3.0 cohttp-lwt-unix=5.3.0 conduit=6.2.0 conduit-lwt=6.2.0 conduit-lwt-unix=6.2.0 cry=f9bf5ac cstruct=6.2.0 ctypes=0.21.1 ctypes-foreign=0.21.1 ctypes.stubs=0.21.1 curl=0.9.2 domain-name=0.4.0 dtools=18de991 dune-build-info=3.10.0 dune-private-libs.dune-section=3.10.0 dune-site=3.10.0 dune-site.private=3.10.0 duppy=0.9.3 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 fdkaac=0.3.3 ffmpeg-av=4859056 ffmpeg-avcodec=4859056 ffmpeg-avdevice=4859056 ffmpeg-avfilter=4859056 ffmpeg-avutil=4859056 ffmpeg-swresample=4859056 ffmpeg-swscale=4859056 fileutils=0.6.4 fmt=0.9.0 fpath=0.7.3 gen=1.1 gmap=0.3.0 hkdf=1.0.4 integers ipaddr=5.5.0 ipaddr-sexp=5.5.0 ipaddr.unix=5.5.0 lame=0.3.7 liquidsoap-lang=v2.2.0-29-gae38109 liquidsoap-lang.console=v2.2.0-29-gae38109 liquidsoap_builtins=v2.2.0-29-gae38109-dirty liquidsoap_core=v2.2.0-29-gae38109-dirty liquidsoap_fdkaac=v2.2.0-29-gae38109-dirty liquidsoap_ffmpeg=v2.2.0-29-gae38109-dirty liquidsoap_lame=v2.2.0-29-gae38109-dirty liquidsoap_mad=v2.2.0-29-gae38109-dirty liquidsoap_magic=v2.2.0-29-gae38109-dirty liquidsoap_mem_usage=v2.2.0-29-gae38109-dirty liquidsoap_ogg=v2.2.0-29-gae38109-dirty liquidsoap_optionals=v2.2.0-29-gae38109-dirty liquidsoap_opus=v2.2.0-29-gae38109-dirty liquidsoap_oss=v2.2.0-29-gae38109-dirty liquidsoap_prometheus=v2.2.0-29-gae38109-dirty liquidsoap_runtime=v2.2.0-29-gae38109-dirty liquidsoap_samplerate=v2.2.0-29-gae38109-dirty liquidsoap_sdl=v2.2.0-29-gae38109-dirty liquidsoap_sdl_log_level=v2.2.0-29-gae38109-dirty liquidsoap_srt=v2.2.0-29-gae38109-dirty liquidsoap_ssl=v2.2.0-29-gae38109-dirty liquidsoap_stereotool=v2.2.0-29-gae38109-dirty liquidsoap_taglib=v2.2.0-29-gae38109-dirty liquidsoap_tls=v2.2.0-29-gae38109-dirty logs=0.7.0 logs.fmt=0.7.0 logs.lwt=0.7.0 lwt=5.6.1 lwt.unix=5.6.1 macaddr=5.5.0 mad=0.5.2 magic=0.7.3 magic-mime=1.3.0 mem_usage=0.0.4 menhirLib=20230608 metadata=900d12f mirage-crypto=0.11.1 mirage-crypto-ec=0.11.1 mirage-crypto-pk=0.11.1 mirage-crypto-rng=0.11.1 mirage-crypto-rng.unix=0.11.1 mm=0.8.4 mm.audio=0.8.4 mm.base=0.8.4 mm.image=0.8.4 mm.midi=0.8.4 mm.video=0.8.4 ocplib-endian ocplib-endian.bigstring ogg=0.7.4 ogg.decoder=0.7.4 opus=7d8fe5b opus.decoder=7d8fe5b parsexp=v0.16.0 pbkdf pcre=7.5.0 posix-base=2.0.2 posix-socket=2.0.2 posix-socket.constants=2.0.2 posix-socket.stubs=2.0.2 posix-socket.types=2.0.2 ppx_sexp_conv.runtime-lib=v0.16.0 prometheus=1.2 prometheus-app=1.2 ptime=1.1.0 ptime.clock.os=1.1.0 re=1.10.4 rresult=0.7.0 samplerate=0.1.6 sedlex=3.2 seq=[distributed with OCaml 4.07 or above] sexplib=v0.16.0 sexplib0=v0.16.0 srt=0.3.0 srt.constants=0.3.0 srt.stubs=0.3.0 srt.stubs.locked=0.3.0 srt.types=0.3.0 ssl=0.7.0 stdlib-shims=0.3.0 stereotool=v2.2.0-29-gae38109-dirty str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] tls=0.17.1 tsdl=v1.0.0 tsdl-image=0.5 tsdl-ttf=0.5 unix=[distributed with OCaml] uri=4.2.0 uri-sexp=4.2.0 uri.services=4.2.0 x509=0.16.5 zarith=1.13
2023/08/11 03:15:05 [clock:3] Using builtin (low-precision) implementation for latency control
2023/08/11 03:15:14 [main:3] Standard library loaded in 8.83 seconds.
2023/08/11 03:15:14 [Vaigatip Kitigiai Vaigatmusik:4] Reloading playlist.
2023/08/11 03:15:14 [Vaigatip Kitigiai Vaigatmusik:4] Playlist is a directory.
2023/08/11 03:15:14 [frame:4] frame.audio.channels set to: 2
2023/08/11 03:15:14 [frame:4] frame.video.default set to: false
2023/08/11 03:15:14 [frame:4] frame.midi.channels set to: 0
2023/08/11 03:15:14 [frame:4] frame.video.width set to: 1280
2023/08/11 03:15:14 [frame:4] frame.video.height set to: 720
2023/08/11 03:15:14 [frame:4] frame.audio.samplerate set to: 44100
2023/08/11 03:15:14 [frame:4] frame.video.framerate set to: 25
2023/08/11 03:15:14 [frame:4] frame.audio.samplerate set to: 44100
2023/08/11 03:15:14 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2023/08/11 03:15:14 [frame:3] Video frame size set to: 1280x720
2023/08/11 03:15:14 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2023/08/11 03:15:14 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2023/08/11 03:15:14 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2023/08/11 03:15:15 [sandbox:3] Sandboxing disabled
2023/08/11 03:15:15 [startup:3] FFmpeg filters registration: 0.04s
2023/08/11 03:15:15 [startup:3] FFmpeg bitstream filters registration: 0.00s
2023/08/11 03:15:15 [startup:3] Typechecking: 8.36s
2023/08/11 03:15:15 [startup:3] Evaluation: 0.03s
2023/08/11 03:15:15 [startup:3] Typechecking: 0.08s
2023/08/11 03:15:15 [startup:3] Evaluation: 0.01s
2023/08/11 03:15:15 [startup:3] Typechecking: 0.02s
2023/08/11 03:15:15 [startup:3] Evaluation: 0.01s
2023/08/11 03:15:15 [startup:3] Loaded /home/dj/liquidsoap-daemon/script/script.liq: 0.03s
2023/08/11 03:15:15 [video.converter:3] Using preferred video converter: ffmpeg.
2023/08/11 03:15:15 [audio.converter:3] Using samplerate converter: libsamplerate.
2023/08/11 03:15:15 [clock:4] Currently 1 clock(s) allocated.
2023/08/11 03:15:15 [clock.main:4] Starting 1 source(s)...
2023/08/11 03:15:15 [source:4] Source audio gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [audio:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source amplify.3 gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [amplify.3:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source amplify.2 gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [amplify.2:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source append gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source on_metadata gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [on_metadata:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source on_track gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [on_track:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source metadata_map.2 gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [metadata_map.2:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [source:4] Source metadata_map gets up with content type: {}.
2023/08/11 03:15:15 [metadata_map:3] Content type is {}.
2023/08/11 03:15:15 [source:4] Source Vaigatip_Kitigiai_Vaigatmusik gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:15:15 [Vaigatip_Kitigiai_Vaigatmusik:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:15:15 [threads:4] Created thread "clock_main" (1 total).
2023/08/11 03:15:15 [clock:4] Main phase starts.
2023/08/11 03:15:15 [threads:4] Created thread "generic queue #1" (1 total).
2023/08/11 03:15:15 [threads:4] Created thread "generic queue #2" (2 total).
2023/08/11 03:15:15 [threads:4] Created thread "non-blocking queue #1" (3 total).
2023/08/11 03:15:15 [threads:4] Created thread "non-blocking queue #2" (4 total).
2023/08/11 03:15:15 [prometheus.server:3] Starting prometheus server on port 9090
2023/08/11 03:15:15 [video.text:3] Using sdl implementation
2023/08/11 03:15:15 [clock.main:3] Streaming loop starts in auto-sync mode
2023/08/11 03:15:15 [clock.main:3] Delegating synchronization to CPU clock
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.midi:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.midi:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.srt:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.wav:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2023/08/11 03:15:15 [decoder:4] Trying decoder "ffmpeg"
2023/08/11 03:15:15 [decoder.ffmpeg:3] Requested content-type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": {audio=pcm(stereo)}
2023/08/11 03:15:15 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3" as audio: {codec: mp3, 48000Hz, 2 channel(s)}
2023/08/11 03:15:15 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": {audio=pcm(stereo)}
2023/08/11 03:15:15 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/11 03:15:15 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3"!
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3": audio/mpeg!
2023/08/11 03:15:15 [Vaigatip_Kitigiai_Vaigatmusik:4] Queued 1 requests
2023/08/11 03:15:15 [Vaigatip_Kitigiai_Vaigatmusik:4] Remaining 0 requests
2023/08/11 03:15:15 [Vaigatip_Kitigiai_Vaigatmusik:3] Prepared "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3" (RID 0).
[mp3float @ 0x7fcb4000f980] Could not update timestamps for skipped samples.
2023/08/11 03:15:15 [audio:3] Connecting to srt://xx.xxx.xx.xx:xxxx..
2023/08/11 03:15:15 [audio:3] Client connected!
2023/08/11 03:15:15 [amplify.2:4] Overriding amplification: 2.398833.
2023/08/11 03:15:15 [ogg.muxer:4] audio: Starting all streams
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.midi:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [ogg.muxer:4] audio: Setting end of track 106e97cc.
2023/08/11 03:15:15 [decoder.midi:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [ogg.muxer:4] audio: Every ogg logical tracks have ended: setting end of stream.
2023/08/11 03:15:15 [ogg.muxer:4] audio: Starting new sequentialized ogg stream.
2023/08/11 03:15:15 [decoder.srt:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.wav:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2023/08/11 03:15:15 [decoder:4] Trying decoder "ffmpeg"
2023/08/11 03:15:15 [ogg.muxer:4] audio: Starting all streams
2023/08/11 03:15:15 [decoder.ffmpeg:3] Requested content-type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": {audio=pcm(stereo)}
2023/08/11 03:15:15 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3" as audio: {codec: mp3, 48000Hz, 2 channel(s)}
2023/08/11 03:15:15 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": {audio=pcm(stereo)}
2023/08/11 03:15:15 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/11 03:15:15 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3"!
2023/08/11 03:15:15 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3": audio/mpeg!
2023/08/11 03:15:15 [Vaigatip_Kitigiai_Vaigatmusik:4] Queued 1 requests
[mp3float @ 0x7fcb4000f980] Could not update timestamps for discarded samples.
2023/08/11 03:17:33 [decoder:2] Decoding "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3" ended: Ffmpeg_decoder.End_of_file.
2023/08/11 03:17:33 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 828, characters 12-29
2023/08/11 03:17:33 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/11 03:17:33 [decoder:4] 
2023/08/11 03:17:33 [Vaigatip_Kitigiai_Vaigatmusik:4] Finished with "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/05 Nunakarfiga Kimaligara.mp3".
2023/08/11 03:17:33 [Vaigatip_Kitigiai_Vaigatmusik:4] Remaining 0 requests
2023/08/11 03:17:33 [Vaigatip_Kitigiai_Vaigatmusik:3] Prepared "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/06 Nunaga-â Nunarssûp Avangnâne.mp3" (RID 1).
2023/08/11 03:17:33 [source:4] Source sequence gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:17:33 [source:4] Source single gets up with content type: {audio=pcm(stereo)}.
2023/08/11 03:17:33 [single:3] Content type is {audio=pcm(stereo)}.
2023/08/11 03:17:33 [amplify.2:4] End of the current overriding.
[mp3float @ 0x7fcb400cb000] Could not update timestamps for skipped samples.
2023/08/11 03:17:33 [process:4] Starting process
2023/08/11 03:17:33 [process:4] Closing process's stdin
2023/08/11 03:17:33 [amplify.2:4] Overriding amplification: 1.541700.
2023/08/11 03:17:33 [ogg.muxer:4] audio: Setting end of track 2624baec.
2023/08/11 03:17:33 [ogg.muxer:4] audio: Every ogg logical tracks have ended: setting end of stream.
2023/08/11 03:17:33 [ogg.muxer:4] audio: Starting new sequentialized ogg stream.
2023/08/11 03:17:33 [ogg.muxer:4] audio: Starting all streams
2023/08/11 03:17:33 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.midi:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.midi:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.srt:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.srt:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.aiff:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.aiff:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.wav:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.wav:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder:4] Available decoders: ffmpeg (priority: 10), mad (priority: 1), image (priority: 1)
2023/08/11 03:17:34 [decoder:4] Trying decoder "ffmpeg"
2023/08/11 03:17:34 [decoder.ffmpeg:3] Requested content-type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": {audio=pcm(stereo)}
2023/08/11 03:17:34 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3" as audio: {codec: mp3, 48000Hz, 2 channel(s)}
2023/08/11 03:17:34 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": {audio=pcm(stereo)}
2023/08/11 03:17:34 [decoder:4] Selected decoder ffmpeg for file "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/11 03:17:34 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported file extension for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3"!
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported MIME type for "/home/dj/music/GL/Jens Hendriksenip Nipillersortartue/Vaigatip Kitigiai Vaigatmusik/10 Upernalerners.mp3": audio/mpeg!
2023/08/11 03:17:34 [Vaigatip_Kitigiai_Vaigatmusik:4] Queued 1 requests
2023/08/11 03:17:34 [lang:3] Failed to execute `curl -sS 'http://192.168.0.107:8000/?f=wav&n=1' --data-urlencode "t=This was Jens Hendriksenip Nipillersortartue with Nunakarfiga Kimaligara" | sed -e 's/^\(.\{4\}\).*/\1&/' -e 's/./&\//4' -e 's/./&\//2' -e 's#^#/home/dj/martha/#'`: timeout (-1) /home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav 
2023/08/11 03:17:34 [process:4] Process exited with code 0
2023/08/11 03:17:34 [process:4] Cleaning up process
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.mad:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.mad:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.midi:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.midi:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.srt:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.srt:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.aiff:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.aiff:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder:4] Available decoders: ffmpeg (priority: 10), image (priority: 1), wav (priority: 1)
2023/08/11 03:17:34 [decoder:4] Trying decoder "ffmpeg"
2023/08/11 03:17:34 [decoder.ffmpeg:3] Requested content-type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": {audio=pcm(stereo)}
2023/08/11 03:17:34 [decoder.ffmpeg:3] FFmpeg recognizes "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav" as audio: {codec: pcm_s16le, 22050Hz, 1 channel(s)}
2023/08/11 03:17:34 [decoder.ffmpeg:3] Decoded content-type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": {audio=pcm(mono)}
2023/08/11 03:17:34 [decoder:4] Selected decoder ffmpeg for file "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(mono)}
2023/08/11 03:17:34 [decoder.video.metadata:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.video.metadata:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.ogg.metadata:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.image.metadata:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.image.metadata:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.flac.metadata:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.flac.metadata:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported file extension for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav"!
2023/08/11 03:17:34 [decoder.ogg:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [decoder.taglib:4] Unsupported MIME type for "/home/dj/martha/db/1a/db1a7e31eaf1fee3dbbcab3c97e4585935b5a893-72.wav": audio/x-wav!
2023/08/11 03:17:34 [single:4] Queued 1 requests

Warblefly commented 11 months ago

Have just added to #3334 because it may be that #3334 is repaired, but this issue #3181 could be persisting. Here's my note on #3334.

Using Liquidsoap 2.2.1+git@de9dc76e1 (the last commit to rolling-release-v2.2.x)

Music crossfades from the playlist are still ok after 12 hours.

But the problem with inserted files, via the request mechanism over telnet, persists.

(Edit: I'll mention #3181 because this might be the problem in question.)

An incoming inserted file plays over the last second or so of the outgoing music (before the liq_cross_duration would allow the next track in version 2.1.4).

Then, after the inserted file, the last second of the previous outgoing file (from the playlist) plays, then the playlist's next track starts.

Thank you for looking into this problem.

Here's the log from around that time.

The track "Gabriella's Gavotte" by John Dankworth had its last few notes crashed by the inserted 'cbsnews.mka'.

After the news, the playout returned to the (almost silent) last second of the John Dankworth track. Then, without any overlap, just a silence, the Bob Dylan track began.

The "cbsnews.mka" is the inserted track via the telnet request mechanism.

2023/08/31 08:44:29 [crossfade:4] After : ("longtail", "False")
2023/08/31 08:44:29 [crossfade:4] After : ("on_air_timestamp", "1693467869.00")
2023/08/31 08:44:29 [crossfade:4] After : ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:44:29 [crossfade:4] After : ("artist", "John Dankworth")
2023/08/31 08:44:29 [crossfade:4] After : ("decoder", "ffmpeg")
2023/08/31 08:44:29 [crossfade:4] After : ("liq_cross_duration", "3.260")
2023/08/31 08:44:29 [crossfade:4] After : ("title", "Gabriella's Gavotte")
2023/08/31 08:44:29 [crossfade:4] After : ("liq_cue_in", "0.000")
2023/08/31 08:44:29 [crossfade:4] After : ("filename", "/home/john/src/radio/mez3/gabriellas-gavotte-dankworth-anpm.e8fdf39bfeb3a03ef0360c7bf40e63ab.mka")
2023/08/31 08:44:29 [crossfade:4] After : ("temporary", "false")
2023/08/31 08:44:29 [crossfade:4] After : ("source", "bc2-30DEC2020-complete_m3u8")
2023/08/31 08:44:29 [crossfade:4] After : ("initial_uri", "annotate:liq_cue_in=\"0.000\",liq_cross_duration=\"3.260\",duration=\"229.460\",liq_amplify=\"-4.900dB\":/home/john/src/radio/mez3/gabriellas-gavotte-dankworth-anpm.e8fdf39bfeb3a03ef0360c7bf40e63ab.mka")
2023/08/31 08:44:29 [crossfade:4] After : ("encoder", "Lavf58.49.100")
2023/08/31 08:44:29 [crossfade:4] After : ("status", "playing")
2023/08/31 08:44:29 [crossfade:4] After : ("on_air", "2023/08/31 08:44:29")
2023/08/31 08:44:29 [crossfade:4] After : ("loudness", "-18.100")
2023/08/31 08:44:29 [crossfade:4] After : ("rid", "145")
2023/08/31 08:44:29 [crossfade:4] After : ("duration", "229.460")
2023/08/31 08:44:29 [crossfade:4] After : ("liq_amplify", "-4.900dB")
2023/08/31 08:44:29 [crossfade:3] Simple transition: crossed, fade-in, fade-out.
2023/08/31 08:44:29 [source:4] Source source.437 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source.437:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source audio.add.143 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [audio.add.143:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source fade_in.286 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [fade_in.286:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source fade_in.285 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [fade_in.285:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_track.572 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_track.572:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_metadata.286 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_metadata.286:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_track.571 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_track.571:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source cross_after.143 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [cross_after.143:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source buffer.286 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [buffer.286:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source fade_out.286 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [fade_out.286:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source fade_out.285 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [fade_out.285:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_end.143 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_end.143:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_track.570 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_track.570:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_metadata.285 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_metadata.285:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source on_track.569 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [on_track.569:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source cross_before.143 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [cross_before.143:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [source:4] Source buffer.285 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:44:29 [buffer.285:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:44:29 [cross_after.143:4] Fading in with type: sin and duration: 0.s.
2023/08/31 08:44:39 [buffer.285:4] End of track.
2023/08/31 08:44:39 [buffer.285:4] Buffer emptied, buffering needed.
2023/08/31 08:44:39 [cross_before.143:4] Fading out with type sin, duration: 0. and 0.s remaining.
2023/08/31 08:44:39 [buffer.286:4] End of track.
2023/08/31 08:44:39 [buffer.286:4] Buffer emptied, buffering needed.
2023/08/31 08:44:39 [source:4] Source source.437 gets down.
2023/08/31 08:44:39 [source:4] Source audio.add.143 gets down.
2023/08/31 08:44:39 [source:4] Source fade_in.286 gets down.
2023/08/31 08:44:39 [source:4] Source fade_in.285 gets down.
2023/08/31 08:44:39 [source:4] Source on_track.572 gets down.
2023/08/31 08:44:39 [source:4] Source on_metadata.286 gets down.
2023/08/31 08:44:39 [source:4] Source on_track.571 gets down.
2023/08/31 08:44:39 [source:4] Source cross_after.143 gets down.
2023/08/31 08:44:39 [source:4] Source buffer.286 gets down.
2023/08/31 08:44:39 [source:4] Source fade_out.286 gets down.
2023/08/31 08:44:39 [source:4] Source fade_out.285 gets down.
2023/08/31 08:44:39 [source:4] Source on_end.143 gets down.
2023/08/31 08:44:39 [source:4] Source on_track.570 gets down.
2023/08/31 08:44:39 [source:4] Source on_metadata.285 gets down.
2023/08/31 08:44:39 [source:4] Source on_track.569 gets down.
2023/08/31 08:44:39 [source:4] Source cross_before.143 gets down.
2023/08/31 08:44:39 [source:4] Source buffer.285 gets down.
2023/08/31 08:44:39 [cross:4] Buffering end of track...
2023/08/31 08:44:39 [cross:4] More buffering will be needed.
2023/08/31 08:48:01 [override:4] Pushing <request(id=147)> on the queue.
2023/08/31 08:48:01 [decoder:4] Available decoders: ffmpeg (priority: 10)
2023/08/31 08:48:01 [decoder:4] Trying decoder "ffmpeg"
2023/08/31 08:48:01 [decoder.ffmpeg:3] Requested content-type for "/home/john/src/radio/cbsnews.mka": {audio=pcm(stereo)}
2023/08/31 08:48:01 [decoder.ffmpeg:3] FFmpeg recognizes "/home/john/src/radio/cbsnews.mka" as audio: {codec: aac, 48000Hz, 2 channel(s)}
2023/08/31 08:48:01 [decoder.ffmpeg:3] Decoded content-type for "/home/john/src/radio/cbsnews.mka": {audio=pcm(stereo)}
2023/08/31 08:48:01 [decoder:4] Selected decoder ffmpeg for file "/home/john/src/radio/cbsnews.mka" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/31 08:48:01 [override:4] Queued 1 requests
2023/08/31 08:48:14 [decoder:2] Decoding "/home/john/src/radio/mez3/gabriellas-gavotte-dankworth-anpm.e8fdf39bfeb3a03ef0360c7bf40e63ab.mka" ended: Ffmpeg_decoder.End_of_file.
2023/08/31 08:48:14 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 827, characters 12-29
2023/08/31 08:48:14 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/31 08:48:14 [decoder:4]
2023/08/31 08:48:15 [bc2-30DEC2020-complete_m3u8:4] Finished with "/home/john/src/radio/mez3/gabriellas-gavotte-dankworth-anpm.e8fdf39bfeb3a03ef0360c7bf40e63ab.mka".
2023/08/31 08:48:15 [bc2-30DEC2020-complete_m3u8:4] Remaining 0 requests
2023/08/31 08:48:15 [bc2-30DEC2020-complete_m3u8:3] Prepared "/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka" (RID 146).
2023/08/31 08:48:15 [amplify.2:4] End of the current overriding.
2023/08/31 08:48:15 [override:4] Remaining 0 requests
2023/08/31 08:48:15 [override:3] Prepared "/home/john/src/radio/cbsnews.mka" (RID 147).
2023/08/31 08:48:15 [switch:3] Switch to override with forgetful transition.
2023/08/31 08:48:15 [source:4] Source replay_metadata.320 gets down.
2023/08/31 08:48:15 [source:4] Source replay_metadata.329 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [replay_metadata.329:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [cross:4] Setting crossfade duration to 30.00s
2023/08/31 08:48:15 [cross:4] Overriding crossfade duration from metadata liq_cross_duration
2023/08/31 08:48:15 [cross:4] Setting crossfade duration to 0.40s
2023/08/31 08:48:15 [cross:3] Analysis: -25.557754dB / -26.420486dB (3.26s / 3.30s)
2023/08/31 08:48:15 [crossfade:4] Before: ("longtail", "False")
2023/08/31 08:48:15 [crossfade:4] Before: ("on_air_timestamp", "1693467869.00")
2023/08/31 08:48:15 [crossfade:4] Before: ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:48:15 [crossfade:4] Before: ("artist", "John Dankworth")
2023/08/31 08:48:15 [crossfade:4] Before: ("decoder", "ffmpeg")
2023/08/31 08:48:15 [crossfade:4] Before: ("liq_cross_duration", "3.260")
2023/08/31 08:48:15 [crossfade:4] Before: ("title", "Gabriella's Gavotte")
2023/08/31 08:48:15 [crossfade:4] Before: ("liq_cue_in", "0.000")
2023/08/31 08:48:15 [crossfade:4] Before: ("filename", "/home/john/src/radio/mez3/gabriellas-gavotte-dankworth-anpm.e8fdf39bfeb3a03ef0360c7bf40e63ab.mka")
2023/08/31 08:48:15 [crossfade:4] Before: ("temporary", "false")
2023/08/31 08:48:15 [crossfade:4] Before: ("source", "bc2-30DEC2020-complete_m3u8")
2023/08/31 08:48:15 [crossfade:4] Before: ("initial_uri", "annotate:liq_cue_in=\"0.000\",liq_cross_duration=\"3.260\",duration=\"229.460\",liq_amplify=\"-4.900dB\":/home/john/src/radio/mez3/gabriellas-gavotte-dankworth-anpm.e8fdf39bfeb3a03ef0360c7bf40e63ab.mka")
2023/08/31 08:48:15 [crossfade:4] Before: ("encoder", "Lavf58.49.100")
2023/08/31 08:48:15 [crossfade:4] Before: ("status", "playing")
2023/08/31 08:48:15 [crossfade:4] Before: ("on_air", "2023/08/31 08:44:29")
2023/08/31 08:48:15 [crossfade:4] Before: ("loudness", "-18.100")
2023/08/31 08:48:15 [crossfade:4] Before: ("rid", "145")
2023/08/31 08:48:15 [crossfade:4] Before: ("duration", "229.460")
2023/08/31 08:48:15 [crossfade:4] Before: ("liq_amplify", "-4.900dB")
2023/08/31 08:48:15 [crossfade:4] After : ("on_air_timestamp", "1693468095.00")
2023/08/31 08:48:15 [crossfade:4] After : ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:48:15 [crossfade:4] After : ("artist", "CBS")
2023/08/31 08:48:15 [crossfade:4] After : ("decoder", "ffmpeg")
2023/08/31 08:48:15 [crossfade:4] After : ("liq_cross_duration", "0.4")
2023/08/31 08:48:15 [crossfade:4] After : ("title", "CBS Radio News")
2023/08/31 08:48:15 [crossfade:4] After : ("filename", "/home/john/src/radio/cbsnews.mka")
2023/08/31 08:48:15 [crossfade:4] After : ("temporary", "false")
2023/08/31 08:48:15 [crossfade:4] After : ("source", "override")
2023/08/31 08:48:15 [crossfade:4] After : ("initial_uri", "annotate:liq_fade_in=\"0.0\",liq_fade_out=\"0.0\",liq_cross_duration=\"0.4\",title=\"CBS Radio News\",artist=\"CBS\":/home/john/src/radio/cbsnews.mka")
2023/08/31 08:48:15 [crossfade:4] After : ("liq_fade_out", "0.0")
2023/08/31 08:48:15 [crossfade:4] After : ("encoder", "Lavc60.23.100 libfdk_aac")
2023/08/31 08:48:15 [crossfade:4] After : ("status", "playing")
2023/08/31 08:48:15 [crossfade:4] After : ("on_air", "2023/08/31 08:48:15")
2023/08/31 08:48:15 [crossfade:4] After : ("liq_fade_in", "0.0")
2023/08/31 08:48:15 [crossfade:4] After : ("rid", "147")
2023/08/31 08:48:15 [crossfade:4] After : ("duration", "00:02:47.099000000")
2023/08/31 08:48:15 [crossfade:3] Simple transition: crossed, fade-in, fade-out.
2023/08/31 08:48:15 [source:4] Source source.440 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source.440:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source audio.add.144 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [audio.add.144:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source fade_in.288 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [fade_in.288:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source fade_in.287 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [fade_in.287:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_track.576 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_track.576:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_metadata.288 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_metadata.288:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_track.575 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_track.575:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source cross_after.144 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [cross_after.144:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source buffer.288 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [buffer.288:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source fade_out.288 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [fade_out.288:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source fade_out.287 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [fade_out.287:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_end.144 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_end.144:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_track.574 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_track.574:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_metadata.287 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_metadata.287:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source on_track.573 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [on_track.573:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source cross_before.144 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [cross_before.144:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [source:4] Source buffer.287 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:48:15 [buffer.287:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:48:15 [cross_after.144:4] New fade duration: 0.s.
2023/08/31 08:48:15 [cross_after.144:4] Fading in with type: sin and duration: 0.s.
2023/08/31 08:48:17 [buffer.287:4] End of track.
2023/08/31 08:48:17 [buffer.287:4] Buffer emptied, buffering needed.
2023/08/31 08:48:17 [cross_before.144:4] Fading out with type sin, duration: 0. and 0.s remaining.
2023/08/31 08:48:18 [buffer.288:4] End of track.
2023/08/31 08:48:18 [buffer.288:4] Buffer emptied, buffering needed.
2023/08/31 08:48:18 [source:4] Source source.440 gets down.
2023/08/31 08:48:18 [source:4] Source audio.add.144 gets down.
2023/08/31 08:48:18 [source:4] Source fade_in.288 gets down.
2023/08/31 08:48:18 [source:4] Source fade_in.287 gets down.
2023/08/31 08:48:18 [source:4] Source on_track.576 gets down.
2023/08/31 08:48:18 [source:4] Source on_metadata.288 gets down.
2023/08/31 08:48:18 [source:4] Source on_track.575 gets down.
2023/08/31 08:48:18 [source:4] Source cross_after.144 gets down.
2023/08/31 08:48:18 [source:4] Source buffer.288 gets down.
2023/08/31 08:48:18 [source:4] Source fade_out.288 gets down.
2023/08/31 08:48:18 [source:4] Source fade_out.287 gets down.
2023/08/31 08:48:18 [source:4] Source on_end.144 gets down.
2023/08/31 08:48:18 [source:4] Source on_track.574 gets down.
2023/08/31 08:48:18 [source:4] Source on_metadata.287 gets down.
2023/08/31 08:48:18 [source:4] Source on_track.573 gets down.
2023/08/31 08:48:18 [source:4] Source cross_before.144 gets down.
2023/08/31 08:48:18 [source:4] Source buffer.287 gets down.
2023/08/31 08:48:18 [cross:4] Buffering end of track...
2023/08/31 08:48:18 [cross:4] More buffering will be needed.
[aac @ 0x7f3f28e1be00] Could not update timestamps for discarded samples.
2023/08/31 08:51:01 [decoder:2] Decoding "/home/john/src/radio/cbsnews.mka" ended: Ffmpeg_decoder.End_of_file.
2023/08/31 08:51:01 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 827, characters 12-29
2023/08/31 08:51:01 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/31 08:51:01 [decoder:4]
2023/08/31 08:51:01 [override:4] Finished with "/home/john/src/radio/cbsnews.mka".
2023/08/31 08:51:01 [switch:3] Switch to amplify.3 with forgetful transition.
2023/08/31 08:51:01 [source:4] Source replay_metadata.329 gets down.
2023/08/31 08:51:01 [source:4] Source replay_metadata.332 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [replay_metadata.332:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [cross:4] Setting crossfade duration to 30.00s
2023/08/31 08:51:01 [cue_cut:4] Cue points : none / none
2023/08/31 08:51:01 [cue_cut:3] Cueing in...
2023/08/31 08:51:01 [amplify.2:4] Overriding amplification: 0.254097.
2023/08/31 08:51:01 [cross:4] Overriding crossfade duration from metadata liq_cross_duration
2023/08/31 08:51:01 [cross:4] Setting crossfade duration to 7.69s
2023/08/31 08:51:01 [decoder:4] Available decoders: ffmpeg (priority: 10)
2023/08/31 08:51:01 [decoder:4] Trying decoder "ffmpeg"
2023/08/31 08:51:01 [cross:3] Analysis: -29.538248dB / -71.397456dB (0.40s / 0.40s)
2023/08/31 08:51:01 [crossfade:4] Before: ("on_air_timestamp", "1693468095.00")
2023/08/31 08:51:01 [crossfade:4] Before: ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:51:01 [crossfade:4] Before: ("artist", "CBS")
2023/08/31 08:51:01 [crossfade:4] Before: ("decoder", "ffmpeg")
2023/08/31 08:51:01 [crossfade:4] Before: ("liq_cross_duration", "0.4")
2023/08/31 08:51:01 [crossfade:4] Before: ("title", "CBS Radio News")
2023/08/31 08:51:01 [crossfade:4] Before: ("filename", "/home/john/src/radio/cbsnews.mka")
2023/08/31 08:51:01 [crossfade:4] Before: ("temporary", "false")
2023/08/31 08:51:01 [crossfade:4] Before: ("source", "override")
2023/08/31 08:51:01 [decoder.ffmpeg:3] Requested content-type for "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka": {audio=pcm(stereo)}
2023/08/31 08:51:01 [crossfade:4] Before: ("initial_uri", "annotate:liq_fade_in=\"0.0\",liq_fade_out=\"0.0\",liq_cross_duration=\"0.4\",title=\"CBS Radio News\",artist=\"CBS\":/home/john/src/radio/cbsnews.mka")
2023/08/31 08:51:01 [decoder.ffmpeg:3] FFmpeg recognizes "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/08/31 08:51:01 [crossfade:4] Before: ("liq_fade_out", "0.0")
2023/08/31 08:51:01 [decoder.ffmpeg:3] Decoded content-type for "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka": {audio=pcm(stereo)}
2023/08/31 08:51:01 [crossfade:4] Before: ("encoder", "Lavc60.23.100 libfdk_aac")
2023/08/31 08:51:01 [crossfade:4] Before: ("status", "playing")
2023/08/31 08:51:01 [decoder:4] Selected decoder ffmpeg for file "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/31 08:51:01 [crossfade:4] Before: ("on_air", "2023/08/31 08:48:15")
2023/08/31 08:51:01 [bc2-30DEC2020-complete_m3u8:4] Queued 1 requests
2023/08/31 08:51:01 [crossfade:4] Before: ("liq_fade_in", "0.0")
2023/08/31 08:51:01 [crossfade:4] Before: ("rid", "147")
2023/08/31 08:51:01 [crossfade:4] Before: ("duration", "00:02:47.099000000")
2023/08/31 08:51:01 [crossfade:4] After : ("replaygain_track_peak", "0.974642")
2023/08/31 08:51:01 [crossfade:4] After : ("album", "Music & Photos")
2023/08/31 08:51:01 [crossfade:4] After : ("longtail", "False")
2023/08/31 08:51:01 [crossfade:4] After : ("date", "2013")
2023/08/31 08:51:01 [crossfade:4] After : ("disc", "1/1")
2023/08/31 08:51:01 [crossfade:4] After : ("on_air_timestamp", "1693468261.00")
2023/08/31 08:51:01 [crossfade:4] After : ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:51:01 [crossfade:4] After : ("artist", "Bob Dylan")
2023/08/31 08:51:01 [crossfade:4] After : ("decoder", "ffmpeg")
2023/08/31 08:51:01 [crossfade:4] After : ("liq_cross_duration", "7.690")
2023/08/31 08:51:01 [crossfade:4] After : ("title", "Sub Terranean Homesick Blues")
2023/08/31 08:51:01 [crossfade:4] After : ("liq_cue_in", "0.000")
2023/08/31 08:51:01 [crossfade:4] After : ("filename", "/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka")
2023/08/31 08:51:01 [crossfade:4] After : ("temporary", "false")
2023/08/31 08:51:01 [crossfade:4] After : ("source", "bc2-30DEC2020-complete_m3u8")
2023/08/31 08:51:01 [crossfade:4] After : ("tracknumber", "08/21")
2023/08/31 08:51:01 [crossfade:4] After : ("initial_uri", "annotate:liq_cue_in=\"0.000\",liq_cross_duration=\"7.690\",duration=\"139.090\",liq_amplify=\"-11.900dB\":/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka")
2023/08/31 08:51:01 [crossfade:4] After : ("encoder", "LAME3.99r")
2023/08/31 08:51:01 [crossfade:4] After : ("status", "playing")
2023/08/31 08:51:01 [crossfade:4] After : ("replaygain_track_gain", "-6.94 dB")
2023/08/31 08:51:01 [crossfade:4] After : ("tbpm", "85.94")
2023/08/31 08:51:01 [crossfade:4] After : ("on_air", "2023/08/31 08:51:01")
2023/08/31 08:51:01 [crossfade:4] After : ("loudness", "-11.100")
2023/08/31 08:51:01 [crossfade:4] After : ("rid", "146")
2023/08/31 08:51:01 [crossfade:4] After : ("genre", "Folk")
2023/08/31 08:51:01 [crossfade:4] After : ("duration", "139.090")
2023/08/31 08:51:01 [crossfade:4] After : ("album_artist", "Bob Dylan")
2023/08/31 08:51:01 [crossfade:4] After : ("liq_amplify", "-11.900dB")
2023/08/31 08:51:01 [crossfade:3] Simple transition: crossed, fade-in, fade-out.
2023/08/31 08:51:01 [source:4] Source source.443 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source.443:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source audio.add.145 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [audio.add.145:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source fade_in.290 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [fade_in.290:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source fade_in.289 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [fade_in.289:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_track.580 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_track.580:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_metadata.290 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_metadata.290:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source fade_in.289 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [fade_in.289:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_track.580 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_track.580:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_metadata.290 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_metadata.290:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_track.579 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_track.579:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source cross_after.145 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [cross_after.145:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source buffer.290 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [buffer.290:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source fade_out.290 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [fade_out.290:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source fade_out.289 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [fade_out.289:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_end.145 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_end.145:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_track.578 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_track.578:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_metadata.289 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_metadata.289:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source on_track.577 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [on_track.577:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source cross_before.145 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [cross_before.145:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [source:4] Source buffer.289 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:51:01 [buffer.289:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:51:01 [cross_before.145:4] New fade duration: 0.s.
2023/08/31 08:51:01 [cross_after.145:4] Fading in with type: sin and duration: 0.s.
2023/08/31 08:51:01 [buffer.289:4] End of track.
2023/08/31 08:51:01 [buffer.289:4] Buffer emptied, buffering needed.
2023/08/31 08:51:01 [cross_before.145:4] Fading out with type sin, duration: 0. and 0.s remaining.
2023/08/31 08:51:01 [buffer.290:4] End of track.
2023/08/31 08:51:01 [buffer.290:4] Buffer emptied, buffering needed.
2023/08/31 08:51:01 [source:4] Source source.443 gets down.
2023/08/31 08:51:01 [source:4] Source audio.add.145 gets down.
2023/08/31 08:51:01 [source:4] Source fade_in.290 gets down.
2023/08/31 08:51:01 [source:4] Source fade_in.289 gets down.
2023/08/31 08:51:01 [source:4] Source on_track.580 gets down.
2023/08/31 08:51:01 [source:4] Source on_metadata.290 gets down.
2023/08/31 08:51:01 [source:4] Source on_track.579 gets down.
2023/08/31 08:51:01 [source:4] Source cross_after.145 gets down.
2023/08/31 08:51:01 [source:4] Source buffer.290 gets down.
2023/08/31 08:51:01 [source:4] Source fade_out.290 gets down.
2023/08/31 08:51:01 [source:4] Source fade_out.289 gets down.
2023/08/31 08:51:01 [source:4] Source on_end.145 gets down.
2023/08/31 08:51:01 [source:4] Source on_track.578 gets down.
2023/08/31 08:51:01 [source:4] Source on_metadata.289 gets down.
2023/08/31 08:51:01 [source:4] Source on_end.145 gets down.
2023/08/31 08:51:01 [source:4] Source on_track.578 gets down.
2023/08/31 08:51:01 [source:4] Source on_metadata.289 gets down.
2023/08/31 08:51:01 [source:4] Source on_track.577 gets down.
2023/08/31 08:51:01 [source:4] Source cross_before.145 gets down.
2023/08/31 08:51:01 [source:4] Source buffer.289 gets down.
2023/08/31 08:51:01 [cross:4] Buffering end of track...
2023/08/31 08:51:02 [cross:4] More buffering will be needed.
[mp3float @ 0x7f3f2816fc80] Could not update timestamps for discarded samples.
2023/08/31 08:53:12 [decoder:2] Decoding "/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka" ended: Ffmpeg_decoder.End_of_file.
2023/08/31 08:53:12 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 827, characters 12-29
2023/08/31 08:53:12 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/31 08:53:12 [decoder:4]
2023/08/31 08:53:13 [bc2-30DEC2020-complete_m3u8:4] Finished with "/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka".
2023/08/31 08:53:13 [bc2-30DEC2020-complete_m3u8:4] Remaining 0 requests
2023/08/31 08:53:13 [bc2-30DEC2020-complete_m3u8:3] Prepared "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka" (RID 148).
2023/08/31 08:53:13 [amplify.2:4] End of the current overriding.
2023/08/31 08:53:13 [cross:4] Setting crossfade duration to 30.00s
2023/08/31 08:53:13 [cue_cut:4] Cue points : 0.699977324263 / none
2023/08/31 08:53:13 [cue_cut:3] Cueing in...
2023/08/31 08:53:13 [decoder:4] Available decoders: ffmpeg (priority: 10)
2023/08/31 08:53:13 [decoder:4] Trying decoder "ffmpeg"
2023/08/31 08:53:13 [decoder.ffmpeg:3] Requested content-type for "/home/john/src/radio/mez3/11-runaway people.dfd215a80d1f85fdb5da3621bf615cb5.mka": {audio=pcm(stereo)}
2023/08/31 08:53:13 [decoder.ffmpeg:3] FFmpeg recognizes "/home/john/src/radio/mez3/11-runaway people.dfd215a80d1f85fdb5da3621bf615cb5.mka" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/08/31 08:53:13 [decoder.ffmpeg:3] Decoded content-type for "/home/john/src/radio/mez3/11-runaway people.dfd215a80d1f85fdb5da3621bf615cb5.mka": {audio=pcm(stereo)}
2023/08/31 08:53:13 [decoder:4] Selected decoder ffmpeg for file "/home/john/src/radio/mez3/11-runaway people.dfd215a80d1f85fdb5da3621bf615cb5.mka" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2023/08/31 08:53:13 [bc2-30DEC2020-complete_m3u8:4] Queued 1 requests
2023/08/31 08:53:13 [amplify.2:4] Overriding amplification: 0.266073.
2023/08/31 08:53:13 [cross:4] Overriding crossfade duration from metadata liq_cross_duration
2023/08/31 08:53:13 [cross:4] Setting crossfade duration to 7.44s
2023/08/31 08:53:13 [cross:3] Analysis: -52.025294dB / -97.128969dB (7.68s / 7.68s)
2023/08/31 08:53:13 [crossfade:4] Before: ("replaygain_track_peak", "0.974642")
2023/08/31 08:53:13 [crossfade:4] Before: ("album", "Music & Photos")
2023/08/31 08:53:13 [crossfade:4] Before: ("longtail", "False")
2023/08/31 08:53:13 [crossfade:4] Before: ("date", "2013")
2023/08/31 08:53:13 [crossfade:4] Before: ("disc", "1/1")
2023/08/31 08:53:13 [crossfade:4] Before: ("on_air_timestamp", "1693468261.00")
2023/08/31 08:53:13 [crossfade:4] Before: ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:53:13 [crossfade:4] Before: ("artist", "Bob Dylan")
2023/08/31 08:53:13 [crossfade:4] Before: ("decoder", "ffmpeg")
2023/08/31 08:53:13 [crossfade:4] Before: ("liq_cross_duration", "7.690")
2023/08/31 08:53:13 [crossfade:4] Before: ("title", "Sub Terranean Homesick Blues")
2023/08/31 08:53:13 [crossfade:4] Before: ("liq_cue_in", "0.000")
2023/08/31 08:53:13 [crossfade:4] Before: ("filename", "/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka")
2023/08/31 08:53:13 [crossfade:4] Before: ("temporary", "false")
2023/08/31 08:53:13 [crossfade:4] Before: ("source", "bc2-30DEC2020-complete_m3u8")
2023/08/31 08:53:13 [crossfade:4] Before: ("tracknumber", "08/21")
2023/08/31 08:53:13 [crossfade:4] Before: ("initial_uri", "annotate:liq_cue_in=\"0.000\",liq_cross_duration=\"7.690\",duration=\"139.090\",liq_amplify=\"-11.900dB\":/home/john/src/radio/mez3/08 Sub Terranean Homesick Blues.ea2c29203f11368b85997c0ef532d26f.mka")
2023/08/31 08:53:13 [crossfade:4] Before: ("encoder", "LAME3.99r")
2023/08/31 08:53:13 [crossfade:4] Before: ("status", "playing")
2023/08/31 08:53:13 [crossfade:4] Before: ("replaygain_track_gain", "-6.94 dB")
2023/08/31 08:53:13 [crossfade:4] Before: ("tbpm", "85.94")
2023/08/31 08:53:13 [crossfade:4] Before: ("on_air", "2023/08/31 08:51:01")
2023/08/31 08:53:13 [crossfade:4] Before: ("loudness", "-11.100")
2023/08/31 08:53:13 [crossfade:4] Before: ("rid", "146")
2023/08/31 08:53:13 [crossfade:4] Before: ("genre", "Folk")
2023/08/31 08:53:13 [crossfade:4] Before: ("duration", "139.090")
2023/08/31 08:53:13 [crossfade:4] Before: ("album_artist", "Bob Dylan")
2023/08/31 08:53:13 [crossfade:4] Before: ("liq_amplify", "-11.900dB")
2023/08/31 08:53:13 [crossfade:4] After : ("replaygain_track_peak", "1.056343")
2023/08/31 08:53:13 [crossfade:4] After : ("composer", "Sandy Denny")
2023/08/31 08:53:13 [crossfade:4] After : ("album", "The North Star Grassman and the Ravens")
2023/08/31 08:53:13 [crossfade:4] After : ("longtail", "False")
2023/08/31 08:53:13 [crossfade:4] After : ("date", "1971")
2023/08/31 08:53:13 [crossfade:4] After : ("disc", "1/1")
2023/08/31 08:53:13 [crossfade:4] After : ("on_air_timestamp", "1693468393.00")
2023/08/31 08:53:13 [crossfade:4] After : ("encoded_by", "dBpoweramp Release 14.2")
2023/08/31 08:53:13 [crossfade:4] After : ("kind", "{audio=pcm(stereo)}")
2023/08/31 08:53:13 [crossfade:4] After : ("artist", "Sandy Denny")
2023/08/31 08:53:13 [crossfade:4] After : ("decoder", "ffmpeg")
2023/08/31 08:53:13 [crossfade:4] After : ("accurateripdiscid", "015-001f879b-01639723-cd0d6d0f-1")
2023/08/31 08:53:13 [crossfade:4] After : ("liq_cross_duration", "7.440")
2023/08/31 08:53:13 [crossfade:4] After : ("title", "Late November")
2023/08/31 08:53:13 [crossfade:4] After : ("liq_cue_in", "0.700")
2023/08/31 08:53:13 [crossfade:4] After : ("filename", "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka")
2023/08/31 08:53:13 [crossfade:4] After : ("publisher", "Island")
2023/08/31 08:53:13 [crossfade:4] After : ("accurateripresult", "AccurateRip: Not in database   Secure: Yes   [7151F09B]")
2023/08/31 08:53:13 [crossfade:4] After : ("temporary", "false")
2023/08/31 08:53:13 [crossfade:4] After : ("source", "bc2-30DEC2020-complete_m3u8")
2023/08/31 08:53:13 [crossfade:4] After : ("tracknumber", "1/15")
2023/08/31 08:53:13 [crossfade:4] After : ("initial_uri", "annotate:liq_cue_in=\"0.700\",liq_cross_duration=\"7.440\",duration=\"271.640\",liq_amplify=\"-11.500dB\":/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka")
2023/08/31 08:53:13 [crossfade:4] After : ("catalog_#", "Universal- Records L")
2023/08/31 08:53:13 [crossfade:4] After : ("tmed", "CD (Lossless)")
2023/08/31 08:53:13 [crossfade:4] After : ("encoder", "LAME3.98r")
2023/08/31 08:53:13 [crossfade:4] After : ("status", "playing")
2023/08/31 08:53:13 [crossfade:4] After : ("replaygain_track_gain", "-6.51 dB")
2023/08/31 08:53:13 [crossfade:4] After : ("tbpm", "75.48")
2023/08/31 08:53:13 [crossfade:4] After : ("on_air", "2023/08/31 08:53:13")
2023/08/31 08:53:13 [crossfade:4] After : ("loudness", "-11.500")
2023/08/31 08:53:13 [crossfade:4] After : ("rid", "148")
2023/08/31 08:53:13 [crossfade:4] After : ("genre", "Folk")
2023/08/31 08:53:13 [crossfade:4] After : ("duration", "271.640")
2023/08/31 08:53:13 [crossfade:4] After : ("album_artist", "Sandy Denny")
2023/08/31 08:53:13 [crossfade:4] After : ("liq_amplify", "-11.500dB")
2023/08/31 08:53:13 [crossfade:3] Simple transition: crossed, fade-in, fade-out.
2023/08/31 08:53:13 [source:4] Source source.446 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source.446:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source audio.add.146 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [audio.add.146:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source fade_in.292 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [fade_in.292:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source fade_in.291 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [fade_in.291:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_track.584 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_track.584:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_metadata.292 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_metadata.292:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_track.583 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_track.583:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source cross_after.146 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [cross_after.146:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source buffer.292 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [buffer.292:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source fade_out.292 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [fade_out.292:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source fade_out.291 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [fade_out.291:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_end.146 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_end.146:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_track.582 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_track.582:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_metadata.291 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_metadata.291:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source on_track.581 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [on_track.581:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source cross_before.146 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [cross_before.146:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [source:4] Source buffer.291 gets up with content type: {audio=pcm(stereo)}.
2023/08/31 08:53:13 [buffer.291:3] Content type is {audio=pcm(stereo)}.
2023/08/31 08:53:13 [cross_after.146:4] Fading in with type: sin and duration: 0.s.
2023/08/31 08:53:20 [buffer.291:4] End of track.
2023/08/31 08:53:20 [buffer.291:4] Buffer emptied, buffering needed.
2023/08/31 08:53:20 [cross_before.146:4] Fading out with type sin, duration: 0. and 0.s remaining.
2023/08/31 08:53:21 [buffer.292:4] End of track.
2023/08/31 08:53:21 [buffer.292:4] Buffer emptied, buffering needed.
2023/08/31 08:53:21 [source:4] Source source.446 gets down.
2023/08/31 08:53:21 [source:4] Source audio.add.146 gets down.
2023/08/31 08:53:21 [source:4] Source fade_in.292 gets down.
2023/08/31 08:53:21 [source:4] Source fade_in.291 gets down.
2023/08/31 08:53:21 [source:4] Source on_track.584 gets down.
2023/08/31 08:53:21 [source:4] Source on_metadata.292 gets down.
2023/08/31 08:53:21 [source:4] Source on_track.583 gets down.
2023/08/31 08:53:21 [source:4] Source cross_after.146 gets down.
2023/08/31 08:53:21 [source:4] Source buffer.292 gets down.
2023/08/31 08:53:21 [source:4] Source fade_out.292 gets down.
2023/08/31 08:53:21 [source:4] Source fade_out.291 gets down.
2023/08/31 08:53:21 [source:4] Source on_end.146 gets down.
2023/08/31 08:53:21 [source:4] Source on_track.582 gets down.
2023/08/31 08:53:21 [source:4] Source on_metadata.291 gets down.
2023/08/31 08:53:21 [source:4] Source on_track.581 gets down.
2023/08/31 08:53:21 [source:4] Source cross_before.146 gets down.
2023/08/31 08:53:21 [source:4] Source buffer.291 gets down.
2023/08/31 08:53:21 [cross:4] Buffering end of track...
2023/08/31 08:53:21 [cross:4] More buffering will be needed.
[mp3float @ 0x7f3f2816fc80] Could not update timestamps for discarded samples.
2023/08/31 08:57:35 [decoder:2] Decoding "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka" ended: Ffmpeg_decoder.End_of_file.
2023/08/31 08:57:35 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 827, characters 12-29
2023/08/31 08:57:35 [decoder:4] Called from Decoder.mk_decoder.fill in file "src/core/decoder/decoder.ml", line 504, characters 10-31
2023/08/31 08:57:35 [decoder:4]
2023/08/31 08:57:36 [bc2-30DEC2020-complete_m3u8:4] Finished with "/home/john/src/radio/mez3/01 - Sandy Denny - Late November - 4.31.f9a474b1fd6d6da1f726da7bb20ecc98.mka".
2023/08/31 08:57:36 [bc2-30DEC2020-complete_m3u8:4] Remaining 0 requests
2023/08/31 08:57:36 [bc2-30DEC2020-complete_m3u8:3] Prepared "/home/john/src/radio/mez3/11-runaway people.dfd215a80d1f85fdb5da3621bf615cb5.mka" (RID 149).
2023/08/31 08:57:36 [amplify.2:4] End of the current overriding.
2023/08/31 08:57:36 [cross:4] Setting crossfade duration to 30.00s
2023/08/31 08:57:36 [cue_cut:4] Cue points : none / none
2023/08/31 08:57:36 [cue_cut:3] Cueing in...
2023/08/31 08:57:36 [amplify.2:4] Overriding amplification: 0.354813.
2023/08/31 08:57:36 [cross:4] Overriding crossfade duration from metadata liq_cross_duration

joe-ms commented 9 months ago

I have rewritten my tts-speaker to follow the say protocol, and with the time shift gone it all works perfectly now for my side.

toots commented 9 months ago

Awesome!

savonet / liquidsoap

2.2.0 has strange issue with source.say_metadata #3181