Hardware Output Audio using ALSA breaks stream

[fiercestartx]

Describe the bug

When enabling Hardware Output Audio in the configuration file, then restarting Libretime services, Liquidsoap seems to have trouble with dealing with any output streams and constantly exits and relaunches. The On Air light is also extinguished when a file should be playing and the local Icecast stream drops out and comes back rapidly.

Trying to output audio to built in 'Line Out' on motherboard and also tried a USB Soundcard, both methods yield same errors. Also, for the record, I did add the 'libretime' user to the 'audio' group! ;-)

To reproduce

1. Goto config configuration file /etc/libretime/config.yml
2. Goto 'System Outputs' section and set enable to true and enter kind as alsa
3. Restart Libretime services using sudo systemctl restart libretime.target
4. On Air light on web UI is extinguished and no audio is heard through sound device and localhost Icecast stream will constantly fall over and relaunch

Expected behavior

Audio output to be sent to soundcard/line out and local streams running on local Icecast server

Relevant log output or error messages

● libretime-liquidsoap.service - LibreTime Liquidsoap Service
     Loaded: loaded (/lib/systemd/system/libretime-liquidsoap.service; enabled; vendor preset: enabled)
     Active: active (running) since Sat 2024-01-13 19:05:14 GMT; 2s ago
   Main PID: 12413 (liquidsoap)
      Tasks: 16 (limit: 4477)
     Memory: 72.8M
     CGroup: /system.slice/libretime-liquidsoap.service
             ├─12413 libretime-liquidsoap --verbose /var/lib/libretime/playout/radio.liq
             ├─12422 timeout --signal=KILL 45 libretime-playout-notify started
             ├─12426 /opt/libretime/bin/python3 /usr/local/bin/libretime-playout-notify started
             ├─12439 timeout --signal=KILL 45 libretime-playout-notify stream 1 1705172715.69
             ├─12441 /opt/libretime/bin/python3 /usr/local/bin/libretime-playout-notify stream 1 1705172715.69
             ├─12444 timeout --signal=KILL 45 libretime-playout-notify live master_dj false
             ├─12445 /opt/libretime/bin/python3 /usr/local/bin/libretime-playout-notify live master_dj false
             ├─12447 timeout --signal=KILL 45 libretime-playout-notify live live_dj false
             └─12448 /opt/libretime/bin/python3 /usr/local/bin/libretime-playout-notify live live_dj false

Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [main:3] Shutdown started!
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [main:3] Waiting for main threads to terminate...
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [icecast:1:3] Closing connection...
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [lang:3] timeout --signal=KILL 45 libretime-playout-notify live 'master_dj' 'false' &
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [harbor:3] Removing mountpoint '/main' on port 8001
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [harbor:3] Nothing more on port 8001: closing sockets.
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [lang:3] timeout --signal=KILL 45 libretime-playout-notify live 'live_dj' 'false' &
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [harbor:3] Removing mountpoint '/show' on port 8002
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [harbor:3] Nothing more on port 8002: closing sockets.
Jan 13 19:05:15 airtime libretime-liquidsoap[12413]: 2024/01/13 19:05:15 [clock.wallclock_alsa:3] Streaming loop stopped.

LibreTime version

4.0.0

Installation method and OS / Environment

Operating system: Ubuntu Server Focal Fossa 20.04.5
Method: Installer script

Installation details

No response

Client Environment

Operating system: macOS Ventura 13.4
Browser: Google Chrome 120.0.6099.216

Screenshots

[jooola]

Check the liquidsoap logs to check if it started properly. Failure for the system output will make liquidsoap crash at some point.

[fiercestartx]

Check the liquidsoap logs to check if it started properly. Failure for the system output will make liquidsoap crash at some point.

Here is what the logfile for liquidsoap outputs in var/logs/libretime/liquidsoap.log, it seems to repeat these logs every time it tries to start up;

2024/01/19 12:21:29 >>> LOG START
2024/01/19 12:21:29 [main:3] Liquidsoap 1.4.2
2024/01/19 12:21:29 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=[unspecified] sedlex=2.1 menhirLib=20200123 dtools=0.4.1 duppy=0.8.0 cry=0.6.4 mm=0.5.0 xmlplaylist=0.1.3 lastfm=0.3.2 ogg=0.5.2 vorbis=0.7.1 opus=0.1.3 speex=0.2.1 mad=0.4.4 flac=0.1.5 flac.ogg=0.1.5 dynlink=[distributed with Ocaml] lame=0.3.2 shine=0.2.0 gstreamer=0.3.0 frei0r=0.1.0 theora=0.3.1 gavl=0.1.5 ffmpeg=0.4.1 bjack=0.1.4 alsa=0.2.3 ao=0.2.0 samplerate=0.1.2 taglib=0.3.1 ssl=0.5.9 magic=0.7.3 camomile=[unspecified] yojson=[unspecified] faad=0.4.0 soundtouch=0.1.7 portaudio=0.2.1 pulseaudio=0.1.2 ladspa=0.1.4 sdl=0.9.1 camlimages=4.2.0 lo=0.1.2 gd=1.0a5
2024/01/19 12:21:29 [gstreamer.loader:3] Loaded GStreamer 1.16.3 0
2024/01/19 12:21:29 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.
2024/01/19 12:21:29 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2024/01/19 12:21:29 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2024/01/19 12:21:29 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2024/01/19 12:21:29 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2024/01/19 12:21:29 [lang:3] timeout --signal=KILL 45 libretime-playout-notify started &
2024/01/19 12:21:29 [sandbox:3] Could not find binary bwrap, disabling sandboxing..
2024/01/19 12:21:29 [video.converter:3] Using preferred video converter: gavl.
2024/01/19 12:21:29 [audio.converter:3] Using samplerate converter: ffmpeg.
2024/01/19 12:21:29 [harbor:3] Adding mountpoint '/main' on port 8001
2024/01/19 12:21:29 [harbor:3] Adding mountpoint '/show' on port 8002
2024/01/19 12:21:29 [icecast:1:3] Connecting mount main.mp3 for source@localhost...
2024/01/19 12:21:29 [icecast:1:3] Connection setup was successful.
2024/01/19 12:21:29 [lang:3] timeout --signal=KILL 45 libretime-playout-notify stream '1' '1705666889.15' &
2024/01/19 12:21:29 [clock.wallclock_alsa:3] Streaming loop starts, synchronized by active sources.
2024/01/19 12:21:29 [map_metadata:offline:3] Inserting missing metadata.
2024/01/19 12:21:29 [switch:blank+schedule+show+main:3] Switch to switch:blank+schedule+show.
2024/01/19 12:21:29 [switch:blank+schedule+show:3] Switch to switch:blank+schedule.
2024/01/19 12:21:29 [switch:blank+schedule:3] Switch to map_metadata:offline.
2024/01/19 12:21:29 [alsa:1:3] Using ALSA 1.2.2.
2024/01/19 12:21:29 [threads:3] Thread "alsa:1" aborts with exception Alsa error: No such file or directory!
2024/01/19 12:21:29 [main:3] Shutdown started!
2024/01/19 12:21:29 [main:3] Waiting for main threads to terminate...
2024/01/19 12:21:29 [icecast:1:3] Closing connection...
2024/01/19 12:21:29 [lang:3] timeout --signal=KILL 45 libretime-playout-notify live 'master_dj' 'false' &
2024/01/19 12:21:29 [harbor:3] Removing mountpoint '/main' on port 8001
2024/01/19 12:21:29 [harbor:3] Nothing more on port 8001: closing sockets.
2024/01/19 12:21:29 [lang:3] timeout --signal=KILL 45 libretime-playout-notify live 'live_dj' 'false' &
2024/01/19 12:21:29 [harbor:3] Removing mountpoint '/show' on port 8002
2024/01/19 12:21:29 [harbor:3] Nothing more on port 8002: closing sockets.
2024/01/19 12:21:29 [clock.wallclock_alsa:3] Streaming loop stopped.
2024-01-19 12:21:30,875 | INFO     | libretime_playout.notify.main:stream:153 - Sending output stream '1' status 'OK'
2024-01-19 12:21:30,881 | INFO     | libretime_playout.notify.main:live:100 - Sending currently playing live source 'master_dj' status 'false'
2024-01-19 12:21:30,910 | INFO     | libretime_playout.notify.main:live:100 - Sending currently playing live source 'live_dj' status 'false'
2024/01/19 12:21:31 [main:3] Threads terminated.
2024/01/19 12:21:31 [threads:3] Shutting down scheduler...
2024/01/19 12:21:31 [threads:3] Scheduler shut down.
2024/01/19 12:21:31 [threads:3] Waiting for queue threads to terminate...
2024/01/19 12:21:31 [threads:3] Queues shut down
2024/01/19 12:21:31 [server:3] Closing socket.
2024/01/19 12:21:31 [main:3] Cleaning downloaded files...
2024/01/19 12:21:31 [main:3] Freeing memory...
2024/01/19 12:21:31 >>> LOG END

I'm guessing this may be the cause of the issue?

2024/01/19 12:21:29 [threads:3] Thread "alsa:1" aborts with exception Alsa error: No such file or directory!

I did install alsa-utils and alsamixer to try and see if that fixed the issue but no dice..

[paddatrapper]

Does aplay work and play out things? https://www.geeksforgeeks.org/aplay-command-in-linux-with-examples/ has some examples on how to test

[fiercestartx]

Does aplay work and play out things? https://www.geeksforgeeks.org/aplay-command-in-linux-with-examples/ has some examples on how to test

I tried aplay /home/airtime/test/test.mp3 with a 320kbps 44.1khz file and it only produces white noise. I then tried play /home/airtime/test/test.mp3 using sox and it comes through perfectly. So the sound card can output audio but aplay does not seem to play nice.

[fiercestartx]

Still having issues with this, any other methods I should try to get this working?

[jooola]

Have you tried with pulseaudio?

[fiercestartx]

Have you tried with pulseaudio?

Hi jooola,

Yes I did. It seems to print out the same error saying that there is 'No such file or directory'. But I did try playing through the terminal and it seems to play files, but the stream keeps breaking and looping to set up the mount point again..