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

Liquidsoap exits on disconnect from PulseAudio #4157

Closed tatokis closed 1 month ago

tatokis commented 2 months ago

Description

Liquidsoap exits when the connection to the PulseAudio server is terminated.

Steps to reproduce

stream = input.pulseaudio(device="stream.monitor")
output.file(fallible=true, %wav, "test.wav", stream)
  1. Run above script
  2. systemctl --user restart pulseaudio or systemctl --user restart pipewire-pulse
  3. Observe Liqudsoap no longer running:
    2024/10/04 14:55:47 [clock.pulseaudio:2] Source output_file failed while streaming: Pulseaudio error: Connection terminated!
    2024/10/04 14:55:47 [clock.pulseaudio:2] Raised by primitive operation at Pulseaudio in file "src/pulseaudio.ml" (inlined), line 39, characters 0-1023
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Pulseaudio_io.input#get_frame in file "src/core/io/pulseaudio_io.ml", line 156, characters 6-34
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 657, characters 6-24
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Source.operator#get in file "src/core/source.ml", line 785, characters 12-44
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Output.output#output in file "src/core/outputs/output.ml", line 184, characters 10-30
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Pipe_output.piped_output#output in file "src/core/outputs/pipe_output.ml", line 367, characters 10-21
    2024/10/04 14:55:47 [clock.pulseaudio:2] Re-raised at Pipe_output.piped_output#reopen_on_error in file "src/core/outputs/pipe_output.ml", line 359, characters 12-48
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Clock.MkClock.clock#end_tick.(fun) in file "src/core/clock.ml", line 318, characters 16-24
    2024/10/04 14:55:47 [clock.pulseaudio:2]
    2024/10/04 14:55:47 [clock.pulseaudio:2] Source input.pulseaudio failed while streaming: Pulseaudio error: Connection terminated!
    2024/10/04 14:55:47 [clock.pulseaudio:2] Raised by primitive operation at Pulseaudio in file "src/pulseaudio.ml" (inlined), line 39, characters 0-1023
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Pulseaudio_io.input#get_frame in file "src/core/io/pulseaudio_io.ml", line 156, characters 6-34
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Source.operator#instrumented_get_frame in file "src/core/source.ml", line 657, characters 6-24
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Source.operator#get in file "src/core/source.ml", line 785, characters 12-44
    2024/10/04 14:55:47 [clock.pulseaudio:2] Called from Clock.MkClock.clock#end_tick.(fun) in file "src/core/clock.ml", line 318, characters 16-24

Expected behavior

The PulseAudio source should be marked as failed so that a fallback can take place, and other streams aren't affected. It should periodically attempt to reconnect to the server.

Liquidsoap version

Liquidsoap 2.2.4-1+dev
Copyright (c) 2003-2023 Savonet team
Liquidsoap is open-source software, released under GNU General Public License.
See <http://liquidsoap.info> for more information.

Liquidsoap build config

* Liquidsoap version  : 2.2.4-1+dev

 * Compilation options
   - Release build       : false
   - Git SHA             : (none)
   - OCaml version       : 4.14.1
   - OS type             : Unix
   - Libs versions       : alsa=0.3.0 angstrom=0.16.0 ao=0.2.4 bigarray=[distributed with Ocaml] bigstringaf=0.9.1 bjack=0.1.6 bytes=[distributed with OCaml 4.02 or above] 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 cry=1.0.3 curl=0.9.2 dssi=0.1.5 dtools=0.4.5 dune-build-info=3.14.0 dune-private-libs.dune-section=3.14.0 dune-site=3.14.0 dune-site.private=3.14.0 duppy=0.9.4 faad=0.5.1 ffmpeg-av=1.1.11 ffmpeg-avcodec=1.1.11 ffmpeg-avdevice=1.1.11 ffmpeg-avfilter=1.1.11 ffmpeg-avutil=1.1.11 ffmpeg-swresample=1.1.11 ffmpeg-swscale=1.1.11 fileutils flac=0.5.0 flac.decoder=0.5.0 flac.ogg=0.5.0 frei0r=0.1.2 gd=0.5.1 gen=1.1 graphics=5.1.2 inotify=2.0-62-g5e58536 ladspa=0.2.2 lame=0.3.7 liquidsoap-lang=2.2.4-1 liquidsoap-lang.console=2.2.4-1 liquidsoap_alsa liquidsoap_ao liquidsoap_bjack liquidsoap_builtins liquidsoap_camlimages liquidsoap_core liquidsoap_dssi liquidsoap_faad liquidsoap_ffmpeg liquidsoap_flac liquidsoap_frei0r liquidsoap_gd liquidsoap_graphics liquidsoap_ladspa liquidsoap_lame liquidsoap_lo liquidsoap_mad liquidsoap_ogg liquidsoap_ogg_flac liquidsoap_optionals liquidsoap_opus liquidsoap_oss liquidsoap_portaudio liquidsoap_pulseaudio liquidsoap_runtime liquidsoap_samplerate liquidsoap_shine liquidsoap_soundtouch liquidsoap_speex liquidsoap_ssl liquidsoap_taglib liquidsoap_theora liquidsoap_vorbis liquidsoap_xmlplaylist lo=0.2.0 mad=0.5.2 magic-mime=1.3.1 menhirLib=20231231 metadata=0.3.0 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 ogg=0.7.4 ogg.decoder=0.7.4 opus=0.2.2 opus.decoder=0.2.2 pcre=7.5.0 portaudio=0.2.3 pulseaudio=0.1.5 re=1.11.0 samplerate=0.1.6 sedlex=3.2 seq=[distributed with OCaml 4.07 or above] shine=0.2.3 soundtouch=0.1.9 speex=0.4.1 speex.decoder=0.4.1 ssl=0.7.0 stdlib-shims=[distributed with OCaml 4.07 or above] str=[distributed with Ocaml] stringext=1.6.0 syslog=2.0.2 taglib=0.3.10 theora=0.4.0 theora.decoder=0.4.0 threads=[distributed with Ocaml] threads.posix=[internal] unix=[distributed with Ocaml] uri=4.4.0 vorbis=0.8.0 vorbis.decoder=0.8.0 xmlm=1.4.0 xmlplaylist=0.1.5
   - architecture        : amd64
   - host                : x86_64-pc-linux-gnu
   - target              : x86_64-pc-linux-gnu
   - system              : linux
   - ocamlopt_cflags     : -O2 -fno-strict-aliasing -fwrapv -pthread -fPIC -g -O2 -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection
   - native_c_compiler   : x86_64-linux-gnu-gcc -O2 -fno-strict-aliasing -fwrapv -pthread -fPIC -g -O2 -fstack-protector-strong -fstack-clash-protection -Wformat -Werror=format-security -fcf-protection -D_FILE_OFFSET_BITS=64 -Wdate-time -D_FORTIFY_SOURCE=2
   - native_c_libraries  : -lm

 * Configured paths
   - mode              : default
   - standard library  : (set by dune-site)
   - scripted binaries : (set by dune-site)
   - rundir            : (set by dune-site)
   - logdir            : (set by dune-site)
   - camomile files    : (set by dune-site)

 * 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           : no (requires fdkaac)
   - 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
   - GStreamer         : no (requires gstreamer)
   - JACK              : yes
   - OSS               : yes
   - Portaudio         : yes
   - Pulseaudio        : yes
   - SRT               : no (requires srt)

 * Audio manipulation
   - FFmpeg            : yes
   - LADSPA            : yes
   - Lilv              : no (requires lilv)
   - Samplerate        : yes
   - SoundTouch        : yes
   - StereoTool        : no (requires ctypes-foreign)

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

 * MIDI manipulation
   - DSSI              : yes

 * Visualization
   - GD                : yes
   - Graphics          : yes
   - SDL               : no (requires tsdl-image & tsdl-ttf)

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

 * Monitoring
   - Prometheus        : no (requires prometheus)

Installation method

From distribution packages

Additional Info

No response

tatokis commented 1 month ago

Thank you very much for taking the time to implement this! It is really appreciated.

I just tested it, and it seems to only work when Liquidsoap is started with PulseAudio not running.

2024/10/13 17:52:52 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:53 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:54 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:55 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:56 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:57 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:58 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:52:59 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused
2024/10/13 17:53:00 [input.pulseaudio:2] Error while connecting to pulseaudio: Pulseaudio error: Connection refused

It keeps retrying every retry_delay seconds, and when the PulseAudio server finally starts up, it connects successfully.

However, if I run systemctl --user restart pipewire-pulse while Liquidsoap is running, it 100%s a CPU core, keeps spamming the following ad nauseam, and never reconnects.

2024/10/13 17:55:31 [output_file:3] Source failed (no more tracks) stopping output...
2024/10/13 17:55:31 [input.pulseaudio:2] Error while reading from pulseaudio: Pulseaudio error: Connection terminated
2024/10/13 17:55:31 [output_file:3] Source failed (no more tracks) stopping output...
2024/10/13 17:55:31 [input.pulseaudio:2] Error while reading from pulseaudio: Pulseaudio error: Connection terminated
2024/10/13 17:55:31 [output_file:3] Source failed (no more tracks) stopping output...
2024/10/13 17:55:31 [input.pulseaudio:2] Error while reading from pulseaudio: Pulseaudio error: Connection terminated
2024/10/13 17:55:31 [output_file:3] Source failed (no more tracks) stopping output...
2024/10/13 17:55:31 [input.pulseaudio:2] Error while reading from pulseaudio: Pulseaudio error: Connection terminated
2024/10/13 17:55:31 [output_file:3] Source failed (no more tracks) stopping output...
2024/10/13 17:55:31 [input.pulseaudio:2] Error while reading from pulseaudio: Pulseaudio error: Connection terminated
2024/10/13 17:55:31 [output_file:3] Source failed (no more tracks) stopping output...
2024/10/13 17:55:31 [input.pulseaudio:2] Error while reading from pulseaudio: Pulseaudio error: Connection terminated

In short:

  1. start Liquidsoap
  2. start PulseAudio
  3. it works

but

  1. start PulseAudio
  2. start Liquidsoap
  3. restart PulseAudio
  4. Liquidsoap won't reconnect
tatokis commented 1 month ago

Not entirely sure this is the right way to fix this, thus not opening a PR, but it seems to work:

diff --git a/src/core/io/pulseaudio_io.ml b/src/core/io/pulseaudio_io.ml
index 7cb56d1ce..87aa0a03a 100644
--- a/src/core/io/pulseaudio_io.ml
+++ b/src/core/io/pulseaudio_io.ml
@@ -222,6 +222,7 @@ class input p =
               (Printexc.to_string exn)
           in
           on_error error;
+          self#close_device;
           Utils.log_exception ~log:self#log
             ~bt:(Printexc.raw_backtrace_to_string bt)
             error;

EDIT: It doesn't actually fix the high CPU load, but it does stop the log spam and allows reconnecting at least.

toots commented 1 month ago

Thanks for the follow-up. You're getting a different error than I get when restarting pulseaudio.

I pushed some fixes to mitigate your issue. Can you confirm if they help on your end?

tatokis commented 1 month ago

With

2024/10/14 16:39:10 [main:3] Liquidsoap rolling-release-v2.3.x-7-g61d12cd+dev

it reconnects as expected. The high CPU usage unfortunately is still there though.

While not the same, perhaps you can reproduce it by running it as follows

PULSE_SERVER=unix:/dev/null liquidsoap test.liq
tatokis commented 1 month ago

It seems like whatever is going wrong is causing the clock to run as fast as it possibly can, which explains the high CPU usage.

I tried adding a playlist fallback for when pulse fails, and it ends up decoding and pushing the audio to the stream much, much faster than realtime. Something like 30 minutes of buffered audio in the player within 60 wall clock seconds.

stream = input.pulseaudio(device="stream.monitor")
fallback_dj = playlist(mode="random", "/path/to/music/files")
out_stream = fallback(track_sensitive=false, replay_metadata=true, [stream, fallback_dj, sine()])
output.icecast(
    %ffmpeg(format="ogg", %audio(
        codec="libopus",
        samplerate=48000,
        b="128k",
        vbr="constrained",
        application="audio",
        channels=2,
        compression_level=10,
    )),
    host = icecast_host,
    port = icecast_port,
    password = icecast_pass,
    mount = "/live.ogg",
    send_icy_metadata=false,
    out_stream
)
toots commented 1 month ago

Thanks. I think you did put your finger on it. The code was mistakenly using the device and not the stream (which is the part that gets defined when connected) to decide if the source controls its own latency. We probably didn't notice because it was always connected before.

Just pushed a patch fixing this. Hopefully this helps.

tatokis commented 1 month ago

Yup, that fixed it. Awesome!

Thank you :)