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

Strange error flushing buffer #77

Closed LeonarddeR closed 6 years ago

LeonarddeR commented 11 years ago

I have a harbor input attached to an lame mp3 icecast stream. Fallible for the stream is enabled, so the stream connects as soon as there's input on the harbor. I however get "strange error flashing buffer" when liquidsoap starts. Here is a log:

2013/05/15 11:42:19 >>> LOG START
2013/05/15 11:42:19 [protocols.external:3] Found "wget.exe".
2013/05/15 11:42:19 [main:3] Liquidsoap 1.1.1
2013/05/15 11:42:19 [main:3] Using: graphics=[distributed with Ocaml] pcre=0.1.0
 dtools=0.3.1 duppy=0.5.1 cry=0.2.2 mm=0.2.1 xmlplaylist=0.1.3 lastfm=0.3.0 ogg=
0.4.5 vorbis=0.6.1 opus=0.1.0 speex=0.2.0 mad=0.4.4 flac=0.1.1 flac.ogg=0.1.1 dy
nlink=[distributed with Ocaml] lame=0.3.2 shine=0.1.1 frei0r=0.1.0 aacplus=0.2.1
 voaacenc=0.1.0 fdkaac=0.1.0 theora=0.3.0 schroedinger=0.1.0 gavl=0.1.5 ao=0.2.0
 samplerate=0.1.2 taglib=0.3.1 camomile=0.8.4 faad=0.3.2 soundtouch=0.1.7 portau
dio=0.2.0 ladspa=0.1.4 yojson=1.0.3 winsvc=0.0.1
2013/05/15 11:42:19 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2013/05/15 11:42:19 [frame:3] Frame size must be a multiple of 1764 ticks = 1764
 audio samples = 1 video samples.
2013/05/15 11:42:19 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio sa
mples = 1764 ticks.
2013/05/15 11:42:19 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video s
amples = 1764 ticks.
2013/05/15 11:42:19 [harbor:3] Adding HTTP handler for 'GET ^/' on port 8005
2013/05/15 11:42:19 [harbor:3] Adding HTTP handler for 'POST ^/(?!interact)' on
port 8005
2013/05/15 11:42:19 [harbor:3] Adding HTTP handler for 'POST /interact' on port
8005
2013/05/15 11:42:19 [threads:3] Created thread "generic queue #1".
2013/05/15 11:42:19 [threads:3] Created thread "generic queue #2".
2013/05/15 11:42:19 [threads:3] Created thread "non-blocking queue #1".
2013/05/15 11:42:19 [threads:3] Created thread "non-blocking queue #2".
2013/05/15 11:42:19 [harbor:3] Adding mountpoint '/bethel' on port 8005
2013/05/15 11:42:19 [out_mb_mp3:3] Connecting mount bethel-mb.mp3 for source@loc
alhost...
2013/05/15 11:42:19 [out_mb_mp3:3] Connection setup was successful.
2013/05/15 11:42:19 [threads:3] Created thread "wallclock_main" (1 total).
2013/05/15 11:42:19 [clock.wallclock_main:3] Streaming loop starts, synchronized
 with wallclock.
2013/05/15 11:42:19 [out_mb_mp3:3] Source failed (no more tracks) stopping outpu
t...
strange error flushing buffer ...
strange error flushing buffer ...
2013/05/15 11:42:19 [out_mb_mp3:3] Closing connection...

What we see here is that a connection to the icecast server is being made and immediately dropped, since there's no input on the harbor. May be this is a part which can be skipped when the only input is a harbor. Or the error, which isn't quite an error in this case since there's indeed no buffer to flush, could be suppressed?

Thanks, Leonard

smimram commented 11 years ago

Unfortunately, the messasge is not ours. It's printed in by lame in bitstream.c. Not sure exactly what that means...

LeonarddeR commented 11 years ago

Well, may be the issue has more to do with the thing i also pointed out above:

What we see here is that a connection to the icecast server is being made and immediately dropped, since there's no input on the harbor.

May be a check should be done on every input whether it contains any track before outputting starts. An example what the log should look like:

[threads:3] Created thread "generic queue #1". [threads:3] Created thread "generic queue #2". [threads:3] Created thread "non-blocking queue #1". [threads:3] Created thread "non-blocking queue #2". [harbor:3] Adding mountpoint '/bethel' on port 8005 [out_mb_mp3:3] Source failed (no tracks yet) waiting for track before output will start...

toots commented 10 years ago

Hey. Any news on this? Also, do you experience and actual issue beside this log line?

ghost commented 9 years ago

My liquidsoap installation was fine, but I have added this line for "recording" the live input to the .mp3 file on my server:

output.file(%mp3, "/var/records/radio-%d-%m-%Y_%H-%M-%S.mp3", live,
fallible=true)

After that every start (restart) of the liquidsoap service goes with a stuttering (appr. 10 seconds nobody can listen to the output stream normally), there is an error in the log file:

2015/03/02 11:53:20 [stderr:3] strange error flushing buffer ... 
2015/03/02 11:53:20 [stderr:3] strange error flushing buffer ...

I use liquidsoap 1.1.1 on the Ubuntu 14.04 server

All contents of my liq file:

# Log dir
set("log.file.path","/tmp/basic-radio.log")

# Serveur settings
set("harbor.bind_addr","0.0.0.0")

# An emergency file
emergency = single("/var/security/music.mp3")

# A playlist
playlist = playlist(mode="randomize",reload=60,"/var/radio/music")

# A live source
live = input.harbor("radio",port=8088,password="somepassword")

# fallback
radio = fallback(track_sensitive=false,
                 [live,playlist,emergency])

# Stream it out
output.shoutcast(%mp3,
    host = "localhost",
    port = 8000, password = "somepassword",
    genre = "Rock",
    url = "http://myradio.com",
    name = "My Radio",
    radio)

output.file(%mp3, "/var/records/radio-%d-%m-%Y_%H-%M-%S.mp3", live,
fallible=true)

The full text of the log file (all what appears after liquidsoap service starts). After approx. 10 seconds it begins to work normally

2015/03/08 18:04:05 >>> LOG START
2015/03/08 18:04:05 [protocols.external:3] Found "/usr/bin/wget".
2015/03/08 18:04:05 [main:3] Liquidsoap 1.1.1
2015/03/08 18:04:05 [main:3] Using: graphics=[distributed with Ocaml] pcre=7.0.4 dtools=0.3.1 duppy=0.5.1 duppy.syntax=0.5.1 cry=0.2.2 mm=0.2.1 xmlplaylist=0.1.3 ogg=0.4.5 vorbis=0.6.1 opus=0.1.0 speex=0.2.0 mad=0.4.4 dynlink=[distributed with Ocaml] lame=0.3.2 shine=0.1.1 fdkaac=0.1.0 theora=0.3.0 ffmpeg=0.1.0 ao=0.2.0 samplerate=0.1.2 taglib=0.3.1 camomile=0.8.4 faad=0.3.2 soundtouch=0.1.7 portaudio=0.2.0 ladspa=0.1.4 dssi=0.1.1 lo=0.1.0
2015/03/08 18:04:05 [dynamic.loader:3] Could not find dynamic module for aacplus encoder.
2015/03/08 18:04:05 [decoder:3] Method "MAD" accepted "/var/security/music.mp3".
2015/03/08 18:04:05 [single:3] "/var/security/music.mp3" is static, resolving once for all...
2015/03/08 18:04:05 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2015/03/08 18:04:05 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2015/03/08 18:04:05 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2015/03/08 18:04:05 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2015/03/08 18:04:05 [threads:3] Created thread "generic queue #1".
2015/03/08 18:04:05 [threads:3] Created thread "generic queue #2".
2015/03/08 18:04:05 [threads:3] Created thread "non-blocking queue #1".
2015/03/08 18:04:05 [threads:3] Created thread "non-blocking queue #2".
2015/03/08 18:04:05 [harbor:3] Adding mountpoint '/radio' on port 8088
2015/03/08 18:04:05 [music:3] Loading playlist...
2015/03/08 18:04:05 [music:3] Playlist is a directory.
2015/03/08 18:04:05 [music:3] Successfully loaded a playlist of 27 tracks.
2015/03/08 18:04:05 [single_5143:3] Prepared "/var/security/music.mp3" (RID 0).
2015/03/08 18:04:05 [output(dot)shoutcast:3] Connecting mount / for source@localhost...
2015/03/08 18:04:05 [decoder:3] Method "MAD" accepted "/var/radio/music/DJ Bobo & Sandra - Secrets of Love.mp3".
2015/03/08 18:04:05 [output(dot)shoutcast:3] Connection setup was successful.
2015/03/08 18:04:05 [threads:3] Created thread "wallclock_main" (1 total).
2015/03/08 18:04:05 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2015/03/08 18:04:05 [fallback_5149:3] Switch to single_5143.
2015/03/08 18:04:05 [music:3] Prepared "/var/radio/music/DJ Bobo & Sandra - Secrets of Love.mp3" (RID 2).
2015/03/08 18:04:05 [fallback_5149:3] Switch to music with transition.
2015/03/08 18:04:05 [output(dot)shoutcast:3] Metadata update may have failed with error: bad answer
2015/03/08 18:04:05 [/var/records/radio-%d-%m-%Y_%H-%M-%S(dot)mp3:3] Source failed (no more tracks) stopping output...
2015/03/08 18:04:05 [stderr:3] strange error flushing buffer ... 
2015/03/08 18:04:05 [stderr:3] strange error flushing buffer ... 
2015/03/08 18:04:05 [output(dot)shoutcast:3] Metadata update may have failed with error: bad answer
alexey-v-paramonov commented 8 years ago

+1. I am using Liquidsoap 1.2.1 with Centova Cast. Liquidsoap starts and exits (with exitcode 0) immediately sending strange error flushing buffer... to stderr. Liquidsoap 1.1 works fine with the same config.

Liquidsoap scripts & log file attached. liquidsoap.tar.gz log.tar.gz

toots commented 8 years ago

Hi @alexey-v-paramonov

Your issue look like it could very likely be coming from a hard crash or a segfault from the lame library.

Are you familiar with gdb? This tool should allow us to know more about the crash. Here's how you can use it (after installing it of course):

Also, you might want to check your version of the lame library and see if there is a more recent version available..

alexey-v-paramonov commented 8 years ago

Thanks for your reply. My Lame version: lame.x86_64 3.99.5-2.el7

Here is what I get from running liquidsoap with gdb:

bash-4.2$ gdb /usr/local/centovacast/liquidsoap/bin/liquidsoap1.2 
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-80.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/local/centovacast/liquidsoap/bin/liquidsoap1.2...done.
(gdb) run source.conf
Starting program: /usr/local/centovacast/liquidsoap/bin/liquidsoap1.2 source.conf
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Detaching after fork from child process 11126.
Detaching after fork from child process 11127.
Detaching after fork from child process 11131.
[New Thread 0x7fffed7e9700 (LWP 11132)]
[New Thread 0x7fffecfe8700 (LWP 11133)]
[New Thread 0x7fffec7e7700 (LWP 11134)]
[New Thread 0x7fffebfe6700 (LWP 11135)]
[New Thread 0x7fffeb7e5700 (LWP 11136)]
[New Thread 0x7fffeafe4700 (LWP 11137)]
[New Thread 0x7fffea7e3700 (LWP 11138)]
strange error flushing buffer ... 
strange error flushing buffer ... 
[Thread 0x7fffea7e3700 (LWP 11138) exited]
[Thread 0x7fffeafe4700 (LWP 11137) exited]
[Thread 0x7fffeb7e5700 (LWP 11136) exited]
[Thread 0x7fffec7e7700 (LWP 11134) exited]
[Thread 0x7fffecfe8700 (LWP 11133) exited]
[Thread 0x7ffff7fa38c0 (LWP 11122) exited]
[Thread 0x7fffebfe6700 (LWP 11135) exited]
[Inferior 1 (process 11122) exited normally]
Missing separate debuginfos, use: debuginfo-install libmad-devel-20010101-5.1.x86_64
(gdb) thread apply all bt
(gdb)

The last command output is empty, maybe I am doing something wrong?

toots commented 8 years ago

Well it looks like your script isn't starting at all. I'll have to look at it.

alexey-v-paramonov commented 8 years ago

I can attach a log file, I can see some activity in it - sources, playlists start, pretty sure that liquidsoap process starts as it should, but at the moment when it tries to play the files - it fails. Maybe there is some kind of desynchronization, when it tries to read files and sends the data for LAME to decode, that data is somehow gets corrupted. Unfortunately I am unfamiliar with Ocaml, that's why I cant fully debug the situation, but I will try to debug LAME - at least I will be able to see the data it gets before the failure.

Moonbase59 commented 8 years ago

Same here, btw., using LS 1.1.1 on Ubuntu Studio 14.04.5 LTS. I record my live inputs since not all DJs have the possibility locally, and whenever I start up my LS script, it generates a 417 byte file for each stream in the "airchecks" folder.

# Add two live sources (Shoutcast-compatible)
live1 = input.harbor("", port=8010, icy=true, on_connect=live_start, on_disconnect=live_stop, user="source", password="hackme")
live2 = input.harbor("", port=8020, icy=true, on_connect=live_start, on_disconnect=live_stop, user="source", password="hackme")

# Archive the live streams
output.file(%mp3(bitrate=128), home^"/airchecks/aufzeichnung.%Y-%m-%d.%H%M%S.live1.mp3", fallible=true, live1)
output.file(%mp3(bitrate=128), home^"/airchecks/aufzeichnung.%Y-%m-%d.%H%M%S.live2.mp3", fallible=true, live2)

…

# *** Output ***
#
# Output stream to local Icecast
# Use a separate clock to allow for some buffering.
clock.assign_new(
  id="icecast",
  [
        output.icecast(
            %mp3(bitrate = 128),
            host = "localhost",
            port = 8000,
            mount = "stream.mp3",
            icy_metadata = "true",
            user = "source",
            password = "hackme",
            name = "Radio Paranoid",
            description = "DEIN Rock- und Metal-Radio! Die Moderatoren live im Chat für Dich.",
            genre = "Rock, Hardrock, Metal",
      url = "http://www.radio-paranoid.de/",
            public = true,
            s
        )
  ]
)
toots commented 6 years ago

Hi,

Unfortunately, this issue is so old that I don't think we'll ever be able to reproduce/fix it in the current codebase. Closing now, feel free to submit or reopen if it still applies to the latest code.