Memory leak, just sharing some preliminary info

[vitoyucepi]

This is the 21 hours of running 2.0.4, and it seems that memory leaks. I will monitor some more before finally will create a new issue. I assume that it exists before 2.0.4 release.
Graph legend:

• x-axis - elapsed_time, seconds since start.
• blue - resident_memory[i]/total_memory, total_memory is 2GB;
• orange - cpu_time[i]/elapsed_time[i] for cumulative;
• green - savgol_filter((cpu_time[i] - cpu_time[i-1]) / (elapsed_time[i] - elapsed_time[i-1]), 50, 3);
• red - uniform_filter1d((cpu_time[i] - cpu_time[i-1]) / (elapsed_time[i] - elapsed_time[i-1]), size = 100).

[toots]

Thanks for the update. Last we checked, more of the memory usage troubles are linked with the OCaml memory manager. Not necessarily memory leaks in the C sense, i.e. lost allocated memory pointers, but, rather, the memory manager keeping too much memory alive, for good or bad reasons.

[vitoyucepi]

I rewrote my monitoring tool to get data directly from /proc/[pid]/stat and polished the graph.
Though I monitor RSS-memory, and they say it's not accurate.
Also my the new method of calculating the cpu consumption is way more precise, because I use time in ticks internally.

Same process, more time passed, but older data is not available now.

[toots]

process_physical_memory is extracted from VmRSS in /proc/<pid>/status. Value is expressed in kb. Could you paste the content of this file?

[toots]

The CPU stuff looks dope BTW. Would love to consider an extension of mem_usage to report this data in a platform-independent way.

[vitoyucepi]

Here's my /proc/[pid]/status from localhost.
And response from api

{
	"date":1651252913,
	"memory":{
		"total_virtual_memory":33585664000,
		"total_used_virtual_memory":22274265088,
		"total_used_physical_memory":22274265088,
		"total_physical_memory":33585664000,
		"process_virtual_memory":1037291520,
		"process_physical_memory":32578,
		"process_managed_memory":131993600
	},
	"errors":[],
	"success":true
}

platform-independent way

I have no idea how to write it for osx and windows.
But in linux I use procps-ng for reference.

[vitoyucepi]

Of course it's showing wrong data, check savonet/ocaml-mem_usage#2.

[vitoyucepi]

I added gc.stat() to my export and now I'm saving all data. Here's my favorite graphs.
Relative is calculated with this function

def percent_filter(items, size = 120):
    average = mean(items[:size])
    return [item / average * 100 for item in items]

Relative average means

percent_filter(uniform_filter1d(value, size = 100))

I'm not sure how to properly measure GC parameters.
@toots, do you see something suspicious in these graphs?
I can also post full log with all of the server metrics (cpu + memory + gc).

[vitoyucepi]

Ok, here's some more graphs. I think 2 more days will be enough to see final trends.

Hypotheses

1. Output encoding is to blame.
   I will replace real encoding with output.dummy.
2. Playlists are to blame.
   I will play a single.

[toots]

Thanks for investigating that. Could you post the script that you are using?

[vitoyucepi]

@toots it's not clear which script is needed, so I'll try to document all of them.

General liquidsoap script is the same as in #2149

I think it's necessary to mention that music_1...music_28 are different genres of music.
Each of the directories contains a lot of subdirectories with assorted types of files i.e. text, image and sound.

def load_playlist(path)
  playlist(mode = "randomize", reload_mode = "watch", path)
end
def create_default_outputs(
  ~mount_prefix,
  ~description_prefix,
  ~source,
  ~icecast_host,
  ~icecast_port,
  ~icecast_user,
  ~icecast_password,
  ~mp3Output_format,
  ~vorbis_output_format,
  ~opus_output_format
)
  icecast_name = "Sample 2.0"
  default_output = output.icecast(
    host = icecast_host,
    port = icecast_port,
    user = icecast_user,
    password = icecast_password,
    name = icecast_name
  )
  default_output(
    mount = "#{mount_prefix}.mp3",
    description = "#{description_prefix} - VBR MP3",
    mp3Output_format,
    source
  )
  default_output(
    mount = "#{mount_prefix}.ogg",
    description = "#{description_prefix} - OGG Vorbis",
    vorbis_output_format,
    source
  )
  default_output(
    mount = "#{mount_prefix}.opus",
    description = "#{description_prefix} - OPUS",
    opus_output_format,
    source
  )
end

MP3_OUTPUT_FORMAT = %mp3.vbr

VORBIS_OUTPUT_FORMAT = %vorbis

OPUS_OUTPUT_FORMAT = %opus(
  application = "audio",
  complexity = 10,
  max_bandwidth = "full_band",
  samplerate = 48000,
  frame_size = 20.,
  channels = 2,
  phase_inversion = false,
  signal = "music",
  vbr = "unconstrained",
  bitrate = 500
)

DEFAULT_ICECAST_HOST = getenv(default = "icecast", "LIQUIDSOAP_DEFAULT_ICECAST_HOST")
DEFAULT_ICECAST_PORT = int_of_string(getenv(default = "8000", "LIQUIDSOAP_DEFAULT_ICECAST_PORT"))
DEFAULT_ICECAST_USER = getenv(default = "source", "LIQUIDSOAP_DEFAULT_ICECAST_USER")
DEFAULT_ICECAST_PASSWORD = getenv("LIQUIDSOAP_DEFAULT_ICECAST_PASSWORD")

ADD_INPUT_HARBOR_PORT = int_of_string(getenv(default = "8000", "LIQUIDSOAP_ADD_INPUT_HARBOR_PORT"))
ADD_INPUT_HARBOR_USER = getenv(default = "source", "LIQUIDSOAP_ADD_INPUT_HARBOR_USER")
ADD_INPUT_HARBOR_PASSWORD = getenv("LIQUIDSOAP_ADD_INPUT_HARBOR_PASSWORD")
ADD_INPUT_HARBOR_MOUNT = getenv(default = "mic", "LIQUIDSOAP_ADD_INPUT_HARBOR_MOUNT")

OVERRIDE_INPUT_HARBOR_PORT = int_of_string(getenv(default = "8000", "LIQUIDSOAP_OVERRIDE_INPUT_HARBOR_PORT"))
OVERRIDE_INPUT_HARBOR_USER = getenv(default = "source", "LIQUIDSOAP_OVERRIDE_INPUT_HARBOR_USER")
OVERRIDE_INPUT_HARBOR_PASSWORD = getenv("LIQUIDSOAP_OVERRIDE_INPUT_HARBOR_PASSWORD")
OVERRIDE_INPUT_HARBOR_MOUNT = getenv(default = "live", "LIQUIDSOAP_OVERRIDE_INPUT_HARBOR_MOUNT")

settings.log.stdout.set(true)
security = single("/var/liquidsoap/sample.ogg")

jingles = load_playlist("/media/jingles")

music_1 = load_playlist("/media/music/1")
music_2 = load_playlist("/media/music/2")
music_3 = load_playlist("/media/music/3")
music_4 = load_playlist("/media/music/4")
music_5 = load_playlist("/media/music/5")
music_6 = load_playlist("/media/music/6")
music_7 = load_playlist("/media/music/7")
music_8 = load_playlist("/media/music/8")
music_9 = load_playlist("/media/music/9")
music_10 = load_playlist("/media/music/10")
music_11 = load_playlist("/media/music/11")
music_12 = load_playlist("/media/music/12")
music_13 = load_playlist("/media/music/13")
music_14 = load_playlist("/media/music/14")
music_15 = load_playlist("/media/music/15")
music_16 = load_playlist("/media/music/16")
music_17 = load_playlist("/media/music/17")
music_18 = load_playlist("/media/music/18")
music_19 = load_playlist("/media/music/19")
music_20 = load_playlist("/media/music/20")
music_21 = load_playlist("/media/music/21")
music_22 = load_playlist("/media/music/22")
music_23 = load_playlist("/media/music/23")
music_24 = load_playlist("/media/music/24")
music_25 = load_playlist("/media/music/25")
music_26 = load_playlist("/media/music/26")
music_27 = load_playlist("/media/music/27")
music_28 = load_playlist("/media/music/28")

monday = random(weights = [10, 10, 10, 10], [music_1, music_2, music_3, music_4])
tuesday = random(weights = [10, 10, 10, 10], [music_5, music_6, music_7, music_8])
wednesday = random(weights = [10, 10, 10, 10], [music_9, music_10, music_11, music_12])
thursday = random(weights = [10, 10, 10, 10], [music_13, music_14, music_15, music_16])
friday = random(weights = [10, 10, 10, 10], [music_17, music_18, music_19, music_20])
saturday = random(weights = [10, 10, 10, 10], [music_21, music_22, music_23, music_24])
sunday = random(weights = [10, 10, 10, 10], [music_25, music_26, music_27, music_28])

schedule = switch([
  ({1w}, monday)
  ({2w}, tuesday)
  ({3w}, wednesday)
  ({4w}, thursday)
  ({5w}, friday)
  ({6w}, saturday)
  ({7w}, sunday)
])

rotation = rotate(weights = [3, 1], [schedule, jingles])

radio = switch(track_sensitive = false, [(schedule.is_ready, rotation), ({true}, security)])

radio = normalize(target = 0.0, window = 0.03, gain_min = -16.0, gain_max = 0.0, radio)
radio = compress.exponential(id = "radio", mu = 1.0, radio)

add_input = input.harbor(
  port = ADD_INPUT_HARBOR_PORT,
  user = ADD_INPUT_HARBOR_USER,
  password = ADD_INPUT_HARBOR_PASSWORD,
  buffer = 1.0,
  ADD_INPUT_HARBOR_MOUNT
)

main_stream = smooth_add(p = 0.15, normal = radio, special = add_input)

override_input = input.harbor(
  port = OVERRIDE_INPUT_HARBOR_PORT,
  user = OVERRIDE_INPUT_HARBOR_USER,
  password = OVERRIDE_INPUT_HARBOR_PASSWORD,
  buffer = 1.0,
  OVERRIDE_INPUT_HARBOR_MOUNT
)

live_stream = fallback(track_sensitive=false, [override_input, main_stream])

default_outputs_generic = create_default_outputs(
  icecast_host = DEFAULT_ICECAST_HOST,
  icecast_port = DEFAULT_ICECAST_PORT,
  icecast_user = DEFAULT_ICECAST_USER,
  icecast_password = DEFAULT_ICECAST_PASSWORD,
  mp3Output_format = MP3_OUTPUT_FORMAT,
  vorbis_output_format = VORBIS_OUTPUT_FORMAT,
  opus_output_format = OPUS_OUTPUT_FORMAT
)

default_outputs_generic(source = main_stream, mount_prefix = "music2.0", description_prefix = "Main Stream Mount")
default_outputs_generic(source = live_stream, mount_prefix = "stream2.0", description_prefix = "Live Stream Mount")

Api

api/index.liq

API_HTTP_HARBOR_PORT = int_of_string(getenv(default = "8001", "LIQUIDSOAP_API_HTTP_HARBOR_PORT"))

let api = ()
let api.http_path_prefix = "^/api/v1"
let api.http_port = API_HTTP_HARBOR_PORT

%include "utils.liq"
%include "server/index.liq"

api/utils.liq

let http.content_type = ()
let http.content_type.json = "application/json; charset=UTF-8"

let http.code = {
  OK = 200,
  Internal_server_error = 500
}

def http.response.json(~code = http.code.OK, data_json)
  try
    http.response(
      code = code,
      content_type = http.content_type.json,
      data = json.stringify(compact = true, data_json) ^ "\n"
    )
  catch _error do
    log.severe(label = "http", null.get(error.message(_error)))
    http.response(code = http.code.Internal_server_error)
  end
end

def error.to_json(~message = null(), _error)
  {
    kind = error.kind(_error),
    message = message ?? error.message(_error)
  }
end

api/server/index.liq

let api.server = ()

%include "memory.liq"
%include "cpu.liq"
%include "gc.liq"

def api.server.register_commands()
  http_path_prefix = "#{api.http_path_prefix}/server"

  harbor.http.register(
    port = api.http_port,
    method = "GET",
    "#{http_path_prefix}/memory",
    api.server.memory.http
  )

  harbor.http.register(
    port = api.http_port,
    method = "GET",
    "#{http_path_prefix}/cpu",
    api.server.cpu.http
  )

  harbor.http.register(
    port = api.http_port,
    method = "GET",
    "#{http_path_prefix}/gc",
    api.server.gc.http
  )
end

api/server/cpu.liq

let api.server.cpu = ()

PROC_PID_STAT_PARAMETERS_COUNT = 52
PROC_UPTIME_PARAMETERS_COUNT = 2

def api.server._cpu()
  error_list = ref([])

  system_uptime =
    try
      system_uptime = string.split(separator = " ", string.trim(file.contents("/proc/uptime")))
      if list.length(system_uptime) != PROC_UPTIME_PARAMETERS_COUNT then
        error.raise(error.invalid, "Unexpected format of '/proc/uptime' file")
      end
      system_uptime
    catch _error do
      error_list := list.add(error.to_json(_error), !error_list)
      []
    end

  process_stat =
    try
      process_stat = string.split(separator = " ", string.trim(file.contents("/proc/self/stat")))
      if list.length(process_stat) != PROC_PID_STAT_PARAMETERS_COUNT then
        error.raise(error.invalid, "Unexpected format of '/proc/self/stat' file")
      end
      process_stat
    catch _error do
      error_list := list.add(error.to_json(_error), !error_list)
      []
    end

  clock_ticks_per_second =
    try
      clock_ticks_per_second = float_of_string(string.trim(process.read("getconf CLK_TCK")))
      if clock_ticks_per_second == 0. then
        error.raise(error.invalid, "CLK_TCK value is not set")
      end
      clock_ticks_per_second
    catch _error do
      error_list := list.add(error.to_json(_error), !error_list)
      0.
    end

  status =
    if list.length(!error_list) == 0 then
      true
    else
      false
    end

  cpu =
    if status then
      up_time = float_of_string(list.nth(system_uptime, 0))
      start_time = float_of_string(list.nth(process_stat, 21))
      elapsed_time = up_time - start_time / clock_ticks_per_second
      user_time = float_of_string(list.nth(process_stat, 13)) / clock_ticks_per_second

      {user_time = user_time, elapsed_time = elapsed_time}
    else
      null()
    end

  {
    success = status,
    errors = !error_list,
    cpu = cpu,
    date = int(time())
  }
end

def api.server.cpu.http(~protocol = _, ~headers = _, ~data = _, _)
  http.response.json(api.server._cpu())
end

api/server/gc.liq

let api.server.gc = ()

def api.server._gc()
  error_list = ref([])

  let (status, gc) =
    try
      (true, null(runtime.gc.stat()))
    catch _error do
      error_list := list.add(error.to_json(_error), !error_list)
      (false, null())
    end

  {
    success = status,
    errors = !error_list,
    gc = gc,
    date = int(time())
  }
end

def api.server.gc.http(~protocol = _, ~headers = _, ~data = _, _)
  http.response.json(api.server._gc())
end

api/server/memory.liq

let api.server.memory = ()

def api.server._memory()
  error_list = ref([])

  let (status, memory) =
    try
      memory = runtime.memory()
      (true, null({
        process_managed_memory = memory.process_managed_memory,
        process_physical_memory = memory.process_physical_memory,
        process_virtual_memory = memory.process_virtual_memory,
        total_physical_memory = memory.total_physical_memory,
        total_used_physical_memory = memory.total_used_physical_memory,
        total_used_virtual_memory = memory.total_used_virtual_memory,
        total_virtual_memory = memory.total_virtual_memory
      }))
    catch _error do
      error_list := list.add(error.to_json(_error), !error_list)
      (false, null())
    end

  {
    success = status,
    errors = !error_list,
    memory = memory,
    date = int(time())
  }
end

def api.server.memory.http(~protocol = _, ~headers = _, ~data = _, _)
  http.response.json(api.server._memory())
end

Graphs

And finally api collector and plotter scripts https://gitlab.com/-/snippets/2304931

The collector is for python3.7+.
To run it use command collector.py <http_path> <log_file>, for me it will look like collector.py http://localhost:8011 liquidsoap-memory.log

The plotter I think will work with python3.8+ with scipy and matplotlib.
Command plotter.py <log_file>

[vitoyucepi]

I waited some more time and now it looks even more obvious that something is wrong.

[toots]

Thanks for these reports. I'm gonna have another pass at it. Before I do, tho, just wanted to confirm: What version of ocaml-ffmpeg are you using? 1.1.3 or later?

[vitoyucepi]

I use official release deb package for ubuntu:20.04. At the moment it has ffmpeg=1.1.4.

[toots]

Ok thanks. My inclination at this point is that there's something in the language runtime that is generating this memory usage. @smimram has some plans to optimize the runtime so hopefully that helps.

[toots]

Hi! We just tracked another issue with memory consumption that appeared to be related to how OCaml cleans up threads memory: #2424. It could be worth trying with the fix for this issue? It should be in the rolling release branches v2.0.x and v2.1.x as well as in main.

[vitoyucepi]

OK. I will end my current test with output.dummy in about a day or two and share the results.
Then I will test with 2.0.x with initial setup to see the differences. It will take two or three days to see the trends.

[vitoyucepi]

Hypothesis 1

Replace encoding with output.dummy

[toots]

@vitoyucepi I've rebuilt most of the binary builds for the rolling releases using OCaml 4.14, would you be able to test again with it? It seems like some of GC issues are fixed there: https://github.com/savonet/liquidsoap/releases/tag/rolling-release-v2.0.x

All the amd64 builds should use 4.14 there now.

[toots]

Actually, would you mind checking with the builds from this run: https://github.com/savonet/liquidsoap/actions/runs/2463570986
These are without the GC workaround so we could make sure that it's not needed anymore as well.

[vitoyucepi]

The results with a0d67fa

[toots]

I've been running the test script on a ubuntu focal with the build here: https://github.com/savonet/liquidsoap/actions/runs/2484217096 (4.14.0 build without the process.run workaround) and it's looking good so far:

[toots]

Thanks! Is the ffmpeg decoder the only one being used for those?

[vitoyucepi]

I think so because I didn't change any decoder priorities.
Also I haven't checked if any other decoders are being used.

[toots]

You could disable all others to make sure.

[vitoyucepi]

OK.
The plan

• use 019a4f5;
• settings.decoder.image_file_decoders.set(["FFMPEG"]);
• settings.decoder.decoders.set(["FFMPEG"]).

Are these decoder settings enough?

[toots]

Should be. Also make sure that you use ocaml 4.14. Should be the default with all builds from the past days on amd64.

[toots]

Looks like no memory leak here after ~2.5 days:

[toots]

I got tired of the jingles, renamed the repository so the playlist resolution would fail and it started leaking. I'm not sure if that's the cause of your leak but this one was traced down to a missing request.destroy: 29a0b1e. Just pushed builds for both v2.0.x and v2.1.x rolling releases fixing it.

[toots]

I've been running an instance with the request.destroy fix and was seeing a slow increase of memory usage:

Since this was still within the bound of reasonable GC wiggle room (5Mo is less than 2% of 285 Mo) I added a manual full_major POST call and restarted the script. If grows again and full_major drops memory usage I'd consider this done on my end I believe.

def api.server.full_major(~protocol = _, ~headers = _, ~data = _, _)
  runtime.gc.full_major()
  http.response.json({status = "ok"})
end
...
  harbor.http.register(
    port = api.http_port,
    method = "POST",
    "#{http_path_prefix}/full_major",
    api.server.full_major
  )

BTW the script is super clean it's pretty impressive!

[vitoyucepi]

This is the results of e73b2b8.
But I don't call full_major() explicitly.

[vitoyucepi]

e73b2b8

[TheRealMattLear]

Hi,

I'm seeing multiple customers having memory leaks with version 2.0.4, 2.0.5 and 2.0.6. The issue i'm describing does not occur with 2.0.3.

I see most processes running with 150MB RSS memory. Within approximately 1 hour we see some creep up over 2 GB memory; even up to 5 GB in some instances. Its causing the system OOM to kill database servers and other processes trying to conserve memory. I have tested with Liquidsoap 2.0.3, 2.0.4, 2.0.5 and 2.0.6 with OCAML 4.14.0.

Interestingly of the ~15 liquidsoap processes running on this server i'm actively watching the memory usage growing on some where others don't budge. I've enabled logging and I can see the below request constantly every few seconds which might be relevant. It's generating a 500 error from liquidsoaps harbor endpoint, which i assume is coming from the clients encoder in shoutcast mode with something like sam broadcaster that checks listener stats (passwords and ips removed). In version 2.0.3, the same 500 error is returned but the memory isn't increasing.

Liquidsoap 500 Error

2022/06/23 00:04:33 [harbor:4] New client on port 6958: ******
2022/06/23 00:04:33 [harbor:4] Method: GET, uri: /admin.cgi?pass=******&mode=viewxml&page=1&sid=1, protocol: HTTP/1.1
2022/06/23 00:04:33 [harbor:4] Header: Host, value: ******.com:6958.
2022/06/23 00:04:33 [harbor:4] Header: Accept, value: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8.
2022/06/23 00:04:33 [harbor:4] Header: User-Agent, value: Mozilla/3.0 (compatible; Indy Library).
2022/06/23 00:04:33 [harbor:4] HTTP GET request on /admin.cgi.
2022/06/23 00:04:33 [harbor:4] HTTP Arg: page, value: 1.
2022/06/23 00:04:33 [harbor:4] HTTP Arg: mode, value: viewxml.
2022/06/23 00:04:33 [harbor:4] HTTP Arg: pass, value: ******.
2022/06/23 00:04:33 [harbor:4] HTTP Arg: sid, value: 1.
2022/06/23 00:04:33 [harbor:4] Returned 500 for '/admin.cgi?pass=******&mode=viewxml&page=1&sid=1'.

This particular system is CentOS 7.9 with samplerate pinned to 0.5.0 (newer versions wont compile with CentOS 7.9)

opam list

# Packages matching: installed
# Name                # Installed # Synopsis
base-bigarray         base
base-bytes            base        Bytes library distributed with the OCaml compiler
base-threads          base
base-unix             base
camomile              1.0.2       A Unicode library
conf-autoconf         0.1         Virtual package relying on autoconf installation
conf-automake         1           Virtual package relying on GNU automake
conf-lame             1           Virtual package relying on lame
conf-libflac          1           Virtual package relying on libFLAC
conf-libogg           1           Virtual package relying on libogg
conf-libpcre          1           Virtual package relying on a libpcre system installation
conf-libsamplerate    1           Virtual package relying on libsamplerate
conf-libtheora        1           Virtual package relying on libtheora
conf-libvorbis        1           Virtual package relying on libvorbis
conf-mad              1           Virtual package relying on mad
conf-pkg-config       2           Check if pkg-config is installed and create an opam switch local pkgconfig folder
conf-taglib           1           Virtual package relying on taglib
conf-which            1           Virtual package relying on which
cry                   0.6.7       OCaml client for the various icecast & shoutcast source protocols
csexp                 1.5.1       Parsing and printing of S-expressions in Canonical form
dtools                0.4.4       Library providing various helper functions to make daemons
dune                  3.3.1       Fast, portable, and opinionated build system
dune-configurator     3.3.1       Helper library for gathering system configuration
duppy                 0.9.2       Library providing monadic threads
faad                  0.5.0       Bindings for the faad library which provides functions for decoding AAC audio files
fdkaac                0.3.2       Fraunhofer FDK AAC Codec Library
flac                  0.3.0       Bindings to libflac
gen                   1.0         Iterators for OCaml, both restartable and consumable
lame                  0.3.6       MP3 encoding library
liquidsoap            2.0.6       pinned to version 2.0.6 at git+file:///usr/local/mediacp/liquidsoap/source#HEAD
mad                   0.5.2       Mad decoding library
menhir                20211128    An LR(1) parser generator
menhirLib             20211128    Runtime support library for parsers generated by Menhir
menhirSdk             20211128    Compile-time library for auxiliary tools related to Menhir
mm                    0.8.1       The mm library contains high-level to create and manipulate multimedia streams (audio, video, MIDI)
ocaml                 4.14.0      The OCaml compiler (virtual package)
ocaml-base-compiler   4.14.0      Official release 4.14.0
ocaml-compiler-libs   v0.12.4     OCaml compiler libraries repackaged
ocaml-config          2           OCaml Switch Configuration
ocaml-options-vanilla 1           Ensure that OCaml is compiled with no special options enabled
ocamlbuild            0.14.1      OCamlbuild is a build system with builtin rules to easily build most OCaml projects
ocamlfind             1.9.5       A library manager for OCaml
ogg                   0.7.1       Bindings to libogg
pcre                  7.5.0       Bindings to the Perl Compatibility Regular Expressions library
ppx_derivers          1.2.1       Shared [@@deriving] plugin registry
ppxlib                0.27.0      Standard library for ppx rewriters
samplerate            0.1.5       pinned to version 0.1.5
sedlex                3.0         An OCaml lexer generator for Unicode
seq                   base        Compatibility package for OCaml's standard iterator type starting from 4.07.
sexplib0              v0.15.1     Library containing the definition of S-expressions and some base converters
stdlib-shims          0.3.0       Backport some of the new stdlib features to older compiler
taglib                0.3.9       Bindings for the taglib library
theora                0.4.0       Bindings to libtheora
uchar                 0.0.2       Compatibility library for OCaml's Uchar module
vorbis                0.8.0       Bindings to libvorbis

liquidsoap script

settings.init.daemon.set(true);
settings.init.daemon.pidfile.set(true);
settings.init.daemon.pidfile.path.set("/usr/local/mediacp/content/user_230/icecast_kh/8406_350/liquidsoap.pid");
settings.server.socket.set(true);
settings.server.socket.path.set("/usr/local/mediacp/content/user_230/icecast_kh/8406_350//liquidsoap.sock")
settings.log.file.set(false);
settings.log.file.path.set("/usr/local/mediacp/content/user_230/icecast_kh/8406_350/logs/liquidsoap.log");
settings.log.stdout.set(false);
settings.log.level.set(4);
settings.tag.encodings.set(["UTF-8","ISO-8859-1"]);
#settings.encoder.metadata.export.set(["artist","title","album","song"])

settings.scheduler.non_blocking_queues.set(4)
settings.scheduler.generic_queues.set(4)
settings.scheduler.fast_queues.set(4)

settings.request.metadata_decoders.set(["TAGLIB", "FLAC", "OGG"])
settings.request.leak_warning.set(100)
#settings.request.grace_time.set(600.)

settings.harbor.bind_addrs.set(["0.0.0.0"]);
settings.harbor.timeout.set(300.)
settings.harbor.verbose.set(true)
queueDebugging = false
recordLiveBroadcasts = false


service_id = 350
harbor_buffer = 11
harbor_clear_queue = 60 # Don't return to original track on harbor disconnection if this has passed in seconds


dj = ref("");
dj_username = ref("");
previousMeta = ref([]);
startRecording = ref (fun () -> ())

def r(type) =
    requestUrl = "https://127.0.0.1:2021/controller/AudioPlayout/350/#{type}";
    log("#### [Request: #{type}] Requesting next track from #{requestUrl}");
    ret = process.read("curl -k " ^ requestUrl);
    log("#### [Request: #{type}] Got Answer: " ^ ret);
    if ret == "" or string.match(pattern="Error", ret) or string.match(pattern="Exception", ret)  or string.match(pattern="no-track", ret) then
        []
    else
        r = request.create(ret)
        if request.resolve(r) then
            [r]
        else
            []
        end
    end
end
def fetchAndRetry(s) =
    thread.run.recurrent(fast=false, delay=0., fun() -> begin
        log("Running s.fetch()");
        if s.fetch() then
            -1.
        else
            2. # Check every 2 seconds until ready
        end
    end);
end

def q(remaining,s) =
    log("Queueing #{s.id()} with #{remaining} seconds remaining");
    s.fetch();
    ()
end

def harborOnConnect(headers) =
    log("### Harbor connected");

        if recordLiveBroadcasts then
                log("#### Broadcast recording starting");
                srf = !startRecording
                srf()
                ()
        end
end
def harborOnDisconnect() =
    log("### Harbor disconnected");
    dj_username := "";
    dj := ""
end

def harborAuth(auth) =

        log("#### Harbor DJ Auth is: " ^ auth.user ^ ":" ^ auth.password);
        log("#### /usr/local/mediacp/php/bin/php /usr/local/mediacp/htdocs/system/misc/scripts/radio_auth.php --server-type=icecast_kh --server-id=350 --username=#{auth.user} --password=#{auth.password}");
        ret = process.read.lines("/usr/local/mediacp/php/bin/php /usr/local/mediacp/htdocs/system/misc/scripts/radio_auth.php --server-type=icecast_kh --server-id=350 --username=#{auth.user} --password=#{auth.password}")

        if list.hd(default="",ret) == "authenticated" then

        dj_username := auth.user
                dj := list.nth(
                        default=
                                                if auth.user == "source" then
                                        list.hd(default="",string.split(separator=":",auth.password))
                                else
                                        auth.user
                                end

                                        ,ret,1)
                log("#### Harbor authentication success");
                log("#### Harbor connected as " ^ !dj);
                true
        else
                log("#### Harbor authentication failed");
                false
        end
end

def metadata_updated(m) =
    if list.length(m) == 0 then
        log("[on_metadata_update] empty metadata")
    elsif string_of(!previousMeta) == string_of(m) then
        log("[on_metadata_update] no change since last track, skipping feedback")
    elsif m["title"] == "" then
        log("[on_metadata_update] title is empty, skipping feedback")
    else
        previousMeta := m # Update previousMeta

        thread.run(fast=false, delay=0., fun() -> begin
            log("######    Metadata Feedback Update");
            if (m["track_id"] != "") then
                log("track_id:" ^ m["track_id"]);
                log("Title: " ^ m["title"])
                log("Artist: " ^ m["artist"])
                log("Album: " ^ m["album"])
                log(string.quote(m["title"]));

                url = '/usr/local/mediacp/php/bin/php /usr/local/mediacp/htdocs/system/misc/scripts/feedback.php' ^
                        " server_id=350" ^
                        ' track_id=' ^ string.quote(m["track_id"]) ^
                        ' playlistable_id=' ^ string.quote(m["playlistable_id"]) ^
                        ' playlistable_type=' ^ string.quote(m["playlistable_type"]) ^
                        ' playlist_position=' ^ string.quote(m["playlist_position"]) ^
                        #' dj_id=' ^ string.quote(m["track_id"]) ^
                        ' title=' ^ string.quote(m["title"]) ^
                        ' artist=' ^ string.quote(m["artist"]);
                log(url);
                ret = list.hd(process.read.lines(url),default="")
                log("MediaCP Feedback Response: #{ret}")
            else
                log("Filename: " ^ m["filename"])
                log("Title: " ^ m["title"])
                log("Artist: " ^ m["artist"])
                log("Album: " ^ m["album"])
                log("Dj: " ^ !dj)

                url = '/usr/local/mediacp/php/bin/php /usr/local/mediacp/htdocs/system/misc/scripts/feedback.php' ^
                        " server_id=350" ^
                        ' dj=' ^ string.quote(!dj) ^
                        ' text=' ^ string.quote(m["title"]);
                log(url);
                ret = list.hd(process.read.lines(url),default="")
                log("MediaCP Feedback Response: #{ret}")
            end
            ()
        end)
    end
   ()
end

def processReplayGain(s) =
    if false then
                log("Triggering enable_replaygain_metadata()");
        enable_replaygain_metadata()
        replaygain(s)
    else
        s
    end
end

# Standard Priority Requests
standardRequest = request.dynamic.list(id="Standard_Request", prefetch=0, { r('standard') })
standardPlayout = source.on_end(
                          id="Standard Playout",
                          delay=5.0,
                          standardRequest,
                          fun(remaining, _) -> begin
                              if list.length(standardRequest.queue()) < 1 then
                                  log("Queueing Standard_Request with #{remaining} seconds remaining");
                                  fetchAndRetry(standardRequest)
                                                ()
                              end
                              ()
                          end
                      );

# High Priority Requests - ping every 20 seconds
priorityRequest = request.dynamic.list(id="Priority Request", prefetch=0, { r('priority') })
priorityPlayout = source.on_end(
                                        id="Priority Playout",
                                        delay=5.0,
                                        priorityRequest,
                                        fun(remaining, _) -> begin
                                                if list.length(priorityRequest.queue()) < 1 then
                                                        log("Queueing Priority_Request with #{remaining} seconds remaining");
                                                        if
                                                                # Attempt fetch
                                                                not priorityRequest.fetch()
                                                                # If no more priority requests, and no queued standard, then fetch fetch fetch
                                                                and list.length(standardRequest.queue()) == 0
                                                                and standardPlayout.remaining() == 0.
                                                                then
                                                                        log("No more priority requests, fetching from standard queue instead");
                                                                        fetchAndRetry(standardRequest)
                                                                        ()
                                                                end
                                                        ()
                                                end
                                                ()
                                        end
                                );

thread.run(fast=false, delay=10., every=20., fun() -> begin
    # Ping for new requests only if the priorityRequest source is not already active, since queueOnEndTrack would run if its active
    if priorityRequest.is_ready() then () else priorityRequest.fetch(); () end
end)

# Add Skip to Playouts
playoutGroup = fallback(id="Playout Group", track_sensitive=false, [priorityPlayout, standardPlayout]);
server.register(
        namespace="#{source.id(playoutGroup)}",
        usage="skip",
        description="Skip the current track.",
        "skip",
        fun(_) ->
        begin
                log("Skip Executed" ^ string_of(priorityRequest.is_ready()));
           # Check if priority playing, attempt next request
           if (priorityRequest.is_ready() and priorityRequest.fetch()) or standardRequest.fetch() then
                thread.run(fast=false, delay=0.75,fun() -> begin source.skip(playoutGroup) end)
           end
                "Done!"
        end
)

# Harbor connection
defaultDj = input.harbor(id="/", port=6958, buffer=float_of_int(harbor_buffer), max=30.0, log_overfull = false, icy=true, password="@Jesucristo1", on_connect=harborOnConnect, on_disconnect=harborOnDisconnect, auth=harborAuth, "");
output.dummy(id="defaultDj", fallible=true, defaultDj);

liveBroadcast = defaultDj;

# Record live broadcasts
stopRecordingFunc = ref (fun () -> ())
def stopRecording() = f = !stopRecordingFunc; f();stopRecordingFunc := { () }; end
startRecording := fun() -> begin
        log("Initialising recording");
        stopRecording()
        currentDj = !dj_username
        outputRecording = output.file(
                                                %mp3(samplerate=44100, stereo=true, bitrate=128, id3v2=true),
                                                fallible=true,
                                                #flush=true,
                                                append=true,
                                                reopen_on_metadata=false,
                                                reopen_on_error=true,
                                                on_stop = fun() -> begin
                                                        log("#### Inform MediaCP of new file recording");
                                                        # Allow plenty of time for file to finish writing
                                                        thread.run(fast=false, delay=5.,fun() -> begin
                                ret = process.read("/usr/local/mediacp/php/bin/php /usr/local/mediacp/htdocs/system/misc/scripts/notify.php server_id=350")
                                log("MediaCP Recording Notify Response: #{ret}")
                                                        end)
                                                end,
                                                "/usr/local/mediacp/content/user_230/music/recordings/%Y/%m/%Y-%m-%d-%H_%M_%S_#{currentDj}.mp3",
                                                liveBroadcast
                                          )
        stopRecordingFunc := { outputRecording.shutdown() }
end

# Play blank if nothing available
radio = fallback(track_sensitive=false,[liveBroadcast, playoutGroup, blank(id="Initial Blank Startup")]) # Play blank, infaillible source if nothing else is available
radio.on_metadata(metadata_updated)

# ReplayGain (if enabled)
radio = processReplayGain(radio)

# Add Crossfading
radio = crossfade(smart=false, duration=3.00,fade_out=3.00,fade_in=2.00,radio)

radio = mksafe(radio)

        output.icecast(

                %fdkaac(
                        channels=2,
                        samplerate=44100,
                        bitrate=128,
                        afterburner=true,
                        aot="mpeg4_aac_lc",
                        transmux="adts",
                        sbr_mode=false
                ),
                mount = "/stream",
                host = "127.0.0.1",
                port = 8406,
                password = "@Jesucristo1",

                encoding = "UTF-8",

                name = "",
                description = "",
                url = "",
                genre = "",
                public = true,

                icy_metadata = "true",

        radio
    );


# Initialise first standard request once we're up and running
fetchAndRetry(standardRequest);

if queueDebugging then
        thread.run(fast=true, delay=5., every=20., fun() -> begin
                log(
                        "Standard[Queued: " ^ string_of(list.length(standardRequest.queue())) ^ " Remaining: " ^string_of(standardPlayout.remaining())^"] " ^
                        "Priority[Queued: " ^ string_of(list.length(priorityRequest.queue())) ^ " Remaining: " ^string_of(priorityPlayout.remaining())^"] " ^
                        "Harbor: " ^ string_of(liveBroadcast.is_ready())
                )
        () end)
end

# If harbor is connected for more than 30 seconds, clear the queue as to not return midway through the original trackd empty queue)
harbor_ping_count = ref(0)
harbor_ping_reached = ref(false)

thread.run(fast=false, delay=1.0, every=10., fun() -> begin
    if not liveBroadcast.is_ready() then
        harbor_ping_count := 0
        harbor_ping_reached := false;
        ()
    else
        if !harbor_ping_count >= harbor_clear_queue and not !harbor_ping_reached then
            log("Clear standard and priority queues so harbor does not return to mid track");
            harbor_ping_reached := true;
            source.skip(standardRequest);
            source.skip(priorityRequest);
            ()
        else
            harbor_ping_count := !harbor_ping_count + 10; # Increment by 2, since thread.run is every 2 seconds
            log("Harbor Ping Count: #{harbor_ping_count}");
            ()
        end
    end

end);

# If priority playlist is connected for more than 60 seconds, clear the standard queue as to not return midway through the original trackd empty queue)
priority_ping_count = ref(0)
priority_ping_reached = ref(false)

thread.run(fast=false, delay=1.0, every=10., fun() -> begin
    if not priorityPlayout.is_ready() then
        priority_ping_count := 0
        priority_ping_reached := false;
        ()
    else
        if !priority_ping_count >= 60 and not !priority_ping_reached then
            log("[priority_ping] Clear standard queue so priority does not return to middle of a standard request track");
            priority_ping_reached := true;
            source.skip(standardRequest);
            ()
        else
            priority_ping_count := !priority_ping_count + 10; # Increment by 2, since thread.run is every 2 seconds
            log("Priority Ping Count: #{priority_ping_count}");
            ()
        end
    end
end);

[toots]

Thanks for the update @TheRealMattLear. This may or may not be related to @vitoyucepi's own issue but does look a lot like the issues reported in #1122

We're actively testing this and fixing and we find issues. 2.0.6 contained some fixes that should avoid request leaks. I can currently reproduce a slow leak under a situation with a lot of stress (multiple playlists not existing) using @vitoyucepi's script:

Let's keep using this conversation to report issues and ways to potentially reproduce them. I'll check on your script very shortly.

[TheRealMattLear]

I'm getting a lot of reports from multiple customers experiencing this leak, our response is to advise reverting to 2.0.3-1. No pressure intended, just identifying that this is an adequate workaround for us. Is there any additional information that i can help with here when i see the problem?

[toots]

Sounds good @TheRealMattLear . I'm glad y'all have a work around. I looked at the code diff and there isn't much indicative of changes that would create this kind of behavior so I'm leaning toward a bug that was already there but appears with some level of randomness.

On my local experiment, it seems that I might have hit the situation. This is with @vitoyucepi's script, 2.0.6 via opam and only the mad decoder. Previously with wav it was dead stable:

I'm letting it run a little more to see how it evolves.

[toots]

Quick update on this issue:

• I have ran the whole testing script on a build of liquidsoap enabled with this leak detection stack: https://github.com/google/sanitizers/wiki/AddressSanitizerLeakSanitizer
• This has revealed one specific leak with ogg/opus headers: savonet/ocaml-opus@1552403
• This also revealed a GC optimization in ocaml-ogg to make it aware of the size of allocated ogg packets: savonet/ocaml-ogg@f9293c8

Running the script again, I now get this memory profile:

I think the next steps for me are:

• Keep running the instrumentalized binary.
• Provide similarly instrumentalized builds for y'all to run.
• Details how to report mem leaks reported by this tool and also by memtrace (OCaml GC allocation tool).

And hope we get more clarity.

The latest rolling release builds should all have the two ogg and opus fixes above now.

[toots]

Ok, we found another issue related to over-allocating around input.http, srt and others after @TheRealMattLear's report. I've recompiled with all latest fixes and now I am getting this:

It looks to me that I cannot reproduce the issue anymore.

[vitoyucepi]

I'm still on 2.0.x and didn't port script for 2.1.x.
Should I expect this changes in rolling-release-v2.0.x?

[toots]

Yes, this is all in the latest 2.0.x.

[vitoyucepi]

Ok, then I'll test the build artifacts from 6ad12f8.

[toots]

It looks like everything is fixed for me here:

It'd be nice if you could send even an early report. Otherwise, I'm contemplating doing a 2.0.7/2.1.0 release some time next week.

[vitoyucepi]

[toots]

Thanks for sharing that. Is it still growing?

[vitoyucepi]

[toots]

Damn. Seems like some improvements but still climbing by steps. Are you still on the same step or did it keep climbing?

[vitoyucepi]

Nope. The process just consumes more memory after that moment.
Check the process_managed_memory at 308 hours. I think ocaml allocated a fresh block of memory.
Am I right that live_blocks is memory that used by liquidsoap in ocaml inner space?

[vitoyucepi]

And the final images for this run.

[toots]

Thanks for sharing that. There's definitely some improvements with the opus leak fix. The plan as I see it is:

• Push 2.0.7/2.1.0 out
• Prepare builds with the memleak tools activated
• Run the experiment out your side with the builds with memleak tools

[vitoyucepi]

2.1.1
This is not okay.

[vitoyucepi]

=================================================================
==1==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 13524 byte(s) in 2 object(s) allocated from:
    #0 0x7f81448d09cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x5574130ccab3 in open_tiff_file_for_read (/usr/bin/liquidsoap+0xd97ab3)
    #2 0x557412dfacd4 in camlTiff__load_355 (/usr/bin/liquidsoap+0xac5cd4)

Direct leak of 8192 byte(s) in 1 object(s) allocated from:
    #0 0x7f81448d09cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x557413264236 in caml_setup_stack_overflow_detection (/usr/bin/liquidsoap+0xf2f236)
    #2 0x5574132643fb in caml_init_signals (/usr/bin/liquidsoap+0xf2f3fb)
    #3 0x55741325eac8 in caml_startup_common (/usr/bin/liquidsoap+0xf29ac8)
    #4 0x55741325ecbe in caml_main (/usr/bin/liquidsoap+0xf29cbe)
    #5 0x5574129bb12b in main (/usr/bin/liquidsoap+0x68612b)
    #6 0x7f814058d209  (/lib/x86_64-linux-gnu/libc.so.6+0x29209)

Direct leak of 40 byte(s) in 1 object(s) allocated from:
    #0 0x7f81448d09cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x5574131e701f in ocaml_ssl_init (/usr/bin/liquidsoap+0xeb201f)
    #2 0x557412f37e0a in camlSsl__init_512 (/usr/bin/liquidsoap+0xc02e0a)

SUMMARY: AddressSanitizer: 21756 byte(s) leaked in 4 allocation(s).

[toots]

Thanks. Were you able to see any memory growing?

We fixed another memory leak in the ffmpeg binding but that was present when using live streams (input.ffmpeg, input.http, etc.) I don't think you would be impacted.

[vitoyucepi]

I don't know if it's native-module related memory leak. At the moment I can't reliable run asan build for longer then 2 days. When memory exceeds 1.5GB, the process will be killed by OOM killer.

Maybe there's a memory leak inside ocaml. I assume that eventual memory consumption over 500MB in this post is not fine.

@toots could you clarify why gc.live_words grows linearly and why gc.heap_words grapth rises periodically?

[vitoyucepi]

=================================================================
==1==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 8192 byte(s) in 1 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x5624d01f5236 in caml_setup_stack_overflow_detection (/usr/bin/liquidsoap+0xf2f236)
    #2 0x5624d01f53fb in caml_init_signals (/usr/bin/liquidsoap+0xf2f3fb)
    #3 0x5624d01efac8 in caml_startup_common (/usr/bin/liquidsoap+0xf29ac8)
    #4 0x5624d01efcbe in caml_main (/usr/bin/liquidsoap+0xf29cbe)
    #5 0x5624cf94c12b in main (/usr/bin/liquidsoap+0x68612b)
    #6 0x7f9dd311d209  (/lib/x86_64-linux-gnu/libc.so.6+0x29209)

Direct leak of 4179 byte(s) in 1 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x5624d005dab3 in open_tiff_file_for_read (/usr/bin/liquidsoap+0xd97ab3)
    #2 0x5624cfd8bcd4 in camlTiff__load_355 (/usr/bin/liquidsoap+0xac5cd4)

Direct leak of 40 byte(s) in 1 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x5624d017801f in ocaml_ssl_init (/usr/bin/liquidsoap+0xeb201f)
    #2 0x5624cfec8e0a in camlSsl__init_512 (/usr/bin/liquidsoap+0xc02e0a)

Indirect leak of 309752 byte(s) in 72 object(s) allocated from:
    #0 0x7f9dd745f8d5 in __interceptor_realloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:85
    #1 0x7f9dd6cb9323 in _TIFFCheckRealloc (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0xb323)

Indirect leak of 15936 byte(s) in 12 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x7f9dd6ce4914 in TIFFInitJPEG (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0x36914)

Indirect leak of 15852 byte(s) in 12 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x7f9dd6cf17c0 in TIFFClientOpen (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0x437c0)

Indirect leak of 6696 byte(s) in 12 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x7f9dd6cbce77 in _TIFFsetByteArray (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0xee77)

Indirect leak of 6016 byte(s) in 24 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x7f9dd6cc373a  (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0x1573a)

Indirect leak of 2304 byte(s) in 12 object(s) allocated from:
    #0 0x7f9dd745f8d5 in __interceptor_realloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:85
    #1 0x7f9dd6cbd3d8  (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0xf3d8)

Indirect leak of 888 byte(s) in 48 object(s) allocated from:
    #0 0x7f9dd74609cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x7f9dd6cbcdff  (/usr/lib/x86_64-linux-gnu/libtiff.so.5+0xedff)

SUMMARY: AddressSanitizer: 369855 byte(s) leaked in 195 allocation(s).

[toots]

Thanks. No, I have no idea.

These report unfortunately do not tell us much. I believe it's time to try to narrow down optional dependencies, maybe.

Are you able to isolate exactly what encoder/decoder you need? Any chance you could run the same tests with only wav files for instance? We could de-activate all C bindings we can and see if the leak is still present.

Might even be able to run longer with the memory leak tooling this way.