MinimServer SLOW!

[promao]

Dear Simon,

Yes, I did did stop the music playing before you changed the logging level back to Info.

I may have a clue: Could this abnormal behavior be consistent to a fault in the wifi network? I have an older Airport Extreme on the living room (where system resides) connecting wirelessly to an Apple Time Capsule on a more distant location. Apparently all devices, iPad included (controlling the DS application of Aries) are in fact only connecting to the distant Time Capsule and not to this Airport Extreme, for some reason.

Could this mean that the delay occurs on the transmission the command on the iPad DS application that only reaches the server with that delay? The delay in seconds on the music was much more than 6 seconds.

Sorry if this may seem a silly question...

Many Thanks.

Pedro

(06-01-2015 12:41)simoncn Wrote:  

(06-01-2015 10:30)promao Wrote:  Yes I did, obviously did not work... I warned about the info-exclusion on my side...

Here it goes (I hope).

Thanks for helping.

Pedro

Thanks for this. Here's the relevant section of the log:

Code:

22:15:44.116 Thread-39: HTTPService: accepted incoming connection
22:15:44.116 Thread-39: HTTPService: waiting for incoming connection
22:15:44.117 Thread-38: HTTPService: received request, Socket[addr=/192.168.1.68,port=56211,localport=9790]
22:15:44.117 Thread-38: HTTPService: adding connection org.jminim.lib.HTTPConnection@1752b9e
22:15:44.118 Thread-3614: HTTPConnection: writer thread waiting for request
22:15:44.118 Thread-3615: HTTPConnection: reading HTTP request
22:15:44.119 Thread-3615: GET /minimserver/*/music/John*20Lurie/African*20Swim*20and*20Manny*20*26*20Lo*20-*20Two*20Film*20Scores*20By*20John*20Lurie/01*20Main*20Titles.aif HTTP/1.1
22:15:44.119 Thread-3615: User-Agent: Music Player Daemon 0.18.5, Host: 192.168.1.252:9790, Accept: */*, Icy-Metadata: 1
22:15:44.119 Thread-3615: HTTPConnection: reading HTTP request
22:15:44.119 Thread-3614: HTTPConnection: writer thread processing request
22:15:44.133 Thread-3614: HTTP/1.1 200 OK, Accept-Ranges: bytes, Date: Mon, 05 Jan 2015 22:15:44 GMT, Content-Length: 34576784, Content-Type: audio/x-aiff, Connection: keep-alive, Last-Modified: Sun, 08 Aug 2010 12:29:55 GMT
22:15:44.133 Thread-3614: writing data: total=34576784 from file John Lurie/African Swim and Manny & Lo - Two Film Scores By John Lurie/01 Main Titles.aif
22:15:47.464 Thread-3613: FileResource: reader thread end of data

This shows that MinimServer received a request from the Aries to play the file at 22:15:44.117 and started to send data to the Aries at 22:15:44.133. The Aries closed the connection at 22:15:47.464 and the logging level was changed to Info at 22:15:50.198.

The only thing that is abnormal is the Aries closing the connection at 22:15:47.464. The connection would normally be left open until the track had finished playing. A closed connection normally means that the renderer encountered a problem with the file or the user stopped the music playing.

Did the music start playing before 22:15:50.198 when the logging level was changed? This was only 6 seconds after the request was received, which isn't consistent with a delay of 15 seconds. Also, did you stop the music playing before you changed the logging level to Info?

There is also a separate request from the Aries at 22:15:43.974 for an artwork image for a different track. This transmission was completed at 22:15:47.900. There shouldn't be any problem with two resources being sent at the same time unless the renderer or the network can't handle this for some reason.