PDA

View Full Version : Server hangs between tracks



Colin Burn-Murdoch
2004-03-10, 16:03
> are you audio files stored locally? do the hard drives have any spin-down power
> saving craziness going on?

Yup, local files. No power saving that I know of, it has previously run without any breaks from files on same disk, no changes have been made to disk settings.

> Also, try running /usr/local/slimserver/slimserver.pl --d_source and see what
> that says between tracks. The debug messages are timestamped so that will help
> find the exact events causing the delay.

Well here's what happens:

2004-03-10 22:53:47.9060 Negative position calculated, we are still playing out the previous song.
2004-03-10 22:53:47.9091 realpos -378613 calcuated from bytes received: 4906668 minus bytes offset: 5024715 minus buffer fullness: 260566
2004-03-10 22:53:47.9121 songTime: [0] = (0(realpos) / 4935680(size) * 308.48(duration) * 1(rate)) + 0(time offset of started stream)
2004-03-10 22:53:47.9157 Negative position calculated, we are still playing out the previous song.
2004-03-10 22:53:47.9187 realpos -378613 calcuated from bytes received: 4906668 minus bytes offset: 5024715 minus buffer fullness: 260566
2004-03-10 22:53:47.9216 songTime: [0] = (0(realpos) / 4935680(size) * 308.48(duration) * 1(rate)) + 0(time offset of started stream)
2004-03-10 22:53:48.2697 Reduced chunksize to 0 at end of file (4935680 - 4935680)
2004-03-10 22:53:48.2732 end of file or error on socket, opening next song, (song pos: 4935680(tell says: . 4935680), totalbytes: 4935680)
2004-03-10 22:53:48.2760 opening next song...
2004-03-10 22:53:48.2798 the next song is number 1, was 0
2004-03-10 22:53:48.2835 checking formats for: mp3-aif-squeezebox-00:04:20:05:0a:34
2004-03-10 22:53:48.2862 checking formats for: mp3-wav-squeezebox-00:04:20:05:0a:34
2004-03-10 22:53:48.2889 checking formats for: mp3-mp3-squeezebox-00:04:20:05:0a:34
2004-03-10 22:53:48.2915 Matched mp3-mp3-squeezebox-*
2004-03-10 22:53:48.2960 openSong on: /data/music/Damien_Rice/O/02-Volcano.mp3
2004-03-10 22:53:48.2994 openSong: getting duration 277.1069375, size 4433711, and offset 0 for /data/music/Damien_Rice/O/02-Volcano.mp3
2004-03-10 22:53:48.3034 checking formats for: mp3-aif-squeezebox-00:04:20:05:0a:34
2004-03-10 22:53:48.3062 checking formats for: mp3-wav-squeezebox-00:04:20:05:0a:34
2004-03-10 22:53:48.3089 checking formats for: mp3-mp3-squeezebox-00:04:20:05:0a:34
2004-03-10 22:53:48.3115 Matched mp3-mp3-squeezebox-*
2004-03-10 22:53:48.3146 openSong: this is an mp3 file: /data/music/Damien_Rice/O/02-Volcano.mp3
2004-03-10 22:53:48.3175 file type: mp3 format: mp3
2004-03-10 22:53:48.3203 command: -
2004-03-10 22:53:48.3237 openSong: opening file /data/music/Damien_Rice/O/02-Volcano.mp3
2004-03-10 22:53:48.3269 seeking in 0 into /data/music/Damien_Rice/O/02-Volcano.mp3
2004-03-10 22:53:48.3301 Streaming with format: mp3


At this point, Squeezebox loses contact with server, displays error, then blank screen. Can verify that server is hung, as web interface sits trying to make a connection (not timing out, but not displaying anything).

Then, after exactly 3 minutes (sorry, my 10 - 60 sec estimate was way out) the display comes alive, the web connection loads the page, and the music starts to play.

I tried logging the transition between two different tracks, and the delay was also 3 minutes on the head.....

Log continues....:

2004-03-10 22:56:48.4501 Negative position calculated, we are still playing out the previous song.
2004-03-10 22:56:48.4530 realpos -261438 calcuated from bytes received: 4924188 minus bytes offset: 4924188 minus buffer fullness: 261438
2004-03-10 22:56:48.4559 songTime: [0] = (0(realpos) / 4433711(size) * 277.1069375(duration) * 1(rate)) + 0(time offset of started stream)
2004-03-10 22:56:48.4591 Negative position calculated, we are still playing out the previous song.
2004-03-10 22:56:48.4620 realpos -261438 calcuated from bytes received: 4924188 minus bytes offset: 4924188 minus buffer fullness: 261438
2004-03-10 22:56:48.4648 songTime: [0] = (0(realpos) / 4433711(size) * 277.1069375(duration) * 1(rate)) + 0(time offset of started stream)
2004-03-10 22:56:48.4724 Negative position calculated, we are still playing out the previous song.
2004-03-10 22:56:48.4754 realpos -261438 calcuated from bytes received: 4924188 minus bytes offset: 4924188 minus buffer fullness: 261438
2
<snip>


To me it looks all ok, apart from that 3 minute hang.

Colin.

--
Colin Burn-Murdoch

kdf
2004-03-10, 16:15
Quoting Colin Burn-Murdoch <colin (AT) aranion (DOT) com>:

[snip]
> Then, after exactly 3 minutes (sorry, my 10 - 60 sec estimate was way out)
> the display comes alive, the web connection loads the page, and the music
> starts to play.
>
> I tried logging the transition between two different tracks, and the delay
> was also 3 minutes on the head.....
>
> Log continues....:
>
[snip]
>
> To me it looks all ok, apart from that 3 minute hang.
>
notmal enough not to scream out what's wrong :)

is there any improvement if you do not use the web ui?

-kdf