Music interrupted

[tarnkappe]

Hi Simon,

usually playing of music from minimserver to my naim uniti works without any problems. But today the music suddenly did stop shortly after beginning a new track. As I am waiting for a BubbleUPnP crash (that I had reported in another thread months ago) I had set the logging level to debug. But this time minimserver did not crash.

The logfile looks like the client has closed the connection, right? (Here is a snippet from the logfile without the ohnet entries ("grep -v ohnet:"). So it is not a minimserver issue?

The first track that was played fine was "01 - Colonel Abrams - Trapped [Dance Version].flac". The second track that was interrupted was "02 - Shirley Lites - Heat You Up (Melt You Down).flac".

Code:

20:48:02.344 Thread-194: HTTPConnection: end of input stream data
20:48:02.344 Thread-194: HTTPConnection: closing Socket[addr=/192.168.178.74,port=52745,localport=9790]
20:48:02.345 Thread-194: HTTPService: removing connection org.jminim.lib.HTTPConnection@9e9f1b
20:48:02.345 Thread-193: HTTPConnection: writer thread interrupted
20:54:19.731 Thread-207: FLACResource: reader thread end of data
20:54:20.008 Thread-205: FLACResource: writer thread end of data, bytesWritten=103765580
20:54:20.008 Thread-205: FLACResource: writeData completed
20:54:20.008 Thread-205: FLACResource: close
20:54:20.008 Thread-205: FLACResource: closeDecoder
20:54:20.008 Thread-205: ServerResourceBase: close
20:54:20.008 Thread-205: HTTPConnection: completed request; socket=Socket[addr=/192.168.178.35,port=1375,localport=9790], keepAlive=false
20:54:20.008 Thread-205: HTTPConnection: closing Socket[addr=/192.168.178.35,port=1375,localport=9790]
20:54:20.009 Thread-205: HTTPService: removing connection org.jminim.lib.HTTPConnection@183222b
20:54:20.009 Thread-206: HTTPConnection: connection closed by client
20:54:26.165 Thread-19: HTTPService: accepted incoming connection
20:54:26.165 Thread-19: HTTPService: waiting for incoming connection
20:54:26.165 Thread-18: HTTPService: received request, Socket[addr=/192.168.178.35,port=1400,localport=9790]
20:54:26.165 Thread-18: HTTPService: adding connection org.jminim.lib.HTTPConnection@1b6611e
20:54:26.166 Thread-208: HTTPConnection: writer thread waiting for request
20:54:26.166 Thread-209: HTTPConnection: reading HTTP request
20:54:26.167 Thread-209: GET /minimserver/*/music/cd_collection/electronic/Various*20Artists/1989*20-*20The*20History*20of*20the*20House*20Sound*20of*20Chicago*20-*20Vol.*2001*20-*20The*20Tracks*20That*20Built*20The*20House/02*20-*20Shirley*20Lites*20-*20Heat*20You*20Up*20(Melt*20You*20Down).flac/$!transcode-24.wav HTTP/1.1
20:54:26.167 Thread-209: Host: 192.168.178.84:9790, Range: bytes=0-, Icy-MetaData: 1, Connection: close, transferMode.dlna.org: Streaming, User-Agent: WinampMPEG/2.8, Accept: */*
20:54:26.167 Thread-208: HTTPConnection: writer thread processing request
20:54:26.167 Thread-208: ServerRequestHandler: factory=com.minimstreamer.Streamer$ResourceFactory@1def03a resourcePath=/volume1/music/cd_collection/electronic/Various Artists/1989 - The History of the House Sound of Chicago - Vol. 01 - The Tracks That Built The House/02 - Shirley Lites - Heat You Up (Melt You Down).flac relativePath=cd_collection/electronic/Various Artists/1989 - The History of the House Sound of Chicago - Vol. 01 - The Tracks That Built The House/02 - Shirley Lites - Heat You Up (Melt You Down).flac fileMimeType=FLAC streamMimeType=WAVE streamSampleBits=24 streamSampleRate=0
20:54:26.168 Thread-208: Streamer.createResource: resourcePath=/volume1/music/cd_collection/electronic/Various Artists/1989 - The History of the House Sound of Chicago - Vol. 01 - The Tracks That Built The House/02 - Shirley Lites - Heat You Up (Melt You Down).flac relativePath=cd_collection/electronic/Various Artists/1989 - The History of the House Sound of Chicago - Vol. 01 - The Tracks That Built The House/02 - Shirley Lites - Heat You Up (Melt You Down).flac fileMimeType=FLAC streamMimeType=WAVE streamSampleBits=24 streamSampleRate=0
20:54:26.169 Thread-209: HTTPConnection: reading HTTP request
20:54:26.189 Thread-208: FLACResource: transcodeType is FLAC16_WAV24
20:54:26.189 Thread-208: $$$ FLACResource: open, start=0
20:54:26.189 Thread-208: FLACResource: 02 - Shirley Lites - Heat You Up (Melt You Down).flac startByte=0 startSample=0
20:54:26.189 Thread-208: $$$ FLACResource: audioStart=8244
20:54:26.190 Thread-208: $$$ FLACResource: seek table is available
20:54:26.190 Thread-208: $$$ FLACResource: found seek table entry
20:54:26.190 Thread-208: $$$ FLACResource: bitStreamPosition=8244 inputStreamPosition=9242
20:54:26.190 Thread-208: $$$ FLACResource: upperSample=438272 lowerSample=0 upperOffset=946275 lowerOffset=0
20:54:26.190 Thread-208: $$$ FLACResource: reading frames
20:54:26.191 Thread-208: $$$ FLACResource: initial frameSampleNumber=0 sampleOffset=0
20:54:26.191 Thread-208: $$$ FLACResource: byteOffset=0
20:54:26.195 Thread-208: FLACResource: writeData, total=109667924
20:54:26.197 Thread-208: HTTP/1.1 206 Partial Content, Content-Range: bytes 0-109667923/109667924, Accept-Ranges: bytes, Date: Fri, 18 Sep 2015 20:54:26 GMT, Content-Length: 109667924, Content-Type: audio/x-wav, Connection: close, Last-Modified: Tue, 14 Aug 2012 07:23:27 GMT, transferMode.dlna.org: Streaming
20:54:48.292 Thread-209: HTTPConnection: connection closed by client
20:54:48.292 Thread-209: HTTPConnection: closing Socket[addr=/192.168.178.35,port=1400,localport=9790]
20:54:48.292 Thread-209: HTTPService: removing connection org.jminim.lib.HTTPConnection@1b6611e
20:54:48.321 Thread-208: FLACResource: close
20:54:48.321 Thread-208: FLACResource: closeDecoder
20:54:48.321 Thread-208: ServerResourceBase: close
20:54:48.322 Thread-208: HTTPConnection: SocketException writing HTTP response to Socket[addr=/192.168.178.35,port=1400,localport=9790]
20:54:48.322 Thread-208: HTTPConnection: writer thread interrupted
20:54:55.108 Thread-10: ContentDirectory action: GetSearchCapabilities
20:54:55.108 Thread-10:  version=1, adapter=192.168.178.84, uriPrefix=http://192.168.178.84:9791/c04da9fe-036d-4bec-aa5c-abb0afa61f63/Upnp/resource/, clientEndpoint=192.168.178.84:52035
20:54:55.108 Thread-10: ContentDirectory response: GetSearchCapabilities
20:54:55.108 Thread-10:  SearchCapabilities=*
20:54:55.190 Thread-12: ContentDirectory action: GetSortCapabilities
20:54:55.190 Thread-12:  version=1, adapter=192.168.178.84, uriPrefix=http://192.168.178.84:9791/c04da9fe-036d-4bec-aa5c-abb0afa61f63/Upnp/resource/, clientEndpoint=192.168.178.84:52036
20:54:55.190 Thread-12: ContentDirectory response: GetSortCapabilities
20:54:55.190 Thread-12:  SortCapabilities=
20:55:00.363 Thread-10: ContentDirectory action: GetSearchCapabilities
20:55:00.363 Thread-10:  version=1, adapter=192.168.178.84, uriPrefix=http://192.168.178.84:9791/c04da9fe-036d-4bec-aa5c-abb0afa61f63/Upnp/resource/, clientEndpoint=192.168.178.35:1043
20:55:00.363 Thread-10: ContentDirectory response: GetSearchCapabilities
20:55:00.363 Thread-10:  SearchCapabilities=*
20:55:00.410 Thread-12: ContentDirectory action: GetSortCapabilities
20:55:00.410 Thread-12:  version=1, adapter=192.168.178.84, uriPrefix=http://192.168.178.84:9791/c04da9fe-036d-4bec-aa5c-abb0afa61f63/Upnp/resource/, clientEndpoint=192.168.178.35:1044
20:55:00.410 Thread-12: ContentDirectory response: GetSortCapabilities
20:55:00.410 Thread-12:  SortCapabilities=
21:06:15.295 Thread-11: ContentDirectory action: Browse 0$folders$f2291$f2525$f2610$f2630
21:06:15.295 Thread-11:  version=1, adapter=192.168.178.84, uriPrefix=http://192.168.178.84:9791/c04da9fe-036d-4bec-aa5c-abb0afa61f63/Upnp/resource/, clientEndpoint=192.168.178.74:52790

[simoncn]

(18-09-2015 22:40)tarnkappe Wrote:  The first track that was played fine was "01 - Colonel Abrams - Trapped [Dance Version].flac". The second track that was interrupted was "02 - Shirley Lites - Heat You Up (Melt You Down).flac".

Your analysis of the log is correct. For the second track, MinimServer started streaming 109667924 bytes to the renderer at 20:54:26 and the renderer closed the connection at 20:54:48. I don't know why the renderer closed the connection.

[tarnkappe]

Ok, thank you.

[tarnkappe]

One more question. Does "connection closed by client" mean that the client disconnected actively and intentionally? Or can it also be a network problem that a router on the way had a hiccup?

[simoncn]

(19-09-2015 10:03)tarnkappe Wrote:  One more question. Does "connection closed by client" mean that the client disconnected actively and intentionally? Or can it also be a network problem that a router on the way had a hiccup?

I don't know whether a router or network problem could cause this message. I could pull out an Ethernet cable while streaming is in progress to see what happens. This will need to wait a day or two because I'm away from home at the moment.

[tarnkappe]

Oh. This is an idea that I can try myself

[simoncn]

(19-09-2015 21:15)simoncn Wrote:  I don't know whether a router or network problem could cause this message. I could pull out an Ethernet cable while streaming is in progress to see what happens. This will need to wait a day or two because I'm away from home at the moment.

I tried this test and the log message produced was:

HTTPConnection: end of input stream data

This confirms that a network problem is unlikely to cause the log message that you saw.

[tarnkappe]

Thank you very much for testing this! It is good to know, though it gives me a somehow bad feeling, why the uniti decided to hang up. I hope it does not get used to it.