Icecast dev - Aug 2004 - Icecast source number problem, ices frozen after reconnect attemps failure (icecastkh13 iceskh48)

Hello,

I had a problem with ices kh48 and icecastkh13. I usually restart them by cron
at 00:00.

----------1----------
This night, icecast told ices "Too many sources" for
radio-bro-gwened.ogg...
All right, I've just seen that my config file is wrong for icecast (I have 3
sources):
            <sources>2</sources>
But, with this configuration, I can have 3 sources:
------------ TEXT COPY OF /listmounts.xsl ----------------
(/radio-bro-gwened-default.ogg) 0 Listener(s)
List Clients 	Move Clients 	Kill Source
(/radio-bro-gwened.mp3) 0 Listener(s)
List Clients 	Move Clients 	Kill Source
(/radio-bro-gwened.ogg) 1 Listener(s)
List Clients 	Move Clients 	Kill Source
----------------------------------------------------------
so even if config file says 2 sources max, I can have three, but sometime,
icecast restricts to the asked value: 2

<p>So, I will correct my config file, but icecast should refuse always a
third source.

<p>-------------2----------
ices could'nt connect because of the source limitation. ok.
But ices process are still alive at 10am.... I killed then, they have been
relaunched by my launcher and ices connects to icecast and then everything goes
right... without changing anything in the config file.
So, if it fails to connect to the server, it does several trial 
(<reconnectdelay>3</reconnectdelay><reconnectattempts>20</reconnectattempts>)
and then froze and stays alive... this prevent any further automatic restart of
ices. My launcher didn't notice ices is frozen (because processes are still
alive) and did nothing instead of restarting it.

Should ices do a shutdown after finishing unsuccessfully its reconnect attempts?

Thanks,
Chris

<p><p><p>########################################################################################
ON ICECAST SIDE
########################################################################################
########################################################################################
[2003-11-26  00:00:04] INFO format-vorbis/vorbis_get_buffer End of Stream
/radio-bro-gwened.ogg
[2003-11-26  00:00:04] INFO source/source_main Source
"/radio-bro-gwened.ogg" exiting
[2003-11-26  00:00:04] INFO source/source_main passing 1 listeners to
/radio-bro-gwened-default.ogg
[2003-11-26  00:00:05] INFO format-mp3/mp3_get_no_meta End of stream
/radio-bro-gwened.mp3
[2003-11-26  00:00:05] INFO source/source_main Source
"/radio-bro-gwened.mp3" exiting
[2003-11-26  00:00:05] DBUG source/source_main Adding 1 client(s)
[2003-11-26  00:00:06] INFO sighandler/_sig_die Caught signal 15, shutting
down...
[2003-11-26  00:00:06] INFO sighandler/_sig_die Caught signal 15, shutting
down...
[2003-11-26  00:00:06] INFO sighandler/_sig_die Caught signal 15, shutting
down...
[2003-11-26  00:00:06] INFO sighandler/_sig_die Caught signal 15, shutting
down...
[2003-11-26  00:00:06] INFO source/source_main Source
"/radio-bro-gwened-default.ogg" exiting
[2003-11-26  00:00:06] INFO main/main Shutting down
[2003-11-26  00:00:04] INFO main/main Icecast 2.0-kh13 server started
[2003-11-26  00:00:05] INFO slave/update_relays Updating relays
[2003-11-26  00:00:07] INFO connection/_handle_source_request Source logging in
at mountpoint "/radio-bro-gwened.mp3"
[2003-11-26  00:00:07] DBUG connection/connection_complete_source matching mount
settings
[2003-11-26  00:00:07] DBUG connection/connection_complete_source mountinfo
/radio-bro-gwened.mp3 fallback /radio-bro-gwened-default.mp3
[2003-11-26  00:00:07] DBUG source/source_main Source creation complete
[2003-11-26  00:00:07] INFO connection/_handle_source_request Source logging in
at mountpoint "/radio-bro-gwened-default.ogg"
[2003-11-26  00:00:07] DBUG connection/connection_complete_source matching mount
settings
[2003-11-26  00:00:07] DBUG source/source_main Source creation complete
[2003-11-26  00:00:07] DBUG connection/_handle_get_request Client connected
[2003-11-26  00:00:07] DBUG admin/admin_handle_request Got command (metadata)
[2003-11-26  00:00:07] INFO admin/admin_handle_request Received admin command
metadata on mount "/radio-bro-gwened.mp3"
[2003-11-26  00:00:07] DBUG admin/command_metadata Got metadata update request
[2003-11-26  00:00:07] INFO admin/command_metadata Metadata on mountpoint
/radio-bro-gwened.mp3 changed to "-"
[2003-11-26  00:00:09] INFO connection/_handle_source_request Source logging in
at mountpoint "/radio-bro-gwened.ogg"
[2003-11-26  00:00:09] INFO source/source_alloc Too many sources

....

[2003-11-26  00:01:03] INFO connection/_handle_source_request Source logging in
at mountpoint "/radio-bro-gwened.ogg"
[2003-11-26  00:01:03] INFO source/source_alloc Too many sources
[2003-11-26  00:01:06] INFO connection/_handle_source_request Source logging in
at mountpoint "/radio-bro-gwened.ogg"
[2003-11-26  00:01:06] INFO source/source_alloc Too many sources

<p><p>########################################################################################
ON ICES SIDE 
########################################################################################
root     19320  0.0  2.6  9352 3396 ?        S    00:00   0:00  \_
/usr/radio/bin/ices /usr/radio/tmp/ices_conf.30966.xml
root     19326  0.0  2.6  9352 3396 ?        S    00:00   0:00  |   \_
/usr/radio/bin/ices /usr/radio/tmp/ices_conf.30966.xml
root     19327  0.0  2.6  9352 3396 ?        S    00:00   0:03  |       \_
/usr/radio/bin/ices /usr/radio/tmp/ices_conf.30966.xml
root     19328  1.1  2.6  9352 3396 ?        S    00:00   7:41  |       \_
/usr/radio/bin/ices /usr/radio/tmp/ices_conf.30966.xml

########################################################################################

[2003-11-25  19:53:13] INFO audio/downmix_initialise Enabling stereo->mono
downmixing
[2003-11-25  19:53:13] INFO audio/resample_initialise Initialised resampler for
1 channels, from 44100 Hz to 19404 Hz
[2003-11-25  19:53:13] INFO encode/encode_setup Encoder initialising with
bitrate management: 1 channels, 19404 Hz, minimum bitrate 0, nominal 25000,
maximum 0
[2003-11-25  19:53:13] DBUG stream/_output_oggpacket seen new stream, better get
headers
[2003-11-25  19:53:13] DBUG stream/_output_oggpacket samplerate is 19404,
channels is 1
[2003-11-25  19:53:16] DBUG om_shout/check_shout_connected Time we started
stream on 82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-25  19:53:17] INFO om_shout/check_shout_connected Connected to server:
82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-25  19:53:17] DBUG om_shout/output_ogg_shout initialising output stream
[2003-11-26  00:00:01] INFO input-pcm/pcm_read No more data available
[2003-11-26  00:00:01] INFO input/input_loop Closing input module
[2003-11-26  00:00:01] INFO input-pcm/pcm_close_module Closing PCM input module
[2003-11-26  00:00:01] DBUG input/open_next_input_module checking module 1

<p>...

[2003-11-26  00:00:01] WARN input/open_next_input_module restarted input within
2 seconds, it probably failed
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM to skip
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM from
standard input
[2003-11-26  00:00:01] DBUG input-pcm/pcm_read metadata updates flagged
[2003-11-26  00:00:01] INFO input-pcm/pcm_read No more data available
[2003-11-26  00:00:01] INFO input/input_loop Closing input module
[2003-11-26  00:00:01] INFO input-pcm/pcm_close_module Closing PCM input module
[2003-11-26  00:00:01] DBUG input/open_next_input_module checking module 1
[2003-11-26  00:00:01] WARN input/open_next_input_module restarted input within
2 seconds, it probably failed
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM to skip
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM from
standard input
[2003-11-26  00:00:01] DBUG input-pcm/pcm_read metadata updates flagged
[2003-11-26  00:00:01] INFO input-pcm/pcm_read No more data available
[2003-11-26  00:00:01] INFO input/input_loop Closing input module
[2003-11-26  00:00:01] INFO input-pcm/pcm_close_module Closing PCM input module
[2003-11-26  00:00:01] DBUG input/open_next_input_module checking module 1
[2003-11-26  00:00:01] WARN input/open_next_input_module restarted input within
2 seconds, it probably failed
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM to skip
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM from
standard input
[2003-11-26  00:00:01] DBUG input-pcm/pcm_read metadata updates flagged
[2003-11-26  00:00:01] INFO input-pcm/pcm_read No more data available
[2003-11-26  00:00:01] INFO input/input_loop Closing input module
[2003-11-26  00:00:01] INFO input-pcm/pcm_close_module Closing PCM input module
[2003-11-26  00:00:01] DBUG input/open_next_input_module checking module 1
[2003-11-26  00:00:01] WARN input/open_next_input_module restarted input within
2 seconds, it probably failed
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM to skip
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM from
standard input
[2003-11-26  00:00:01] DBUG input-pcm/pcm_read metadata updates flagged
[2003-11-26  00:00:01] INFO input-pcm/pcm_read No more data available
[2003-11-26  00:00:01] INFO input/input_loop Closing input module
[2003-11-26  00:00:01] INFO input-pcm/pcm_close_module Closing PCM input module
[2003-11-26  00:00:01] DBUG input/open_next_input_module checking module 1
[2003-11-26  00:00:01] WARN input/open_next_input_module restarted input within
2 seconds, it probably failed
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM to skip
[2003-11-26  00:00:01] INFO input-pcm/pcm_open_module Retrieving PCM from
standard input
[2003-11-26  00:00:01] DBUG input-pcm/pcm_read metadata updates flagged
[2003-11-26  00:00:01] INFO input-pcm/pcm_read No more data available
[2003-11-26  00:00:01] INFO input/input_loop Closing input module
[2003-11-26  00:00:01] INFO input-pcm/pcm_close_module Closing PCM input module
[2003-11-26  00:00:01] DBUG input/open_next_input_module checking module 1
[2003-11-26  00:00:01] WARN input/open_next_input_module Too many failures on
input module 1 (pcm)
[2003-11-26  00:00:01] DBUG input/input_loop All input stopped, shutting down.
[2003-11-26  00:00:01] DBUG stream/runner_close Runner thread 1 shutting down
[2003-11-26  00:00:01] DBUG stream/ices_runner Runner thread 1 cleaning up
streams
[2003-11-26  00:00:01] DBUG stream/stream_cleanup Cleanup of stream 1 required
[2003-11-26  00:00:01] DBUG stream/flush_ogg_packets Flushing out encoded ogg
packets stream 1
[2003-11-26  00:00:01] DBUG stream/_output_oggpacket packet marked with EOS seen
[2003-11-26  00:00:01] DBUG encode/encode_free Freeing encoder engine
[2003-11-26  00:00:01] DBUG stream/output_clear Clearing up output state
[2003-11-26  00:00:01] DBUG om_shout/_output_connection_close closed shout
connection
[2003-11-26  00:00:01] DBUG stream/ices_runner Runner thread 1 finshed
[2003-11-26  00:00:01] DBUG input/free_modules freeing up module storage
[2003-11-26  00:00:01] INFO ices-core/main Shutdown in progress
[2003-11-26  00:00:04] INFO ices-core/main Streamer version IceS 2.0-kh48
[2003-11-26  00:00:04] INFO ices-core/main libshout version 2.0-kh22
[2003-11-26  00:00:04] INFO ices-core/main realtime scheduling has been enabled
[2003-11-26  00:00:04] DBUG stream/start_runners starting runner
[2003-11-26  00:00:04] INFO stream/ices_runner Runner 1 ready
[2003-11-26  00:00:04] INFO input-pcm/pcm_initialise_module Initialising PCM
input module
[2003-11-26  00:00:04] DBUG input-pcm/pcm_initialise_module Module PCM using
buffers of 4096 samples
[2003-11-26  00:00:04] DBUG input/initialise_input_modules Module 1 (pcm) has 20
buffers
[2003-11-26  00:00:04] DBUG input/open_next_input_module checking module 1
[2003-11-26  00:00:04] INFO input-pcm/pcm_open_module Retrieving PCM to skip
[2003-11-26  00:00:04] INFO input-pcm/pcm_open_module Retrieving PCM from
standard input
[2003-11-26  00:00:04] DBUG input-pcm/pcm_read metadata updates flagged
[2003-11-26  00:00:05] INFO stream/process_encode_init Restarting encoder for
PCM input on stream 1
[2003-11-26  00:00:05] INFO audio/downmix_initialise Enabling stereo->mono
downmixing
[2003-11-26  00:00:05] INFO audio/resample_initialise Initialised resampler for
1 channels, from 44100 Hz to 19404 Hz
[2003-11-26  00:00:05] INFO encode/encode_setup Encoder initialising with
bitrate management: 1 channels, 19404 Hz, minimum bitrate 0, nominal 25000,
maximum 0
[2003-11-26  00:00:05] DBUG stream/_output_oggpacket seen new stream, better get
headers
[2003-11-26  00:00:05] DBUG stream/_output_oggpacket samplerate is 19404,
channels is 1
[2003-11-26  00:00:09] DBUG om_shout/check_shout_connected Time we started
stream on 82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-26  00:00:09] EROR om_shout/check_shout_connected Failed to connect to
82.67.34.81:443/radio-bro-gwened.ogg (Login failed)
[2003-11-26  00:00:09] DBUG om_shout/_output_connection_close closed shout
connection
[2003-11-26  00:00:12] DBUG om_shout/check_shout_connected Time we started
stream on 82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-26  00:00:12] EROR om_shout/check_shout_connected Failed to connect to
82.67.34.81:443/radio-bro-gwened.ogg (Login failed)
[2003-11-26  00:00:12] DBUG om_shout/_output_connection_close closed shout
connection
[2003-11-26  00:00:15] DBUG om_shout/check_shout_connected Time we started
stream on 82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-26  00:00:15] EROR om_shout/check_shout_connected Failed to connect to
82.67.34.81:443/radio-bro-gwened.ogg (Login failed)
[2003-11-26  00:00:15] DBUG om_shout/_output_connection_close closed shout
connection

...

[2003-11-26  00:01:03] DBUG om_shout/check_shout_connected Time we started
stream on 82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-26  00:01:03] EROR om_shout/check_shout_connected Failed to connect to
82.67.34.81:443/radio-bro-gwened.ogg (Login failed)
[2003-11-26  00:01:03] DBUG om_shout/_output_connection_close closed shout
connection
[2003-11-26  00:01:06] DBUG om_shout/check_shout_connected Time we started
stream on 82.67.34.81:443/radio-bro-gwened.ogg
[2003-11-26  00:01:06] EROR om_shout/check_shout_connected Failed to connect to
82.67.34.81:443/radio-bro-gwened.ogg (Login failed)
[2003-11-26  00:01:06] DBUG om_shout/_output_connection_close closed shout
connection
[2003-11-26  00:01:06] INFO om_shout/check_shout_connected giving up stream on
82.67.34.81:443/radio-bro-gwened.ogg
--- >8 ----
List archives:  http://www.xiph.org/archives/
icecast project homepage: http://www.icecast.org/
To unsubscribe from this list, send a message to
'icecast-dev-request@xiph.org'
containing only the word 'unsubscribe' in the body.  No subject is
needed.
Unsubscribe messages sent to the list will be ignored/filtered.

On Wed, 2003-11-26 at 10:17, iceuse@kezako.net wrote:
> Hello,
> 
> I had a problem with ices kh48 and icecastkh13. I usually restart them by
cron at 00:00.
> 
> ----------1----------
> This night, icecast told ices "Too many sources" for
radio-bro-gwened.ogg...
> All right, I've just seen that my config file is wrong for icecast (I
have 3 sources):
>             <sources>2</sources>
...
> so even if config file says 2 sources max, I can have three, but sometime,
icecast restricts to the asked value: 2
hmm, ok I'll look into this.. Do you have any relays defined ?
> -------------2----------
> ices could'nt connect because of the source limitation. ok.
> But ices process are still alive at 10am.... I killed then, they have been
relaunched by my launcher and ices connects to icecast and then everything goes
right... without changing anything in the config file.
> So, if it fails to connect to the server, it does several trial 
>
(<reconnectdelay>3</reconnectdelay><reconnectattempts>20</reconnectattempts>)
> and then froze and stays alive... this prevent any further automatic
restart of ices. My launcher didn't notice ices is frozen (because processes
are still alive) and did nothing instead of restarting it.
> 
> Should ices do a shutdown after finishing unsuccessfully its reconnect
attempts?
The reconnectattempts value is from the CVS code, and can be a bit awkward
in general.

ices can have multiple instances and in these mods can have multiple shout
connections per instance.  I don't think terminating ices for just one shout
connection is acceptable, I'm more inclined to drop the reconnectattempts
completely and treating it as indefinite. Use a value of -1 now for the same
effect.

karl

--- >8 ----
List archives:  http://www.xiph.org/archives/
icecast project homepage: http://www.icecast.org/
To unsubscribe from this list, send a message to
'icecast-dev-request@xiph.org'
containing only the word 'unsubscribe' in the body.  No subject is
needed.
Unsubscribe messages sent to the list will be ignored/filtered.

No, I don't have any relay.

For ices, yes, 
>I'm more inclined to drop the reconnectattempts
completely and treating it as indefinite

yes, that may be better than waiting nothing. But perhaps reconnect delay can be
increased after each loop for all attempts...
to avoid too many logging...

Chris
--- >8 ----
List archives:  http://www.xiph.org/archives/
icecast project homepage: http://www.icecast.org/
To unsubscribe from this list, send a message to
'icecast-dev-request@xiph.org'
containing only the word 'unsubscribe' in the body.  No subject is
needed.
Unsubscribe messages sent to the list will be ignored/filtered.

Hi,

On 2003.11.26 15:42 Karl Heyes wrote:
> The reconnectattempts value is from the CVS code, and can be a bit awkward
> in general.
> 
> ices can have multiple instances and in these mods can have multiple shout
> connections per instance.  I don't think terminating ices for just one
> shout
> connection is acceptable, I'm more inclined to drop the
reconnectattempts
> completely and treating it as indefinite. Use a value of -1 now for the
> same
> effect.
That would be a showstopper for me. I _need_ ices to terminate if it cannot 
connect successfully. This ought to be an option, IMHO.

Melanie
--- >8 ----
List archives:  http://www.xiph.org/archives/
icecast project homepage: http://www.icecast.org/
To unsubscribe from this list, send a message to
'icecast-dev-request@xiph.org'
containing only the word 'unsubscribe' in the body.  No subject is
needed.
Unsubscribe messages sent to the list will be ignored/filtered.