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.39k stars 127 forks source link

`clock(sync="none")` with `output.dummy` hangs up liquidsoap #3543

Open vitoyucepi opened 9 months ago

vitoyucepi commented 9 months ago

Describe the bug While debugging other issues, I use output.dummy with clock(sync="none") to consume a lot of tracks from the playlist. Sometimes the liquidsoap hangs completely without any activity.

It's difficult to reproduce the problem, but recently I found a more or less stable way. I use files with covers and enable replaygain calculation. As a result, the logging stops after a few tracks and the CPU usage drops. The process cannot be stopped normally and must be killed.

Log ``` INFO: Loading Sdl_image, Target = linux INFO: Loading Sdl_ttf, Target = linux 2023/11/20 07:09:02 >>> LOG START 2023/11/20 07:08:58 [main:3] Liquidsoap 2.2.2 2023/11/20 07:08:58 [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/20 07:08:58 [clock:3] Using native (high-precision) implementation for latency control 2023/11/20 07:09:01 [main:3] Standard library loaded in 3.56 seconds. 2023/11/20 07:09:02 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main. 2023/11/20 07:09:02 [frame:3] Video frame size set to: 1280x720 2023/11/20 07:09:02 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples. 2023/11/20 07:09:02 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks. 2023/11/20 07:09:02 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks. 2023/11/20 07:09:02 [sandbox:3] Sandboxing disabled 2023/11/20 07:09:02 [startup:3] DSSI plugins registration: 0.00s 2023/11/20 07:09:02 [startup:3] FFmpeg filters registration: 0.02s 2023/11/20 07:09:02 [startup:3] FFmpeg bitstream filters registration: 0.00s 2023/11/20 07:09:02 [startup:3] Lilv plugins registration: 0.00s 2023/11/20 07:09:02 [startup:3] Frei0r plugin registration: 0.00s 2023/11/20 07:09:02 [startup:3] LADSPA plugins registration: 0.00s 2023/11/20 07:09:02 [startup:3] Typechecking: 3.33s 2023/11/20 07:09:02 [startup:3] Evaluation: 0.01s 2023/11/20 07:09:02 [startup:3] Typechecking: 0.03s 2023/11/20 07:09:02 [startup:3] Evaluation: 0.00s 2023/11/20 07:09:02 [startup:3] Typechecking: 0.00s 2023/11/20 07:09:02 [startup:3] Evaluation: 0.00s 2023/11/20 07:09:02 [startup:3] Loaded main.liq: 0.00s 2023/11/20 07:09:02 [dummy:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [source.2:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [track_amplify:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [metadata_map.2:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [metadata_map:3] Content type is {}. 2023/11/20 07:09:02 [music:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [clock.source.2:3] Streaming loop starts in no sync mode 2023/11/20 07:09:02 [clock.source.2:3] Delegating synchronization to active sources 2023/11/20 07:09:02 [video.converter:3] Using preferred video converter: ffmpeg. 2023/11/20 07:09:02 [audio.converter:3] Using samplerate converter: libsamplerate. 2023/11/20 07:09:02 [video.text:3] Using sdl implementation 2023/11/20 07:09:02 [decoder.ffmpeg:3] Requested content-type for "/tmp/test/music/6.mp3": {audio=pcm(stereo)} 2023/11/20 07:09:02 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/test/music/6.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)}, video: {codec: png, 600x600, rgb48be} 2023/11/20 07:09:02 [decoder.ffmpeg:3] Decoded content-type for "/tmp/test/music/6.mp3": {audio=pcm(mono)} 2023/11/20 07:09:02 [file.replaygain:3] Computing replay gain for "/tmp/test/music/6.mp3" 2023/11/20 07:09:02 [dummy.2:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [source.replaygain.compute:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [request.once:3] Content type is {audio=pcm(stereo)}. 2023/11/20 07:09:02 [decoder.ffmpeg:3] Requested content-type for "/tmp/test/music/6.mp3": {audio=pcm(stereo)} 2023/11/20 07:09:02 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/test/music/6.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)}, video: {codec: png, 600x600, rgb48be} 2023/11/20 07:09:02 [decoder.ffmpeg:3] Decoded content-type for "/tmp/test/music/6.mp3": {audio=pcm(mono)} 2023/11/20 07:09:02 [request.once:3] Prepared "/tmp/test/music/6.mp3" (RID 1). [mp3float @ 0x7fec1d640900] Could not update timestamps for skipped samples. [mp3float @ 0x7fec1d640900] Could not update timestamps for discarded samples. 2023/11/20 07:09:02 [decoder:2] Decoding "/tmp/test/music/6.mp3" ended: Ffmpeg_decoder.End_of_file. 2023/11/20 07:09:02 [dummy.2:3] Source failed (no more tracks) stopping output... 2023/11/20 07:09:02 [file.replaygain:3] Computed replay gain 6.87 dB for "/tmp/test/music/6.mp3" (time: 0.0696790218353 s). ^C2023/11/20 07:09:09 [main:3] Shutdown signal received. 2023/11/20 07:09:09 [threads:3] Main loop exited 2023/11/20 07:09:09 [main:3] Shutdown started! 2023/11/20 07:09:09 [threads:3] Waiting for main threads to terminate... ```

To Reproduce

  1. Generate tracks with covers. 
    mkdir music;
for i in $(seq 1 9); do
  convert -size 600x600 plasma: cover.png;
  ffmpeg \
      -f lavfi -i "sine=frequency=${i}00:duration=1" \
      -i "cover.png" \
      -map 0:0 -map 1:0 \
      -c:v copy \
      -c:a libmp3lame -b:a 128k \
      -id3v2_version 4 \
      -metadata "title=$i" \
      -metadata:s:v title="Album cover" \
      -metadata:s:v comment="Cover (front)" \
      "music/$i.mp3";
  rm cover.png;
done

  2. main.liq

    enable_replaygain_metadata()

s = playlist("/tmp/test/music")
s = replaygain(s)
s = clock(sync="none", s)
output.dummy(s, fallible=true)

If you run this script, you should notice that the logging stops completely after some time. Even the strace -f -o /tmp/log liquidsoap /tmp/test/main.liq log stops abruptly.

Expected behavior The output.dummy should not suddenly stop the execution of the script.

Version details

Install method

Common issues N/A

toots commented 9 months ago

Thanks for reporting. I plan on addressing extreme cases like this during the clock rewrite, which I hope to get started soon.