Error messages - help needed

[lion1108]

Dear all,

can someone tell me what the root cause is for following messages in the error logfile:
(Using SHOUTcast Server v2.0.0.29/posix(linux x64) with Centova as MGT software and CentOS as linux OS)

(1) 2013-07-02 16:10:45 E msg:[DST e179036250.adsl.alicedsl.de:20657 sid=1] Socket error while waiting to send data. err=Broken pipe(32)

(2) 2013-07-02 16:10:46 E msg:[DST 2-235-11-41.ip225.fastwebnet.it:50724 sid=1] Timeout waiting to send data (1372774246 1372774216[30] )

(3) 2013-07-02 16:10:46 E msg:[DST exchange.paradine.at:49313 sid=1] SHOUTcast 1 client connection rejected. Stream not available. Mozilla/5.0 (Windows NT 6.1; rv:21.0) Gecko/20100101 Firefox/21.0

Background:
I am getting very often the socket error (1) messages during the whole day.
Several times during the day i am somehow "loosing" most of client connections after many messages (2) and (3).

My hosting provider and myself where looking at the ressources and at the network connections - no prblems during the streaming failures.

After the messages above i found following message:
(4) 2013-07-02 16:10:47 I msg:[SRC 91.250.98.119:56722 sid=1] stream configuration complete. [type=SHOUTcast 2
mimeType=audio/mpeg
maxPayloadSize=16377
avgBitrate=128000
maxBitrate=128000
desiredBufferSize=320
minimumBufferSize=0
icyName=salsaclub.fm
icyGenre=Latin Salsa Tropicalia
icyURL=http://www.salsaclub.fm
icyPub=1]

Does this all tell me, that the shoutcast server did "reinitialize", "reset", or...?

If someone could give me a hint, and what to do, that would be very helpfull.

best regards from Vienna,
Georg

[DrO]

1) socket errors are normal and is some debugging output which was left enabled when it should not have been.

2) that's just a client which closed the connection but didn't do it properly. it relates to #1 with debug output that isn't needed (as you should see a client closed message just afterwards showing how long it was running for).

3) that one is pretty clear, the stream is not available and so it won't allow listener connections. and from the next part of your post, if the source is reconnecting, then at some point it has disconnected and that would explain the blocking of listener connections. for that, you need to find out why it's disconnecting / try to improve the reliability of the connection between the source and the DNAS.

[lion1108]

Thanks for the reply so far.

I do not know where exactly to look at, source and DNAS are running on the same virtual machine (Cloud Based).
Everything works pretty well.
But then, at least one time a day (randomly), everytime when i get such (3) "SHOUTcast 1 client connection rejected" messages, i have on the source log side following messages:
2013-08-30 15:13:04 E msg:[UVOX2] 1483609999 [UVOX2] 1483609999 socket send error.
2013-08-30 15:13:04 E msg:[UVOX2] 1483609999 Waiting 30 seconds

After 30 seconds the source then seems to "restart" or reininitialize:
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Creating stream socket
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Connecting to stream host
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Sending Ultravox 2.1 authentication
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Mime type
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Broadcast setup
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Negotiating buffer sizes
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Negotiated buffer size is 160KB
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Negotiating payload sizes
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Negotiated payload size is 16377
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Configuring ICY-NAME [salsaclub.fm]
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Configuring ICY-GENRE [Latin Salsa Tropicalia]
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Configuring ICY-URL [http://www.salsaclub.fm]
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Configuring ICY-PUB [1]
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Flush metadata
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Standby
2013-08-30 15:13:34 I msg:[UVOX2] 1483609999 Streaming
...and everything works fine again, until the next time when the source is sending out: "socket send error", and my listeners are discnnected again.

Can i get somehow more info, why the socket error occurs? What are the possible root causes for such source errors?

Can someone help, what to do next?

Best regards,
Georg

[DrO]

the lines before the socket error in the source's log would be more helpful, though as the log appears to be sc_trans output, without an updated sc_trans build (not available), for the time being you're going to have to put up with the random disconnect (if it's the issue i think it is which causes sc_trans to lock-up on some title updates - hence looking for the preceding part of the log output).

[lion1108]

Thx for quick reply ;-)

here is another timestamp:
Source Log:
"2013-09-01 21:11:42 I msg:[UVOX2] 1483609999 Sending metadata 3902 [525 bytes] content="
<?xml version="1.0" encoding="UTF-8" ?>
<metadata>
<TIT2>DEREK DAVID - SIN CITY</TIT2>
<extension>
" <title seq=""1"">DEREK DAVID - SIN CITY</title>"
" <title seq=""2"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""3"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""4"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <soon>nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</soon>"
</extension>
</metadata>

"2013-09-01 21:14:29 E msg:[UVOX2] 1483609999 [UVOX2] 1483609999 socket send error."
"2013-09-01 21:14:29 E msg:[UVOX2] 1483609999 Waiting 30 seconds"
"2013-09-01 21:14:29 E msg:[UVOX2] 131325653 [UVOX2] 131325653 socket send error."
"2013-09-01 21:14:29 E msg:[UVOX2] 131325653 Waiting 30 seconds"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Creating stream socket"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Connecting to stream host"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Sending Ultravox 2.1 authentication"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Mime type"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Broadcast setup"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Negotiating buffer sizes"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Negotiated buffer size is 160KB"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Negotiating payload sizes"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Negotiated payload size is 16377"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Configuring ICY-NAME [salsaclub.fm]"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Configuring ICY-GENRE [Latin Salsa Tropicalia]"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Configuring ICY-URL [http://www.salsaclub.fm]"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Configuring ICY-PUB [1]"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Flush metadata"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Standby"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Streaming"
"2013-09-01 21:14:55 I msg:[UVOX2] 1483609999 Sending metadata 3902 [525 bytes] content="
<?xml version="1.0" encoding="UTF-8" ?>
<metadata>
<TIT2>DEREK DAVID - SIN CITY</TIT2>
<extension>
" <title seq=""1"">DEREK DAVID - SIN CITY</title>"
" <title seq=""2"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""3"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""4"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <soon>nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</soon>"
</extension>
</metadata>

"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Creating stream socket"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Connecting to stream host"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Sending Ultravox 2.1 authentication"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Mime type"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Broadcast setup"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Negotiating buffer sizes"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Negotiated buffer size is 320KB"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Negotiating payload sizes"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Negotiated payload size is 16377"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Configuring ICY-NAME [salsaclub.fm]"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Configuring ICY-GENRE [Latin Salsa Tropicalia]"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Configuring ICY-URL [http://www.salsaclub.fm]"
"2013-09-01 21:14:59 I msg:[UVOX2] 131325653 Configuring ICY-PUB [1]"
"2013-09-01 21:15:00 I msg:[UVOX2] 131325653 Flush metadata"
"2013-09-01 21:15:00 I msg:[UVOX2] 131325653 Standby"
"2013-09-01 21:15:00 I msg:[UVOX2] 131325653 Streaming"
"2013-09-01 21:15:00 I msg:[UVOX2] 131325653 Sending metadata 3902 [525 bytes] content="
<?xml version="1.0" encoding="UTF-8" ?>
<metadata>
<TIT2>DEREK DAVID - SIN CITY</TIT2>
<extension>
" <title seq=""1"">DEREK DAVID - SIN CITY</title>"
" <title seq=""2"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""3"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""4"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <soon>nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</soon>"
</extension>
</metadata>

Streaming server Log:
"2013-09-01 21:11:49 I msg:[YP2] Connecting to yp.shoutcast.com"
"2013-09-01 21:12:04 I msg:[YP2] Connecting to yp.shoutcast.com"
"2013-09-01 21:12:15 I msg:[YP2] Connecting to yp.shoutcast.com"
"2013-09-01 21:12:23 I msg:[DST tmo-102-167.customers.d1-online.com:30381 sid=1] SHOUTcast 1 client connection accepted. radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)"
"2013-09-01 21:12:31 I msg:[DST tmo-102-167.customers.d1-online.com:27845 sid=1] SHOUTcast 1 client connection accepted. radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)"
"2013-09-01 21:12:50 E msg:[DST tmo-102-167.customers.d1-online.com:12488 sid=1] Timeout waiting to send data (1378062770 1378062740[30] )"
"2013-09-01 21:12:50 I msg:[DST tmo-102-167.customers.d1-online.com:12488 sid=1] SHOUTcast 1 client connection closed (76 seconds) [Bytes: 534201] Agent: `radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:12:50 I msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49725 sid=1] SHOUTcast 1 client connection accepted. radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)"
"2013-09-01 21:12:59 E msg:[DST tmo-102-167.customers.d1-online.com:30381 sid=1] Timeout waiting to send data (1378062779 1378062749[30] )"
"2013-09-01 21:12:59 I msg:[DST tmo-102-167.customers.d1-online.com:30381 sid=1] SHOUTcast 1 client connection closed (36 seconds) [Bytes: 74037] Agent: `radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:13:19 E msg:[DST tmo-102-167.customers.d1-online.com:27845 sid=1] Timeout waiting to send data (1378062799 1378062769[30] )"
"2013-09-01 21:13:19 I msg:[DST tmo-102-167.customers.d1-online.com:27845 sid=1] SHOUTcast 1 client connection closed (48 seconds) [Bytes: 225701] Agent: `radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:13:54 I msg:[DST ec2-54-246-66-165.eu-west-1.compute.amazonaws.com:10274 sid=1] SHOUTcast 1 client connection accepted. Java/1.7.0_15"
"2013-09-01 21:13:54 E msg:[DST ec2-54-246-66-165.eu-west-1.compute.amazonaws.com:10274 sid=1] Socket error while waiting to send data. err=Broken pipe(32)"
"2013-09-01 21:13:54 I msg:[DST ec2-54-246-66-165.eu-west-1.compute.amazonaws.com:10274 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 10136] Agent: `Java/1.7.0_15'"
"2013-09-01 21:14:29 E msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49177 sid=1] Socket error while waiting to send data. err=Broken pipe(32)"
"2013-09-01 21:14:29 I msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49177 sid=1] SHOUTcast 1 client connection closed (7243 seconds) [Bytes: 115750585] Agent: `NSPlayer/4.1.0.3925'"
"2013-09-01 21:14:29 I msg:[DST 87.114.145.247.plusnet.thn-ag1.dyn.plus.net:49167 sid=1] SHOUTcast 1 client connection accepted. iTunes/10.6.3 (Macintosh; PPC Mac OS X 10.5.8) AppleWebKit/534.50.2"
"2013-09-01 21:14:29 I msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49445 sid=1] SHOUTcast 1 client connection accepted. NSPlayer/4.1.0.3925"
"2013-09-01 21:14:30 I msg:[DST 201.87.150.194:48837 sid=1] SHOUTcast 1 client connection accepted. iTunes/11.0.2 (Macintosh; OS X 10.8.2) AppleWebKit/536.26.14"
"2013-09-01 21:14:37 I msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49447 sid=1] SHOUTcast 1 client connection accepted. NSPlayer/4.1.0.3925"
"2013-09-01 21:14:44 I msg:[DST 194-166-242-11.adsl.highway.telekom.at:2441 sid=2] SHOUTcast 1 client connection accepted. Nullsoft Winamp3 version 3.0 (compatible)"
"2013-09-01 21:14:45 I msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49449 sid=1] SHOUTcast 1 client connection accepted. NSPlayer/4.1.0.3925"
"2013-09-01 21:14:45 I msg:[DST p4FF1AEA4.dip0.t-ipconnect.de:13227 sid=1] SHOUTcast 1 client connection accepted. Roku SoundBridge/3.0"
"2013-09-01 21:14:45 E msg:[DST p4FF1AEA4.dip0.t-ipconnect.de:13227 sid=1] Socket error while waiting to send data. err=Broken pipe(32)"
"2013-09-01 21:14:45 I msg:[DST p4FF1AEA4.dip0.t-ipconnect.de:13227 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 31893] Agent: `Roku SoundBridge/3.0'"
"2013-09-01 21:14:45 I msg:[DST p4FF1AEA4.dip0.t-ipconnect.de:13228 sid=1] SHOUTcast 1 client connection accepted. Roku SoundBridge/3.0"
"2013-09-01 21:14:48 I msg:[DST softbank126114153230.bbtec.net:55448 sid=1] SHOUTcast 1 client connection accepted. WinampMPEG/5.50"
"2013-09-01 21:14:51 I msg:[DST dsl-173-206-91-98.tor.primus.ca:52531 sid=1] SHOUTcast 1 client connection accepted. SC_iRadio/1.5.0.19 (WinampMPEG Compatible; Version Version 6.1.3 (Build 10B329)) (deviceID; f953b69d8996facfd0199bbd2b31ae32fb971aa7)"
"2013-09-01 21:14:52 I msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49451 sid=1] SHOUTcast 1 client connection accepted. NSPlayer/4.1.0.3925"
"2013-09-01 21:14:55 E msg:[SRC 91.250.98.119:53493 sid=2] Remote socket closed while waiting for data"
"2013-09-01 21:14:55 I msg:[SRC 91.250.98.119:41367] SHOUTcast 2 source connection."
"2013-09-01 21:14:55 I msg:[SRC 91.250.98.119:41367] Password accepted. Stream id is 2"
"2013-09-01 21:14:55 I msg:[SRC 91.250.98.119:41367 sid=2] stream configuration complete. ["
type=SHOUTcast 2
mimeType=audio/mpeg
maxPayloadSize=16377
avgBitrate=64000
maxBitrate=64000
desiredBufferSize=160
minimumBufferSize=0
icyName=salsaclub.fm
icyGenre=Latin Salsa Tropicalia
icyURL=http://www.salsaclub.fm
icyPub=1
]
"2013-09-01 21:14:55 I msg:[SRC 91.250.98.119:41367 sid=2] Got complete metadata message type=3902 [525 bytes] id=1 span=1 content="
<?xml version="1.0" encoding="UTF-8" ?>
<metadata>
<TIT2>DEREK DAVID - SIN CITY</TIT2>
<extension>
" <title seq=""1"">DEREK DAVID - SIN CITY</title>"
" <title seq=""2"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""3"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""4"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <soon>nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</soon>"
</extension>
</metadata>

"2013-09-01 21:14:55 I msg:[YP2] Connecting to yp.shoutcast.com"
"2013-09-01 21:14:59 E msg:[DST chello080109095134.8.15.vie.surfer.at:52562 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[SRC 91.250.98.119:53497 sid=1] Timeout waiting for data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 87.114.145.247.plusnet.thn-ag1.dyn.plus.net:49167 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST p4FC9B837.dip0.t-ipconnect.de:60561 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 194-166-242-11.adsl.highway.telekom.at:2349 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 174-2925375747.93.176.1.dsl.bell.ca:50659 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 91-114-141-44.adsl.highway.telekom.at:1033 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST c-76-19-14-96.hsd1.ct.comcast.net:49248 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49445 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST fa-padur-binz.ediscom.de:50225 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST softbank126114153230.bbtec.net:52855 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST cable-77-77-245-175.dynamic.telemach.ba:43502 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST p4FEE02F2.dip0.t-ipconnect.de:53206 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST dsl-173-206-91-98.tor.primus.ca:50941 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 7723-metroe-cust.host.net:1569 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49725 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST ALamentin-106-1-77-124.w92-160.abo.wanadoo.fr:4958 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 46.115.33.41:3622 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST cpe-186-22-176-37.telecentro-reversos.com.ar:49333 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 E msg:[DST 171.47.7.109.rev.sfr.net:46555 sid=1] Timeout waiting to send data (1378062899 1378062869[30] )"
"2013-09-01 21:14:59 I msg:[DST chello080109095134.8.15.vie.surfer.at:52562 sid=1] SHOUTcast 1 client connection closed (1806 seconds) [Bytes: 28614399] Agent: `Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_4) AppleWebKit/536.30.1 (KHTML, like Gecko) Version/6.0.5 Safari/536.30.1'"
"2013-09-01 21:14:59 I msg:[DST 87.114.145.247.plusnet.thn-ag1.dyn.plus.net:49167 sid=1] SHOUTcast 1 client connection closed (30 seconds) [Bytes: 314092] Agent: `iTunes/10.6.3 (Macintosh; PPC Mac OS X 10.5.8) AppleWebKit/534.50.2'"
"2013-09-01 21:14:59 I msg:[DST p4FC9B837.dip0.t-ipconnect.de:60561 sid=1] SHOUTcast 1 client connection closed (26368 seconds) [Bytes: 420696267] Agent: `radio.de 1.17.2 rv:591 (iPad 2G; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:14:59 I msg:[DST 194-166-242-11.adsl.highway.telekom.at:2349 sid=1] SHOUTcast 1 client connection closed (2902 seconds) [Bytes: 46109623] Agent: `Nullsoft Winamp3 version 3.0 (compatible)'"
"2013-09-01 21:14:59 I msg:[DST 174-2925375747.93.176.1.dsl.bell.ca:50659 sid=1] SHOUTcast 1 client connection closed (6709 seconds) [Bytes: 106885126] Agent: `iTunes/10.7 (Windows; Microsoft Windows 7 x64 Home Premium Edition Service Pack 1 (Build 7601)) AppleWebKit/536.26.9'"
"2013-09-01 21:14:59 I msg:[DST 91-114-141-44.adsl.highway.telekom.at:1033 sid=1] SHOUTcast 1 client connection closed (6356 seconds) [Bytes: 101240494] Agent: `WinampMPEG/2.8'"
"2013-09-01 21:14:59 I msg:[DST c-76-19-14-96.hsd1.ct.comcast.net:49248 sid=1] SHOUTcast 1 client connection closed (1366 seconds) [Bytes: 21590278] Agent: `iTunes/11.0.4 (Macintosh; OS X 10.7.5) AppleWebKit/534.57.7'"
"2013-09-01 21:14:59 I msg:[DST AToulouse-553-1-171-34.w92-156.abo.wanadoo.fr:49445 sid=1] SHOUTcast 1 client connection closed (30 seconds) [Bytes: 281655] Agent: `NSPlayer/4.1.0.3925'"
"2013-09-01 21:14:59 I msg:[DST fa-padur-binz.ediscom.de:50225 sid=1] SHOUTcast 1 client connection closed (5426 seconds) [Bytes: 86393298] Agent: `iTunes/10.7 (Windows; Microsoft Windows 7 x64 Home Premium Edition Service Pack 1 (Build 7601)) AppleWebKit/536.26.9'"
"2013-09-01 21:14:59 I msg:[DST softbank126114153230.bbtec.net:52855 sid=1] SHOUTcast 1 client connection closed (2292 seconds) [Bytes: 36366628] Agent: `WinampMPEG/5.50'"
"2013-09-01 21:14:59 I msg:[DST cable-77-77-245-175.dynamic.telemach.ba:43502 sid=1] SHOUTcast 1 client connection closed (3210 seconds) [Bytes: 51026668] Agent: `iTunes/11.0.5 (Windows; Microsoft Windows XP Professional Service Pack 3 (Build 2600)) AppleWebKit/536.30.1'"
"2013-09-01 21:14:59 I msg:[DST p4FEE02F2.dip0.t-ipconnect.de:53206 sid=1] SHOUTcast 1 client connection closed (471 seconds) [Bytes: 7307846] Agent: `Mozilla/5.0 (Windows NT 6.1; WOW64; rv:23.0) Gecko/20100101 Firefox/23.0'"
"2013-09-01 21:14:59 I msg:[DST dsl-173-206-91-98.tor.primus.ca:50941 sid=1] SHOUTcast 1 client connection closed (4022 seconds) [Bytes: 63991054] Agent: `SC_iRadio/1.5.0.19 (WinampMPEG Compatible; Version Version 6.1.3 (Build 10B329)) (deviceID; f953b69d8996facfd0199bbd2b31ae32fb971aa7)'"
"2013-09-01 21:14:59 I msg:[DST 7723-metroe-cust.host.net:1569 sid=1] SHOUTcast 1 client connection closed (2003 seconds) [Bytes: 31757968] Agent: `Screamer Radio v0.4.4'"
"2013-09-01 21:14:59 I msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49725 sid=1] SHOUTcast 1 client connection closed (129 seconds) [Bytes: 1836687] Agent: `radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:14:59 I msg:[DST ALamentin-106-1-77-124.w92-160.abo.wanadoo.fr:4958 sid=1] SHOUTcast 1 client connection closed (677 seconds) [Bytes: 10590909] Agent: `liveradioVintage'"
"2013-09-01 21:14:59 I msg:[DST 46.115.33.41:3622 sid=1] SHOUTcast 1 client connection closed (4155 seconds) [Bytes: 66110429] Agent: `NSPlayer/11.0.5721.5275 WMFSDK/11.0'"
"2013-09-01 21:14:59 I msg:[DST cpe-186-22-176-37.telecentro-reversos.com.ar:49333 sid=1] SHOUTcast 1 client connection closed (7464 seconds) [Bytes: 118923135] Agent: `iTunes/11.0 (Windows; Microsoft Windows 7 Business Edition Service Pack 1 (Build 7601)) AppleWebKit/536.27.1'"
"2013-09-01 21:14:59 I msg:[DST 171.47.7.109.rev.sfr.net:46555 sid=1] SHOUTcast 1 client connection closed (5517 seconds) [Bytes: 87854688] Agent: `iTunes/11.0.2 (Windows; Microsoft Windows 7 x64 Home Premium Edition Service Pack 1 (Build 7601)) AppleWebKit/536.27.1'"
"2013-09-01 21:14:59 E msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49734 sid=1] SHOUTcast 1 client connection rejected. Stream not available. radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)"
"2013-09-01 21:14:59 I msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49734 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 0] Agent: `radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:14:59 E msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49738 sid=1] SHOUTcast 1 client connection rejected. Stream not available. radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)"
"2013-09-01 21:14:59 I msg:[DST p5DD6CBDF.dip0.t-ipconnect.de:49738 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 0] Agent: `radio.de 1.3.1 rv:590 (iPhone 4S; iPhone OS 6.1.3; de_DE)'"
"2013-09-01 21:14:59 I msg:[SRC 91.250.98.119:41379] SHOUTcast 2 source connection."
"2013-09-01 21:14:59 I msg:[SRC 91.250.98.119:41379] Password accepted. Stream id is 1"
"2013-09-01 21:15:00 E msg:[DST ip-87-240-203-165.dyn.luxdsl.pt.lu:49217 sid=1] Timeout waiting to send data (1378062900 1378062870[30] )"
"2013-09-01 21:15:00 E msg:[DST D57DF14A.static.ziggozakelijk.nl:49276 sid=1] Timeout waiting to send data (1378062900 1378062870[30] )"
"2013-09-01 21:15:00 I msg:[DST ip-87-240-203-165.dyn.luxdsl.pt.lu:49217 sid=1] SHOUTcast 1 client connection closed (3231 seconds) [Bytes: 51336467] Agent: `iTunes/11.0.2 (Windows; Microsoft Windows 7 x64 Ultimate Edition Service Pack 1 (Build 7601)) AppleWebKit/536.27.1'"
"2013-09-01 21:15:00 I msg:[DST D57DF14A.static.ziggozakelijk.nl:49276 sid=1] SHOUTcast 1 client connection closed (122799 seconds) [Bytes: 1959132075] Agent: `iTunes/11.0.4 (Windows; Microsoft Windows 7 x64 Home Premium Edition Service Pack 1 (Build 7601)) AppleWebKit/536.30.1'"
"2013-09-01 21:15:00 E msg:[DST 7723-metroe-cust.host.net:54994 sid=1] SHOUTcast 1 client connection rejected. Stream not available. Screamer Radio v0.4.4"
"2013-09-01 21:15:00 I msg:[DST 7723-metroe-cust.host.net:54994 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 0] Agent: `Screamer Radio v0.4.4'"
"2013-09-01 21:15:00 E msg:[DST chello080109095134.8.15.vie.surfer.at:52655 sid=1] SHOUTcast 1 client connection rejected. Stream not available. Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_4) AppleWebKit/536.30.1 (KHTML, like Gecko) Version/6.0.5 Safari/536.30.1"
"2013-09-01 21:15:00 I msg:[DST chello080109095134.8.15.vie.surfer.at:52655 sid=1] SHOUTcast 1 client connection closed (0 seconds) [Bytes: 0] Agent: `Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_4) AppleWebKit/536.30.1 (KHTML, like Gecko) Version/6.0.5 Safari/536.30.1'"
"2013-09-01 21:15:00 I msg:[SRC 91.250.98.119:41379 sid=1] stream configuration complete. ["
type=SHOUTcast 2
mimeType=audio/mpeg
maxPayloadSize=16377
avgBitrate=128000
maxBitrate=128000
desiredBufferSize=320
minimumBufferSize=0
icyName=salsaclub.fm
icyGenre=Latin Salsa Tropicalia
icyURL=http://www.salsaclub.fm
icyPub=1
]
"2013-09-01 21:15:00 I msg:[SRC 91.250.98.119:41379 sid=1] Got complete metadata message type=3902 [525 bytes] id=1 span=1 content="
<?xml version="1.0" encoding="UTF-8" ?>
<metadata>
<TIT2>DEREK DAVID - SIN CITY</TIT2>
<extension>
" <title seq=""1"">DEREK DAVID - SIN CITY</title>"
" <title seq=""2"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""3"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <title seq=""4"">nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</title>"
" <soon>nextsong salsaclubfm 994da60f70ab30c85cb58ab351f97853 sctrans2next</soon>"
</extension>
</metadata>

"2013-09-01 21:15:00 I msg:[DST chello080109095134.8.15.vie.surfer.at:52656 sid=1] SHOUTcast 1 client connection accepted. Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_4) AppleWebKit/536.30.1 (KHTML, like Gecko) Version/6.0.5 Safari/536.30.1"
"2013-09-01 21:15:01 E msg:[DST host118-239-static.105-82-b.business.telecomitalia.it:3266 sid=1] Timeout waiting to send data (1378062901 1378062871[30] )"
"2013-09-01 21:15:01 I msg:[DST host118-239-static.105-82-b.business.telecomitalia.it:3266 sid=1] SHOUTcast 1 client connection closed (20749 seconds) [Bytes: 330971258] Agent: `iTunes/11.0.5 (Windows; Microsoft Windows XP Professional Service Pack 3 (Build 2600)) AppleWebKit/536.30.1'"
"2013-09-01 21:15:01 I msg:[YP2] Connecting to yp.shoutcast.com"

We are using Shoucast server 2 since May 2013. Since then we encounter such "stream outages" every day minimum to 3,4 times. Radomly.

Server and source are on the same server (with Centos).

I've upgraded the server, but this was useless. Same behavior. I have enough resources left for up to 300 concurrent listeners. Currently we have in average 15-40 (max 77).

This problem was not in shpoutcast V1.

Please help.

Same thong is happening also to a colleague on his stream on another server. He has the same problem.

best regards,
Georg

[alfabravo14]

.

I have a similar problem
I´m on Centova 1 with Sc v.1
Its on a external hosted shoutcast-service.

My host has 8 other streams in this Centova package (max 10)
The server is a VPS.

After 24:00 each day... 1 or 2 of the other stations
switch from live to autodj...from that moment till the next morning
my stream is chopped (short interrupts 1 to 10 secs or more).
When the interuptions are long enough (30 sec>) all current listeners
are disconnected.

When they go back live next morning they stop the autodj
and my stream (and theirs) is back to normal (no interruptions)
at 24:00 the same shit again...everyday !
They are to stupid to even check their own streams

I found this happens when they (the other 2) have files in their auto-dj
that are at much higher bitrate as their stream:
ie: their stream is @128 kbs , Mp3
but their autodj files are sometimes up to @320 kbs and sometimes in AAC (iTunes) format
everytime they play such a file their stream AND MINE is ruined.

I found this by asking my host to turn of "re-encoding"
so all 8 streams were streamed at the same bitrate as the files in their autodj´s
so i could see their original bitrate and format.

At the ame moment they play a file that is not 128kbs (160,190,256,320 ...etc)
then immidiatly my (and their) stream starts to interrupt.
I even listened on a headphone with my stream on the right and their stream
on the left...and the interruptions are nearly in-sync ! (occur at the same moments)

So the problem is probably that either Centova or Sc-trans or my host VPS
cant handle different or to high autodj bitrates (in a 10 stream package)...
even when "re-encode" is off and "crossfade" and other stuff off also that would use
more server-processor-power.
the VPS has assigned max cpu-time...nothing solves it.

In Centova "source-log" it nearly never shows any errors
only when the interruptions happen during the start of the next song
the log then says something like "no data" from socket (autodj port)
in that case audio only comes back at the start of the next track.

My host cant solve it (he says)..and Centova is dead (no response in 2 weeks)
So i´m forced to find a new shoutcast host..and contact all portals and apps that
list me...and tell them the new stream-ip...that really sucks.

My host says he cant force the other stations to upload their autodj files in the same
bitrate and format as the stream(128,mp3)...cause he did not mention that in the contracts.
And Centova and SC and VPS are supposed to be able to handle it...so he never knew
it would be needed to put that in the contracts...and as said centova dont respond
AND they have taken their forum offline also ..and nothing can be found using Google.

So i who does it all perfect by the book have to find a new server/host and those that
spoil the whole server and dont even check their own streams can stay (with their only 1 or 2 lauzy listeners each night) DAMN !

So questions:

1) Are you one of more streams in the same Centova package ?
2) Is it on a hosted service ?
3) Is your host using VPS ?

If yes i can maybe help to locate the problem..solving it is the next step.

.

[DrO]

re-encoding anything uses CPU resources so it's no wonder that sc_trans is having to use a lot when it's having to re-encode a lot of files (and when multiplied against other streams).

if the host(s) you're hosting provider are using cannot deal with it:

• you need to be moved to a different host or find another hosting provider
• the other stream(s) need to be moved to a different host

so now with the extra information provided in the above post, the issue has zero to do with Centova other than being involved as the control panel your hosting povider is using.

the issue is your hosting provider is oversubscribed on the resources available on the VPS being used in combination with how sc_trans works (which is not as optimised as it should be assuming they're using v2 though that's more against AAC transcoding than MP3 transcoding) which is going to eat a lot of CPU to keep up with transcoding and streaming. so it's no wonder you have such issues with a shared VPS setup your hosting provider appears to be using.


so irrespective of the issues you and your host are having with Centova (assuming they were even emailed), it is not their fault at all. and sc_trans is just working as it will do so that cannot be blamed (other than trying to do what it's been asked to do). so that leaves the point of issue as the hosting provider being used and i suspect them trying to do things on the cheap so they make as much money as possible without having to do anything.

[alfabravo14]

> " i suspect them trying to do things on the cheap "

Shure that could be the case.

Allthough during the times the problems occur
theres 8 streams (stations) most with no more then max only 2 listeners
only my stream is influenced by the 2 with to high bitrates
the other 6 have no interruptions at all...i dont understand that
How can it only affect me...and not the other 6.

Anyway they say they passed on all info i gave them
and they say no reply from Centova.

That is my problem
Could be that Centova is kind of tired of getting blamed or even asked about
stuff that is not caused by their software ... but not replying is not a good thing
or they did reply and my host dont want to tell me that cause centovas reply
probably indidcated that their VPS cant cope with it ..on the other hand i wouild think
that most host would use VPS.

Hope you understand my (what you elsewhere called) "negativity" its caused by this kind of unfair politics....And its all over the place...i now have to change to another sc-host again
this is going to be nr4 in my 1st year !...i´m not blaming it on you or sc...its probably the hosts.

What might help would be "approval mark" (cant find the right translation)
you know what i mean something like a "UL-listed" kind of thing.


Anyway ...curious what "lion1108" has to say.

[lion1108]

alfabravo14,

thx for your input.
I am also wondering if i, or we two (and my colleague) are the only ones having these kind of troubles...

1) We are running two streams of 10 (Yes, Centova). But the second stream is only for testing purposes.
2) & 3) hosted Service / VPS with OS: Centos

We are running SC2
And the latest Centova 3.0.4

Centova answered quickly and clearly said, that this is not a problem of Centova Software, but looks a problem of Shoutcast.

thx to every one who can help us.

Georg

[lion1108]

DrO,

thx for reply.

I've contacted also my hosting provider (host europe by the way)
They have been running some analysis and came to the point, that they cannot find any issue.
Anyhow, i upgraded the package and have nearly doubled the CPU power etc,...
But this didn't help either.
With my current setup is should be able to handle minimum up to 150 concurent lsiteners - even up to 300.

When i am looking at the logfiles above, from my perspectove in my humble opogion the source seems just to have this "socket send error" and then resets after 30 seconds and restarts the source. And of course all listeners are then refused to connect, and lsiteners being already on the stream are disconnecting, because of timeout.

My questions:
1) is there any possibility to get more info about the root cause of this "socket send error"?
2) Can i reduce the time from 30 seconds to let's say 10 seconds or less?

best regards and greetings from Vienna,
Georg

[alfabravo14]

@lion1108

Can you do some test (same as i done myself before).

1)

Ask your host to (temporarely) turn-off "re-encoding" (in his Centova admin)
this should now make (all 10) streams in the same bitrate as whatever
those stations have uploaded in their autodj files.

Not shore if you own the whole 10-stream package yourself
in that case you can do the above yourself (remotely ?).

2)

Ask your host for a list of the other stations on your server (iP´s + portnr)
if he dont give it try to find them (try different portnr´s close to yours)
usually they are spaced by 2 (8001,8003,8005...etc)

Or you know that yourself if you own/control the whole thing yourself

3)

After above is done ... see what the "official" stream bitrate should be for each station
by looking at its DNAS page (status).

After that play the stations and see what the real actual bitrate is now
do that when you have no interruptions on your own stream.
and also when you have interruptions.

In other words try to find if there´s a station that now is streaming
at a higher bitrate (or different format) as what its stream normally is.
And see if the interruptions occur during the playing of a "wrong" bitrate"

If the above is indeed the case then we have the same problem.

Dont forget to tell your host he can turn-on "re-encoding" again.
and tell him your findings.



> "Can i reduce the time from 30 seconds to let's say 10 seconds or less?"

you mean the time it takes for the server to disconnect source ?
when your stream is silent ? ...if that is what you mean then
there´s a setting in Centova > Config > Advanced

" Disconnect idle sources after :"

its 30 by default,

if you set that to a lower value (10) it means it will disconnect source even faster
so better to leave it ..or set it higher ...i think this wont help solve your problem.

[lion1108]

alfabravo14,

thx for your hints.

In fact, it is our server, with our centova 10 pack ;-)

We are running only two streams for now, but will have soon new customers on with other streams.
Our own stream is set to 128kbit/s. (also our second test stream is set to 128kbit7s - but is not listed and noone knows the link and port to connect).
All our songs are encoded in 128kbit/s CBR. So, in my humble opignion there shouldn't be a problem with the re-encoding of the files.

thx fpr the hint with the 30 seconds - i'll wait now for the next outage and see what happens ;-)

@ DrO,
Could you also check the above logfiles and give further advice?

thx for every help ;-)

BR
Georg