search

savonet / liquidsoap

Liquidsoap is a statically typed scripting general-purpose language with dedicated operators and backend for all thing media, streaming, file generation, automation, HTTP backend and more.
http://liquidsoap.info
GNU General Public License v2.0
1.41k stars 130 forks source link

Liquidsoap 2.2.2 | Video Stream High CPU #3503

Closed gAlleb closed 1 year ago

gAlleb commented 1 year ago

Hello! I've recently upgraded azuracast (latest rolling release) to accommodate liquidsoap 2.2.2. And CPU usage of Liquidsoap increased dramatically in regards of video stream and I haven't changed anything in the script. Only Video stream now consumes 70-100% of CPU. My video output is:

radio_vid = source.mux.video(video=background, radio)
output.icecast(%ffmpeg(format="mpegts", %audio(codec="aac",samplerate=44100,channels=2, b="192k",profile="aac_low"), %video(codec="libx264",g="50", maxrate="5000k",bufsize="10000k",preset="ultrafast", tune="zerolatency")),...

Average 15min load is 2.15 (with azuracast) but has been 1.2. Average liquidsoap CPU usage is 95% (with peaks to 125%) but has been no more than 55-60%. When I don't use video then CPU usage is the same as it has been in 2.2.1 — 15-20% for 2 icecast streams and an HLS.

Can't see the reason for such dramatic increase of CPU for video stream. But it is how it is.

1 2 3
toots commented 1 year ago

Hi,

Thanks for reporting, I'm gonna have a look very soon.

Couple of questions:

toots commented 1 year ago

I'm using this script to try to reproduce and cannot see a significant change in CPU yet:

background = single("./image.jpg")

radio = playlist("./audio")

radio_vid = source.mux.video(video=background, radio)

output.file(
  fallible=true,
  %ffmpeg(
    format = "mpegts",
    %audio(
      codec = "aac",
      samplerate = 44100,
      channels = 2,
      b = "192k",
      profile = "aac_low"
    ),
    %video(
      codec = "libx264",
      g = "50",
      maxrate = "5000k",
      bufsize = "10000k",
      preset = "ultrafast",
      tune = "zerolatency"
    )
  ),
  "/tmp/bla.ts",
  radio_vid
)
gAlleb commented 1 year ago

Hi @toots !

radio source is usual azuracast audio source. Here is background video source script:

def format_time(time)
    seconds = int(time mod 60.)
    seconds_string =
        if seconds < 10 then
            "0" ^ string(seconds)
        else
            string(seconds)
        end
    minutes = int(time / 60.)
    minutes_string =
        if minutes < 10 then
            "0" ^ string(minutes)
        else
            string(minutes)
        end
    minutes_string ^ ":" ^ seconds_string
end

station_dir = "/var/azuracast/stations/radio/media/youtube-stream"
myfont = station_dir ^ "/fonts/DejaVuSans.ttf"
myfont2 = station_dir ^ "/fonts/AmaticSC-Bold.ttf"

# 15 min long *.mkv videos 1280x720
video_playlist = station_dir ^ "/img/background/background_video/onair"
background = mksafe(playlist(reload_mode="watch", video_playlist))
background = video.add_rectangle(color=0x333333, alpha=0.4, x=945, y=30, width=335, height=55, background)
background = video.add_text(color=0x000000,"Radio",font=myfont2, speed=0, x=963, y=34, size=43,
background)
background = video.add_text(color=0xFCB900,"Radio",font=myfont2, speed=0, x=961, y=32, size=43,
background)
background = video.add_rectangle(color=0x333333, alpha=0.4, x=0, y=560, width=1280, height=123, background)
background = video.add_rectangle(color=0xfcb900, alpha=0.7,x=0, y=642, width=1280, height=2, background)

def percent(s)
  source.elapsed(s) / source.duration(s) * 100.0
end
px_percent = 1280.0/100.0

background = video.rectangle(color=0xfcb900, x=0, y=670, height=10, width={int(px_percent*percent(radio))}, background)

background = video.add_text(size=20, x=30, y=645, color=0xcccccc, {"Next in " ^ "#{format_time(source.remaining(radio))}"}, background) 

###### COVER ART MANAGER ######
def logger(label="lang")
    let replaces log = fun(message, ~label=label, ~level=3) -> log(message, label=label, level=level)
    let log.critical = fun(message, ~label=label) -> log.critical(message, label=label)
    let log.severe = fun(message, ~label=label) -> log.severe(message, label=label)
    let log.important = fun(message, ~label=label) -> log.important(message, label=label)
    let log.info = fun(message, ~label=label) -> log.info(message, label=label)
    let log.debug = fun(message, ~label=label) -> log.debug(message, label=label)
    log
end

def cover_files_manager(~id=null(), ~default_cover_file="", ~covers_keep=2)
    id = string.id.default(id, default="cover")
    log = logger(id)
    mime_types = [
        ("image/gif", "gif"),
        ("image/jpeg", "jpeg"),
        ("image/jpg", "jpeg"),
        ("image/png", "png"),
        ("image/webp", "webp")
    ]

    cover_files = ref([])
    current_cover_file = ref(default_cover_file)

    def remove_file(filename)
        log.info("Remove #{string.quote(filename)}")
        file.remove(filename)
    end

    def rotate_cover_files(cover_file)
        current_cover_file := cover_file
        cover_files := cover_file::cover_files()
        if list.length(cover_files()) > covers_keep then
            remove_file(list.last(cover_files()))
            cover_files := list.prefix(covers_keep, cover_files())
        end
    end

    def save_cover_to_file(cover)
        mime = cover.mime
        extension = mime_types[mime]
        log.debug("mime=#{mime}, extension=#{extension}")
        cover_file =
            if extension != "" then
                cover_file = file.temp("#{id}_", ".#{extension}")
                file.write(cover_file, data=cover)
                cover_file
            else
                null()
            end
        (cover_file, mime)
    end

    def extract_cover_from_metadata(_metadata)
        filename = _metadata["filename"]
        log.info("Extracting cover from #{string.quote(filename)}.")
        cover = metadata.cover(_metadata)
        let (cover_file, mime) = null.case(cover, {(null(), "")}, save_cover_to_file)

        if cover == null() then
            log.important("File #{string.quote(filename)} has no cover.")
            current_cover_file := default_cover_file
        elsif cover_file == null() then
            log.important("File #{string.quote(filename)} has unknown mime type \
                           #{string.quote(mime)}.")
            current_cover_file := default_cover_file
        else
            cover_file = null.get(cover_file)
            log.important("Cover for #{string.quote(filename)} saved to \
                           #{string.quote(cover_file)}.")
            rotate_cover_files(cover_file)
        end
    end

    def get_cover()
        log.debug("current_cover_file=#{current_cover_file()}")
        current_cover_file()
    end

    get_cover.{set = extract_cover_from_metadata}
end

cover_files = cover_files_manager(default_cover_file=station_dir ^ "/img/cover_default.png")
radio.on_track(cover_files.set)

background = video.add_rectangle(color=0xfcb900, x=27, y=327, height=206, width=206, background)
background = video.add_image(x=30, y=330, width=200, height=200, file=cover_files, background)

nowplaying = ref("")
nowplaying2 = ref("")
 def update_nowplaying(m)
    nowplaying.set(m["title"])
    nowplaying2.set(m["artist"])
end
radio.on_metadata(update_nowplaying)

background = video.add_text(color=0xFCB900, font=myfont, speed=0, x=30, y=568, size=30,{nowplaying()},background)
background = video.add_text(color=0xFCB900, font=myfont, speed=0, x=30, y=603, size=30,{nowplaying2()},background)

radio_vid = source.mux.video(video=background, radio)
videostream = mksafe(buffer(radio_vid))
clock.assign_new(id="video", [videostream])

output.icecast(%ffmpeg(format="mpegts",
  %audio(
    codec="aac",
    samplerate=44100,
    channels=2,
    b="192k",
    profile="aac_low"
  ),
  %video(codec="libx264",g="50",
    maxrate="7500k",bufsize="15000k",
    preset="ultrafast", tune="zerolatency")),
   , ... videostream)

Some startup logs

2023/11/06 09:15:30 >>> LOG START
2023/11/06 09:15:23 [main:3] Liquidsoap 2.2.2
2023/11/06 09:15:23 [main:3] Using: alsa=0.3.0 angstrom=0.15.0 ao=0.2.4 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 bjack=0.1.6 bos=0.2.1 bytes=[distributed with OCaml] ca-certs=v0.2.3 camlimages.all_formats=4.2.6 camlimages.core=5.0.4 camlimages.exif=5.0.4 camlimages.gif=5.0.4 camlimages.jpeg=5.0.4 camlimages.png=5.0.4 camlimages.tiff=5.0.4 camlimages.xpm=5.0.4 camlp-streams camomile.lib=2.0 cohttp=5.1.0 cohttp-lwt=5.1.0 cohttp-lwt-unix=5.1.0 conduit=6.2.0 conduit-lwt=6.2.0 conduit-lwt-unix=6.2.0 cry=1.0.2 cstruct=6.2.0 ctypes=0.20.2 ctypes.foreign=0.20.2 ctypes.stubs=0.20.2 curl=0.9.2 domain-name=0.4.0 dssi=0.1.5 dtools=0.4.5 dune-build-info=3.8.2 dune-private-libs.dune-section=3.8.2 dune-site=3.8.2 dune-site.private=3.8.2 duppy=0.9.3 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 faad=0.5.2 fdkaac=0.3.3 ffmpeg-av=1.1.9 ffmpeg-avcodec=1.1.9 ffmpeg-avdevice=1.1.9 ffmpeg-avfilter=1.1.9 ffmpeg-avutil=1.1.9 ffmpeg-swresample=1.1.9 ffmpeg-swscale=1.1.9 fileutils=0.6.4 flac=0.5.0 flac.decoder=0.5.0 flac.ogg=0.5.0 fmt=0.9.0 fpath=0.7.3 frei0r=0.1.2 gd=1.0a5 gen=1.1 gmap=0.3.0 hkdf=1.0.4 inotify=2.4.1 integers ipaddr=5.5.0 ipaddr-sexp=5.5.0 ipaddr.unix=5.5.0 irc-client irc-client-unix jemalloc ladspa=0.2.2 lame=0.3.7 lastfm=0.3.3 lilv=0.1.0 liquidsoap-lang=2.2.2 liquidsoap-lang.console=2.2.2 liquidsoap_alsa=v2.2.2-1-g93f305b liquidsoap_ao=v2.2.2-1-g93f305b liquidsoap_bjack=v2.2.2-1-g93f305b liquidsoap_builtins=v2.2.2-1-g93f305b liquidsoap_camlimages=v2.2.2-1-g93f305b liquidsoap_core=v2.2.2-1-g93f305b liquidsoap_dssi=v2.2.2-1-g93f305b liquidsoap_faad=v2.2.2-1-g93f305b liquidsoap_fdkaac=v2.2.2-1-g93f305b liquidsoap_ffmpeg=v2.2.2-1-g93f305b liquidsoap_flac=v2.2.2-1-g93f305b liquidsoap_frei0r=v2.2.2-1-g93f305b liquidsoap_gd=v2.2.2-1-g93f305b liquidsoap_irc=v2.2.2-1-g93f305b liquidsoap_jemalloc=v2.2.2-1-g93f305b liquidsoap_ladspa=v2.2.2-1-g93f305b liquidsoap_lame=v2.2.2-1-g93f305b liquidsoap_lastfm=v2.2.2-1-g93f305b liquidsoap_lilv=v2.2.2-1-g93f305b liquidsoap_lo=v2.2.2-1-g93f305b liquidsoap_mad=v2.2.2-1-g93f305b liquidsoap_magic=v2.2.2-1-g93f305b liquidsoap_mem_usage=v2.2.2-1-g93f305b liquidsoap_memtrace=v2.2.2-1-g93f305b liquidsoap_ogg=v2.2.2-1-g93f305b liquidsoap_ogg_flac=v2.2.2-1-g93f305b liquidsoap_optionals=v2.2.2-1-g93f305b liquidsoap_opus=v2.2.2-1-g93f305b liquidsoap_osc=v2.2.2-1-g93f305b liquidsoap_oss=v2.2.2-1-g93f305b liquidsoap_portaudio=v2.2.2-1-g93f305b liquidsoap_posix_time=v2.2.2-1-g93f305b liquidsoap_prometheus=v2.2.2-1-g93f305b liquidsoap_pulseaudio=v2.2.2-1-g93f305b liquidsoap_runtime=v2.2.2-1-g93f305b liquidsoap_samplerate=v2.2.2-1-g93f305b liquidsoap_sdl=v2.2.2-1-g93f305b liquidsoap_shine=v2.2.2-1-g93f305b liquidsoap_soundtouch=v2.2.2-1-g93f305b liquidsoap_speex=v2.2.2-1-g93f305b liquidsoap_srt=v2.2.2-1-g93f305b liquidsoap_ssl=v2.2.2-1-g93f305b liquidsoap_stereotool=v2.2.2-1-g93f305b liquidsoap_taglib=v2.2.2-1-g93f305b liquidsoap_theora=v2.2.2-1-g93f305b liquidsoap_tls=v2.2.2-1-g93f305b liquidsoap_vorbis=v2.2.2-1-g93f305b liquidsoap_xmlplaylist=v2.2.2-1-g93f305b liquidsoap_yaml=v2.2.2-1-g93f305b lo=0.2.0 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.3 magic=0.7.3 magic-mime=1.3.0 mem_usage=0.0.4 memtrace=0.2.3 menhirLib=20230608 metadata=0.2.0 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=0.2.3 opus.decoder=0.2.3 osc osc-unix parsexp=v0.16.0 pbkdf pcre=7.5.0 portaudio=0.2.3 posix-base=b516d46 posix-socket=b516d46 posix-socket.constants=b516d46 posix-socket.stubs=b516d46 posix-socket.types=b516d46 posix-time2=b516d46 posix-time2.constants=b516d46 posix-time2.stubs=b516d46 posix-time2.types=b516d46 posix-types=b516d46 posix-types.constants=b516d46 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 pulseaudio=0.1.6 re=1.10.4 result=1.5 rresult=0.7.0 samplerate=0.1.7 sedlex=a1362bd seq=[distributed with OCaml 4.07 or above] sexplib=v0.16.0 sexplib0=v0.16.0 shine=0.2.3 soundtouch=0.1.9 speex=0.4.2 speex.decoder=0.4.2 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.2-1-g93f305b str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 theora=0.4.1 theora.decoder=0.4.1 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] tls=0.17.0 tsdl=v1.0.0 tsdl-image=0.5 tsdl-ttf=0.5 unix=[distributed with OCaml] unix-errno=52c6ecb unix-errno.errno_bindings=52c6ecb unix-errno.errno_types=52c6ecb unix-errno.errno_types_detected=52c6ecb unix-errno.unix=52c6ecb uri=4.2.0 uri-sexp=4.2.0 uri.services=4.2.0 vorbis=0.8.1 vorbis.decoder=0.8.1 x509=0.16.4 xmlm=1.4.0 xmlplaylist=0.1.5 yaml=3.1.0 yaml.bindings=3.1.0 yaml.bindings.types=3.1.0 yaml.c=3.1.0 yaml.ffi=3.1.0 yaml.types=3.1.0 zarith=1.12
2023/11/06 09:15:23 [clock:3] Using native (high-precision) implementation for latency control
2023/11/06 09:15:29 [main:3] Standard library loaded in 5.81 seconds.
2023/11/06 09:15:29 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2023/11/06 09:15:29 [frame:3] Video frame size set to: 1280x720
2023/11/06 09:15:29 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2023/11/06 09:15:29 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2023/11/06 09:15:29 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2023/11/06 09:15:30 [sandbox:3] Sandboxing disabled
2023/11/06 09:15:30 [startup:3] DSSI plugins registration: 0.00s
2023/11/06 09:15:30 [startup:3] FFmpeg filters registration: 0.02s
2023/11/06 09:15:30 [startup:3] FFmpeg bitstream filters registration: 0.00s
2023/11/06 09:15:30 [startup:3] Lilv plugins registration: 0.01s
2023/11/06 09:15:30 [startup:3] Frei0r plugin registration: 0.00s
2023/11/06 09:15:30 [startup:3] LADSPA plugins registration: 0.06s
2023/11/06 09:15:30 [startup:3] Typechecking: 5.39s
2023/11/06 09:15:30 [startup:3] Evaluation: 0.02s
2023/11/06 09:15:30 [startup:3] Typechecking: 0.05s
2023/11/06 09:15:30 [startup:3] Evaluation: 0.00s
2023/11/06 09:15:30 [startup:3] Typechecking: 0.10s
2023/11/06 09:15:30 [startup:3] Evaluation: 0.30s
2023/11/06 09:15:30 [startup:3] Loaded /var/azuracast/stations/radio/config/liquidsoap.liq: 0.42s
2023/11/06 09:15:30 [videostream:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:15:30 [buffer.producer:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:15:30 [safe_blank.2:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:15:30 [clock.videostream:3] Streaming loop starts in auto-sync mode
2023/11/06 09:15:30 [clock.videostream:3] Delegating synchronization to CPU clock
2023/11/06 09:15:30 [local_1:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [metadata_map.6:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [metadata_map.5:3] Content type is {}.
2023/11/06 09:15:30 [metadata_map.4:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [metadata_map.3:3] Content type is {}.
2023/11/06 09:15:30 [custom_metadata:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cross:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [amplify:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [track_amplify:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_interrupting_requests:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [interrupting_requests:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_requests:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [requests:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_next_song:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [next_song:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [source.available:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [autodj_startup_blank:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_morning_hour:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_morning_hour:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_chill__ambient:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_chill__ambient:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_one_album_hour__monday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_one_album_hour__monday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_one_album_hour__tuesday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_one_album_hour__tuesday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_one_album_hour__wednesday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_one_album_hour__wednesday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_one_album_hour__thursday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_one_album_hour__thursday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_one_album_hour__friday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_one_album_hour__friday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_indielofi_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_indielofi_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [source:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_soft_jingle:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_soft_jingle:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_lofi_sunday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_lofi_sunday:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [delay:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [source.2:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_jingles__night:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_jingles__night:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [on_track:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [on_track.2:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [source.3:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [cue_playlist_jingles__day:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [playlist_jingles__day:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [on_track.3:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [metadata_map.2:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [metadata_map:3] Content type is {}.
2023/11/06 09:15:30 [error_jingle:3] "/usr/local/share/icecast/web/error.mp3" is static, resolving once for all...
2023/11/06 09:15:30 [mksafe.2:3] Switch to safe_blank.2.
2023/11/06 09:15:30 [decoder.ffmpeg:3] Requested content-type for "/usr/local/share/icecast/web/error.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:30 [decoder.ffmpeg:3] FFmpeg recognizes "/usr/local/share/icecast/web/error.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:30 [decoder.ffmpeg:3] Decoded content-type for "/usr/local/share/icecast/web/error.mp3": {audio=pcm(stereo)}
[libx264 @ 0x7f711065df00] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
[libx264 @ 0x7f711065df00] profile Constrained Baseline, level 3.2, 4:2:0, 8-bit
2023/11/06 09:15:30 [videostream:3] Connecting mount /video for source@127.0.0.1...
2023/11/06 09:15:30 [error_jingle:3] Prepared "/usr/local/share/icecast/web/error.mp3" (RID 15).
2023/11/06 09:15:30 [local_3:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [/var/azuracast/stations/radio/hls/live_m3u8:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:30 [buffer.consumer:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:15:30 [source.13:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:15:30 [source.11:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add.5:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [source.10:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video_add_image:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add_rectangle.5:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add_rectangle.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add_rectangle.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add_rectangle.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [source.6:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [source.5:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.add_rectangle:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [onair:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [safe_blank:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [source.available.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.translate:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.info:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.crop:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.text:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [source.available.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.translate.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.info.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.crop.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.text.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [on_frame:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [track_video_add_image.2:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.crop.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [track_video_add_image:3] "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" is static, resolving once for all...
2023/11/06 09:15:30 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
2023/11/06 09:15:30 [source.available.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.translate.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.info.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.crop.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.text.3:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [source.available.5:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.translate.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.info.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.crop.5:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.text.4:3] Content type is {video=canvas}.
2023/11/06 09:15:30 [video.converter:3] Using preferred video converter: ffmpeg.
2023/11/06 09:15:30 [audio.converter:3] Using samplerate converter: libsamplerate.
2023/11/06 09:15:30 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/06 09:15:30 [clock.main:3] Streaming loop starts in auto-sync mode
2023/11/06 09:15:30 [clock.main:3] Delegating synchronization to CPU clock
[mp3float @ 0x7f710801c000] Could not update timestamps for skipped samples.
2023/11/06 09:15:30 [safe_fallback:3] Switch to metadata_map.2.
2023/11/06 09:15:30 [local_1:3] Connecting mount /radio.mp3 for source@127.0.0.1...
2023/11/06 09:15:30 [lang:3] API nextsong - Response (200): annotate:title="Rock @ omFM",artist="Rock @ omFM",duration="6.00",song_id="481c81d184b3fbec5ca510c735915022",media_id="5869",playlist_id="11",jingle_mode="true":media:jingles/rock/day/logo2.2.mp3
[mp3 @ 0x7f71089a2000] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:30 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:30 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:30 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f71089a2000] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:30 [videostream:3] Connection setup was successful.
2023/11/06 09:15:30 [local_1:3] Connection setup was successful.
2023/11/06 09:15:30 [local_3:3] Connecting mount /radio.aac for source@127.0.0.1...
2023/11/06 09:15:30 [local_3:3] Connection setup was successful.
[mpegts @ 0x7f7131f34600] frame size not set
[mpegts @ 0x7f7131f35200] frame size not set
[mpegts @ 0x7f7131f35e00] frame size not set
2023/11/06 09:15:30 [mksafe:3] Switch to safe_blank.
[mp3 @ 0x7f710813e000] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f710813e000] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:30 [next_song:3] Prepared "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3" (RID 17).
2023/11/06 09:15:30 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
[swscaler @ 0x7f7104f6e900] Warning: dstStride is not aligned!
         ->cannot do aligned memory accesses anymore
[swscaler @ 0x7f7104f6e900] Warning: data is not aligned! This can lead to a speed loss
2023/11/06 09:15:30 [track_video_add_image:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" (RID 14).
2023/11/06 09:15:30 [safe_fallback:3] Switch to custom_metadata with transition.
2023/11/06 09:15:30 [interrupting_fallback:3] Switch to requests_fallback.
2023/11/06 09:15:30 [requests_fallback:3] Switch to autodj_fallback.
2023/11/06 09:15:30 [autodj_fallback:3] Switch to dynamic_startup.
2023/11/06 09:15:30 [dynamic_startup:3] Switch to cue_next_song.
2023/11/06 09:15:30 [cue_next_song:3] Cueing in...
2023/11/06 09:15:30 [cover:3] File "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3" has no cover.
2023/11/06 09:15:33 [clock.videostream:2] We must catchup 2.19 seconds!
2023/11/06 09:15:33 [clock.main:2] We must catchup 2.60 seconds!
2023/11/06 09:15:35 [clock.main:2] We must catchup 2.58 seconds!
2023/11/06 09:15:35 [clock.videostream:2] We must catchup 4.07 seconds!
2023/11/06 09:15:36 [clock.main:2] We must catchup 5.45 seconds!
2023/11/06 09:15:36 [clock.videostream:2] We must catchup 4.80 seconds!
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:37 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/ROCK/nightshift/Planetary Confinement/1-03 Line Of Fire.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:37 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/ROCK/nightshift/Planetary Confinement/1-03 Line Of Fire.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:37 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/ROCK/nightshift/Planetary Confinement/1-03 Line Of Fire.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:37 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Inhale - recall.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:37 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Inhale - recall.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:37 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Inhale - recall.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:37 [clock.videostream:2] We must catchup 5.58 seconds!
2023/11/06 09:15:37 [clock.main:2] We must catchup 6.28 seconds!
2023/11/06 09:15:38 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:15:38 [clock.videostream:2] We must catchup 6.14 seconds!
2023/11/06 09:15:38 [clock.main:2] We must catchup 6.89 seconds!
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:39 [clock.main:2] We must catchup 7.66 seconds!
2023/11/06 09:15:39 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:39 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:39 [clock.videostream:2] We must catchup 6.90 seconds!
2023/11/06 09:15:39 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:39 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:39 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:39 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:39 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/birp/daylight-soft-emotional-logo-119131.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/birp/daylight-soft-emotional-logo-119131.mp3" as audio: {codec: mp3, 48000Hz, 2 channel(s)}
2023/11/06 09:15:39 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/birp/daylight-soft-emotional-logo-119131.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:42 [clock.videostream:2] We must catchup 9.22 seconds!
2023/11/06 09:15:42 [clock.main:2] We must catchup 9.96 seconds!
2023/11/06 09:15:42 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Various Artists - BIRP!/Various Artists - BIRP! Best of 2022/006 - Kowloon - A Thousand Pictures.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:42 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Various Artists - BIRP!/Various Artists - BIRP! Best of 2022/006 - Kowloon - A Thousand Pictures.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x600, yuvj420p}
2023/11/06 09:15:42 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Various Artists - BIRP!/Various Artists - BIRP! Best of 2022/006 - Kowloon - A Thousand Pictures.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:43 [clock.main:2] We must catchup 10.77 seconds!
2023/11/06 09:15:43 [clock.videostream:2] We must catchup 10.00 seconds!
2023/11/06 09:15:43 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/lofi/_onair/lofi-records/VA - Cozy Winter/06 towerz x farewell - sparkler (Kupla Master).mp3": {audio=pcm(stereo)}
2023/11/06 09:15:43 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/lofi/_onair/lofi-records/VA - Cozy Winter/06 towerz x farewell - sparkler (Kupla Master).mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:43 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/lofi/_onair/lofi-records/VA - Cozy Winter/06 towerz x farewell - sparkler (Kupla Master).mp3": {audio=pcm(stereo)}
2023/11/06 09:15:44 [clock.videostream:2] We must catchup 10.67 seconds!
2023/11/06 09:15:44 [clock.main:2] We must catchup 11.53 seconds!
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:45 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:45 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:45 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:45 [clock.videostream:2] We must catchup 11.43 seconds!
[mp3 @ 0x7f7131f52600] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:45 [clock.main:2] We must catchup 12.35 seconds!
2023/11/06 09:15:47 [clock.videostream:2] We must catchup 13.68 seconds!
2023/11/06 09:15:47 [clock.main:2] We must catchup 14.66 seconds!
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:47 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:47 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:47 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7f7131f36a00] Estimating duration from bitrate, this may be inaccurate
2023/11/06 09:15:48 [clock.videostream:2] We must catchup 14.62 seconds!
2023/11/06 09:15:48 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/06 09:15:48 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" as video: {codec: h264, 1280x720, yuv420p}
2023/11/06 09:15:48 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/06 09:15:48 [clock.main:2] We must catchup 15.81 seconds!
2023/11/06 09:15:49 [decoder.taglib:2] Error while decoding file tags: Taglib.File.Invalid_file
2023/11/06 09:15:49 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Queen/1982.05.25 - Hot Space (1994. Digital Remaster EMI)/06 - Put Out The Fire.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:49 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Queen/1982.05.25 - Hot Space (1994. Digital Remaster EMI)/06 - Put Out The Fire.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x595, yuvj444p}
2023/11/06 09:15:49 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Queen/1982.05.25 - Hot Space (1994. Digital Remaster EMI)/06 - Put Out The Fire.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:49 [video.text:3] Using sdl implementation
2023/11/06 09:15:49 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/06 09:15:49 [lang:3] API nextsong - Response (200): annotate:title="new macabre",artist="russian circles",duration="318.00",song_id="28ba06fff32796459c0a1b407eff827b",media_id="8737",playlist_id="2":media:GoogleDrive_music/rock/russian circles/enter/new macabre.mp3
2023/11/06 09:15:51 [onair:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" (RID 30).
2023/11/06 09:15:51 [mksafe:3] Switch to onair with transition.
2023/11/06 09:15:51 [clock.main:2] We must catchup 17.92 seconds!
2023/11/06 09:15:51 [clock.videostream:2] We must catchup 16.92 seconds!
2023/11/06 09:15:53 [clock.videostream:2] We must catchup 18.55 seconds!
2023/11/06 09:15:54 [clock.videostream:2] We must catchup 19.23 seconds!
2023/11/06 09:15:54 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/russian circles/enter/new macabre.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:54 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/russian circles/enter/new macabre.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/06 09:15:54 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/russian circles/enter/new macabre.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:54 [clock.main:2] We must catchup 20.80 seconds!
2023/11/06 09:15:55 [clock.videostream:2] We must catchup 19.98 seconds!
2023/11/06 09:15:55 [clock.main:2] We must catchup 21.79 seconds!
2023/11/06 09:15:55 [lang:3] AutoDJ is ready!
2023/11/06 09:15:55 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/06 09:15:55 [lang:3]   "song_id": "481c81d184b3fbec5ca510c735915022",
2023/11/06 09:15:55 [lang:3]   "playlist_id": "11",
2023/11/06 09:15:55 [lang:3]   "media_id": "5869"
2023/11/06 09:15:55 [lang:3] }
2023/11/06 09:15:55 [lang:3] API feedback - Response (200): true
2023/11/06 09:15:55 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/06 09:15:55 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" as video: {codec: h264, 1280x720, yuv420p}
2023/11/06 09:15:55 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/06 09:15:56 [clock.videostream:2] We must catchup 20.73 seconds!
2023/11/06 09:15:56 [decoder.taglib:2] Error while decoding file tags: Taglib.File.Invalid_file
2023/11/06 09:15:56 [clock.main:2] We must catchup 22.77 seconds!
2023/11/06 09:15:56 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:15:56 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:15:56 [decoder:2] Decoding "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3" ended: Ffmpeg_decoder.End_of_file.
2023/11/06 09:15:57 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/russian circles/enter/new macabre.mp3" (RID 31).
[mp3float @ 0x7f710801f200] Could not update timestamps for skipped samples.
2023/11/06 09:15:57 [cue_next_song:3] Cueing in...
2023/11/06 09:15:57 [clock.videostream:2] We must catchup 19.47 seconds!
2023/11/06 09:15:57 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/06 09:15:57 [cover:3] File "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/russian circles/enter/new macabre.mp3" has no cover.
2023/11/06 09:15:57 [cross:3] Analysis: -13.900387dB / -11.332347dB (2.98s / 2.98s)
2023/11/06 09:15:57 [source.16:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [audio.add:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [lang:3] API nextsong - Response (200): annotate:title="This Punishment",artist="Katatonia",duration="166.00",song_id="996550f540bbfb84caa192832db43f8a",media_id="8480",playlist_id="2":media:GoogleDrive_music/rock/Katatonia/Tonight's Decision/1-05 This Punishment.mp3
2023/11/06 09:15:57 [fade_in:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [track_amplify.3:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [on_track.7:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [on_metadata.2:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [on_track.6:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [cross_after:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [buffer.2:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [fade_out:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:57 [track_amplify.2:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [on_end:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [on_track.5:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [on_metadata:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [on_track.4:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [cross_before:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [buffer:3] Content type is {audio=pcm(stereo)}.
2023/11/06 09:15:58 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/06 09:15:58 [lang:3]   "song_id": "28ba06fff32796459c0a1b407eff827b",
2023/11/06 09:15:58 [lang:3]   "playlist_id": "2",
2023/11/06 09:15:58 [lang:3]   "media_id": "8737"
2023/11/06 09:15:58 [lang:3] }
2023/11/06 09:15:58 [clock.videostream:2] We must catchup 20.83 seconds!
2023/11/06 09:15:58 [lang:3] API feedback - Response (200): true
2023/11/06 09:15:59 [clock.main:2] We must catchup 24.72 seconds!
2023/11/06 09:15:59 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Katatonia/Tonight's Decision/1-05 This Punishment.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:59 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Katatonia/Tonight's Decision/1-05 This Punishment.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x600, yuvj444p}
2023/11/06 09:15:59 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Katatonia/Tonight's Decision/1-05 This Punishment.mp3": {audio=pcm(stereo)}
2023/11/06 09:15:59 [clock.videostream:2] We must catchup 21.09 seconds!
2023/11/06 09:16:00 [clock.main:2] We must catchup 25.85 seconds!
2023/11/06 09:16:00 [clock.videostream:2] We must catchup 21.69 seconds!
2023/11/06 09:16:01 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:01 [replay_metadata.3:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:16:01 [clock.main:2] We must catchup 26.73 seconds!
2023/11/06 09:16:02 [clock.videostream:2] We must catchup 21.85 seconds!
2023/11/06 09:16:02 [clock.main:2] We must catchup 27.10 seconds!
2023/11/06 09:16:03 [clock.videostream:2] We must catchup 21.61 seconds!
2023/11/06 09:16:03 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:16:03 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:16:03 [clock.main:2] We must catchup 27.32 seconds!
2023/11/06 09:16:04 [clock.videostream:2] We must catchup 19.02 seconds!
2023/11/06 09:16:04 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:04 [replay_metadata.4:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:16:04 [clock.main:2] We must catchup 27.45 seconds!
2023/11/06 09:16:05 [clock.videostream:2] We must catchup 17.91 seconds!
2023/11/06 09:16:05 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:16:05 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:16:05 [clock.main:2] We must catchup 27.68 seconds!
2023/11/06 09:16:06 [clock.videostream:2] We must catchup 16.51 seconds!
2023/11/06 09:16:06 [clock.main:2] We must catchup 27.80 seconds!
2023/11/06 09:16:06 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:06 [replay_metadata.5:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:16:07 [clock.videostream:2] We must catchup 14.09 seconds!
2023/11/06 09:16:07 [clock.main:2] We must catchup 27.95 seconds!
2023/11/06 09:16:08 [clock.videostream:2] We must catchup 13.28 seconds!
2023/11/06 09:16:08 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:16:08 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:16:08 [clock.main:2] We must catchup 27.96 seconds!
2023/11/06 09:16:09 [clock.videostream:2] We must catchup 11.77 seconds!
2023/11/06 09:16:09 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:09 [replay_metadata.6:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:16:09 [clock.main:2] We must catchup 28.10 seconds!
2023/11/06 09:16:10 [clock.videostream:2] We must catchup 10.47 seconds!
2023/11/06 09:16:10 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:16:10 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:16:10 [clock.main:2] We must catchup 28.37 seconds!
2023/11/06 09:16:11 [clock.videostream:2] We must catchup 9.09 seconds!
2023/11/06 09:16:11 [clock.main:2] We must catchup 28.46 seconds!
2023/11/06 09:16:11 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:11 [replay_metadata.7:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:16:12 [clock.videostream:2] We must catchup 7.06 seconds!
2023/11/06 09:16:12 [clock.main:2] We must catchup 28.52 seconds!
2023/11/06 09:16:13 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:16:13 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:16:13 [clock.videostream:2] We must catchup 6.02 seconds!
2023/11/06 09:16:13 [clock.main:2] We must catchup 28.57 seconds!
2023/11/06 09:16:14 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:14 [replay_metadata.8:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/06 09:16:14 [clock.videostream:2] We must catchup 3.40 seconds!
2023/11/06 09:16:15 [clock.main:2] We must catchup 28.59 seconds!
2023/11/06 09:16:15 [clock.videostream:2] We must catchup 2.62 seconds!
2023/11/06 09:16:15 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/06 09:16:15 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/06 09:16:16 [clock.main:2] We must catchup 28.63 seconds!
2023/11/06 09:16:16 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/06 09:16:16 [replay_metadata.9:3] Content type is {audio=pcm(stereo),video=canvas}.
1 2 4 5
gAlleb commented 1 year ago

Have restored previous version (2.2.1) to take snapshots.

3 2 1

Probably it's a bulk of functions and video.add_*** causing this or something else.

toots commented 1 year ago

Hi! First, this script is awesome, I'm impressed. You should consider posting it to https://github.com/savonet/liquidsoap/discussions/categories/show-and-tell !

I have been able to make it work locally but I cannot observe any significant change in CPU usage in the first few minutes running.

I'm gonna let it run see if perhaps a difference does build up. Meanwhile, could you post logs with log level 4? I'd like to make sure that I'm using the same decoders are you are.

gAlleb commented 1 year ago

Hi! First, this script is awesome, I'm impressed. You should consider posting it to https://github.com/savonet/liquidsoap/discussions/categories/show-and-tell !

Hi @toots ! Thanks! But all the credit here goes to @vitoyucepi for majority of functions and @Moonbase59 for general ideas 😉

I have reinstalled the system and somehow things got a little better, at the same time liquidsoap proccess cpu sometimes spikes up to 145% (usually on track change).

INFO: Loading Sdl_image, Target = linux
INFO: Loading Sdl_ttf, Target = linux
2023/11/07 03:06:57 >>> LOG START
2023/11/07 03:06:50 [main:3] Liquidsoap 2.2.2
2023/11/07 03:06:50 [main:3] Using: alsa=0.3.0 angstrom=0.15.0 ao=0.2.4 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 bjack=0.1.6 bos=0.2.1 bytes=[distributed with OCaml] ca-certs=v0.2.3 camlimages.all_formats=4.2.6 camlimages.core=5.0.4 camlimages.exif=5.0.4 camlimages.gif=5.0.4 camlimages.jpeg=5.0.4 camlimages.png=5.0.4 camlimages.tiff=5.0.4 camlimages.xpm=5.0.4 camlp-streams camomile.lib=2.0 cohttp=5.1.0 cohttp-lwt=5.1.0 cohttp-lwt-unix=5.1.0 conduit=6.2.0 conduit-lwt=6.2.0 conduit-lwt-unix=6.2.0 cry=1.0.2 cstruct=6.2.0 ctypes=0.20.2 ctypes.foreign=0.20.2 ctypes.stubs=0.20.2 curl=0.9.2 domain-name=0.4.0 dssi=0.1.5 dtools=0.4.5 dune-build-info=3.8.2 dune-private-libs.dune-section=3.8.2 dune-site=3.8.2 dune-site.private=3.8.2 duppy=0.9.3 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 faad=0.5.2 fdkaac=0.3.3 ffmpeg-av=1.1.9 ffmpeg-avcodec=1.1.9 ffmpeg-avdevice=1.1.9 ffmpeg-avfilter=1.1.9 ffmpeg-avutil=1.1.9 ffmpeg-swresample=1.1.9 ffmpeg-swscale=1.1.9 fileutils=0.6.4 flac=0.5.0 flac.decoder=0.5.0 flac.ogg=0.5.0 fmt=0.9.0 fpath=0.7.3 frei0r=0.1.2 gd=1.0a5 gen=1.1 gmap=0.3.0 hkdf=1.0.4 inotify=2.4.1 integers ipaddr=5.5.0 ipaddr-sexp=5.5.0 ipaddr.unix=5.5.0 irc-client irc-client-unix jemalloc ladspa=0.2.2 lame=0.3.7 lastfm=0.3.3 lilv=0.1.0 liquidsoap-lang=2.2.2 liquidsoap-lang.console=2.2.2 liquidsoap_alsa=v2.2.2-1-g93f305b liquidsoap_ao=v2.2.2-1-g93f305b liquidsoap_bjack=v2.2.2-1-g93f305b liquidsoap_builtins=v2.2.2-1-g93f305b liquidsoap_camlimages=v2.2.2-1-g93f305b liquidsoap_core=v2.2.2-1-g93f305b liquidsoap_dssi=v2.2.2-1-g93f305b liquidsoap_faad=v2.2.2-1-g93f305b liquidsoap_fdkaac=v2.2.2-1-g93f305b liquidsoap_ffmpeg=v2.2.2-1-g93f305b liquidsoap_flac=v2.2.2-1-g93f305b liquidsoap_frei0r=v2.2.2-1-g93f305b liquidsoap_gd=v2.2.2-1-g93f305b liquidsoap_irc=v2.2.2-1-g93f305b liquidsoap_jemalloc=v2.2.2-1-g93f305b liquidsoap_ladspa=v2.2.2-1-g93f305b liquidsoap_lame=v2.2.2-1-g93f305b liquidsoap_lastfm=v2.2.2-1-g93f305b liquidsoap_lilv=v2.2.2-1-g93f305b liquidsoap_lo=v2.2.2-1-g93f305b liquidsoap_mad=v2.2.2-1-g93f305b liquidsoap_magic=v2.2.2-1-g93f305b liquidsoap_mem_usage=v2.2.2-1-g93f305b liquidsoap_memtrace=v2.2.2-1-g93f305b liquidsoap_ogg=v2.2.2-1-g93f305b liquidsoap_ogg_flac=v2.2.2-1-g93f305b liquidsoap_optionals=v2.2.2-1-g93f305b liquidsoap_opus=v2.2.2-1-g93f305b liquidsoap_osc=v2.2.2-1-g93f305b liquidsoap_oss=v2.2.2-1-g93f305b liquidsoap_portaudio=v2.2.2-1-g93f305b liquidsoap_posix_time=v2.2.2-1-g93f305b liquidsoap_prometheus=v2.2.2-1-g93f305b liquidsoap_pulseaudio=v2.2.2-1-g93f305b liquidsoap_runtime=v2.2.2-1-g93f305b liquidsoap_samplerate=v2.2.2-1-g93f305b liquidsoap_sdl=v2.2.2-1-g93f305b liquidsoap_shine=v2.2.2-1-g93f305b liquidsoap_soundtouch=v2.2.2-1-g93f305b liquidsoap_speex=v2.2.2-1-g93f305b liquidsoap_srt=v2.2.2-1-g93f305b liquidsoap_ssl=v2.2.2-1-g93f305b liquidsoap_stereotool=v2.2.2-1-g93f305b liquidsoap_taglib=v2.2.2-1-g93f305b liquidsoap_theora=v2.2.2-1-g93f305b liquidsoap_tls=v2.2.2-1-g93f305b liquidsoap_vorbis=v2.2.2-1-g93f305b liquidsoap_xmlplaylist=v2.2.2-1-g93f305b liquidsoap_yaml=v2.2.2-1-g93f305b lo=0.2.0 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.3 magic=0.7.3 magic-mime=1.3.0 mem_usage=0.0.4 memtrace=0.2.3 menhirLib=20230608 metadata=0.2.0 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=0.2.3 opus.decoder=0.2.3 osc osc-unix parsexp=v0.16.0 pbkdf pcre=7.5.0 portaudio=0.2.3 posix-base=b516d46 posix-socket=b516d46 posix-socket.constants=b516d46 posix-socket.stubs=b516d46 posix-socket.types=b516d46 posix-time2=b516d46 posix-time2.constants=b516d46 posix-time2.stubs=b516d46 posix-time2.types=b516d46 posix-types=b516d46 posix-types.constants=b516d46 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 pulseaudio=0.1.6 re=1.10.4 result=1.5 rresult=0.7.0 samplerate=0.1.7 sedlex=a1362bd seq=[distributed with OCaml 4.07 or above] sexplib=v0.16.0 sexplib0=v0.16.0 shine=0.2.3 soundtouch=0.1.9 speex=0.4.2 speex.decoder=0.4.2 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.2-1-g93f305b str=[distributed with OCaml] stringext=1.6.0 taglib=0.3.10 theora=0.4.1 theora.decoder=0.4.1 threads=[distributed with OCaml] threads.posix=[distributed with OCaml] tls=0.17.0 tsdl=v1.0.0 tsdl-image=0.5 tsdl-ttf=0.5 unix=[distributed with OCaml] unix-errno=52c6ecb unix-errno.errno_bindings=52c6ecb unix-errno.errno_types=52c6ecb unix-errno.errno_types_detected=52c6ecb unix-errno.unix=52c6ecb uri=4.2.0 uri-sexp=4.2.0 uri.services=4.2.0 vorbis=0.8.1 vorbis.decoder=0.8.1 x509=0.16.4 xmlm=1.4.0 xmlplaylist=0.1.5 yaml=3.1.0 yaml.bindings=3.1.0 yaml.bindings.types=3.1.0 yaml.c=3.1.0 yaml.ffi=3.1.0 yaml.types=3.1.0 zarith=1.12
2023/11/07 03:06:50 [clock:3] Using native (high-precision) implementation for latency control
2023/11/07 03:06:57 [main:3] Standard library loaded in 5.84 seconds.
2023/11/07 03:06:57 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2023/11/07 03:06:57 [frame:3] Video frame size set to: 1280x720
2023/11/07 03:06:57 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2023/11/07 03:06:57 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2023/11/07 03:06:57 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2023/11/07 03:06:57 [sandbox:3] Sandboxing disabled
2023/11/07 03:06:57 [startup:3] DSSI plugins registration: 0.00s
2023/11/07 03:06:57 [startup:3] FFmpeg filters registration: 0.03s
2023/11/07 03:06:57 [startup:3] FFmpeg bitstream filters registration: 0.00s
2023/11/07 03:06:57 [startup:3] Lilv plugins registration: 0.01s
2023/11/07 03:06:57 [startup:3] Frei0r plugin registration: 0.00s
2023/11/07 03:06:57 [startup:3] LADSPA plugins registration: 0.06s
2023/11/07 03:06:57 [startup:3] Typechecking: 5.41s
2023/11/07 03:06:57 [startup:3] Evaluation: 0.02s
2023/11/07 03:06:57 [startup:3] Typechecking: 0.05s
2023/11/07 03:06:57 [startup:3] Evaluation: 0.00s
2023/11/07 03:06:57 [startup:3] Typechecking: 0.09s
2023/11/07 03:06:57 [startup:3] Evaluation: 0.26s
2023/11/07 03:06:57 [startup:3] Loaded /var/azuracast/stations/radio/config/liquidsoap.liq: 0.37s
2023/11/07 03:06:57 [videostream:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:06:57 [buffer.producer:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:06:57 [safe_blank.2:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:06:57 [local_1:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [metadata_map.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [metadata_map.5:3] Content type is {}.
2023/11/07 03:06:57 [metadata_map.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [metadata_map.3:3] Content type is {}.
2023/11/07 03:06:57 [custom_metadata:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cross:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [amplify:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [track_amplify:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_interrupting_requests:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [interrupting_requests:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_requests:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [requests:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_next_song:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [next_song:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [source.available:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [autodj_startup_blank:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_morning_hour:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_morning_hour:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_chill__ambient:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_chill__ambient:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_one_album_hour__monday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_one_album_hour__monday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_one_album_hour__tuesday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_one_album_hour__tuesday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_one_album_hour__wednesday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_one_album_hour__wednesday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_one_album_hour__thursday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_one_album_hour__thursday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_one_album_hour__friday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_one_album_hour__friday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_indielofi_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_indielofi_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [source:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_soft_jingle:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_soft_jingle:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_lofi_sunday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_lofi_sunday:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [delay:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [source.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_jingles__night:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_jingles__night:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [on_track:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_rock:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [on_track.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [source.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [cue_playlist_jingles__day:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [playlist_jingles__day:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [on_track.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [metadata_map.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [metadata_map:3] Content type is {}.
2023/11/07 03:06:57 [error_jingle:3] "/usr/local/share/icecast/web/error.mp3" is static, resolving once for all...
2023/11/07 03:06:57 [clock.videostream:3] Streaming loop starts in auto-sync mode
2023/11/07 03:06:57 [clock.videostream:3] Delegating synchronization to CPU clock
2023/11/07 03:06:57 [decoder.ffmpeg:3] Requested content-type for "/usr/local/share/icecast/web/error.mp3": {audio=pcm(stereo)}
2023/11/07 03:06:57 [decoder.ffmpeg:3] FFmpeg recognizes "/usr/local/share/icecast/web/error.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:06:57 [decoder.ffmpeg:3] Decoded content-type for "/usr/local/share/icecast/web/error.mp3": {audio=pcm(stereo)}
2023/11/07 03:06:57 [mksafe.2:3] Switch to safe_blank.2.
2023/11/07 03:06:57 [error_jingle:3] Prepared "/usr/local/share/icecast/web/error.mp3" (RID 15).
2023/11/07 03:06:57 [local_3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [/var/azuracast/stations/radio/hls/live_m3u8:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:06:57 [buffer.consumer:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:06:57 [source.14:3] Content type is {audio=pcm(stereo),video=canvas}.
[libx264 @ 0x7fad0f05df00] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
2023/11/07 03:06:57 [source.12:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add.6:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.11:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video_add_image:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add_rectangle.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.7:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add_rectangle.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add_rectangle.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add_rectangle.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.6:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.add_rectangle:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [onair:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [safe_blank:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.available.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.translate:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.info:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.crop:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.text:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.available.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.translate.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.info.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.crop.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.text.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.available.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.translate.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.info.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.crop.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.text.3:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [on_frame:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [track_video_add_image.2:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.crop.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [track_video_add_image:3] "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" is static, resolving once for all...
[libx264 @ 0x7fad0f05df00] profile Constrained Baseline, level 3.2, 4:2:0, 8-bit
2023/11/07 03:06:57 [videostream:3] Connecting mount /video for source@127.0.0.1...
2023/11/07 03:06:57 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
2023/11/07 03:06:57 [source.available.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.translate.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.info.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.crop.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.text.4:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [source.available.6:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.translate.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.info.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.crop.6:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [video.text.5:3] Content type is {video=canvas}.
2023/11/07 03:06:57 [clock.main:3] Streaming loop starts in auto-sync mode
2023/11/07 03:06:57 [clock.main:3] Delegating synchronization to CPU clock
2023/11/07 03:06:57 [video.converter:3] Using preferred video converter: ffmpeg.
2023/11/07 03:06:57 [audio.converter:3] Using samplerate converter: libsamplerate.
2023/11/07 03:06:57 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:06:59 [safe_fallback:3] Switch to metadata_map.2.
[mp3float @ 0x7fad07e1c000] Could not update timestamps for skipped samples.
2023/11/07 03:06:59 [videostream:3] Connection setup was successful.
2023/11/07 03:06:59 [clock.videostream:2] We must catchup 1.88 seconds!
2023/11/07 03:06:59 [lang:3] API nextsong - Response (200): annotate:title="Nightshift | Rock @ omFM",artist="Nightshift | Rock @ omFM",duration="33.00",song_id="35882685be4ebcc847fb3aaf8863e7dd",media_id="5865",playlist_id="14",jingle_mode="true":media:jingles/rock/night/nightshift3.mp3
2023/11/07 03:06:59 [local_1:3] Connecting mount /radio.mp3 for source@127.0.0.1...
2023/11/07 03:07:00 [local_1:3] Connection setup was successful.
2023/11/07 03:07:00 [local_3:3] Connecting mount /radio.aac for source@127.0.0.1...
[mp3 @ 0x7fad071a5000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:00 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:00 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:00 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:00 [local_3:3] Connection setup was successful.
[mpegts @ 0x7fad30952600] frame size not set
[mpegts @ 0x7fad30953200] frame size not set
[mpegts @ 0x7fad30953e00] frame size not set
2023/11/07 03:07:00 [mksafe:3] Switch to safe_blank.
2023/11/07 03:07:00 [clock.videostream:2] We must catchup 2.74 seconds!
[mp3 @ 0x7fad071a5000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:00 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/ROCK/nightshift/Vindarnas Hus/06 Sadan Var Vintern Om Sommaren.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:00 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/ROCK/nightshift/Vindarnas Hus/06 Sadan Var Vintern Om Sommaren.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:00 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/ROCK/nightshift/Vindarnas Hus/06 Sadan Var Vintern Om Sommaren.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:01 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
[swscaler @ 0x7fad02f64600] Warning: dstStride is not aligned!
         ->cannot do aligned memory accesses anymore
[swscaler @ 0x7fad02f64600] Warning: data is not aligned! This can lead to a speed loss
2023/11/07 03:07:01 [track_video_add_image:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" (RID 14).
2023/11/07 03:07:01 [clock.main:2] We must catchup 3.21 seconds!
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:01 [next_song:3] Prepared "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3" (RID 17).
2023/11/07 03:07:01 [safe_fallback:3] Switch to custom_metadata with transition.
2023/11/07 03:07:02 [clock.videostream:2] We must catchup 4.04 seconds!
2023/11/07 03:07:02 [clock.main:2] We must catchup 4.48 seconds!
2023/11/07 03:07:02 [interrupting_fallback:3] Switch to requests_fallback.
2023/11/07 03:07:02 [requests_fallback:3] Switch to autodj_fallback.
2023/11/07 03:07:02 [autodj_fallback:3] Switch to dynamic_startup.
2023/11/07 03:07:02 [dynamic_startup:3] Switch to cue_next_song.
2023/11/07 03:07:02 [cue_next_song:3] Cueing in...
2023/11/07 03:07:04 [cover:3] File "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3" has no cover.
2023/11/07 03:07:04 [clock.videostream:2] We must catchup 5.43 seconds!
2023/11/07 03:07:04 [decoder.id3:2] Error while decoding file tags: Failure("Unsynchronized headers not handled.")
2023/11/07 03:07:04 [clock.main:2] We must catchup 6.77 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:05 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Ptr. - Spellbound.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:05 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Ptr. - Spellbound.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:05 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Ptr. - Spellbound.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:05 [clock.videostream:2] We must catchup 5.92 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:05 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:07:05 [lang:3]   "song_id": "35882685be4ebcc847fb3aaf8863e7dd",
2023/11/07 03:07:05 [lang:3]   "playlist_id": "14",
2023/11/07 03:07:05 [lang:3]   "media_id": "5865"
2023/11/07 03:07:05 [lang:3] }
2023/11/07 03:07:05 [clock.main:2] We must catchup 7.03 seconds!
2023/11/07 03:07:05 [lang:3] API feedback - Response (200): true
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:06 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:06 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:06 [mksafe.2:3] Switch to buffer.producer with transition.
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:06 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:06 [clock.videostream:2] We must catchup 5.54 seconds!
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:06 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:06 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:06 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/onealbum/darkintro.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:08 [clock.videostream:2] We must catchup 7.84 seconds!
2023/11/07 03:07:08 [clock.main:2] We must catchup 9.65 seconds!
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:09 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/birp/daylight-soft-emotional-logo-119131.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:09 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/birp/daylight-soft-emotional-logo-119131.mp3" as audio: {codec: mp3, 48000Hz, 2 channel(s)}
2023/11/07 03:07:09 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/birp/daylight-soft-emotional-logo-119131.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:09 [clock.main:2] We must catchup 10.57 seconds!
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:10 [clock.videostream:2] We must catchup 9.03 seconds!
2023/11/07 03:07:12 [clock.videostream:2] We must catchup 10.96 seconds!
2023/11/07 03:07:12 [clock.main:2] We must catchup 12.67 seconds!
2023/11/07 03:07:13 [clock.videostream:2] We must catchup 12.04 seconds!
2023/11/07 03:07:13 [clock.main:2] We must catchup 13.91 seconds!
2023/11/07 03:07:13 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Various Artists - BIRP!/Various Artists - BIRP! Best of 2022/016 - PERSONA 749 - Billy.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:13 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Various Artists - BIRP!/Various Artists - BIRP! Best of 2022/016 - PERSONA 749 - Billy.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x600, yuvj420p}
2023/11/07 03:07:13 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Various Artists - BIRP!/Various Artists - BIRP! Best of 2022/016 - PERSONA 749 - Billy.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:14 [clock.main:2] We must catchup 14.95 seconds!
2023/11/07 03:07:14 [clock.videostream:2] We must catchup 13.25 seconds!
2023/11/07 03:07:15 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/lofi/_onair/The Jazz Hop Café/2020 - VA - Dreamscape/13. Morfhin - Reflections.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:15 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/lofi/_onair/The Jazz Hop Café/2020 - VA - Dreamscape/13. Morfhin - Reflections.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 700x700, yuvj444p}
2023/11/07 03:07:15 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/lofi/_onair/The Jazz Hop Café/2020 - VA - Dreamscape/13. Morfhin - Reflections.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:15 [clock.videostream:2] We must catchup 13.91 seconds!
2023/11/07 03:07:15 [clock.main:2] We must catchup 16.05 seconds!
2023/11/07 03:07:16 [clock.videostream:2] We must catchup 14.47 seconds!
2023/11/07 03:07:17 [clock.main:2] We must catchup 16.52 seconds!
2023/11/07 03:07:18 [clock.videostream:2] We must catchup 15.36 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:18 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift1.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:18 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift1.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:18 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift1.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:18 [clock.main:2] We must catchup 17.41 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:20 [clock.videostream:2] We must catchup 17.31 seconds!
2023/11/07 03:07:20 [clock.main:2] We must catchup 19.29 seconds!
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:20 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:20 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:20 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/jingles/rock/day/logo2.2.mp3": {audio=pcm(stereo)}
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:20 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:07:20 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" as video: {codec: h264, 1280x720, yuv420p}
2023/11/07 03:07:20 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:07:20 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Envy/A Dead Sinking Story [Level Plane Rec., LP-56]/07 A Conviction That Speeds.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:20 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Envy/A Dead Sinking Story [Level Plane Rec., LP-56]/07 A Conviction That Speeds.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 300x300, yuvj420p}
2023/11/07 03:07:20 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_music/rock/Envy/A Dead Sinking Story [Level Plane Rec., LP-56]/07 A Conviction That Speeds.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:20 [decoder.taglib:2] Error while decoding file tags: Taglib.File.Invalid_file
2023/11/07 03:07:20 [video.text:3] Using sdl implementation
2023/11/07 03:07:20 [lang:3] AutoDJ is ready!
2023/11/07 03:07:20 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:07:20 [lang:3] API nextsong - Response (200): annotate:title="Homeward",artist="Tim Schaufert",duration="202.00",song_id="1118a7e3ddfa10a96bfecf86c3e8e16e",media_id="4314",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3
2023/11/07 03:07:21 [onair:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" (RID 30).
2023/11/07 03:07:21 [mksafe:3] Switch to onair with transition.
2023/11/07 03:07:21 [clock.main:2] We must catchup 20.97 seconds!
2023/11/07 03:07:21 [clock.videostream:2] We must catchup 18.75 seconds!
2023/11/07 03:07:24 [clock.videostream:2] We must catchup 21.50 seconds!
2023/11/07 03:07:25 [clock.videostream:2] We must catchup 22.55 seconds!
2023/11/07 03:07:26 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/07 03:07:26 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/07 03:07:26 [clock.videostream:2] We must catchup 23.26 seconds!
2023/11/07 03:07:27 [clock.main:2] We must catchup 25.97 seconds!
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:27 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:27 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:07:27 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:28 [clock.videostream:2] We must catchup 23.87 seconds!
2023/11/07 03:07:28 [clock.main:2] We must catchup 26.95 seconds!
[mp3 @ 0x7fad06d76000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:29 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:07:29 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" as video: {codec: h264, 1280x720, yuv420p}
2023/11/07 03:07:29 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:07:29 [clock.videostream:2] We must catchup 24.12 seconds!
2023/11/07 03:07:29 [clock.main:2] We must catchup 27.95 seconds!
2023/11/07 03:07:29 [decoder.taglib:2] Error while decoding file tags: Taglib.File.Invalid_file
2023/11/07 03:07:30 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/07 03:07:30 [replay_metadata:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:07:30 [clock.videostream:2] We must catchup 22.84 seconds!
2023/11/07 03:07:30 [clock.main:2] We must catchup 27.79 seconds!
2023/11/07 03:07:31 [clock.videostream:2] We must catchup 21.73 seconds!
2023/11/07 03:07:31 [clock.main:2] We must catchup 27.18 seconds!
2023/11/07 03:07:32 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/07 03:07:32 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/07 03:07:32 [clock.videostream:2] We must catchup 20.89 seconds!
2023/11/07 03:07:32 [clock.main:2] We must catchup 27.04 seconds!
2023/11/07 03:07:33 [clock.videostream:2] We must catchup 17.66 seconds (we've been late for 100 rounds)!
2023/11/07 03:07:33 [clock.main:2] We must catchup 27.21 seconds!
2023/11/07 03:07:33 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/07 03:07:33 [replay_metadata.2:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:07:34 [clock.videostream:2] We must catchup 16.10 seconds!
2023/11/07 03:07:34 [clock.main:2] We must catchup 26.72 seconds!
2023/11/07 03:07:35 [clock.videostream:2] We must catchup 14.92 seconds!
2023/11/07 03:07:35 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/07 03:07:35 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/07 03:07:35 [clock.main:2] We must catchup 26.25 seconds!
2023/11/07 03:07:36 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/07 03:07:36 [replay_metadata.3:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:07:36 [clock.videostream:2] We must catchup 11.98 seconds!
2023/11/07 03:07:36 [clock.main:2] We must catchup 25.70 seconds!
2023/11/07 03:07:37 [clock.videostream:2] We must catchup 10.99 seconds!
2023/11/07 03:07:37 [clock.main:2] We must catchup 25.24 seconds!
2023/11/07 03:07:38 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/07 03:07:38 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/07 03:07:38 [clock.videostream:2] We must catchup 9.04 seconds!
2023/11/07 03:07:38 [clock.main:2] We must catchup 24.89 seconds!
2023/11/07 03:07:38 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/07 03:07:38 [replay_metadata.4:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:07:39 [clock.videostream:2] We must catchup 6.79 seconds!
2023/11/07 03:07:39 [clock.main:2] We must catchup 24.26 seconds!
2023/11/07 03:07:40 [clock.videostream:2] We must catchup 5.64 seconds!
2023/11/07 03:07:40 [clock.main:2] We must catchup 23.83 seconds!
2023/11/07 03:07:40 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/07 03:07:40 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/07 03:07:41 [clock.videostream:2] We must catchup 3.88 seconds!
2023/11/07 03:07:41 [clock.main:2] We must catchup 24.08 seconds!
2023/11/07 03:07:41 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/07 03:07:41 [replay_metadata.5:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:07:42 [clock.videostream:2] We must catchup 2.16 seconds!
2023/11/07 03:07:42 [clock.main:2] We must catchup 24.23 seconds!
2023/11/07 03:07:43 [buffer.producer:3] Buffer emptied, start buffering...
2023/11/07 03:07:43 [mksafe.2:3] Switch to safe_blank.2 with forgetful transition.
2023/11/07 03:07:43 [clock.main:2] We must catchup 23.71 seconds!
2023/11/07 03:07:43 [mksafe.2:3] Switch to buffer.producer with transition.
2023/11/07 03:07:43 [replay_metadata.6:3] Content type is {audio=pcm(stereo),video=canvas}.
2023/11/07 03:07:44 [clock.main:2] We must catchup 23.40 seconds!
2023/11/07 03:07:45 [clock.main:2] We must catchup 22.84 seconds!
2023/11/07 03:07:46 [clock.main:2] We must catchup 22.21 seconds!
2023/11/07 03:07:47 [clock.main:2] We must catchup 21.45 seconds!
2023/11/07 03:07:48 [decoder:2] Decoding "/var/azuracast/stations/radio/media/jingles/rock/night/nightshift3.mp3" ended: Ffmpeg_decoder.End_of_file.
2023/11/07 03:07:48 [clock.main:2] We must catchup 20.70 seconds!
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:48 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3" (RID 31).
2023/11/07 03:07:48 [cue_next_song:3] Cueing in...
2023/11/07 03:07:48 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:07:49 [lang:3] API nextsong - Response (200): annotate:title="Together With You Under the Stars",artist="Andy Leech",duration="398.00",song_id="b133edb2ad1416965a4ce974948fba7e",media_id="4366",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3
2023/11/07 03:07:49 [cover:3] File "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3" has no cover.
2023/11/07 03:07:51 [clock.videostream:2] We must catchup 2.44 seconds!
2023/11/07 03:07:53 [clock.videostream:2] We must catchup 4.57 seconds!
2023/11/07 03:07:53 [cross:3] Analysis: -47.001981dB / -40.545709dB (2.96s / 3.00s)
2023/11/07 03:07:53 [source.17:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [audio.add:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [fade_in:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [track_amplify.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_track.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_metadata.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_track.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [cross_after:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [buffer.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [fade_out:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [track_amplify.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_end:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_track.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_metadata:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [on_track.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [cross_before:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [buffer:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:07:53 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:07:53 [lang:3]   "song_id": "1118a7e3ddfa10a96bfecf86c3e8e16e",
2023/11/07 03:07:53 [lang:3]   "playlist_id": "4",
2023/11/07 03:07:53 [lang:3]   "media_id": "4314"
2023/11/07 03:07:53 [lang:3] }
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:54 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:54 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x600, yuvj420p}
2023/11/07 03:07:54 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3": {audio=pcm(stereo)}
2023/11/07 03:07:54 [clock.main:2] We must catchup 25.87 seconds!
2023/11/07 03:07:54 [lang:3] API feedback - Response (200): true
2023/11/07 03:07:54 [clock.videostream:2] We must catchup 5.22 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:07:55 [clock.main:2] We must catchup 26.43 seconds!
2023/11/07 03:07:55 [clock.videostream:2] We must catchup 4.93 seconds!
2023/11/07 03:07:56 [clock.main:2] We must catchup 25.95 seconds!
2023/11/07 03:07:56 [clock.videostream:2] We must catchup 3.92 seconds!
2023/11/07 03:07:57 [clock.main:2] We must catchup 25.66 seconds!
2023/11/07 03:07:57 [clock.videostream:2] We must catchup 2.84 seconds!
2023/11/07 03:07:58 [clock.main:2] We must catchup 24.99 seconds!
2023/11/07 03:07:58 [clock.videostream:2] We must catchup 1.71 seconds!
2023/11/07 03:07:59 [clock.main:2] We must catchup 24.53 seconds!
2023/11/07 03:08:00 [clock.main:2] We must catchup 24.02 seconds!
2023/11/07 03:08:01 [clock.main:2] We must catchup 23.52 seconds!
2023/11/07 03:08:02 [clock.main:2] We must catchup 23.21 seconds!
2023/11/07 03:08:03 [clock.main:2] We must catchup 23.06 seconds!
2023/11/07 03:08:04 [clock.main:2] We must catchup 22.47 seconds!
2023/11/07 03:08:05 [clock.main:2] We must catchup 22.00 seconds!
2023/11/07 03:08:06 [clock.main:2] We must catchup 21.49 seconds!
2023/11/07 03:08:07 [clock.main:2] We must catchup 20.89 seconds!
2023/11/07 03:08:08 [clock.main:2] We must catchup 20.58 seconds!
2023/11/07 03:08:09 [clock.main:2] We must catchup 20.02 seconds!
2023/11/07 03:08:10 [clock.main:2] We must catchup 19.38 seconds!
2023/11/07 03:08:11 [clock.main:2] We must catchup 18.92 seconds!
2023/11/07 03:08:12 [clock.main:2] We must catchup 18.57 seconds!
2023/11/07 03:08:13 [clock.main:2] We must catchup 18.15 seconds!
2023/11/07 03:08:14 [clock.main:2] We must catchup 17.51 seconds!
2023/11/07 03:08:15 [clock.main:2] We must catchup 16.81 seconds!
2023/11/07 03:08:16 [clock.main:2] We must catchup 16.08 seconds!
2023/11/07 03:08:17 [clock.main:2] We must catchup 15.12 seconds!
2023/11/07 03:08:18 [clock.main:2] We must catchup 14.29 seconds!
2023/11/07 03:08:19 [clock.main:2] We must catchup 14.14 seconds!
2023/11/07 03:08:20 [clock.main:2] We must catchup 13.72 seconds!
2023/11/07 03:08:21 [clock.main:2] We must catchup 13.00 seconds!
2023/11/07 03:08:22 [clock.main:2] We must catchup 12.74 seconds!
2023/11/07 03:08:23 [clock.main:2] We must catchup 11.68 seconds!
2023/11/07 03:08:24 [clock.main:2] We must catchup 10.89 seconds!
2023/11/07 03:08:25 [clock.main:2] We must catchup 9.98 seconds!
2023/11/07 03:08:26 [clock.main:2] We must catchup 9.01 seconds!
2023/11/07 03:08:27 [clock.main:2] We must catchup 8.19 seconds!
2023/11/07 03:08:28 [clock.main:2] We must catchup 7.20 seconds!
2023/11/07 03:08:29 [clock.main:2] We must catchup 6.13 seconds!
2023/11/07 03:08:30 [clock.main:2] We must catchup 5.59 seconds!
2023/11/07 03:08:31 [clock.main:2] We must catchup 5.21 seconds!
2023/11/07 03:08:32 [clock.main:2] We must catchup 4.50 seconds!
2023/11/07 03:08:33 [clock.main:2] We must catchup 3.83 seconds!
2023/11/07 03:08:34 [clock.main:2] We must catchup 2.97 seconds!
2023/11/07 03:08:35 [clock.main:2] We must catchup 1.97 seconds!
2023/11/07 03:08:36 [clock.main:2] We must catchup 1.06 seconds!
2023/11/07 03:10:02 [clock.main:2] We must catchup 1.06 seconds!
2023/11/07 03:10:03 [clock.main:2] We must catchup 1.11 seconds!
[mp3float @ 0x7fad03068e00] Header missing
2023/11/07 03:10:47 [decoder:2] Decoding "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Tim Schaufert - Homeward.mp3" ended: Ffmpeg_decoder.End_of_file.
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:10:47 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3" (RID 33).
2023/11/07 03:10:47 [cue_next_song:3] Cueing in...
2023/11/07 03:10:47 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:10:48 [cover:3] Cover for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3" saved to "/tmp/cover_6d3b7e.jpeg".
2023/11/07 03:10:48 [cross:3] Analysis: -61.366940dB / -54.794613dB (2.98s / 2.98s)
2023/11/07 03:10:48 [source.20:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [audio.add.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [fade_in.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [track_amplify.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_track.11:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_metadata.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_track.10:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [cross_after.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [buffer.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [fade_out.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [track_amplify.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_end.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_track.9:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_metadata.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [on_track.8:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [cross_before.2:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [buffer.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:10:48 [lang:3] API nextsong - Response (200): annotate:title="The Shore",artist="Mango, SEAWAVES",duration="428.00",song_id="32b0cfa0fc068ce8159d652d1be3d04c",media_id="4383",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3
2023/11/07 03:10:50 [track_video_add_image.4:3] Content type is {video=canvas}.
2023/11/07 03:10:50 [video.crop.7:3] Content type is {video=canvas}.
2023/11/07 03:10:50 [track_video_add_image.3:3] "/tmp/cover_6d3b7e.jpeg" is static, resolving once for all...
2023/11/07 03:10:50 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:10:50 [lang:3]   "song_id": "b133edb2ad1416965a4ce974948fba7e",
2023/11/07 03:10:50 [lang:3]   "playlist_id": "4",
2023/11/07 03:10:50 [lang:3]   "media_id": "4366"
2023/11/07 03:10:50 [lang:3] }
2023/11/07 03:10:50 [decoder:3] Method "sdl" accepted "/tmp/cover_6d3b7e.jpeg".
2023/11/07 03:10:50 [clock.videostream:2] We must catchup 2.72 seconds!
2023/11/07 03:10:50 [lang:3] API feedback - Response (200): true
2023/11/07 03:10:50 [decoder:3] Method "sdl" accepted "/tmp/cover_6d3b7e.jpeg".
2023/11/07 03:10:50 [track_video_add_image.3:3] Prepared "/tmp/cover_6d3b7e.jpeg" (RID 35).
2023/11/07 03:10:51 [clock.main:2] We must catchup 3.66 seconds!
2023/11/07 03:10:52 [clock.videostream:2] We must catchup 3.74 seconds!
2023/11/07 03:10:52 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3": {audio=pcm(stereo)}
2023/11/07 03:10:52 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 800x800, yuvj420p}
2023/11/07 03:10:52 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3": {audio=pcm(stereo)}
2023/11/07 03:10:52 [clock.main:2] We must catchup 4.42 seconds!
2023/11/07 03:10:53 [clock.videostream:2] We must catchup 4.17 seconds!
2023/11/07 03:10:53 [clock.main:2] We must catchup 4.71 seconds!
2023/11/07 03:10:54 [clock.videostream:2] We must catchup 3.74 seconds!
2023/11/07 03:10:54 [clock.main:2] We must catchup 4.32 seconds!
2023/11/07 03:10:55 [clock.videostream:2] We must catchup 2.86 seconds!
2023/11/07 03:10:55 [clock.main:2] We must catchup 4.28 seconds!
2023/11/07 03:10:56 [clock.videostream:2] We must catchup 1.79 seconds!
2023/11/07 03:10:56 [clock.main:2] We must catchup 3.89 seconds!
2023/11/07 03:10:57 [clock.main:2] We must catchup 3.58 seconds!
2023/11/07 03:10:58 [clock.main:2] We must catchup 2.87 seconds!
2023/11/07 03:10:59 [clock.main:2] We must catchup 2.41 seconds!
2023/11/07 03:11:00 [clock.main:2] We must catchup 1.74 seconds!
2023/11/07 03:11:01 [clock.main:2] We must catchup 1.20 seconds!
2023/11/07 03:15:04 [clock.main:2] We must catchup 1.01 seconds!
2023/11/07 03:15:05 [clock.main:2] We must catchup 1.15 seconds!
[mp3float @ 0x7fad02e0e000] Header missing
2023/11/07 03:17:22 [decoder:2] Decoding "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Andy Leech - Together With You Under The Stars.mp3" ended: Ffmpeg_decoder.End_of_file.
2023/11/07 03:17:25 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3" (RID 34).
2023/11/07 03:17:25 [clock.main:2] We must catchup 2.45 seconds!
[mp3float @ 0x7fad019d9c00] Could not update timestamps for skipped samples.
2023/11/07 03:17:25 [cue_next_song:3] Cueing in...
2023/11/07 03:17:25 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:17:25 [cover:3] Cover for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3" saved to "/tmp/cover_fe1b79.jpeg".
2023/11/07 03:17:25 [lang:3] API nextsong - Response (200): annotate:title="Love Story",artist="The Ambientalist",duration="206.00",song_id="22491db0f622e891657def0e4062f206",media_id="4300",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3
2023/11/07 03:17:26 [cross:3] Analysis: -61.048879dB / -28.798872dB (2.98s / 3.02s)
2023/11/07 03:17:26 [source.23:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [audio.add.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [fade_in.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [track_amplify.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_track.15:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_metadata.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_track.14:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [cross_after.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [buffer.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [fade_out.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [track_amplify.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_end.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_track.13:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_metadata.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [on_track.12:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [cross_before.3:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [buffer.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:17:27 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:17:27 [lang:3]   "song_id": "32b0cfa0fc068ce8159d652d1be3d04c",
2023/11/07 03:17:27 [lang:3]   "playlist_id": "4",
2023/11/07 03:17:27 [lang:3]   "media_id": "4383"
2023/11/07 03:17:27 [lang:3] }
2023/11/07 03:17:27 [clock.videostream:2] We must catchup 1.76 seconds!
2023/11/07 03:17:27 [lang:3] API feedback - Response (200): true
2023/11/07 03:17:27 [track_video_add_image.6:3] Content type is {video=canvas}.
2023/11/07 03:17:27 [video.crop.8:3] Content type is {video=canvas}.
2023/11/07 03:17:27 [track_video_add_image.5:3] "/tmp/cover_fe1b79.jpeg" is static, resolving once for all...
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:17:27 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3": {audio=pcm(stereo)}
2023/11/07 03:17:27 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:17:27 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3": {audio=pcm(stereo)}
2023/11/07 03:17:28 [decoder:3] Method "sdl" accepted "/tmp/cover_fe1b79.jpeg".
2023/11/07 03:17:28 [decoder:3] Method "sdl" accepted "/tmp/cover_fe1b79.jpeg".
2023/11/07 03:17:28 [track_video_add_image.5:3] Prepared "/tmp/cover_fe1b79.jpeg" (RID 37).
2023/11/07 03:17:28 [clock.main:2] We must catchup 4.90 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:17:28 [clock.videostream:2] We must catchup 2.20 seconds!
2023/11/07 03:17:29 [clock.main:2] We must catchup 5.42 seconds!
2023/11/07 03:17:29 [clock.videostream:2] We must catchup 1.42 seconds!
2023/11/07 03:17:30 [clock.main:2] We must catchup 5.32 seconds!
2023/11/07 03:17:31 [clock.main:2] We must catchup 4.97 seconds!
2023/11/07 03:17:32 [clock.main:2] We must catchup 4.34 seconds!
2023/11/07 03:17:33 [clock.main:2] We must catchup 3.54 seconds!
2023/11/07 03:17:34 [clock.main:2] We must catchup 2.98 seconds!
2023/11/07 03:17:35 [clock.main:2] We must catchup 2.10 seconds!
2023/11/07 03:17:36 [clock.main:2] We must catchup 1.23 seconds!
2023/11/07 03:19:05 [decoder:2] Decoding "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" ended: Ffmpeg_decoder.End_of_file.
2023/11/07 03:19:05 [onair:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" (RID 32).
2023/11/07 03:19:05 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:19:05 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" as video: {codec: h264, 1280x720, yuv420p}
2023/11/07 03:19:05 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:19:06 [decoder.taglib:2] Error while decoding file tags: Taglib.File.Invalid_file
2023/11/07 03:20:06 [clock.main:2] We must catchup 1.00 seconds!
2023/11/07 03:21:09 [clock.main:2] We must catchup 0.04 seconds!
2023/11/07 03:21:33 [clock.main:2] We must catchup 0.21 seconds!
[mp3float @ 0x7fad019d9c00] Could not update timestamps for discarded samples.
2023/11/07 03:24:27 [decoder:2] Decoding "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/VA - Maldesoule 001 (2022)/13. Mango; SEAWAVES - The Shore.mp3" ended: Ffmpeg_decoder.End_of_file.
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:24:28 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3" (RID 36).
2023/11/07 03:24:28 [cue_next_song:3] Cueing in...
2023/11/07 03:24:28 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:24:28 [cover:3] File "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3" has no cover.
2023/11/07 03:24:28 [lang:3] API nextsong - Response (200): annotate:title="breathe with me",artist="ALONE",duration="315.00",song_id="deb5b24f5925cc97d56b8c9adbac83ae",media_id="4282",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3
2023/11/07 03:24:30 [cross:3] Analysis: -49.572359dB / -22.967387dB (2.96s / 2.96s)
2023/11/07 03:24:30 [source.26:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [audio.add.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [fade_in.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [track_amplify.9:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_track.19:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_metadata.8:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_track.18:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [cross_after.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [buffer.8:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [fade_out.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [track_amplify.8:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_end.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_track.17:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_metadata.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [on_track.16:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [cross_before.4:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [buffer.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:24:30 [clock.videostream:2] We must catchup 1.83 seconds!
2023/11/07 03:24:30 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:24:30 [lang:3]   "song_id": "22491db0f622e891657def0e4062f206",
2023/11/07 03:24:30 [lang:3]   "playlist_id": "4",
2023/11/07 03:24:30 [lang:3]   "media_id": "4300"
2023/11/07 03:24:30 [lang:3] }
2023/11/07 03:24:30 [track_video_add_image.8:3] Content type is {video=canvas}.
2023/11/07 03:24:30 [video.crop.9:3] Content type is {video=canvas}.
2023/11/07 03:24:30 [lang:3] API feedback - Response (200): true
2023/11/07 03:24:30 [track_video_add_image.7:3] "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" is static, resolving once for all...
2023/11/07 03:24:30 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
2023/11/07 03:24:30 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
2023/11/07 03:24:31 [track_video_add_image.7:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" (RID 40).
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:24:31 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3": {audio=pcm(stereo)}
2023/11/07 03:24:31 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:24:31 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3": {audio=pcm(stereo)}
2023/11/07 03:24:31 [clock.main:2] We must catchup 3.02 seconds!
2023/11/07 03:24:31 [clock.videostream:2] We must catchup 2.48 seconds!
[mp3 @ 0x7fad07f24a00] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:24:32 [clock.videostream:2] We must catchup 2.09 seconds!
2023/11/07 03:24:32 [clock.main:2] We must catchup 3.28 seconds!
2023/11/07 03:24:33 [clock.videostream:2] We must catchup 1.18 seconds!
2023/11/07 03:24:33 [clock.main:2] We must catchup 2.90 seconds!
2023/11/07 03:24:34 [clock.main:2] We must catchup 2.35 seconds!
2023/11/07 03:24:35 [clock.main:2] We must catchup 1.56 seconds!
2023/11/07 03:25:04 [clock.main:2] We must catchup 0.14 seconds!
2023/11/07 03:26:04 [clock.main:2] We must catchup 0.11 seconds!
2023/11/07 03:27:10 [clock.main:2] We must catchup 0.06 seconds!
[mp3float @ 0x7facff530500] Header missing
2023/11/07 03:27:51 [decoder:2] Decoding "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/The Ambientalist - Love Story.mp3" ended: Ffmpeg_decoder.End_of_file.
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:27:53 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3" (RID 39).
2023/11/07 03:27:53 [clock.main:2] We must catchup 1.57 seconds!
2023/11/07 03:27:53 [cue_next_song:3] Cueing in...
2023/11/07 03:27:53 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:27:53 [cover:3] File "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3" has no cover.
2023/11/07 03:27:53 [lang:3] API nextsong - Response (200): annotate:title="Remnants",artist="4lienetic",duration="165.00",song_id="f69295eb53cf5667b41fd63b18a632d9",media_id="4443",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3
2023/11/07 03:27:55 [clock.videostream:2] We must catchup 1.28 seconds!
2023/11/07 03:27:56 [clock.videostream:2] We must catchup 2.21 seconds!
2023/11/07 03:27:56 [cross:3] Analysis: -48.005891dB / -46.434802dB (2.97s / 2.99s)
2023/11/07 03:27:56 [source.29:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [audio.add.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [fade_in.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [track_amplify.11:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_track.23:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_metadata.10:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_track.22:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [cross_after.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [buffer.10:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [fade_out.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [track_amplify.10:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_end.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_track.21:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_metadata.9:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [on_track.20:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [cross_before.5:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [buffer.9:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:27:56 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:27:56 [lang:3]   "song_id": "deb5b24f5925cc97d56b8c9adbac83ae",
2023/11/07 03:27:56 [lang:3]   "playlist_id": "4",
2023/11/07 03:27:56 [lang:3]   "media_id": "4282"
2023/11/07 03:27:56 [lang:3] }
2023/11/07 03:27:56 [lang:3] API feedback - Response (200): true
2023/11/07 03:27:57 [clock.main:2] We must catchup 4.77 seconds!
2023/11/07 03:27:57 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3": {audio=pcm(stereo)}
2023/11/07 03:27:57 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 1280x1280, yuvj420p}
2023/11/07 03:27:57 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3": {audio=pcm(stereo)}
2023/11/07 03:27:57 [clock.videostream:2] We must catchup 2.86 seconds!
2023/11/07 03:27:58 [clock.main:2] We must catchup 5.57 seconds!
2023/11/07 03:27:58 [clock.videostream:2] We must catchup 3.19 seconds!
2023/11/07 03:27:59 [clock.main:2] We must catchup 5.38 seconds!
2023/11/07 03:27:59 [clock.videostream:2] We must catchup 2.16 seconds!
2023/11/07 03:28:00 [clock.main:2] We must catchup 4.98 seconds!
2023/11/07 03:28:00 [clock.videostream:2] We must catchup 1.24 seconds!
2023/11/07 03:28:01 [clock.main:2] We must catchup 4.93 seconds!
2023/11/07 03:28:02 [clock.main:2] We must catchup 4.97 seconds!
2023/11/07 03:28:03 [clock.main:2] We must catchup 5.00 seconds!
2023/11/07 03:28:04 [clock.main:2] We must catchup 4.88 seconds!
2023/11/07 03:28:05 [clock.main:2] We must catchup 4.93 seconds!
2023/11/07 03:28:06 [clock.main:2] We must catchup 5.15 seconds!
2023/11/07 03:28:07 [clock.main:2] We must catchup 4.63 seconds!
2023/11/07 03:28:08 [clock.main:2] We must catchup 4.16 seconds!
2023/11/07 03:28:09 [clock.main:2] We must catchup 3.60 seconds!
2023/11/07 03:28:10 [clock.main:2] We must catchup 2.91 seconds!
2023/11/07 03:28:11 [clock.main:2] We must catchup 2.06 seconds!
2023/11/07 03:28:12 [clock.main:2] We must catchup 1.19 seconds!
2023/11/07 03:30:03 [clock.main:2] We must catchup 1.05 seconds!
2023/11/07 03:30:03 [clock.videostream:2] We must catchup 1.05 seconds!
2023/11/07 03:30:04 [clock.main:2] We must catchup 1.70 seconds!
2023/11/07 03:30:05 [clock.main:2] We must catchup 2.15 seconds!
2023/11/07 03:30:06 [clock.main:2] We must catchup 2.36 seconds!
2023/11/07 03:30:07 [clock.main:2] We must catchup 2.13 seconds!
2023/11/07 03:30:08 [clock.main:2] We must catchup 1.70 seconds!
2023/11/07 03:30:09 [clock.main:2] We must catchup 1.28 seconds!
2023/11/07 03:30:10 [clock.main:2] We must catchup 1.01 seconds!
2023/11/07 03:31:09 [decoder:2] Decoding "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" ended: Ffmpeg_decoder.End_of_file.
2023/11/07 03:31:10 [onair:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" (RID 38).
2023/11/07 03:31:10 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:31:10 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv" as video: {codec: h264, 1280x720, yuv420p}
2023/11/07 03:31:10 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/youtube-stream/img/background/background_video/onair/fire-blast-wild-controlle720_169_12min.mkv": {video=canvas}
2023/11/07 03:31:10 [decoder.taglib:2] Error while decoding file tags: Taglib.File.Invalid_file
2023/11/07 03:31:31 [clock.main:2] We must catchup 0.21 seconds!
[mp3float @ 0x7facff233700] Header missing
2023/11/07 03:33:04 [decoder:2] Decoding "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/ALONE - breathe with me.mp3" ended: Ffmpeg_decoder.End_of_file.
2023/11/07 03:33:04 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3" (RID 41).
[mp3float @ 0x7facfcf43a00] Could not update timestamps for skipped samples.
2023/11/07 03:33:04 [cue_next_song:3] Cueing in...
2023/11/07 03:33:04 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:33:04 [cover:3] Cover for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3" saved to "/tmp/cover_920113.jpeg".
2023/11/07 03:33:04 [cross:3] Analysis: -59.450694dB / -19.175550dB (2.97s / 2.99s)
2023/11/07 03:33:04 [source.32:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [audio.add.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [fade_in.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [track_amplify.13:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_track.27:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_metadata.12:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_track.26:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [cross_after.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [buffer.12:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [fade_out.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [track_amplify.12:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_end.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_track.25:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_metadata.11:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [on_track.24:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [cross_before.6:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [buffer.11:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:33:04 [lang:3] API nextsong - Response (200): annotate:title="Forever in My Heart",artist="Azaleh",duration="234.00",song_id="2bf286b910122667d59bbd3889ade248",media_id="4324",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Azaleh - Forever in My Heart.mp3
2023/11/07 03:33:04 [track_video_add_image.10:3] Content type is {video=canvas}.
2023/11/07 03:33:04 [video.crop.10:3] Content type is {video=canvas}.
2023/11/07 03:33:04 [track_video_add_image.9:3] "/tmp/cover_920113.jpeg" is static, resolving once for all...
2023/11/07 03:33:06 [decoder:3] Method "sdl" accepted "/tmp/cover_920113.jpeg".
2023/11/07 03:33:06 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:33:06 [lang:3]   "song_id": "f69295eb53cf5667b41fd63b18a632d9",
2023/11/07 03:33:06 [lang:3]   "playlist_id": "4",
2023/11/07 03:33:06 [lang:3]   "media_id": "4443"
2023/11/07 03:33:06 [lang:3] }
2023/11/07 03:33:06 [clock.videostream:2] We must catchup 1.56 seconds!
2023/11/07 03:33:06 [decoder:3] Method "sdl" accepted "/tmp/cover_920113.jpeg".
2023/11/07 03:33:06 [lang:3] API feedback - Response (200): true
2023/11/07 03:33:06 [track_video_add_image.9:3] Prepared "/tmp/cover_920113.jpeg" (RID 44).
2023/11/07 03:33:07 [clock.videostream:2] We must catchup 2.49 seconds!
2023/11/07 03:33:07 [clock.main:2] We must catchup 3.15 seconds!
[mp3 @ 0x7fad07f25000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:33:08 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Azaleh - Forever in My Heart.mp3": {audio=pcm(stereo)}
2023/11/07 03:33:08 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Azaleh - Forever in My Heart.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/11/07 03:33:08 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Azaleh - Forever in My Heart.mp3": {audio=pcm(stereo)}
2023/11/07 03:33:08 [clock.videostream:2] We must catchup 3.35 seconds!
2023/11/07 03:33:09 [clock.main:2] We must catchup 4.36 seconds!
2023/11/07 03:33:09 [clock.videostream:2] We must catchup 4.16 seconds!
[mp3 @ 0x7fad07f25000] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:33:10 [clock.main:2] We must catchup 5.17 seconds!
2023/11/07 03:33:10 [clock.videostream:2] We must catchup 4.32 seconds!
2023/11/07 03:33:11 [clock.main:2] We must catchup 5.14 seconds!
2023/11/07 03:33:11 [clock.videostream:2] We must catchup 3.40 seconds!
2023/11/07 03:33:12 [clock.main:2] We must catchup 4.74 seconds!
2023/11/07 03:33:12 [clock.videostream:2] We must catchup 2.41 seconds!
2023/11/07 03:33:13 [clock.main:2] We must catchup 4.75 seconds!
2023/11/07 03:33:14 [clock.main:2] We must catchup 4.59 seconds!
2023/11/07 03:33:14 [clock.videostream:2] We must catchup 0.15 seconds!
2023/11/07 03:33:15 [clock.main:2] We must catchup 4.28 seconds!
2023/11/07 03:33:16 [clock.main:2] We must catchup 3.60 seconds!
2023/11/07 03:33:17 [clock.main:2] We must catchup 2.58 seconds!
2023/11/07 03:33:18 [clock.main:2] We must catchup 1.56 seconds!
2023/11/07 03:35:03 [clock.main:2] We must catchup 1.03 seconds!
2023/11/07 03:35:04 [clock.main:2] We must catchup 1.16 seconds!
2023/11/07 03:35:06 [clock.main:2] We must catchup 1.14 seconds!
2023/11/07 03:35:08 [clock.main:2] We must catchup 0.06 seconds!
2023/11/07 03:35:46 [decoder:2] Decoding "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/4lienetic - Inure (2018)/3. 4lienetic - Remnants.mp3" ended: Ffmpeg_decoder.End_of_file.
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
[mp3 @ 0x7fad07f26200] Estimating duration from bitrate, this may be inaccurate
2023/11/07 03:35:48 [next_song:3] Prepared "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Azaleh - Forever in My Heart.mp3" (RID 43).
2023/11/07 03:35:48 [clock.main:2] We must catchup 1.53 seconds!
2023/11/07 03:35:48 [cue_next_song:3] Cueing in...
2023/11/07 03:35:48 [lang:3] API nextsong - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/nextsong' with body: 
2023/11/07 03:35:48 [cover:3] File "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chill Music Lab/Azaleh - Forever in My Heart.mp3" has no cover.
2023/11/07 03:35:48 [lang:3] API nextsong - Response (200): annotate:title="Along Empyrean Waterways",artist="WMD",duration="193.00",song_id="84f40ceac74380499403091fe67b3a6d",media_id="4404",playlist_id="4":media:GoogleDrive_radio/Chill_Music_Lab/Chillout/WMD - Young Angry Love (2019)/05. WMD - Along Empyrean Waterways.mp3
2023/11/07 03:35:51 [clock.videostream:2] We must catchup 2.94 seconds!
2023/11/07 03:35:53 [clock.videostream:2] We must catchup 4.46 seconds!
2023/11/07 03:35:53 [cross:3] Analysis: -37.419219dB / -19.907008dB (2.99s / 3.01s)
2023/11/07 03:35:53 [source.35:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [audio.add.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [fade_in.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [track_amplify.15:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_track.31:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_metadata.14:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_track.30:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [cross_after.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [buffer.14:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [fade_out.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [track_amplify.14:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_end.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_track.29:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_metadata.13:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [on_track.28:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [cross_before.7:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [buffer.13:3] Content type is {audio=pcm(stereo)}.
2023/11/07 03:35:53 [lang:3] API feedback - Sending POST request to 'http://127.0.0.1:6010/api/internal/1/liquidsoap/feedback' with body: {
2023/11/07 03:35:53 [lang:3]   "song_id": "2bf286b910122667d59bbd3889ade248",
2023/11/07 03:35:53 [lang:3]   "playlist_id": "4",
2023/11/07 03:35:53 [lang:3]   "media_id": "4324"
2023/11/07 03:35:53 [lang:3] }
2023/11/07 03:35:53 [track_video_add_image.12:3] Content type is {video=canvas}.
2023/11/07 03:35:53 [video.crop.11:3] Content type is {video=canvas}.
2023/11/07 03:35:53 [track_video_add_image.11:3] "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" is static, resolving once for all...
2023/11/07 03:35:53 [decoder.ffmpeg:3] Requested content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/WMD - Young Angry Love (2019)/05. WMD - Along Empyrean Waterways.mp3": {audio=pcm(stereo)}
2023/11/07 03:35:53 [decoder.ffmpeg:3] FFmpeg recognizes "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/WMD - Young Angry Love (2019)/05. WMD - Along Empyrean Waterways.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 800x800, yuvj444p}
2023/11/07 03:35:53 [decoder.ffmpeg:3] Decoded content-type for "/var/azuracast/stations/radio/media/GoogleDrive_radio/Chill_Music_Lab/Chillout/WMD - Young Angry Love (2019)/05. WMD - Along Empyrean Waterways.mp3": {audio=pcm(stereo)}
2023/11/07 03:35:53 [lang:3] API feedback - Response (200): true
2023/11/07 03:35:53 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
2023/11/07 03:35:53 [decoder:3] Method "ffmpeg" accepted "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png".
2023/11/07 03:35:53 [track_video_add_image.11:3] Prepared "/var/azuracast/stations/radio/media/youtube-stream/img/cover_default.png" (RID 46).
2023/11/07 03:35:54 [clock.main:2] We must catchup 6.90 seconds!
2023/11/07 03:35:54 [clock.videostream:2] We must catchup 4.98 seconds!
gAlleb commented 1 year ago

So I've been able to find a pattern. As I've written after reinstall overall CPU consumption has decreased and changes in CPU are indeed are not so significant (I would say 5-10%) and the following load is average for the middle of every track playing:

4

  1. Then when a new track comes in there is a visible increase in liquidsoap process 100% CPU and google-drive-ocamlfuse 80% CPU (tracks are in google drive) for 10-15 seconds:

    2

  2. Then google-drive-ocamlfuse goes normal mode but liquidsoap process spikes up to 125% - 145% CPU and average 1min load spikes up to 2.7-2.8:

    1

  3. Clock catches up and sometimes it catches up with playback fast forwarded for 5-10 seconds.

  4. Then average load normalizes as per 1st screenshot (azuracast php not taken into account). And I wonder that it is probably due to azuracast/google-drive bundle.

Moonbase59 commented 1 year ago

@gAlleb Thanks for the kind words—looked a little familiar, the code, indeed. ;-)

I’ve been running several audio and 2 video streams for months (almost identical settings to yours, in lack of HW accel…) and also recently switched to 2.2.2 but didn’t see a notable increase. Maybe it’s really the Google Drive userspace filesystem. Some are rather bad with large files.

I have all my music files on a remote NFS mount, but keep the (large!) videos on the host SSD. This works rather well, although I had to increase my storage from 40 GB to 80 GB. For safety’s sake, I also increased my CPUs from 2 to 4. The average load I see is about 1.9–2.3, depending on what else is happening. (Uploading large videos via SFTP is especially resource-hungry!)

gAlleb commented 1 year ago

@Moonbase59 Thanks!

I tend to think that it is google-drive-ocamlfuse and it's consuming too much CPU lately (probably due to system upgrade or something) and all of this coincided with the upgrade of liquidsoap so the last one became prime suspect.

toots commented 1 year ago

If the problem is the virtual FS, it should be possible to define a copy protocol:

def protocol.copy(~rlog=_, ~maxtime=_, arg) =
  extname = file.extension(arg)
  tmpfile = file.temp("tmp", extname)
  file.copy(force=true, arg, tmpfile)
  [tmpfile]
end

protocol.add(
  static=true,
  "copy",
  protocol.copy,
  doc=
    "Copy file to a temporary destination",
  syntax="copy:/path/to/file.extname"
)

Then:

s = playlist(prefix="copy:", ...)

I'll be adding this protocol to main.