Shoutcast re-streaming: stuttering and buffer problems (urgent)

Hi forum

I have a serious problem concerning Icecast/Shoutcast re-streaming.

I am re-streaming a standard installation of Icecast through an instance of Wowza on the same server.

Streams have recently started periodically stuttering (like a CD jumping). Then the stream starts to loop a few times before eventually cutting off, then restarting. It then goes back to normal for a while.

Sounds like some sort of buffering problem?

This is really urgent: it’s obviously destroying our listeners’ experience so any help would be really appreciated.

Sample log output:

2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	ShoutCastReceiver.doWatchdog[http://localhost:9595/mountname]: reset	-	-	-	605.436	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	ShoutCastReceiver.resetConnection: (SOCKET, R: localhost/127.0.0.1:9595, L: /127.0.0.1:49359, S: localhost/127.0.0.1:9595)	-	-	-	605.436	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	ShoutCastReceiver.sessionClosed: 	-	-	-	605.437	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	ShoutCastReceiver.sessionClosed: reconnect: isCurrentSession:false tryConnect:true	-	-	605.437	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: chunkDurationTarget: 10000	-	-	-	605.438	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: chunkDurationTolerance: 500	-	-	-	605.438	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: audioGroupCount: 3	-	-	-	605.438	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: playlistChunkCount:3	-	-	-	605.438	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	MediaStreamMap.getLiveStreamPacketizer: Create live stream packetizer: cupertinostreamingpacketizer:http://localhost:9595/mountname	-	-	-	605.439	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	CupertinoPacketHandler.startStream[shoutcast/_definst_/http://localhost:9595/mountname]	-	-	605.439	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	CupertinoPacketHandler.resetStream[shoutcast/_definst_/http://localhost:9595/mountname]	-	-	605.439	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:04	EDT	comment	server	INFO	200	-	ShoutCastReceiver.internalConnect: http://localhost:9595/mountname	-	-	-	605.54	-	-
2010-09-08	17:17:05	EDT	comment	server	INFO	200	-	ShoutCastDecoder.checkHeader[http://localhost:9595/mountname]: HTTP OK	-	-	-	606.021	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:05	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.handlePacket: Audio codec: MP3	-	-	-	606.526	-	-
2010-09-08	17:17:06	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.endChunkTS[shoutcast/_definst_/http://localhost:9595/mountname]: Add chunk: id:1 a/v/k:33/0/0 duration:10344	-	-	-	606.779	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:18	EDT	comment	server	INFO	200	-	MediaStreamMap.removeLiveStreamPacketizer[shoutcast/_definst_/http://localhost:9595/mountname]: Destroy live stream packetizer: cupertinostreamingpacketizer	-	-	-	619.497	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	ShoutCastReceiver.doWatchdog[http://localhost:9595/mountname]: reset	-	-	-	620.577	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	ShoutCastReceiver.resetConnection: (SOCKET, R: localhost/127.0.0.1:9595, L: /127.0.0.1:55768, S: localhost/127.0.0.1:9595)	-	-	-	620.577	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: chunkDurationTarget: 10000	-	-	-	620.578	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: chunkDurationTolerance: 500	-	-	-	620.578	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: audioGroupCount: 3	-	-	-	620.578	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.init[shoutcast/_definst_/http://localhost:9595/mountname]: playlistChunkCount:3	-	-	-	620.578	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	MediaStreamMap.getLiveStreamPacketizer: Create live stream packetizer: cupertinostreamingpacketizer:http://localhost:9595/mountname	-	-	-	620.578	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	CupertinoPacketHandler.startStream[shoutcast/_definst_/http://localhost:9595/mountname]	-	-	620.578	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	CupertinoPacketHandler.resetStream[shoutcast/_definst_/http://localhost:9595/mountname]	-	-	620.579	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	ShoutCastReceiver.sessionClosed: 	-	-	-	620.579	-	-	-	-	-
2010-09-08	17:17:19	EDT	comment	server	INFO	200	-	ShoutCastReceiver.sessionClosed: reconnect: isCurrentSession:false tryConnect:true	-	-	620.579	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:20	EDT	comment	server	INFO	200	-	ShoutCastReceiver.internalConnect: http://localhost:9595/mountname	-	-	-	620.681	-	-
2010-09-08	17:17:20	EDT	comment	server	INFO	200	-	ShoutCastDecoder.checkHeader[http://localhost:9595/mountname]: HTTP OK	-	-	-	621.121	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:21	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.handlePacket: Audio codec: MP3	-	-	-	621.628	-	-
2010-09-08	17:17:21	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.endChunkTS[shoutcast/_definst_/http://localhost:9595/mountname]: Add chunk: id:1 a/v/k:33/0/0 duration:10344	-	-	-	621.898	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-
2010-09-08	17:17:31	EDT	comment	server	INFO	200	-	LiveStreamPacketizerCupertino.endChunkTS[shoutcast/_definst_/http://localhost:9595/mountname]: Add chunk: id:2 a/v/k:33/0/0 duration:10344	-	-	-	631.987	-	-	-	-	-	-	-	-	-	-	-	-	-	-	-

Icecast settings:

        <clients>10000</clients>
        <sources>200</sources>
        <threadpool>5</threadpool>
        <queue-size>1048576</queue-size>
        <client-timeout>60</client-timeout>
        <header-timeout>60</header-timeout>
        <source-timeout>60</source-timeout>
        <burst-on-connect>1</burst-on-connect>
        <burst-size>262140</burst-size>
    </limits>

couple more points to add to the mystery:

  1. this doesn’t happen to all streams. I’ve got two streams playing simultaneously at the moment, 1 is stuttering throughout and sounds terrible, the other is perfect. Both are coming from the same client software, through the same instances of Icecast and Wowza

  2. the same cd-jumping has also occasionally been happening with static mp3s playing through vods3 application.

Hi,

Does it happen consistently with the same streams?

**** No & Yes ****

Allow me to Explain my 3 days research and results at one of my servers.

Explanation / Answer: ( Briefly )

Reason 1.

When a connection from the source encoder have:

  1. Some packet loss,

  2. Lags,

  3. Disconnections,

  4. The last listener stops from listening.

WSE4.0 get unstable for that application.

But not Icecast/Shoutcast, which continues with the mount point unaltered, you can compare it by playing via: any device or software and at the same time connect directly to the mountpoint at Icecast/Shoutcast and you will notice when it happends.

The Icecast/Shoutcast will drop to 0 connections if WSE4.0 cannot get back to it.

Or in the Worst case scenario, you will see connections there ( possible lots of them trying to connect ) BUT!:

  1. The audio coming from WSE4.0 is a repetitive one (short loop of last buffer that plays for ever, unless you disconnect and start it over from wowza)

  2. You will hear connection tries from WSE4.0 to Icecast/Shoutcast like gasps or hickups that have no meanings.

  3. Long wait, then suddenly some kind of noise or sound, then same one of the above.

Again, if you are using a player connected to Icecast/Shoutcast you wont see this happening.

The Audio continues to flow normally at it.

I even changed Icecast version from Icecast 2.3.2-KH29.1 to icecast 2.3.3-KH9 (Latest Version for Windows) to see if any changes on WSE4.0

But i got exactly the same results.

Reason 2.

It seems to be a possible Sync issue with Icecast/Shoutcast somehow.

*** My previous version of WMS3.6.x where running like a charm, without any kind of issues ***

My current hardware scenario for that server in particular is:


Windows Server 2008 Enterprise R2 64 Bit

2.0GHz Intel Xeon Hexa-Core Sandy Bridge E5-2620 Romley with 15MB cache & HT

40,000GB Transfer/ 1Gbps port

16GB DDR3 26.00

1000GB SATAIII

1000GB SATAIII

1000GB SATAIII

1000GB SATAIII

SATA RAID 10

From WSE4.0 About:

OS

Windows Server 2008 R2 (amd64)

Java Information

Java Version

1.7.0_09

Java VM Version

23.5-b02

Java Architecture

64

Java Name

Java HotSpot™ 64-Bit Server VM

Java Vendor

Oracle Corporation

Java Home

C:\Program Files\Java\jdk1.7.0_09\jre

Java Max Heap Size

10000MB


Hope this helps.

-MUSARANO

Does it happen consistently with the same streams? Did those streams work okay before? Are you streaming to IPhone? Is the problem in Flash and IPhone?

Richard

What you describe with vods3 streaming is not really unusual, it sounds like the

file was not in cache. You can increase the life of the cache.

Try adding these to Properties list in /conf/Server.xml:

<Property>
<Name>mediaCacheSourceMaxTimeToLive</Name>
<Value>3600000</Value>
<Type>Long</Type>
</Property>
<Property>
<Name>mediaCacheSourceMinTimeToLive</Name>
<Value>600000</Value>
<Type>Long</Type>
</Property>

The Value is milliseconds. These are the default

Richard

Hi Richard

Does it happen consistently with the same streams?]

Haven’t been able to find any consistency yet. When listening via vods3 the other day, the CD-jumping occured sporadically: when I moved back to the same part of the file and played again, it would play fine. With icecast re-streaming, like I say last night one stream was fine and the other simultaneously terrible.

Did those streams work okay before?

Yes the problem has only been noticed in the last few days, we’ve been running for a couple of months now with no problems. (We’re on EC2 if that helps)

Is the problem in Flash and IPhone?

The Icecast stream last night was definitely broken in both Flash and iPhone. Haven’t tested the vods3 on iPhone yet. I will listen back to some files later and test

That is interesting, thanks. I now believe the live streaming jumping was caused by a connectivity issue, I will update if I am able to confirm this.

cheers

Forum user musarano has submitted support ticket #81399 related to this issue. -Tim