search

savonet / liquidsoap

Liquidsoap is a statically typed scripting general-purpose language with dedicated operators and backend for all thing media, streaming, file generation, automation, HTTP backend and more.
http://liquidsoap.info
GNU General Public License v2.0
1.4k stars 130 forks source link

Liquidsoap CPU to 100% and then crashes #628

Closed illestrater closed 5 years ago

illestrater commented 6 years ago

I'm unsure if this is a memory leak or if it's an issue with not properly shutting down dynamic transcoders...

Does source.shutdown() completely destroy the transcoder?

Here's my script:

set("server.telnet", true)

dyn_sources = ref []

def add_source(uri) =
  url = mksafe(input.http("http://illestrater.com:1337/#{uri}"))
  source = output.icecast(
    %mp3(bitrate=128),
    mount="#{uri}-mp3",
    host="illestrater.com",
    port=1337,
    password="*******",
    fallible=true
  )

  output = source(url)

  dyn_sources := 
      list.append( [(uri, output)],
                    !dyn_sources )
  "transcoding #{uri}"
end

def remove_source(uri) =
  def search(x, y) =
    current_uri = fst(y)
    if current_uri == uri then
      test = snd(y)
      source.shutdown(test)
      (["#{uri} closed"])
    else
      ([])
    end
  end
  result = list.fold(search, ([]), !dyn_sources)
  "#{result}"
end

server.register(namespace="sources",
                description="Start a new dynamic playlist.",
                usage="add <uri>",
                "add",
                add_source)
server.register(namespace="sources",
                description="Start a new dynamic playlist.",
                usage="remove <uri>",
                "remove",
                remove_source)

output.dummy(blank())

Any help would be much appreciated!! Thanks :)

toots commented 6 years ago

Your script looks great, there must be a bug in liquidsoap. I'll try to test it locally. Could you share some of the logs as well? Thks!

toots commented 6 years ago

Hi,

Quick testing here seems fine with 1.3.4.

Thanks!

illestrater commented 6 years ago

hi @toots , thanks for the quick reply! My issue must likely be occurring because I'm using v1.1.1

Apologies for the late response, been working on other things, but now I'm back to working on my streaming services :) I'll rebuild with 1.3.4 and report back!

illestrater commented 6 years ago

@toots, I've rebuilt Liquidsoap 1.3.3-1 and am running into the same issues. The way that I tested was by running my script and, as it uses telnet for dynamic source creation, created 20 transcoders (telnet command: "sources.add randomstring"), and then killed the 20 transcoders ("sources.remove randomstring"). Monitoring the memory usage, it went up and never came back down.

Provided are some logs: https://pastebin.com/Ga83f3mp

My check of the memory not decreasing is performed by around line ~490 I believe.

illestrater commented 6 years ago

@toots I've rebuilt again with Ubuntu 18.04 x64 and Liquidsoap v1.3.4 and still face the same issue. Memory increases and does not drop back down. Logs don't seem to indicate much...

Could you look into this and would you know of any alternative approaches I can take for dynamic transcoding on the fly?

Thank you for your work.

2018/10/06 20:15:46 >>> LOG START
2018/10/06 20:15:45 [main:3] Liquidsoap 1.3.4
2018/10/06 20:15:45 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.3.4 dtools=0.4.1 duppy=0.7.3 duppy.syntax=0.7.3 cry=0.6.2 mm=0.4.0 ogg=0.5.2 vorbis=0.7.1 mad=0.4.5 dynlink=[distributed with Ocaml] lame=0.3.3 samplerate=0.1.4 taglib=0.3.3 camomile=1.0.1
2018/10/06 20:15:45 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.
2018/10/06 20:15:45 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2018/10/06 20:15:45 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2018/10/06 20:15:45 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2018/10/06 20:15:45 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2018/10/06 20:15:46 [threads:3] Created thread "generic queue #1".
2018/10/06 20:15:46 [threads:3] Created thread "generic queue #2".
2018/10/06 20:15:46 [threads:3] Created thread "non-blocking queue #1".
2018/10/06 20:15:46 [threads:3] Created thread "non-blocking queue #2".
2018/10/06 20:15:46 [threads:3] Created thread "wallclock_main" (1 total).
2018/10/06 20:15:46 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2018/10/06 20:17:00 [server:3] New client: 127.0.0.1.
2018/10/06 20:17:03 [threads:3] Created thread "http polling" (2 total).
2018/10/06 20:17:03 [asldjkfhaskfd-mp3:3] Connecting mount asldjkfhaskfd-mp3 for source@stream.cue.dj...
2018/10/06 20:17:03 [asldjkfhaskfd-mp3:3] Connection setup was successful.
2018/10/06 20:17:03 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:06 [threads:3] Created thread "http polling" (3 total).
2018/10/06 20:17:06 [alweghfwfhlkawh-mp3:3] Connecting mount alweghfwfhlkawh-mp3 for source@stream.cue.dj...
2018/10/06 20:17:06 [alweghfwfhlkawh-mp3:3] Connection setup was successful.
2018/10/06 20:17:06 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:07 [threads:3] Created thread "http polling" (4 total).
2018/10/06 20:17:07 [alwehfiwaufhew-mp3:3] Connecting mount alwehfiwaufhew-mp3 for source@stream.cue.dj...
2018/10/06 20:17:07 [alwehfiwaufhew-mp3:3] Connection setup was successful.
2018/10/06 20:17:08 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:09 [threads:3] Created thread "http polling" (5 total).
2018/10/06 20:17:09 [awheufkwauhfeauilwkh-mp3:3] Connecting mount awheufkwauhfeauilwkh-mp3 for source@stream.cue.dj...
2018/10/06 20:17:09 [awheufkwauhfeauilwkh-mp3:3] Connection setup was successful.
2018/10/06 20:17:09 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:11 [threads:3] Created thread "http polling" (6 total).
2018/10/06 20:17:11 [lakhwjefkljawhf-mp3:3] Connecting mount lakhwjefkljawhf-mp3 for source@stream.cue.dj...
2018/10/06 20:17:11 [lakhwjefkljawhf-mp3:3] Connection setup was successful.
2018/10/06 20:17:11 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:13 [threads:3] Created thread "http polling" (7 total).
2018/10/06 20:17:13 [kaljhsdlfkjhsa-mp3:3] Connecting mount kaljhsdlfkjhsa-mp3 for source@stream.cue.dj...
2018/10/06 20:17:13 [kaljhsdlfkjhsa-mp3:3] Connection setup was successful.
2018/10/06 20:17:13 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:14 [threads:3] Created thread "http polling" (8 total).
2018/10/06 20:17:14 [alwiuehfiulh-mp3:3] Connecting mount alwiuehfiulh-mp3 for source@stream.cue.dj...
2018/10/06 20:17:14 [alwiuehfiulh-mp3:3] Connection setup was successful.
2018/10/06 20:17:14 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:16 [threads:3] Created thread "http polling" (9 total).
2018/10/06 20:17:16 [alkjshdfkjlhas-mp3:3] Connecting mount alkjshdfkjlhas-mp3 for source@stream.cue.dj...
2018/10/06 20:17:16 [alkjshdfkjlhas-mp3:3] Connection setup was successful.
2018/10/06 20:17:16 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:18 [threads:3] Created thread "http polling" (10 total).
2018/10/06 20:17:18 [lawiuhfiluwaehf-mp3:3] Connecting mount lawiuhfiluwaehf-mp3 for source@stream.cue.dj...
2018/10/06 20:17:18 [lawiuhfiluwaehf-mp3:3] Connection setup was successful.
2018/10/06 20:17:18 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:19 [threads:3] Created thread "http polling" (11 total).
2018/10/06 20:17:19 [wliuhfialwuhf-mp3:3] Connecting mount wliuhfialwuhf-mp3 for source@stream.cue.dj...
2018/10/06 20:17:19 [wliuhfialwuhf-mp3:3] Connection setup was successful.
2018/10/06 20:17:19 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:21 [threads:3] Created thread "http polling" (12 total).
2018/10/06 20:17:21 [laiwuhfiaulwehf-mp3:3] Connecting mount laiwuhfiaulwehf-mp3 for source@stream.cue.dj...
2018/10/06 20:17:21 [laiwuhfiaulwehf-mp3:3] Connection setup was successful.
2018/10/06 20:17:21 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:22 [threads:3] Created thread "http polling" (13 total).
2018/10/06 20:17:22 [liwhfiaulwhf-mp3:3] Connecting mount liwhfiaulwhf-mp3 for source@stream.cue.dj...
2018/10/06 20:17:22 [liwhfiaulwhf-mp3:3] Connection setup was successful.
2018/10/06 20:17:23 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:24 [threads:3] Created thread "http polling" (14 total).
2018/10/06 20:17:24 [lkauhwkfljwhea-mp3:3] Connecting mount lkauhwkfljwhea-mp3 for source@stream.cue.dj...
2018/10/06 20:17:24 [lkauhwkfljwhea-mp3:3] Connection setup was successful.
2018/10/06 20:17:24 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:27 [threads:3] Created thread "http polling" (15 total).
2018/10/06 20:17:27 [awliufhwiuf-mp3:3] Connecting mount awliufhwiuf-mp3 for source@stream.cue.dj...
2018/10/06 20:17:27 [awliufhwiuf-mp3:3] Connection setup was successful.
2018/10/06 20:17:27 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:29 [threads:3] Created thread "http polling" (16 total).
2018/10/06 20:17:29 [klajwhefkjlawhe-mp3:3] Connecting mount klajwhefkjlawhe-mp3 for source@stream.cue.dj...
2018/10/06 20:17:29 [klajwhefkjlawhe-mp3:3] Connection setup was successful.
2018/10/06 20:17:29 [mksafe:3] Switch to safe_blank.
2018/10/06 20:17:33 [server:3] Client 127.0.0.1 disconnected.
2018/10/06 20:17:50 [server:3] New client: 127.0.0.1.
2018/10/06 20:17:55 [alkjshdfkjlhas-mp3:3] Closing connection...
2018/10/06 20:17:56 [threads:3] Thread "http polling" terminated (15 remaining).
2018/10/06 20:18:00 [alweghfwfhlkawh-mp3:3] Closing connection...
2018/10/06 20:18:02 [threads:3] Thread "http polling" terminated (14 remaining).
2018/10/06 20:18:05 [alwehfiwaufhew-mp3:3] Closing connection...
2018/10/06 20:18:06 [threads:3] Thread "http polling" terminated (13 remaining).
2018/10/06 20:18:09 [alwiuehfiulh-mp3:3] Closing connection...
2018/10/06 20:18:10 [threads:3] Thread "http polling" terminated (12 remaining).
2018/10/06 20:18:13 [asldjkfhaskfd-mp3:3] Closing connection...
2018/10/06 20:18:14 [threads:3] Thread "http polling" terminated (11 remaining).
2018/10/06 20:18:19 [awheufkwauhfeauilwkh-mp3:3] Closing connection...
2018/10/06 20:18:20 [threads:3] Thread "http polling" terminated (10 remaining).
2018/10/06 20:18:24 [awliufhwiuf-mp3:3] Closing connection...
2018/10/06 20:18:25 [threads:3] Thread "http polling" terminated (9 remaining).
2018/10/06 20:18:30 [kaljhsdlfkjhsa-mp3:3] Closing connection...
2018/10/06 20:18:31 [threads:3] Thread "http polling" terminated (8 remaining).
2018/10/06 20:18:35 [klajwhefkjlawhe-mp3:3] Closing connection...
2018/10/06 20:18:37 [threads:3] Thread "http polling" terminated (7 remaining).
2018/10/06 20:18:39 [laiwuhfiaulwehf-mp3:3] Closing connection...
2018/10/06 20:18:41 [threads:3] Thread "http polling" terminated (6 remaining).
2018/10/06 20:18:46 [lakhwjefkljawhf-mp3:3] Closing connection...
2018/10/06 20:18:47 [threads:3] Thread "http polling" terminated (5 remaining).
2018/10/06 20:18:54 [liwhfiaulwhf-mp3:3] Closing connection...
2018/10/06 20:18:55 [threads:3] Thread "http polling" terminated (4 remaining).
2018/10/06 20:19:00 [lawiuhfiluwaehf-mp3:3] Closing connection...
2018/10/06 20:19:02 [threads:3] Thread "http polling" terminated (3 remaining).
2018/10/06 20:19:08 [lkauhwkfljwhea-mp3:3] Closing connection...
2018/10/06 20:19:08 [threads:3] Thread "http polling" terminated (2 remaining).
2018/10/06 20:19:13 [wliuhfialwuhf-mp3:3] Closing connection...
2018/10/06 20:19:14 [threads:3] Thread "http polling" terminated (1 remaining).
2018/10/06 20:19:24 [server:3] Client 127.0.0.1 disconnected.
illestrater commented 6 years ago

@toots Apologies for the mention again, but could you look into this one more time? It's a show stopper for my audio platform to be able to scale. It won't work out if I have to manually restart liquidsoap every few days.

toots commented 5 years ago

Hey. I'm back from a short liquidsoap break. I actually just pushed a fix I believe might have affected all users. Any chance you could try it? You can do it this way, via opam:

git clone --recursive https://github.com/savonet/ocaml-duppy.git
cd ocaml-duppy
opam pin add .
toots commented 5 years ago

Ok, nevermind, I think I found your issue. You also need to remove the source from the dyn_sources list, otherwise it never gets garbage collected. Just add dyn_sources := list.remove_assoc(uri,!dyn_sources) to your script:

set("server.telnet", true)

dyn_sources = ref []

def add_source(uri) =
  url = mksafe(input.http("http://illestrater.com:1337/#{uri}"))
  source = output.icecast(
    %mp3(bitrate=128),
    mount="#{uri}-mp3",
    host="illestrater.com",
    port=1337,
    password="*******",
    fallible=true
  )

  output = source(url)

  dyn_sources := 
      list.append( [(uri, output)],
                    !dyn_sources )
  "transcoding #{uri}"
end

def remove_source(uri) =
  def search(x, y) =
    current_uri = fst(y)
    if current_uri == uri then
      test = snd(y)
      source.shutdown(test)
      (["#{uri} closed"])
    else
      ([])
    end
  end
  result = list.fold(search, ([]), !dyn_sources)
  dyn_sources := list.remove_assoc(uri,!dyn_sources)
  "#{result}"
end

server.register(namespace="sources",
                description="Start a new dynamic playlist.",
                usage="add <uri>",
                "add",
                add_source)
server.register(namespace="sources",
                description="Start a new dynamic playlist.",
                usage="remove <uri>",
                "remove",
                remove_source)

output.dummy(blank())

If you set the log level to 4, you can monitor the garbage collection calls and you should see your dynamic sources get cleaned up. It might not happen immediately, though, but as memory grows, the application will eventually reclaim their memory.

I'm closing here since I believe that was the issue. Please reopen if you still see an issue.

illestrater commented 5 years ago

@toots Thank you for returning to this! Apologies for inquiring your help again, but by using remove_assoc() I am encountering a code error:

Starting liquidsoap channels: transcoder.liq At line 39, char 41-53:
  this value has type
    [(_*active_source(_))] (inferred at line 6, char 19-20)
  but it should be a subtype of (the type of the value at /usr/lib/liquidsoap/1.1.1/utils.liq, line 37, char 26)
    [(_*string)] (inferred at /usr/lib/liquidsoap/1.1.1/utils.liq, line 14, char 4)

I hate to ask for coding advice, but it's quite difficult for me to understand this language and its errors, but I'm thinking since the list isn't a typical key value pair and its key is actually (uri, output), this is why I'm having troubles? Any advice here?

toots commented 5 years ago

It looks like you are using an old version of liquidsoap. In version 1.1.1, list.remove_assoc was not as generic and could only process lists of the type: [(string*string)].

However, you can rewrite the operator this way:

def list.remove_assoc(label, l) =
  def f(result,element) =
    current_label = fst(element)
    if current_label == label then
      result
    else
      list.add(element,result)
    end
  end
  list.fold(f,[],l)
end
illestrater commented 5 years ago

@toots thank you. I've upgraded our production liquidsoap to 1.3.4 and am using the native function now, and initial tests are showing substantial improvement as you expected! :) Will report back after some time has elapsed, and will test your latest fix for ocaml-duppy if the issue persists before getting back to you.

This has been a huge relief and will allow me to move forward with my project. If you're interested in what we're using liquidsoap for, I'm building a live streaming platform for DJs to play to an online audience called CUE Music (https://cue.dj). We hope to be successful and change how music is consumed, and we most definitely will donate to your project once we start seeking for some sort of revenue and have the means to. Much appreciated.

toots commented 5 years ago

Glad to hear it's working! Good luck with your project, it looks awesome. As I was saying in the release email, we're hoping to be able to provide a consulting service fairly soon.