Hi: I'm running ices on one box with three streams, one streaming as is and two re-encodes, and another box running icecast2. The straight-through stream is going strong, but the two re-encodes have died. Ices is trying to re-establish them, but it keeps saying it gets a broken pipe, as evidenced below: [2004-03-09 10:47:55] INFO encode/encode_initialise Encoder initialising in VBR mode: 2 channel(s), 44100 Hz, quality 0.000000 [2004-03-09 10:47:56] EROR stream/ices_instance_stream Send error: Socket error (Broken pipe) [2004-03-09 10:47:56] DBUG input/input_flush_queue Input queue flush requested [2004-03-09 10:47:56] WARN stream/ices_instance_stream Trying reconnect after server socket error [2004-03-09 10:47:56] EROR stream/ices_instance_stream Send error: Socket error (Broken pipe) [2004-03-09 10:47:56] DBUG input/input_flush_queue Input queue flush requested [2004-03-09 10:47:56] WARN stream/ices_instance_stream Trying reconnect after server socket error [2004-03-09 10:47:57] INFO stream/ices_instance_stream Connected to server: linux-speakup.org:9000/egoplay24.ogg [2004-03-09 10:47:57] DBUG input/input_flush_queue Input queue flush requested [2004-03-09 10:47:57] INFO stream/ices_instance_stream Connected to server: linux-speakup.org:9000/egoplay64.ogg [2004-03-09 10:47:57] DBUG input/input_flush_queue Input queue flush requested and this cycle repeats. There's not much of help in the icecast error log. I had to grep for "source" because of all the YP activity (see below), but it seems as if ices isn't sending anything down the line. [2004-03-09 10:47:56] INFO connection/_handle_source_request Source logging in at mountpoint "/egoplay24.ogg" [2004-03-09 10:47:56] INFO connection/_handle_source_request Source logging in at mountpoint "/egoplay64.ogg" [2004-03-09 10:47:57] DBUG source/source_main Source creation complete [2004-03-09 10:47:57] DBUG source/source_main Source creation complete [2004-03-09 10:48:07] WARN source/source_main Disconnecting source: socket timeout (10 s) expired [2004-03-09 10:48:07] INFO source/source_main Removing source following disconnection [2004-03-09 10:48:07] INFO source/source_main Source "/egoplay24.ogg" exiting [2004-03-09 10:48:07] WARN source/source_main Disconnecting source: socket timeout (10 s) expired [2004-03-09 10:48:07] INFO source/source_main Removing source following disconnection [2004-03-09 10:48:07] INFO source/source_main Source "/egoplay64.ogg" exiting Note that I don't think the two clocks are sinched, so don't try to align the two sets of times. The access log is even less helpful. 129.100.249.144 - - [09/Mar/2004:10:43:50 -0500] "SOURCE /egoplay24.ogg HTTP/1.0" 200 19 "-" "IceS 2.0-Beta4" 11 129.100.249.144 - - [09/Mar/2004:10:43:51 -0500] "SOURCE /egoplay64.ogg HTTP/1.0" 200 19 "-" "IceS 2.0-Beta4" 12 129.100.249.144 - - [09/Mar/2004:10:48:07 -0500] "SOURCE /egoplay64.ogg HTTP/1.0" 200 19 "-" "IceS 2.0-Beta4" 11 129.100.249.144 - - [09/Mar/2004:10:48:12 -0500] "SOURCE /egoplay24.ogg HTTP/1.0" 200 19 "-" "IceS 2.0-Beta4" 16 129.100.249.144 - - [09/Mar/2004:10:51:38 -0500] "SOURCE /egoplay24.ogg HTTP/1.0" 200 19 "-" "IceS 2.0-Beta4" 10 129.100.249.144 - - [09/Mar/2004:10:51:38 -0500] "SOURCE /egoplay64.ogg HTTP/1.0" 200 19 "-" "IceS 2.0-Beta4" 10 Unfortunately, I don't have the ices log for when the problem started. For some hither-to unknown reason, the ices log starts at just before 19 hours on Sunday, by which time this had already started. I'm running ices 2.0beta4 from Debian Unstable, along with libogg 1.1 and libvorbis 1.01 packages. Libshout is 2.0, also in Debian Unstable. I'm also running icecast 2.0 (compiled from source) with GCC 2.95.4, against libogg 1.1 and libvorbis 1.01 (both compiled from source), and libcurl 7.10.5 (also compiled from source). This is running on a Debian 3.0 (aka Woody) system. Another, quite likely unrelated question, is that the YP stuff seems to be doing a hell of a lot. at one stage, I could see only 2 seconds worth of activity on the screen, with all the YP debug stuff. Is there some specific delay time between YP touches? I do of course realise that ices trying to reconnect may be causing this and not the other way around, it's just that there's nothing in the icecast config that defines how often to touch the YP servers (at least as far as I can see). I've been running the server since Saturday and the error log is 61.3 meg. Any help with either would be appreciated. Geoff. <p>--- >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-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:
As an adendum, we restarted ices without touching icecast. All three
streams came up and seem to be stable.
I note from the stats page that the two re-encoded streams died on the same
song. Here is the output of ogginfo running on that file. Note the stuff
at the bottom.
Processing file
"/var/music/Emerson,_Lake_&_Palmer/Pictures_At_An_Exhibition/11-The_Great_Gates_Of_Kiev._The_End.ogg"...
New logical stream (#1, serial: 638b57af): type vorbis
Vorbis headers parsed for stream 1, information follows...
Version: 0
Vendor: Xiph.Org libVorbis I 20030909 (1.0.1)
Channels: 2
Rate: 44100
Nominal bitrate: 112.001000 kb/s
Upper bitrate not set
Lower bitrate not set
User comments section follows...
ARTIST=Emerson, Lake & Palmer
ALBUM=Pictures At An Exhibition
TITLE=The Great Gates Of Kiev. The End
DATE=1971
GENRE=Rock
TRACKNUMBER=11
Vorbis stream 1:
Total data length: 4184073 bytes
Playback length: 5m:06.371s
Average bitrate: 109.254946 kbps
Logical stream 1 ended
Warning: Invalid header page, no packet found
Warning: Invalid header page in stream 2, contains multiple packets
New logical stream (#2, serial: 2cf8d192): type invalid
Warning: stream start flag not set on stream 2
Warning: sequence number gap in stream 2. Got page 984 when expecting page
0. Indicates missing data.
Logical stream 2 ended
We've no idea how this came about. The guy who ripped it uses ABCDE which
calls oggenc to do the encoding. The vendor tag suggests that the oggenc
used is that which is contained in vorbis-tools 1.0.1. The rip was
apparently done during the last week in december. the really odd thing is
that tracks 10 and 11 are affected like this, whereas tracks 1-9 and 12 are
fine.
anyway, I guess that's possibly what put ices into a weird state.
Geoff.
--- >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-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 Tue, 2004-03-09 at 16:17, Geoff Shang wrote:> Hi: > > I'm running ices on one box with three streams, one streaming as is and two > re-encodes, and another box running icecast2. > > The straight-through stream is going strong, but the two re-encodes have > died. Ices is trying to re-establish them, but it keeps saying it gets a > broken pipe, as evidenced below:...> There's not much of help in the icecast error log. I had to grep for > "source" because of all the YP activity (see below), but it seems as if > ices isn't sending anything down the line.This can happen unfortunately with the current ices code base, the back end does not cache what it needs to resume nicely, and it's not so easy to change without some fairly big changes. I suspect the workaround is to send a USR1 signal on re-connection, so that the headers can kick in or use the ices-kh mods which cache the necessary info.> Unfortunately, I don't have the ices log for when the problem started. For > some hither-to unknown reason, the ices log starts at just before 19 hours > on Sunday, by which time this had already started.Thats probably because of the log size, ~2Meg at the moment, I'm thinking of making that configurable.> Another, quite likely unrelated question, is that the YP stuff seems to be > doing a hell of a lot. at one stage, I could see only 2 seconds worth of > activity on the screen, with all the YP debug stuff. Is there some > specific delay time between YP touches? I do of course realise that ices > trying to reconnect may be causing this and not the other way around, it's > just that there's nothing in the icecast config that defines how often to > touch the YP servers (at least as far as I can see). I've been running the > server since Saturday and the error log is 61.3 meg.On source connection, the YP update is flagged, so you are probably seeing an effect of ices reconnecting. The YP side of icecast needs to be fixed up as well (that's in progress) as it is too verbose as is. karl. <p>--- >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-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.