Threaded Mode | Linear Mode

jack_c85 · 23-02-2015, 23:07

Hi Simon,

Although it's way better than the rubbish MP3 streams, using a Raspberry Pi, running your fantastic MinimServer to provide the 320kbs BBC Radio streams to my Sonos system is great, however... I experience quite a bit of dropout, only for short periods of time generally but occasionally the stream stops completely.

I have flashed the Pi and am running it on Raspbain in the command line form so that is literally the only thing running on the Pi... can you think of any other reason the streams could be experiencing dropout. The Pi is using wired network connection to my router which is wired directly to the Sonos system so no reason there should be any network issues. Are you able to test this your end. Because it's Sonos I'm not using the UPNP server just the HTTP URL's for the MinimStreamer.

Thanks in advance.

Jack

simoncn · 23-02-2015, 23:21

(23-02-2015 23:07)jack_c85 Wrote: Hi Simon,

Although it's way better than the rubbish MP3 streams, using a Raspberry Pi, running your fantastic MinimServer to provide the 320kbs BBC Radio streams to my Sonos system is great, however... I experience quite a bit of dropout, only for short periods of time generally but occasionally the stream stops completely.

I have flashed the Pi and am running it on Raspbain in the command line form so that is literally the only thing running on the Pi... can you think of any other reason the streams could be experiencing dropout. The Pi is using wired network connection to my router which is wired directly to the Sonos system so no reason there should be any network issues. Are you able to test this your end. Because it's Sonos I'm not using the UPNP server just the HTTP URL's for the MinimStreamer.

Thanks in advance.

Jack

Are you sending the same internet stream to two different clients? There is a known issue with this.

If not, the issue could be related to how the Sonos handles buffering. Are you able to try it with any other player or intenet radio to see if that performs better?

Other users have reported success with this setup, so the problem isn't caused by a lack of CPU power in the Pi.

simoncn · 23-02-2015, 23:42

Please try enabling Debug logging in the MinimServer log window while the stream is playing. Let the stream play for a minute or two, then copy and post what appears in the log during this time. If you get a dropout while you are doing this, please note the time of the dropout so that I can correlate it with the log activity. Many thanks!

I am playing the 320 kbps Radio 3 stream now from my Raspberry Pi to my Linn DS renderer. The java process on the Pi is taking only about 7% of the CPU (measured using top) and I have had no dropouts.

jack_c85 · 23-02-2015, 23:54

(23-02-2015 23:42)simoncn Wrote: Please try enabling Debug logging in the MinimServer log window while the stream is playing. Let the stream play for a minute or two, then copy and post what appears in the log during this time. If you get a dropout while you are doing this, please note the time of the dropout so that I can correlate it with the log activity. Many thanks!

I am playing the 320 kbps Radio 3 stream now from my Raspberry Pi to my Linn DS renderer. The java process on the Pi is taking only about 7% of the CPU (measured using top) and I have had no dropouts.

Of course... I'll try both. I'll play one of the streams on my computer and also turn the logs on whilst streaming to Sonos (separately obviously) but no, not sinulatneously streaming the same thing twice, I would start one instance on Sonos and distribute using Sonos if I was to do that as it keeps the rooms in sync.

Will post tomorrow with my findings.

Many thanks

jack_c85 · 24-02-2015, 11:09

(23-02-2015 23:42)simoncn Wrote: Please try enabling Debug logging in the MinimServer log window while the stream is playing. Let the stream play for a minute or two, then copy and post what appears in the log during this time. If you get a dropout while you are doing this, please note the time of the dropout so that I can correlate it with the log activity. Many thanks!

I am playing the 320 kbps Radio 3 stream now from my Raspberry Pi to my Linn DS renderer. The java process on the Pi is taking only about 7% of the CPU (measured using top) and I have had no dropouts.

Here are my findings... we got lucky and a dropout occurred whilst logging and it looks quite different to normal streaming so hopefully you can see whats going on... it happens at 10:05:09 and lasts around 10 seconds.

10:03:00.867 Thread-511: adding media segment 222620658
10:03:00.888 Thread-511: playing media segment 222620658
10:03:01.402 Thread-511: finished writing 258141 bytes
10:03:07.860 Thread-511: adding media segment 222620659
10:03:07.867 Thread-511: playing media segment 222620659
10:03:08.431 Thread-511: finished writing 258077 bytes
10:03:14.930 Thread-511: adding media segment 222620660
10:03:14.944 Thread-511: playing media segment 222620660
10:03:15.449 Thread-511: finished writing 258155 bytes
10:03:20.132 Thread-511: adding media segment 222620661
10:03:20.143 Thread-511: playing media segment 222620661
10:03:20.786 Thread-511: finished writing 258321 bytes
10:03:27.127 Thread-511: adding media segment 222620662
10:03:27.140 Thread-511: playing media segment 222620662
10:03:27.653 Thread-511: finished writing 257861 bytes
10:03:32.479 Thread-511: adding media segment 222620663
10:03:32.489 Thread-511: playing media segment 222620663
10:03:33.070 Thread-511: finished writing 258094 bytes
10:03:39.388 Thread-511: adding media segment 222620664
10:03:39.419 Thread-511: playing media segment 222620664
10:03:39.935 Thread-511: finished writing 258159 bytes
10:03:44.654 Thread-511: adding media segment 222620665
10:03:44.670 Thread-511: playing media segment 222620665
10:03:45.183 Thread-511: finished writing 258105 bytes
10:03:53.420 Thread-511: adding media segment 222620666
10:03:53.434 Thread-511: playing media segment 222620666
10:03:53.938 Thread-511: finished writing 258049 bytes
10:03:58.662 Thread-511: adding media segment 222620667
10:03:58.669 Thread-511: playing media segment 222620667
10:03:59.206 Thread-511: finished writing 258100 bytes
10:04:05.665 Thread-511: adding media segment 222620668
10:04:05.677 Thread-511: playing media segment 222620668
10:04:06.264 Thread-511: finished writing 258100 bytes
10:04:12.688 Thread-511: adding media segment 222620669
10:04:12.703 Thread-511: playing media segment 222620669
10:04:13.200 Thread-511: finished writing 258100 bytes
10:04:19.695 Thread-511: adding media segment 222620670
10:04:19.702 Thread-511: playing media segment 222620670
10:04:20.208 Thread-511: finished writing 258108 bytes
10:04:24.931 Thread-511: adding media segment 222620671
10:04:24.949 Thread-511: playing media segment 222620671
10:04:25.449 Thread-511: finished writing 258150 bytes
10:04:30.196 Thread-511: adding media segment 222620672
10:04:30.212 Thread-511: playing media segment 222620672
10:04:30.714 Thread-511: finished writing 258089 bytes
10:04:35.447 Thread-511: adding media segment 222620673
10:04:35.460 Thread-511: playing media segment 222620673
10:04:36.077 Thread-511: finished writing 258113 bytes
10:04:42.450 Thread-511: adding media segment 222620674
10:04:42.463 Thread-511: playing media segment 222620674
10:04:42.966 Thread-511: finished writing 258111 bytes
10:04:49.455 Thread-511: adding media segment 222620675
10:04:49.469 Thread-511: playing media segment 222620675
10:04:49.970 Thread-511: finished writing 258078 bytes
10:04:56.438 Thread-511: adding media segment 222620676
10:04:56.450 Thread-511: playing media segment 222620676
10:04:56.968 Thread-511: finished writing 258125 bytes
10:05:09.569 Thread-509: HTTPConnection: end of input stream data
10:05:09.573 Thread-509: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@110eb56
10:05:09.577 Thread-509: Streamer: stopping chain org.jstreamer.core.ChainImpl@bd59df
10:05:09.586 Thread-509: ChainImpl: stop org.jstreamer.core.ChainImpl@bd59df
10:05:09.586 Thread-509: ChainImpl: removing target from org.jstreamer.core.TargetChain@764922
10:05:09.587 Thread-509: ChainImpl: stop org.jstreamer.core.ChainImpl@19a3929
10:05:09.587 Thread-509: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@19a3929
10:05:09.588 Thread-509: ChainSource: stopping reader thread
10:05:09.591 Thread-513: ChainSource: error reading input stream: org.jstreamer.OutputException: java.io.InterruptedIOException
10:05:09.592 Thread-513: Buffer: closing buffer: org.jstreamer.core.Buffer@1bfc54
10:05:09.593 Thread-509: ChainSource: stopping source
10:05:09.594 Thread-512: BufferReader: fillBuffer returned -1: buffer=org.jstreamer.core.Buffer@1bfc54
10:05:09.596 Thread-512: ChainTarget: end of data from input stream
10:05:09.596 Thread-512: ChainImpl: stop org.jstreamer.core.ChainImpl@bd59df
10:05:09.597 Thread-512: BufferPoolReader: close
10:05:09.598 Thread-512: BufferReader: close: buffer=org.jstreamer.core.Buffer@1c4f6a1
10:05:09.600 Thread-511: HTTPSource.ReaderThread caught InterruptedException
10:05:09.601 Thread-511: HTTPSource: closing piped output stream
10:05:09.602 Thread-509: HTTPSource: closing outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.243,port=80,localport=59635]
10:05:09.603 Thread-509: ChainSource: source stopped
10:05:09.603 Thread-509: TargetChain: stop
10:05:09.604 Thread-509: TargetChain: stopping subchain
10:05:09.604 Thread-509: ChainImpl: stop org.jstreamer.core.ChainImpl@bd59df
10:05:09.605 Thread-509: TargetChain: subchain stopped
10:05:09.605 Thread-509: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@19a3929
10:05:09.606 Thread-509: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@bd59df
10:05:09.606 Thread-509: ChainTarget: stop
10:05:09.607 Thread-509: ChainTarget: stopping target
10:05:09.607 Thread-509: HTTPRequestTarget: stop this=com.minimstreamer.HTTPRequestTarget@8ff567 outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@19e9a8d
10:05:09.609 Thread-512: Buffer: removeReader: org.jstreamer.core.Buffer@1c4f6a1
10:05:09.609 Thread-512: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@1c4f6a1
10:05:09.610 Thread-512: BufferReader: close: buffer=org.jstreamer.core.Buffer@1bfc54
10:05:09.611 Thread-512: Buffer: removeReader: org.jstreamer.core.Buffer@1bfc54
10:05:09.611 Thread-512: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@1bfc54
10:05:09.613 Thread-509: HTTPRequestTarget: closeSocket
10:05:09.614 Thread-509: HTTPRequestTarget: closing Socket[addr=/192.168.0.20,port=3551,localport=9790]
10:05:09.615 Thread-509: HTTPRequestTarget: notifyStopped com.minimstreamer.Streamer$NotifyStopped@8a80d8
10:05:09.616 Thread-509: Streamer.NotifyStopped: run
10:05:09.617 Thread-508: Streamer: removing request chain for org.jminim.lib.HTTPConnection$Request@110eb56
10:05:09.617 Thread-508: Streamer: completed network request
10:05:09.619 Thread-508: HTTPConnection: completed request; socket=Socket[addr=/192.168.0.20,port=3551,localport=9790], keepAlive=true
10:05:09.620 Thread-508: HTTPConnection: writer thread waiting for request
10:05:09.620 Thread-509: ChainTarget: target stopped
10:05:09.637 Thread-509: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@bd59df
10:05:09.639 Thread-508: HTTPConnection: writer thread interrupted
10:05:09.640 Thread-509: HTTPService: removing connection org.jminim.lib.HTTPConnection@18581f3
10:05:19.945 Thread-495: HTTPService: accepted incoming connection
10:05:19.958 Thread-494: HTTPService: received request, Socket[addr=/192.168.0.20,port=3582,localport=9790]
10:05:19.959 Thread-494: HTTPService: adding connection org.jminim.lib.HTTPConnection@b9e764
10:05:19.960 Thread-495: HTTPService: waiting for incoming connection
10:05:19.964 Thread-515: HTTPConnection: writer thread waiting for request
10:05:19.965 Thread-516: HTTPConnection: reading HTTP request
10:05:19.966 Thread-516: GET /minimstreamer/*/R1/ HTTP/1.1
10:05:19.966 Thread-516: ACCEPT: */*, HOST: 192.168.0.3:9790, User-Agent: Nullsoft Winamp3 version 3.0 (compatible), Icy-MetaData: 1
10:05:19.967 Thread-515: HTTPConnection: writer thread processing request
10:05:19.968 Thread-515: Streamer: processing HTTP request
10:05:19.968 Thread-515: Streamer: releaseChains
10:05:19.969 Thread-515: Streamer: releasing chain: R1
10:05:19.970 Thread-515: Streamer: streamID is R1
10:05:19.970 Thread-515: Streamer: URL scheme is http
10:05:19.971 Thread-515: Streamer: request path is a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8
10:05:19.971 Thread-515: Streamer: transcodeType is
10:05:19.973 Thread-515: ChainImpl: addSource org.jstreamer.core.ChainSource@1d580a8
10:05:19.973 Thread-515: ChainSource: init
10:05:19.974 Thread-515: ChainImpl: getting property .inputBufferSize
10:05:19.974 Thread-515: ChainImpl: property .inputBufferSize has null value
10:05:19.974 Thread-515: ChainImpl: getting property .inputBuffers
10:05:19.975 Thread-515: ChainImpl: property .inputBuffers has null value
10:05:19.975 Thread-515: BufferPool: init
10:05:19.976 Thread-515: ChainSource: source created
10:05:19.977 Thread-515: ChainImpl: getting property scfilter.link
10:05:19.977 Thread-515: ChainImpl: property scfilter.link has literal value 'source'
10:05:19.978 Thread-515: ChainImpl: getting property scfilter.mode
10:05:19.978 Thread-516: HTTPConnection: reading HTTP request
10:05:19.979 Thread-515: ChainImpl: property scfilter.mode has literal value 'out'
10:05:19.979 Thread-515: ChainImpl: addFilter org.jstreamer.core.ChainSource@1d580a8
10:05:19.980 Thread-515: LinkBase: adding output filter org.jstreamer.lib.ShoutcastFilter@1f1c19e
10:05:19.980 Thread-515: created new root chain org.jstreamer.core.ChainImpl@de86b6
10:05:19.981 Thread-515: ChainImpl: setting property .requestPath to 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:05:19.981 Thread-515: ChainImpl: setting property .requestMethod to 'GET'
10:05:19.982 Thread-515: ChainImpl: setting property .requestHeaders to 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:05:19.983 Thread-515: ChainImpl: addTarget org.jstreamer.core.ChainTarget@13521ec
10:05:19.984 Thread-515: ChainTarget: init
10:05:19.984 Thread-515: LinkBase: adding input filter com.minimstreamer.HTTPRequestTarget$TargetFilter@1463073
10:05:19.985 Thread-515: ChainTarget: target created
10:05:19.986 Thread-515: ChainImpl: getting property adfilter.link
10:05:19.986 Thread-515: ChainImpl: property adfilter.link has literal value 'request'
10:05:19.987 Thread-515: ChainImpl: getting property adfilter.mode
10:05:19.987 Thread-515: ChainImpl: property adfilter.mode has null value
10:05:19.988 Thread-515: ChainImpl: addFilter org.jstreamer.core.ChainTarget@13521ec
10:05:19.988 Thread-515: LinkBase: adding input filter org.jstreamer.lib.FrameFilter@116e01c
10:05:19.989 Thread-515: ChainImpl: setting property .timeout to '2000'
10:05:19.989 Thread-515: ChainImpl: setting property object .@timeoutAction to com.minimstreamer.Streamer$TimeoutAction@1e897cc
10:05:19.990 Thread-515: ChainImpl: setting property object .@notifyStopped to com.minimstreamer.Streamer$NotifyStopped@146096c
10:05:19.990 Thread-515: ChainImpl: setting property object .@httpRequest to org.jminim.lib.HTTPConnection$Request@114cc93
10:05:19.991 Thread-515: ChainImpl: setting property object .@http to org.jminim.lib.HTTPContext@1ca88c8
10:05:19.991 Thread-515: ChainImpl: setting property .transcodeType to ''
10:05:19.992 Thread-515: ChainImpl: setting property object .@streamer to com.minimstreamer.Streamer@1c9e7ec
10:05:19.992 Thread-515: ChainImpl: setting property object .@parentChain to org.jstreamer.core.ChainImpl@de86b6
10:05:19.993 Thread-515: Streamer: adding request chain for org.jminim.lib.HTTPConnection$Request@114cc93: org.jstreamer.core.ChainImpl@d379e8
10:05:19.993 Thread-515: ChainImpl: addTargetChain org.jstreamer.core.TargetChain@830606
10:05:19.994 Thread-515: TargetChain: init
10:05:19.994 Thread-515: BufferPoolReader: new
10:05:19.995 Thread-515: Buffer: createReader: org.jstreamer.core.Buffer@7d68
10:05:20.009 Thread-515: BufferReader: initial readSequence=1
10:05:20.010 Thread-515: Buffer: createReader: org.jstreamer.core.Buffer@2963fb
10:05:20.010 Thread-515: BufferReader: initial readSequence=1
10:05:20.011 Thread-515: ChainImpl: start org.jstreamer.core.ChainImpl@de86b6
10:05:20.011 Thread-515: ChainImpl: startLinks org.jstreamer.core.ChainImpl@de86b6
10:05:20.012 Thread-515: ChainImpl: starting chain org.jstreamer.core.ChainImpl@de86b6
10:05:20.012 Thread-515: TargetChain: start
10:05:20.013 Thread-515: TargetChain: starting subchain links
10:05:20.013 Thread-515: ChainImpl: startLinks org.jstreamer.core.ChainImpl@d379e8
10:05:20.013 Thread-515: ChainImpl: starting chain org.jstreamer.core.ChainImpl@d379e8
10:05:20.014 Thread-515: ChainTarget: start
10:05:20.014 Thread-515: ChainImpl: property obj request.@notifyStopped is reference to .@notifyStopped
10:05:20.015 Thread-515: ChainImpl: property object request.@notifyStopped has value com.minimstreamer.Streamer$NotifyStopped@146096c
10:05:20.015 Thread-515: ChainImpl: property obj request.@httpRequest is reference to .@httpRequest
10:05:20.016 Thread-515: ChainImpl: property object request.@httpRequest has value org.jminim.lib.HTTPConnection$Request@114cc93
10:05:20.016 Thread-515: ChainImpl: property obj request.@http is reference to .@http
10:05:20.017 Thread-515: ChainImpl: property object request.@http has value org.jminim.lib.HTTPContext@1ca88c8
10:05:20.017 Thread-515: ChainImpl: property obj request.@timeoutAction is reference to .@timeoutAction
10:05:20.018 Thread-515: ChainImpl: property object request.@timeoutAction has value com.minimstreamer.Streamer$TimeoutAction@1e897cc
10:05:20.022 Thread-515: ChainImpl: getting property request.timeout
10:05:20.022 Thread-515: ChainImpl: property request.timeout has initial value '$.timeout'
10:05:20.023 Thread-515: ChainImpl: property .timeout has literal value '2000'
10:05:20.023 Thread-515: ChainImpl: substitution property .timeout has value '2000'
10:05:20.024 Thread-515: ChainImpl: property request.timeout has final value '2000'
10:05:20.024 Thread-515: HTTPRequestTarget: timeout is 2000
10:05:20.025 Thread-515: HTTPRequestTarget: initRequest socket=Socket[addr=/192.168.0.20,port=3582,localport=9790] this=com.minimstreamer.HTTPRequestTarget@15e3a0c outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@82d2bf
10:05:20.026 Thread-515: ChainTarget: target started
10:05:20.027 Thread-515: ChainImpl: started chain org.jstreamer.core.ChainImpl@d379e8
10:05:20.027 Thread-515: TargetChain: subchain links started
10:05:20.027 Thread-515: ChainSource: start
10:05:20.028 Thread-515: ChainImpl: getting property source.resource
10:05:20.029 Thread-515: ChainImpl: property source.resource has initial value '$.requestPath'
10:05:20.029 Thread-515: ChainImpl: property .requestPath has literal value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:05:20.029 Thread-515: ChainImpl: substitution property .requestPath has value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:05:20.030 Thread-515: ChainImpl: property source.resource has final value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:05:20.030 Thread-515: ChainImpl: getting property source.requestMethod
10:05:20.031 Thread-515: ChainImpl: property source.requestMethod has initial value '$.requestMethod'
10:05:20.031 Thread-515: ChainImpl: property .requestMethod has literal value 'GET'
10:05:20.032 Thread-515: ChainImpl: substitution property .requestMethod has value 'GET'
10:05:20.032 Thread-515: ChainImpl: property source.requestMethod has final value 'GET'
10:05:20.033 Thread-515: ChainImpl: getting property source.requestHeaders
10:05:20.033 Thread-515: ChainImpl: property source.requestHeaders has initial value '$.requestHeaders'
10:05:20.034 Thread-515: ChainImpl: property .requestHeaders has literal value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:05:20.034 Thread-515: ChainImpl: substitution property .requestHeaders has value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:05:20.035 Thread-515: ChainImpl: property source.requestHeaders has final value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:05:20.073 Thread-515: HTTPSource: created outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.192,port=80,localport=58253]
10:05:20.075 Thread-515: HTTPSource: sending HTTP request:
GET /media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8 HTTP/1.1
Host: a.files.bbci.co.uk
ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

10:05:20.218 Thread-515: HTTPSource: stream response status HTTP/1.1 200 OK
10:05:20.225 Thread-515: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
10:05:20.243 Thread-515: x-amz-id-2: AElQV6K45JyJ2KUHrwCVIFs5eESWe7XU7gMQ3FFppNNo7oe15gXqxs1lb1atOzoXge4RfHh3PtI=
x-amz-request-id: CB35EC00D12993E6
Last-Modified: Mon, 23 Feb 2015 12:57:06 GMT
ETag: "63d4e22dd630ccd330c3b3841e909eed"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 234
Server: AmazonS3
Cache-Control: max-age=294
Expires: Tue, 24 Feb 2015 10:10:14 GMT
Date: Tue, 24 Feb 2015 10:05:20 GMT
Connection: keep-alive
access-control-max-age: 300
access-control-allow-credentials: false
access-control-allow-headers: *
access-control-allow-methods: HEAD,GET
access-control-allow-origin: *

10:05:20.243 Thread-515: ChainImpl: setting property source.responseHeaders to 'x-amz-id-2: AElQV6K45JyJ2KUHrwCVIFs5eESWe7XU7gMQ3FFppNNo7oe15gXqxs1lb1atOzoXge4RfHh3PtI=
x-amz-request-id: CB35EC00D12993E6
Last-Modified: Mon, 23 Feb 2015 12:57:06 GMT
ETag: "63d4e22dd630ccd330c3b3841e909eed"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 234
Server: AmazonS3
Cache-Control: max-age=294
Expires: Tue, 24 Feb 2015 10:10:14 GMT
Date: Tue, 24 Feb 2015 10:05:20 GMT
Connection: keep-alive
access-control-max-age: 300
access-control-allow-credentials: false
access-control-allow-headers: *
access-control-allow-methods: HEAD,GET
access-control-allow-origin: *
'
10:05:20.244 Thread-515: HTTPSource: content type is 'application/x-mpegurl'
10:05:20.245 Thread-515: HTTPSource: reading playlist from URL http://a.files.bbci.co.uk/media/live/man...o_one.m3u8
10:05:20.246 Thread-515: HTTPSource: using HLS
10:05:20.246 Thread-515: HTTPSource: found valid stream URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
10:05:20.247 Thread-515: HTTPSource: reading HLS media playlist from URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
10:05:20.248 Thread-515: ChainImpl: setting property source.responseHeaders to ''
10:05:20.344 Thread-515: adding media segment 222620675
10:05:20.347 Thread-515: adding media segment 222620676
10:05:20.351 Thread-515: adding media segment 222620677
10:05:20.352 Thread-515: adding media segment 222620678
10:05:20.352 Thread-515: adding media segment 222620679
10:05:20.364 Thread-518: starting to play HLS stream
10:05:20.364 Thread-518: skipping media segment 222620675
10:05:20.365 Thread-518: skipping media segment 222620676
10:05:20.365 Thread-518: skipping media segment 222620677
10:05:20.366 Thread-518: playing media segment 222620678
10:05:20.431 Thread-518: media segment content type is video/mp2t
10:05:20.433 Thread-515: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
10:05:20.433 Thread-515: ChainImpl: setting property source.contentType to 'audio/aac'
10:05:20.434 Thread-515: ChainImpl: setting property source.contentFormat to 'aac'
10:05:20.434 Thread-515: ChainImpl: setting property source.responseMessage to ''
10:05:20.435 Thread-515: ChainImpl: setting property source.sourcePath to '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:05:20.436 Thread-515: ChainSource: source started
10:05:20.436 Thread-515: ChainImpl: started chain org.jstreamer.core.ChainImpl@de86b6
10:05:20.437 Thread-515: ChainImpl: runLinks org.jstreamer.core.ChainImpl@de86b6
10:05:20.437 Thread-515: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@de86b6
10:05:20.440 Thread-515: TargetChain: run
10:05:20.441 Thread-515: TargetChain: running subchain links
10:05:20.441 Thread-515: ChainImpl: runLinks org.jstreamer.core.ChainImpl@d379e8
10:05:20.443 Thread-515: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@d379e8
10:05:20.443 Thread-515: ChainTarget: run
10:05:20.444 Thread-515: ChainImpl: getting property request.transcodeType
10:05:20.444 Thread-515: ChainImpl: property request.transcodeType has initial value '$.transcodeType'
10:05:20.445 Thread-515: ChainImpl: property .transcodeType has literal value ''
10:05:20.457 Thread-515: ChainImpl: substitution property .transcodeType has value ''
10:05:20.457 Thread-515: ChainImpl: property request.transcodeType has final value ''
10:05:20.459 Thread-515: ChainImpl: getting property request.transcodeLimit
10:05:20.459 Thread-515: ChainImpl: property request.transcodeLimit has null value
10:05:20.461 Thread-515: ChainImpl: getting property request.contentType
10:05:20.462 Thread-515: ChainImpl: property request.contentType has initial value '$/source.contentType'
10:05:20.463 Thread-515: ChainImpl: property source.contentType has literal value 'audio/aac'
10:05:20.463 Thread-515: ChainImpl: substitution property /source.contentType has value 'audio/aac'
10:05:20.464 Thread-515: ChainImpl: property request.contentType has final value 'audio/aac'
10:05:20.465 Thread-515: ChainImpl: property obj request.@streamer is reference to .@streamer
10:05:20.466 Thread-515: ChainImpl: property object request.@streamer has value com.minimstreamer.Streamer@1c9e7ec
10:05:20.467 Thread-515: ChainTarget: target running
10:05:20.467 Thread-515: ChainTarget: starting writer thread
10:05:20.480 Thread-515: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@d379e8
10:05:20.480 Thread-515: TargetChain: subchain links running
10:05:20.481 Thread-515: ChainSource: run
10:05:20.481 Thread-515: ChainSource: source running
10:05:20.482 Thread-515: ChainSource: starting reader thread
10:05:20.489 Thread-515: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@de86b6
10:05:20.489 Thread-515: Streamer: waiting for completion of network request
10:05:20.490 Thread-515: Streamer.NotifyStopped: waitFor
10:05:20.490 Thread-515: Streamer.NotifyStopped: waiting
10:05:21.444 Thread-520: ChainImpl: getting property scfilter.responseHeaders
10:05:21.447 Thread-520: ChainImpl: property scfilter.responseHeaders has initial value '$source.responseHeaders'
10:05:21.453 Thread-520: ChainImpl: property source.responseHeaders has literal value ''
10:05:21.454 Thread-520: ChainImpl: substitution property source.responseHeaders has value ''
10:05:21.454 Thread-520: ChainImpl: property scfilter.responseHeaders has final value ''
10:05:21.455 Thread-520: ShoutcastFilter: response headers=
10:05:21.456 Thread-520: ShoutcastFilter: icyMetaint=0
10:05:21.468 Thread-519: ChainImpl: getting property request.delay
10:05:21.468 Thread-519: ChainImpl: property request.delay has null value
10:05:21.469 Thread-519: ChainImpl: getting property request.responseHeaders
10:05:21.470 Thread-519: ChainImpl: property request.responseHeaders has null value
10:05:21.470 Thread-519: ChainImpl: getting property request.status
10:05:21.470 Thread-519: ChainImpl: property request.status has initial value '$/source.status'
10:05:21.471 Thread-519: ChainImpl: property source.status has literal value 'HTTP/1.1 200 OK
'
10:05:21.471 Thread-519: ChainImpl: substitution property /source.status has value 'HTTP/1.1 200 OK
'
10:05:21.472 Thread-519: ChainImpl: property request.status has final value 'HTTP/1.1 200 OK
'
10:05:21.472 Thread-519: ChainImpl: getting property request.sourceResponseHeaders
10:05:21.473 Thread-519: ChainImpl: property request.sourceResponseHeaders has initial value '$/source.responseHeaders'
10:05:21.473 Thread-519: ChainImpl: property source.responseHeaders has literal value ''
10:05:21.474 Thread-519: ChainImpl: substitution property /source.responseHeaders has value ''
10:05:21.474 Thread-519: ChainImpl: property request.sourceResponseHeaders has final value ''
10:05:21.477 Thread-519: ChainImpl: getting property request.sourcePath
10:05:21.478 Thread-519: ChainImpl: property request.sourcePath has initial value '$/source.sourcePath'
10:05:21.479 Thread-519: ChainImpl: property source.sourcePath has literal value '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:05:21.479 Thread-519: ChainImpl: substitution property /source.sourcePath has value '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:05:21.480 Thread-519: ChainImpl: property request.sourcePath has final value '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:05:21.481 Thread-519: HTTP/1.1 200 OK, Date: Tue, 24 Feb 2015 10:05:21 GMT, Connection: close, Server: MinimStreamer, Content-Type: audio/aac
10:05:21.482 Thread-519: ChainImpl: getting property adfilter.contentType
10:05:21.482 Thread-519: ChainImpl: property adfilter.contentType has initial value '$/source.contentType'
10:05:21.483 Thread-519: ChainImpl: property source.contentType has literal value 'audio/aac'
10:05:21.484 Thread-519: ChainImpl: substitution property /source.contentType has value 'audio/aac'
10:05:21.484 Thread-519: ChainImpl: property adfilter.contentType has final value 'audio/aac'
10:05:21.485 Thread-519: FrameFilter: contentType is 'audio/aac'
10:05:21.486 Thread-519: ADTSFilter: state SYNC1 at position 0
10:05:21.487 Thread-519: ADTSFilter: state SYNC2 at position 1
10:05:21.489 Thread-519: ADTSFilter: state SYNC3 at position 2
10:05:21.489 Thread-519: ADTSFilter: state SYNCED at position 3
10:05:21.900 Thread-518: finished writing 258074 bytes
10:05:21.915 Thread-518: playing media segment 222620679
10:05:22.761 Thread-518: finished writing 258133 bytes
10:05:23.783 Thread-518: adding media segment 222620680
10:05:23.795 Thread-518: playing media segment 222620680
10:05:26.863 Thread-518: finished writing 258042 bytes
10:05:27.310 Thread-518: adding media segment 222620681
10:05:27.316 Thread-518: playing media segment 222620681
10:05:30.686 Thread-518: finished writing 258143 bytes
10:05:34.323 Thread-518: adding media segment 222620682
10:05:34.336 Thread-518: playing media segment 222620682
10:05:34.878 Thread-518: finished writing 258079 bytes
10:05:44.826 Thread-518: adding media segment 222620683
10:05:44.839 Thread-518: playing media segment 222620683
10:05:45.460 Thread-518: finished writing 258108 bytes
10:05:48.339 Thread-518: adding media segment 222620684
10:05:48.346 Thread-518: playing media segment 222620684
10:05:48.850 Thread-518: finished writing 258060 bytes
10:05:53.585 Thread-518: adding media segment 222620685
10:05:53.598 Thread-518: playing media segment 222620685
10:05:54.105 Thread-518: finished writing 258100 bytes
10:06:00.574 Thread-518: adding media segment 222620686
10:06:00.587 Thread-518: playing media segment 222620686
10:06:01.095 Thread-518: finished writing 258293 bytes
10:06:07.574 Thread-518: adding media segment 222620687
10:06:07.581 Thread-518: playing media segment 222620687
10:06:08.098 Thread-518: finished writing 257956 bytes
10:06:14.601 Thread-518: adding media segment 222620688
10:06:14.614 Thread-518: playing media segment 222620688
10:06:15.124 Thread-518: finished writing 258092 bytes
10:06:19.831 Thread-518: adding media segment 222620689
10:06:19.848 Thread-518: playing media segment 222620689
10:06:20.364 Thread-518: finished writing 258202 bytes

simoncn · 24-02-2015, 18:27

(24-02-2015 11:09)jack_c85 Wrote: Here are my findings... we got lucky and a dropout occurred whilst logging and it looks quite different to normal streaming so hopefully you can see whats going on... it happens at 10:05:09 and lasts around 10 seconds.

Thanks for this. New media segments are supposed to arrive from the BBC every 7 seconds. Whn the dropout happened, nothing arrived between 10:04:56.438 and 10:05:09.569 (a gap of 13 seconds). At that point, it appears the Sonos ran out of stream data to play and it closed the connection to MinimServer.

I don't know why there was a 13-second gap. This might be caused by an issue with the BBC servers or a problem with your internet connection. I will add some additional debug output in the next MinimStreamer update, which should provide more information. To prevent this, it might be necessary to increase internal buffering within MinimStreamer, which would unfortunately cause the stream to be played with an additional 7 seconds of delay from "real time" analogue radio.

jack_c85 · 24-02-2015, 18:41

(24-02-2015 18:27)simoncn Wrote:
(24-02-2015 11:09)jack_c85 Wrote: Here are my findings... we got lucky and a dropout occurred whilst logging and it looks quite different to normal streaming so hopefully you can see whats going on... it happens at 10:05:09 and lasts around 10 seconds.

Thanks for this. New media segments are supposed to arrive from the BBC every 7 seconds. Whn the dropout happened, nothing arrived between 10:04:56.438 and 10:05:09.569 (a gap of 13 seconds). At that point, it appears the Sonos ran out of stream data to play and it closed the connection to MinimServer.

I don't know why there was a 13-second gap. This might be caused by an issue with the BBC servers or a problem with your internet connection. I will add some additional debug output in the next MinimStreamer update, which should provide more information. To prevent this, it might be necessary to increase internal buffering within MinimStreamer, which would unfortunately cause the stream to be played with an additional 7 seconds of delay from "real time" analogue radio.

Thats good to know it's not really my system although could be my internet connection (I doubt it though as I have fibre broadband and get a connection speed of just under 40Mbps).

I personally wouldn't mind 7 seconds delay, would much rather this than experience drop outs. Is this a setting I can adjust or is that something you'd have to do in an update?

Many thanks for your great service.

Jack

simoncn · 24-02-2015, 19:12

(24-02-2015 18:41)jack_c85 Wrote: Thats good to know it's not really my system although could be my internet connection (I doubt it though as I have fibre broadband and get a connection speed of just under 40Mbps).

I personally wouldn't mind 7 seconds delay, would much rather this than experience drop outs. Is this a setting I can adjust or is that something you'd have to do in an update?

Many thanks for your great service.

Jack

There is no adjustable setting for this at present. This might be available in a future update. Before I do this, I would like to add the extra debug logging to make sure I know exactly what's happening.

jack_c85 · 24-02-2015, 19:17

(24-02-2015 19:12)simoncn Wrote:
(24-02-2015 18:41)jack_c85 Wrote: Thats good to know it's not really my system although could be my internet connection (I doubt it though as I have fibre broadband and get a connection speed of just under 40Mbps).

I personally wouldn't mind 7 seconds delay, would much rather this than experience drop outs. Is this a setting I can adjust or is that something you'd have to do in an update?

Many thanks for your great service.

Jack

There is no adjustable setting for this at present. This might be available in a future update. Before I do this, I would like to add the extra debug logging to make sure I know exactly what's happening.

Great, thanks. Let me know when the updat is available and I'll get you some more logs.

jack_c85 · 25-02-2015, 11:53

(24-02-2015 19:17)jack_c85 Wrote:
(24-02-2015 19:12)simoncn Wrote:
(24-02-2015 18:41)jack_c85 Wrote: Thats good to know it's not really my system although could be my internet connection (I doubt it though as I have fibre broadband and get a connection speed of just under 40Mbps).

I personally wouldn't mind 7 seconds delay, would much rather this than experience drop outs. Is this a setting I can adjust or is that something you'd have to do in an update?

Many thanks for your great service.

Jack

There is no adjustable setting for this at present. This might be available in a future update. Before I do this, I would like to add the extra debug logging to make sure I know exactly what's happening.

Great, thanks. Let me know when the updat is available and I'll get you some more logs.

Doing some more tests this end, I ran the server on my Mac instead of Raspberry Pi to see if that was the cause of the issue and the dropout still occurred... I was taking Debug logs at the time and this is the result this time, is it the same?

10:48:03.617 Thread-113: adding media segment 222634580
10:48:03.617 Thread-113: playing media segment 222634580
10:48:03.976 Thread-113: finished writing 258109 bytes
10:48:10.559 Thread-113: adding media segment 222634581
10:48:10.559 Thread-113: playing media segment 222634581
10:48:10.859 Thread-113: finished writing 258100 bytes
10:48:14.061 Thread-113: adding media segment 222634582
10:48:14.061 Thread-113: playing media segment 222634582
10:48:14.237 Thread-113: finished writing 258103 bytes
10:48:19.316 Thread-113: adding media segment 222634583
10:48:19.317 Thread-113: playing media segment 222634583
10:48:19.504 Thread-113: finished writing 258122 bytes
10:48:26.311 Thread-113: adding media segment 222634584
10:48:26.311 Thread-113: playing media segment 222634584
10:48:26.520 Thread-113: finished writing 258088 bytes
10:48:33.331 Thread-113: adding media segment 222634585
10:48:33.331 Thread-113: playing media segment 222634585
10:48:33.521 Thread-113: finished writing 258107 bytes
10:48:40.369 Thread-113: adding media segment 222634586
10:48:40.370 Thread-113: playing media segment 222634586
10:48:40.550 Thread-113: finished writing 258046 bytes
10:48:45.583 Thread-113: adding media segment 222634587
10:48:45.583 Thread-113: playing media segment 222634587
10:48:45.780 Thread-113: finished writing 258148 bytes
10:48:52.661 Thread-113: adding media segment 222634588
10:48:52.662 Thread-113: playing media segment 222634588
10:48:52.938 Thread-113: finished writing 258069 bytes
10:48:57.847 Thread-113: adding media segment 222634589
10:48:57.848 Thread-113: playing media segment 222634589
10:48:58.033 Thread-113: finished writing 258083 bytes
10:49:06.621 Thread-113: adding media segment 222634590
10:49:06.621 Thread-113: playing media segment 222634590
10:49:06.855 Thread-113: finished writing 258100 bytes
10:49:13.624 Thread-113: adding media segment 222634591
10:49:13.624 Thread-113: playing media segment 222634591
10:49:13.801 Thread-113: finished writing 258157 bytes
10:49:17.130 Thread-113: adding media segment 222634592
10:49:17.131 Thread-113: playing media segment 222634592
10:49:17.390 Thread-113: finished writing 258056 bytes
10:49:24.137 Thread-113: adding media segment 222634593
10:49:24.138 Thread-113: playing media segment 222634593
10:49:24.342 Thread-113: finished writing 258087 bytes
10:49:31.141 Thread-113: adding media segment 222634594
10:49:31.141 Thread-113: playing media segment 222634594
10:49:31.330 Thread-113: finished writing 258142 bytes
10:49:38.154 Thread-113: adding media segment 222634595
10:49:38.154 Thread-113: playing media segment 222634595
10:49:38.333 Thread-113: finished writing 258085 bytes
10:49:43.414 Thread-113: adding media segment 222634596
10:49:43.414 Thread-113: playing media segment 222634596
10:49:43.609 Thread-113: finished writing 258078 bytes
10:49:50.662 Thread-113: adding media segment 222634597
10:49:50.662 Thread-113: playing media segment 222634597
10:49:56.502 Thread-111: HTTPConnection: end of input stream data
10:49:56.503 Thread-111: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@618a2870
10:49:56.503 Thread-111: Streamer: stopping chain org.jstreamer.core.ChainImpl@3cce68b4
10:49:56.503 Thread-111: ChainImpl: stop org.jstreamer.core.ChainImpl@3cce68b4
10:49:56.503 Thread-111: ChainImpl: removing target from org.jstreamer.core.TargetChain@2e4e773d
10:49:56.503 Thread-111: ChainImpl: stop org.jstreamer.core.ChainImpl@5ebce5a
10:49:56.503 Thread-111: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@5ebce5a
10:49:56.503 Thread-111: ChainSource: stopping reader thread
10:49:56.503 Thread-111: ChainSource: stopping source
10:49:56.503 Thread-115: ChainSource: error reading input stream: org.jstreamer.OutputException: java.io.InterruptedIOException
10:49:56.503 Thread-115: Buffer: closing buffer: org.jstreamer.core.Buffer@1e80f32f
10:49:56.503 Thread-114: BufferReader: fillBuffer returned -1: buffer=org.jstreamer.core.Buffer@1e80f32f
10:49:56.503 Thread-114: ChainTarget: end of data from input stream
10:49:56.503 Thread-114: ChainImpl: stop org.jstreamer.core.ChainImpl@3cce68b4
10:49:56.504 Thread-114: BufferPoolReader: close
10:49:56.504 Thread-114: BufferReader: close: buffer=org.jstreamer.core.Buffer@1e80f32f
10:49:56.504 Thread-114: Buffer: removeReader: org.jstreamer.core.Buffer@1e80f32f
10:49:56.504 Thread-114: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@1e80f32f
10:49:56.504 Thread-114: BufferReader: close: buffer=org.jstreamer.core.Buffer@2cfaa13a
10:49:56.504 Thread-114: Buffer: removeReader: org.jstreamer.core.Buffer@2cfaa13a
10:49:56.504 Thread-114: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@2cfaa13a
10:50:01.829 Thread-113: playMediaSegment: write caught exception java.io.IOException: Read end dead
10:50:01.830 Thread-113: HTTPSource.ReaderThread has been interrupted
10:50:01.830 Thread-113: HTTPSource: closing piped output stream
10:50:01.830 Thread-111: HTTPSource: closing outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.192,port=80,localport=62068]
10:50:01.830 Thread-111: ChainSource: source stopped
10:50:01.830 Thread-111: TargetChain: stop
10:50:01.830 Thread-111: TargetChain: stopping subchain
10:50:01.830 Thread-111: ChainImpl: stop org.jstreamer.core.ChainImpl@3cce68b4
10:50:01.830 Thread-111: TargetChain: subchain stopped
10:50:01.830 Thread-111: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@5ebce5a
10:50:01.830 Thread-111: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@3cce68b4
10:50:01.830 Thread-111: ChainTarget: stop
10:50:01.831 Thread-111: ChainTarget: stopping target
10:50:01.831 Thread-111: HTTPRequestTarget: stop this=com.minimstreamer.HTTPRequestTarget@46a3fe1f outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@41a9be4f
10:50:01.831 Thread-111: HTTPRequestTarget: closeSocket
10:50:01.831 Thread-111: HTTPRequestTarget: closing Socket[addr=/192.168.0.20,port=1119,localport=9790]
10:50:01.831 Thread-111: HTTPRequestTarget: notifyStopped com.minimstreamer.Streamer$NotifyStopped@2582e94c
10:50:01.831 Thread-111: Streamer.NotifyStopped: run
10:50:01.831 Thread-111: ChainTarget: target stopped
10:50:01.831 Thread-111: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@3cce68b4
10:50:01.831 Thread-111: HTTPService: removing connection org.jminim.lib.HTTPConnection@4d9ccb20
10:50:01.831 Thread-110: NetworkRequestHandler: thread interrupted
10:50:01.831 Thread-110: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@618a2870
10:50:01.831 Thread-110: ChainImpl: stop org.jstreamer.core.ChainImpl@3cce68b4
10:50:01.831 Thread-110: Streamer: removing request chain for org.jminim.lib.HTTPConnection$Request@618a2870
10:50:01.831 Thread-110: Streamer: completed network request
10:50:01.831 Thread-110: HTTPConnection: completed request; socket=Socket[addr=/192.168.0.20,port=1119,localport=9790], keepAlive=true
10:50:01.831 Thread-110: HTTPConnection: writer thread interrupted
10:50:05.865 Thread-90: HTTPService: accepted incoming connection
10:50:05.865 Thread-90: HTTPService: waiting for incoming connection
10:50:05.865 Thread-89: HTTPService: received request, Socket[addr=/192.168.0.20,port=1131,localport=9790]
10:50:05.865 Thread-89: HTTPService: adding connection org.jminim.lib.HTTPConnection@3dee458f
10:50:05.866 Thread-119: HTTPConnection: writer thread waiting for request
10:50:05.866 Thread-120: HTTPConnection: reading HTTP request
10:50:05.869 Thread-120: GET /minimstreamer/*/R1 HTTP/1.1
10:50:05.869 Thread-120: ACCEPT: */*, HOST: 192.168.0.17:9790, User-Agent: Nullsoft Winamp3 version 3.0 (compatible), Icy-MetaData: 1
10:50:05.869 Thread-119: HTTPConnection: writer thread processing request
10:50:05.869 Thread-120: HTTPConnection: reading HTTP request
10:50:05.869 Thread-119: Streamer: processing HTTP request
10:50:05.869 Thread-119: Streamer: releaseChains
10:50:05.869 Thread-119: Streamer: releasing chain: R1
10:50:05.869 Thread-119: Streamer: streamID is R1
10:50:05.869 Thread-119: Streamer: URL scheme is http
10:50:05.869 Thread-119: Streamer: request path is a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8
10:50:05.869 Thread-119: Streamer: transcodeType is
10:50:05.870 Thread-119: ChainImpl: addSource org.jstreamer.core.ChainSource@45b2a1ac
10:50:05.870 Thread-119: ChainSource: init
10:50:05.870 Thread-119: ChainImpl: getting property .inputBufferSize
10:50:05.870 Thread-119: ChainImpl: property .inputBufferSize has null value
10:50:05.870 Thread-119: ChainImpl: getting property .inputBuffers
10:50:05.870 Thread-119: ChainImpl: property .inputBuffers has null value
10:50:05.870 Thread-119: BufferPool: init
10:50:05.870 Thread-119: ChainSource: source created
10:50:05.870 Thread-119: ChainImpl: getting property scfilter.link
10:50:05.870 Thread-119: ChainImpl: property scfilter.link has literal value 'source'
10:50:05.870 Thread-119: ChainImpl: getting property scfilter.mode
10:50:05.870 Thread-119: ChainImpl: property scfilter.mode has literal value 'out'
10:50:05.870 Thread-119: ChainImpl: addFilter org.jstreamer.core.ChainSource@45b2a1ac
10:50:05.870 Thread-119: LinkBase: adding output filter org.jstreamer.lib.ShoutcastFilter@418d3dc2
10:50:05.870 Thread-119: created new root chain org.jstreamer.core.ChainImpl@48fab97
10:50:05.870 Thread-119: ChainImpl: setting property .requestPath to 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:50:05.870 Thread-119: ChainImpl: setting property .requestMethod to 'GET'
10:50:05.870 Thread-119: ChainImpl: setting property .requestHeaders to 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:50:05.871 Thread-119: ChainImpl: addTarget org.jstreamer.core.ChainTarget@3541cfaa
10:50:05.871 Thread-119: ChainTarget: init
10:50:05.871 Thread-119: LinkBase: adding input filter com.minimstreamer.HTTPRequestTarget$TargetFilter@1d8a87ed
10:50:05.871 Thread-119: ChainTarget: target created
10:50:05.871 Thread-119: ChainImpl: getting property adfilter.link
10:50:05.871 Thread-119: ChainImpl: property adfilter.link has literal value 'request'
10:50:05.871 Thread-119: ChainImpl: getting property adfilter.mode
10:50:05.871 Thread-119: ChainImpl: property adfilter.mode has null value
10:50:05.871 Thread-119: ChainImpl: addFilter org.jstreamer.core.ChainTarget@3541cfaa
10:50:05.871 Thread-119: LinkBase: adding input filter org.jstreamer.lib.FrameFilter@64a054d8
10:50:05.871 Thread-119: ChainImpl: setting property .timeout to '2000'
10:50:05.871 Thread-119: ChainImpl: setting property object .@timeoutAction to com.minimstreamer.Streamer$TimeoutAction@4ff29db8
10:50:05.871 Thread-119: ChainImpl: setting property object .@notifyStopped to com.minimstreamer.Streamer$NotifyStopped@68ece44
10:50:05.871 Thread-119: ChainImpl: setting property object .@httpRequest to org.jminim.lib.HTTPConnection$Request@60ee4cd9
10:50:05.871 Thread-119: ChainImpl: setting property object .@http to org.jminim.lib.HTTPContext@203bb8da
10:50:05.871 Thread-119: ChainImpl: setting property .transcodeType to ''
10:50:05.871 Thread-119: ChainImpl: setting property object .@streamer to com.minimstreamer.Streamer@429bffaa
10:50:05.871 Thread-119: ChainImpl: setting property object .@parentChain to org.jstreamer.core.ChainImpl@48fab97
10:50:05.871 Thread-119: Streamer: adding request chain for org.jminim.lib.HTTPConnection$Request@60ee4cd9: org.jstreamer.core.ChainImpl@74f53013
10:50:05.871 Thread-119: ChainImpl: addTargetChain org.jstreamer.core.TargetChain@3d468d7f
10:50:05.871 Thread-119: TargetChain: init
10:50:05.871 Thread-119: BufferPoolReader: new
10:50:05.871 Thread-119: Buffer: createReader: org.jstreamer.core.Buffer@6682c832
10:50:05.871 Thread-119: BufferReader: initial readSequence=1
10:50:05.872 Thread-119: Buffer: createReader: org.jstreamer.core.Buffer@168ec648
10:50:05.872 Thread-119: BufferReader: initial readSequence=1
10:50:05.872 Thread-119: ChainImpl: start org.jstreamer.core.ChainImpl@48fab97
10:50:05.872 Thread-119: ChainImpl: startLinks org.jstreamer.core.ChainImpl@48fab97
10:50:05.872 Thread-119: ChainImpl: starting chain org.jstreamer.core.ChainImpl@48fab97
10:50:05.872 Thread-119: TargetChain: start
10:50:05.872 Thread-119: TargetChain: starting subchain links
10:50:05.872 Thread-119: ChainImpl: startLinks org.jstreamer.core.ChainImpl@74f53013
10:50:05.872 Thread-119: ChainImpl: starting chain org.jstreamer.core.ChainImpl@74f53013
10:50:05.872 Thread-119: ChainTarget: start
10:50:05.872 Thread-119: ChainImpl: property obj request.@notifyStopped is reference to .@notifyStopped
10:50:05.872 Thread-119: ChainImpl: property object request.@notifyStopped has value com.minimstreamer.Streamer$NotifyStopped@68ece44
10:50:05.872 Thread-119: ChainImpl: property obj request.@httpRequest is reference to .@httpRequest
10:50:05.872 Thread-119: ChainImpl: property object request.@httpRequest has value org.jminim.lib.HTTPConnection$Request@60ee4cd9
10:50:05.872 Thread-119: ChainImpl: property obj request.@http is reference to .@http
10:50:05.872 Thread-119: ChainImpl: property object request.@http has value org.jminim.lib.HTTPContext@203bb8da
10:50:05.872 Thread-119: ChainImpl: property obj request.@timeoutAction is reference to .@timeoutAction
10:50:05.872 Thread-119: ChainImpl: property object request.@timeoutAction has value com.minimstreamer.Streamer$TimeoutAction@4ff29db8
10:50:05.872 Thread-119: ChainImpl: getting property request.timeout
10:50:05.872 Thread-119: ChainImpl: property request.timeout has initial value '$.timeout'
10:50:05.872 Thread-119: ChainImpl: property .timeout has literal value '2000'
10:50:05.872 Thread-119: ChainImpl: substitution property .timeout has value '2000'
10:50:05.872 Thread-119: ChainImpl: property request.timeout has final value '2000'
10:50:05.872 Thread-119: HTTPRequestTarget: timeout is 2000
10:50:05.873 Thread-119: HTTPRequestTarget: initRequest socket=Socket[addr=/192.168.0.20,port=1131,localport=9790] this=com.minimstreamer.HTTPRequestTarget@65aebd72 outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@db0805c
10:50:05.873 Thread-119: ChainTarget: target started
10:50:05.873 Thread-119: ChainImpl: started chain org.jstreamer.core.ChainImpl@74f53013
10:50:05.873 Thread-119: TargetChain: subchain links started
10:50:05.873 Thread-119: ChainSource: start
10:50:05.873 Thread-119: ChainImpl: getting property source.resource
10:50:05.873 Thread-119: ChainImpl: property source.resource has initial value '$.requestPath'
10:50:05.873 Thread-119: ChainImpl: property .requestPath has literal value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:50:05.873 Thread-119: ChainImpl: substitution property .requestPath has value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:50:05.873 Thread-119: ChainImpl: property source.resource has final value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8'
10:50:05.873 Thread-119: ChainImpl: getting property source.requestMethod
10:50:05.873 Thread-119: ChainImpl: property source.requestMethod has initial value '$.requestMethod'
10:50:05.873 Thread-119: ChainImpl: property .requestMethod has literal value 'GET'
10:50:05.873 Thread-119: ChainImpl: substitution property .requestMethod has value 'GET'
10:50:05.873 Thread-119: ChainImpl: property source.requestMethod has final value 'GET'
10:50:05.873 Thread-119: ChainImpl: getting property source.requestHeaders
10:50:05.873 Thread-119: ChainImpl: property source.requestHeaders has initial value '$.requestHeaders'
10:50:05.873 Thread-119: ChainImpl: property .requestHeaders has literal value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:50:05.873 Thread-119: ChainImpl: substitution property .requestHeaders has value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:50:05.873 Thread-119: ChainImpl: property source.requestHeaders has final value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
10:50:05.913 Thread-119: HTTPSource: created outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.195,port=80,localport=62646]
10:50:05.913 Thread-119: HTTPSource: sending HTTP request:
GET /media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_one.m3u8 HTTP/1.1
Host: a.files.bbci.co.uk
ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

10:50:06.016 Thread-119: HTTPSource: stream response status HTTP/1.1 200 OK
10:50:06.016 Thread-119: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
10:50:06.018 Thread-119: x-amz-id-2: AElQV6K45JyJ2KUHrwCVIFs5eESWe7XU7gMQ3FFppNNo7oe15gXqxs1lb1atOzoXge4RfHh3PtI=
x-amz-request-id: CB35EC00D12993E6
Last-Modified: Mon, 23 Feb 2015 12:57:06 GMT
ETag: "63d4e22dd630ccd330c3b3841e909eed"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 234
Server: AmazonS3
Cache-Control: max-age=286
Expires: Wed, 25 Feb 2015 10:54:52 GMT
Date: Wed, 25 Feb 2015 10:50:06 GMT
Connection: keep-alive
access-control-max-age: 300
access-control-allow-credentials: false
access-control-allow-headers: *
access-control-allow-methods: HEAD,GET
access-control-allow-origin: *

10:50:06.018 Thread-119: ChainImpl: setting property source.responseHeaders to 'x-amz-id-2: AElQV6K45JyJ2KUHrwCVIFs5eESWe7XU7gMQ3FFppNNo7oe15gXqxs1lb1atOzoXge4RfHh3PtI=
x-amz-request-id: CB35EC00D12993E6
Last-Modified: Mon, 23 Feb 2015 12:57:06 GMT
ETag: "63d4e22dd630ccd330c3b3841e909eed"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 234
Server: AmazonS3
Cache-Control: max-age=286
Expires: Wed, 25 Feb 2015 10:54:52 GMT
Date: Wed, 25 Feb 2015 10:50:06 GMT
Connection: keep-alive
access-control-max-age: 300
access-control-allow-credentials: false
access-control-allow-headers: *
access-control-allow-methods: HEAD,GET
access-control-allow-origin: *
'
10:50:06.018 Thread-119: HTTPSource: content type is 'application/x-mpegurl'
10:50:06.018 Thread-119: HTTPSource: reading playlist from URL http://a.files.bbci.co.uk/media/live/man...o_one.m3u8
10:50:06.018 Thread-119: HTTPSource: using HLS
10:50:06.018 Thread-119: HTTPSource: found valid stream URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
10:50:06.018 Thread-119: HTTPSource: reading HLS media playlist from URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
10:50:06.018 Thread-119: ChainImpl: setting property source.responseHeaders to ''
10:50:06.083 Thread-119: adding media segment 222634595
10:50:06.083 Thread-119: adding media segment 222634596
10:50:06.083 Thread-119: adding media segment 222634597
10:50:06.083 Thread-119: adding media segment 222634598
10:50:06.083 Thread-119: adding media segment 222634599
10:50:06.083 Thread-122: starting to play HLS stream
10:50:06.083 Thread-122: skipping media segment 222634595
10:50:06.083 Thread-122: skipping media segment 222634596
10:50:06.083 Thread-122: skipping media segment 222634597
10:50:06.083 Thread-122: playing media segment 222634598
10:50:06.148 Thread-122: media segment content type is video/mp2t
10:50:06.148 Thread-119: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
10:50:06.148 Thread-119: ChainImpl: setting property source.contentType to 'audio/aac'
10:50:06.148 Thread-119: ChainImpl: setting property source.contentFormat to 'aac'
10:50:06.148 Thread-119: ChainImpl: setting property source.responseMessage to ''
10:50:06.148 Thread-119: ChainImpl: setting property source.sourcePath to '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:50:06.149 Thread-119: ChainSource: source started
10:50:06.149 Thread-119: ChainImpl: started chain org.jstreamer.core.ChainImpl@48fab97
10:50:06.149 Thread-119: ChainImpl: runLinks org.jstreamer.core.ChainImpl@48fab97
10:50:06.149 Thread-119: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@48fab97
10:50:06.149 Thread-119: TargetChain: run
10:50:06.149 Thread-119: TargetChain: running subchain links
10:50:06.149 Thread-119: ChainImpl: runLinks org.jstreamer.core.ChainImpl@74f53013
10:50:06.149 Thread-119: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@74f53013
10:50:06.149 Thread-119: ChainTarget: run
10:50:06.149 Thread-119: ChainImpl: getting property request.transcodeType
10:50:06.149 Thread-119: ChainImpl: property request.transcodeType has initial value '$.transcodeType'
10:50:06.149 Thread-119: ChainImpl: property .transcodeType has literal value ''
10:50:06.149 Thread-119: ChainImpl: substitution property .transcodeType has value ''
10:50:06.149 Thread-119: ChainImpl: property request.transcodeType has final value ''
10:50:06.149 Thread-119: ChainImpl: getting property request.transcodeLimit
10:50:06.149 Thread-119: ChainImpl: property request.transcodeLimit has null value
10:50:06.149 Thread-119: ChainImpl: getting property request.contentType
10:50:06.149 Thread-119: ChainImpl: property request.contentType has initial value '$/source.contentType'
10:50:06.149 Thread-119: ChainImpl: property source.contentType has literal value 'audio/aac'
10:50:06.149 Thread-119: ChainImpl: substitution property /source.contentType has value 'audio/aac'
10:50:06.149 Thread-119: ChainImpl: property request.contentType has final value 'audio/aac'
10:50:06.149 Thread-119: ChainImpl: property obj request.@streamer is reference to .@streamer
10:50:06.149 Thread-119: ChainImpl: property object request.@streamer has value com.minimstreamer.Streamer@429bffaa
10:50:06.149 Thread-119: ChainTarget: target running
10:50:06.149 Thread-119: ChainTarget: starting writer thread
10:50:06.149 Thread-119: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@74f53013
10:50:06.150 Thread-119: TargetChain: subchain links running
10:50:06.150 Thread-119: ChainSource: run
10:50:06.150 Thread-119: ChainSource: source running
10:50:06.150 Thread-119: ChainSource: starting reader thread
10:50:06.150 Thread-119: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@48fab97
10:50:06.150 Thread-119: Streamer: waiting for completion of network request
10:50:06.150 Thread-119: Streamer.NotifyStopped: waitFor
10:50:06.150 Thread-119: Streamer.NotifyStopped: waiting
10:50:07.150 Thread-124: ChainImpl: getting property scfilter.responseHeaders
10:50:07.150 Thread-124: ChainImpl: property scfilter.responseHeaders has initial value '$source.responseHeaders'
10:50:07.150 Thread-124: ChainImpl: property source.responseHeaders has literal value ''
10:50:07.150 Thread-124: ChainImpl: substitution property source.responseHeaders has value ''
10:50:07.150 Thread-124: ChainImpl: property scfilter.responseHeaders has final value ''
10:50:07.151 Thread-124: ShoutcastFilter: response headers=
10:50:07.151 Thread-124: ShoutcastFilter: icyMetaint=0
10:50:07.151 Thread-123: ChainImpl: getting property request.delay
10:50:07.151 Thread-123: ChainImpl: property request.delay has null value
10:50:07.151 Thread-123: ChainImpl: getting property request.responseHeaders
10:50:07.151 Thread-123: ChainImpl: property request.responseHeaders has null value
10:50:07.151 Thread-123: ChainImpl: getting property request.status
10:50:07.151 Thread-123: ChainImpl: property request.status has initial value '$/source.status'
10:50:07.151 Thread-123: ChainImpl: property source.status has literal value 'HTTP/1.1 200 OK
'
10:50:07.151 Thread-123: ChainImpl: substitution property /source.status has value 'HTTP/1.1 200 OK
'
10:50:07.151 Thread-123: ChainImpl: property request.status has final value 'HTTP/1.1 200 OK
'
10:50:07.151 Thread-123: ChainImpl: getting property request.sourceResponseHeaders
10:50:07.151 Thread-123: ChainImpl: property request.sourceResponseHeaders has initial value '$/source.responseHeaders'
10:50:07.151 Thread-123: ChainImpl: property source.responseHeaders has literal value ''
10:50:07.151 Thread-123: ChainImpl: substitution property /source.responseHeaders has value ''
10:50:07.151 Thread-123: ChainImpl: property request.sourceResponseHeaders has final value ''
10:50:07.151 Thread-123: ChainImpl: getting property request.sourcePath
10:50:07.151 Thread-123: ChainImpl: property request.sourcePath has initial value '$/source.sourcePath'
10:50:07.151 Thread-123: ChainImpl: property source.sourcePath has literal value '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:50:07.151 Thread-123: ChainImpl: substitution property /source.sourcePath has value '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:50:07.151 Thread-123: ChainImpl: property request.sourcePath has final value '/pool_7/live/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d320000.m3u8'
10:50:07.151 Thread-123: HTTP/1.1 200 OK, Date: Wed, 25 Feb 2015 10:50:07 GMT, Connection: close, Server: MinimStreamer, Content-Type: audio/aac
10:50:07.152 Thread-123: ChainImpl: getting property adfilter.contentType
10:50:07.152 Thread-123: ChainImpl: property adfilter.contentType has initial value '$/source.contentType'
10:50:07.152 Thread-123: ChainImpl: property source.contentType has literal value 'audio/aac'
10:50:07.152 Thread-123: ChainImpl: substitution property /source.contentType has value 'audio/aac'
10:50:07.152 Thread-123: ChainImpl: property adfilter.contentType has final value 'audio/aac'
10:50:07.152 Thread-123: FrameFilter: contentType is 'audio/aac'
10:50:07.152 Thread-123: ADTSFilter: state SYNC1 at position 0
10:50:07.152 Thread-123: ADTSFilter: state SYNC2 at position 1
10:50:07.152 Thread-123: ADTSFilter: state SYNC3 at position 2
10:50:07.152 Thread-123: ADTSFilter: state SYNCED at position 3
10:50:07.287 Thread-122: finished writing 258017 bytes
10:50:07.287 Thread-122: playing media segment 222634599
10:50:07.483 Thread-122: finished writing 258100 bytes
10:50:09.570 Thread-122: adding media segment 222634600
10:50:09.570 Thread-122: playing media segment 222634600
10:50:10.893 Thread-122: finished writing 258157 bytes
10:50:16.608 Thread-122: adding media segment 222634601
10:50:16.608 Thread-122: playing media segment 222634601
10:50:16.927 Thread-122: finished writing 258043 bytes
10:50:23.654 Thread-122: adding media segment 222634602
10:50:23.654 Thread-122: playing media segment 222634602
10:50:23.934 Thread-122: finished writing 258177 bytes
10:50:28.911 Thread-122: adding media segment 222634603
10:50:28.911 Thread-122: playing media segment 222634603
10:50:29.222 Thread-122: finished writing 258193 bytes