liquidsoap icon indicating copy to clipboard operation
liquidsoap copied to clipboard

Multiple output.hls with differing FFmpeg processing results in audio jumps

Open Warblefly opened this issue 1 year ago • 14 comments

Describe the bug Thank you for looking at this.

When making two separate streams using two different FFmpeg chains for audio processing, both streams exhibit severe jumping in the audio output.

Either stream on its own does not exhibit this effect.

I have checked the HLS segments, and the audio skipping is clearly audible within each segment, every couple of seconds or thereabouts.

Intriguingly, surrounding one of the audio streams going into ffmpeg.raw.encode.audio(%ffmpeg(%audio.raw), s) with ffmpeg.raw.encode.audio(%ffmpeg(%audio.raw), buffer(s)) fixes the problem for now. Haven't run it for very long yet.

To Reproduce Full script below including audio processing and HLS setup. This script, written for 2.1.x, has run reliably for many months.

set("log.level", 3)
settings.server.telnet.set(true)
settings.server.telnet.bind_addr.set("0.0.0.0")
settings.server.telnet.port.set(1235)
settings.server.timeout.set(-1.0)

# audio processing for high quality stream

def audio_process(s) =
  def mkfilter(graph) =
    let {audio} = source.tracks(s)
    audio = ffmpeg.filter.audio.input(graph, audio)
    audio = ffmpeg.filter.dynaudnorm(graph, audio, gausssize=23, correctdc=true, altboundary=true, maxgain=80., b=true, targetrms=1.)
    audio = ffmpeg.filter.alimiter(graph, audio, limit=0.95, attack=3., release=50., asc=true, asc_level=1.)
    ffmpeg.filter.audio.output(graph, audio)
  end
  ffmpeg.filter.create(mkfilter)
end

def audio_process_wrap(s) =
  a = ffmpeg.raw.encode.audio(%ffmpeg(%audio.raw), s)
  a = audio_process(a)
  b = source({audio = a, metadata = track.metadata(a), track_marks = track.track_marks(a)})
  ffmpeg.raw.decode.audio(b)
end

# audio processing for low quality stream
#
def audio_process_multi(s) =
  def mkfilter_multi(graph) =
    let {audio} = source.tracks(s)
    audio = ffmpeg.filter.audio.input(graph, pass_metadata=true, audio)
    audio = ffmpeg.filter.aresample(graph, audio, sample_rate=32000)
    audio = ffmpeg.filter.dynaudnorm(graph, audio, gausssize=7, correctdc=true, altboundary=true, maxgain=80., b=true, targetrms=1.)
    audio = ffmpeg.filter.volume(graph, audio, volume="-18dB", precision=2, replaygain=0)
    audio = ffmpeg.filter.mcompand(graph, audio, args="0.005,0.1 6 -47/-37,-34/-34,-17/-33 90 | 0.003,0.05 6 -47/-40,-34/-34,-17/-33 180 | 0.003,0.05 6 -47/-40,-34/-34,-17/-33 360 | 0.000625,0.03 6 -47/-40,-34/-34,-17/-33 1600 | 0.000625,0.03 6 -47/-40,-34/-34,-17/-33 2800 | 0.0001,0.025 6 -47/-35,-34/-34,-17/-33 4800 | 0,0.025 6 -47/-35,-34/-34,-17/-33 8192 | 0,0.025 6 -47/-40,-34/-34,-17/-33 15999")
    audio = ffmpeg.filter.volume(graph, audio, volume="+20dB", precision=2, replaygain=0)
    audio = ffmpeg.filter.aresample(graph, audio, sample_rate=192000)
    audio = ffmpeg.filter.alimiter(graph, audio, limit=0.7, attack=3., release=50., asc=false, asc_level=0., level=true)
    audio = ffmpeg.filter.aresample(graph, audio, sample_rate=32000)
    ffmpeg.filter.audio.output(graph, pass_metadata=true, audio)
  end
  ffmpeg.filter.create(mkfilter_multi)
end

def audio_process_multi_wrap(s) =
  a = ffmpeg.raw.encode.audio(%ffmpeg(%audio.raw), s)
  a = audio_process_multi(a)
  b = source({audio = a, metadata = track.metadata(a), track_marks = track.track_marks(a)})
  ffmpeg.raw.decode.audio(b)
end

# Here's the playlist, annotated as per our Python pre-production program dictates
myplaylist = playlist(reload_mode="watch", mime_type="application/x-mpegURL", "/home/john/src/radio/bc2-30DEC2020-complete.m3u8")

# Cut off any silent starts
myplaylist = cue_cut(myplaylist)

# Amplify each track according to our own EBU R.128 volume data
myplaylist = amplify(override="liq_amplify", 1.0, myplaylist)

# Add the news
myplaylist = fallback(track_sensitive=true, transition_length=30.0, [request.queue(id="override"), myplaylist])

# Do the crossfades
myplaylist = crossfade(duration=30.0, smart=false, fade_out=0.0, fade_in=0.0, minimum=-1.0, default=(fun(a,b)->add(normalize=false,([b, a]))), conservative=true,  myplaylist)

radio = mksafe(audio_process_wrap(myplaylist))
radio_comp = mksafe(audio_process_multi_wrap(myplaylist))

# What shall we name our HLS segments?
#
def segment_name(~position, ~extname, stream_name) =
        timestamp = int_of_float(time())
        duration = 10
        "#{stream_name}_#{duration}_#{timestamp}_#{position}.#{extname}"
end

# Here's the high bandwidth stream
output.file.hls(
        playlist="live_high.m3u8",
        segment_name=segment_name,
        persist_at="/home/liquidsoap/audio/state.config",
        "/home/liquidsoap/audio",
                [
                (
                        "AAC",
                        %ffmpeg(
                                format="mpegts",
                                %audio(
                                        codec="libfdk_aac",
                                        samplerate=48000,
                                        vbr=5,
                                        afterburner=1
                                        )
                                ))],
        radio
        )

# Here's the low bandwidth stream
#
output.file.hls(
        playlist="live.m3u8",
        segment_name=segment_name,
        persist_at="/home/liquidsoap/audio/state_low.config",
        "/home/liquidsoap/audio",
                [
                (
                        "HEAAC+",
                        %ffmpeg(
                                format="mpegts",
                                %audio(
                                        codec="libfdk_aac",
                                        samplerate=32000,
                                        vbr=1,
                                        afterburner=1,
                                        profile="aac_he_v2"
                                        )
                                ))],
        radio_comp
        )

Expected behavior Both streams in version 2.1.x have perfect audio, though with different audio processing.

Version details

  • OS: Debian
  • Version: testing

Install method Opam for nearly everything, dune for latest 2.2.x rolling release

Warblefly avatar Aug 09 '23 10:08 Warblefly

Hi @Warblefly. Thanks for reporting this.

Are you able to test the blit-again branch? I suspect this might have the fix for your problem.

toots avatar Aug 09 '23 12:08 toots

Thank you for the advice!

Very happy to try later today when I get back to the console.

Warblefly avatar Aug 09 '23 12:08 Warblefly

Good evening,

I did try this, and have checked the commit signature in the version number, so I know it's the correct branch.

The problem is not solved, I'm afraid. The audio jumps forwards at about one-second intervals.

Something else I've noticed is that putting the buffer() command into the simpler FFmpeg filter (not using multiband compression and samplerate conversion), there is an error on running liquidsoap ("Invalid ffmpeg content: non-monotonic PTS!").

The error does not occur on putting buffer() into the more complex FFmpeg filter, and the audio proceeds without skipping.

Here is the full log. Hope that's useful to you. Best wishes, John

2023/08/09 21:09:44 >>> LOG START
2023/08/09 21:09:17 [ffmpeg.filter.bitstream:3] No valid mode found for filter pgs_frame_merge!
2023/08/09 21:09:17 [main:3] Liquidsoap 2.2.1+git@7d84ed1d7
2023/08/09 21:09:17 [main:3] Using: angstrom=0.15.0 asn1-combinators=0.2.6 astring=0.8.5 base64=3.5.1 bigstringaf=0.9.1 bos=0.2.1 bytes=[distributed with OCaml 4.02 or above] ca-certs=v0.2.3 camlp-streams camomile.lib=2.0 cry=1.0.1 cstruct=6.2.0 curl=0.9.2 domain-name=0.4.0 dtools=0.4.5 dune-build-info=3.10.0 dune-private-libs.dune-section=3.10.0 dune-site=3.10.0 dune-site.private=3.10.0 duppy=0.9.3 eqaf=0.9 eqaf.bigstring=0.9 eqaf.cstruct=0.9 ffmpeg-av=1.1.9 ffmpeg-avcodec=1.1.9 ffmpeg-avdevice=1.1.9 ffmpeg-avfilter=1.1.9 ffmpeg-avutil=1.1.9 ffmpeg-swresample=1.1.9 ffmpeg-swscale=1.1.9 fileutils=0.6.4 fmt=0.9.0 fpath=0.7.3 gen=1.1 gmap=0.3.0 hkdf=1.0.4 ipaddr=5.5.0 ladspa=0.2.2 liquidsoap-lang=2.2.1 liquidsoap-lang.console=2.2.1 liquidsoap_builtins=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_core=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_ffmpeg=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_ladspa=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_optionals=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_oss=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_runtime=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_samplerate=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_ssl=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_taglib=rolling-release-v2.2.x-1-g7d84ed1 liquidsoap_tls=rolling-release-v2.2.x-1-g7d84ed1 logs=0.7.0 macaddr=5.5.0 menhirLib=20230608 metadata=0.2.0 mirage-crypto=0.11.1 mirage-crypto-ec=0.11.1 mirage-crypto-pk=0.11.1 mirage-crypto-rng=0.11.1 mirage-crypto-rng.unix=0.11.1 mm=0.8.4 mm.audio=0.8.4 mm.base=0.8.4 mm.image=0.8.4 mm.midi=0.8.4 mm.video=0.8.4 pbkdf pcre=7.5.0 ptime=1.1.0 ptime.clock.os=1.1.0 rresult=0.7.0 samplerate=0.1.6 sedlex=3.2 seq=[distributed with OCaml 4.07 or above] sexplib0=v0.16.0 ssl=0.7.0 stdlib-shims=0.3.0 str=5.0.0 stringext=1.6.0 taglib=0.3.10 threads=5.0.0 tls=0.17.1 unix=5.0.0 uri=4.2.0 x509=0.16.5 zarith=1.13
2023/08/09 21:09:17 [main:3]
2023/08/09 21:09:17 [main:3] DISCLAIMER: This version of Liquidsoap has been compiled from a snapshot of the
2023/08/09 21:09:17 [main:3] development code. As such, it should not be used in production unless you know
2023/08/09 21:09:17 [main:3] what you are doing!
2023/08/09 21:09:17 [main:3]
2023/08/09 21:09:17 [main:3] We are, however, very interested in any feedback about our development code and
2023/08/09 21:09:17 [main:3] committed to fix issues as soon as possible.
2023/08/09 21:09:17 [main:3]
2023/08/09 21:09:17 [main:3] If you are interested in collaborating to the development of Liquidsoap, feel
2023/08/09 21:09:17 [main:3] free to drop us a mail at <[email protected]> or to join the slack chat
2023/08/09 21:09:17 [main:3] at <http://slack.liquidsoap.info>.
2023/08/09 21:09:17 [main:3]
2023/08/09 21:09:17 [main:3] Please send any bug report or feature request at
2023/08/09 21:09:17 [main:3] <https://github.com/savonet/liquidsoap/issues>.
2023/08/09 21:09:17 [main:3]
2023/08/09 21:09:17 [main:3] We hope you enjoy this snapshot build of Liquidsoap!
2023/08/09 21:09:17 [main:3]
2023/08/09 21:09:17 [clock:3] Using builtin (low-precision) implementation for latency control
2023/08/09 21:09:21 [main:3] Standard library loaded in 4.73 seconds.
2023/08/09 21:09:44 [lang:2] WARNING: "set" is deprecated and will be removed in future version. Please use `settings.path.to.key := value`
2023/08/09 21:09:44 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2023/08/09 21:09:44 [frame:3] Video frame size set to: 1280x720
2023/08/09 21:09:44 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2023/08/09 21:09:44 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2023/08/09 21:09:44 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2023/08/09 21:09:45 [sandbox:3] Sandboxing disabled
2023/08/09 21:09:45 [startup:3] FFmpeg filters registration: 0.05s
2023/08/09 21:09:45 [startup:3] FFmpeg bitstream filters registration: 0.00s
2023/08/09 21:09:45 [startup:3] LADSPA plugins registration: 0.00s
2023/08/09 21:09:45 [startup:3] Typechecking: 3.93s
2023/08/09 21:09:45 [startup:3] Evaluation: 0.03s
2023/08/09 21:09:45 [startup:3] Typechecking: 0.10s
2023/08/09 21:09:45 [startup:3] Evaluation: 0.01s
2023/08/09 21:09:45 [startup:3] Typechecking: 22.14s
2023/08/09 21:09:45 [startup:3] Evaluation: 0.37s
2023/08/09 21:09:45 [startup:3] Loaded ./test.liq: 22.52s
2023/08/09 21:09:45 [video.converter:3] Using preferred video converter: ffmpeg.
2023/08/09 21:09:45 [audio.converter:3] Using samplerate converter: libsamplerate.
2023/08/09 21:09:45 [audio.consumer.2:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [source.4:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [ffmpeg.filter.audio.output:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [audio.consumer.4:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [source.7:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [ffmpeg.filter.audio.output.2:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [ffmpeg_filter_audio_input:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [ffmpeg_raw_encode_audio:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [audio.producer:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [audio.consumer:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [buffer.producer:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [buffer.consumer:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [crossfade.2:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [track_metadata_deduplicate:3] Content type is {}.
2023/08/09 21:09:45 [cross:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [override:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [amplify.3:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [amplify.2:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [cue_cut:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [bc2-30DEC2020-complete_m3u8:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [audio.consumer.3:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [ffmpeg_filter_audio_input.2:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [ffmpeg_raw_encode_audio.2:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [audio.producer.3:3] Content type is {audio=ffmpeg.audio.raw}.
2023/08/09 21:09:45 [/home/liquidsoap/audio/live_m3u8:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [ffmpeg_raw_decode_audio.2:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [audio.producer.4:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [safe_blank.2:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [/home/liquidsoap/audio/live_high_m3u8:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [ffmpeg_raw_decode_audio:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [audio.producer.2:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [safe_blank:3] Content type is {audio=pcm(stereo)}.
2023/08/09 21:09:45 [video.text:3] Using native implementation
2023/08/09 21:09:45 [clock.main:3] Streaming loop starts in auto-sync mode
2023/08/09 21:09:45 [clock.main:3] Delegating synchronization to CPU clock
2023/08/09 21:09:45 [mksafe.2:3] Switch to safe_blank.2.
2023/08/09 21:09:45 [mksafe:3] Switch to safe_blank.
[mpegts @ 0x5607a109e400] frame size not set
2023/08/09 21:09:45 [decoder.ffmpeg:3] Requested content-type for "/home/john/src/radio/mez3/Various - Funkin' On The 1 Cd5 - 03 - Everything I Do Gonna Be Funky (From Now On).5fd0a017482fb56d9f962b2da22aa04c.mka": {audio=pcm(stereo)}
2023/08/09 21:09:45 [decoder.ffmpeg:3] FFmpeg recognizes "/home/john/src/radio/mez3/Various - Funkin' On The 1 Cd5 - 03 - Everything I Do Gonna Be Funky (From Now On).5fd0a017482fb56d9f962b2da22aa04c.mka" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/08/09 21:09:45 [decoder.ffmpeg:3] Decoded content-type for "/home/john/src/radio/mez3/Various - Funkin' On The 1 Cd5 - 03 - Everything I Do Gonna Be Funky (From Now On).5fd0a017482fb56d9f962b2da22aa04c.mka": {audio=pcm(stereo)}
2023/08/09 21:09:45 [bc2-30DEC2020-complete_m3u8:3] Prepared "/home/john/src/radio/mez3/Various - Funkin' On The 1 Cd5 - 03 - Everything I Do Gonna Be Funky (From Now On).5fd0a017482fb56d9f962b2da22aa04c.mka" (RID 1).
2023/08/09 21:09:45 [mksafe.2:3] Switch to ffmpeg_raw_decode_audio.2 with transition.
[mpegts @ 0x5607a0cc9e00] frame size not set
2023/08/09 21:09:45 [switch:3] Switch to amplify.3.
2023/08/09 21:09:45 [cue_cut:3] Cueing in...
2023/08/09 21:09:45 [decoder.ffmpeg:3] Requested content-type for "/home/john/src/radio/mez3/John Dankworth Orchestra - Eleven Plus [3011686427].37324a43998819e24dfe6fdeb222f741.mka": {audio=pcm(stereo)}
2023/08/09 21:09:45 [decoder.ffmpeg:3] FFmpeg recognizes "/home/john/src/radio/mez3/John Dankworth Orchestra - Eleven Plus [3011686427].37324a43998819e24dfe6fdeb222f741.mka" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2023/08/09 21:09:45 [decoder.ffmpeg:3] Decoded content-type for "/home/john/src/radio/mez3/John Dankworth Orchestra - Eleven Plus [3011686427].37324a43998819e24dfe6fdeb222f741.mka": {audio=pcm(stereo)}
2023/08/09 21:09:46 [buffer.producer:3] Buffer emptied, start buffering...
2023/08/09 21:09:46 [audio.consumer:3] Source failed (no more tracks) stopping output...
2023/08/09 21:09:46 [ffmpeg_filter_audio_input:3] Source failed (no more tracks) stopping output...
2023/08/09 21:09:46 [audio.consumer.2:3] Source failed (no more tracks) stopping output...
2023/08/09 21:09:47 [ffmpeg:3] Invalid ffmpeg content: non-monotonic PTS!
2023/08/09 21:09:47 [clock.ffmpeg.filter:2] Source ffmpeg_filter_audio_input failed while streaming: Content_base.Invalid!
2023/08/09 21:09:47 [clock.ffmpeg.filter:2] Raised at Ffmpeg_utils.Duration.push in file "src/core/tools/ffmpeg_utils.ml", line 317, characters 14-35
2023/08/09 21:09:47 [clock.ffmpeg.filter:2] Called from Ffmpeg_filter_io.base_output#send_frame.(fun) in file "src/core/io/ffmpeg_filter_io.ml", line 128, characters 12-79
2023/08/09 21:09:47 [clock.ffmpeg.filter:2] Called from Stdlib__List.iter in file "list.ml", line 110, characters 12-15
2023/08/09 21:09:47 [clock.ffmpeg.filter:2] Called from Output.output#output in file "src/core/outputs/output.ml", line 180, characters 45-70
2023/08/09 21:09:47 [clock.ffmpeg.filter:2] Called from Clock.MkClock.clock#end_tick.(fun) in file "src/core/clock.ml", line 318, characters 16-24
2023/08/09 21:09:47 [clock.ffmpeg.filter:2]
2023/08/09 21:09:47 [threads:3] Main loop exited
2023/08/09 21:09:47 [main:3] Shutdown started!
2023/08/09 21:09:47 [threads:3] Waiting for main threads to terminate...
2023/08/09 21:09:47 [audio.consumer.2:3] Source failed (no more tracks) stopping output...
[libfdk_aac @ 0x7fb52ccd0840] Note, the VBR setting is unsupported and only works with some parameter combinations
[libfdk_aac @ 0x7fb53f559440] Note, the VBR setting is unsupported and only works with some parameter combinations
2023/08/09 21:09:47 [clock.main:3] Streaming loop stopped.
2023/08/09 21:09:47 [threads:3] Main threads terminated.
2023/08/09 21:09:47 [threads:3] Shutting down scheduler...
2023/08/09 21:09:47 [threads:3] Scheduler shut down.
2023/08/09 21:09:47 [server:3] Closing socket.
2023/08/09 21:09:47 [main:3] Cleaning downloaded files...
2023/08/09 21:09:47 [main:3] Freeing memory...
2023/08/09 21:09:47 >>> LOG END

Warblefly avatar Aug 09 '23 20:08 Warblefly

Stream. Let me know if you'd like the 'skipping' version so you can check/listen?

http://warblefly.sytes.net:8000/live_high.m3u8

Warblefly avatar Aug 10 '23 06:08 Warblefly

Thanks for trying. I can reproduce with your script. Will have a pass at finding the source of the problem.

toots avatar Aug 10 '23 14:08 toots

Also, after a few hours, crossfading breaks down; outgoing tracks are cut off, silence follows for a few seconds, then the next track begins. The same playlist in 2.1.x does not exhibit this problem.

Warblefly avatar Aug 13 '23 16:08 Warblefly

Hi @Warblefly. I'm getting close to the source of the issue here. When you say it worked in 2.1.x, could you share your script for that version? Thanks!

toots avatar Aug 14 '23 23:08 toots

Sure thing. Here's the script, followed by the opening of the debug output. Hope this helps you.

Release 2.1.4 installed from a clean ocaml start by opam.

(There's a buffer() before one of the audio processing wrappers; without this, Liquidsoap says a clock cannot belong to two sources.)

ERROR AT FIRST:

Unknown position:

Error 10: A source cannot belong to two clocks (ffmpeg.raw.encode.audio.producer_1.child[], ffmpeg.raw.encode.audio.producer_0.child[cross_0.child[cue_cut_0.child[]]]).

SCRIPT:

settings.server.log.level.set(4)
settings.server.telnet.set(true)
settings.server.telnet.bind_addr.set("0.0.0.0")
settings.server.telnet.port.set(1235)
settings.server.timeout.set(-1.0)
settings.decoder.decoders.set(["ffmpeg"])

# audio processing for high quality stream

def audio_process(s) =
  def mkfilter(graph) =
    audio = s
    audio = ffmpeg.filter.audio.input(graph, audio)
    audio = ffmpeg.filter.dynaudnorm(graph, audio, gausssize=23, correctdc=true, altboundary=true, maxgain=80., b=true, targetrms=1.)
    audio = ffmpeg.filter.alimiter(graph, audio, limit=0.95, attack=3., release=50., asc=true, asc_level=1.)
    ffmpeg.filter.audio.output(graph, audio)
  end
  ffmpeg.filter.create(mkfilter)
end

def audio_process_wrap(s) =
  a = ffmpeg.raw.encode.audio(%ffmpeg(%audio.raw), s)
  a = audio_process(a)
  ffmpeg.raw.decode.audio(a)
end

# audio processing for low quality stream
#
def audio_process_multi(s) =
  def mkfilter_multi(graph) =
    audio = s
    audio = ffmpeg.filter.audio.input(graph, pass_metadata=true, audio)
    audio = ffmpeg.filter.aresample(graph, audio, sample_rate=32000)
    audio = ffmpeg.filter.dynaudnorm(graph, audio, gausssize=7, correctdc=true, altboundary=true, maxgain=80., b=true, targetrms=1.)
    audio = ffmpeg.filter.volume(graph, audio, volume="-18dB", precision=2, replaygain=0)
    audio = ffmpeg.filter.mcompand(graph, audio, args="0.005,0.1 6 -47/-37,-34/-34,-17/-33 90 | 0.003,0.05 6 -47/-40,-34/-34,-17/-33 180 | 0.003,0.05 6 -47/-40,-34/-34,-17/-33 360 | 0.000625,0.03 6 -47/-40,-34/-34,-17/-33 1600 | 0.000625,0.03 6 -47/-40,-34/-34,-17/-33 2800 | 0.0001,0.025 6 -47/-35,-34/-34,-17/-33 4800 | 0,0.025 6 -47/-35,-34/-34,-17/-33 8192 | 0,0.025 6 -47/-40,-34/-34,-17/-33 15999")
    audio = ffmpeg.filter.volume(graph, audio, volume="+20dB", precision=2, replaygain=0)
    audio = ffmpeg.filter.aresample(graph, audio, sample_rate=192000)
    audio = ffmpeg.filter.alimiter(graph, audio, limit=0.7, attack=3., release=50., asc=false, asc_level=0., level=true)
    audio = ffmpeg.filter.aresample(graph, audio, sample_rate=32000)
    ffmpeg.filter.audio.output(graph, pass_metadata=true, audio)
  end
  ffmpeg.filter.create(mkfilter_multi)
end

def audio_process_multi_wrap(s) =
  a = ffmpeg.raw.encode.audio(%ffmpeg(%audio.raw), buffer(s))
  a = audio_process_multi(a)
  ffmpeg.raw.decode.audio(a)
end

# Security fallback
security = single("/home/john/src/radio/fault.mka")

# Here's the playlist, annotated as per our Python pre-production program dictates
myplaylist = playlist(reload_mode="watch", mime_type="application/x-mpegURL", "/home/john/src/radio/bc2-30DEC2020-complete.m3u8")

# Cut off any silent starts
myplaylist = cue_cut(myplaylist)

# Amplify each track according to our own EBU R.128 volume data
myplaylist = amplify(override="liq_amplify", 1.0, myplaylist)

# Add the news
myplaylist = fallback(track_sensitive=true, transition_length=30.0, [request.queue(id="override"), myplaylist])

# Do the crossfades
myplaylist = crossfade(duration=30.0, smart=false, fade_out=0.0, fade_in=0.0, minimum=-1.0, default=(fun(a,b)->add(normalize=false,([b, a]))), conservative=true,  myplaylist)

#myplaylist = mksafe(myplaylist)


radio = fallback(track_sensitive=false, [audio_process_wrap(myplaylist), security])
radio_comp = fallback(track_sensitive=false, [audio_process_multi_wrap(myplaylist), security])

# What shall we name our HLS segments?
#
def segment_name(~position, ~extname, stream_name) =
        timestamp = int_of_float(time())
        duration = 10
        "#{stream_name}_#{duration}_#{timestamp}_#{position}.#{extname}"
end

# Here's the high bandwidth stream
output.file.hls(
        playlist="live_high.m3u8",
        segment_name=segment_name,
        persist_at="/home/liquidsoap/audio/state.config",
        "/home/liquidsoap/audio",
                [
                (
                        "AAC",
                        %ffmpeg(
                                format="mpegts",
                                %audio(
                                        codec="libfdk_aac",
                                        samplerate=48000,
                                        vbr=5,
                                        afterburner=1
                                        )
                                ).{bandwidth=200000})],
        radio
        )

# Here's the low bandwidth stream

output.file.hls(
        playlist="live.m3u8",
        segment_name=segment_name,
        persist_at="/home/liquidsoap/audio/state_low.config",
        "/home/liquidsoap/audio",
                [
                (
                        "HEAAC+",
                        %ffmpeg(
                                format="mpegts",
                                %audio(
                                        codec="libfdk_aac",
                                        samplerate=32000,
                                        vbr=1,
                                        afterburner=1,
                                        profile="aac_he_v2"
                                        )
                        ).{bandwidth=30000})],
        radio_comp
        )

Here's the debug log; I let the system start, then CTRL-C out of it.

DEBUG OUTPUT:

[libfdk_aac @ 0x555641ac02c0] Note, the VBR setting is unsupported and only works with some parameter combinations
[libfdk_aac @ 0x555641ae8240] Note, the VBR setting is unsupported and only works with some parameter combinations
2023/08/15 11:23:30 >>> LOG START
2023/08/15 11:23:19 [ffmpeg.filter.bitstream:3] No valid mode found for filter pgs_frame_merge!
2023/08/15 11:23:19 [main:3] Liquidsoap 2.1.4
2023/08/15 11:23:19 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.5.0 sedlex=3.2 menhirLib=20230608 curl=0.9.2 uri=4.2.0 dtools=0.4.5 duppy=0.9.2 mm=0.8.4 dynlink=[distributed with Ocaml] ffmpeg=1.1.7 taglib=0.3.10 camomile=1.0.2
2023/08/15 11:23:19 [dynamic.loader:3] Could not find dynamic module for lame encoder.
2023/08/15 11:23:19 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.
2023/08/15 11:23:19 [clock:3] Using builtin (low-precision) implementation for latency control
2023/08/15 11:23:30 [bc2-30DEC2020-complete.m3u8:4] Reloading playlist.
2023/08/15 11:23:30 [frame:4] frame.audio.samplerate set to: 44100
2023/08/15 11:23:30 [frame:4] frame.video.framerate set to: 25
2023/08/15 11:23:30 [source:4] Setting crossfade duration to 30.00s
2023/08/15 11:23:30 [frame:4] frame.audio.channels set to: 2
2023/08/15 11:23:30 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz main.
2023/08/15 11:23:30 [frame:3] Video frame size set to: 1280x720
2023/08/15 11:23:30 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2023/08/15 11:23:30 [frame:3] Targeting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2023/08/15 11:23:30 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2023/08/15 11:23:30 [frame:4] frame.video.default set to: false
2023/08/15 11:23:30 [frame:4] frame.midi.channels set to: 0
2023/08/15 11:23:30 [frame:4] frame.video.width set to: 1280
2023/08/15 11:23:30 [frame:4] frame.video.height set to: 720
2023/08/15 11:23:30 [frame:4] frame.audio.samplerate set to: 44100
2023/08/15 11:23:30 [sandbox:3] Sandboxing disabled
2023/08/15 11:23:30 [video.converter:3] Using preferred video converter: ffmpeg.
2023/08/15 11:23:30 [audio.converter:3] Using samplerate converter: ffmpeg.
2023/08/15 11:23:30 [clock:4] Currently 9 clock(s) allocated.
2023/08/15 11:23:30 [clock.main:4] Starting 2 source(s)...
2023/08/15 11:23:30 [source:4] Source output.file_0 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [/home/liquidsoap/audio/live_high.m3u8:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source switch_1 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.decode.audio.producer_0 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.decode.audio.producer_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.decode.audio.consumer_0 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.decode.audio.consumer_0:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.filter.output_0 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.filter.output_0:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source single_0 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [single_0:3] "/home/john/src/radio/fault.mka" is static, resolving once for all...
2023/08/15 11:23:30 [decoder:4] Available decoders: ffmpeg (priority: 10)
2023/08/15 11:23:30 [decoder:4] Trying decoder "ffmpeg"
2023/08/15 11:23:30 [decoder.ffmpeg:4] ffmpeg recognizes "/home/john/src/radio/fault.mka" as: audio: {codec: flac, 44100Hz, 2 channel(s)} and content-type: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [decoder:4] Selected decoder ffmpeg for file "/home/john/src/radio/fault.mka" with expected kind {audio=pcm(stereo),video=none,midi=none} and detected content {audio=pcm(stereo),video=none,midi=none}
2023/08/15 11:23:30 [decoder.taglib:4] Unsupported file extension for "/home/john/src/radio/fault.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/fault.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/fault.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/fault.mka"!
2023/08/15 11:23:30 [decoder.image.metadata:4] Unsupported file extension for "/home/john/src/radio/fault.mka"!
2023/08/15 11:23:30 [decoder.video.metadata:4] Unsupported file extension for "/home/john/src/radio/fault.mka"!
2023/08/15 11:23:30 [single_0:3] Prepared "/home/john/src/radio/fault.mka" (RID 0).
2023/08/15 11:23:30 [/home/liquidsoap/audio/live_high.m3u8:4] Resuming from saved state
2023/08/15 11:23:30 [source:4] Source output.file_1 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [/home/liquidsoap/audio/live.m3u8:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source switch_2 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.decode.audio.producer_1 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.decode.audio.producer_1:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.decode.audio.consumer_1 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.decode.audio.consumer_1:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.filter.output_1 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.filter.output_1:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [/home/liquidsoap/audio/live.m3u8:4] Resuming from saved state
2023/08/15 11:23:30 [/home/liquidsoap/audio/live.m3u8:4] Failed to resume from saved state: Hls_output.Invalid_state
2023/08/15 11:23:30 [threads:4] Created thread "clock_main" (1 total).
2023/08/15 11:23:30 [clock.ffmpeg.raw.encode.audio.producer_0.child:4] Starting 2 source(s)...
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.encode.audio.consumer_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.encode.audio.consumer_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source crossfade_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [crossfade_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source cross_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [cross_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source switch_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source override gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [override:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [clock.main:3] Streaming loop starts in auto-sync mode
2023/08/15 11:23:30 [source:4] Source amplify_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [clock.main:3] Delegating synchronisation to CPU clock
2023/08/15 11:23:30 [amplify_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source cue_cut_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [cue_cut_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source bc2-30DEC2020-complete.m3u8 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [bc2-30DEC2020-complete.m3u8:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [switch_1:3] Switch to single_0.
2023/08/15 11:23:30 [source:4] Source buffer.consumer_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [buffer.consumer_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [clock.ffmpeg.raw.encode.audio.producer_1.child:4] Starting 1 source(s)...
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.encode.audio.consumer_1 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.encode.audio.consumer_1:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source buffer.producer_0 gets up with content kind: {audio=pcm,video=none,midi=none}.
2023/08/15 11:23:30 [buffer.producer_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [clock.ffmpeg.raw.decode.audio.producer_1.child:4] Starting 1 source(s)...
2023/08/15 11:23:30 [clock.ffmpeg.raw.decode.audio.producer_0.child:4] Starting 1 source(s)...
2023/08/15 11:23:30 [clock.ffmpeg.filter:4] Starting 1 source(s)...
2023/08/15 11:23:30 [source:4] Source ffmpeg.filter.input_0 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [abuffer_0:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.encode.audio.producer_0 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.encode.audio.producer_0:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [clock.ffmpeg.filter:4] Starting 1 source(s)...
2023/08/15 11:23:30 [source:4] Source ffmpeg.filter.input_1 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [abuffer_1:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [source:4] Source ffmpeg.raw.encode.audio.producer_1 gets up with content kind: {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [ffmpeg.raw.encode.audio.producer_1:4] Content type is {audio=ffmpeg.audio.raw,video=none,midi=none}.
2023/08/15 11:23:30 [clock:4] Main phase starts.
2023/08/15 11:23:30 [threads:4] Created thread "generic queue #1" (1 total).
2023/08/15 11:23:30 [threads:4] Created thread "generic queue #2" (2 total).
2023/08/15 11:23:30 [threads:4] Created thread "non-blocking queue #1" (3 total).
2023/08/15 11:23:30 [threads:4] Created thread "non-blocking queue #2" (4 total).
2023/08/15 11:23:30 [video.text:3] Using native implementation
[mpegts @ 0x555641a84080] frame size not set
2023/08/15 11:23:30 [decoder:4] Available decoders: ffmpeg (priority: 10)
2023/08/15 11:23:30 [decoder:4] Trying decoder "ffmpeg"
2023/08/15 11:23:30 [switch_2:3] Switch to single_0.
2023/08/15 11:23:30 [source:4] Source replay_metadata_0 gets up with content kind: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [replay_metadata_0:4] Content type is {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [decoder.ffmpeg:4] ffmpeg recognizes "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka" as: audio: {codec: mp3, 48000Hz, 2 channel(s)} and content-type: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [decoder:4] Selected decoder ffmpeg for file "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka" with expected kind {audio=pcm(stereo),video=none,midi=none} and detected content {audio=pcm(stereo),video=none,midi=none}
2023/08/15 11:23:30 [decoder.taglib:4] Unsupported file extension for "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka"!
2023/08/15 11:23:30 [decoder.image.metadata:4] Unsupported file extension for "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka"!
2023/08/15 11:23:30 [decoder.video.metadata:4] Unsupported file extension for "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka"!
2023/08/15 11:23:30 [bc2-30DEC2020-complete.m3u8:4] Queued 1 requests
[mpegts @ 0x555641ae7b80] frame size not set
2023/08/15 11:23:30 [bc2-30DEC2020-complete.m3u8:4] Remaining 0 requests
2023/08/15 11:23:30 [bc2-30DEC2020-complete.m3u8:3] Prepared "/home/john/src/radio/mez3/11. You've Got A Friend.b1c2c90672fa7b5a75559ed33e828509.mka" (RID 2).
2023/08/15 11:23:30 [switch_1:3] Switch to ffmpeg.raw.decode.audio.producer_0 with transition.
2023/08/15 11:23:30 [cross_0:4] Buffering end of track...
2023/08/15 11:23:30 [switch_0:3] Switch to amplify_0.
2023/08/15 11:23:30 [cue_cut_0:4] Cue points : none / none
2023/08/15 11:23:30 [cue_cut_0:3] Cueing in...
2023/08/15 11:23:30 [amplify_0:4] Overriding amplification: 0.393550.
2023/08/15 11:23:30 [cross_0:4] Overriding crossfade duration from metadata liq_cross_duration
2023/08/15 11:23:30 [cross_0:4] Setting crossfade duration to 8.92s
2023/08/15 11:23:30 [decoder:4] Available decoders: ffmpeg (priority: 10)
2023/08/15 11:23:30 [decoder:4] Trying decoder "ffmpeg"
2023/08/15 11:23:30 [decoder.ffmpeg:4] ffmpeg recognizes "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka" as: audio: {codec: mp3, 44100Hz, 2 channel(s)} and content-type: {audio=pcm(stereo),video=none,midi=none}.
2023/08/15 11:23:30 [decoder:4] Selected decoder ffmpeg for file "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka" with expected kind {audio=pcm(stereo),video=none,midi=none} and detected content {audio=pcm(stereo),video=none,midi=none}
2023/08/15 11:23:30 [decoder.taglib:4] Unsupported file extension for "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka"!
2023/08/15 11:23:30 [decoder.id3:4] Unsupported file extension for "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka"!
2023/08/15 11:23:30 [decoder.image.metadata:4] Unsupported file extension for "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka"!
2023/08/15 11:23:30 [decoder.video.metadata:4] Unsupported file extension for "/home/john/src/radio/mez3/The_Other_Side_Stereo_MCs.964f038c67bc5f56bc3c71e3f8d60c1e.mka"!
2023/08/15 11:23:30 [bc2-30DEC2020-complete.m3u8:4] Queued 1 requests
2023/08/15 11:23:31 [cross_0:4] More buffering will be needed.
2023/08/15 11:23:31 [ffmpeg.filter:4] Initializing graph
2023/08/15 11:23:31 [switch_2:3] Switch to ffmpeg.raw.decode.audio.producer_1 with transition.
2023/08/15 11:23:31 [source:4] Source replay_metadata_0 gets down.
2023/08/15 11:23:31 [ffmpeg.filter:4] Initializing graph
^C2023/08/15 11:25:49 [main:3] Shutdown started!
2023/08/15 11:25:49 [main:3] Waiting for main threads to terminate...
2023/08/15 11:25:49 [threads:4] Waiting for thread clock_main to shutdown
2023/08/15 11:25:49 [source:4] Source /home/liquidsoap/audio/live_high.m3u8 gets down.
[libfdk_aac @ 0x7fdd28c6e0c0] Note, the VBR setting is unsupported and only works with some parameter combinations
2023/08/15 11:25:49 [/home/liquidsoap/audio/live_high.m3u8:4] Saving state to "/home/liquidsoap/audio/state.config"..
2023/08/15 11:25:49 [/home/liquidsoap/audio/live_high.m3u8:4] Reading state file at "/home/liquidsoap/audio/state.config"..
2023/08/15 11:25:49 [source:4] Source switch_1 gets down.
2023/08/15 11:25:49 [source:4] Source ffmpeg.raw.decode.audio.producer_0 gets down.
2023/08/15 11:25:49 [source:4] Source /home/liquidsoap/audio/live.m3u8 gets down.
[libfdk_aac @ 0x7fdd2874c480] Note, the VBR setting is unsupported and only works with some parameter combinations
2023/08/15 11:25:49 [/home/liquidsoap/audio/live.m3u8:4] Saving state to "/home/liquidsoap/audio/state_low.config"..
2023/08/15 11:25:49 [/home/liquidsoap/audio/live.m3u8:4] Reading state file at "/home/liquidsoap/audio/state_low.config"..
2023/08/15 11:25:49 [source:4] Source switch_2 gets down.
2023/08/15 11:25:49 [source:4] Source single_0 gets down.
2023/08/15 11:25:49 [single_0:4] Finished with "/home/john/src/radio/fault.mka".
2023/08/15 11:25:49 [source:4] Source ffmpeg.raw.decode.audio.producer_1 gets down.
2023/08/15 11:25:49 [clock.main:3] Streaming loop stopped.
2023/08/15 11:25:49 [threads:4] Thread "clock_main" terminated (0 remaining).
2023/08/15 11:25:49 [main:3] Main threads terminated.
2023/08/15 11:25:49 [threads:3] Shutting down scheduler...
2023/08/15 11:25:49 [threads:4] Thread "generic queue #1" terminated (3 remaining).
2023/08/15 11:25:49 [threads:4] Thread "non-blocking queue #2" terminated (2 remaining).
2023/08/15 11:25:49 [threads:4] Thread "generic queue #2" terminated (1 remaining).
2023/08/15 11:25:49 [threads:4] Thread "non-blocking queue #1" terminated (0 remaining).
2023/08/15 11:25:49 [threads:3] Scheduler shut down.
2023/08/15 11:25:49 [server:4] Closing socket.
2023/08/15 11:25:49 [main:3] Cleaning downloaded files...
2023/08/15 11:25:49 [main:3] Freeing memory...
2023/08/15 11:25:50 >>> LOG END

Warblefly avatar Aug 15 '23 10:08 Warblefly

Thanks! Everything makes sense now! The real problem is that your script should have failed! Adding a buffer is exactly the solution!

I've pushed a PR here: https://github.com/savonet/liquidsoap/pull/3317 it improves exceptions raised with clock issues and makes sure they are raised with your script: Screenshot 2023-08-15 at 8 46 52 AM

The error location is correct but not quite helpful because it is raised in a function from our standard library. I'll work on adding a better stack traces to errors soon.

toots avatar Aug 15 '23 13:08 toots

Hi, that's really interesting. Given time, I'd like to understand why a buffer is needed or why the FFmpeg filter creates a need for a new clock. Admittedly, it introduces a delay into the stream that isn't identical at all to the other FFmpeg filter.

Ok, will give it a go... though the last time I tried trunk, and put a buffer in, there was also that strange problem of songs finishing early (cutting off) after liquidsoap had been running a few hours, then the next song starting after a silence. 2.1.4 doesn't do this.

Let's have a go, anyway.

with best wishes, John

Warblefly avatar Aug 15 '23 17:08 Warblefly

The reason behind this is because a filter might get a bunch of data from its input. For each output frame, say 0.04s of audio data, when the output needs to generate that amount of data, it might need to ask its input a bunch more, for instance if the filters needs an internal buffer to compute FFT transforms and etc.

The clock system, here, is used to prevent two filers from using the same source as input. Otherwise, one filter might ask this source for a bunch of data and, when the other filters asks for data, the source has already produced a bunch earlier that is now lost for the second filter.

This is exactly what is causing your bug.

With a buffer, we get a chance to keep some data around so that the second buffer can still get the data it needs too.

I am not too happy with the current implementation. You know how things some times start a certain way and end up another. Part of the goals for the 2.3.x development cycle is to revisit both how sources generate and pass content and how clocks operate so we can make this make more sense for everyone.

toots avatar Aug 15 '23 18:08 toots

This is very helpfully clear. Thank you!

Warblefly avatar Aug 15 '23 18:08 Warblefly

@toots Yep, thanks for the explanation too. Great that you plan to tackle all that clock & buffering stuff again—thinking of how much LS can do, this must be even more of a nightmare to you developers than for us!

Hope you can come up with something that’s logical, robust and easy to handle.

Moonbase59 avatar Aug 20 '23 10:08 Moonbase59

Thanks. This is actually trickier than I thought so I plan on addressing this in the next big dev push on clocks and streaming API. But first, let's finish the pretty printing!

toots avatar Aug 26 '23 16:08 toots