"Error while sending data" - disconnect every few hours

[FlorianReiterer]

Every few hours clients get disconnected and icecast reports the stream as restarted. here is the log bit of an error:

2021/10/29 13:14:43 [Musik:3] Prepared "/home/motherearth/FTP/media/Musik/Eels/in my dreams.flac" (RID 14).
2021/10/29 13:14:58 [buffer.producer_1:3] Buffer emptied, start buffering...
2021/10/29 13:14:58 [Mother_Earth_Radio:3] Source failed (no more tracks) stopping output...
2021/10/29 13:14:58 [Mother_Earth_Radio:3] Closing connection...
2021/10/29 13:15:18 [Mother_Earth_Radio:3] Metadata update may have failed with error: Cry__Cry_common.Timeout
2021/10/29 13:15:18 [clock.main:2] We must catchup 29.99 seconds!
2021/10/29 13:15:18 [Mother_Earth_Radio:2] Error while sending data: could not write data to host: Broken pipe in write()!
2021/10/29 13:15:18 [Mother_Earth_Radio:3] Closing connection...
2021/10/29 13:15:18 [Mother_Earth_Radio:3] Will try to reconnect in 3.00 seconds.
2021/10/29 13:15:18 [Mother_Earth_Radio:3] Connecting mount /motherearth.mp3 for source@server12.streamserver24.com...
2021/10/29 13:15:18 [Mother_Earth_Radio:3] Connection setup was successful.
2021/10/29 13:15:22 [Mother_Earth_Radio:3] Connecting mount motherearth for source@server9.streamserver24.com...
2021/10/29 13:15:22 [Mother_Earth_Radio:3] Connection setup was successful.

the log from the start time:

2021/10/25 12:31:29 [main:3] Liquidsoap 2.1.0+git@1d956c81
2021/10/25 12:31:29 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.5.0 sedlex=2.4 menhirLib=20210929 curl=0.9.1 dtools=0.4.4 duppy=0.9.2 cry=0.6.5 mm=0.7.1 ogg=0.7.0 ogg.decoder=0.7.0 mad=0.5.0 flac=0.3.0 flac.ogg=0.3.0 flac.decoder=0.3.0 dynlink=[distributed with Ocaml] lame=0.3.4 ffmpeg-avutil=1.0.1 ffmpeg-avcodec=1.0.1 ffmpeg-avdevice=1.0.1 ffmpeg-av=1.0.1 ffmpeg-avfilter=1.0.1 ffmpeg-swresample=1.0.1 ffmpeg-swscale=1.0.1 samplerate=0.1.6 taglib=0.3.6 ssl=0.5.9 camomile=1.0.2 camlimages=4.2.6
2021/10/25 12:31:29 [main:3] 
....
2021/10/25 12:31:29 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.
2021/10/25 12:31:29 [clock:3] Using builtin (low-precision) implementation for latency control
2021/10/25 12:31:30 [frame:3] Using 96000Hz audio, 25Hz video, 96000Hz main.
2021/10/25 12:31:30 [frame:3] Video frame size set to: 1280x720
2021/10/25 12:31:30 [frame:3] Frame size must be a multiple of 3840 ticks = 3840 audio samples = 1 video samples.
2021/10/25 12:31:30 [frame:3] Targeting 'frame.duration': 0.04s = 3840 audio samples = 3840 ticks.
2021/10/25 12:31:30 [frame:3] Frames last 0.04s = 3840 audio samples = 1 video samples = 3840 ticks.
2021/10/25 12:31:30 [sandbox:3] Sandboxing disabled
2021/10/25 12:31:30 [video.converter:3] Using preferred video converter: ffmpeg.
2021/10/25 12:31:30 [audio.converter:3] Using samplerate converter: ffmpeg.
2021/10/25 12:31:30 [Mother_Earth_Radio:3] Connecting mount /motherearth.mp3 for source@server12.streamserver24.com...
2021/10/25 12:31:30 [Mother_Earth_Radio:3] Connection setup was successful.
2021/10/25 12:31:30 [harbor:3] Adding mountpoint '/live' on port 18888
2021/10/25 12:31:30 [clock.buffer.producer_1:3] Streaming loop starts in auto-sync mode
2021/10/25 12:31:30 [clock.buffer.producer_1:3] Delegating synchronisation to CPU clock
2021/10/25 12:31:30 [Mother_Earth_Radio:3] Connecting mount motherearth for source@server9.streamserver24.com...
2021/10/25 12:31:30 [Mother_Earth_Radio:3] Connection setup was successful.
2021/10/25 12:31:30 [server:2] Server command Mother_Earth_Radio.skip already registered! Previous definition replaced.
2021/10/25 12:31:30 [server:2] Server command Mother_Earth_Radio.metadata already registered! Previous definition replaced.
2021/10/25 12:31:30 [server:2] Server command Mother_Earth_Radio.remaining already registered! Previous definition replaced.

running on a debian virtual machine bit on the server. streaming to RSAS (FLAC) and Icecast-kh (mp3). installed via opam

the .liq:

motherearth_v2.3 Kopie.txt

[Russsgithub]

@FlorianReiterer Hello,

I've had similar issues using rsas (rocket audio server). I've managed to avoid it by adding a buffer before the output, or (my preferred) by adding clock to the output source.

output.icecast(clock(source))

or

source = clock(source)
output.icecast(source)

Rsas does seem to work reliably and I love the push notification metadata, but it does also have a few issues - this being one.

I hope this helps.

Russ

[FlorianReiterer]

thanks for the input, i already have an extra clock plus a buffer in there clock(buffer(buffer=5.,(radio)))) It's great to hear you fixed the same issue. You do feed mp3 files and output to mp3 i assume? For maybe it's the FLAC files i use and their decoder then....

[Russsgithub]

I didn't realise you output as flac. I'm use fdkaac as output codec , which behaves (for me as above). I did have unresolvable issues with opus.

I input a mixture of mp3 and opus , but don't think this is your issue.

Btw I don't think you need double buffers. I think the default buffer duration is 5s (might be wrong) but you can increase the duration on one and remove the other.

Have you tried with just clock ?

For a 'hungry' script I had to have a 25 sec buffer before output to stop this, but got annoyed with the lag. Removing the buffer and adding clock made it better some what.

Good luck.

[FlorianReiterer]

Thank You Russ! clock is for the second output, to give it a separate clock (thats how i understood those two functions):

output.icecast(%flac etc...(buffer(radio)
output.mp3(%mp3 etc...clock(buffer(radio))

i see those [clock.main:2] We must catchup 29.99 seconds! errors, therefore will increase to 40 seconds buffer. Thanks for the hint. (i'm long-term testing at home right now where i only have icecast :( its running smoothly for hours now - points to RSAS indeed!) regards, Florian

[Russsgithub]

Metadata update may have failed with error: Cry__Cry_common.Timeout

This is the line I got when rsas was failing. So I agree its an rsas issue. It could be flac and rsas together.

I wonder if using the same buffer would speed things up and avoid the rsas glitch.

Eg.

s = buffer(s)

## lengthen buffer if it 5s isn't enough

s = clock(s)

output.icecast(%mp3,s)
output.icecast(%flac,s)

Maybe.

[FlorianReiterer]

good call. looking nice. will do.

maybe

s = buffer(s)

output.icecast(%flac,s)
ouput.icecast(%mp3,clock(s))

is preferred by liquidsoap engine, giving seperate clocks to seperate outputs and nicely buffer the whole thing beforehand. to be sure i'm still thinking 30s-40s buffer, since RSAS seems to quickly disconnect and not be ready when liquidsoap retries(?)

s = buffer(buffer=40.,s)
output.icecast(%flac,s)
ouput.icecast(%mp3,clock(s))

where did the lag became annoying for you? live mic? switches?

[Russsgithub]

Hey Florian,

I'd start the buffer duration low and build it up until it works, if it does.

The lag I was referring to was related to externally adjusting things like interactive.float which would take the buffers length to take effect. I also had a metadata rewrite that's timing was effected by the buffer in some way.

You will get lag between mic and output using a buffer, as I'm sure you know.

I just reread the docs, buffer takes buffer(length) and max. I'd increase max rather than buffer, so it'll use what it needs.

Saying that it probably shouldn't need a buffer, I noticed all inputs eg harbor have a buffer attached that you could increase if its dropping at the input.

Unless you've got a lot going on at the same time (thread.run can help in some places to free up the main thread a bit) it should feed through OK and get to the mount point.

I don't know how reliable flac (lots of data) and rsas are together, .. try other formats, or flac in a straight file to output liq script to test things.

There may be a better way of fixing this.

Russ

On 30 Oct 2021 16:16, FlorianReiterer @.***> wrote:

good call. looking nice. will do.

maybe

s = buffer(s)

output.icecast(%flac,s) ouput.icecast(%mp3,clock(s))

is preferred by liquidsoap engine, giving seperate clocks to seperate outputs and nicely buffer the whole thing beforehand. to be sure i'm still thinking 30s-40s buffer, since RSAS seems to quickly disconnect and not be ready when liquidsoap retries(?)

s = buffer(buffer=40.,s) output.icecast(%flac,s) ouput.icecast(%mp3,clock(s))

where did the lag became annoying for you? live mic? switches?

— You are receiving this because you commented. Reply to this email directly, view it on GitHubhttps://github.com/savonet/liquidsoap/issues/2039#issuecomment-955307449, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AB627QJ6ITFYTEZ7VYVAORLUJQK57ANCNFSM5G73LVIA. Triage notifications on the go with GitHub Mobile for iOShttps://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Androidhttps://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

[FlorianReiterer]

thanks for the insight.

i have to test "in production" because i simply lack a test machine (raspbian -macos-windows but no debian) to run RSAS. (My test raspbian with icecast does everything just as it should) so i sent the 40 seconds buffer version to the server guys, will post the outcome.

the script is really simple, the most intense thing is decoding flac files, radio them and output to two sources, FLAC and mp3. i agree with the doubt on the buffer. RSAS themselves note the trouble with FLAC (namely disconnects) and also suggests another format. Unfortunately that's just what it's all about in my case: 96k/24bits lossless streaming. An argueable decision admittedly, but, you know, me say: sounds greaat maahn! ;)

many thanks for your help, all the best, Florian

[Russsgithub]

No worries, I hope its some help.

I've had the same thoughts on quality myself in the past so know where you're coming from.

Good luck.

On 30 Oct 2021 19:43, FlorianReiterer @.***> wrote:

thanks for the insight.

i have to test "in production" because i simply lack a test machine (raspbian -macos-windows but no debian) to run RSAS. (My test raspbian with icecast does everything just as it should) so i sent the 40 seconds buffer version to the server guys, will post the outcome.

the script is really simple, the most intense thing is decoding flac files, radio them and output to two sources, FLAC and mp3. i agree with the doubt on the buffer. RSAS themselves note the trouble with FLAC (namely disconnects) and also suggests another format. Unfortunately that's just what it's all about in my case: 96k/24bits lossless streaming. An argueable decision admittedly, but, you know, me say: sounds greaat maahn! ;)

many thanks for your help, all the best, Florian

— You are receiving this because you commented. Reply to this email directly, view it on GitHubhttps://github.com/savonet/liquidsoap/issues/2039#issuecomment-955575841, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AB627QIZPG2WEJGJHFBNAFTUJRDGZANCNFSM5G73LVIA. Triage notifications on the go with GitHub Mobile for iOShttps://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Androidhttps://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

[FlorianReiterer]

first followup: this fixes icecast disconnects, though RSAS still reports the stream as restarted:

output.icecast(%flac(...), buffer(buffer=40., radio))
output.icecast(%mp3(...), clock(buffer(buffer=40., radio)))

next candidate is

radio = buffer(buffer=40.,radio)
output.icecast(%flac,radio)
ouput.icecast(%mp3,clock(radio))

will report the next days

[FlorianReiterer]

no luck with the above way

2021/11/04 20:55:59 [Mother_Earth_Radio:3] Metadata update may have failed with error: Cry__Cry_common.Timeout
2021/11/04 20:55:59 [clock.buffer.producer_0:2] We must catchup 29.99 seconds!
2021/11/04 20:55:59 [Mother_Earth_Radio:2] Error while sending data: could not write data to host: Broken pipe in write()!
2021/11/04 20:55:59 [Mother_Earth_Radio:3] Closing connection...
2021/11/04 20:55:59 [Mother_Earth_Radio:3] Will try to reconnect in 3.00 seconds.
2021/11/04 20:56:03 [Mother_Earth_Radio:3] Connecting mount motherearth for source@server9.streamserver24.com...
2021/11/04 20:56:03 [Mother_Earth_Radio:3] Connection setup was successful.

also the buffer/clock setting

output.icecast(%ogg(%flac(..), clock(buffer(buffer=40., radio)))
output.icecast(%mp3), clock(buffer(radio)))

does not fix. Icecast mount is stable now with buffer and clock, it does not disconnect, only the RSAS mount gives the errors.

I will try with settings, since buffer/clock does not change RSAS behaviour:

settings.request.metadata_decoders.set(["FFMPEG", "FLAC", "OGG", "TAGLIB", "ID3V2"])
settings.root.max_latency.set(1920.)

[Russsgithub]

Hi Florian,

the end of my script (fdk-aac) to rsas has this.

s = clock(s)
output.icecast(ice_metadata="true", format="audio/aac", %fdkaac(.....), mksafe(s))

I can see the point of the buffer if needed, but think buffer(max=40., s) may be 'better' ?

I think setting the rsas output with its own clock helped me, I got the impression that this was the flac stream from your post.

I guess having the same buffer used by two outputs may have issues if one runs a lot quicker than the other.

I also guess that the rasparian may not be able to deal with decoding flac and then re-encoding to both flac and mp3 ? ( i have no experience with them)

Once again, good luck. I hope you work it out.

[FlorianReiterer]

Reporting no change in RSAS disconnect by using max_latency setting. Same old liquidsoap error

2021/11/05 12:01:31 [Mother_Earth_Radio:3] Metadata update may have failed with error: Cry__Cry_common.Timeout
2021/11/05 12:01:31 [clock.buffer.producer_0:2] We must catchup 29.99 seconds!
2021/11/05 12:01:31 [Mother_Earth_Radio:2] Error while sending data: could not write data to host: Broken pipe in write()!

the RSAS log:

[2021-11-05 12:01:16.880 +01:00] [info] /motherearth: Source disconnected
[2021-11-05 12:01:33.000 +01:00] [info] /motherearth: Source connected

no more info than this from RSAS, except some errors hours before that didnt lead to a disconnect:

[2021-11-05 09:10:46.964 +01:00] [info] /motherearth: Source disconnected
[2021-11-05 09:10:56.778 +01:00] [info] /motherearth: Source reconnected - keeping 4 listeners
[2021-11-05 09:10:56.779 +01:00] [error] Insufficient buffered audio to complete the frame during failover. A glitch may be heard.

this runs on a high-end debian server of the provider's server farm. on another occasion this error in liquidsoap showed up:

2021/11/05 12:31:09 [clock.buffer.producer_1:2] We must catchup 1.05 seconds!
2021/11/05 12:31:11 [clock.buffer.producer_1:2] We must catchup 2.68 seconds!
2021/11/05 12:31:12 [clock.buffer.producer_1:2] We must catchup 3.30 seconds!
2021/11/05 12:31:15 [clock.buffer.producer_1:2] We must catchup 5.44 seconds!
2021/11/05 12:31:16 [clock.buffer.producer_1:2] We must catchup 6.14 seconds!
2021/11/05 12:31:17 [clock.buffer.producer_1:2] We must catchup 6.91 seconds!
2021/11/05 12:31:18 [clock.buffer.producer_1:2] We must catchup 7.23 seconds!
2021/11/05 12:31:19 [clock.buffer.producer_1:2] We must catchup 7.79 seconds!
2021/11/05 12:31:20 [clock.buffer.producer_1:2] We must catchup 8.28 seconds!
2021/11/05 12:31:23 [clock.buffer.producer_1:2] We must catchup 10.77 seconds!
2021/11/05 12:31:24 [clock.buffer.producer_1:2] We must catchup 11.93 seconds!
2021/11/05 12:31:25 [clock.buffer.producer_1:2] We must catchup 12.03 seconds!
2021/11/05 12:31:26 [clock.buffer.producer_1:2] We must catchup 12.66 seconds!
2021/11/05 12:31:28 [clock.buffer.producer_1:2] We must catchup 13.36 seconds!
2021/11/05 12:31:29 [clock.buffer.producer_1:2] We must catchup 14.31 seconds!
2021/11/05 12:31:31 [clock.buffer.producer_1:2] We must catchup 15.72 seconds!
2021/11/05 12:31:34 [clock.buffer.producer_1:2] We must catchup 17.94 seconds!
2021/11/05 12:31:37 [clock.buffer.producer_1:2] We must catchup 20.59 seconds!
2021/11/05 12:31:38 [clock.buffer.producer_1:2] We must catchup 21.43 seconds!
2021/11/05 12:31:40 [clock.buffer.producer_1:2] We must catchup 22.41 seconds!
2021/11/05 12:31:43 [clock.buffer.producer_1:2] We must catchup 24.94 seconds!
2021/11/05 12:31:44 [clock.buffer.producer_1:2] We must catchup 25.95 seconds!
2021/11/05 12:31:46 [clock.buffer.producer_1:2] We must catchup 27.39 seconds!
2021/11/05 12:32:16 [Mother_Earth_Radio:2] Error while sending data: could not write data to host: connection timeout!
2021/11/05 12:32:16 [Mother_Earth_Radio:3] Closing connection...
2021/11/05 12:32:16 [Mother_Earth_Radio:3] Will try to reconnect in 3.00 seconds.
2021/11/05 12:32:16 [clock.buffer.producer_1:2] We must catchup 57.35 seconds!
2021/11/05 12:32:16 [buffer.producer_1:3] Buffer emptied, start buffering...
2021/11/05 12:32:16 [Mother_Earth_Radio:3] Source failed (no more tracks) stopping output...

thanks again for the input @Russsgithub : I was thinking that icecast and RSAS outputs get their own clock and a individual buffer with this

output.icecast(%ogg(%flac(..), clock(buffer(buffer=40., radio)))
output.icecast(%mp3), clock(buffer(radio)))

having buffered it beforehand

s = buffer(buffer=40.,s)
output.icecast(%flac,s)
ouput.icecast(%mp3,clock(s))

lead to disconnecting both Icecast and RSAS again. Individual buffers then fixed Icecast. (will try max buffer)

Pretty much no idea anymore. Dev's, can we check more stuff, or is this RSAS territory? motherearth_v2.41.txt

[toots]

Hi all! This seems more like an issue with RSAS right? I'm moving this to a discussion. Hope y'all find a good workaround.