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.4k stars 130 forks source link

Playlist with mode="normal" containing external files loops on the second song #4002

Closed adworks closed 3 months ago

adworks commented 3 months ago

Describe the bug I have a playlist containing external music files, with reload_mode="watch" and mode="normal". When starting the script, the first song is played, then the second song is played over and over again without moving to the third song. This DOES NOT happen if the playlist contains local files.

To Reproduce

  1. Create a playlist with reload_mode="watch" and mode="normal" and output it like this:
radio = playlist(reload_mode="watch", mode="normal, "/etc/liquidsoap/stream-3/music.m3u")
radio = fallback([radio, blank(duration=5.0)])
  1. The "/etc/liquidsoap/stream-3/music.m3u" contains external files and it looks like this:
#EXTM3U
https://example.com/song1.mp3
https://example.com/song2.mp3
https://example.com/song3.mp3

At this point, the script will play song1.mp3, song2.mp3, song2.mp3, song2.mp3 and continue looping song2.mp3 forever.

If the "/etc/liquidsoap/stream-3/music.m3u" contains:

#EXTM3U
/etc/liquidsoap/stream-3/song1.mp3
/etc/liquidsoap/stream-3/song2.mp3
/etc/liquidsoap/stream-3/song3.mp3

then everything works as expected: the songs are played in the correct order 1-2-3-1-2-3-1-etc.

Expected behavior The playlist should be played in the correct order even if it contains external files.

Version details

Install method Using the savonet/liquidsoap:v2.2.5 docker image.

vitoyucepi commented 3 months ago

Hi @adworks, I can't reproduce this behavior. In my case, playlist works as expected.

radio = playlist("/tmp/test/music.m3u", mode="normal", reload_mode="watch")
radio = fallback([radio, blank(duration=5.0)])
radio.on_metadata(print)
output.dummy(radio, fallible=true)
services:
  liquidsoap:
    image: savonet/liquidsoap:v2.2.5
    command: /tmp/test/main.liq
    volumes:
      - ./:/tmp/test
Log ``` 2024/07/03 07:32:40 >>> LOG START 2024/07/03 07:32:34 [ffmpeg.filter.bitstream:3] No valid mode found for filter pgs_frame_merge! 2024/07/03 07:32:34 [main:3] Liquidsoap 2.2.5 2024/07/03 07:32:34 [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 4.02 or above] 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.3.0 cohttp-lwt=5.3.0 cohttp-lwt-unix=5.3.0 conduit=6.2.0 conduit-lwt=6.2.0 conduit-lwt-unix=6.2.0 cry=1.0.3 cstruct=6.2.0 ctypes=0.21.1 ctypes-foreign=0.21.1 ctypes.stubs=0.21.1 curl=0.9.2 domain-name=0.4.0 domain_shims dssi=0.1.5 dtools=0.4.5 dune-build-info=3.11.1 dune-private-libs.dune-section=3.11.1 dune-site=3.11.1 dune-site.private=3.11.1 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.1.10 ffmpeg-avcodec=1.1.10 ffmpeg-avdevice=1.1.10 ffmpeg-avfilter=1.1.10 ffmpeg-avutil=1.1.10 ffmpeg-swresample=1.1.10 ffmpeg-swscale=1.1.10 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 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.4 lilv=0.1.0 liquidsoap-lang=2.2.5 liquidsoap-lang.console=2.2.5 liquidsoap_alsa=f0fdb0e-dirty liquidsoap_ao=f0fdb0e-dirty liquidsoap_bjack=f0fdb0e-dirty liquidsoap_builtins=f0fdb0e-dirty liquidsoap_camlimages=f0fdb0e-dirty liquidsoap_core=f0fdb0e-dirty liquidsoap_dssi=f0fdb0e-dirty liquidsoap_faad=f0fdb0e-dirty liquidsoap_fdkaac=f0fdb0e-dirty liquidsoap_ffmpeg=f0fdb0e-dirty liquidsoap_flac=f0fdb0e-dirty liquidsoap_frei0r=f0fdb0e-dirty liquidsoap_gd=f0fdb0e-dirty liquidsoap_irc=f0fdb0e-dirty liquidsoap_jemalloc=f0fdb0e-dirty liquidsoap_ladspa=f0fdb0e-dirty liquidsoap_lame=f0fdb0e-dirty liquidsoap_lastfm=f0fdb0e-dirty liquidsoap_lilv=f0fdb0e-dirty liquidsoap_lo=f0fdb0e-dirty liquidsoap_mad=f0fdb0e-dirty liquidsoap_mem_usage=f0fdb0e-dirty liquidsoap_memtrace=f0fdb0e-dirty liquidsoap_ogg=f0fdb0e-dirty liquidsoap_ogg_flac=f0fdb0e-dirty liquidsoap_optionals=f0fdb0e-dirty liquidsoap_opus=f0fdb0e-dirty liquidsoap_osc=f0fdb0e-dirty liquidsoap_oss=f0fdb0e-dirty liquidsoap_portaudio=f0fdb0e-dirty liquidsoap_posix_time=f0fdb0e-dirty liquidsoap_prometheus=f0fdb0e-dirty liquidsoap_pulseaudio=f0fdb0e-dirty liquidsoap_runtime=f0fdb0e-dirty liquidsoap_samplerate=f0fdb0e-dirty liquidsoap_sdl=f0fdb0e-dirty liquidsoap_shine=f0fdb0e-dirty liquidsoap_soundtouch=f0fdb0e-dirty liquidsoap_speex=f0fdb0e-dirty liquidsoap_srt=f0fdb0e-dirty liquidsoap_ssl=f0fdb0e-dirty liquidsoap_stereotool=f0fdb0e-dirty liquidsoap_taglib=f0fdb0e-dirty liquidsoap_theora=f0fdb0e-dirty liquidsoap_tls=f0fdb0e-dirty liquidsoap_vorbis=f0fdb0e-dirty liquidsoap_xmlplaylist=f0fdb0e-dirty liquidsoap_yaml=f0fdb0e-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.5.0 mad=0.5.3 magic-mime=1.3.1 mem_usage=0.1.1 memtrace=0.2.3 menhirLib=20230608 metadata=0.3.0 mirage-crypto=0.11.2 mirage-crypto-ec=0.11.2 mirage-crypto-pk=0.11.2 mirage-crypto-rng=0.11.2 mirage-crypto-rng.unix=0.11.2 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 pcre=7.5.0 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_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=ccd3dea 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.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=f0fdb0e-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.1 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.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.13 2024/07/03 07:32:34 [clock:3] Using native (high-precision) implementation for latency control 2024/07/03 07:32:40 [main:3] Standard library loaded in 5.43 seconds. 2024/07/03 07:32:40 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main. 2024/07/03 07:32:40 [frame:3] Video frame size set to: 1280x720 2024/07/03 07:32:40 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples. 2024/07/03 07:32:40 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks. 2024/07/03 07:32:40 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks. 2024/07/03 07:32:40 [sandbox:3] Sandboxing disabled 2024/07/03 07:32:40 [startup:3] DSSI plugins registration: 0.00s 2024/07/03 07:32:40 [startup:3] FFmpeg filters registration: 0.03s 2024/07/03 07:32:40 [startup:3] FFmpeg bitstream filters registration: 0.00s 2024/07/03 07:32:40 [startup:3] Lilv plugins registration: 0.00s 2024/07/03 07:32:40 [startup:3] Frei0r plugin registration: 0.00s 2024/07/03 07:32:40 [startup:3] LADSPA plugins registration: 0.00s 2024/07/03 07:32:40 [startup:3] Typechecking: 5.20s 2024/07/03 07:32:40 [startup:3] Evaluation: 0.02s 2024/07/03 07:32:40 [startup:3] Typechecking: 0.04s 2024/07/03 07:32:40 [startup:3] Evaluation: 0.00s 2024/07/03 07:32:40 [startup:3] Typechecking: 0.00s 2024/07/03 07:32:40 [startup:3] Evaluation: 0.00s 2024/07/03 07:32:40 [startup:3] Loaded /tmp/test/main.liq: 0.00s 2024/07/03 07:32:40 [dummy:3] Content type is {audio=pcm(stereo)}. 2024/07/03 07:32:40 [music_m3u:3] Content type is {audio=pcm(stereo)}. 2024/07/03 07:32:40 [blank.2:3] Content type is {audio=pcm(stereo)}. 2024/07/03 07:32:40 [video.converter:3] Using preferred video converter: ffmpeg. 2024/07/03 07:32:40 [audio.converter:3] Using samplerate converter: libsamplerate. 2024/07/03 07:32:40 [clock.main:3] Streaming loop starts in auto-sync mode 2024/07/03 07:32:40 [clock.main:3] Delegating synchronization to CPU clock 2024/07/03 07:32:40 [video.text:3] Using sdl implementation 2024/07/03 07:32:40 [switch:3] Switch to blank.2. 2024/07/03 07:32:40 [decoder.ffmpeg:3] Requested content-type for "/tmp/liq-processa01e2a.mp3": {audio=pcm(stereo)} 2024/07/03 07:32:40 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/liq-processa01e2a.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)} 2024/07/03 07:32:40 [decoder.ffmpeg:3] Decoded content-type for "/tmp/liq-processa01e2a.mp3": {audio=pcm(mono)} 2024/07/03 07:32:45 [music_m3u:3] Prepared "/tmp/liq-processa01e2a.mp3" (RID 1). 2024/07/03 07:32:45 [switch:3] Switch to music_m3u with forgetful transition. [mp3float @ 0x7ed17d471400] Could not update timestamps for skipped samples. [("on_air_timestamp", "1719991965.00"), ("kind", "{audio=pcm(stereo)}"), ("decoder", "ffmpeg"), ("title", "music_1"), ("filename", "/tmp/liq-processa01e2a.mp3"), ("encoding", "Lavf61.1.100"), ("temporary", "true"), ("source", "music_m3u"), ("initial_uri", "https://example.com/song1.mp3"), ("status", "playing"), ("encoder", "Lavf61.1.100"), ("on_air", "2024/07/03 07:32:45"), ("rid", "1")] 2024/07/03 07:32:46 [decoder.ffmpeg:3] Requested content-type for "/tmp/liq-process0716f0.mp3": {audio=pcm(stereo)} 2024/07/03 07:32:46 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/liq-process0716f0.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)} 2024/07/03 07:32:46 [decoder.ffmpeg:3] Decoded content-type for "/tmp/liq-process0716f0.mp3": {audio=pcm(mono)} [mp3float @ 0x7ed17d471400] Could not update timestamps for discarded samples. 2024/07/03 07:32:54 [decoder:2] Decoding "/tmp/liq-processa01e2a.mp3" ended: Ffmpeg_decoder.End_of_file. [mp3float @ 0x7ed17d471400] Could not update timestamps for skipped samples. 2024/07/03 07:32:55 [music_m3u:3] Prepared "/tmp/liq-process0716f0.mp3" (RID 2). [("on_air_timestamp", "1719991975.00"), ("kind", "{audio=pcm(stereo)}"), ("decoder", "ffmpeg"), ("title", "music_2"), ("filename", "/tmp/liq-process0716f0.mp3"), ("encoding", "Lavf61.1.100"), ("temporary", "true"), ("source", "music_m3u"), ("initial_uri", "https://example.com/song2.mp3"), ("status", "playing"), ("encoder", "Lavf61.1.100"), ("on_air", "2024/07/03 07:32:55"), ("rid", "2")] 2024/07/03 07:32:56 [decoder.ffmpeg:3] Requested content-type for "/tmp/liq-processf02bec.mp3": {audio=pcm(stereo)} 2024/07/03 07:32:56 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/liq-processf02bec.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)} 2024/07/03 07:32:56 [decoder.ffmpeg:3] Decoded content-type for "/tmp/liq-processf02bec.mp3": {audio=pcm(mono)} [mp3float @ 0x7ed17d471400] Could not update timestamps for discarded samples. 2024/07/03 07:33:04 [decoder:2] Decoding "/tmp/liq-process0716f0.mp3" ended: Ffmpeg_decoder.End_of_file. 2024/07/03 07:33:05 [music_m3u:3] Prepared "/tmp/liq-processf02bec.mp3" (RID 3). [mp3float @ 0x7ed17d471400] Could not update timestamps for skipped samples. [("on_air_timestamp", "1719991985.00"), ("kind", "{audio=pcm(stereo)}"), ("decoder", "ffmpeg"), ("title", "music_3"), ("filename", "/tmp/liq-processf02bec.mp3"), ("encoding", "Lavf61.1.100"), ("temporary", "true"), ("source", "music_m3u"), ("initial_uri", "https://example.com/song3.mp3"), ("status", "playing"), ("encoder", "Lavf61.1.100"), ("on_air", "2024/07/03 07:33:05"), ("rid", "3")] 2024/07/03 07:33:05 [decoder.ffmpeg:3] Requested content-type for "/tmp/liq-process999adc.mp3": {audio=pcm(stereo)} 2024/07/03 07:33:05 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/liq-process999adc.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)} 2024/07/03 07:33:05 [decoder.ffmpeg:3] Decoded content-type for "/tmp/liq-process999adc.mp3": {audio=pcm(mono)} [mp3float @ 0x7ed17d471400] Could not update timestamps for discarded samples. 2024/07/03 07:33:14 [decoder:2] Decoding "/tmp/liq-processf02bec.mp3" ended: Ffmpeg_decoder.End_of_file. 2024/07/03 07:33:15 [music_m3u:3] Prepared "/tmp/liq-process999adc.mp3" (RID 4). [mp3float @ 0x7ed17d471400] Could not update timestamps for skipped samples. [("on_air_timestamp", "1719991995.00"), ("kind", "{audio=pcm(stereo)}"), ("decoder", "ffmpeg"), ("title", "music_1"), ("filename", "/tmp/liq-process999adc.mp3"), ("encoding", "Lavf61.1.100"), ("temporary", "true"), ("source", "music_m3u"), ("initial_uri", "https://example.com/song1.mp3"), ("status", "playing"), ("encoder", "Lavf61.1.100"), ("on_air", "2024/07/03 07:33:15"), ("rid", "4")] 2024/07/03 07:33:16 [decoder.ffmpeg:3] Requested content-type for "/tmp/liq-processa06350.mp3": {audio=pcm(stereo)} 2024/07/03 07:33:16 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/liq-processa06350.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)} 2024/07/03 07:33:16 [decoder.ffmpeg:3] Decoded content-type for "/tmp/liq-processa06350.mp3": {audio=pcm(mono)} [mp3float @ 0x7ed17d471400] Could not update timestamps for discarded samples. 2024/07/03 07:33:24 [decoder:2] Decoding "/tmp/liq-process999adc.mp3" ended: Ffmpeg_decoder.End_of_file. [mp3float @ 0x7ed17d471400] Could not update timestamps for skipped samples. 2024/07/03 07:33:25 [music_m3u:3] Prepared "/tmp/liq-processa06350.mp3" (RID 5). [("on_air_timestamp", "1719992005.00"), ("kind", "{audio=pcm(stereo)}"), ("decoder", "ffmpeg"), ("title", "music_2"), ("filename", "/tmp/liq-processa06350.mp3"), ("encoding", "Lavf61.1.100"), ("temporary", "true"), ("source", "music_m3u"), ("initial_uri", "https://example.com/song2.mp3"), ("status", "playing"), ("encoder", "Lavf61.1.100"), ("on_air", "2024/07/03 07:33:25"), ("rid", "5")] 2024/07/03 07:33:25 [decoder.ffmpeg:3] Requested content-type for "/tmp/liq-process34d9cb.mp3": {audio=pcm(stereo)} 2024/07/03 07:33:25 [decoder.ffmpeg:3] FFmpeg recognizes "/tmp/liq-process34d9cb.mp3" as audio: {codec: mp3, 44100Hz, 1 channel(s)} 2024/07/03 07:33:25 [decoder.ffmpeg:3] Decoded content-type for "/tmp/liq-process34d9cb.mp3": {audio=pcm(mono)} 2024/07/03 07:33:33 [main:3] Shutdown signal received. 2024/07/03 07:33:33 [threads:3] Main loop exited 2024/07/03 07:33:33 [main:3] Shutdown started! 2024/07/03 07:33:33 [threads:3] Waiting for main threads to terminate... 2024/07/03 07:33:33 [clock.main:3] Streaming loop stopped. 2024/07/03 07:33:33 [threads:3] Main threads terminated. 2024/07/03 07:33:33 [threads:3] Shutting down scheduler... 2024/07/03 07:33:33 [threads:3] Scheduler shut down. 2024/07/03 07:33:33 [main:3] Cleaning downloaded files... 2024/07/03 07:33:33 [main:3] Freeing memory... 2024/07/03 07:33:33 >>> LOG END ```

By the way, why do you use blank(duration=5.0) instead of mksafe or fallback(track_sensitive=false)?

adworks commented 3 months ago

Hey @vitoyucepi ,

Thank you so much for the quick reply.

It isn't a bug, it was our fault / a bug in our system: we were rewriting music.m3u periodically, regardless of whether its contents changed or not. Having reload_mode="watch", the playlist would be reloaded and having mode="normal" it would start from the top (and not from the second track - after printing the metadata and properly checking the log). So, my apologies for jumping to reporting this without investigating more thoroughly.

We use blank(duration=5.0) because we sometimes rewrite the music.m3u playlist. We thought that silence would be ok as a fallback when no music is available (while a new m3u file is generated, though this is mostly instant). We're just starting with liquidsoap, so: are we wrong to do this?

Thanks again!

vitoyucepi commented 3 months ago

and not from the second track

You may suddenly discover the same behavior as in #3343.

We thought that silence would be ok as a fallback when no music is available

radio = playlist("/tmp/test/music.m3u", mode="normal", reload_mode="watch")
radio = mksafe(radio)
radio = playlist("/tmp/test/music.m3u", mode="normal", reload_mode="watch")
radio = fallback([radio, blank()], track_sensitive=false)

If you need help with your script, feel free to start a new discussion.