T HTTP/1.1 /status_header.html?player=00%3A04%3A20%3A10%3A01%3A0c HTTP parameter player = 00:04:20:10:01:0c processURL Clients: 201.201.201.203:34539 Generating response for (htm, text/html) status_header.html generating from include.html type: fill found path: D:\Program Files\SlimServer\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 Reading firmware version file: D:\Program Files\SlimServer\server\Firmware\transporter.version transporter firmware is up-to-date, v. 29 songTime: rate:1 -songtime:0 -startStream:0 songTime: rate:1 -songtime:0 -startStream:0 SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' SELECT me.id, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.tracknum, me.timestamp, me.filesize, me.disc, me.thumb, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.moodlogic_id, me.moodlogic_mixable, me.musicmagic_mixable, me.musicbrainz_id, me.playcount, me.lastplayed, me.lossless, me.lyrics, me.rating, me.replay_gain, me.replay_peak FROM tracks me WHERE ( ( me.id = ? ) ): '87' _checkValidity: Checking to see if file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac has changed. _hasChanged: Checking for [D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac] - size & timestamp. SELECT me.id, me.track, me.value FROM comments me WHERE ( me.track = ? ): '87' Retrieving artwork (thumb) for: file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac readCoverArtTags: Looking for a cover art image in the tags of: [D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac] Looking for image files in D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10 generating from status_header.html type: fill found path: D:\Program Files\SlimServer\server\HTML\Default\status_header.html idleStreams: select_time: 0, checkTimers: 1 SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' idleStreams: select_time: 0, checkTimers: 1 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [1] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5065bac) on connection = Keep-Alive select_time: 0.0273759365081787 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 285 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.0261449813842773 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 19293 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.022752046585083 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Removing write select_time: 0.0215370655059814 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00753998756408691 late. screenSaver idle display 4076.4934990406(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999181985855103 sec select_time: 0.00622105598449707 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00788688659667969 late. Checking if 00:04:20:10:01:0c is still alive [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99157309532166 sec select_time: 0.630092859268188 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5065bac)) for GET HTTP/1.1 /playlist.html?player=00%3A04%3A20%3A10%3A01%3A0c&d=1174496082000 HTTP parameter player = 00:04:20:10:01:0c HTTP parameter d = 1174496082000 processURL Clients: 201.201.201.203:34539 Generating response for (htm, text/html) playlist.html generating from include.html type: fill found path: D:\Program Files\SlimServer\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 Reading firmware version file: D:\Program Files\SlimServer\server\Firmware\transporter.version transporter firmware is up-to-date, v. 29 currentPlaylistChangeTime : Wed Mar 21 08:54:41 2007 currentPlaylistRender : Wed Mar 21 08:54:31 2007 currentPlaylistRenderSkin : currentPlaylistRenderStart: 0 skinOverride: start: 0 SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' idleStreams: select_time: 0, checkTimers: 1 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMd bytes_rec_H 0 bytes_rec_L 506992 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 506992 jiffies: 169993695 output size: 3528000 output fullness: 3487488 elapsed seconds: 0 00:04:20:10:01:0c: Decoder underrun while this mode: playout-play the next song is number 0, was 0 **skipahead: opening next song opening next song... the next song is number 0, was 0 undermax = 1, type = flc, transporter = 00:04:20:10:01:0c checking formats for: flc-wma-transporter-00:04:20:10:01:0c checking formats for: flc-wma-*-00:04:20:10:01:0c checking formats for: flc-wma-transporter-* checking formats for: flc-wma-squeezebox2-* checking formats for: flc-wma-*-* checking formats for: flc-ogg-transporter-00:04:20:10:01:0c checking formats for: flc-ogg-*-00:04:20:10:01:0c checking formats for: flc-ogg-transporter-* checking formats for: flc-ogg-squeezebox2-* checking formats for: flc-ogg-*-* checking formats for: flc-flc-transporter-00:04:20:10:01:0c checking formats for: flc-flc-*-00:04:20:10:01:0c checking formats for: flc-flc-transporter-* checking formats for: flc-flc-squeezebox2-* checking formats for: flc-flc-*-* Checking to see if flc-flc-*-* is enabled enabled Found command: - Matched Format: flc Type: flc Command: - opening next song (old format: flc, new: flc) current playmode: playout-play Adding song index 0 to song queue Song queue is now 0,0 **skipahead: restarting 00:04:20:10:01:0c: Switching to mode play from playout-play Backtrace: frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 742) frame 1: Slim::Player::Source::skipahead (/PerlApp/Slim/Player/Source.pm line 591) frame 2: Slim::Player::Source::decoderUnderrun (/PerlApp/Slim/Networking/Slimproto.pm line 658) frame 3: Slim::Networking::Slimproto::_stat_handler (/PerlApp/Slim/Networking/Slimproto.pm line 387) frame 4: Slim::Networking::Slimproto::client_readable (/PerlApp/Slim/Networking/Select.pm line 238) frame 5: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 6: Slim::Networking::Select::select (slimserver.pl line 521) frame 7: main::idleStreams (/PerlApp/Slim/Web/Pages/Playlist.pm line 193) frame 8: Slim::Web::Pages::Playlist::playlist (/PerlApp/Slim/Web/HTTP.pm line 828) frame 9: Slim::Web::HTTP::generateHTTPResponse (/PerlApp/Slim/Web/HTTP.pm line 694) frame 10: Slim::Web::HTTP::processURL (/PerlApp/Slim/Web/HTTP.pm line 540) frame 11: Slim::Web::HTTP::processHTTP (/PerlApp/Slim/Networking/Select.pm line 238) frame 12: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 13: Slim::Networking::Select::select (slimserver.pl line 493) frame 14: main::idle (slimserver.pl line 35) frame 15: PerlSvc::Startup (perlsvc.pl line 1482) frame 16: PerlSvc::_startup (slimserver.pl line 0) frame 17: (eval) (slimserver.pl line 0) _checkValidity: Checking to see if file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac has changed. _hasChanged: Checking for [D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac] - size & timestamp. openSong on: file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac openSong: duration: [10] size: [506992] endian [] offset: [0] for file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac undermax = 1, type = flc, transporter = 00:04:20:10:01:0c checking formats for: flc-wma-transporter-00:04:20:10:01:0c checking formats for: flc-wma-*-00:04:20:10:01:0c checking formats for: flc-wma-transporter-* checking formats for: flc-wma-squeezebox2-* checking formats for: flc-wma-*-* checking formats for: flc-ogg-transporter-00:04:20:10:01:0c checking formats for: flc-ogg-*-00:04:20:10:01:0c checking formats for: flc-ogg-transporter-* checking formats for: flc-ogg-squeezebox2-* checking formats for: flc-ogg-*-* checking formats for: flc-flc-transporter-00:04:20:10:01:0c checking formats for: flc-flc-*-00:04:20:10:01:0c checking formats for: flc-flc-transporter-* checking formats for: flc-flc-squeezebox2-* checking formats for: flc-flc-*-* Checking to see if flc-flc-*-* is enabled enabled Found command: - Matched Format: flc Type: flc Command: - openSong: this is an flc file: file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac file type: flc format: flc inrate: 398.95 maxRate: 0 command: - openSong: opening file D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac openSong: seeking in 0 into D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac openSong: Streaming with format: flc UPDATE tracks SET lastplayed = ?, playcount = ? WHERE ( id = ? ): '1174496082', '45', '87' 00:04:20:10:01:0c New play mode: play sending squeezebox frame: audg, length: 18 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 24 bytes Transporter::play - setting DigitalInput to 0 for [file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac] sending squeezebox frame: audp, length: 1 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 7 bytes *************stream called: s paused: 0 format: flc url: file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac Backtrace: frame 0: Slim::Player::Squeezebox::stream (/PerlApp/Slim/Player/Squeezebox.pm line 177) frame 1: Slim::Player::Squeezebox::play (/PerlApp/Slim/Player/Transporter.pm line 113) frame 2: Slim::Player::Transporter::play (/PerlApp/Slim/Player/Source.pm line 493) frame 3: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 742) frame 4: Slim::Player::Source::skipahead (/PerlApp/Slim/Player/Source.pm line 591) frame 5: Slim::Player::Source::decoderUnderrun (/PerlApp/Slim/Networking/Slimproto.pm line 658) frame 6: Slim::Networking::Slimproto::_stat_handler (/PerlApp/Slim/Networking/Slimproto.pm line 387) frame 7: Slim::Networking::Slimproto::client_readable (/PerlApp/Slim/Networking/Select.pm line 238) frame 8: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 9: Slim::Networking::Select::select (slimserver.pl line 521) frame 10: main::idleStreams (/PerlApp/Slim/Web/Pages/Playlist.pm line 193) frame 11: Slim::Web::Pages::Playlist::playlist (/PerlApp/Slim/Web/HTTP.pm line 828) frame 12: Slim::Web::HTTP::generateHTTPResponse (/PerlApp/Slim/Web/HTTP.pm line 694) frame 13: Slim::Web::HTTP::processURL (/PerlApp/Slim/Web/HTTP.pm line 540) frame 14: Slim::Web::HTTP::processHTTP (/PerlApp/Slim/Networking/Select.pm line 238) frame 15: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 16: Slim::Networking::Select::select (slimserver.pl line 493) frame 17: main::idle (slimserver.pl line 35) frame 18: PerlSvc::Startup (perlsvc.pl line 1482) frame 19: PerlSvc::_startup (slimserver.pl line 0) frame 20: (eval) (slimserver.pl line 0) SELECT me.id, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.tracknum, me.timestamp, me.filesize, me.disc, me.thumb, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.moodlogic_id, me.moodlogic_mixable, me.musicmagic_mixable, me.musicbrainz_id, me.playcount, me.lastplayed, me.lossless, me.lyrics, me.rating, me.replay_gain, me.replay_peak FROM tracks me WHERE ( url = ? ): 'file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac' _checkValidity: Checking to see if file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac has changed. _hasChanged: Checking for [D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac] - size & timestamp. starting with decoder with format: f autostart: 1 threshold: 255 samplesize: ? samplerate: ? endian: ? channels: ? flags: 0 sending strm frame of length: 76 request string: GET /stream.mp3?player=00:04:20:10:01:0c HTTP/1.0 sending squeezebox frame: strm, length: 76 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 82 bytes sending squeezebox frame: audg, length: 18 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 24 bytes Playlist: Jumping to song index: 0 new playlistindex: 0 00:04:20:10:01:0c: Current playmode: play new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: audg bytes_rec_H 0 bytes_rec_L 506992 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 506992 jiffies: 169993769 output size: 3528000 output fullness: 3458944 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: audp bytes_rec_H 0 bytes_rec_L 506992 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 506992 jiffies: 169993771 output size: 3528000 output fullness: 3458176 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMf bytes_rec_H 0 bytes_rec_L 506992 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 506992 jiffies: 169993781 output size: 3528000 output fullness: 3454464 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMc bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 169993783 output size: 3528000 output fullness: 3453824 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: strm bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 169993784 output size: 3528000 output fullness: 3453312 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: audg bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 169993786 output size: 3528000 output fullness: 3452672 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMe bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 169993788 output size: 3528000 output fullness: 3451776 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. End playlist build. generating from playlist.html type: fill found path: D:\Program Files\SlimServer\server\HTML\Default\playlist.html idleStreams: select_time: 0, checkTimers: 1 Caching playlist as html. [norm] Killed 1 timer(s) for Slim::Player::Transporter=ARRAY(0x4851bf0) / Slim::Web::Pages::Playlist::flushCachedHTML [norm] set Slim::Web::Pages::Playlist::flushCachedHTML, in 299.832989931107 sec Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [2] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5065bac) on connection = Keep-Alive sending new knob position- listIndex: 0 with knobPos: 0 of 1 sync: 96 flags: 0 sending squeezebox frame: knob, length: 14 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 20 bytes modifyPlaylistCallback: savecurrsong is 1 select_time: 0 Select: [HTTP::Daemon=GLOB(0x48517e8)] read, calling Slim::Web::HTTP::acceptHTTP Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Adding read -> Slim::Web::HTTP::processHTTP Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Adding error -> Slim::Web::HTTP::closeStreamingSocket Accepted connection 2 from 201.201.201.203 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 284 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.462857961654663 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 201.201.201.203 (HTTP::Daemon::ClientConn=GLOB(0x309ef84)) for GET HTTP/1.0 /stream.mp3?player=00:04:20:10:01:0c HTTP parameter player = 00:04:20:10:01:0c processURL Clients: 201.201.201.203:34539 Generating response for (mp3, audio/mpeg) stream.mp3 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Removing read Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Adding write -> Slim::Web::HTTP::sendStreamingResponse End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x309ef84) on connection = close Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 6811 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.450932025909424 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Streamed 100 to 201.201.201.203 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Removing write select_time: 0.448999881744385 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMh bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 169993848 output size: 3528000 output fullness: 3428736 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: RESP new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 100, inbuflen: 0 attempting to read 100 bytes Got 100 bytes from client, 0 remaining Squeezebox got HTTP response: HTTP/1.0 200 OK Server: SlimServer (6.5.2 - 11645) Connection: close Content-Type: audio/mpeg processing headers for direct streaming: HTTP/1.0 200 OK Server: SlimServer (6.5.2 - 11645) Connection: close Content-Type: audio/mpeg new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.438638925552368 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.435947895050049 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.428266048431396 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.421121835708618 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.414484024047852 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.407882928848267 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.402346849441528 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.393738985061646 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.387394905090332 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.381916046142578 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.374508857727051 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.36687183380127 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.358829021453857 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.349206924438477 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Read 32768 bytes from source read a chunk of 32768 length (audio: 32768 bytes) Streamed 32768 to 201.201.201.203 select_time: 0.338667869567871 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Reduced chunksize to 15472 at end of file (506992 - 491520) Read 15472 bytes from source read a chunk of 15472 length (audio: 15472 bytes) Streamed 15472 to 201.201.201.203 select_time: 0.328085899353027 Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] write, calling Slim::Web::HTTP::sendStreamingResponse sendstreaming response begun... Reduced chunksize to 0 at end of file (506992 - 506992) end of file or error on socket, opening next song, (song pos: 506992(tell says: . 506992), totalbytes: 506992) opening next song... the next song is number 0, was 0 undermax = 1, type = flc, transporter = 00:04:20:10:01:0c checking formats for: flc-wma-transporter-00:04:20:10:01:0c checking formats for: flc-wma-*-00:04:20:10:01:0c checking formats for: flc-wma-transporter-* checking formats for: flc-wma-squeezebox2-* checking formats for: flc-wma-*-* checking formats for: flc-ogg-transporter-00:04:20:10:01:0c checking formats for: flc-ogg-*-00:04:20:10:01:0c checking formats for: flc-ogg-transporter-* checking formats for: flc-ogg-squeezebox2-* checking formats for: flc-ogg-*-* checking formats for: flc-flc-transporter-00:04:20:10:01:0c checking formats for: flc-flc-*-00:04:20:10:01:0c checking formats for: flc-flc-transporter-* checking formats for: flc-flc-squeezebox2-* checking formats for: flc-flc-*-* Checking to see if flc-flc-*-* is enabled enabled Found command: - Matched Format: flc Type: flc Command: - playing out before starting next song. (old format: flc, new: flc) 00:04:20:10:01:0c: Switching to mode playout-play from play Backtrace: frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 1046) frame 1: Slim::Player::Source::gotoNext (/PerlApp/Slim/Player/Source.pm line 1970) frame 2: Slim::Player::Source::readNextChunk (/PerlApp/Slim/Player/Source.pm line 773) frame 3: Slim::Player::Source::nextChunk (/PerlApp/Slim/Web/HTTP.pm line 1709) frame 4: Slim::Web::HTTP::sendStreamingResponse (/PerlApp/Slim/Networking/Select.pm line 238) frame 5: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 6: Slim::Networking::Select::select (slimserver.pl line 493) frame 7: main::idle (slimserver.pl line 35) frame 8: PerlSvc::Startup (perlsvc.pl line 1482) frame 9: PerlSvc::_startup (slimserver.pl line 0) frame 10: (eval) (slimserver.pl line 0) 00:04:20:10:01:0c New play mode: playout-play *************stream called: u paused: format: url: Backtrace: frame 0: Slim::Player::Squeezebox::stream (/PerlApp/Slim/Player/Squeezebox.pm line 195) frame 1: Slim::Player::Squeezebox::resume (/PerlApp/Slim/Player/Source.pm line 449) frame 2: Slim::Player::Source::playmode (/PerlApp/Slim/Player/Source.pm line 1046) frame 3: Slim::Player::Source::gotoNext (/PerlApp/Slim/Player/Source.pm line 1970) frame 4: Slim::Player::Source::readNextChunk (/PerlApp/Slim/Player/Source.pm line 773) frame 5: Slim::Player::Source::nextChunk (/PerlApp/Slim/Web/HTTP.pm line 1709) frame 6: Slim::Web::HTTP::sendStreamingResponse (/PerlApp/Slim/Networking/Select.pm line 238) frame 7: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 8: Slim::Networking::Select::select (slimserver.pl line 493) frame 9: main::idle (slimserver.pl line 35) frame 10: PerlSvc::Startup (perlsvc.pl line 1482) frame 11: PerlSvc::_startup (slimserver.pl line 0) frame 12: (eval) (slimserver.pl line 0) starting with decoder with format: m autostart: 1 threshold: 255 samplesize: ? samplerate: ? endian: ? channels: ? flags: 0 sending strm frame of length: 24 request string: sending squeezebox frame: strm, length: 24 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 30 bytes Playlist: Jumping to song index: 0 new playlistindex: 0 00:04:20:10:01:0c: Current playmode: playout-play No pending chunks - we're dropping the streaming connection Closing streaming socket. Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Removing read Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Removing write Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Removing error 00:04:20:10:01:0c: Can't opennext, returning no chunk. Nothing to stream, let's wait for 0.05 seconds... Select: [HTTP::Daemon::ClientConn=GLOB(0x309ef84)] Removing write Got nothing for streaming data to select_time: 0.314584016799927 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMr bytes_rec_H 0 bytes_rec_L 506992 fullness: 481392 (15%) bufferSize 3145728 fullness 481392 bytes_received 506992 jiffies: 169993980 output size: 3528000 output fullness: 3509120 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: strm bytes_rec_H 0 bytes_rec_L 506992 fullness: 481392 (15%) bufferSize 3145728 fullness 481392 bytes_received 506992 jiffies: 169993981 output size: 3528000 output fullness: 3508736 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: DSCO new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 1, inbuflen: 0 attempting to read 1 bytes Got 1 bytes from client, 0 remaining Squeezebox got disconnection on the data channel why: Connection closed normally new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.304815053939819 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 472688 (15%) bufferSize 3145728 fullness 472688 bytes_received 506992 jiffies: 169994181 output size: 3528000 output fullness: 3497472 elapsed seconds: 1 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.111638069152832 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0174510478973389 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.982077836990356 sec songTime: rate:1 -songtime:1 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.328728914260864 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00731611251831055 late. screenSaver idle display 4077.50116801262(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999176979064941 sec select_time: 0.637346029281616 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.43558406829834 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.290142059326172 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 421488 (13%) bufferSize 3145728 fullness 421488 bytes_received 506992 jiffies: 169995181 output size: 3528000 output fullness: 3506688 elapsed seconds: 2 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.101887941360474 select_time: 0.000421047210693359 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.015172004699707 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.984396934509277 sec songTime: rate:1 -songtime:2 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.338732004165649 select_time: 0.000211954116821289 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152740478515625 late. screenSaver idle display 4078.51675605774(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999182939529419 sec select_time: 0.621763944625854 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 370289 (11%) bufferSize 3145728 fullness 370289 bytes_received 506992 jiffies: 169996181 output size: 3528000 output fullness: 3515904 elapsed seconds: 3 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.107460021972656 select_time: 0.00593805313110352 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0100171566009521 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989547967910767 sec songTime: rate:1 -songtime:3 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.359471082687378 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00754404067993164 late. screenSaver idle display 4079.52465200424(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999176979064941 sec select_time: 0.613864898681641 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 323699 (10%) bufferSize 3145728 fullness 323699 bytes_received 506992 jiffies: 169997181 output size: 3528000 output fullness: 3492352 elapsed seconds: 4 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.10745906829834 select_time: 0.00587987899780273 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00970196723937988 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.98983097076416 sec songTime: rate:1 -songtime:4 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.367113828659058 select_time: 0.000234842300415039 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0230860710144043 late. screenSaver idle display 4080.54809212685(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99915599822998 sec select_time: 0.590401887893677 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.434668064117432 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.29381799697876 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 272499 (8%) bufferSize 3145728 fullness 272499 bytes_received 506992 jiffies: 169998181 output size: 3528000 output fullness: 3501568 elapsed seconds: 5 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.0996119976043701 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997704982757568 sec songTime: rate:1 -songtime:5 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.35099196434021 [norm] firing Slim::Networking::Slimproto::check_all_clients 2.19345092773438e-005 late. Checking if 00:04:20:10:01:0c is still alive [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99943590164185 sec select_time: 0.0463881492614746 select_time: 0.000256061553955078 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.015265941619873 late. screenSaver idle display 4081.5637140274(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999186038970947 sec select_time: 0.574812889099121 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 222323 (7%) bufferSize 3145728 fullness 222323 bytes_received 506992 jiffies: 169999181 output size: 3528000 output fullness: 3510784 elapsed seconds: 6 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.10745096206665 select_time: 0.00592494010925293 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0100510120391846 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989488840103149 sec songTime: rate:1 -songtime:6 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.406385898590088 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152740478515625 late. screenSaver idle display 4082.57934999466(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999169826507568 sec select_time: 0.559157848358154 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 171123 (5%) bufferSize 3145728 fullness 171123 bytes_received 506992 jiffies: 170000181 output size: 3528000 output fullness: 3487232 elapsed seconds: 7 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.0993330478668213 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997698068618774 sec songTime: rate:1 -songtime:7 -startStream:0 sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes select_time: 0.430210828781128 select_time: 0.000293970108032227 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0151779651641846 late. screenSaver idle display 4083.59483218193(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999173164367676 sec select_time: 0.543681859970093 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.45120906829834 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.308840990066528 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMt bytes_rec_H 0 bytes_rec_L 506992 fullness: 124021 (3%) bufferSize 3145728 fullness 124021 bytes_received 506992 jiffies: 170001181 output size: 3528000 output fullness: 3496448 elapsed seconds: 8 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.114670038223267 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5065bac)) for GET HTTP/1.1 /status_header.html?p0=stop&player=00%3A04%3A20%3A10%3A01%3A0c HTTP parameter p0 = stop HTTP parameter player = 00:04:20:10:01:0c processURL Clients: 201.201.201.203:34540 00:04:20:10:01:0c: Switching to mode stop from playout-play Backtrace: frame 0: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Commands.pm line 418) frame 1: Slim::Control::Commands::playcontrolCommand (/PerlApp/Slim/Control/Request.pm line 1483) frame 2: (eval) (/PerlApp/Slim/Control/Request.pm line 1483) frame 3: Slim::Control::Request::execute (/PerlApp/Slim/Control/Request.pm line 772) frame 4: Slim::Control::Request::executeRequest (/PerlApp/Slim/Web/HTTP.pm line 690) frame 5: Slim::Web::HTTP::processURL (/PerlApp/Slim/Web/HTTP.pm line 540) frame 6: Slim::Web::HTTP::processHTTP (/PerlApp/Slim/Networking/Select.pm line 238) frame 7: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 8: Slim::Networking::Select::select (slimserver.pl line 493) frame 9: main::idle (slimserver.pl line 35) frame 10: PerlSvc::Startup (perlsvc.pl line 1482) frame 11: PerlSvc::_startup (slimserver.pl line 0) frame 12: (eval) (slimserver.pl line 0) 00:04:20:10:01:0c New play mode: stop Stopping and clearing out old chunks for client 00:04:20:10:01:0c *************stream called: q paused: format: url: Backtrace: frame 0: Slim::Player::Squeezebox::stream (/PerlApp/Slim/Player/Squeezebox.pm line 218) frame 1: Slim::Player::Squeezebox::stop (/PerlApp/Slim/Player/Squeezebox2.pm line 233) frame 2: Slim::Player::Squeezebox2::stop (/PerlApp/Slim/Player/Source.pm line 464) frame 3: Slim::Player::Source::playmode (/PerlApp/Slim/Control/Commands.pm line 418) frame 4: Slim::Control::Commands::playcontrolCommand (/PerlApp/Slim/Control/Request.pm line 1483) frame 5: (eval) (/PerlApp/Slim/Control/Request.pm line 1483) frame 6: Slim::Control::Request::execute (/PerlApp/Slim/Control/Request.pm line 772) frame 7: Slim::Control::Request::executeRequest (/PerlApp/Slim/Web/HTTP.pm line 690) frame 8: Slim::Web::HTTP::processURL (/PerlApp/Slim/Web/HTTP.pm line 540) frame 9: Slim::Web::HTTP::processHTTP (/PerlApp/Slim/Networking/Select.pm line 238) frame 10: (eval) (/PerlApp/Slim/Networking/Select.pm line 238) frame 11: Slim::Networking::Select::select (slimserver.pl line 493) frame 12: main::idle (slimserver.pl line 35) frame 13: PerlSvc::Startup (perlsvc.pl line 1482) frame 14: PerlSvc::_startup (slimserver.pl line 0) frame 15: (eval) (slimserver.pl line 0) starting with decoder with format: m autostart: 0 threshold: 255 samplesize: ? samplerate: ? endian: ? channels: ? flags: 0 sending strm frame of length: 24 request string: sending squeezebox frame: strm, length: 24 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 30 bytes Resetting song queue Song queue is now 0 newSongPlaylistCallback() writeCurTrackForM3U() Playlist: Jumping to song index: 0 new playlistindex: 0 00:04:20:10:01:0c: Current playmode: stop sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 1290 bytes Request: Calling callback function Generating response for (htm, text/html) status_header.html generating from include.html type: fill found path: D:\Program Files\SlimServer\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: STMf bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170001293 output size: 3528000 output fullness: 3519104 elapsed seconds: 8 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: strm bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170001294 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0129270553588867 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.986670970916748 sec Reading firmware version file: D:\Program Files\SlimServer\server\Firmware\transporter.version transporter firmware is up-to-date, v. 29 songTime: rate:1 -songtime:0 -startStream:0 songTime: rate:1 -songtime:0 -startStream:0 SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' SELECT me.id, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.tracknum, me.timestamp, me.filesize, me.disc, me.thumb, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.moodlogic_id, me.moodlogic_mixable, me.musicmagic_mixable, me.musicbrainz_id, me.playcount, me.lastplayed, me.lossless, me.lyrics, me.rating, me.replay_gain, me.replay_peak FROM tracks me WHERE ( ( me.id = ? ) ): '87' _checkValidity: Checking to see if file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac has changed. _hasChanged: Checking for [D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac] - size & timestamp. SELECT me.id, me.track, me.value FROM comments me WHERE ( me.track = ? ): '87' Retrieving artwork (thumb) for: file:///D:/Documents%20and%20Settings/TestPC04Adm/My%20Documents/My%20Music/Music/flac_24_48000_2_440_10/flac_24_48000_2_440_10.flac readCoverArtTags: Looking for a cover art image in the tags of: [D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10\flac_24_48000_2_440_10.flac] Looking for image files in D:\Documents and Settings\TestPC04Adm\My Documents\My Music\Music\flac_24_48000_2_440_10 generating from status_header.html type: fill found path: D:\Program Files\SlimServer\server\HTML\Default\status_header.html idleStreams: select_time: 0, checkTimers: 1 SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' idleStreams: select_time: 0, checkTimers: 1 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Adding write -> Slim::Web::HTTP::sendResponse Request: Command [00:04:20:10:01:0c->stop] cb+ (Done) End request: keepAlive: [3] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5065bac) on connection = Keep-Alive select_time: 0 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 285 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.315165042877197 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 19289 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.312727212905884 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Removing write select_time: 0.311630010604858 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5065bac)) for GET HTTP/1.1 /playlist.html?player=00%3A04%3A20%3A10%3A01%3A0c&d=1174496089828 HTTP parameter player = 00:04:20:10:01:0c HTTP parameter d = 1174496089828 processURL Clients: 201.201.201.203:34540 Generating response for (htm, text/html) playlist.html generating from include.html type: fill found path: D:\Program Files\SlimServer\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 Reading firmware version file: D:\Program Files\SlimServer\server\Firmware\transporter.version transporter firmware is up-to-date, v. 29 currentPlaylistChangeTime : Wed Mar 21 08:54:42 2007 currentPlaylistRender : Wed Mar 21 08:54:42 2007 currentPlaylistRenderSkin : currentPlaylistRenderStart: 0 skinOverride: start: 0 SELECT contributor.id, contributor.name, contributor.namesort, contributor.moodlogic_id, contributor.moodlogic_mixable, contributor.musicmagic_mixable, contributor.namesearch, contributor.musicbrainz_id FROM contributor_track me JOIN contributors contributor ON ( contributor.id = me.contributor ) WHERE ( ( ( role IN ( ? ) ) AND ( me.track = ? ) ) ) GROUP BY contributor.id ORDER BY role desc: '1', '87' idleStreams: select_time: 0, checkTimers: 1 End playlist build. generating from playlist.html type: fill found path: D:\Program Files\SlimServer\server\HTML\Default\playlist.html idleStreams: select_time: 0, checkTimers: 1 Caching playlist as html. [norm] Killed 1 timer(s) for Slim::Player::Transporter=ARRAY(0x4851bf0) / Slim::Web::Pages::Playlist::flushCachedHTML [norm] set Slim::Web::Pages::Playlist::flushCachedHTML, in 299.084670066834 sec Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [4] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5065bac) on connection = Keep-Alive select_time: 0.175617218017578 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 284 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.171137094497681 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 6811 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.168980121612549 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Removing write select_time: 0.165203094482422 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00373101234436035 late. screenSaver idle display 4084.59892511368(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999427080154419 sec select_time: 0.53985595703125 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0174510478973389 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.982074975967407 sec select_time: 0.433982133865356 select_time: 0.00427913665771484 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0112209320068359 late. screenSaver idle display 4085.61049699783(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999411821365356 sec select_time: 0.52827000617981 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997704029083252 sec select_time: 0.353188991546631 select_time: 0 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000403881072998047 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99863004684448 sec select_time: 0.107952833175659 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170003648 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.103410959243774 select_time: 0.000129938125610352 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153000354766846 late. screenSaver idle display 4086.62610006332(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999433040618896 sec select_time: 0.512694835662842 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.435560941696167 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.293652057647705 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00082707405090332 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998715877532959 sec select_time: 0.479443073272705 select_time: 0.000147104263305664 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153319835662842 late. screenSaver idle display 4087.64173913002(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999433040618896 sec select_time: 0.497051000595093 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997706890106201 sec select_time: 0.494079113006592 select_time: 0.000159025192260742 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153100490570068 late. screenSaver idle display 4088.65735816956(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999435186386108 sec select_time: 0.481431007385254 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00180697441101074 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998152017593384 sec select_time: 0.509711980819702 select_time: 0.000151157379150391 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153188705444336 late. screenSaver idle display 4089.67299199104(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999430894851685 sec select_time: 0.465796947479248 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.409288883209229 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.29283595085144 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00181102752685547 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997714996337891 sec select_time: 0.525343894958496 select_time: 0.000142812728881836 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153710842132568 late. screenSaver idle display 4090.68868207932(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999376058578491 sec select_time: 0.450033903121948 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00180411338806152 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997725963592529 sec select_time: 0.353215932846069 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99896192550659 sec select_time: 0.186465978622437 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170008648 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.18190598487854 select_time: 0.000133991241455078 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153191089630127 late. screenSaver idle display 4091.70437598228(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999423980712891 sec select_time: 0.434401035308838 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997705936431885 sec select_time: 0.556707859039307 select_time: 0.000295877456665039 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0112290382385254 late. screenSaver idle display 4092.71592307091(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99941611289978 sec select_time: 0.422857999801636 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.293781995773315 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00186896324157715 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997674942016602 sec select_time: 0.568222999572754 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00369000434875488 late. screenSaver idle display 4093.71996116638(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999425172805786 sec select_time: 0.418810844421387 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00180196762084961 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997731924057007 sec select_time: 0.572323083877563 select_time: 0.000255107879638672 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152599811553955 late. screenSaver idle display 4094.73553609848(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999427080154419 sec select_time: 0.403249979019165 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00180506706237793 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997732877731323 sec select_time: 0.587876081466675 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5065bac)) for GET HTTP/1.1 /log.txt processURL Clients: 201.201.201.203:34540 Generating response for (txt, text/plain) log.txt generating from include.html type: fill found path: D:\Program Files\SlimServer\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [5] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5065bac) on connection = Keep-Alive select_time: 0.489447116851807 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 192 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.488299131393433 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse Sent 102400 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.485687971115112 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] Removing write select_time: 0.480211973190308 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.0324809551239014 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.015326976776123 late. screenSaver idle display 4095.75119304657(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99943208694458 sec select_time: 0.0477759838104248 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.0135159492492676 late. [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999859333038 sec select_time: 0 [norm] firing Plugins::Rescan::checkScanTimer 0.0136768817901611 late. [norm] set Plugins::Rescan::checkScanTimer, in 59.9999871253967 sec select_time: 0.324877977371216 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.291846990585327 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00184297561645508 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997676849365234 sec select_time: 0.353173971176147 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 5 sec select_time: 0.250051975250244 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170013650 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.245468854904175 select_time: 0.0032188892364502 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0123019218444824 late. screenSaver idle display 4096.76380801201(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999413013458252 sec select_time: 0.374963998794556 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99770188331604 sec select_time: 0.616111040115356 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00268006324768066 late. screenSaver idle display 4097.76684117317(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999426126480103 sec select_time: 0.371938943862915 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182414054870605 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997709035873413 sec select_time: 0.619163990020752 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.0627641677856445 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00394296646118164 late. screenSaver idle display 4098.77114009857(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999429941177368 sec select_time: 0.367642879486084 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.304898977279663 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00615596771240234 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99337100982666 sec select_time: 0.61884593963623 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0109729766845703 late. screenSaver idle display 4099.78247308731(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999401092529297 sec select_time: 0.356282949447632 select_time: 1.40666961669922e-005 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.015610933303833 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.983926057815552 sec select_time: 0.620619058609009 select_time: 0.000262975692749023 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.015225887298584 late. screenSaver idle display 4100.79800796509(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999123811721802 sec select_time: 0.340419054031372 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00181293487548828 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997720956802368 sec select_time: 0.353214979171753 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0 late. Prevent Standby plugin: client if in playmode stop Prevent Standby plugin: starting timer [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9970729351044 sec select_time: 0 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00350308418273926 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99551796913147 sec select_time: 0.29235577583313 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170018651 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.287761926651001 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.0817079544067383 select_time: 0.000178813934326172 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0156371593475342 late. screenSaver idle display 4101.81413817406(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99924111366272 sec select_time: 0.324451923370361 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.292470932006836 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997694969177246 sec select_time: 0.666488170623779 select_time: 0.000681161880493164 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0148279666900635 late. screenSaver idle display 4102.82929396629(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999421834945679 sec select_time: 0.309483051300049 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182795524597168 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997700929641724 sec select_time: 0.681603908538818 select_time: 0.000211954116821289 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153369903564453 late. screenSaver idle display 4103.84495615959(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999433040618896 sec select_time: 0.293834924697876 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182414054870605 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997706890106201 sec select_time: 0.697309017181396 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.140878200531006 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.0104939937591553 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00394892692565918 late. screenSaver idle display 4104.84924197197(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999428987503052 sec select_time: 0.28954291343689 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00618195533752441 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.993350028991699 sec select_time: 0.697057962417603 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0109961032867432 late. screenSaver idle display 4105.86059617996(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999428987503052 sec select_time: 0.278185844421387 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00179505348205566 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99775505065918 sec select_time: 0.353228092193604 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99893498420715 sec select_time: 0.358355045318604 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170023648 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.353862047195435 select_time: 0.000268220901489258 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152428150177002 late. screenSaver idle display 4106.87616014481(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999427080154419 sec select_time: 0.262622833251953 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997714996337891 sec select_time: 0.728506088256836 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.172083139419556 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.0412461757659912 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00399088859558105 late. screenSaver idle display 4107.88047909737(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999424934387207 sec select_time: 0.258304834365845 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00647807121276855 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.9930419921875 sec select_time: 0.728101015090942 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0110089778900146 late. screenSaver idle display 4108.89186811447(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999426126480103 sec select_time: 0.246906995773315 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00185298919677734 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997660875320435 sec select_time: 0.744193077087402 select_time: 0.000287055969238281 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153160095214844 late. screenSaver idle display 4109.90771698952(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999037027359009 sec select_time: 0.230427980422974 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00180816650390625 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997686862945557 sec select_time: 0.760005950927734 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.203639030456543 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.0715649127960205 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00372815132141113 late. screenSaver idle display 4110.91178512573(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999431133270264 sec select_time: 0.226999998092651 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00617194175720215 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.993376016616821 sec select_time: 0.348839998245239 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.015625 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.983323097229 sec select_time: 0.393927097320557 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170028664 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.389405012130737 select_time: 0.00440812110900879 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0109560489654541 late. screenSaver idle display 4111.92307806015(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999427080154419 sec select_time: 0.215705871582031 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997716903686523 sec select_time: 0.775352954864502 select_time: 0.000247001647949219 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152261257171631 late. screenSaver idle display 4112.93860507011(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999433040618896 sec select_time: 0.200187921524048 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00178313255310059 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997781991958618 sec select_time: 0.790957927703857 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.234527111053467 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.104131937026978 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00394392013549805 late. screenSaver idle display 4113.9428961277(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999441146850586 sec select_time: 0.195899963378906 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0061030387878418 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.993429899215698 sec select_time: 0.789541006088257 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.011091947555542 late. screenSaver idle display 4114.95434117317(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99943208694458 sec select_time: 0.184459924697876 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00178813934326172 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997770071029663 sec select_time: 0.806536197662354 select_time: 0.000261068344116211 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152158737182617 late. screenSaver idle display 4115.96986317635(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999433040618896 sec select_time: 0.168927907943726 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00178098678588867 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997774839401245 sec select_time: 0.353198051452637 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99896192550659 sec select_time: 0.467650175094604 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170033648 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.463165044784546 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.253785133361816 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.12224006652832 select_time: 0.000202178955078125 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153138637542725 late. screenSaver idle display 4116.98548102379(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999428987503052 sec select_time: 0.153307914733887 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00182604789733887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997745037078857 sec select_time: 0.837776899337769 select_time: 0.00014805793762207 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153231620788574 late. screenSaver idle display 4118.00111198425(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999430894851685 sec select_time: 0.137670993804932 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00178813934326172 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997779846191406 sec select_time: 0.853490829467773 select_time: 0.000154972076416016 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0153591632843018 late. screenSaver idle display 4119.01678204536(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999430894851685 sec select_time: 0.122009038925171 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00187015533447266 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997686862945557 sec select_time: 0.869067907333374 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.312704086303711 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.175297021865845 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00394010543823242 late. screenSaver idle display 4120.02104496956(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999430894851685 sec select_time: 0.11774206161499 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00612306594848633 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99343204498291 sec select_time: 0.869064807891846 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0110681056976318 late. screenSaver idle display 4121.03246617317(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999418020248413 sec select_time: 0.106308937072754 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00179004669189453 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997781991958618 sec select_time: 0.353226900100708 [norm] firing Slim::Networking::Slimproto::check_all_clients 1.9073486328125e-005 late. Checking if 00:04:20:10:01:0c is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x4abcf88)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99892210960388 sec select_time: 0.530211210250854 Select: [IO::Socket::INET=GLOB(0x4abcf88)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 201.201.201.203:34496 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:10:01:0c signalstrength=65535 00:04:20:10:01:0c Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 fullness 0 bytes_received 0 jiffies: 170038648 output size: 3528000 output fullness: 3519104 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. select_time: 0.525703191757202 select_time: 0.000259160995483398 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152099132537842 late. screenSaver idle display 4122.04798007011(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999429941177368 sec select_time: 0.0908100605010986 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00177812576293945 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99779486656189 sec select_time: 0.900367975234985 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 4, revision = 4.13, MAC = 00:04:20:06:f8:c8 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.3438720703125 Select: [IO::Socket::INET=GLOB(0x2202d48)] read, calling Slim::Networking::UDP::readUDP gotDiscoveryRequest: deviceid = 5, revision = 1.12, MAC = 00:04:20:ff:ff:01 It's a Squeezebox calculated testpc04 length: 17 gotDiscoveryRequest: Sent discovery response. select_time: 0.200623035430908 select_time: 0.011436939239502 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00410103797912598 late. screenSaver idle display 4123.05238008499(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99943208694458 sec select_time: 0.0864229202270508 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00621294975280762 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.993351936340332 sec select_time: 0.900329113006592 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0109829902648926 late. screenSaver idle display 4124.06372714043(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999423027038574 sec select_time: 0.075037956237793 select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.000324010848999023 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999274969100952 sec select_time: 0.916201114654541 select_time: 0.00027012825012207 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0152888298034668 late. screenSaver idle display 4125.07934117317(mode:playlist) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999418020248413 sec select_time: 0.0594320297241211 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0018160343170166 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997758865356445 sec select_time: 0.931654214859009 Select: [HTTP::Daemon::ClientConn=GLOB(0x5065bac)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5065bac)) for GET HTTP/1.1 /log.txt processURL Clients: 201.201.201.203:34540 Generating response for (txt, text/plain) log.txt generating from include.html type: fill found path: D:\Program Files\SlimServer\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1