Post Reply 
 
Thread Rating:
  • 0 Votes - 0 Average
  • 1
  • 2
  • 3
  • 4
  • 5
MinimStreamer on Raspberry Pi dropout
25-02-2015, 16:02
Post: #11
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 11:53)jack_c85 Wrote:  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: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

Thanks for this. It isn't the same for the following reasons:

1) There were only 5.9 seconds between starting to play segment 222634597 and the Sonos closing the connection. At this point, the Sonos should have still been playing segment 222634597.

2) There is no "finished writing nnnn bytes" message for segment 222634597 before the connection was closed. For previous segments, this happens about 0.2 seconds after the "playing" message. This short interval indicates thet the segment has been written to the Sonos buffer and not yet played by the Sonos. The lack of such a message for segment 222634597 suggests a possible communication problem between MinimStreamer and the Sonos or some other issue that has prevented the Sonos receiving the data for segment 222634597 .

I should be able to post the update with extra debug logging some time later today.
Find all posts by this user
Quote this message in a reply
25-02-2015, 16:07
Post: #12
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 16:02)simoncn Wrote:  
(25-02-2015 11:53)jack_c85 Wrote:  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: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

Thanks for this. It isn't the same for the following reasons:

1) There were only 5.9 seconds between starting to play segment 222634597 and the Sonos closing the connection. At this point, the Sonos should have still been playing segment 222634597.

2) There is no "finished writing nnnn bytes" message for segment 222634597 before the connection was closed. For previous segments, this happens about 0.2 seconds after the "playing" message. This short interval indicates thet the segment has been written to the Sonos buffer and not yet played by the Sonos. The lack of such a message for segment 222634597 suggests a possible communication problem between MinimStreamer and the Sonos or some other issue that has prevented the Sonos receiving the data for segment 222634597 .

I should be able to post the update with extra debug logging some time later today.

Interesting! Slightly frustrating too! I'll continue down the Pi route as this is what I ultimately want to use and will get further logs once the update is issued.
Find all posts by this user
Quote this message in a reply
25-02-2015, 18:39
Post: #13
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 16:07)jack_c85 Wrote:  Interesting! Slightly frustrating too! I'll continue down the Pi route as this is what I ultimately want to use and will get further logs once the update is issued.

MinimStreamer 0.5.4 is now available. It has some additional debug logging and it also has a new property stream.options.

Please run two tests with this new version:

1) Repeat what you have been doing to provoke a dropout, then post the debug log.

2) Set the stream.options property to delayHLS=10 to delay the HLS stream by 10 seconds and let me know whether this improves things.

Many thanks!
Find all posts by this user
Quote this message in a reply
25-02-2015, 20:28
Post: #14
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 18:39)simoncn Wrote:  
(25-02-2015 16:07)jack_c85 Wrote:  Interesting! Slightly frustrating too! I'll continue down the Pi route as this is what I ultimately want to use and will get further logs once the update is issued.

MinimStreamer 0.5.4 is now available. It has some additional debug logging and it also has a new property stream.options.

Please run two tests with this new version:

1) Repeat what you have been doing to provoke a dropout, then post the debug log.

2) Set the stream.options property to delayHLS=10 to delay the HLS stream by 10 seconds and let me know whether this improves things.

Many thanks!

Great, thanks Simon... will get this to you asap.
Find all posts by this user
Quote this message in a reply
25-02-2015, 20:52
Post: #15
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 20:28)jack_c85 Wrote:  
(25-02-2015 18:39)simoncn Wrote:  
(25-02-2015 16:07)jack_c85 Wrote:  Interesting! Slightly frustrating too! I'll continue down the Pi route as this is what I ultimately want to use and will get further logs once the update is issued.

MinimStreamer 0.5.4 is now available. It has some additional debug logging and it also has a new property stream.options.

Please run two tests with this new version:

1) Repeat what you have been doing to provoke a dropout, then post the debug log.

2) Set the stream.options property to delayHLS=10 to delay the HLS stream by 10 seconds and let me know whether this improves things.

Many thanks!

Great, thanks Simon... will get this to you asap.

Here's an instance of dropout before extending the stream delay to 10 seconds:

19:49:15.602 Thread-357: loading media playlist
19:49:15.688 Thread-357: adding media segment 222639654
19:49:15.703 Thread-357: playing media segment 222639654
19:49:16.306 Thread-357: finished writing 258098 bytes
19:49:16.319 Thread-357: sleeping for 2817 ms
19:49:19.138 Thread-357: loading media playlist
19:49:19.195 Thread-357: no new media segments available
19:49:19.209 Thread-357: sleeping for 1680 ms
19:49:20.890 Thread-357: loading media playlist
19:49:20.973 Thread-357: no new media segments available
19:49:20.979 Thread-357: sleeping for 1697 ms
19:49:22.686 Thread-357: loading media playlist
19:49:22.747 Thread-357: adding media segment 222639655
19:49:22.759 Thread-357: playing media segment 222639655
19:49:23.370 Thread-357: finished writing 258121 bytes
19:49:23.377 Thread-357: sleeping for 2817 ms
19:49:26.203 Thread-357: loading media playlist
19:49:26.299 Thread-357: no new media segments available
19:49:26.312 Thread-357: sleeping for 1649 ms
19:49:27.963 Thread-357: loading media playlist
19:49:28.021 Thread-357: no new media segments available
19:49:28.028 Thread-357: sleeping for 1689 ms
19:49:29.726 Thread-357: loading media playlist
19:49:29.771 Thread-357: no new media segments available
19:49:29.772 Thread-357: sleeping for 1706 ms
19:49:31.479 Thread-357: loading media playlist
19:49:31.563 Thread-357: adding media segment 222639656
19:49:31.578 Thread-357: playing media segment 222639656
19:49:32.158 Thread-357: finished writing 258052 bytes
19:49:32.167 Thread-357: sleeping for 2848 ms
19:49:35.023 Thread-357: loading media playlist
19:49:35.082 Thread-357: adding media segment 222639657
19:49:35.088 Thread-357: playing media segment 222639657
19:49:35.784 Thread-357: finished writing 258095 bytes
19:49:35.791 Thread-357: sleeping for 2733 ms
19:49:38.525 Thread-357: loading media playlist
19:49:47.341 Thread-355: HTTPConnection: end of input stream data
19:49:47.344 Thread-355: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@ccc8e3
19:49:47.349 Thread-355: Streamer: stopping chain org.jstreamer.core.ChainImpl@6ae59d
19:49:47.349 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:47.350 Thread-355: ChainImpl: removing target from org.jstreamer.core.TargetChain@1978bea
19:49:47.350 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@ad8b8f
19:49:47.351 Thread-355: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@ad8b8f
19:49:47.352 Thread-355: ChainSource: stopping reader thread
19:49:47.363 Thread-359: ChainSource: error reading input stream: org.jstreamer.OutputException: java.io.InterruptedIOException
19:49:47.363 Thread-359: Buffer: closing buffer: org.jstreamer.core.Buffer@1300d9a
19:49:47.364 Thread-355: ChainSource: stopping source
19:49:47.366 Thread-358: BufferReader: fillBuffer returned -1: buffer=org.jstreamer.core.Buffer@1300d9a
19:49:47.367 Thread-358: ChainTarget: end of data from input stream
19:49:47.368 Thread-358: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:47.369 Thread-358: BufferPoolReader: close
19:49:47.370 Thread-358: BufferReader: close: buffer=org.jstreamer.core.Buffer@157422
19:49:47.371 Thread-358: Buffer: removeReader: org.jstreamer.core.Buffer@157422
19:49:47.371 Thread-358: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@157422
19:49:47.372 Thread-358: BufferReader: close: buffer=org.jstreamer.core.Buffer@1300d9a
19:49:47.372 Thread-358: Buffer: removeReader: org.jstreamer.core.Buffer@1300d9a
19:49:47.373 Thread-358: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@1300d9a
19:49:53.579 Thread-357: loadMediaPlaylist openConnection: java.net.ConnectException: Connection refused
Error reading HLS stream: java.net.ConnectException: Connection refused
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:2​06)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:589)
at java.net.Socket.connect(Socket.java:538)
at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
at sun.net.www.http.HttpClient.openServer(HttpClient.java:432)
at sun.net.www.http.HttpClient.openServer(HttpClient.java:527)
at sun.net.www.http.HttpClient.<init>(HttpClient.java:211)
at sun.net.www.http.HttpClient.New(HttpClient.java:308)
at sun.net.www.http.HttpClient.New(HttpClient.java:326)
at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.j​ava:1167)
at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java​:1103)
at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:​997)
at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:931)
at org.jstreamer.lib.HTTPSource$ReaderThread.loadMediaPlaylist(HTTPSource.java:536)​
at org.jstreamer.lib.HTTPSource$ReaderThread.playStream(HTTPSource.java:677)
at org.jstreamer.lib.HTTPSource$ReaderThread.run(HTTPSource.java:483)
19:49:55.309 Thread-357: HTTPSource: closing piped output stream
19:49:55.315 Thread-355: HTTPSource: closing outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.203,port=80,localport=53276]
19:49:55.315 Thread-355: ChainSource: source stopped
19:49:55.316 Thread-355: TargetChain: stop
19:49:55.317 Thread-355: TargetChain: stopping subchain
19:49:55.317 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:55.319 Thread-355: TargetChain: subchain stopped
19:49:55.320 Thread-355: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@ad8b8f
19:49:55.320 Thread-355: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@6ae59d
19:49:55.321 Thread-355: ChainTarget: stop
19:49:55.321 Thread-355: ChainTarget: stopping target
19:49:55.322 Thread-355: HTTPRequestTarget: stop this=com.minimstreamer.HTTPRequestTarget@bfdba6 outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@b441cd
19:49:55.323 Thread-355: HTTPRequestTarget: closeSocket
19:49:55.324 Thread-355: HTTPRequestTarget: closing Socket[addr=/192.168.0.24,port=55178,localport=9790]
19:49:55.325 Thread-355: HTTPRequestTarget: notifyStopped com.minimstreamer.Streamer$NotifyStopped@13b8ab0
19:49:55.326 Thread-355: Streamer.NotifyStopped: run
19:49:55.326 Thread-354: Streamer: removing request chain for org.jminim.lib.HTTPConnection$Request@ccc8e3
19:49:55.327 Thread-354: Streamer: completed network request
19:49:55.328 Thread-354: HTTPConnection: completed request; socket=Socket[addr=/192.168.0.24,port=55178,localport=9790], keepAlive=true
19:49:55.329 Thread-354: HTTPConnection: writer thread waiting for request
19:49:55.329 Thread-355: ChainTarget: target stopped
19:49:55.330 Thread-355: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@6ae59d
19:49:55.331 Thread-355: HTTPService: removing connection org.jminim.lib.HTTPConnection@139708a
19:49:55.332 Thread-354: HTTPConnection: writer thread interrupted
19:49:57.775 Thread-339: HTTPService: accepted incoming connection
19:49:57.789 Thread-338: HTTPService: received request, Socket[addr=/192.168.0.24,port=55235,localport=9790]
19:49:57.791 Thread-338: HTTPService: adding connection org.jminim.lib.HTTPConnection@164ed3a
19:49:57.793 Thread-339: HTTPService: waiting for incoming connection
19:49:57.796 Thread-361: HTTPConnection: writer thread waiting for request
19:49:57.797 Thread-362: HTTPConnection: reading HTTP request
19:49:57.799 Thread-362: GET /minimstreamer/*/R3 HTTP/1.1
19:49:57.800 Thread-362: ACCEPT: */*, HOST: 192.168.0.3:9790, User-Agent: Nullsoft Winamp3 version 3.0 (compatible), Icy-MetaData: 1
19:49:57.801 Thread-361: HTTPConnection: writer thread processing request
19:49:57.802 Thread-361: Streamer: processing HTTP request
19:49:57.802 Thread-361: Streamer: releaseChains
19:49:57.802 Thread-361: Streamer: releasing chain: R3
19:49:57.803 Thread-361: Streamer: streamID is R3
19:49:57.804 Thread-361: Streamer: URL scheme is http
19:49:57.804 Thread-361: Streamer: request path is a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_three.m3u8
19:49:57.805 Thread-361: Streamer: transcodeType is
19:49:57.806 Thread-361: ChainImpl: addSource org.jstreamer.core.ChainSource@508e7
19:49:57.807 Thread-361: ChainSource: init
19:49:57.807 Thread-361: ChainImpl: getting property .inputBufferSize
19:49:57.808 Thread-362: HTTPConnection: reading HTTP request
19:49:57.808 Thread-361: ChainImpl: property .inputBufferSize has null value
19:49:57.809 Thread-361: ChainImpl: getting property .inputBuffers
19:49:57.810 Thread-361: ChainImpl: property .inputBuffers has null value
19:49:57.811 Thread-361: ChainSource: inputBufferSize=5000 inputBuffers=2
19:49:57.811 Thread-361: BufferPool: init
19:49:57.812 Thread-361: ChainSource: source created
19:49:57.813 Thread-361: ChainImpl: getting property scfilter.link
19:49:57.813 Thread-361: ChainImpl: property scfilter.link has literal value 'source'
19:49:57.814 Thread-361: ChainImpl: getting property scfilter.mode
19:49:57.814 Thread-361: ChainImpl: property scfilter.mode has literal value 'out'
19:49:57.815 Thread-361: ChainImpl: addFilter org.jstreamer.core.ChainSource@508e7
19:49:57.815 Thread-361: LinkBase: adding output filter org.jstreamer.lib.ShoutcastFilter@3a8eff
19:49:57.816 Thread-361: created new root chain org.jstreamer.core.ChainImpl@13802dc
19:49:57.817 Thread-361: ChainImpl: setting property .requestPath to 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_three.m3u8'
19:49:57.817 Thread-361: ChainImpl: setting property .requestMethod to 'GET'
19:49:57.818 Thread-361: ChainImpl: setting property .requestHeaders to 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
19:49:57.820 Thread-361: ChainImpl: addTarget org.jstreamer.core.ChainTarget@2512f5
19:49:57.820 Thread-361: ChainTarget: init
19:49:57.821 Thread-361: LinkBase: adding input filter com.minimstreamer.HTTPRequestTarget$TargetFilter@ae35b8
19:49:57.821 Thread-361: ChainTarget: target created
19:49:57.823 Thread-361: ChainImpl: getting property adfilter.link
19:49:57.823 Thread-361: ChainImpl: property adfilter.link has literal value 'request'
19:49:57.824 Thread-361: ChainImpl: getting property adfilter.mode
19:49:57.824 Thread-361: ChainImpl: property adfilter.mode has null value
19:49:57.839 Thread-361: ChainImpl: addFilter org.jstreamer.core.ChainTarget@2512f5
19:49:57.841 Thread-361: LinkBase: adding input filter org.jstreamer.lib.FrameFilter@117fd93
19:49:57.842 Thread-361: ChainImpl: setting property .timeout to '2000'
19:49:57.843 Thread-361: ChainImpl: setting property object .@timeoutAction to com.minimstreamer.Streamer$TimeoutAction@f844b4
19:49:57.844 Thread-361: ChainImpl: setting property object .@notifyStopped to com.minimstreamer.Streamer$NotifyStopped@1aabfa6
19:49:57.844 Thread-361: ChainImpl: setting property object .@httpRequest to org.jminim.lib.HTTPConnection$Request@1592625
19:49:57.845 Thread-361: ChainImpl: setting property object .@http to org.jminim.lib.HTTPContext@1dd8253
19:49:57.845 Thread-361: ChainImpl: setting property .transcodeType to ''
19:49:57.846 Thread-361: ChainImpl: setting property object .@streamer to com.minimstreamer.Streamer@1ac631b
19:49:57.846 Thread-361: ChainImpl: setting property object .@parentChain to org.jstreamer.core.ChainImpl@13802dc
19:49:57.847 Thread-361: Streamer: adding request chain for org.jminim.lib.HTTPConnection$Request@1592625: org.jstreamer.core.ChainImpl@84586b
19:49:57.848 Thread-361: ChainImpl: addTargetChain org.jstreamer.core.TargetChain@1986725
19:49:57.853 Thread-361: TargetChain: init
19:49:57.853 Thread-361: BufferPoolReader: new
19:49:57.854 Thread-361: Buffer: createReader: org.jstreamer.core.Buffer@1ed48c6
19:49:57.854 Thread-361: BufferReader: initial readSequence=1
19:49:57.855 Thread-361: Buffer: createReader: org.jstreamer.core.Buffer@1d49352
19:49:57.855 Thread-361: BufferReader: initial readSequence=1
19:49:57.856 Thread-361: ChainImpl: start org.jstreamer.core.ChainImpl@13802dc
19:49:57.857 Thread-361: ChainImpl: startLinks org.jstreamer.core.ChainImpl@13802dc
19:49:57.857 Thread-361: ChainImpl: starting chain org.jstreamer.core.ChainImpl@13802dc
19:49:57.858 Thread-361: TargetChain: start
19:49:57.859 Thread-361: TargetChain: starting subchain links
19:49:57.859 Thread-361: ChainImpl: startLinks org.jstreamer.core.ChainImpl@84586b
19:49:57.860 Thread-361: ChainImpl: starting chain org.jstreamer.core.ChainImpl@84586b
19:49:57.860 Thread-361: ChainTarget: start
19:49:57.861 Thread-361: ChainImpl: property obj request.@notifyStopped is reference to .@notifyStopped
19:49:57.861 Thread-361: ChainImpl: property object request.@notifyStopped has value com.minimstreamer.Streamer$NotifyStopped@1aabfa6
19:49:57.862 Thread-361: ChainImpl: property obj request.@httpRequest is reference to .@httpRequest
19:49:57.862 Thread-361: ChainImpl: property object request.@httpRequest has value org.jminim.lib.HTTPConnection$Request@1592625
19:49:57.863 Thread-361: ChainImpl: property obj request.@http is reference to .@http
19:49:57.864 Thread-361: ChainImpl: property object request.@http has value org.jminim.lib.HTTPContext@1dd8253
19:49:57.864 Thread-361: ChainImpl: property obj request.@timeoutAction is reference to .@timeoutAction
19:49:57.865 Thread-361: ChainImpl: property object request.@timeoutAction has value com.minimstreamer.Streamer$TimeoutAction@f844b4
19:49:57.865 Thread-361: ChainImpl: getting property request.timeout
19:49:57.866 Thread-361: ChainImpl: property request.timeout has initial value '$.timeout'
19:49:57.866 Thread-361: ChainImpl: property .timeout has literal value '2000'
19:49:57.867 Thread-361: ChainImpl: substitution property .timeout has value '2000'
19:49:57.867 Thread-361: ChainImpl: property request.timeout has final value '2000'
19:49:57.868 Thread-361: HTTPRequestTarget: timeout is 2000
19:49:57.869 Thread-361: HTTPRequestTarget: initRequest socket=Socket[addr=/192.168.0.24,port=55235,localport=9790] this=com.minimstreamer.HTTPRequestTarget@597b29 outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@1910441
19:49:57.870 Thread-361: ChainTarget: target started
19:49:57.871 Thread-361: ChainImpl: started chain org.jstreamer.core.ChainImpl@84586b
19:49:57.872 Thread-361: TargetChain: subchain links started
19:49:57.872 Thread-361: ChainSource: start
19:49:57.873 Thread-361: ChainImpl: getting property source.resource
19:49:57.874 Thread-361: ChainImpl: property source.resource has initial value '$.requestPath'
19:49:57.874 Thread-361: ChainImpl: property .requestPath has literal value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_three.m3u8'
19:49:57.875 Thread-361: ChainImpl: substitution property .requestPath has value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_three.m3u8'
19:49:57.875 Thread-361: ChainImpl: property source.resource has final value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_three.m3u8'
19:49:57.876 Thread-361: ChainImpl: getting property source.requestMethod
19:49:57.876 Thread-361: ChainImpl: property source.requestMethod has initial value '$.requestMethod'
19:49:57.877 Thread-361: ChainImpl: property .requestMethod has literal value 'GET'
19:49:57.889 Thread-361: ChainImpl: substitution property .requestMethod has value 'GET'
19:49:57.890 Thread-361: ChainImpl: property source.requestMethod has final value 'GET'
19:49:57.890 Thread-361: ChainImpl: getting property source.requestHeaders
19:49:57.891 Thread-361: ChainImpl: property source.requestHeaders has initial value '$.requestHeaders'
19:49:57.891 Thread-361: ChainImpl: property .requestHeaders has literal value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
19:49:57.892 Thread-361: ChainImpl: substitution property .requestHeaders has value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
19:49:57.892 Thread-361: ChainImpl: property source.requestHeaders has final value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
19:49:57.893 Thread-361: ChainImpl: getting property source.delayHLS
19:49:57.893 Thread-361: ChainImpl: property source.delayHLS has initial value '$.delayHLS'
19:49:57.894 Thread-361: ChainImpl: property .delayHLS has null value
19:49:57.894 Thread-361: ChainImpl: substitution property .delayHLS has value ''
19:49:57.895 Thread-361: ChainImpl: property source.delayHLS has final value ''
19:49:57.938 Thread-361: HTTPSource: created outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.192,port=80,localport=50765]
19:49:57.941 Thread-361: HTTPSource: sending HTTP request:
GET /media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_three.m3u8 HTTP/1.1
Host: a.files.bbci.co.uk
ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1


19:49:57.953 Thread-361: HTTPSource: stream response status HTTP/1.1 200 OK
19:49:57.954 Thread-361: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
19:49:57.964 Thread-361: x-amz-id-2: IVT9HCVwGPDICVBvNMqdOctmJu3+EDRn4hCSbYk3IOE2blce/rNbe1MjB/i2ZhdwRRdAo2JFTk0=
x-amz-request-id: ED8BF91E31097D24
Last-Modified: Wed, 25 Feb 2015 11:59:01 GMT
ETag: "b96d2d1264d8a911ed8ff2e147880bfa"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 240
Server: AmazonS3
Cache-Control: max-age=109
Expires: Wed, 25 Feb 2015 19:51:46 GMT
Date: Wed, 25 Feb 2015 19:49:57 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: *

19:49:57.965 Thread-361: ChainImpl: setting property source.responseHeaders to 'x-amz-id-2: IVT9HCVwGPDICVBvNMqdOctmJu3+EDRn4hCSbYk3IOE2blce/rNbe1MjB/i2ZhdwRRdAo2JFTk0=
x-amz-request-id: ED8BF91E31097D24
Last-Modified: Wed, 25 Feb 2015 11:59:01 GMT
ETag: "b96d2d1264d8a911ed8ff2e147880bfa"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 240
Server: AmazonS3
Cache-Control: max-age=109
Expires: Wed, 25 Feb 2015 19:51:46 GMT
Date: Wed, 25 Feb 2015 19:49:57 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: *
'
19:49:57.966 Thread-361: HTTPSource: content type is 'application/x-mpegurl'
19:49:57.966 Thread-361: HTTPSource: reading playlist from URL http://a.files.bbci.co.uk/media/live/man...three.m3u8
19:49:57.967 Thread-361: HTTPSource: using HLS
19:49:57.968 Thread-361: HTTPSource: found valid stream URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
19:49:57.969 Thread-361: HTTPSource: reading HLS media playlist from URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
19:49:57.970 Thread-361: ChainImpl: setting property source.responseHeaders to ''
19:49:57.970 Thread-361: loading media playlist
19:49:58.097 Thread-361: adding media segment 222639656
19:49:58.101 Thread-361: adding media segment 222639657
19:49:58.110 Thread-361: adding media segment 222639658
19:49:58.110 Thread-361: adding media segment 222639659
19:49:58.111 Thread-361: adding media segment 222639660
19:49:58.116 Thread-364: starting to play HLS stream
19:49:58.117 Thread-364: initial delay is 2 media segments
19:49:58.117 Thread-364: skipping media segment 222639656
19:49:58.118 Thread-364: skipping media segment 222639657
19:49:58.119 Thread-364: skipping media segment 222639658
19:49:58.119 Thread-364: playing media segment 222639659
19:49:58.268 Thread-364: media segment content type is video/mp2t
19:49:58.283 Thread-361: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
19:49:58.283 Thread-361: ChainImpl: setting property source.contentType to 'audio/aac'
19:49:58.284 Thread-361: ChainImpl: setting property source.contentFormat to 'aac'
19:49:58.284 Thread-361: ChainImpl: setting property source.responseMessage to ''
19:49:58.289 Thread-361: ChainImpl: setting property source.sourcePath to '/pool_7/live/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d320000.m3u8'
19:49:58.292 Thread-361: ChainSource: source started
19:49:58.293 Thread-361: ChainImpl: started chain org.jstreamer.core.ChainImpl@13802dc
19:49:58.294 Thread-361: ChainImpl: runLinks org.jstreamer.core.ChainImpl@13802dc
19:49:58.294 Thread-361: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@13802dc
19:49:58.295 Thread-361: TargetChain: run
19:49:58.296 Thread-361: TargetChain: running subchain links
19:49:58.297 Thread-361: ChainImpl: runLinks org.jstreamer.core.ChainImpl@84586b
19:49:58.297 Thread-361: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@84586b
19:49:58.313 Thread-361: ChainTarget: run
19:49:58.314 Thread-361: ChainImpl: getting property request.transcodeType
19:49:58.315 Thread-361: ChainImpl: property request.transcodeType has initial value '$.transcodeType'
19:49:58.315 Thread-361: ChainImpl: property .transcodeType has literal value ''
19:49:58.316 Thread-361: ChainImpl: substitution property .transcodeType has value ''
19:49:58.316 Thread-361: ChainImpl: property request.transcodeType has final value ''
19:49:58.317 Thread-361: ChainImpl: getting property request.transcodeLimit
19:49:58.317 Thread-361: ChainImpl: property request.transcodeLimit has null value
19:49:58.318 Thread-361: ChainImpl: getting property request.contentType
19:49:58.339 Thread-361: ChainImpl: property request.contentType has initial value '$/source.contentType'
19:49:58.340 Thread-361: ChainImpl: property source.contentType has literal value 'audio/aac'
19:49:58.341 Thread-361: ChainImpl: substitution property /source.contentType has value 'audio/aac'
19:49:58.342 Thread-361: ChainImpl: property request.contentType has final value 'audio/aac'
19:49:58.343 Thread-361: ChainImpl: property obj request.@streamer is reference to .@streamer
19:49:58.343 Thread-361: ChainImpl: property object request.@streamer has value com.minimstreamer.Streamer@1ac631b
19:49:58.344 Thread-361: ChainTarget: target running
19:49:58.345 Thread-361: ChainTarget: starting writer thread
19:49:58.359 Thread-361: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@84586b
19:49:58.360 Thread-361: TargetChain: subchain links running
19:49:58.360 Thread-361: ChainSource: run
19:49:58.361 Thread-361: ChainSource: source running
19:49:58.362 Thread-361: ChainSource: starting reader thread
19:49:58.369 Thread-361: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@13802dc
19:49:58.441 Thread-361: Streamer: waiting for completion of network request
19:49:58.448 Thread-361: Streamer.NotifyStopped: waitFor
19:49:58.466 Thread-361: Streamer.NotifyStopped: waiting
19:49:59.287 Thread-366: ChainImpl: getting property scfilter.responseHeaders
19:49:59.290 Thread-366: ChainImpl: property scfilter.responseHeaders has initial value '$source.responseHeaders'
19:49:59.299 Thread-366: ChainImpl: property source.responseHeaders has literal value ''
19:49:59.299 Thread-366: ChainImpl: substitution property source.responseHeaders has value ''
19:49:59.300 Thread-366: ChainImpl: property scfilter.responseHeaders has final value ''
19:49:59.301 Thread-366: ShoutcastFilter: response headers=
19:49:59.302 Thread-366: ShoutcastFilter: icyMetaint=0
19:49:59.312 Thread-365: ChainImpl: getting property request.delay
19:49:59.313 Thread-365: ChainImpl: property request.delay has null value
19:49:59.314 Thread-365: ChainImpl: getting property request.responseHeaders
19:49:59.314 Thread-365: ChainImpl: property request.responseHeaders has null value
19:49:59.315 Thread-365: ChainImpl: getting property request.status
19:49:59.315 Thread-365: ChainImpl: property request.status has initial value '$/source.status'
19:49:59.316 Thread-365: ChainImpl: property source.status has literal value 'HTTP/1.1 200 OK
'
19:49:59.316 Thread-365: ChainImpl: substitution property /source.status has value 'HTTP/1.1 200 OK
'
19:49:59.317 Thread-365: ChainImpl: property request.status has final value 'HTTP/1.1 200 OK
'
19:49:59.317 Thread-365: ChainImpl: getting property request.sourceResponseHeaders
19:49:59.318 Thread-365: ChainImpl: property request.sourceResponseHeaders has initial value '$/source.responseHeaders'
19:49:59.319 Thread-365: ChainImpl: property source.responseHeaders has literal value ''
19:49:59.319 Thread-365: ChainImpl: substitution property /source.responseHeaders has value ''
19:49:59.320 Thread-365: ChainImpl: property request.sourceResponseHeaders has final value ''
19:49:59.322 Thread-365: ChainImpl: getting property request.sourcePath
19:49:59.323 Thread-365: ChainImpl: property request.sourcePath has initial value '$/source.sourcePath'
19:49:59.323 Thread-365: ChainImpl: property source.sourcePath has literal value '/pool_7/live/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d320000.m3u8'
19:49:59.324 Thread-365: ChainImpl: substitution property /source.sourcePath has value '/pool_7/live/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d320000.m3u8'
19:49:59.324 Thread-365: ChainImpl: property request.sourcePath has final value '/pool_7/live/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d320000.m3u8'
19:49:59.325 Thread-365: HTTP/1.1 200 OK, Date: Wed, 25 Feb 2015 19:49:59 GMT, Connection: close, Server: MinimStreamer, Content-Type: audio/aac
19:49:59.327 Thread-365: ChainImpl: getting property adfilter.contentType
19:49:59.328 Thread-365: ChainImpl: property adfilter.contentType has initial value '$/source.contentType'
19:49:59.329 Thread-365: ChainImpl: property source.contentType has literal value 'audio/aac'
19:49:59.329 Thread-365: ChainImpl: substitution property /source.contentType has value 'audio/aac'
19:49:59.330 Thread-365: ChainImpl: property adfilter.contentType has final value 'audio/aac'
19:49:59.331 Thread-365: FrameFilter: contentType is 'audio/aac'
19:49:59.333 Thread-365: ADTSFilter: state SYNC1 at position 0
19:49:59.334 Thread-365: ADTSFilter: state SYNC2 at position 1
19:49:59.335 Thread-365: ADTSFilter: state SYNC3 at position 2
19:49:59.336 Thread-365: ADTSFilter: state SYNCED at position 3
19:49:59.809 Thread-364: finished writing 258138 bytes
19:49:59.819 Thread-364: playing media segment 222639660
19:50:01.168 Thread-364: finished writing 258117 bytes
19:50:01.178 Thread-364: sleeping for 301 ms
19:50:01.481 Thread-364: loading media playlist
19:50:01.524 Thread-364: no new media segments available
19:50:01.525 Thread-364: sleeping for 1707 ms
19:50:03.232 Thread-364: loading media playlist
19:50:03.288 Thread-364: adding media segment 222639661
19:50:03.299 Thread-364: playing media segment 222639661
19:50:05.214 Thread-364: finished writing 258235 bytes
19:50:05.227 Thread-364: sleeping for 1509 ms
19:50:06.737 Thread-364: loading media playlist
19:50:06.779 Thread-364: no new media segments available
19:50:06.780 Thread-364: sleeping for 1711 ms
19:50:08.491 Thread-364: loading media playlist
19:50:08.551 Thread-364: adding media segment 222639662
19:50:08.557 Thread-364: playing media segment 222639662
19:50:09.309 Thread-364: finished writing 257948 bytes
19:50:09.315 Thread-364: sleeping for 2677 ms
19:50:12.000 Thread-364: loading media playlist
19:50:12.061 Thread-364: no new media segments available
19:50:12.074 Thread-364: sleeping for 1677 ms
19:50:13.752 Thread-364: loading media playlist
19:50:13.804 Thread-364: no new media segments available
19:50:13.818 Thread-364: sleeping for 1699 ms
19:50:15.518 Thread-364: loading media playlist
19:50:15.575 Thread-364: adding media segment 222639663
19:50:15.598 Thread-364: playing media segment 222639663
Find all posts by this user
Quote this message in a reply
25-02-2015, 21:08
Post: #16
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 20:52)jack_c85 Wrote:  Here's an instance of dropout before extending the stream delay to 10 seconds:

19:49:15.602 Thread-357: loading media playlist
19:49:15.688 Thread-357: adding media segment 222639654
19:49:15.703 Thread-357: playing media segment 222639654
19:49:16.306 Thread-357: finished writing 258098 bytes
19:49:16.319 Thread-357: sleeping for 2817 ms
19:49:19.138 Thread-357: loading media playlist
19:49:19.195 Thread-357: no new media segments available
19:49:19.209 Thread-357: sleeping for 1680 ms
19:49:20.890 Thread-357: loading media playlist
19:49:20.973 Thread-357: no new media segments available
19:49:20.979 Thread-357: sleeping for 1697 ms
19:49:22.686 Thread-357: loading media playlist
19:49:22.747 Thread-357: adding media segment 222639655
19:49:22.759 Thread-357: playing media segment 222639655
19:49:23.370 Thread-357: finished writing 258121 bytes
19:49:23.377 Thread-357: sleeping for 2817 ms
19:49:26.203 Thread-357: loading media playlist
19:49:26.299 Thread-357: no new media segments available
19:49:26.312 Thread-357: sleeping for 1649 ms
19:49:27.963 Thread-357: loading media playlist
19:49:28.021 Thread-357: no new media segments available
19:49:28.028 Thread-357: sleeping for 1689 ms
19:49:29.726 Thread-357: loading media playlist
19:49:29.771 Thread-357: no new media segments available
19:49:29.772 Thread-357: sleeping for 1706 ms
19:49:31.479 Thread-357: loading media playlist
19:49:31.563 Thread-357: adding media segment 222639656
19:49:31.578 Thread-357: playing media segment 222639656
19:49:32.158 Thread-357: finished writing 258052 bytes
19:49:32.167 Thread-357: sleeping for 2848 ms
19:49:35.023 Thread-357: loading media playlist
19:49:35.082 Thread-357: adding media segment 222639657
19:49:35.088 Thread-357: playing media segment 222639657
19:49:35.784 Thread-357: finished writing 258095 bytes
19:49:35.791 Thread-357: sleeping for 2733 ms
19:49:38.525 Thread-357: loading media playlist
19:49:47.341 Thread-355: HTTPConnection: end of input stream data
19:49:47.344 Thread-355: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@ccc8e3
19:49:47.349 Thread-355: Streamer: stopping chain org.jstreamer.core.ChainImpl@6ae59d
19:49:47.349 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:47.350 Thread-355: ChainImpl: removing target from org.jstreamer.core.TargetChain@1978bea
19:49:47.350 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@ad8b8f
19:49:47.351 Thread-355: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@ad8b8f
19:49:47.352 Thread-355: ChainSource: stopping reader thread
19:49:47.363 Thread-359: ChainSource: error reading input stream: org.jstreamer.OutputException: java.io.InterruptedIOException
19:49:47.363 Thread-359: Buffer: closing buffer: org.jstreamer.core.Buffer@1300d9a
19:49:47.364 Thread-355: ChainSource: stopping source
19:49:47.366 Thread-358: BufferReader: fillBuffer returned -1: buffer=org.jstreamer.core.Buffer@1300d9a
19:49:47.367 Thread-358: ChainTarget: end of data from input stream
19:49:47.368 Thread-358: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:47.369 Thread-358: BufferPoolReader: close
19:49:47.370 Thread-358: BufferReader: close: buffer=org.jstreamer.core.Buffer@157422
19:49:47.371 Thread-358: Buffer: removeReader: org.jstreamer.core.Buffer@157422
19:49:47.371 Thread-358: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@157422
19:49:47.372 Thread-358: BufferReader: close: buffer=org.jstreamer.core.Buffer@1300d9a
19:49:47.372 Thread-358: Buffer: removeReader: org.jstreamer.core.Buffer@1300d9a
19:49:47.373 Thread-358: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@1300d9a
19:49:53.579 Thread-357: loadMediaPlaylist openConnection: java.net.ConnectException: Connection refused
Error reading HLS stream: java.net.ConnectException: Connection refused
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:2​06)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:589)
at java.net.Socket.connect(Socket.java:538)
at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
at sun.net.www.http.HttpClient.openServer(HttpClient.java:432)
at sun.net.www.http.HttpClient.openServer(HttpClient.java:527)
at sun.net.www.http.HttpClient.<init>(HttpClient.java:211)
at sun.net.www.http.HttpClient.New(HttpClient.java:308)
at sun.net.www.http.HttpClient.New(HttpClient.java:326)
at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.j​ava:1167)
at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java​:1103)
at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:​997)
at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:931)
at org.jstreamer.lib.HTTPSource$ReaderThread.loadMediaPlaylist(HTTPSource.java:536)​
at org.jstreamer.lib.HTTPSource$ReaderThread.playStream(HTTPSource.java:677)
at org.jstreamer.lib.HTTPSource$ReaderThread.run(HTTPSource.java:483)
19:49:55.309 Thread-357: HTTPSource: closing piped output stream
19:49:55.315 Thread-355: HTTPSource: closing outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.203,port=80,localport=53276]
19:49:55.315 Thread-355: ChainSource: source stopped

This log is very interesting. It shows that the BBC server didn't respond to the "loading media playlist" request sent at 19:49:38.525 and this eventually caused the Sonos to run out of audio data to play.

It might be that MinimStreamer is sending requests too frequently and the BBC server is detecting this. If so, it's strange that I haven't seen this myself. How long were you playing the stream before the dropout happened?
Find all posts by this user
Quote this message in a reply
25-02-2015, 21:40
Post: #17
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 21:08)simoncn Wrote:  
(25-02-2015 20:52)jack_c85 Wrote:  Here's an instance of dropout before extending the stream delay to 10 seconds:

19:49:15.602 Thread-357: loading media playlist
19:49:15.688 Thread-357: adding media segment 222639654
19:49:15.703 Thread-357: playing media segment 222639654
19:49:16.306 Thread-357: finished writing 258098 bytes
19:49:16.319 Thread-357: sleeping for 2817 ms
19:49:19.138 Thread-357: loading media playlist
19:49:19.195 Thread-357: no new media segments available
19:49:19.209 Thread-357: sleeping for 1680 ms
19:49:20.890 Thread-357: loading media playlist
19:49:20.973 Thread-357: no new media segments available
19:49:20.979 Thread-357: sleeping for 1697 ms
19:49:22.686 Thread-357: loading media playlist
19:49:22.747 Thread-357: adding media segment 222639655
19:49:22.759 Thread-357: playing media segment 222639655
19:49:23.370 Thread-357: finished writing 258121 bytes
19:49:23.377 Thread-357: sleeping for 2817 ms
19:49:26.203 Thread-357: loading media playlist
19:49:26.299 Thread-357: no new media segments available
19:49:26.312 Thread-357: sleeping for 1649 ms
19:49:27.963 Thread-357: loading media playlist
19:49:28.021 Thread-357: no new media segments available
19:49:28.028 Thread-357: sleeping for 1689 ms
19:49:29.726 Thread-357: loading media playlist
19:49:29.771 Thread-357: no new media segments available
19:49:29.772 Thread-357: sleeping for 1706 ms
19:49:31.479 Thread-357: loading media playlist
19:49:31.563 Thread-357: adding media segment 222639656
19:49:31.578 Thread-357: playing media segment 222639656
19:49:32.158 Thread-357: finished writing 258052 bytes
19:49:32.167 Thread-357: sleeping for 2848 ms
19:49:35.023 Thread-357: loading media playlist
19:49:35.082 Thread-357: adding media segment 222639657
19:49:35.088 Thread-357: playing media segment 222639657
19:49:35.784 Thread-357: finished writing 258095 bytes
19:49:35.791 Thread-357: sleeping for 2733 ms
19:49:38.525 Thread-357: loading media playlist
19:49:47.341 Thread-355: HTTPConnection: end of input stream data
19:49:47.344 Thread-355: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@ccc8e3
19:49:47.349 Thread-355: Streamer: stopping chain org.jstreamer.core.ChainImpl@6ae59d
19:49:47.349 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:47.350 Thread-355: ChainImpl: removing target from org.jstreamer.core.TargetChain@1978bea
19:49:47.350 Thread-355: ChainImpl: stop org.jstreamer.core.ChainImpl@ad8b8f
19:49:47.351 Thread-355: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@ad8b8f
19:49:47.352 Thread-355: ChainSource: stopping reader thread
19:49:47.363 Thread-359: ChainSource: error reading input stream: org.jstreamer.OutputException: java.io.InterruptedIOException
19:49:47.363 Thread-359: Buffer: closing buffer: org.jstreamer.core.Buffer@1300d9a
19:49:47.364 Thread-355: ChainSource: stopping source
19:49:47.366 Thread-358: BufferReader: fillBuffer returned -1: buffer=org.jstreamer.core.Buffer@1300d9a
19:49:47.367 Thread-358: ChainTarget: end of data from input stream
19:49:47.368 Thread-358: ChainImpl: stop org.jstreamer.core.ChainImpl@6ae59d
19:49:47.369 Thread-358: BufferPoolReader: close
19:49:47.370 Thread-358: BufferReader: close: buffer=org.jstreamer.core.Buffer@157422
19:49:47.371 Thread-358: Buffer: removeReader: org.jstreamer.core.Buffer@157422
19:49:47.371 Thread-358: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@157422
19:49:47.372 Thread-358: BufferReader: close: buffer=org.jstreamer.core.Buffer@1300d9a
19:49:47.372 Thread-358: Buffer: removeReader: org.jstreamer.core.Buffer@1300d9a
19:49:47.373 Thread-358: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@1300d9a
19:49:53.579 Thread-357: loadMediaPlaylist openConnection: java.net.ConnectException: Connection refused
Error reading HLS stream: java.net.ConnectException: Connection refused
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:2​06)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:589)
at java.net.Socket.connect(Socket.java:538)
at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
at sun.net.www.http.HttpClient.openServer(HttpClient.java:432)
at sun.net.www.http.HttpClient.openServer(HttpClient.java:527)
at sun.net.www.http.HttpClient.<init>(HttpClient.java:211)
at sun.net.www.http.HttpClient.New(HttpClient.java:308)
at sun.net.www.http.HttpClient.New(HttpClient.java:326)
at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.j​ava:1167)
at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java​:1103)
at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:​997)
at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:931)
at org.jstreamer.lib.HTTPSource$ReaderThread.loadMediaPlaylist(HTTPSource.java:536)​
at org.jstreamer.lib.HTTPSource$ReaderThread.playStream(HTTPSource.java:677)
at org.jstreamer.lib.HTTPSource$ReaderThread.run(HTTPSource.java:483)
19:49:55.309 Thread-357: HTTPSource: closing piped output stream
19:49:55.315 Thread-355: HTTPSource: closing outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.203,port=80,localport=53276]
19:49:55.315 Thread-355: ChainSource: source stopped

This log is very interesting. It shows that the BBC server didn't respond to the "loading media playlist" request sent at 19:49:38.525 and this eventually caused the Sonos to run out of audio data to play.

It might be that MinimStreamer is sending requests too frequently and the BBC server is detecting this. If so, it's strange that I haven't seen this myself. How long were you playing the stream before the dropout happened?

Oh ok... interesting. I wasn't playing it long, probably under 10 minutes.

This morning however it was fine for around 50 minutes, it completely varies.
Find all posts by this user
Quote this message in a reply
25-02-2015, 23:11
Post: #18
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 21:40)jack_c85 Wrote:  Oh ok... interesting. I wasn't playing it long, probably under 10 minutes.

This morning however it was fine for around 50 minutes, it completely varies.

I have tried to reproduce this problem without success. I am wondering if it might be related to playing the stream on the Sonos. Do you have any results from using the delayHLS=10 setting?
Find all posts by this user
Quote this message in a reply
25-02-2015, 23:13
Post: #19
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 23:11)simoncn Wrote:  
(25-02-2015 21:40)jack_c85 Wrote:  Oh ok... interesting. I wasn't playing it long, probably under 10 minutes.

This morning however it was fine for around 50 minutes, it completely varies.

I have tried to reproduce this problem without success. I am wondering if it might be related to playing the stream on the Sonos. Do you have any results from using the delayHLS=10 setting?

That's what I'm thinking... perhaps your streamer adds enough buffer to deal with this. I think I just experienced dropout but I was in the other room without debugging on... will put it on and continue listening. If I experiemce anything I'll send the logs straight over.
Find all posts by this user
Quote this message in a reply
25-02-2015, 23:21
Post: #20
RE: MinimStreamer on Raspberry Pi dropout
(25-02-2015 23:13)jack_c85 Wrote:  
(25-02-2015 23:11)simoncn Wrote:  
(25-02-2015 21:40)jack_c85 Wrote:  Oh ok... interesting. I wasn't playing it long, probably under 10 minutes.

This morning however it was fine for around 50 minutes, it completely varies.

I have tried to reproduce this problem without success. I am wondering if it might be related to playing the stream on the Sonos. Do you have any results from using the delayHLS=10 setting?

That's what I'm thinking... perhaps your streamer adds enough buffer to deal with this. I think I just experienced dropout but I was in the other room without debugging on... will put it on and continue listening. If I experiemce anything I'll send the logs straight over.

Just dropped out again... this is with the delayHLS=10 setting. Shall I increase this?

22:17:01.549 Thread-56: loading media playlist
22:17:01.590 Thread-56: no new media segments available
22:17:01.591 Thread-56: sleeping for 1710 ms
22:17:03.302 Thread-56: loading media playlist
22:17:03.362 Thread-56: no new media segments available
22:17:03.373 Thread-56: sleeping for 1686 ms
22:17:05.062 Thread-56: loading media playlist
22:17:05.192 Thread-56: no new media segments available
22:17:05.204 Thread-56: sleeping for 1611 ms
22:17:06.819 Thread-56: loading media playlist
22:17:06.873 Thread-56: adding media segment 222641040
22:17:06.883 Thread-56: playing media segment 222641040
22:17:07.516 Thread-56: finished writing 258100 bytes
22:17:07.530 Thread-56: sleeping for 2801 ms
22:17:10.333 Thread-56: loading media playlist
22:17:10.398 Thread-56: no new media segments available
22:17:10.412 Thread-56: sleeping for 1675 ms
22:17:12.089 Thread-56: loading media playlist
22:17:12.156 Thread-56: adding media segment 222641041
22:17:12.170 Thread-56: playing media segment 222641041
22:17:12.799 Thread-56: finished writing 258100 bytes
22:17:12.813 Thread-56: sleeping for 2790 ms
22:17:15.605 Thread-56: loading media playlist
22:17:15.669 Thread-56: no new media segments available
22:17:15.670 Thread-56: sleeping for 1706 ms
22:17:17.376 Thread-56: loading media playlist
22:17:17.433 Thread-56: no new media segments available
22:17:17.444 Thread-56: sleeping for 1684 ms
22:17:19.133 Thread-56: loading media playlist
22:17:19.255 Thread-56: adding media segment 222641042
22:17:19.268 Thread-56: playing media segment 222641042
22:17:19.900 Thread-56: finished writing 258100 bytes
22:17:19.907 Thread-56: sleeping for 2738 ms
22:17:22.652 Thread-56: loading media playlist
22:17:22.708 Thread-56: no new media segments available
22:17:22.720 Thread-56: sleeping for 1686 ms
22:17:24.408 Thread-56: loading media playlist
22:17:24.460 Thread-56: adding media segment 222641043
22:17:24.473 Thread-56: playing media segment 222641043
22:17:25.186 Thread-56: finished writing 258100 bytes
22:17:25.199 Thread-56: sleeping for 2710 ms
22:17:27.912 Thread-56: loading media playlist
22:17:27.958 Thread-56: no new media segments available
22:17:27.959 Thread-56: sleeping for 1709 ms
22:17:29.669 Thread-56: loading media playlist
22:17:29.746 Thread-56: adding media segment 222641044
22:17:29.753 Thread-56: playing media segment 222641044
22:17:30.388 Thread-56: finished writing 258100 bytes
22:17:30.395 Thread-56: sleeping for 2775 ms
22:17:33.179 Thread-56: loading media playlist
22:17:33.243 Thread-56: no new media segments available
22:17:33.257 Thread-56: sleeping for 1687 ms
22:17:34.946 Thread-56: loading media playlist
22:17:34.989 Thread-56: no new media segments available
22:17:34.990 Thread-56: sleeping for 1707 ms
22:17:36.698 Thread-56: loading media playlist
22:17:36.750 Thread-56: no new media segments available
22:17:36.764 Thread-56: sleeping for 1685 ms
22:17:38.450 Thread-56: loading media playlist
22:17:38.511 Thread-56: adding media segment 222641045
22:17:38.523 Thread-56: playing media segment 222641045
22:17:39.170 Thread-56: finished writing 258100 bytes
22:17:39.176 Thread-56: sleeping for 2781 ms
22:17:41.965 Thread-56: loading media playlist
22:17:42.042 Thread-56: no new media segments available
22:17:42.053 Thread-56: sleeping for 1669 ms
22:17:43.725 Thread-56: loading media playlist
22:17:43.783 Thread-56: no new media segments available
22:17:43.793 Thread-56: sleeping for 1688 ms
22:17:45.484 Thread-56: loading media playlist
22:17:45.541 Thread-56: adding media segment 222641046
22:17:45.548 Thread-56: playing media segment 222641046
22:17:46.168 Thread-56: finished writing 258100 bytes
22:17:46.175 Thread-56: sleeping for 2814 ms
22:17:48.998 Thread-56: loading media playlist
22:17:49.140 Thread-56: no new media segments available
22:17:49.153 Thread-56: sleeping for 1602 ms
22:17:50.757 Thread-56: loading media playlist
22:17:50.817 Thread-56: adding media segment 222641047
22:17:50.831 Thread-56: playing media segment 222641047
22:17:51.394 Thread-56: finished writing 258202 bytes
22:17:51.407 Thread-56: sleeping for 2852 ms
22:17:54.262 Thread-56: loading media playlist
22:17:54.318 Thread-56: no new media segments available
22:17:54.331 Thread-56: sleeping for 1685 ms
22:17:56.018 Thread-56: loading media playlist
22:17:56.144 Thread-56: adding media segment 222641048
22:17:56.158 Thread-56: playing media segment 222641048
22:17:56.714 Thread-56: finished writing 258284 bytes
22:17:56.720 Thread-56: sleeping for 2808 ms
22:17:59.537 Thread-56: loading media playlist
22:17:59.649 Thread-56: no new media segments available
22:17:59.650 Thread-56: sleeping for 1709 ms
22:18:01.360 Thread-56: loading media playlist
22:18:01.523 Thread-56: no new media segments available
22:18:01.533 Thread-56: sleeping for 1583 ms
22:18:03.121 Thread-56: loading media playlist
22:18:03.180 Thread-56: no new media segments available
22:18:03.194 Thread-56: sleeping for 1681 ms
22:18:04.876 Thread-56: loading media playlist
22:18:04.999 Thread-56: adding media segment 222641049
22:18:05.013 Thread-56: playing media segment 222641049
22:18:05.653 Thread-56: finished writing 257930 bytes
22:18:05.663 Thread-56: sleeping for 2779 ms
22:18:08.448 Thread-56: loading media playlist
22:18:08.503 Thread-56: no new media segments available
22:18:08.512 Thread-56: sleeping for 1690 ms
22:18:10.212 Thread-56: loading media playlist
22:18:10.278 Thread-56: adding media segment 222641050
22:18:10.291 Thread-56: playing media segment 222641050
22:18:10.919 Thread-56: finished writing 257984 bytes
22:18:10.933 Thread-56: sleeping for 2792 ms
22:18:13.727 Thread-56: loading media playlist
22:18:13.770 Thread-56: no new media segments available
22:18:13.771 Thread-56: sleeping for 1707 ms
22:18:15.479 Thread-56: loading media playlist
22:18:15.621 Thread-56: no new media segments available
22:18:15.634 Thread-56: sleeping for 1676 ms
22:18:17.311 Thread-56: loading media playlist
22:18:17.366 Thread-56: adding media segment 222641051
22:18:17.379 Thread-56: playing media segment 222641051
22:18:18.017 Thread-56: finished writing 258100 bytes
22:18:18.030 Thread-56: sleeping for 2789 ms
22:18:20.821 Thread-56: loading media playlist
22:18:20.936 Thread-56: no new media segments available
22:18:20.937 Thread-56: sleeping for 1711 ms
22:18:22.649 Thread-56: loading media playlist
22:18:22.714 Thread-56: adding media segment 222641052
22:18:22.725 Thread-56: playing media segment 222641052
22:18:23.356 Thread-56: finished writing 258100 bytes
22:18:23.363 Thread-56: sleeping for 2803 ms
22:18:26.175 Thread-56: loading media playlist
22:18:26.281 Thread-56: no new media segments available
22:18:26.287 Thread-56: sleeping for 1690 ms
22:18:27.984 Thread-56: loading media playlist
22:18:28.073 Thread-56: adding media segment 222641053
22:18:28.077 Thread-56: playing media segment 222641053
22:18:28.726 Thread-56: finished writing 258132 bytes
22:18:28.739 Thread-56: sleeping for 2746 ms
22:18:31.487 Thread-56: loading media playlist
22:18:31.624 Thread-56: no new media segments available
22:18:31.638 Thread-56: sleeping for 1672 ms
22:18:33.311 Thread-56: loading media playlist
22:18:33.373 Thread-56: no new media segments available
22:18:33.384 Thread-56: sleeping for 1691 ms
22:18:35.079 Thread-56: loading media playlist
22:18:35.138 Thread-56: adding media segment 222641054
22:18:35.151 Thread-56: playing media segment 222641054
22:18:35.719 Thread-56: finished writing 258074 bytes
22:18:35.725 Thread-56: sleeping for 2855 ms
22:18:38.588 Thread-56: loading media playlist
22:18:38.644 Thread-56: no new media segments available
22:18:38.658 Thread-56: sleeping for 1683 ms
22:18:40.342 Thread-56: loading media playlist
22:18:40.474 Thread-56: no new media segments available
22:18:40.487 Thread-56: sleeping for 1607 ms
22:18:42.096 Thread-56: loading media playlist
22:18:42.165 Thread-56: adding media segment 222641055
22:18:42.171 Thread-56: playing media segment 222641055
22:18:42.806 Thread-56: finished writing 258072 bytes
22:18:42.820 Thread-56: sleeping for 2791 ms
22:18:45.613 Thread-56: loading media playlist
22:18:45.653 Thread-56: no new media segments available
22:18:45.654 Thread-56: sleeping for 1712 ms
22:18:47.367 Thread-56: loading media playlist
22:18:47.422 Thread-56: no new media segments available
22:18:47.433 Thread-56: sleeping for 1687 ms
22:18:49.122 Thread-56: loading media playlist
22:18:49.163 Thread-56: no new media segments available
22:18:49.164 Thread-56: sleeping for 1710 ms
22:18:50.875 Thread-56: loading media playlist
22:18:50.931 Thread-56: no new media segments available
22:18:50.945 Thread-56: sleeping for 1689 ms
22:18:52.635 Thread-56: loading media playlist
22:18:52.691 Thread-56: no new media segments available
22:18:52.703 Thread-56: sleeping for 1684 ms
22:18:54.294 Thread-54: HTTPConnection: end of input stream data
22:18:54.295 Thread-54: Streamer: getting request chain for org.jminim.lib.HTTPConnection$Request@14e47cc
22:18:54.298 Thread-54: Streamer: stopping chain org.jstreamer.core.ChainImpl@675788
22:18:54.299 Thread-54: ChainImpl: stop org.jstreamer.core.ChainImpl@675788
22:18:54.300 Thread-54: ChainImpl: removing target from org.jstreamer.core.TargetChain@17f833a
22:18:54.300 Thread-54: ChainImpl: stop org.jstreamer.core.ChainImpl@12f0322
22:18:54.301 Thread-54: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@12f0322
22:18:54.301 Thread-54: ChainSource: stopping reader thread
22:18:54.314 Thread-58: ChainSource: error reading input stream: org.jstreamer.OutputException: java.io.InterruptedIOException
22:18:54.315 Thread-58: Buffer: closing buffer: org.jstreamer.core.Buffer@370265
22:18:54.316 Thread-57: BufferReader: fillBuffer returned -1: buffer=org.jstreamer.core.Buffer@370265
22:18:54.317 Thread-57: ChainTarget: end of data from input stream
22:18:54.318 Thread-57: ChainImpl: stop org.jstreamer.core.ChainImpl@675788
22:18:54.318 Thread-57: BufferPoolReader: close
22:18:54.319 Thread-57: BufferReader: close: buffer=org.jstreamer.core.Buffer@370265
22:18:54.319 Thread-57: Buffer: removeReader: org.jstreamer.core.Buffer@370265
22:18:54.320 Thread-57: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@370265
22:18:54.320 Thread-57: BufferReader: close: buffer=org.jstreamer.core.Buffer@b2921b
22:18:54.321 Thread-57: Buffer: removeReader: org.jstreamer.core.Buffer@b2921b
22:18:54.321 Thread-57: Buffer: removeReaders calling notifyAll: org.jstreamer.core.Buffer@b2921b
22:18:54.323 Thread-54: ChainSource: stopping source
22:18:54.324 Thread-56: HTTPSource.ReaderThread caught InterruptedException
22:18:54.324 Thread-56: HTTPSource: closing piped output stream
22:18:54.326 Thread-54: HTTPSource: closing outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.203,port=80,localport=42583]
22:18:54.327 Thread-54: ChainSource: source stopped
22:18:54.327 Thread-54: TargetChain: stop
22:18:54.328 Thread-54: TargetChain: stopping subchain
22:18:54.328 Thread-54: ChainImpl: stop org.jstreamer.core.ChainImpl@675788
22:18:54.329 Thread-54: TargetChain: subchain stopped
22:18:54.329 Thread-54: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@12f0322
22:18:54.330 Thread-54: ChainImpl: stopping chain org.jstreamer.core.ChainImpl@675788
22:18:54.330 Thread-54: ChainTarget: stop
22:18:54.331 Thread-54: ChainTarget: stopping target
22:18:54.371 Thread-54: HTTPRequestTarget: stop this=com.minimstreamer.HTTPRequestTarget@eef3c6 outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@c0f6b1
22:18:54.384 Thread-54: HTTPRequestTarget: closeSocket
22:18:54.385 Thread-54: HTTPRequestTarget: closing Socket[addr=/192.168.0.24,port=37702,localport=9790]
22:18:54.386 Thread-54: HTTPRequestTarget: notifyStopped com.minimstreamer.Streamer$NotifyStopped@16d2058
22:18:54.386 Thread-54: Streamer.NotifyStopped: run
22:18:54.389 Thread-53: Streamer: removing request chain for org.jminim.lib.HTTPConnection$Request@14e47cc
22:18:54.390 Thread-53: Streamer: completed network request
22:18:54.390 Thread-53: HTTPConnection: completed request; socket=Socket[addr=/192.168.0.24,port=37702,localport=9790], keepAlive=true
22:18:54.391 Thread-53: HTTPConnection: writer thread waiting for request
22:18:54.391 Thread-54: ChainTarget: target stopped
22:18:54.392 Thread-54: ChainImpl: stopped chain org.jstreamer.core.ChainImpl@675788
22:18:54.393 Thread-53: HTTPConnection: writer thread interrupted
22:18:54.394 Thread-54: HTTPService: removing connection org.jminim.lib.HTTPConnection@19a1fcc
22:19:06.757 Thread-16: HTTPService: accepted incoming connection
22:19:06.764 Thread-15: HTTPService: received request, Socket[addr=/192.168.0.24,port=48607,localport=9790]
22:19:06.765 Thread-15: HTTPService: adding connection org.jminim.lib.HTTPConnection@b21bf5
22:19:06.767 Thread-16: HTTPService: waiting for incoming connection
22:19:06.777 Thread-59: HTTPConnection: writer thread waiting for request
22:19:06.778 Thread-60: HTTPConnection: reading HTTP request
22:19:06.779 Thread-60: GET /minimstreamer/*/R2 HTTP/1.1
22:19:06.780 Thread-60: ACCEPT: */*, HOST: 192.168.0.3:9790, User-Agent: Nullsoft Winamp3 version 3.0 (compatible), Icy-MetaData: 1
22:19:06.791 Thread-59: HTTPConnection: writer thread processing request
22:19:06.792 Thread-59: Streamer: processing HTTP request
22:19:06.792 Thread-59: Streamer: releaseChains
22:19:06.793 Thread-59: Streamer: releasing chain: R2
22:19:06.794 Thread-59: Streamer: streamID is R2
22:19:06.794 Thread-59: Streamer: URL scheme is http
22:19:06.794 Thread-59: Streamer: request path is a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_two.m3u8
22:19:06.795 Thread-59: Streamer: transcodeType is
22:19:06.796 Thread-59: ChainImpl: addSource org.jstreamer.core.ChainSource@78d9f8
22:19:06.797 Thread-59: ChainSource: init
22:19:06.797 Thread-59: ChainImpl: getting property .inputBufferSize
22:19:06.797 Thread-59: ChainImpl: property .inputBufferSize has null value
22:19:06.798 Thread-59: ChainImpl: getting property .inputBuffers
22:19:06.798 Thread-59: ChainImpl: property .inputBuffers has null value
22:19:06.799 Thread-59: ChainSource: inputBufferSize=5000 inputBuffers=2
22:19:06.799 Thread-59: BufferPool: init
22:19:06.800 Thread-59: ChainSource: source created
22:19:06.801 Thread-59: ChainImpl: getting property scfilter.link
22:19:06.802 Thread-60: HTTPConnection: reading HTTP request
22:19:06.802 Thread-59: ChainImpl: property scfilter.link has literal value 'source'
22:19:06.803 Thread-59: ChainImpl: getting property scfilter.mode
22:19:06.803 Thread-59: ChainImpl: property scfilter.mode has literal value 'out'
22:19:06.804 Thread-59: ChainImpl: addFilter org.jstreamer.core.ChainSource@78d9f8
22:19:06.804 Thread-59: LinkBase: adding output filter org.jstreamer.lib.ShoutcastFilter@4756af
22:19:06.805 Thread-59: created new root chain org.jstreamer.core.ChainImpl@145d3c3
22:19:06.805 Thread-59: ChainImpl: setting property .requestPath to 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_two.m3u8'
22:19:06.806 Thread-59: ChainImpl: setting property .requestMethod to 'GET'
22:19:06.807 Thread-59: ChainImpl: setting property .requestHeaders to 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
22:19:06.807 Thread-59: ChainImpl: setting property .delayHLS to '10'
22:19:06.809 Thread-59: ChainImpl: addTarget org.jstreamer.core.ChainTarget@12ec57
22:19:06.809 Thread-59: ChainTarget: init
22:19:06.823 Thread-59: LinkBase: adding input filter com.minimstreamer.HTTPRequestTarget$TargetFilter@822554
22:19:06.824 Thread-59: ChainTarget: target created
22:19:06.825 Thread-59: ChainImpl: getting property adfilter.link
22:19:06.825 Thread-59: ChainImpl: property adfilter.link has literal value 'request'
22:19:06.826 Thread-59: ChainImpl: getting property adfilter.mode
22:19:06.826 Thread-59: ChainImpl: property adfilter.mode has null value
22:19:06.827 Thread-59: ChainImpl: addFilter org.jstreamer.core.ChainTarget@12ec57
22:19:06.827 Thread-59: LinkBase: adding input filter org.jstreamer.lib.FrameFilter@16a2c8c
22:19:06.828 Thread-59: ChainImpl: setting property .timeout to '2000'
22:19:06.828 Thread-59: ChainImpl: setting property object .@timeoutAction to com.minimstreamer.Streamer$TimeoutAction@f1c1a8
22:19:06.829 Thread-59: ChainImpl: setting property object .@notifyStopped to com.minimstreamer.Streamer$NotifyStopped@186ed27
22:19:06.829 Thread-59: ChainImpl: setting property object .@httpRequest to org.jminim.lib.HTTPConnection$Request@124b557
22:19:06.830 Thread-59: ChainImpl: setting property object .@http to org.jminim.lib.HTTPContext@1c08084
22:19:06.831 Thread-59: ChainImpl: setting property .transcodeType to ''
22:19:06.831 Thread-59: ChainImpl: setting property object .@streamer to com.minimstreamer.Streamer@265ba4
22:19:06.832 Thread-59: ChainImpl: setting property object .@parentChain to org.jstreamer.core.ChainImpl@145d3c3
22:19:06.832 Thread-59: Streamer: adding request chain for org.jminim.lib.HTTPConnection$Request@124b557: org.jstreamer.core.ChainImpl@1bae39c
22:19:06.836 Thread-59: ChainImpl: addTargetChain org.jstreamer.core.TargetChain@1641fec
22:19:06.837 Thread-59: TargetChain: init
22:19:06.837 Thread-59: BufferPoolReader: new
22:19:06.838 Thread-59: Buffer: createReader: org.jstreamer.core.Buffer@11c7129
22:19:06.838 Thread-59: BufferReader: initial readSequence=1
22:19:06.839 Thread-59: Buffer: createReader: org.jstreamer.core.Buffer@11148b8
22:19:06.839 Thread-59: BufferReader: initial readSequence=1
22:19:06.840 Thread-59: ChainImpl: start org.jstreamer.core.ChainImpl@145d3c3
22:19:06.840 Thread-59: ChainImpl: startLinks org.jstreamer.core.ChainImpl@145d3c3
22:19:06.841 Thread-59: ChainImpl: starting chain org.jstreamer.core.ChainImpl@145d3c3
22:19:06.841 Thread-59: TargetChain: start
22:19:06.841 Thread-59: TargetChain: starting subchain links
22:19:06.842 Thread-59: ChainImpl: startLinks org.jstreamer.core.ChainImpl@1bae39c
22:19:06.842 Thread-59: ChainImpl: starting chain org.jstreamer.core.ChainImpl@1bae39c
22:19:06.843 Thread-59: ChainTarget: start
22:19:06.844 Thread-59: ChainImpl: property obj request.@notifyStopped is reference to .@notifyStopped
22:19:06.844 Thread-59: ChainImpl: property object request.@notifyStopped has value com.minimstreamer.Streamer$NotifyStopped@186ed27
22:19:06.845 Thread-59: ChainImpl: property obj request.@httpRequest is reference to .@httpRequest
22:19:06.845 Thread-59: ChainImpl: property object request.@httpRequest has value org.jminim.lib.HTTPConnection$Request@124b557
22:19:06.846 Thread-59: ChainImpl: property obj request.@http is reference to .@http
22:19:06.846 Thread-59: ChainImpl: property object request.@http has value org.jminim.lib.HTTPContext@1c08084
22:19:06.847 Thread-59: ChainImpl: property obj request.@timeoutAction is reference to .@timeoutAction
22:19:06.847 Thread-59: ChainImpl: property object request.@timeoutAction has value com.minimstreamer.Streamer$TimeoutAction@f1c1a8
22:19:06.848 Thread-59: ChainImpl: getting property request.timeout
22:19:06.848 Thread-59: ChainImpl: property request.timeout has initial value '$.timeout'
22:19:06.849 Thread-59: ChainImpl: property .timeout has literal value '2000'
22:19:06.849 Thread-59: ChainImpl: substitution property .timeout has value '2000'
22:19:06.849 Thread-59: ChainImpl: property request.timeout has final value '2000'
22:19:06.850 Thread-59: HTTPRequestTarget: timeout is 2000
22:19:06.851 Thread-59: HTTPRequestTarget: initRequest socket=Socket[addr=/192.168.0.24,port=48607,localport=9790] this=com.minimstreamer.HTTPRequestTarget@3f4471 outStr=com.minimstreamer.HTTPRequestTarget$ProxyOutputStream@e724eb
22:19:06.852 Thread-59: ChainTarget: target started
22:19:06.853 Thread-59: ChainImpl: started chain org.jstreamer.core.ChainImpl@1bae39c
22:19:06.854 Thread-59: TargetChain: subchain links started
22:19:06.854 Thread-59: ChainSource: start
22:19:06.855 Thread-59: ChainImpl: getting property source.resource
22:19:06.855 Thread-59: ChainImpl: property source.resource has initial value '$.requestPath'
22:19:06.856 Thread-59: ChainImpl: property .requestPath has literal value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_two.m3u8'
22:19:06.856 Thread-59: ChainImpl: substitution property .requestPath has value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_two.m3u8'
22:19:06.856 Thread-59: ChainImpl: property source.resource has final value 'a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_two.m3u8'
22:19:06.857 Thread-59: ChainImpl: getting property source.requestMethod
22:19:06.857 Thread-59: ChainImpl: property source.requestMethod has initial value '$.requestMethod'
22:19:06.858 Thread-59: ChainImpl: property .requestMethod has literal value 'GET'
22:19:06.858 Thread-59: ChainImpl: substitution property .requestMethod has value 'GET'
22:19:06.859 Thread-59: ChainImpl: property source.requestMethod has final value 'GET'
22:19:06.859 Thread-59: ChainImpl: getting property source.requestHeaders
22:19:06.860 Thread-59: ChainImpl: property source.requestHeaders has initial value '$.requestHeaders'
22:19:06.860 Thread-59: ChainImpl: property .requestHeaders has literal value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
22:19:06.873 Thread-59: ChainImpl: substitution property .requestHeaders has value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
22:19:06.874 Thread-59: ChainImpl: property source.requestHeaders has final value 'ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1

'
22:19:06.875 Thread-59: ChainImpl: getting property source.delayHLS
22:19:06.875 Thread-59: ChainImpl: property source.delayHLS has initial value '$.delayHLS'
22:19:06.876 Thread-59: ChainImpl: property .delayHLS has literal value '10'
22:19:06.876 Thread-59: ChainImpl: substitution property .delayHLS has value '10'
22:19:06.876 Thread-59: ChainImpl: property source.delayHLS has final value '10'
22:19:06.917 Thread-59: HTTPSource: created outgoing socket Socket[addr=a.files.bbci.co.uk/90.223.233.192,port=80,localport=32940]
22:19:06.925 Thread-59: HTTPSource: sending HTTP request:
GET /media/live/manifesto/audio/simulcast/hls/uk/sbr_high/llnw/bbc_radio_two.m3u8 HTTP/1.1
Host: a.files.bbci.co.uk
ACCEPT: */*
User-Agent: Nullsoft Winamp3 version 3.0 (compatible)
Icy-MetaData: 1


22:19:06.976 Thread-59: HTTPSource: stream response status HTTP/1.1 200 OK
22:19:06.977 Thread-59: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
22:19:06.986 Thread-59: x-amz-id-2: u687wPpQq/ndcSZdQYKdYDex8Q5t4dEe7QOtnHiXNDeHDs4rg62/8Bip6LAjih4W
x-amz-request-id: DB1BD6452AA82660
Last-Modified: Wed, 25 Feb 2015 11:59:01 GMT
ETag: "9231664d41cab9bef8f50bfa68df5c82"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 234
Server: AmazonS3
Cache-Control: max-age=274
Expires: Wed, 25 Feb 2015 22:23:40 GMT
Date: Wed, 25 Feb 2015 22:19: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: *

22:19:06.987 Thread-59: ChainImpl: setting property source.responseHeaders to 'x-amz-id-2: u687wPpQq/ndcSZdQYKdYDex8Q5t4dEe7QOtnHiXNDeHDs4rg62/8Bip6LAjih4W
x-amz-request-id: DB1BD6452AA82660
Last-Modified: Wed, 25 Feb 2015 11:59:01 GMT
ETag: "9231664d41cab9bef8f50bfa68df5c82"
Accept-Ranges: bytes
Content-Type: application/x-mpegurl
Content-Length: 234
Server: AmazonS3
Cache-Control: max-age=274
Expires: Wed, 25 Feb 2015 22:23:40 GMT
Date: Wed, 25 Feb 2015 22:19: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: *
'
22:19:06.988 Thread-59: HTTPSource: content type is 'application/x-mpegurl'
22:19:06.989 Thread-59: HTTPSource: reading playlist from URL http://a.files.bbci.co.uk/media/live/man...o_two.m3u8
22:19:06.991 Thread-59: HTTPSource: using HLS
22:19:06.992 Thread-59: HTTPSource: found valid stream URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
22:19:06.993 Thread-59: HTTPSource: reading HLS media playlist from URL http://as-hls-uk-live.bbcfmt.vo.llnwd.ne..._length=24
22:19:06.994 Thread-59: ChainImpl: setting property source.responseHeaders to ''
22:19:06.995 Thread-59: loading media playlist
22:19:07.111 Thread-59: adding media segment 222641055
22:19:07.114 Thread-59: adding media segment 222641056
22:19:07.124 Thread-59: adding media segment 222641057
22:19:07.125 Thread-59: adding media segment 222641058
22:19:07.125 Thread-59: adding media segment 222641059
22:19:07.136 Thread-62: starting to play HLS stream
22:19:07.137 Thread-62: playStream: delayHLS=10 targetDuration=7
22:19:07.137 Thread-62: initial delay is 3 media segments
22:19:07.137 Thread-62: skipping media segment 222641055
22:19:07.138 Thread-62: skipping media segment 222641056
22:19:07.138 Thread-62: playing media segment 222641057
22:19:07.280 Thread-62: media segment content type is video/mp2t
22:19:07.294 Thread-59: ChainImpl: setting property source.status to 'HTTP/1.1 200 OK
'
22:19:07.295 Thread-59: ChainImpl: setting property source.contentType to 'audio/aac'
22:19:07.296 Thread-59: ChainImpl: setting property source.contentFormat to 'aac'
22:19:07.296 Thread-59: ChainImpl: setting property source.responseMessage to ''
22:19:07.297 Thread-59: ChainImpl: setting property source.sourcePath to '/pool_7/live/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d320000.m3u8'
22:19:07.298 Thread-59: ChainSource: source started
22:19:07.298 Thread-59: ChainImpl: started chain org.jstreamer.core.ChainImpl@145d3c3
22:19:07.299 Thread-59: ChainImpl: runLinks org.jstreamer.core.ChainImpl@145d3c3
22:19:07.299 Thread-59: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@145d3c3
22:19:07.300 Thread-59: TargetChain: run
22:19:07.300 Thread-59: TargetChain: running subchain links
22:19:07.301 Thread-59: ChainImpl: runLinks org.jstreamer.core.ChainImpl@1bae39c
22:19:07.308 Thread-59: ChainImpl: running links for chain org.jstreamer.core.ChainImpl@1bae39c
22:19:07.309 Thread-59: ChainTarget: run
22:19:07.310 Thread-59: ChainImpl: getting property request.transcodeType
22:19:07.310 Thread-59: ChainImpl: property request.transcodeType has initial value '$.transcodeType'
22:19:07.312 Thread-59: ChainImpl: property .transcodeType has literal value ''
22:19:07.314 Thread-59: ChainImpl: substitution property .transcodeType has value ''
22:19:07.315 Thread-59: ChainImpl: property request.transcodeType has final value ''
22:19:07.317 Thread-59: ChainImpl: getting property request.transcodeLimit
22:19:07.317 Thread-59: ChainImpl: property request.transcodeLimit has null value
22:19:07.318 Thread-59: ChainImpl: getting property request.contentType
22:19:07.318 Thread-59: ChainImpl: property request.contentType has initial value '$/source.contentType'
22:19:07.319 Thread-59: ChainImpl: property source.contentType has literal value 'audio/aac'
22:19:07.319 Thread-59: ChainImpl: substitution property /source.contentType has value 'audio/aac'
22:19:07.320 Thread-59: ChainImpl: property request.contentType has final value 'audio/aac'
22:19:07.322 Thread-59: ChainImpl: property obj request.@streamer is reference to .@streamer
22:19:07.322 Thread-59: ChainImpl: property object request.@streamer has value com.minimstreamer.Streamer@265ba4
22:19:07.324 Thread-59: ChainTarget: target running
22:19:07.326 Thread-59: ChainTarget: starting writer thread
22:19:07.329 Thread-59: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@1bae39c
22:19:07.330 Thread-59: TargetChain: subchain links running
22:19:07.330 Thread-59: ChainSource: run
22:19:07.331 Thread-59: ChainSource: source running
22:19:07.350 Thread-59: ChainSource: starting reader thread
22:19:07.352 Thread-59: ChainImpl: links running for chain org.jstreamer.core.ChainImpl@145d3c3
22:19:07.353 Thread-59: Streamer: waiting for completion of network request
22:19:07.353 Thread-59: Streamer.NotifyStopped: waitFor
22:19:07.354 Thread-59: Streamer.NotifyStopped: waiting
22:19:08.311 Thread-64: ChainImpl: getting property scfilter.responseHeaders
22:19:08.312 Thread-64: ChainImpl: property scfilter.responseHeaders has initial value '$source.responseHeaders'
22:19:08.318 Thread-64: ChainImpl: property source.responseHeaders has literal value ''
22:19:08.318 Thread-64: ChainImpl: substitution property source.responseHeaders has value ''
22:19:08.319 Thread-64: ChainImpl: property scfilter.responseHeaders has final value ''
22:19:08.319 Thread-64: ShoutcastFilter: response headers=
22:19:08.320 Thread-64: ShoutcastFilter: icyMetaint=0
22:19:08.333 Thread-63: ChainImpl: getting property request.delay
22:19:08.333 Thread-63: ChainImpl: property request.delay has null value
22:19:08.334 Thread-63: ChainImpl: getting property request.responseHeaders
22:19:08.334 Thread-63: ChainImpl: property request.responseHeaders has null value
22:19:08.335 Thread-63: ChainImpl: getting property request.status
22:19:08.335 Thread-63: ChainImpl: property request.status has initial value '$/source.status'
22:19:08.336 Thread-63: ChainImpl: property source.status has literal value 'HTTP/1.1 200 OK
'
22:19:08.336 Thread-63: ChainImpl: substitution property /source.status has value 'HTTP/1.1 200 OK
'
22:19:08.336 Thread-63: ChainImpl: property request.status has final value 'HTTP/1.1 200 OK
'
22:19:08.337 Thread-63: ChainImpl: getting property request.sourceResponseHeaders
22:19:08.337 Thread-63: ChainImpl: property request.sourceResponseHeaders has initial value '$/source.responseHeaders'
22:19:08.338 Thread-63: ChainImpl: property source.responseHeaders has literal value ''
22:19:08.338 Thread-63: ChainImpl: substitution property /source.responseHeaders has value ''
22:19:08.338 Thread-63: ChainImpl: property request.sourceResponseHeaders has final value ''
22:19:08.342 Thread-63: ChainImpl: getting property request.sourcePath
22:19:08.348 Thread-63: ChainImpl: property request.sourcePath has initial value '$/source.sourcePath'
22:19:08.348 Thread-63: ChainImpl: property source.sourcePath has literal value '/pool_7/live/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d320000.m3u8'
22:19:08.349 Thread-63: ChainImpl: substitution property /source.sourcePath has value '/pool_7/live/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d320000.m3u8'
22:19:08.349 Thread-63: ChainImpl: property request.sourcePath has final value '/pool_7/live/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d320000.m3u8'
22:19:08.351 Thread-63: HTTP/1.1 200 OK, Date: Wed, 25 Feb 2015 22:19:08 GMT, Connection: close, Server: MinimStreamer, Content-Type: audio/aac
22:19:08.352 Thread-63: ChainImpl: getting property adfilter.contentType
22:19:08.352 Thread-63: ChainImpl: property adfilter.contentType has initial value '$/source.contentType'
22:19:08.353 Thread-63: ChainImpl: property source.contentType has literal value 'audio/aac'
22:19:08.354 Thread-63: ChainImpl: substitution property /source.contentType has value 'audio/aac'
22:19:08.354 Thread-63: ChainImpl: property adfilter.contentType has final value 'audio/aac'
22:19:08.355 Thread-63: FrameFilter: contentType is 'audio/aac'
22:19:08.355 Thread-63: ADTSFilter: state SYNC1 at position 0
22:19:08.356 Thread-63: ADTSFilter: state SYNC2 at position 1
22:19:08.357 Thread-63: ADTSFilter: state SYNC3 at position 2
22:19:08.357 Thread-63: ADTSFilter: state SYNCED at position 3
22:19:08.800 Thread-62: finished writing 258170 bytes
22:19:08.813 Thread-62: playing media segment 222641058
22:19:09.326 Thread-62: finished writing 258000 bytes
22:19:09.339 Thread-62: playing media segment 222641059
22:19:13.432 Thread-62: finished writing 258145 bytes
22:19:13.443 Thread-62: loading media playlist
22:19:13.578 Thread-62: adding media segment 222641060
22:19:13.585 Thread-62: playing media segment 222641060
Find all posts by this user
Quote this message in a reply
Post Reply 


Forum Jump:


User(s) browsing this thread: 1 Guest(s)