search

karlheyes / icecast-kh

KH branch of icecast
GNU General Public License v2.0
298 stars 106 forks source link

Relay `run-on` setting seems to be ignored. #140

Open rfwatson opened 7 years ago

rfwatson commented 7 years ago

Hi there

Firstly thanks for your hard work on this great project.

I am running icecast-2.4.0-kh3. My requirements are for an Icecast server to relay many (hundreds) of MP3 streams from other Icecast instances.

These relay streams are each configured as an on-demand, single-broadcast relay on the slave:

<relay>
  <server>my-master-hostname</server>
  <port>8000</port>
  <mount>/my_stream</mount>
  <on-demand>1</on-demand>
  <run-on>60</run-on>
</relay>

With this configuration I expect the relay to:

1) stay alive for at least 60 seconds after the last listener disconnects 2) the slave should never return 404, as long as /my_stream is available on my-master-hostname

Unfortunately neither of these hold. When connecting and disconnecting to the stream I periodically (every few minutes) I notice the following in my logs:

1491006:[2016-09-07  13:50:23] INFO source/source_read listener count on /my_stream now 1
1491009:[2016-09-07  13:50:27] INFO source/source_read listener count on /my_stream now 0
1491010:[2016-09-07  13:50:27] INFO slave/relay_reset servers to be retried on /my_stream
1491011:[2016-09-07  13:50:27] INFO slave/relay_read fallback on /my_stream attempted
1491012:[2016-09-07  13:50:27] INFO source/source_shutdown Source "/my_stream" exiting
1491013:[2016-09-07  13:50:27] INFO slave/relay_read standing by to restart relay on /my_stream in 120 seconds
1491014:[2016-09-07  13:50:27] INFO slave/relay_reset servers to be retried on /my_stream

As you can see the relay is shut down immediately after listener count drops from 1 to 0, which seems to conflict with the run-on setting.

Additionally, after this occurs the stream is unavailable on the slave for a few seconds, returning 404 - despite still being available on the master.

This behaviour is not consistent and appears to contradict the Icecast documentation, which is why I am reporting it as a bug.

How can I stop this behaviour, and make Icecast behave per the expectations above?

(I don't know if this is relevant but: the only non-standard thing I am doing is periodically sending Icecast a HUP signal to reload configuration and add new relays. However, at no point is the example stream above changed or removed.)

acorkin commented 6 years ago

Icecast 2.4.0-kh5

I am also seeing this issue in our configuration.

Icecast XML:

<limits>
        <clients>10000</clients>
        <workers>2</workers>
        <sources>10000</sources>
        <queue-size>524288</queue-size>
        <burst-size>65535</burst-size>
</limits>

<relay>
                <server>example.server.com</server>
                <port>1234</port>
                <mount>/70e739c0/listen</mount>
                <local-mount>/70e739c0/listen</local-mount>
                <on-demand>1</on-demand>
                <retry-delay>5</retry-delay>
                <run-on>300</run-on>
</relay>

We stream up to 1000 Icecast servers through a number relay servers. When we reach about 800 active streams in the relay server config, we notice the same debug entries.

on the listener side, they get up to 5 seconds of silence while the relay restarts. 


[2017-07-13  15:17:48] INFO format-mp3/parse_icy_metadata incoming title for /70e739c0/listen Unknown
[2017-07-13  15:18:13] INFO slave/relay_reset servers to be retried on /70e739c0/listen
[2017-07-13  15:18:13] INFO slave/relay_read fallback on /70e739c0/listen not attempted
[2017-07-13  15:18:13] INFO source/source_shutdown Source "/70e739c0/listen" exiting
[2017-07-13  15:18:13] INFO slave/relay_read standing by to restart relay on /70e739c0/listen
[2017-07-13  15:18:13] INFO source/source_apply_mount Applying mount information for "/70e739c0/listen" from "/*"
[2017-07-13  15:18:16] INFO source/source_add_listener max on /70e739c0/listen is -1 (cur 0)
[2017-07-13  15:18:16] INFO slave/relay_startup starting on-demand relay /70e739c0/listen
[2017-07-13  15:18:16] INFO slave/start_relay_stream Starting relayed source at mountpoint "/70e739c0/listen"
[2017-07-13  15:18:16] INFO slave/open_relay_connection connecting to example.server.com:1234 for /70e739c0/listen
[2017-07-13  15:18:17] INFO format-mp3/mpeg_apply_client icy metadata format expected on /70e739c0/listen, interval 16000
[2017-07-13  15:18:17] INFO source/source_init Source /70e739c0/listen initialised
[2017-07-13  15:18:17] INFO source/source_apply_mount Applying mount information for "/70e739c0/listen" from "/*"
[2017-07-13  15:18:17] INFO slave/start_relay_stream source /70e739c0/listen is ready to start
[2017-07-13  15:18:17] INFO source/source_read listener count on /70e739c0/listen now 1
[2017-07-13  15:18:17] INFO source/source_set_override no override for /70e739c0/listen set
[2017-07-13  15:18:17] INFO format-mp3/parse_icy_metadata incoming title for /70e739c0/listen Unknown
karlheyes commented 6 years ago

That log sample is not saying anything about the last listener disconnecting so it's not easy to see the run-on applying or not. I tried it here and the run-on is fine. Obviously 10k clients should be plenty for 800 streams and 9000+ listeners. A delay in the relay starting up, like a timeout or things just running slowly would show as a delay for the listeners at startup, again though, hard to tell from this output alone.

karl.