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.44k stars 131 forks source link

Infinite loop 2.3.0+git@10453cf85 #4068

Closed gAlleb closed 1 month ago

gAlleb commented 4 months ago

Description

To separate bugs, I've created this issue regarding infinite loop. Quiet Bug in Azuracast issue is here https://github.com/savonet/liquidsoap/issues/4064

1. Sometimes this happens during startup (1 out of 5 times) - with alpine image:

liquidsoap-1  | 2024/08/01 14:23:42 [autocue.cue_file:3] Writing metadata to /tmp/cue_file15f464.json
liquidsoap-1  | 2024/08/01 14:23:47 [switch.5:3] Switch to main with transition.
liquidsoap-1  | 2024/08/01 14:23:47 [replay_metadata.4:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/01 14:23:47 [switch.5:3] Switch to on_track with transition.
liquidsoap-1  | 2024/08/01 14:23:47 [replay_metadata.5:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/01 14:23:47 [switch.5:3] Switch to main with transition.
liquidsoap-1  | 2024/08/01 14:23:47 [replay_metadata.6:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/01 14:23:47 [switch.5:3] Switch to on_track with transition.
liquidsoap-1  | 2024/08/01 14:23:47 [replay_metadata.7:3] Content type is {audio=pcm(stereo)}.

and looping...

This could be connected with

last_metadata = ref([])
def handle_jingle_mode(m) =
    if (m["jingle_mode"] == "true") then
        last_metadata()
    else
        last_metadata.set(m)
        m
    end
end

omfm_0 = metadata.map(update=false, strip=true, handle_jingle_mode, omfm_0)

From my dilettant point of view it all started from https://github.com/savonet/liquidsoap/commit/ae87e3b7567a7313d0473912e7ba4b95bf4bea2d (2.3.0+git@10453cf). Making resolution concurrent somehow messes up this function and maybe check_next - sometimes resulting in a loop. This has never happened before.

Looks like sometimes under load on startup when playing first jingle and waiting for autocue calculation - security kicks in and then this loop.


Steps to reproduce

Liquidsoap version

2.3.0+git@10453cf85

Liquidsoap build config

* Liquidsoap version  : 2.3.0+git@10453cf85

 * Compilation options
   - Release build       : false
   - Git SHA             : 10453cf85
   - OCaml version       : 4.14.2
   - OS type             : Unix
   - Libs versions       : alsa=0.3.0 angstrom=0.16.0 ao=0.2.4 asetmap=0.8.1 asn1-combinators=0.2.6 astring=0.8.5 base=v0.16.3 base.base_internalhash_types=v0.16.3 base.caml=v0.16.3 base.shadow_stdlib=v0.16.3 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 4.02 or above] ca-certs=v0.2.3 camlp-streams camomile.lib=2.0 cohttp=5.3.1 cohttp-lwt=5.3.0 cohttp-lwt-unix=5.3.0 conduit=6.2.2 conduit-lwt=6.2.2 conduit-lwt-unix=6.2.2 cry=1.0.3 cstruct=6.2.0 ctypes=0.22.0 ctypes-foreign=0.22.0 ctypes.stubs=0.22.0 curl=0.9.2 domain-name=0.4.0 domain_shims dssi=0.1.5 dtools=0.4.5 dune-build-info=3.15.3 dune-private-libs.dune-section=3.15.3 dune-site=3.15.3 dune-site.private=3.15.3 duppy=0.9.4 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 faad=0.5.2 fdkaac=0.3.3 ffmpeg-av=1.2.0 ffmpeg-avcodec=1.2.0 ffmpeg-avdevice=1.2.0 ffmpeg-avfilter=1.2.0 ffmpeg-avutil=1.2.0 ffmpeg-swresample=1.2.0 ffmpeg-swscale=1.2.0 fileutils=0.6.4 flac=0.5.1 flac.decoder=0.5.1 flac.ogg=0.5.1 fmt=0.9.0 fpath=0.7.3 frei0r=0.1.2 gen=1.1 gmap=0.3.0 hkdf=1.0.4 inotify=2.0-62-g5e58536 integers ipaddr=5.6.0 ipaddr-sexp=5.6.0 ipaddr.unix=5.6.0 irc-client irc-client-unix ladspa=0.2.2 lame=0.3.7 lastfm=0.3.4 lilv=0.2.0 liquidsoap-lang=2.3.0 liquidsoap-lang.console=2.3.0 liquidsoap_alsa=c721555-dirty liquidsoap_ao=c721555-dirty liquidsoap_bjack=c721555-dirty liquidsoap_builtins=c721555-dirty liquidsoap_core=c721555-dirty liquidsoap_dssi=c721555-dirty liquidsoap_faad=c721555-dirty liquidsoap_fdkaac=c721555-dirty liquidsoap_ffmpeg=c721555-dirty liquidsoap_flac=c721555-dirty liquidsoap_frei0r=c721555-dirty liquidsoap_irc=c721555-dirty liquidsoap_ladspa=c721555-dirty liquidsoap_lame=c721555-dirty liquidsoap_lastfm=c721555-dirty liquidsoap_lilv=c721555-dirty liquidsoap_lo=c721555-dirty liquidsoap_mad=c721555-dirty liquidsoap_ogg=c721555-dirty liquidsoap_ogg_flac=c721555-dirty liquidsoap_optionals=c721555-dirty liquidsoap_opus=c721555-dirty liquidsoap_osc=c721555-dirty liquidsoap_oss=c721555-dirty liquidsoap_portaudio=c721555-dirty liquidsoap_posix_time=c721555-dirty liquidsoap_prometheus=c721555-dirty liquidsoap_pulseaudio=c721555-dirty liquidsoap_runtime=c721555-dirty liquidsoap_samplerate=c721555-dirty liquidsoap_sdl=c721555-dirty liquidsoap_sdl_log_level=c721555-dirty liquidsoap_shine=c721555-dirty liquidsoap_soundtouch=c721555-dirty liquidsoap_speex=c721555-dirty liquidsoap_sqlite=c721555-dirty liquidsoap_srt=c721555-dirty liquidsoap_ssl=c721555-dirty liquidsoap_stdlib=c721555-dirty liquidsoap_stereotool=c721555-dirty liquidsoap_taglib=c721555-dirty liquidsoap_theora=c721555-dirty liquidsoap_tls=c721555-dirty liquidsoap_vorbis=c721555-dirty liquidsoap_xmlplaylist=c721555-dirty liquidsoap_yaml=c721555-dirty lo=0.2.0 logs=0.7.0 logs.fmt=0.7.0 logs.lwt=0.7.0 lwt=5.7.0 lwt.unix=5.7.0 macaddr=5.6.0 mad=0.5.3 magic-mime=1.3.1 mem_usage=0.1.1 memtrace=0.2.3 menhirLib=20231231 metadata=0.3.0 mirage-crypto=0.11.3 mirage-crypto-ec=0.11.3 mirage-crypto-pk=0.11.3 mirage-crypto-rng=0.11.3 mirage-crypto-rng.unix=0.11.3 mm=0.8.5 mm.audio=0.8.5 mm.base=0.8.5 mm.image=0.8.5 mm.midi=0.8.5 mm.video=0.8.5 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 portaudio=0.2.3 posix-base=5a7f328 posix-socket=5a7f328 posix-socket.constants=5a7f328 posix-socket.stubs=5a7f328 posix-socket.types=5a7f328 posix-time2=5a7f328 posix-time2.constants=5a7f328 posix-time2.stubs=5a7f328 posix-time2.types=5a7f328 posix-types=5a7f328 posix-types.constants=5a7f328 ppx_compare.runtime-lib=v0.16.0 ppx_hash.runtime-lib=v0.16.0 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.11.0 result=1.5 rresult=0.7.0 samplerate=0.1.7 saturn_lockfree=0.4.1 sedlex=3.2 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 sqlite3=5.1.0 srt=0.3.1 srt.constants=0.3.1 srt.stubs=0.3.1 srt.stubs.locked=0.3.1 srt.types=0.3.1 ssl=0.7.0 stdlib-shims=0.3.0 stereotool=c721555-dirty 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=[internal] tls=0.17.4 tsdl=v1.0.0 tsdl-image=0.5 tsdl-ttf=0.6 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.4.0 uri-sexp=4.4.0 uri.services=4.4.0 vorbis=0.8.1 vorbis.decoder=0.8.1 x509=0.16.5 xmlm=1.4.0 xmlplaylist=0.1.5 yaml=3.2.0 yaml.bindings=3.2.0 yaml.bindings.types=3.2.0 yaml.c=3.2.0 yaml.ffi=3.2.0 yaml.types=3.2.0 zarith=1.13
   - architecture        : amd64
   - host                : x86_64-pc-linux-musl
   - target              : x86_64-pc-linux-musl
   - system              : linux
   - ocamlopt_cflags     : -O2 -fno-strict-aliasing -fwrapv -pthread -fPIC
   - native_c_compiler   : gcc -O2 -fno-strict-aliasing -fwrapv -pthread -fPIC -D_FILE_OFFSET_BITS=64
   - native_c_libraries  : -lm

 * Configured paths
   - mode              : posix
   - standard library  : /usr/share/liquidsoap/libs
   - scripted binaries : /usr/share/liquidsoap/bin
   - rundir            : /var/run/liquidsoap
   - logdir            : /var/log/liquidsoap
   - user cache        : $HOME/.cache/liquidsoap (override with $LIQ_CACHE_USER_DIR)
   - system cache      : /var/cache/liquidsoap (override with $LIQ_CACHE_SYSTEM_DIR)
   - camomile files    : /usr/share/liquidsoap/camomile

 * Supported input formats
   - MP3               : yes
   - AAC               : yes
   - Ffmpeg            : yes
   - Flac (native)     : yes
   - Flac (ogg)        : yes
   - Opus              : yes
   - Speex             : yes
   - Theora            : yes
   - Vorbis            : yes

 * Supported output formats
   - FDK-AAC           : yes
   - Ffmpeg            : yes
   - MP3               : yes
   - MP3 (fixed-point) : yes
   - Flac (native)     : yes
   - Flac (ogg)        : yes
   - Opus              : yes
   - Speex             : yes
   - Theora            : yes
   - Vorbis            : yes

 * Tags
   - Taglib (ID3 tags) : yes
   - Vorbis            : yes

 * Input / output
   - ALSA              : yes
   - AO                : yes
   - FFmpeg            : yes
   - JACK              : yes
   - OSS               : yes
   - Portaudio         : yes
   - Pulseaudio        : yes
   - SRT               : yes

 * Audio manipulation
   - FFmpeg            : yes
   - LADSPA            : yes
   - Lilv              : yes
   - Samplerate        : yes
   - SoundTouch        : yes
   - StereoTool        : yes

 * Video manipulation
   - camlimages        : no (requires camlimages)
   - FFmpeg            : yes
   - frei0r            : yes
   - ImageLib          : no (requires imagelib)
   - SDL               : yes

 * MIDI manipulation
   - DSSI              : yes

 * Visualization
   - GD                : no (requires gd)
   - Graphics          : no (requires graphics)
   - SDL               : yes

 * Additional libraries
   - FFmpeg filters    : yes
   - FFmpeg devices    : yes
   - inotify           : yes
   - irc               : yes
   - jemalloc          : no (requires jemalloc)
   - lastfm            : yes
   - lo                : yes
   - memtrace          : no (requires memtrace)
   - osc               : yes
   - ssl               : yes
   - sqlite3           : yes
   - tls               : yes
   - posix-time2       : yes
   - windows service   : no (requires winsvc)
   - YAML support      : yes
   - XML playlists     : yes

 * Monitoring
   - Prometheus        : yes

Installation method

From official container image

Additional Info

No response

gAlleb commented 3 months ago

One time it has stopped looping with a message:

liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.874:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to main with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.875:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to on_track with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.876:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to main with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.877:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to on_track with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.878:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to main with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.879:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to on_track with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.880:3] Content type is {audio=pcm(stereo)}.
liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Switch to main with transition.
liquidsoap-1  | 2024/08/03 09:00:49 [replay_metadata.881:3] Content type is {audio=pcm(stereo)}.

liquidsoap-1  | 2024/08/03 09:00:49 [switch.5:3] Source created multiple tracks in a single frame! Sub-frame tracks are not supported and are merged into a single one..
gAlleb commented 3 months ago

So this is minimal reproduction which I could get. I think number of playlists somehow connected. Only one playlist with check function. Happens with alpine 10453cf85.


%include "/home/radio/liquidsoap/autocue/autocue.cue_file-2.3.0.liq"

enable_autocue_metadata()

def my_hash(m)
artist = metadata.artist(m)
string.trim(artist)
end
l = playlog(persistency="/home/radio/liquidsoap/omfm/log/songs_check_omfm.log", duration=7200.,hash=my_hash)

def check(r)
  #log.critical(label="request.uri","#{request.uri(r)}")
  if request.resolve(r) then
    m = request.metadata(r)

    if l.last(m) < 6000. then
    log(level=3,"Rejecting #{m['artist']} (played #{l.last(m)}s ago).")
      false
    else
      l.add(m)
      true
    end
  else
    false
  end
  end

 # one playlist with check function 

relax = playlist(check_next=check,prefix='annotate:liq_blankskip="false",playlist="Main Playlist":',id="omFM Main Playlist", reload_mode="watch", "/home/radio/playlist/icecast-playlist-relax.m3u")

# other playlists 

…
…
…

omfm_0 = relax

omfm_0 = switch([
({23h-4h}, lofi2), 
({4h-6h}, mantraom528), 
({10h-11h}, omfmclassic), 
(predicate.at_most(2,{23h00-23h15}), jinglesnightshiftintroomfm), 
(predicate.at_most(2,{10h00m-10h15m}), jinglesclassicintroomfm), 
(predicate.once({10h20m-10h50m}), jinglesclassicomfm), 
(predicate.once({9h-10h or 11h-13h or 13h-16h or 18h-19h or 20h-21h or 22h-23h}), suttas),
(predicate.once({19h-20h}), nazarenko), 
({6h0m-10h0m or 11h0m-23h0m }, rotate(weights=[1,4], [jinglesomfm, omfm_0])),
({true}, omfm_0)
])

icecast_omfm = mksafe(omfm_0)

output.icecast(%mp3(bitrate=128))

Maybe I’m doing something wrong with check_next function. It started happening only with the above release. @toots, maybe it’s because of adding autocue.cue_file? However before 10453cf85 everything was great.

toots commented 3 months ago

This is very likely fixed in the latest rolling-release-v2.3.x

toots commented 1 month ago

Hi! Any update on this one?

gAlleb commented 1 month ago

Haven't noticed it for a while. Let's close this one. Thanks!