Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Liquidsoap sporadically restarting a few seconds after a fade operation #4274

Closed
fkane opened this issue Dec 17, 2024 · 23 comments
Closed

Liquidsoap sporadically restarting a few seconds after a fade operation #4274

fkane opened this issue Dec 17, 2024 · 23 comments
Labels

Comments

@fkane
Copy link

fkane commented Dec 17, 2024

Description

Very sporadically - it could be after a few hours, it could be after a couple of days - Liquidsoap will stop and restart with no useful information in the logs as to why. The only pattern I can determine is that it usually happens shortly after a fade transition.

It seemed to start happening less frequently after reducing the quality setting for samplerate from "medium" to "fast," but it may just be a coincidence that it took longer to happen after that. We do stream in 48kHz - 24 bit from sources that range from 44.1/16 to 96/24. Source formats are flac or m4a, and jingles are wav.

We are running on an AWS EC2 instance. Upgrading from a t3.medium instance type to a t3.large (twice as powerful) didn't help.

This started happening after updating my Liquidsoap from a custom-built 2.1.x to 2.2.5 and then to 2.3.0 hoping it was a known issue that was addressed, but the problem persists in 2.3.0. Another change possibly associated with this issue was getting my metadata-driven crossfades working properly again as described in this discussion. These restarts seemed to go away while my crossfades were broken and just starting tracks sequentially instead of fading. Which makes me suspect it does have something to do with crossfades, but the restarts only seem to happen after the fade is complete, based on the timestamps in the log.

I have also observed the same behavior while testing the new autocue stuff and no fade-related annotations in the playlist. Again, it happens a few seconds following a fade transition between tracks.

Steps to reproduce

Unfortunately there is no known way to reproduce this behavior. It seems to happen at random, and very infrequently. You'd have to run for days to confirm it is fixed, unless the cause can be better isolated. I checked, and it's not the case that the same song(s) seem to be associated with the fault. Although it is possible it is triggered by different songs that have something in common.

Expected behavior

Playlists should continue through to completion before restarting.

Liquidsoap version

Liquidsoap 2.3.0+dev
Copyright (c) 2003-2024 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.3.0+dev

 * Compilation options
   - Release build       : false
   - Git SHA             : (none)
   - OCaml version       : 4.14.2
   - OS type             : Unix
   - Libs versions       : alsa=0.3.0 angstrom=0.16.1 ao=0.2.4 base=v0.16.3 base.base_internalhash_types=v0.16.3 base.caml=v0.16.3 base.shadow_stdlib=v0.16.3 bigarray=[distributed with Ocaml] bigstringaf=0.10.0 bytes=[distributed with OCaml 4.02 or above] camlp-streams camomile.lib=2.0 cry=1.0.3 curl=0.9.2 domain_shims dtools=0.4.5 dune-build-info=3.17.0 dune-private-libs.dune-section=3.17.0 dune-site=3.17.0 dune-site.private=3.17.0 duppy=0.9.4 faad=0.5.1 fdkaac=0.3.3 ffmpeg-av=1.2.1 ffmpeg-avcodec=1.2.1 ffmpeg-avdevice=1.2.1 ffmpeg-avfilter=1.2.1 ffmpeg-avutil=1.2.1 ffmpeg-swresample=1.2.1 ffmpeg-swscale=1.2.1 fileutils=0.6.4 flac=0.5.0 flac.decoder=0.5.0 flac.ogg=0.5.0 gen=1.1 lame=0.3.7 liquidsoap-lang=2.3.0 liquidsoap-lang.console=2.3.0 liquidsoap_alsa liquidsoap_ao liquidsoap_builtins liquidsoap_core liquidsoap_faad liquidsoap_fdkaac liquidsoap_ffmpeg liquidsoap_flac liquidsoap_lame liquidsoap_ogg liquidsoap_ogg_flac liquidsoap_optionals liquidsoap_oss liquidsoap_runtime liquidsoap_samplerate liquidsoap_vorbis magic-mime=1.3.1 mem_usage=0.1.1 menhirLib=20240715 metadata=0.3.0 mm=0.8.6 mm.audio=0.8.6 mm.base=0.8.6 mm.image=0.8.6 mm.midi=0.8.6 mm.video=0.8.6 ogg=0.7.4 ogg.decoder=0.7.4 ppx_compare.runtime-lib=v0.16.0 ppx_hash.runtime-lib=v0.16.0 ppx_sexp_conv.runtime-lib=v0.16.0 re=1.12.0 samplerate=0.1.6 saturn_lockfree=0.4.1 sedlex=3.3 seq=[distributed with OCaml 4.07 or above] sexplib0=v0.16.0 stdlib-shims=0.3.0 str=[distributed with Ocaml] stringext=1.6.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
   - 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
   - native_c_compiler   : gcc -O2 -fno-strict-aliasing -fwrapv -pthread -fPIC -D_FILE_OFFSET_BITS=64
   - 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)
   - user cache        : $HOME/.cache/liquidsoap (override with $LIQ_CACHE_USER_DIR)
   - system cache      : (set by dune-site) (override with $LIQ_CACHE_SYSTEM_DIR)
   - camomile files    : (set by dune-site)

 * Supported input formats
   - MP3               : no (requires mad)
   - AAC               : yes
   - Ffmpeg            : yes
   - Flac (native)     : yes
   - Flac (ogg)        : yes
   - Opus              : no (requires opus)
   - Speex             : no (requires speex)
   - Theora            : no (requires theora)
   - Vorbis            : yes
   - WAV/AIFF          : yes (native)

 * Supported output formats
   - FDK-AAC           : yes
   - FFmpeg            : yes
   - MP3               : yes
   - MP3 (fixed-point) : no (requires shine)
   - Flac (native)     : yes
   - Flac (ogg)        : yes
   - Opus              : no (requires opus)
   - Speex             : no (requires speex)
   - Theora            : no (requires theora)
   - Vorbis            : yes
   - WAV/AIFF          : yes (native)

 * Tags
   - AAC               : yes
   - FFmpeg            : yes
   - FLAC (native)     : yes
   - Flac (ogg)        : yes
   - Native decoder    : yes
   - Vorbis            : yes

 * Input / output
   - ALSA              : yes
   - AO                : yes
   - FFmpeg            : yes
   - JACK              : no (requires bjack)
   - NDI               : no (requires ctypes-foreign)
   - OSS               : yes
   - Portaudio         : no (requires portaudio)
   - Pulseaudio        : no (requires pulseaudio)
   - SRT               : no (requires srt)

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

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

 * MIDI manipulation
   - DSSI              : no (requires dssi)

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

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

 * Monitoring
   - Prometheus        : no (requires prometheus)

Installation method

From OPAM

Additional Info

Here is a sample segment of the log surrounding the most recent time this happened. As I mistakenly thought the issue was resolved after lowering my samplerate conversion quality settings, I was only running with the default log level... but there is no additional useful information with log level 4.

In this case it happened after a jingle, and there is a warning about the crossfade duration being longer than the track duration. I don't THINK that is the cause as I've seen this happen without that case. I've run into problems using liq_cross_duration metadata in 2.3.0, so I'm passing in a 30 second duration to cross() - which is long enough to cover my longest fades, but longer than most jingles. I have also observed this same behavior when fading between two full-length music tracks; it doesn't just happen after a jingle.

EDIT: This has since happened twice more since I filed this issue this morning, and both times it was again associated with a short jingle with a crossfade duration longer than the jingle. That seems suspicious. To rule that out, I've modified my playlist to include a liq_cross_duration of 0.2 on all jingles and restarted... I'll report back on if that has an effect.

2024/12/17 01:01:50 [decoder:2] Decoding "/home/ubuntu/media/Thomas_Dolby-Retrospectacle-The_Best_Of_Thomas_Dolby/01-06-Thomas_Dolby-She_Blinded_Me_With_Science-LLS.flac" ended: Ffmpeg_decoder.End_of_file.
2024/12/17 01:01:50 [playlist_pls:3] Prepared "/home/ubuntu/new-music-jingles/NewMusic-MeowMeow-ComingUpNext.wav" (RID 564).
2024/12/17 01:01:50 [decoder.ffmpeg.internal:3] Frame format change detected!
2024/12/17 01:01:50 [decoder.ffmpeg:3] Requested content-type for "/home/ubuntu/current-hits/PromoOnly/Ripe-Friend_In_The_Dark.m4a": {audio=pcm(stereo)}
2024/12/17 01:01:50 [decoder.ffmpeg:3] FFmpeg recognizes "/home/ubuntu/current-hits/PromoOnly/Ripe-Friend_In_The_Dark.m4a" as audio: {codec: alac, 44100Hz, 2 channel(s)}, video: {codec: png, 500x500, rgb24}
2024/12/17 01:01:50 [decoder.ffmpeg:3] Decoded content-type for "/home/ubuntu/current-hits/PromoOnly/Ripe-Friend_In_The_Dark.m4a": {audio=pcm(stereo)}
2024/12/17 01:01:50 [decoder:2] Decoding "/home/ubuntu/new-music-jingles/NewMusic-MeowMeow-ComingUpNext.wav" ended: Ffmpeg_decoder.End_of_file.
2024/12/17 01:01:50 [playlist_pls:3] Prepared "/home/ubuntu/current-hits/PromoOnly/Ripe-Friend_In_The_Dark.m4a" (RID 565).
2024/12/17 01:01:50 [cross:1] End of track reached while buffering next track data, crossfade duration is longer than the track's duration. Make sure to adjust the crossfade duration to avoid issues.
2024/12/17 01:01:50 [cross:3] Analysis: -65.976678dB / -21.335820dB (2.19s / 8.24s)
2024/12/17 01:01:50 [sequence.940:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [source.1412:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [audio.add.470:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [fade_in.470:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [fade_scale.470:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [track_amplify.941:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [sequence.939:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [blank.471:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [on_metadata.940:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [on_track.940:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [cross_after.470:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [cross.buffer.1880:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [fade_out.470:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [track_amplify.940:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [on_frame.939:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [on_metadata.939:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [on_track.939:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [cross_before.470:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [cross.buffer.1878:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [cross_after_tail.453:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:50 [clock.generic:2] We must catchup 0.35 seconds!
2024/12/17 01:01:50 [decoder.ffmpeg:3] Requested content-type for "/home/ubuntu/media/Queens_Of_The_Stone_Age/Songs_For_The_Deaf/1/3-No_One_Knows.flac": {audio=pcm(stereo)}
2024/12/17 01:01:50 [decoder.ffmpeg:3] FFmpeg recognizes "/home/ubuntu/media/Queens_Of_The_Stone_Age/Songs_For_The_Deaf/1/3-No_One_Knows.flac" as audio: {codec: flac, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x600, yuvj444p}
2024/12/17 01:01:50 [decoder.ffmpeg:3] Decoded content-type for "/home/ubuntu/media/Queens_Of_The_Stone_Age/Songs_For_The_Deaf/1/3-No_One_Knows.flac": {audio=pcm(stereo)}
2024/12/17 01:01:53 >>> LOG START
2024/12/17 01:01:51 [ffmpeg.filter.bitstream:3] No valid mode found for filter pgs_frame_merge!
2024/12/17 01:01:51 [main:3] Liquidsoap 2.3.0+dev
2024/12/17 01:01:51 [main:3] Using: alsa=0.3.0 angstrom=0.16.1 ao=0.2.4 base=v0.16.3 base.base_internalhash_types=v0.16.3 base.caml=v0.16.3 base.shadow_stdlib=v0.16.3 bigarray=[distributed with Ocaml] bigstringaf=0.10.0 bytes=[distributed with OCaml 4.02 or above] camlp-streams camomile.lib=2.0 cry=1.0.3 curl=0.9.2 domain_shims dtools=0.4.5 dune-build-info=3.17.0 dune-private-libs.dune-section=3.17.0 dune-site=3.17.0 dune-site.private=3.17.0 duppy=0.9.4 faad=0.5.1 fdkaac=0.3.3 ffmpeg-av=1.2.1 ffmpeg-avcodec=1.2.1 ffmpeg-avdevice=1.2.1 ffmpeg-avfilter=1.2.1 ffmpeg-avutil=1.2.1 ffmpeg-swresample=1.2.1 ffmpeg-swscale=1.2.1 fileutils=0.6.4 flac=0.5.0 flac.decoder=0.5.0 flac.ogg=0.5.0 gen=1.1 lame=0.3.7 liquidsoap-lang=2.3.0 liquidsoap-lang.console=2.3.0 liquidsoap_alsa liquidsoap_ao liquidsoap_builtins liquidsoap_core liquidsoap_faad liquidsoap_fdkaac liquidsoap_ffmpeg liquidsoap_flac liquidsoap_lame liquidsoap_ogg liquidsoap_ogg_flac liquidsoap_optionals liquidsoap_oss liquidsoap_runtime liquidsoap_samplerate liquidsoap_vorbis magic-mime=1.3.1 mem_usage=0.1.1 menhirLib=20240715 metadata=0.3.0 mm=0.8.6 mm.audio=0.8.6 mm.base=0.8.6 mm.image=0.8.6 mm.midi=0.8.6 mm.video=0.8.6 ogg=0.7.4 ogg.decoder=0.7.4 ppx_compare.runtime-lib=v0.16.0 ppx_hash.runtime-lib=v0.16.0 ppx_sexp_conv.runtime-lib=v0.16.0 re=1.12.0 samplerate=0.1.6 saturn_lockfree=0.4.1 sedlex=3.3 seq=[distributed with OCaml 4.07 or above] sexplib0=v0.16.0 stdlib-shims=0.3.0 str=[distributed with Ocaml] stringext=1.6.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
2024/12/17 01:01:51 [clock:3] Using builtin (low-precision) implementation for latency control
2024/12/17 01:01:52 [lang:2] WARNING: "set" is deprecated and will be removed in future version. Please use `settings.path.to.key := value`
2024/12/17 01:01:52 [lang:2] WARNING: "set" is deprecated and will be removed in future version. Please use `settings.path.to.key := value`
2024/12/17 01:01:52 [main:3] Script-base daemonization is DEPRECATED! Please use a modern daemonization facility such as `systemd` or `launchd` instead.
2024/12/17 01:01:53 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2024/12/17 01:01:53 [frame:3] Video frame size set to: 1280x720
2024/12/17 01:01:53 [frame:3] Targeting 'frame.duration': 0.02s = 882 ticks.
2024/12/17 01:01:53 [main:3] User script loaded in 1.35 seconds.
2024/12/17 01:01:53 [sandbox:3] Sandboxing disabled
2024/12/17 01:01:53 [startup:3] FFmpeg filters registration: 0.05s
2024/12/17 01:01:53 [startup:3] FFmpeg bitstream filters registration: 0.00s
2024/12/17 01:01:53 [startup:3] main script hash computation: 0.06s
2024/12/17 01:01:53 [startup:3] Loading main script from cache!
2024/12/17 01:01:53 [startup:3] main script cache retrieval: 0.11s
2024/12/17 01:01:53 [startup:3] Evaluating main script: 0.68s
2024/12/17 01:01:53 [clock:3] Starting clock generic with 9 source(s) and sync: auto
2024/12/17 01:01:53 [clock:3] Starting clock generic.child.child with 3 source(s) and sync: passive
2024/12/17 01:01:53 [video.converter:3] Using preferred video converter: ffmpeg.
2024/12/17 01:01:53 [audio.converter:3] Using samplerate converter: libsamplerate.
2024/12/17 01:01:53 [video.text:3] Using native implementation
2024/12/17 01:01:53 [safe_blank:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [cross:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [amplify:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [track_amplify:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [playlist_pls:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [track_metadata_deduplicate:3] Content type is {}.
2024/12/17 01:01:53 [metadata_deduplicate:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [mksafe:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [output.icecast:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [Radio_Calico_-_lossless:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [output.icecast.2:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [Radio_Calico_-_192kpbs:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [output.icecast.3:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [Radio_Calico_-_lossless,_with_metadata:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [output.file:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [live_m3u8:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [mksafe:3] Switch to safe_blank.
2024/12/17 01:01:53 [Radio_Calico_-_lossless:3] Connecting mount calico for source@localhost...
2024/12/17 01:01:53 [Radio_Calico_-_lossless:3] Connection setup was successful.
2024/12/17 01:01:53 [Radio_Calico_-_192kpbs:3] Connecting mount calico.mp3 for source@localhost...
2024/12/17 01:01:53 [Radio_Calico_-_192kpbs:3] Connection setup was successful.
2024/12/17 01:01:53 [Radio_Calico_-_lossless,_with_metadata:3] Connecting mount roon for [email protected]...
2024/12/17 01:01:53 [Radio_Calico_-_lossless,_with_metadata:3] Connection setup was successful.
2024/12/17 01:01:53 [decoder.ffmpeg:3] Requested content-type for "/home/ubuntu/media/Promo_Only_Keepers/AJA-Little_Black_Dress.m4a": {audio=pcm(stereo)}
2024/12/17 01:01:53 [decoder.ffmpeg:3] FFmpeg recognizes "/home/ubuntu/media/Promo_Only_Keepers/AJA-Little_Black_Dress.m4a" as audio: {codec: alac, 44100Hz, 2 channel(s)}, video: {codec: png, 500x500, rgb24}
2024/12/17 01:01:53 [decoder.ffmpeg:3] Decoded content-type for "/home/ubuntu/media/Promo_Only_Keepers/AJA-Little_Black_Dress.m4a": {audio=pcm(stereo)}
2024/12/17 01:01:53 [decoder.ffmpeg:3] Requested content-type for "/home/ubuntu/media/Danzig-Danzig/01-06-Rick_Rubin-Mother-LLS.flac": {audio=pcm(stereo)}
2024/12/17 01:01:53 [decoder.ffmpeg:3] FFmpeg recognizes "/home/ubuntu/media/Danzig-Danzig/01-06-Rick_Rubin-Mother-LLS.flac" as audio: {codec: flac, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 600x600, yuvj444p}
2024/12/17 01:01:53 [decoder.ffmpeg:3] Decoded content-type for "/home/ubuntu/media/Danzig-Danzig/01-06-Rick_Rubin-Mother-LLS.flac": {audio=pcm(stereo)}
2024/12/17 01:01:53 [playlist_pls:3] Prepared "/home/ubuntu/media/Promo_Only_Keepers/AJA-Little_Black_Dress.m4a" (RID 1).
2024/12/17 01:01:53 [cross.buffer:3] Content type is {audio=pcm(stereo)}.
2024/12/17 01:01:53 [mksafe:3] Switch to metadata_deduplicate with transition.

Also here is my complete script:

log.file.path.set("/home/ubuntu/soapstuff/basic-radio.log")
#log.level.set(4)

#settings.audio.converter.samplerate.libsamplerate.quality.set("medium")
#settings.audio.converter.samplerate.native.quality.set("linear")
settings.audio.converter.samplerate.converters.set(["libsamplerate", "ffmpeg", "native"])
#settings.encoder.metadata.export.set(["artist", "title", "album", "genre", "date", "tracknumber", "url", "comment", "track", "year", "dj", "next", "apic", "pic", "metadata_url", "metadata_block_picture", "coverart"])

#enable_autocue_metadata()


last_metadata = ref([])

def log_song(m)
	listeners_1 = process.read("curl -s http://localhost:8080/status-json.xsl | jq .icestats.source[0].listeners | tr -d \"[:space:]\"")
	listeners_2 = process.read("curl -s http://localhost:8080/status-json.xsl | jq .icestats.source[1].listeners | tr -d \"[:space:]\"")
	listeners_3 = process.read("curl -s http://roon.radio-calico.com:8000/health | jq .mounts.\\\"/roon\\\".listener_count | tr -d \"[:space:]\"")
	active_web_users = process.read("curl -s https://www.radio-calico.com/wp-json/wpstatistics/v1/summary?token_auth=c9c238aef7afc00345ab45db | jq .user_online | tr -d \"[:space:]\" | tr -d \\\"")
	artist = m["artist"]
	title = m["title"]
	album = m["album"]
	if (not string.contains(substring="LINER", title)) then
		t = time.local()
		filename = "/var/log/calico/log-#{t.year}-#{t.month}-#{t.day}.txt"
		file.write(append=true,
			data = "#{t.year}|#{t.month}|#{t.day}|#{t.hour}|#{t.min}|#{t.sec}|#{active_web_users}|#{listeners_1}|#{artist}|#{title}|#{album}|#{listeners_2}\n",
			filename)
		filename = "/var/log/calicov2/log-#{t.year}-#{t.month}-#{t.day}.txt"
		file.write(append=true,
			data = "#{t.year}|#{t.month}|#{t.day}|#{t.hour}|#{t.min}|#{t.sec}|#{active_web_users}|#{listeners_1}|#{artist}|#{title}|#{album}|#{listeners_2}|#{listeners_3}\n",
			filename)
	end
end

def publish_metadata(m)
	last_metadata := m
	mediafile = m["filename"]
	log_song(m)
	process.run("python3 /home/ubuntu/extract-cover.py \"#{mediafile}\"")		
end

def rebuild_playlist()
	process.run("python3 /home/ubuntu/make-playlist.py")
end

thread.run(every=3600.0, fast=false, rebuild_playlist)

process.run("mkdir /mnt/ramdisk/hls")
process.run("mkdir /mnt/ramdisk/tmp")

radio = amplify(override="liq_amplify", 1.0, playlist(mode="normal", reload_mode="rounds", reload=1, "/home/ubuntu/playlist.pls"))

radio.on_track(fun(m) -> thread.run(fast=false,{publish_metadata(m)}))

#radio = crossfade(fade_in=0.,fade_out=0.,radio)

def custom_crossfade(old, new) =
        cross.simple(
                old.source, 
                new.source, 
                fade_in=00.0,
                fade_out=00.0
            )
end
radio = cross(
       # duration, should be not longer than a track length. Other wise it will give a warning like:
       # "End of track reached while buffering next track data, crossfade duration is longer than the track's duration. "
       # "Make sure to adjust the crossfade duration to avoid issues."
       # We override the duration using liq_cross_duration for jingles to try and get around this.
        duration=30.0,
        custom_crossfade,
        radio
    )

radio = mksafe(radio)

output.icecast(%ogg(%flac(samplerate=48000, channels=2, bits_per_sample=24)),
	host="localhost", port=8080, encoding="UTF-8",
	genre="Rock / Pop", name="Radio Calico - lossless",
	description= "High resolution Internet radio for audiophiles like you! Lossless 48kHz/24-bit streaming of a variety of genres, with a focus on quality remasters. Ad-free. radio-calico.com",
	password="XXXXXXXXXXXXXX", mount="calico", radio)

output.icecast(%mp3.abr(bitrate=192), host="localhost", port=8080, 
	genre="Rock / Pop", name="Radio Calico - 192kpbs", encoding="UTF-8",
	description= "Streaming the music of Generation X, with a focus on quality remasters. Ad-free. radio-calico.com",
	password="XXXXXXXXXXXXX", mount="calico.mp3", radio)

# Comment out while in dev
output.icecast(%ogg(%flac(samplerate=48000, channels=2, bits_per_sample=24)),
	host="roon.radio-calico.com", port=8000, send_icy_metadata=true, encoding="UTF-8",
	genre="Rock / Pop", name="Radio Calico - lossless, with metadata",
	description= "High resolution Internet radio for audiophiles like you! Lossless 48kHz/24-bit streaming of a variety of genres, with a focus on quality remasters. Ad-free. radio-calico.com",
	password="XXXXXXXXXXXXXXXX", mount="roon", radio)

#HLS STUFF

aac_hifi = %ffmpeg(format="mpegts",
                   %audio(
                     codec="aac",
		     channels=2,
		     ar=44100,
                     b="192k"
                 ))

#flac_hifi = %ffmpeg(format="mp4",
#		     movflags="+dash+skip_sidx+skip_trailer+frag_custom",
#		     frag_duration=10,
#                    strict="-2",
#                    %audio(
#                      codec="flac",
#                      channels=2,
#                      ar=44100
#                    ))

flac_hires = %ffmpeg(format="mp4",
                   movflags="+dash+skip_sidx+skip_trailer+frag_custom",
                   frag_duration=10,
                   strict="-2",
                   %audio(
                     codec="flac",
                     channels=2,
                     ar=48000
                   ))

streams = [("flac_hires", flac_hires),
#	   ("fLaC_hires", flac_hires),
#           ("flac_hifi", flac_hifi),
#           ("fLaC_hifi", flac_hifi),
	   ("aac_hifi", aac_hifi)]

# Current browsers work with "flac", but all have bugs filed with them to switch to "fLaC"
# So we will publish streams for both, for now.
# Hm, streams_info no longer supported, but browsers seem to work OK without it AFAIK
#streams_info = [("flac_hires", {bandwidth=2000000, codecs="flac", extname="m4s", video_size=null()}),
#                ("fLaC_hires", {bandwidth=2000000, codecs="fLaC", extname="m4s", video_size=null()}),
#               ("flac_hifi", {bandwidth=1000000, codecs="flac", extname="m4s", video_size=null()}),
#		("fLaC_hifi", {bandwidth=1000000, codecs="fLaC", extname="m4s", video_size=null()}),
#                ("aac_hifi", {bandwidth=220000, codecs="mp4a.40.2", extname="ts", video_size=null()})]

def segment_name(metadata) =
  timestamp = int_of_float(time())
  duration = 5
  "#{metadata.stream_name}_#{duration}_#{timestamp}_#{metadata.position}.#{metadata.extname}"
end   

output.file.hls(playlist="live.m3u8",
		segment_duration = 5.0,
		segments = 6,
		segments_overhead=6,
		segment_name=segment_name,
		persist_at="/home/ubuntu/soapstuff/state.config",
		temp_dir="/mnt/ramdisk/tmp",
#		streams_info=streams_info,
		"/mnt/ramdisk/hls",
		streams,
		radio)

Here is a sample of my playlist annotated for crossfades:

annotate:liq_cue_in="3.200",liq_cross_start_next="218.100",liq_cross_max_start_duration="218.100",liq_cross_end_duration="10.400",liq_fade_out_delay="10.400",duration="228.500",liq_amplify="-2.07dB":/home/ubuntu/media/Thompson_Twins/Love,_Lies_and_Other_Strange_Things_Greatest_Hits/1/1-In_the_Name_of_Love.flac
annotate:liq_cue_in="0.000",liq_cross_start_next="97.700",liq_cross_max_start_duration="97.700",liq_cross_end_duration="1.500",liq_fade_out_delay="1.500",duration="99.200",liq_amplify="-12.75dB":/home/ubuntu/media/NOFX-Pump_Up_The_Valuum/01-05-NOFX-Thank_God_It_s_Monday-LLS.flac
annotate:liq_cue_in="0.000",liq_cross_start_next="178.500",liq_cross_max_start_duration="178.500",liq_cross_end_duration="0.400",liq_fade_out_delay="0.400",duration="178.900",liq_amplify="-10.76dB":/home/ubuntu/media/Nina_Nesbitt/Alskar_Nights_Deluxe_Version_/2/5-Life_s_a_Bitch.flac
annotate:liq_cue_in="0.900",liq_cross_start_next="265.300",liq_cross_max_start_duration="265.300",liq_cross_end_duration="6.000",liq_fade_out_delay="6.000",duration="271.300",liq_amplify="-11.13dB":/home/ubuntu/media/Velvet_Revolver/Contraband/1/6-Fall_to_Pieces.flac
annotate:liq_cue_in="0.000",liq_cross_start_next="299.800",liq_cross_max_start_duration="299.800",liq_cross_end_duration="3.100",liq_fade_out_delay="3.100",duration="302.900",liq_amplify="-10.67dB":/home/ubuntu/media/Arcade_Fire/Everything_Now/1/2-Everything_Now.flac
@fkane fkane added the bug label Dec 17, 2024
@toots
Copy link
Member

toots commented Dec 17, 2024

Thanks for this report, I'll have a look as soon as possible.

What version of Liquidsoap are you using? There were some important bugfixes added to 2.3.0 right before the release.

@fkane
Copy link
Author

fkane commented Dec 17, 2024

Thank you @toots , It is 2.3.0 built from opam a few days ago.

I just updated the info above to note that the 3 most recent restarts are in fact associated with short jingles finishing, that are shorter than the cross fade duration. I'm not really sure how to properly use liq_cross_duration in 2.3.0, might that be a possible explanation? As a test I've added a liq_cross_duration=0.2 annotation into the playlist for all jingles and restarted, but I think that may result in crossfades into jingles not happening at the best time. I'll trade that off for stability though if need be.

@toots
Copy link
Member

toots commented Dec 17, 2024

@fkane are you sure about the version? The build info says:

* Liquidsoap version  : 2.3.0+dev

It should say 2.3.0 for the version from opam.

@toots
Copy link
Member

toots commented Dec 17, 2024

Ho wait, this looks like a bug in our build system:

<><> liquidsoap.2.3.0 installed successfully ><><><><><><><><><><><><><><><>  🐫
=> ✨ Congratulations on installing liquidsoap! ✨

% liquidsoap --version                                                                                                                         1m 23s 23:42:00
Liquidsoap 2.3.0+dev
Copyright (c) 2003-2024 Savonet team
Liquidsoap is open-source software, released under GNU General Public License.
See <http://liquidsoap.info> for more information.

% which liquidsoap                                                                                                                                    23:42:05
/Users/toots/.opam/main-4.14.2/bin/liquidsoap

@toots
Copy link
Member

toots commented Dec 17, 2024

Ok sorry about that. How are you running liquidsoap? If practical, running it inside a screen would give you the last log lines before the crash.

@fkane
Copy link
Author

fkane commented Dec 17, 2024

I'm still using the old liquidsoap-daemon package. Yes, i can run it from screen and see if that turns up more info next time it happens. Will report back.

@fkane
Copy link
Author

fkane commented Dec 18, 2024

So I did find the logs via journalctl for when it restarted twice this afternoon. Not much to go on, other than it shows it did in fact crash:

Dec 17 13:24:52 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Main process exited, code=dumped, status=11/SEGV
Dec 17 13:24:52 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Failed with result 'core-dump'.
Dec 17 13:24:52 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Consumed 2h 30min 1.995s CPU time.
Dec 17 13:24:53 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Scheduled restart job, restart counter is at 2.
Dec 17 13:24:53 ip-172-30-2-186 systemd[1]: Starting basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon...
Dec 17 13:24:55 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Supervising process 80315 which is not our child. We'll most likely not notice when it exits.
Dec 17 13:24:55 ip-172-30-2-186 systemd[1]: Started basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon.
Dec 17 15:30:04 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Main process exited, code=dumped, status=11/SEGV
Dec 17 15:30:04 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Failed with result 'core-dump'.
Dec 17 15:30:04 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Consumed 25min 17.246s CPU time.
Dec 17 15:30:04 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Scheduled restart job, restart counter is at 3.
Dec 17 15:30:04 ip-172-30-2-186 systemd[1]: Starting basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon...
Dec 17 15:30:06 ip-172-30-2-186 systemd[1]: Started basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon.

I haven't had any luck locating those core dumps however.

Still running another instance under screen to see if it says anything more if it crashes.

@fkane
Copy link
Author

fkane commented Dec 18, 2024

Liquidsoap output after the crash... took about 10 hours this time. Not much to go on.

Something very weird is that our live server restarted at almost exactly the same time as this test server that was running independently, with a completely different playlist and even a different instance type. Both crashed at 6:52 AM.

[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d924006680] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d924006680] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d9480cf1c0] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d9480cf1c0] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d930037280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d930037280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d9485fd280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d9485fd280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d924006680] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d924006680] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d9485fd280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d9485fd280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d930037280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d930037280] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d94813b380] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d94813b380] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d920006700] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d920006700] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d94859b5c0] stream 0, timescale not set
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x77d94859b5c0] stream 0, timescale not set
Segmentation fault (core dumped)

@toots
Copy link
Member

toots commented Dec 18, 2024

Ok thanks for this! I think the next step is to run it insude a gdb console. Something like this:

% which liquidsoap
<path to liquidsoap>
% gdb <path to liquidsoap>
> r /path/to/script.liq

This should capture the stacktrace from the segfault.

@fkane
Copy link
Author

fkane commented Dec 18, 2024

OK, on it. Thank you.

@fkane
Copy link
Author

fkane commented Dec 18, 2024

Found a little more info in the syslog of the test server; it suggests the crash is clock-related:

2024-12-18T06:51:45.237053-05:00 ip-172-30-2-111 kernel: traps: Clock generic[1303] general protection fault ip:60c8eb957bca sp:77d9571feab0 error:0 in liquidsoap[60c8eb35d000+5fe000]
2024-12-18T06:51:45.456510-05:00 ip-172-30-2-111 systemd[1064]: Created slice session.slice - User Core Session Slice.
2024-12-18T06:51:45.464426-05:00 ip-172-30-2-111 systemd[1064]: Starting dbus.service - D-Bus User Message Bus...
2024-12-18T06:51:45.483282-05:00 ip-172-30-2-111 dbus-daemon[23084]: [session uid=1000 pid=23084] AppArmor D-Bus mediation is enabled
2024-12-18T06:51:45.484090-05:00 ip-172-30-2-111 systemd[1064]: Started dbus.service - D-Bus User Message Bus.

The main server's syslog suggests it restarted at the same time as a coincidence, as that seems to have been driven by an automated system upgrade that restarted everything. That may be the culprit there.

2024-12-18T06:51:58.476137-05:00 ip-172-30-2-186 systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities...
2024-12-18T06:52:01.881050-05:00 ip-172-30-2-186 CRON[111232]: (root) CMD (/usr/bin/aws-kinesis-agent-babysit > /dev/null 2>&1)
2024-12-18T06:52:06.198133-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:52:06.198542-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:52:11.965606-05:00 ip-172-30-2-186 dbus-daemon[561]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.87' (uid=0 pid=111358 comm="/usr/bin/gdbus call --system --dest org.freedeskto" label="unconfined")
2024-12-18T06:52:11.973866-05:00 ip-172-30-2-186 systemd[1]: Starting packagekit.service - PackageKit Daemon...
2024-12-18T06:52:11.987645-05:00 ip-172-30-2-186 PackageKit: daemon start
2024-12-18T06:52:12.060952-05:00 ip-172-30-2-186 dbus-daemon[561]: [system] Successfully activated service 'org.freedesktop.PackageKit'
2024-12-18T06:52:12.061072-05:00 ip-172-30-2-186 systemd[1]: Started packagekit.service - PackageKit Daemon.
2024-12-18T06:52:13.096645-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Killing process 87356 (liquidsoap) with signal SIGKILL.
2024-12-18T06:52:13.096791-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Failed to kill control group /system.slice/basic-radio-liquidsoap.service, ignoring: Invalid argument
2024-12-18T06:52:13.096859-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Killing process 87356 (liquidsoap) with signal SIGKILL.
2024-12-18T06:52:13.106914-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Failed to kill control group /system.slice/basic-radio-liquidsoap.service, ignoring: Invalid argument
2024-12-18T06:52:13.107026-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Deactivated successfully.
2024-12-18T06:52:13.107075-05:00 ip-172-30-2-186 systemd[1]: Stopped basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon.
2024-12-18T06:52:13.107121-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Consumed 2h 54min 37.212s CPU time, 5.2G memory peak, 0B memory swap peak.
2024-12-18T06:52:13.107207-05:00 ip-172-30-2-186 systemd[1]: Stopping basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon...
2024-12-18T06:52:13.119629-05:00 ip-172-30-2-186 systemd[1]: Starting basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon...
2024-12-18T06:52:13.121971-05:00 ip-172-30-2-186 systemd[1]: Stopping icecast2.service - LSB: Icecast2 streaming media server...
2024-12-18T06:52:13.150957-05:00 ip-172-30-2-186 icecast2[111388]:  * Stopping streaming media server icecast2
2024-12-18T06:52:14.377061-05:00 ip-172-30-2-186 icecast2[111388]:    ...done.
2024-12-18T06:52:14.377331-05:00 ip-172-30-2-186 systemd[1]: icecast2.service: Deactivated successfully.
2024-12-18T06:52:14.377453-05:00 ip-172-30-2-186 systemd[1]: Stopped icecast2.service - LSB: Icecast2 streaming media server.
2024-12-18T06:52:14.377505-05:00 ip-172-30-2-186 systemd[1]: icecast2.service: Consumed 26min 16.174s CPU time, 23.3M memory peak, 0B memory swap peak.
2024-12-18T06:52:14.388246-05:00 ip-172-30-2-186 systemd[1]: Starting icecast2.service - LSB: Icecast2 streaming media server...
2024-12-18T06:52:14.408547-05:00 ip-172-30-2-186 icecast2[111401]:  * Starting streaming media server icecast2
2024-12-18T06:52:14.432842-05:00 ip-172-30-2-186 icecast2[111401]:    ...done.
2024-12-18T06:52:14.433037-05:00 ip-172-30-2-186 systemd[1]: Started icecast2.service - LSB: Icecast2 streaming media server.
2024-12-18T06:52:14.838998-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Supervising process 111420 which is not our child. We'll most likely not notice when it exits.
2024-12-18T06:52:14.839846-05:00 ip-172-30-2-186 systemd[1]: Started basic-radio-liquidsoap.service - basic-radio Liquidsoap daemon.
2024-12-18T06:52:18.197967-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:52:18.198058-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:52:25.280714-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:52:25.280919-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:52:57.304209-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:52:57.311183-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:53:01.932424-05:00 ip-172-30-2-186 CRON[116986]: (root) CMD (/usr/bin/aws-kinesis-agent-babysit > /dev/null 2>&1)
2024-12-18T06:53:04.285389-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:53:04.285550-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:53:08.682944-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:53:08.683212-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:53:12.082140-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:53:12.082273-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:53:18.856178-05:00 ip-172-30-2-186 apt.systemd.daily[111177]: /usr/bin/unattended-upgrade:567: DeprecationWarning: This process (pid=111177) is multi-threaded, use of fork() may lead to deadlocks in the child.
2024-12-18T06:53:18.856253-05:00 ip-172-30-2-186 apt.systemd.daily[111177]:   pid = os.fork()
2024-12-18T06:53:22.669311-05:00 ip-172-30-2-186 systemd[1]: apt-daily-upgrade.service: Deactivated successfully.
2024-12-18T06:53:22.669504-05:00 ip-172-30-2-186 systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities.
2024-12-18T06:53:22.670085-05:00 ip-172-30-2-186 systemd[1]: apt-daily-upgrade.service: Consumed 59.239s CPU time.

@fkane
Copy link
Author

fkane commented Dec 18, 2024

The syslog on our live server shows a previous restart was due to the same clock-related crash:

2024-12-17T15:30:04.500942-05:00 ip-172-30-2-186 kernel: Clock generic[80318]: segfault at 7d1 ip 00005dce32e99cbf sp 0000745cd23feae0 error 4 in liquidsoap[5dce3289f000+5fe000] likely on CPU 0 (core 0, socket 0)
2024-12-17T15:30:04.500961-05:00 ip-172-30-2-186 kernel: Code: 89 fe 48 8d 05 02 d5 12 00 49 8b 66 10 41 8f 46 10 c3 90 53 55 41 54 41 55 41 56 41 57 48 83 ec 08 49 89 fe 48 89 f3 48 8b 02 <4c> 8b 23 e9 d5 fe ff ff 90 53 55 41 54 41 55 41 56 41 57 48 83 ec
2024-12-17T15:30:04.722968-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Main process exited, code=dumped, status=11/SEGV
2024-12-17T15:30:04.725211-05:00 ip-172-30-2-186 systemd[1]: basic-radio-liquidsoap.service: Failed with result 'core-dump'.

Still running the test server under gdb, I'll let you know what that turns up. Meanwhile I'm disabling auto-updates on the server to at least resolve some of the restarts. I think those updates started when we upgraded from Ubuntu 22 to 24 in order to gain compatibility with Liquidsoap 2.3.0.

@fkane
Copy link
Author

fkane commented Dec 19, 2024

OK, it finally did crash under gdb:

Thread 8 "Clock generic" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffdcc006c0 (LWP 23774)]
0x00005555560dbbca in caml_start_program ()
(gdb)

Here is a backtrace:

#0  0x00005555560dbbca in caml_start_program ()
#1  0x00005555560d1b71 in caml_callback_exn (closure=<optimized out>,
    arg=<optimized out>) at callback.c:111
#2  0x000055555606f819 in enc_write_callback (encoder=<optimized out>,
    buffer=0x7fffd01ee900 "\204", bytes=87, samples=<optimized out>,
    current_frame=<optimized out>, client_data=<optimized out>)
    at flac_stubs.c:671
#3  0x00007ffff7bda518 in ?? () from /lib/x86_64-linux-gnu/libFLAC.so.12
#4  0x00007ffff7bdb7de in ?? () from /lib/x86_64-linux-gnu/libFLAC.so.12
#5  0x00007ffff7bdc082 in FLAC__stream_encoder_init_ogg_stream ()
   from /lib/x86_64-linux-gnu/libFLAC.so.12
#6  0x000055555606d3f9 in ocaml_flac_encoder_ogg_create (
    comments=<optimized out>, params=<optimized out>, _enc_cb=<optimized out>,
    _serialno=<optimized out>) at flac_ogg_stubs.c:76
#7  0x0000555555b28ee9 in camlFlac_ogg__create_inner_1085 ()
    at src/flac_ogg.ml:97
#8  0x0000555555b1f834 in camlOgg_flac_encoder__get_enc_415 ()
    at src/core/ogg_formats/ogg_flac_encoder.ml:53
#9  0x0000555555b1f88d in camlOgg_flac_encoder__header_encoder_578 ()
    at src/core/ogg_formats/ogg_flac_encoder.ml:63
#10 0x0000555555b20a46 in camlOgg_muxer__register_track_912 ()
    at src/core/ogg_formats/ogg_muxer.ml:186
#11 0x0000555555b2287c in camlOgg_encoder__f_1926 ()
    at src/core/encoder/encoders/ogg_encoder.ml:142
#12 0x0000555556004a40 in camlStdlib__List__iter_507 () at list.ml:110
#13 0x0000555555ba06aa in camlEncoder__fun_2081 ()
    at src/core/tools/mutex_utils.ml:25
#14 0x0000555555bd8e5c in camlOutput__output_chunks_2611 ()
    at src/core/outputs/output.ml:249
#15 0x0000555555bd68a5 in camlOutput__fun_2921 ()
    at src/core/outputs/output.ml:180
#16 0x0000555555b92bc7 in camlClock__wrap_errors_1138 ()
    at src/core/clock.ml:364
#17 0x0000555556004a40 in camlStdlib__List__iter_507 () at list.ml:110
#18 0x0000555555b930c7 in camlClock___tick_1181 () at src/core/clock.ml:399
#19 0x0000555555b936cb in camlClock__fun_2368 () at src/core/clock.ml:438
#20 0x0000555555b8f0e5 in camlTutils__process_1200 ()
    at src/core/tools/tutils.ml:175
#21 0x0000555555fc5135 in camlThread__fun_850 () at thread.ml:49
#22 0x00005555560dbbcd in caml_start_program ()
#23 0x00005555560d1b71 in caml_callback_exn (
    closure=closure@entry=140737062501592, arg=<optimized out>, arg@entry=1)
    at callback.c:111
#24 0x00005555560a4368 in caml_thread_start (arg=0x5555567f5f40)
    at st_stubs.c:546
#25 0x00007ffff3c9ca94 in start_thread (arg=<optimized out>)
#26 0x00007ffff3d29c3c in clone3 ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

I'll leave gdb running for a bit in case there is more info you want me to gather.

Here are the log entries prior to the crash; again, it happened after a short jingle with a too-long crossfade duration. I'm starting to believe that is what's triggering it; on my live server running the same configuration, I added liq_cross_duration=0.2 to all jingle tracks, and since disabling Ubuntu's auto-updates, it has been running reliably. (It's not an ideal solution though as it results in poor transitions to jingles from the previous track)

2024/12/19 04:29:23 [playlist_pls:4] Queued 1 request(s)
2024/12/19 04:29:23 [process:4] Process exited with code 0
2024/12/19 04:29:23 [process:4] Starting process
2024/12/19 04:29:23 [process:4] Cleaning up process
2024/12/19 04:29:23 [process:4] Closing process's stdin
2024/12/19 04:29:23 [process:4] Process exited with code 0
2024/12/19 04:29:23 [process:4] Cleaning up process
2024/12/19 04:29:23 [process:4] Starting process
2024/12/19 04:29:23 [process:4] Closing process's stdin
2024/12/19 04:29:23 [decoder:2] Decoding "/home/ubuntu/jingles-proc/MrVintage-RadioCalico-11.wav" ended: Ffmpeg_decoder.End_of_file.
2024/12/19 04:29:23 [decoder:4] Raised at Ffmpeg_decoder.mk_decoder.(fun).f in file "src/core/decoder/ffmpeg_decoder.ml", line 924, characters 12-29
2024/12/19 04:29:23 [decoder:4] Called from Decoder.mk_decoder.fread in file "src/core/decoder/decoder.ml", line 537, characters 10-31
2024/12/19 04:29:23 [decoder:4]
2024/12/19 04:29:23 [playlist_pls:4] Finished with "/home/ubuntu/jingles-proc/MrVintage-RadioCalico-11.wav".
2024/12/19 04:29:23 [request.421:4] Request destroyed.
2024/12/19 04:29:23 [playlist_pls:4] Remaining 0 requests
2024/12/19 04:29:23 [request.422:4] Cueing in to position: 0.00
2024/12/19 04:29:23 [playlist_pls:3] Prepared "/home/ubuntu/media/Postmodern_Jukebox/01-09-Postmodern_Jukebox-The_Fourth_Tuning-American_Boy.flac" (RID 422).
2024/12/19 04:29:23 [track_amplify:4] End of the current overriding.
2024/12/19 04:29:23 [track_amplify:4] Overriding amplification: 0.578762.
2024/12/19 04:29:23 [cross:1] End of track reached while buffering next track data, crossfade duration is longer than the track's duration. Make sure to adjust the crossfade duration to avoid issues.
2024/12/19 04:29:23 [cross:3] Analysis: -43.236647dB / -26.310256dB (3.89s / 11.56s)
2024/12/19 04:29:23 [request.423:4] Pushed ["annotate:liq_cue_in=\"0.000\",liq_cross_start_next=\"97.500\",liq_cross_max_start_duration=\"97.500\",liq_cross_end_duration=\"0.400\",liq_fade_out_delay=\"0.400\",duration=\"97.900\",liq_amplify=\"-14.51dB\":/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a";...].
2024/12/19 04:29:23 [request.423:4] Resolving "annotate:liq_cue_in=\"0.000\",liq_cross_start_next=\"97.500\",liq_cross_max_start_duration=\"97.500\",liq_cross_end_duration=\"0.400\",liq_fade_out_delay=\"0.400\",duration=\"97.900\",liq_amplify=\"-14.51dB\":/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a" (timeout 29s)...
2024/12/19 04:29:23 [request.423:4] Pushed ["/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a";...].
2024/12/19 04:29:23 [decoder.video.metadata:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.ogg.metadata:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.image.metadata:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.id3:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.id3:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.id3:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.flac.metadata:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [metadata.mp4:4] Unsupported file extension for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a"!
2024/12/19 04:29:23 [source:4] Source sequence.684 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [sequence.684:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [decoder.ffmpeg:4] Unsupported file extension for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a"!
2024/12/19 04:29:23 [source:4] Source source.1028 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [process:4] Starting process
2024/12/19 04:29:23 [source.1028:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source audio.add.342 gets up with content type: {audio=pcm(stereo)} and frame type: 'A.{audio : pcm(stereo)}.
2024/12/19 04:29:23 [audio.add.342:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [process:4] Closing process's stdin
2024/12/19 04:29:23 [source:4] Source fade_in.342 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [metadata.flac:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.ogg:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [fade_in.342:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [decoder.ogg:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.ffmpeg:4] Unsupported file extension for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a"!
2024/12/19 04:29:23 [decoder.flac:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [source:4] Source fade_scale.342 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [decoder.mp4:4] Unsupported file extension for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a"!
2024/12/19 04:29:23 [fade_scale.342:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [decoder.aac:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.midi:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [source:4] Source track_amplify.685 gets up with content type: {audio=pcm(stereo)} and frame type: 'A.{audio : pcm(stereo)}.
2024/12/19 04:29:23 [decoder.srt:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.aiff:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder.wav:4] Unsupported MIME type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": audio/mp4!
2024/12/19 04:29:23 [decoder:4] Available decoders: ffmpeg (priority: 10), mp4 (priority: 1), image (priority: 1)
2024/12/19 04:29:23 [decoder:4] Trying decoder "ffmpeg"
2024/12/19 04:29:23 [track_amplify.685:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source sequence.683 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [sequence.683:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [decoder.ffmpeg:3] Requested content-type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": {audio=pcm(stereo)}
2024/12/19 04:29:23 [decoder.ffmpeg:3] FFmpeg recognizes "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a" as audio: {codec: alac, 44100Hz, 2 channel(s)}, video: {codec: mjpeg, 500x500, gray}
2024/12/19 04:29:23 [decoder.ffmpeg:3] Decoded content-type for "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a": {audio=pcm(stereo)}
2024/12/19 04:29:23 [decoder:4] Selected decoder ffmpeg for file "/home/ubuntu/media/Promo_Only_Keepers/Bad_Nerves-USA.m4a" with expected kind {audio=pcm(stereo)} and detected content {audio=pcm(stereo)}
2024/12/19 04:29:23 [source:4] Source blank.343 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [blank.343:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [playlist_pls:4] Queued 1 request(s)
2024/12/19 04:29:23 [process:4] Process exited with code 0
2024/12/19 04:29:23 [process:4] Starting process
2024/12/19 04:29:23 [process:4] Cleaning up process
2024/12/19 04:29:23 [source:4] Source on_metadata.684 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [on_metadata.684:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source on_track.684 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [on_track.684:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [process:4] Closing process's stdin
2024/12/19 04:29:23 [source:4] Source cross_after.342 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [cross_after.342:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source cross.buffer.1368 gets up with content type: {audio=pcm(stereo)} and frame type: 'A.
2024/12/19 04:29:23 [cross.buffer.1368:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source fade_out.342 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [fade_out.342:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source track_amplify.684 gets up with content type: {audio=pcm(stereo)} and frame type: 'A.{audio : pcm(stereo)}.
2024/12/19 04:29:23 [track_amplify.684:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source on_frame.683 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [on_frame.683:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source on_metadata.683 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [on_metadata.683:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source on_track.683 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [on_track.683:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source cross_before.342 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [cross_before.342:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source cross.buffer.1366 gets up with content type: {audio=pcm(stereo)} and frame type: 'A.
2024/12/19 04:29:23 [cross.buffer.1366:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [source:4] Source cross_after_tail.328 gets up with content type: {audio=pcm(stereo)} and frame type: {audio : pcm(stereo)}.
2024/12/19 04:29:23 [cross_after_tail.328:3] Content type is {audio=pcm(stereo)}.
2024/12/19 04:29:23 [cross_after.342:4] Fading in with type: sin, curve: default, delay: 0.0s and duration: 0.0s.
2024/12/19 04:29:23 [cross_before.342:4] New fade out delay: 3.9s.
2024/12/19 04:29:23 [cross_before.342:4] Fading out with type: sin, curve: 10.0, delay: 3.87297052154s, duration: 0.0s and 3.87297052154s remaining.
2024/12/19 04:29:23 [process:4] Process exited with code 0
2024/12/19 04:29:23 [process:4] Cleaning up process
2024/12/19 04:29:23 [process:4] Starting process
2024/12/19 04:29:23 [process:4] Closing process's stdin
2024/12/19 04:29:23 [sequence.683:4] Finished with blank.343
2024/12/19 04:29:23 [ogg.muxer:4] Radio_Calico_-_lossless: Setting end of track 214fede8.
2024/12/19 04:29:23 [ogg.muxer:4] Radio_Calico_-_lossless: Every ogg logical tracks have ended: setting end of stream.
2024/12/19 04:29:23 [ogg.muxer:4] Radio_Calico_-_lossless: Starting new sequentialized ogg stream.
2024/12/19 04:29:23 [process:4] Process exited with code 0
2024/12/19 04:29:23 [process:4] Starting process
2024/12/19 04:29:23 [process:4] Cleaning up process

@toots
Copy link
Member

toots commented Dec 19, 2024

I see. Thanks so much for taking the time here.

I have to see what to do with our native flac support. It's never been quite stable because the C library is callback-based and this is pretty tricky to implement in OCaml.

As of now, my advice would be to switch to the %ffmpeg encoder to encode in flac, native or ogg. The only limitation being that ffmpeg, like pretty much everyone on the planet, is bad at doing multitrack ogg. But, more generally, it seems to be the consensus that multitrack ogg is to be avoided nowaways because none of the listening client know how to handle it either..

I'm gonna have a more detailed look at the actual crash as soon as I have some time.

Again, thank you for your patience and experimentation!

@fkane
Copy link
Author

fkane commented Dec 19, 2024

We currently handle multitrack ogg by sending an ogg/flac stream to an external Rocket Streaming Audio Server that does seem to handle it properly, along with the metadata. So far that's been the only way to send a hi-res lossless stream to Roon that preserves metadata and doesn't stop after every track. I'd hate to lose that, but I guess it doesn't really affect that many people.

Thanks for the advice and for taking a look!

@toots
Copy link
Member

toots commented Dec 19, 2024

Ha I see. Yes, there aren't a lot of alternatives for sending hires with metadata indeed. I'll have a look at the actual crash, maybe we can fix it.

@toots
Copy link
Member

toots commented Dec 19, 2024

@fkane I just pushed another cleanup of the code around the issue you found here: https://github.com/savonet/ocaml-flac

Would you be able to test? All you should have to do since you already installed via opam is:

git clone https://github.com/savonet/ocaml-flac.git
cd ocaml-flac
opam install -y .

@fkane
Copy link
Author

fkane commented Dec 19, 2024

Thank you! I've kicked off a test with flac 0.5.1 under gdb; I'll let you know how it does.

@toots
Copy link
Member

toots commented Dec 20, 2024

Great. Finger crossed it fixes the issue. I'm pretty mad I realized I already had done work there and forgot to release it. Won't miss it this time if it works for you.

@fkane
Copy link
Author

fkane commented Dec 20, 2024

So far so good... we should let it run for another day though before declaring victory.

@fkane
Copy link
Author

fkane commented Dec 21, 2024

OK, it's been running for 2 days straight now without incident! And that's on a t3.medium with the samplerate quality settings bumped back up to try and stress it.

The only issue worth noting is that there are occasional short gaps between tracks on the ogg/flac icecast stream. The clock has gotten pretty far behind over time:

2024/12/21 07:51:51 [cross.buffer.3154:3] Content type is {audio=pcm(stereo)}.
2024/12/21 07:51:51 [cross_after_tail.648:3] Content type is {audio=pcm(stereo)}.
2024/12/21 07:51:51 [clock.generic:2] We must catchup 3.22 seconds!
2024/12/21 07:52:18 [cross.buffer.3157:3] Content type is {audio=pcm(stereo)}.
2024/12/21 07:52:19 [clock.generic:2] We must catchup 1.10 seconds!

It may be unrelated or due to the extra overhead of gdb, and it's better than crashing.

I have kicked off a new test not running under gdb just to confirm performance is acceptable over time in a scenario closer to production. I think releasing ocaml-flac 0.5.1 is a good idea, though.

@toots
Copy link
Member

toots commented Dec 21, 2024

Well this is awesome. I'm gonna mark this issue as resolved and we can follow-up with one specific to performance issues if that is confirmed (which I think might have b/c of gdb).

Thanks again for the help and coorperation!

@toots toots closed this as completed Dec 21, 2024
@fkane
Copy link
Author

fkane commented Dec 24, 2024

Unfortunately I think I spoke too soon... even with flac 0.5.1, I just experienced two similar crashes this evening. It just took longer to hit whatever triggers it this time.

I've started another gdb session on a test server to try and capture a stack trace again and see if it is indeed the same issue or not. I'll report back with what I find, but it may take a few days to reproduce.

Once again it does seem associated with crossfades involving a short jingle, but it is very sporadic. I can't reproduce it by just playing the same sequence of tracks again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants