Icecast - Nov 2004 - ices2 not re-connecting on live stream

hi everyone, congratulations on the release of icecast 2.1.0

I presume this is the right place to post about iceS. please correct if 
wrong.

I have a two instance setup, and have been finding that after a network 
error occurs, the instance does not reconnect.

The source server is behind a linux NAT box.

I have simulated the problem by using iptables REJECT with tcp-reset and 
here is the resulting log file from iceS:

ice@debian:~$ /usr/local/bin/ices /usr/local/share/ices/live_debug.xml
[ 02:17:19] INFO ices-core/main IceS 2.0.0 started...
[ 02:17:19] INFO input-alsa/alsa_open_module Opened audio device plughw:0,0
[ 02:17:19] INFO input-alsa/alsa_open_module using 2 channel(s), 44100 
Hz, buffer 371 ms (2 periods)
[ 02:17:19] INFO input-alsa/alsa_open_module Starting metadata update thread
[ 02:17:19] INFO encode/encode_initialise Encoder initialising in VBR 
mode: 2 channel(s), 44100 Hz, quality 0.500000
[ 02:17:19] INFO audio/downmix_initialise Enabling stereo->mono downmixing
[ 02:17:19] INFO audio/resample_initialise Initialised resampler for 1 
channels, from 44100 Hz to 11025 Hz
[ 02:17:19] INFO encode/encode_initialise Encoder initialising with 
bitrate management: 1 channels, 11025 Hz, minimum bitrate 16000, nominal 
20000, maximum 24000
[ 02:17:19] INFO signals/signal_usr1_handler Metadata update requested
[ 02:17:19] DBUG metadata/metadata_thread_signal meta thread wakeup
[ 02:17:19] DBUG metadata/metadata_thread_signal reading metadata from 
"/home/ice/metadata"
[ 02:17:19] INFO metadata/metadata_thread_signal tag 1 is artist=Near FM 
101.6
[ 02:17:19] INFO metadata/metadata_thread_signal tag 2 is title=Live
[ 02:17:19] INFO metadata/metadata_thread_signal Updating metadata
[ 02:17:20] INFO stream/ices_instance_stream Connected to server: 
radioserver:8000/radio_low.ogg
[ 02:17:20] INFO audio/resample_initialise Initialised resampler for 1 
channels, from 44100 Hz to 11025 Hz
[ 02:17:20] DBUG encode/encode_clear Clearing encoder engine
[ 02:17:20] INFO encode/encode_initialise Encoder initialising with 
bitrate management: 1 channels, 11025 Hz, minimum bitrate 16000, nominal 
20000, maximum 24000
[ 02:17:20] INFO stream/ices_instance_stream Connected to server: 
radioserver:8000/radio.ogg
[ 02:17:20] DBUG encode/encode_clear Clearing encoder engine
[ 02:17:20] INFO encode/encode_initialise Encoder initialising in VBR 
mode: 2 channel(s), 44100 Hz, quality 0.500000

At this point, I simulate loss of network connectivity:

[ 02:17:43] EROR stream/ices_instance_stream Send error: Socket error 
(Connection reset by peer)
[ 02:17:43] DBUG input/input_flush_queue Input queue flush requested
[ 02:17:43] WARN stream/ices_instance_stream Trying reconnect after 
server socket error
[ 02:17:44] EROR stream/ices_instance_stream Failed to reconnect to 
radioserver:8000 (Login failed)
[ 02:17:46] WARN stream/ices_instance_stream Trying reconnect after 
server socket error
[ 02:17:47] EROR stream/ices_instance_stream Failed to reconnect to 
radioserver:8000 (Login failed)
[ 02:17:49] WARN stream/ices_instance_stream Trying reconnect after 
server socket error
[ 02:17:49] EROR stream/ices_instance_stream Failed to reconnect to 
radioserver:8000 (Login failed)
[ 02:17:51] WARN stream/ices_instance_stream Trying reconnect after 
server socket error
[ 02:17:52] EROR stream/ices_instance_stream Failed to reconnect to 
radioserver:8000 (Login failed)
[ 02:17:54] WARN stream/ices_instance_stream Trying reconnect after 
server socket error

Restore network connectivity:

[ 02:17:55] INFO stream/ices_instance_stream Connected to server: 
radioserver:8000/radio_low.ogg
[ 02:17:55] DBUG input/input_flush_queue Input queue flush requested

only, the stream has not reconnected.

the source box netstat shows:
tcp        1      0 192.168.1.20:32822      radioserver:8000 CLOSE_WAIT
tcp       27      0 192.168.1.20:32820      radioserver:8000 CLOSE_WAIT
tcp       27      0 192.168.1.20:32821      radioserver:8000 CLOSE_WAIT
tcp       27      0 192.168.1.20:32818      radioserver:8000 CLOSE_WAIT
tcp       27      0 192.168.1.20:32819      radioserver:8000 CLOSE_WAIT
tcp        0   4107 192.168.1.20:32816      radioserver:8000 ESTABLISHED

The ESTABLISHED connection is the instance which didn't get blocked by 
iptables.
and those sockets seem to remain in CLOSE_WAIT until i kill the ices 
process.

any help is much appreciated.
thanks,
Keith.

On Wed, Nov 24, 2004 at 07:26:27PM -0600, Keith Whyte
wrote:
> I have a two instance setup, and have been finding that after a network 
> error occurs, the instance does not reconnect.
> 
> The ESTABLISHED connection is the instance which didn't get blocked by 
> iptables.
> and those sockets seem to remain in CLOSE_WAIT until i kill the ices 
> process.
This sounds similar to what I encountered when I first set up ices2 --
see <http://lists.xiph.org/pipermail/icecast/2004-July/007364.html>.

In short, if you're streaming over a WAN, the main ices2 branch is
woefully inadequate, and you ought to try Karl Heyes' branch at
<http://mediacast1.com/~karl/>, as he described in his reply to my
original email.  (Don't get ices 2.0.1, which is merely a point release
and doesn't incorporate Karl's changes.)

If you let ices2 run for a long time, you'll probably need this patch as
well:

--- ices2-2.0.0-kh59.orig/src/input.c
+++ ices2-2.0.0-kh59/src/input.c
@@ -335,6 +335,7 @@
                 if (next_mod->open_module (next_mod) == 0)
                 {
                     next_mod->start = start;
+		    next_mod->failures = 0;
                     ices_config->next_track = 0;
                     return next_mod;
                 }


I've been running ices2 like this 24/7 for months now, only restarting
it once a week for log rotation.  Never had a problem since.


-- 
             Fr?d?ric Bri?re    <*>    fbriere@fbriere.net

 =>  <fbriere@abacom.com> IS NO MORE: 
<http://www.abacomsucks.com>  <=

On Sun, 2005-02-20 at 12:15, Fr?d?ric Bri?re wrote:
> I've been running ices2 like this 24/7 for months now, only restarting
> it once a week for log rotation.  Never had a problem since.
setting <logsize> will cause an automatic log rotation when a certain
file size has been reached. It renames <logfile> to <logfile>.1 then
opens a new file <logfile>

karl.