2006-11-10 12:44:41.2590 generating from setup_input_chk.html
2006-11-10 12:44:41.2972 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.3005 generating from setup_pref.html
2006-11-10 12:44:41.3104 generating from setup_input_chk.html
2006-11-10 12:44:41.3231 generating from setup_pref.html
2006-11-10 12:44:41.3318 generating from setup_input_chk.html
2006-11-10 12:44:41.3418 generating from setup_pref.html
2006-11-10 12:44:41.3578 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.3656 generating from setup_input_chk.html
2006-11-10 12:44:41.3745 generating from setup_pref.html
2006-11-10 12:44:41.3832 generating from setup_input_chk.html
2006-11-10 12:44:41.3918 generating from setup_pref.html
2006-11-10 12:44:41.4033 generating from setup_input_chk.html
2006-11-10 12:44:41.4117 generating from setup_pref.html
2006-11-10 12:44:41.4142 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.4234 generating from setup_input_chk.html
2006-11-10 12:44:41.4322 generating from setup_pref.html
2006-11-10 12:44:41.4417 generating from setup_input_chk.html
2006-11-10 12:44:41.4508 generating from setup_pref.html
2006-11-10 12:44:41.4617 generating from setup_input_chk.html
2006-11-10 12:44:41.4668 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.4755 generating from setup_pref.html
2006-11-10 12:44:41.4896 generating from setup_input_chk.html
2006-11-10 12:44:41.4991 generating from setup_pref.html
2006-11-10 12:44:41.5114 generating from setup_input_chk.html
2006-11-10 12:44:41.5207 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.5282 generating from setup_pref.html
2006-11-10 12:44:41.5384 generating from setup_input_chk.html
2006-11-10 12:44:41.5480 generating from setup_pref.html
2006-11-10 12:44:41.5602 generating from setup_input_chk.html
2006-11-10 12:44:41.5694 generating from setup_pref.html
2006-11-10 12:44:41.5772 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.5803 generating from setup_input_chk.html
2006-11-10 12:44:41.5900 generating from setup_pref.html
2006-11-10 12:44:41.6033 generating from setup_input_chk.html
2006-11-10 12:44:41.6116 generating from setup_pref.html
2006-11-10 12:44:41.6212 generating from setup_input_chk.html
2006-11-10 12:44:41.6317 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.6356 generating from setup_pref.html
2006-11-10 12:44:41.6448 generating from setup_input_chk.html
2006-11-10 12:44:41.6536 generating from setup_pref.html
2006-11-10 12:44:41.6634 generating from setup_input_chk.html
2006-11-10 12:44:41.6719 generating from setup_pref.html
2006-11-10 12:44:41.6808 generating from setup_input_chk.html
2006-11-10 12:44:41.6838 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.6907 generating from setup_pref.html
2006-11-10 12:44:41.6994 generating from setup_input_chk.html
2006-11-10 12:44:41.7090 generating from setup_pref.html
2006-11-10 12:44:41.7178 generating from setup_input_chk.html
2006-11-10 12:44:41.7288 generating from setup_pref.html
2006-11-10 12:44:41.7359 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.7384 generating from setup_input_chk.html
2006-11-10 12:44:41.7472 generating from setup_pref.html
2006-11-10 12:44:41.7575 generating from setup_input_chk.html
2006-11-10 12:44:41.7661 generating from setup_pref.html
2006-11-10 12:44:41.7775 generating from setup_input_chk.html
2006-11-10 12:44:41.7871 generating from setup_pref.html
2006-11-10 12:44:41.7898 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.7968 generating from setup_input_chk.html
2006-11-10 12:44:41.8060 generating from setup_pref.html
2006-11-10 12:44:41.8146 generating from setup_input_chk.html
2006-11-10 12:44:41.8240 generating from setup_pref.html
2006-11-10 12:44:41.8331 generating from setup_input_chk.html
2006-11-10 12:44:41.8406 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.8426 generating from setup_pref.html
2006-11-10 12:44:41.8526 generating from setup_input_chk.html
2006-11-10 12:44:41.8617 generating from setup_pref.html
2006-11-10 12:44:41.8719 generating from setup_input_chk.html
2006-11-10 12:44:41.8809 generating from setup_pref.html
2006-11-10 12:44:41.8899 generating from setup_input_chk.html
2006-11-10 12:44:41.8923 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.9008 generating from setup_pref.html
2006-11-10 12:44:41.9098 generating from setup_input_chk.html
2006-11-10 12:44:41.9182 generating from setup_pref.html
2006-11-10 12:44:41.9278 generating from setup_input_chk.html
2006-11-10 12:44:41.9374 generating from setup_pref.html
2006-11-10 12:44:41.9445 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:41.9470 generating from setup_input_chk.html
2006-11-10 12:44:41.9554 generating from setup_pref.html
2006-11-10 12:44:41.9652 generating from setup_input_chk.html
2006-11-10 12:44:41.9745 generating from setup_pref.html
2006-11-10 12:44:41.9844 generating from setup_input_chk.html
2006-11-10 12:44:41.9929 generating from setup_pref.html
2006-11-10 12:44:41.9954 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.0041 generating from setup_input_chk.html
2006-11-10 12:44:42.0130 generating from setup_pref.html
2006-11-10 12:44:42.0233 generating from setup_input_chk.html
2006-11-10 12:44:42.0328 generating from setup_pref.html
2006-11-10 12:44:42.0417 generating from setup_input_chk.html
2006-11-10 12:44:42.0472 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.0744 generating from setup_pref.html
2006-11-10 12:44:42.0833 generating from setup_input_chk.html
2006-11-10 12:44:42.0915 generating from setup_pref.html
2006-11-10 12:44:42.1073 generating from setup_input_chk.html
2006-11-10 12:44:42.1159 generating from setup_pref.html
2006-11-10 12:44:42.1230 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.1295 generating from setup_input_chk.html
2006-11-10 12:44:42.1395 generating from setup_pref.html
2006-11-10 12:44:42.1507 generating from setup_input_chk.html
2006-11-10 12:44:42.1611 generating from setup_pref.html
2006-11-10 12:44:42.1696 generating from setup_input_chk.html
2006-11-10 12:44:42.1867 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.1948 generating from setup_pref.html
2006-11-10 12:44:42.2033 generating from setup_input_chk.html
2006-11-10 12:44:42.2116 generating from setup_pref.html
2006-11-10 12:44:42.2204 generating from setup_input_chk.html
2006-11-10 12:44:42.2345 generating from setup_pref.html
2006-11-10 12:44:42.2418 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.2461 generating from setup_input_chk.html
2006-11-10 12:44:42.2557 generating from setup_pref.html
2006-11-10 12:44:42.2656 generating from setup_input_chk.html
2006-11-10 12:44:42.2765 generating from setup_pref.html
2006-11-10 12:44:42.2859 generating from setup_input_chk.html
2006-11-10 12:44:42.2941 generating from setup_pref.html
2006-11-10 12:44:42.2966 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.3055 generating from setup_input_chk.html
2006-11-10 12:44:42.3246 generating from setup_pref.html
2006-11-10 12:44:42.3346 generating from setup_input_chk.html
2006-11-10 12:44:42.3430 generating from setup_pref.html
2006-11-10 12:44:42.3488 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.3537 generating from setup_input_chk.html
2006-11-10 12:44:42.3622 generating from setup_pref.html
2006-11-10 12:44:42.3713 generating from setup_input_chk.html
2006-11-10 12:44:42.3803 generating from setup_pref.html
2006-11-10 12:44:42.3901 generating from setup_input_chk.html
2006-11-10 12:44:42.3991 generating from setup_pref.html
2006-11-10 12:44:42.4021 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.4103 generating from setup_input_chk.html
2006-11-10 12:44:42.4199 generating from setup_pref.html
2006-11-10 12:44:42.4293 generating from setup_input_chk.html
2006-11-10 12:44:42.4377 generating from setup_pref.html
2006-11-10 12:44:42.4463 generating from setup_input_chk.html
2006-11-10 12:44:42.4540 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.4560 generating from setup_pref.html
2006-11-10 12:44:42.4646 generating from setup_input_chk.html
2006-11-10 12:44:42.4744 generating from setup_pref.html
2006-11-10 12:44:42.4828 generating from setup_group.html
2006-11-10 12:44:42.4927 generating from setup.html
2006-11-10 12:44:42.5066 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:42.5313 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Adding write -> Slim::Web::HTTP::sendResponse
2006-11-10 12:44:42.5316 End request: keepAlive: [3] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x4fd8db4) on connection = Keep-Alive

2006-11-10 12:44:42.5321 select_time: 1
2006-11-10 12:44:42.5324 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] write, calling Slim::Web::HTTP::sendResponse
2006-11-10 12:44:42.5344 Sent 215 to 127.0.0.1
2006-11-10 12:44:42.5346 More to send to 127.0.0.1
2006-11-10 12:44:42.5348 select_time: 1
2006-11-10 12:44:42.5350 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] write, calling Slim::Web::HTTP::sendResponse
2006-11-10 12:44:42.5359 Sent 26625 to 127.0.0.1
2006-11-10 12:44:42.5361 No more messages to send to 127.0.0.1
2006-11-10 12:44:42.5369 select_time: 1
2006-11-10 12:44:42.5380 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] write, calling Slim::Web::HTTP::sendResponse
2006-11-10 12:44:42.5383 No segment to send to 127.0.0.1, waiting for next request..
2006-11-10 12:44:42.5385 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Removing write
2006-11-10 12:44:42.5387 select_time: 1
2006-11-10 12:44:43.5497 select_time: 0.45033597946167
2006-11-10 12:44:44.0010 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000890970230102539 late.
2006-11-10 12:44:44.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99880194664001 sec
2006-11-10 12:44:44.0014 select_time: 1
2006-11-10 12:44:45.0064 select_time: 1
2006-11-10 12:44:46.0089 select_time: 1
2006-11-10 12:44:47.0114 select_time: 1
2006-11-10 12:44:47.7162 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:44:47.7166 select_time: 1
2006-11-10 12:44:47.7169 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:44:47.7172 select_time: 1
2006-11-10 12:44:48.7188 select_time: 0.2812180519104
2006-11-10 12:44:49.0001 [norm] firing Slim::Networking::Slimproto::check_all_clients 2.09808349609375e-005 late.
2006-11-10 12:44:49.0003 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.999675989151 sec
2006-11-10 12:44:49.0005 select_time: 1
2006-11-10 12:44:50.0032 select_time: 1
2006-11-10 12:44:51.0057 select_time: 1
2006-11-10 12:44:52.0082 select_time: 0.991776943206787
2006-11-10 12:44:52.6190 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:44:52.6209 reading request...
2006-11-10 12:44:52.6212 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)) for GET HTTP/1.1 /home.html?player= 
2006-11-10 12:44:52.6229 HTTP parameter player = 
2006-11-10 12:44:52.6239 processURL Clients: 
2006-11-10 12:44:52.6245 Generating response for (htm, text/html) home.html
2006-11-10 12:44:52.6248 generating from include.html
2006-11-10 12:44:52.6275 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:52.6416 SELECT me.name, me.value FROM metainformation me WHERE ( name = ? ): 'isScanning'
2006-11-10 12:44:52.6663 SELECT COUNT( DISTINCT( me.id ) ) FROM tracks me WHERE ( me.audio = ? ): '1'
2006-11-10 12:44:52.7953 SELECT COUNT( DISTINCT( me.id ) ) FROM albums me: 
2006-11-10 12:44:52.8043 SELECT COUNT( DISTINCT( me.id ) ) FROM contributors me LEFT JOIN contributor_album contributorAlbums ON ( contributorAlbums.contributor = me.id ) WHERE ( contributorAlbums.role IN ( ?, ? ) ): '1', '5'
2006-11-10 12:44:52.8162 ->addLibraryStats() found 20694 songs, 1885 albums & 1373 artists
2006-11-10 12:44:52.8165 generating from home.html
2006-11-10 12:44:52.8327 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:52.8683 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Adding write -> Slim::Web::HTTP::sendResponse
2006-11-10 12:44:52.8686 End request: keepAlive: [4] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x4fd8db4) on connection = Keep-Alive

2006-11-10 12:44:52.8691 select_time: 0.130888938903809
2006-11-10 12:44:52.8694 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] write, calling Slim::Web::HTTP::sendResponse
2006-11-10 12:44:52.8710 Sent 214 to 127.0.0.1
2006-11-10 12:44:52.8712 More to send to 127.0.0.1
2006-11-10 12:44:52.8714 select_time: 0.128576993942261
2006-11-10 12:44:52.8717 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] write, calling Slim::Web::HTTP::sendResponse
2006-11-10 12:44:52.8724 Sent 9414 to 127.0.0.1
2006-11-10 12:44:52.8725 No more messages to send to 127.0.0.1
2006-11-10 12:44:52.8734 select_time: 0.126626014709473
2006-11-10 12:44:52.8737 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] write, calling Slim::Web::HTTP::sendResponse
2006-11-10 12:44:52.8738 No segment to send to 127.0.0.1, waiting for next request..
2006-11-10 12:44:52.8740 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Removing write
2006-11-10 12:44:52.8742 select_time: 0.125765085220337
2006-11-10 12:44:52.9999 select_time: 8.60691070556641e-005
2006-11-10 12:44:52.0008 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.000760078430175781 late.
2006-11-10 12:44:52.0010 Prevent Standby plugin: starting timer
2006-11-10 12:44:52.0011 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 58.9989008903503 sec
2006-11-10 12:44:52.0013 select_time: 0.998713970184326
2006-11-10 12:44:53.4492 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:44:53.4512 reading request...
2006-11-10 12:44:53.4516 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:44:53.4530 Bad Request: [head /status_header.html]
2006-11-10 12:44:53.4533 generating from html/errors/405.html
2006-11-10 12:44:53.4583 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:44:53.4711 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Removing read
2006-11-10 12:44:53.4714 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Removing write
2006-11-10 12:44:53.4716 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd8db4)] Removing error
2006-11-10 12:44:53.4720 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x4fd8db4) on connection = close

2006-11-10 12:44:53.4731 select_time: 0.526892900466919
2006-11-10 12:44:53.9975 select_time: 0.00244998931884766
2006-11-10 12:44:53.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000332117080688477 late.
2006-11-10 12:44:53.0006 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99941611289978 sec
2006-11-10 12:44:53.0007 select_time: 1
2006-11-10 12:44:54.0000 select_time: 1
2006-11-10 12:44:56.0025 select_time: 1
2006-11-10 12:44:57.0050 select_time: 0.994961023330688
2006-11-10 12:44:57.7411 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:44:57.7416 select_time: 0.258415937423706
2006-11-10 12:44:57.7418 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:44:57.7422 select_time: 0.257731914520264
2006-11-10 12:44:57.9999 select_time: 6.69956207275391e-005
2006-11-10 12:44:57.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000773906707763672 late.
2006-11-10 12:44:57.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99899506568909 sec
2006-11-10 12:44:57.0012 select_time: 1
2006-11-10 12:44:58.9944 select_time: 1
2006-11-10 12:44:59.9969 select_time: 0.94674015045166
2006-11-10 12:45:00.9524 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.00868487358093262 late.
2006-11-10 12:45:00.9526 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999868869781 sec
2006-11-10 12:45:00.9528 select_time: 0.0245959758758545
2006-11-10 12:45:00.9777 [norm] firing Plugins::Rescan::checkScanTimer 0.000251054763793945 late.
2006-11-10 12:45:00.9780 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999849796295 sec
2006-11-10 12:45:00.9781 select_time: 1
2006-11-10 12:45:01.9862 select_time: 0.0138089656829834
2006-11-10 12:45:02.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000771999359130859 late.
2006-11-10 12:45:02.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99891901016235 sec
2006-11-10 12:45:02.0012 select_time: 1
2006-11-10 12:45:03.0043 select_time: 1
2006-11-10 12:45:04.0068 select_time: 1
2006-11-10 12:45:05.0093 select_time: 1
2006-11-10 12:45:06.0118 select_time: 0.988156080245972
2006-11-10 12:45:06.9987 select_time: 0.00132989883422852
2006-11-10 12:45:06.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000482082366943359 late.
2006-11-10 12:45:06.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99925899505615 sec
2006-11-10 12:45:06.0009 select_time: 1
2006-11-10 12:45:07.7661 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:07.7665 select_time: 1
2006-11-10 12:45:07.7668 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:07.7671 select_time: 1
2006-11-10 12:45:08.7687 select_time: 1
2006-11-10 12:45:09.7712 select_time: 1
2006-11-10 12:45:10.7737 select_time: 0.226304054260254
2006-11-10 12:45:10.0003 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00018000602722168 late.
2006-11-10 12:45:10.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99949908256531 sec
2006-11-10 12:45:10.0007 select_time: 1
2006-11-10 12:45:11.9955 select_time: 1
2006-11-10 12:45:12.9980 select_time: 1
2006-11-10 12:45:14.0005 select_time: 0.999519109725952
2006-11-10 12:45:15.0030 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00289607048034668 late.
2006-11-10 12:45:15.0032 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99679088592529 sec
2006-11-10 12:45:15.0034 select_time: 1
2006-11-10 12:45:16.0055 select_time: 1
2006-11-10 12:45:17.0079 select_time: 1
2006-11-10 12:45:17.7910 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:17.7915 select_time: 1
2006-11-10 12:45:17.7918 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:17.7921 select_time: 1
2006-11-10 12:45:18.7936 select_time: 1
2006-11-10 12:45:19.0104 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:45:19.0107 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:45:19.0108 It's a Squeezebox
2006-11-10 12:45:19.0109  calculated destruction length: 17
2006-11-10 12:45:19.0112 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:45:19.0114 select_time: 0.988562107086182
2006-11-10 12:45:19.9998 select_time: 0.000207901000976563
2006-11-10 12:45:19.0009 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000847101211547852 late.
2006-11-10 12:45:19.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99887704849243 sec
2006-11-10 12:45:19.0013 select_time: 1
2006-11-10 12:45:21.0022 select_time: 1
2006-11-10 12:45:22.0048 select_time: 1
2006-11-10 12:45:23.0073 select_time: 0.992721080780029
2006-11-10 12:45:24.0098 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00969600677490234 late.
2006-11-10 12:45:24.0100 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98996210098267 sec
2006-11-10 12:45:24.0102 select_time: 1
2006-11-10 12:45:25.0123 select_time: 1
2006-11-10 12:45:26.0147 select_time: 1
2006-11-10 12:45:27.0172 select_time: 1
2006-11-10 12:45:27.8160 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:27.8165 select_time: 1
2006-11-10 12:45:27.8168 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:27.8171 select_time: 1
2006-11-10 12:45:28.8186 select_time: 0.181376934051514
2006-11-10 12:45:29.0002 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000169992446899414 late.
2006-11-10 12:45:29.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99950504302979 sec
2006-11-10 12:45:29.0007 select_time: 1
2006-11-10 12:45:30.0091 select_time: 1
2006-11-10 12:45:31.0116 select_time: 1
2006-11-10 12:45:32.0141 select_time: 1
2006-11-10 12:45:33.0166 select_time: 0.983426094055176
2006-11-10 12:45:34.0034 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00332808494567871 late.
2006-11-10 12:45:34.0036 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99634909629822 sec
2006-11-10 12:45:34.0038 select_time: 1
2006-11-10 12:45:35.0059 select_time: 1
2006-11-10 12:45:36.0084 select_time: 1
2006-11-10 12:45:37.0109 select_time: 1
2006-11-10 12:45:37.8410 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:37.8414 select_time: 1
2006-11-10 12:45:37.8417 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:37.8420 select_time: 1
2006-11-10 12:45:38.1655 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1661 select_time: 0.833929061889648
2006-11-10 12:45:38.1665 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1670 select_time: 0.833025932312012
2006-11-10 12:45:38.1677 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1683 select_time: 0.831684112548828
2006-11-10 12:45:38.1690 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1695 select_time: 0.830441951751709
2006-11-10 12:45:38.1703 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1708 select_time: 0.829134941101074
2006-11-10 12:45:38.1716 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1721 select_time: 0.827855110168457
2006-11-10 12:45:38.1729 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1734 select_time: 0.826540946960449
2006-11-10 12:45:38.1743 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1749 select_time: 0.825134038925171
2006-11-10 12:45:38.1755 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1761 select_time: 0.82384204864502
2006-11-10 12:45:38.1768 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1773 select_time: 0.822673082351685
2006-11-10 12:45:38.1781 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:38.1786 select_time: 0.821352958679199
2006-11-10 12:45:39.0002 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000144004821777344 late.
2006-11-10 12:45:39.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.9995219707489 sec
2006-11-10 12:45:39.0006 select_time: 1
2006-11-10 12:45:40.0027 select_time: 1
2006-11-10 12:45:41.0052 select_time: 1
2006-11-10 12:45:42.0077 select_time: 1
2006-11-10 12:45:43.0102 select_time: 0.989794969558716
2006-11-10 12:45:43.9970 select_time: 0.00296211242675781
2006-11-10 12:45:43.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000790119171142578 late.
2006-11-10 12:45:43.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99893188476563 sec
2006-11-10 12:45:43.0012 select_time: 1
2006-11-10 12:45:44.9995 select_time: 1
2006-11-10 12:45:46.0020 select_time: 1
2006-11-10 12:45:47.0045 select_time: 0.995474100112915
2006-11-10 12:45:47.8659 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:47.8664 select_time: 0.133573055267334
2006-11-10 12:45:47.8667 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:47.8670 select_time: 0.132963895797729
2006-11-10 12:45:47.0003 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000193119049072266 late.
2006-11-10 12:45:47.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99947905540466 sec
2006-11-10 12:45:47.0007 select_time: 1
2006-11-10 12:45:48.9938 select_time: 1
2006-11-10 12:45:49.9963 select_time: 1
2006-11-10 12:45:50.9988 select_time: 1
2006-11-10 12:45:52.0012 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.00126409530639648 late.
2006-11-10 12:45:52.0014 Prevent Standby plugin: starting timer
2006-11-10 12:45:52.0016 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9984250068665 sec
2006-11-10 12:45:52.0017 select_time: 0
2006-11-10 12:45:52.0021 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0020449161529541 late.
2006-11-10 12:45:52.0022 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99774789810181 sec
2006-11-10 12:45:52.0024 select_time: 1
2006-11-10 12:45:53.0038 select_time: 1
2006-11-10 12:45:53.6146 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:45:53.6161 Select: [HTTP::Daemon::ClientConn=GLOB(0x500eff4)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:45:53.6164 Select: [HTTP::Daemon::ClientConn=GLOB(0x500eff4)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:45:53.6165 Accepted connection 1 from 127.0.0.1
2006-11-10 12:45:53.6167 select_time: 1
2006-11-10 12:45:53.6176 Select: [HTTP::Daemon::ClientConn=GLOB(0x500eff4)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:45:53.6196 reading request...
2006-11-10 12:45:53.6201 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x500eff4)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:45:53.6217 Bad Request: [head /status_header.html]
2006-11-10 12:45:53.6220 generating from html/errors/405.html
2006-11-10 12:45:53.6247 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:45:53.6354 Select: [HTTP::Daemon::ClientConn=GLOB(0x500eff4)] Removing read
2006-11-10 12:45:53.6357 Select: [HTTP::Daemon::ClientConn=GLOB(0x500eff4)] Removing write
2006-11-10 12:45:53.6359 Select: [HTTP::Daemon::ClientConn=GLOB(0x500eff4)] Removing error
2006-11-10 12:45:53.6363 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x500eff4) on connection = close

2006-11-10 12:45:53.6369 select_time: 1
2006-11-10 12:45:54.6485 select_time: 1
2006-11-10 12:45:55.6510 select_time: 1
2006-11-10 12:45:56.6536 select_time: 0.346447944641113
2006-11-10 12:45:56.0002 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000154018402099609 late.
2006-11-10 12:45:56.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99949288368225 sec
2006-11-10 12:45:56.0007 select_time: 1
2006-11-10 12:45:57.8909 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:57.8913 select_time: 1
2006-11-10 12:45:57.8917 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:45:57.8920 select_time: 1
2006-11-10 12:45:58.8935 select_time: 1
2006-11-10 12:45:59.1617 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:45:59.1620 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:45:59.1621 It's a Squeezebox
2006-11-10 12:45:59.1622  calculated destruction length: 17
2006-11-10 12:45:59.1625 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:45:59.1628 select_time: 1
2006-11-10 12:46:00.1623 select_time: 0.790320873260498
2006-11-10 12:46:00.9612 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.00846600532531738 late.
2006-11-10 12:46:00.9615 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999849796295 sec
2006-11-10 12:46:00.9617 select_time: 0.0162930488586426
2006-11-10 12:46:00.9785 [norm] firing Plugins::Rescan::checkScanTimer 0.000452041625976563 late.
2006-11-10 12:46:00.9787 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999868869781 sec
2006-11-10 12:46:00.9789 select_time: 0.0210440158843994
2006-11-10 12:46:00.0000 select_time: 1.19209289550781e-005
2006-11-10 12:46:00.0009 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000844955444335938 late.
2006-11-10 12:46:00.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99891400337219 sec
2006-11-10 12:46:00.0012 select_time: 1
2006-11-10 12:46:01.9950 select_time: 1
2006-11-10 12:46:02.9975 select_time: 1
2006-11-10 12:46:03.0000 select_time: 1
2006-11-10 12:46:05.0025 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00238394737243652 late.
2006-11-10 12:46:05.0027 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99726605415344 sec
2006-11-10 12:46:05.0029 select_time: 1
2006-11-10 12:46:06.0049 select_time: 1
2006-11-10 12:46:07.0074 select_time: 1
2006-11-10 12:46:07.9158 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:07.9164 select_time: 1
2006-11-10 12:46:07.9167 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:07.9170 select_time: 1
2006-11-10 12:46:08.9184 select_time: 1
2006-11-10 12:46:09.9210 select_time: 0.0790410041809082
2006-11-10 12:46:09.0000 select_time: 0
2006-11-10 12:46:09.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000358104705810547 late.
2006-11-10 12:46:09.0006 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99942708015442 sec
2006-11-10 12:46:09.0007 select_time: 1
2006-11-10 12:46:11.0018 select_time: 1
2006-11-10 12:46:11.0642 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:11.0648 UPnP: Notify from new device [uuid:526F6B75-536F-756E-6442-000D4B03AC87 at http://192.168.13.103:80/DeviceDescription.xml]
2006-11-10 12:46:11.0653 SimpleAsyncHTTP: GETing http://192.168.13.103:80/DeviceDescription.xml
2006-11-10 12:46:11.0669 Async: Connecting to 192.168.13.103:80
2006-11-10 12:46:11.0723 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:46:11.0727 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:46:11.0729 [norm] set Slim::Networking::Async::_connect_error, in 4.99992394447327 sec
2006-11-10 12:46:11.0733 select_time: 1
2006-11-10 12:46:11.0736 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:11.0743 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:46:11.0747 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404) / Slim::Networking::Async::_connect_error
2006-11-10 12:46:11.0751 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing error
2006-11-10 12:46:11.0753 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing write
2006-11-10 12:46:11.0754 Async: connected, ready to write request
2006-11-10 12:46:11.0761 Async: Sending:
GET /DeviceDescription.xml HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.13.103

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:46:11.0765 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:46:11.0769 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:46:11.0772 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Wrote 257 bytes
2006-11-10 12:46:11.0776 [norm] set Slim::Networking::Async::_async_error, in 4.99992084503174 sec
2006-11-10 12:46:11.0779 select_time: 1
2006-11-10 12:46:11.0870 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:11.0876 select_time: 1
2006-11-10 12:46:11.0896 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:11.0902 select_time: 1
2006-11-10 12:46:11.1038 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:46:11.1043 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404) / Slim::Networking::Async::_async_error
2006-11-10 12:46:11.1054 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing error
2006-11-10 12:46:11.1057 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing read
2006-11-10 12:46:11.1064 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:46:11.1077 bless({
  "cache-control" => "no-cache",
  connection => "close",
  "content-type" => "text/xml; charset=\"utf-8\"",
  expires => "Thu, 26 Oct 1995 00:00:00 GMT",
  server => "Allegro-Software-RomPager/4.32",
}, "HTTP::Headers")
2006-11-10 12:46:11.1082 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997997283936 sec
2006-11-10 12:46:11.1085 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:46:11.1087 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:46:11.1091 select_time: 1
2006-11-10 12:46:11.1094 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:11.1099 select_time: 1
2006-11-10 12:46:11.1102 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:11.1107 select_time: 1
2006-11-10 12:46:11.1266 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:46:11.1271 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:46:11.1276 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:46:11.1279 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99998307228088 sec
2006-11-10 12:46:11.1281 select_time: 1
2006-11-10 12:46:11.1285 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:46:11.1290 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:46:11.1293 Async::HTTP: Read body: 426 bytes
2006-11-10 12:46:11.1295 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99998307228088 sec
2006-11-10 12:46:11.1298 select_time: 1
2006-11-10 12:46:11.1445 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:46:11.1452 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:46:11.1455 Async::HTTP: Read body: 718 bytes
2006-11-10 12:46:11.1458 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99998307228088 sec
2006-11-10 12:46:11.1460 select_time: 1
2006-11-10 12:46:11.3304 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:46:11.3310 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:46:11.3315 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing error
2006-11-10 12:46:11.3318 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing read
2006-11-10 12:46:11.3320 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] Removing write
2006-11-10 12:46:11.3321 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ca404)] removing writeNoBlock queue
2006-11-10 12:46:11.3325 Async::HTTP: Body read
2006-11-10 12:46:11.3328 SimpleAsyncHTTP: status for http://192.168.13.103:80/DeviceDescription.xml is 200 OK
2006-11-10 12:46:11.3331 SimpleAsyncHTTP: Done
2006-11-10 12:46:11.3337 UPnP: New device found: SoundBridge [http://192.168.13.103:80/DeviceDescription.xml]
2006-11-10 12:46:11.3341 UPnP: SoundBridge is a Roku Roku SoundBridge M1000 (urn:schemas-upnp-org:device:MediaRenderer:1), ignoring
2006-11-10 12:46:11.3354 select_time: 1
2006-11-10 12:46:12.3332 select_time: 1
2006-11-10 12:46:13.0693 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:13.0699 select_time: 0.930075883865356
2006-11-10 12:46:13.0707 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:13.0712 select_time: 0.928757905960083
2006-11-10 12:46:13.0909 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:13.0916 select_time: 0.908416986465454
2006-11-10 12:46:13.0924 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:13.0929 select_time: 0.907041072845459
2006-11-10 12:46:13.1099 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:13.1107 select_time: 0.889333963394165
2006-11-10 12:46:13.1112 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:13.1117 select_time: 0.888252019882202
2006-11-10 12:46:13.9936 select_time: 0.00640106201171875
2006-11-10 12:46:14.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000298976898193359 late.
2006-11-10 12:46:14.0006 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99937796592712 sec
2006-11-10 12:46:14.0008 select_time: 1
2006-11-10 12:46:14.4627 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:14.4633 select_time: 1
2006-11-10 12:46:15.0743 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:15.0748 select_time: 1
2006-11-10 12:46:16.0768 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:16.0773 select_time: 1
2006-11-10 12:46:17.0794 select_time: 1
2006-11-10 12:46:17.9251 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:17.9256 select_time: 1
2006-11-10 12:46:17.9260 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:17.9264 select_time: 1
2006-11-10 12:46:18.9278 select_time: 0.0722429752349854
2006-11-10 12:46:19.0000 select_time: 0
2006-11-10 12:46:19.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000356912612915039 late.
2006-11-10 12:46:19.0006 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99940896034241 sec
2006-11-10 12:46:19.0008 select_time: 1
2006-11-10 12:46:20.0086 select_time: 1
2006-11-10 12:46:21.0111 select_time: 1
2006-11-10 12:46:22.0135 select_time: 1
2006-11-10 12:46:23.0161 select_time: 0.983937978744507
2006-11-10 12:46:24.0029 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00281596183776855 late.
2006-11-10 12:46:24.0032 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99682593345642 sec
2006-11-10 12:46:24.0034 select_time: 1
2006-11-10 12:46:25.0054 select_time: 1
2006-11-10 12:46:26.0079 select_time: 1
2006-11-10 12:46:27.0104 select_time: 1
2006-11-10 12:46:27.9501 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:27.9506 select_time: 1
2006-11-10 12:46:27.9509 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:27.9515 select_time: 1
2006-11-10 12:46:28.9684 select_time: 0.0316169261932373
2006-11-10 12:46:28.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000525951385498047 late.
2006-11-10 12:46:28.0009 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99911189079285 sec
2006-11-10 12:46:28.0011 select_time: 1
2006-11-10 12:46:30.0022 select_time: 1
2006-11-10 12:46:31.0047 select_time: 1
2006-11-10 12:46:32.0072 select_time: 0.99280309677124
2006-11-10 12:46:32.9940 select_time: 0.00597000122070313
2006-11-10 12:46:33.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000731945037841797 late.
2006-11-10 12:46:33.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99894309043884 sec
2006-11-10 12:46:33.0012 select_time: 1
2006-11-10 12:46:34.0122 select_time: 1
2006-11-10 12:46:35.0147 select_time: 1
2006-11-10 12:46:36.0172 select_time: 1
2006-11-10 12:46:37.0197 select_time: 0.980320930480957
2006-11-10 12:46:37.9907 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:37.9913 select_time: 0.00873589515686035
2006-11-10 12:46:37.9916 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:37.9920 select_time: 0.00802993774414063
2006-11-10 12:46:37.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000480890274047852 late.
2006-11-10 12:46:37.0009 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99913692474365 sec
2006-11-10 12:46:37.0011 select_time: 1
2006-11-10 12:46:38.3589 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3595 select_time: 1
2006-11-10 12:46:38.3601 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3606 select_time: 1
2006-11-10 12:46:38.3612 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3617 select_time: 1
2006-11-10 12:46:38.3624 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3630 select_time: 1
2006-11-10 12:46:38.3638 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3643 select_time: 1
2006-11-10 12:46:38.3650 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3705 select_time: 1
2006-11-10 12:46:38.3710 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3717 select_time: 1
2006-11-10 12:46:38.3721 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3726 select_time: 1
2006-11-10 12:46:38.3729 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3734 select_time: 1
2006-11-10 12:46:38.3738 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3743 select_time: 1
2006-11-10 12:46:38.3746 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:38.3751 select_time: 1
2006-11-10 12:46:39.3065 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:46:39.3068 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:46:39.3070 It's a Squeezebox
2006-11-10 12:46:39.3071  calculated destruction length: 17
2006-11-10 12:46:39.3074 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:46:39.3080 select_time: 1
2006-11-10 12:46:40.3091 select_time: 1
2006-11-10 12:46:41.3116 select_time: 0.688383102416992
2006-11-10 12:46:42.0165 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.016416072845459 late.
2006-11-10 12:46:42.0168 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98320603370667 sec
2006-11-10 12:46:42.0170 select_time: 1
2006-11-10 12:46:43.0190 select_time: 1
2006-11-10 12:46:44.0215 select_time: 1
2006-11-10 12:46:45.0240 select_time: 1
2006-11-10 12:46:46.0265 select_time: 0.973520040512085
2006-11-10 12:46:46.9976 select_time: 0.00235295295715332
2006-11-10 12:46:46.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000422954559326172 late.
2006-11-10 12:46:46.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99927401542664 sec
2006-11-10 12:46:46.0009 select_time: 1
2006-11-10 12:46:48.0001 select_time: 1
2006-11-10 12:46:48.0054 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:48.0059 select_time: 1
2006-11-10 12:46:48.0063 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:48.0066 select_time: 1
2006-11-10 12:46:49.0026 select_time: 1
2006-11-10 12:46:50.0051 select_time: 0.994863986968994
2006-11-10 12:46:51.0076 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00755190849304199 late.
2006-11-10 12:46:51.0079 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99206805229187 sec
2006-11-10 12:46:51.0081 select_time: 0.991838932037354
2006-11-10 12:46:52.0101 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.0100479125976563 late.
2006-11-10 12:46:52.0104 Prevent Standby plugin: starting timer
2006-11-10 12:46:52.0105 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9894421100616 sec
2006-11-10 12:46:52.0108 select_time: 1
2006-11-10 12:46:53.0126 select_time: 1
2006-11-10 12:46:53.7957 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:46:53.7972 Select: [HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:46:53.7975 Select: [HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:46:53.7977 Accepted connection 1 from 127.0.0.1
2006-11-10 12:46:53.7979 select_time: 1
2006-11-10 12:46:53.7987 Select: [HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:46:53.8009 reading request...
2006-11-10 12:46:53.8013 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:46:53.8029 Bad Request: [head /status_header.html]
2006-11-10 12:46:53.8032 generating from html/errors/405.html
2006-11-10 12:46:53.8058 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:46:53.8163 Select: [HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)] Removing read
2006-11-10 12:46:53.8166 Select: [HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)] Removing write
2006-11-10 12:46:53.8168 Select: [HTTP::Daemon::ClientConn=GLOB(0x52c2ad8)] Removing error
2006-11-10 12:46:53.8173 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x52c2ad8) on connection = close

2006-11-10 12:46:53.8178 select_time: 1
2006-11-10 12:46:54.8296 select_time: 1
2006-11-10 12:46:55.8321 select_time: 0.167855978012085
2006-11-10 12:46:55.0001 [norm] firing Slim::Networking::Slimproto::check_all_clients 3.00407409667969e-005 late.
2006-11-10 12:46:55.0004 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99959492683411 sec
2006-11-10 12:46:55.0006 select_time: 1
2006-11-10 12:46:56.9913 select_time: 1
2006-11-10 12:46:57.9938 select_time: 1
2006-11-10 12:46:58.0298 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:58.0303 select_time: 1
2006-11-10 12:46:58.0307 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:46:58.0311 select_time: 1
2006-11-10 12:46:59.0433 select_time: 0.956732988357544
2006-11-10 12:46:59.9988 select_time: 0.00123405456542969
2006-11-10 12:46:59.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000562906265258789 late.
2006-11-10 12:46:59.0008 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99916195869446 sec
2006-11-10 12:46:59.0010 select_time: 0.960383892059326
2006-11-10 12:47:00.9699 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.00840306282043457 late.
2006-11-10 12:47:00.9703 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999849796295 sec
2006-11-10 12:47:00.9705 select_time: 0.00823593139648438
2006-11-10 12:47:00.9797 [norm] firing Plugins::Rescan::checkScanTimer 0.000849008560180664 late.
2006-11-10 12:47:00.9800 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999861717224 sec
2006-11-10 12:47:00.9802 select_time: 1
2006-11-10 12:47:01.9724 select_time: 1
2006-11-10 12:47:02.9749 select_time: 1
2006-11-10 12:47:03.9774 select_time: 0.0225789546966553
2006-11-10 12:47:04.0009 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00077509880065918 late.
2006-11-10 12:47:04.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99885201454163 sec
2006-11-10 12:47:04.0014 select_time: 1
2006-11-10 12:47:05.0112 select_time: 1
2006-11-10 12:47:06.0137 select_time: 1
2006-11-10 12:47:07.0162 select_time: 1
2006-11-10 12:47:08.0187 select_time: 0.981266021728516
2006-11-10 12:47:08.0621 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:08.0626 select_time: 0.937357902526855
2006-11-10 12:47:08.0630 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:08.0635 select_time: 0.936476945877075
2006-11-10 12:47:09.0056 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00548791885375977 late.
2006-11-10 12:47:09.0059 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99411606788635 sec
2006-11-10 12:47:09.0061 select_time: 1
2006-11-10 12:47:10.0080 select_time: 1
2006-11-10 12:47:11.0105 select_time: 1
2006-11-10 12:47:12.0130 select_time: 1
2006-11-10 12:47:13.0155 select_time: 0.984445095062256
2006-11-10 12:47:14.0024 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0023040771484375 late.
2006-11-10 12:47:14.0027 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99730896949768 sec
2006-11-10 12:47:14.0029 select_time: 1
2006-11-10 12:47:15.0049 select_time: 1
2006-11-10 12:47:16.0074 select_time: 1
2006-11-10 12:47:17.0099 select_time: 1
2006-11-10 12:47:18.0124 select_time: 0.987632989883423
2006-11-10 12:47:18.0836 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:18.0841 select_time: 0.91589093208313
2006-11-10 12:47:18.0845 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:18.0848 select_time: 0.915143013000488
2006-11-10 12:47:18.9992 select_time: 0.00080108642578125
2006-11-10 12:47:18.0001 [norm] firing Slim::Networking::Slimproto::check_all_clients 2.09808349609375e-005 late.
2006-11-10 12:47:18.0003 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99971604347229 sec
2006-11-10 12:47:18.0005 select_time: 1
2006-11-10 12:47:19.4663 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:47:19.4667 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:47:19.4668 It's a Squeezebox
2006-11-10 12:47:19.4670  calculated destruction length: 17
2006-11-10 12:47:19.4673 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:47:19.4676 select_time: 1
2006-11-10 12:47:20.4716 select_time: 1
2006-11-10 12:47:21.4741 select_time: 1
2006-11-10 12:47:22.4766 select_time: 0.523394107818604
2006-11-10 12:47:23.0092 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00910401344299316 late.
2006-11-10 12:47:23.0095 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99050092697144 sec
2006-11-10 12:47:23.0097 select_time: 1
2006-11-10 12:47:24.0116 select_time: 1
2006-11-10 12:47:25.0142 select_time: 1
2006-11-10 12:47:26.0167 select_time: 1
2006-11-10 12:47:27.0192 select_time: 0.9808349609375
2006-11-10 12:47:28.0060 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0059199333190918 late.
2006-11-10 12:47:28.0063 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99369692802429 sec
2006-11-10 12:47:28.0065 select_time: 1
2006-11-10 12:47:28.1137 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:28.1144 select_time: 1
2006-11-10 12:47:28.1148 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:28.1152 select_time: 1
2006-11-10 12:47:29.1181 select_time: 1
2006-11-10 12:47:30.1206 select_time: 1
2006-11-10 12:47:31.1231 select_time: 1
2006-11-10 12:47:32.1256 select_time: 0.87437105178833
2006-11-10 12:47:33.0028 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00273609161376953 late.
2006-11-10 12:47:33.0031 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99687004089355 sec
2006-11-10 12:47:33.0034 select_time: 1
2006-11-10 12:47:34.0053 select_time: 1
2006-11-10 12:47:35.0078 select_time: 1
2006-11-10 12:47:36.0103 select_time: 1
2006-11-10 12:47:37.0128 select_time: 0.987200975418091
2006-11-10 12:47:37.9996 select_time: 0.000369071960449219
2006-11-10 12:47:37.0014 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00132107734680176 late.
2006-11-10 12:47:37.0017 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99833488464355 sec
2006-11-10 12:47:37.0019 select_time: 1
2006-11-10 12:47:38.1382 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.1388 select_time: 1
2006-11-10 12:47:38.1392 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.1396 select_time: 1
2006-11-10 12:47:38.5477 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5485 select_time: 1
2006-11-10 12:47:38.5491 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5496 select_time: 1
2006-11-10 12:47:38.5509 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5516 select_time: 1
2006-11-10 12:47:38.5532 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5539 select_time: 1
2006-11-10 12:47:38.5545 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5551 select_time: 1
2006-11-10 12:47:38.5557 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5563 select_time: 1
2006-11-10 12:47:38.5572 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5578 select_time: 1
2006-11-10 12:47:38.5584 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5590 select_time: 1
2006-11-10 12:47:38.5597 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5603 select_time: 1
2006-11-10 12:47:38.5610 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5615 select_time: 1
2006-11-10 12:47:38.5622 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:38.5630 select_time: 1
2006-11-10 12:47:39.5660 select_time: 1
2006-11-10 12:47:40.5685 select_time: 1
2006-11-10 12:47:41.5710 select_time: 0.428977966308594
2006-11-10 12:47:42.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000412940979003906 late.
2006-11-10 12:47:42.0008 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99918794631958 sec
2006-11-10 12:47:42.0010 select_time: 1
2006-11-10 12:47:43.0121 select_time: 1
2006-11-10 12:47:44.0146 select_time: 1
2006-11-10 12:47:45.0171 select_time: 1
2006-11-10 12:47:46.0196 select_time: 0.980402946472168
2006-11-10 12:47:46.9908 select_time: 0.0092320442199707
2006-11-10 12:47:47.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000446081161499023 late.
2006-11-10 12:47:47.0008 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99916100502014 sec
2006-11-10 12:47:47.0011 select_time: 1
2006-11-10 12:47:48.0089 select_time: 1
2006-11-10 12:47:48.1519 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:48.1525 select_time: 1
2006-11-10 12:47:48.1529 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:48.1533 select_time: 1
2006-11-10 12:47:49.1524 select_time: 1
2006-11-10 12:47:50.1549 select_time: 1
2006-11-10 12:47:51.1574 select_time: 0.84260892868042
2006-11-10 12:47:52.0033 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.00316810607910156 late.
2006-11-10 12:47:52.0035 Prevent Standby plugin: starting timer
2006-11-10 12:47:52.0037 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9962849617004 sec
2006-11-10 12:47:52.0039 select_time: 0
2006-11-10 12:47:52.0043 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00428104400634766 late.
2006-11-10 12:47:52.0045 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99546694755554 sec
2006-11-10 12:47:52.0047 select_time: 1
2006-11-10 12:47:53.0057 select_time: 1
2006-11-10 12:47:53.9768 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:47:53.9783 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca950)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:47:53.9787 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca950)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:47:53.9789 Accepted connection 1 from 127.0.0.1
2006-11-10 12:47:53.9791 select_time: 1
2006-11-10 12:47:53.9800 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca950)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:47:53.9837 reading request...
2006-11-10 12:47:53.9841 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x52ca950)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:47:53.9858 Bad Request: [head /status_header.html]
2006-11-10 12:47:53.9862 generating from html/errors/405.html
2006-11-10 12:47:53.9889 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:47:54.9993 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca950)] Removing read
2006-11-10 12:47:54.9996 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca950)] Removing write
2006-11-10 12:47:54.9998 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca950)] Removing error
2006-11-10 12:47:54.0004 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x52ca950) on connection = close

2006-11-10 12:47:54.0010 select_time: 1
2006-11-10 12:47:55.0107 select_time: 1
2006-11-10 12:47:56.0132 select_time: 0.986771106719971
2006-11-10 12:47:56.0000 select_time: 0
2006-11-10 12:47:56.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000457048416137695 late.
2006-11-10 12:47:56.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99904704093933 sec
2006-11-10 12:47:56.0012 select_time: 1
2006-11-10 12:47:58.0025 select_time: 1
2006-11-10 12:47:58.1713 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:58.1718 select_time: 1
2006-11-10 12:47:58.1722 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:47:58.1726 select_time: 1
2006-11-10 12:47:59.1773 select_time: 1
2006-11-10 12:47:59.6095 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:47:59.6099 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:47:59.6101 It's a Squeezebox
2006-11-10 12:47:59.6103  calculated destruction length: 17
2006-11-10 12:47:59.6106 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:47:59.6110 select_time: 1
2006-11-10 12:48:00.6184 select_time: 0.351806163787842
2006-11-10 12:48:00.9710 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.000651836395263672 late.
2006-11-10 12:48:00.9713 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999830722809 sec
2006-11-10 12:48:00.9871 select_time: 0
2006-11-10 12:48:00.9876 [norm] firing Plugins::Rescan::checkScanTimer 0.00755500793457031 late.
2006-11-10 12:48:00.9878 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999868869781 sec
2006-11-10 12:48:00.9880 select_time: 0.0119369029998779
2006-11-10 12:48:00.0002 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00015711784362793 late.
2006-11-10 12:48:00.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99946188926697 sec
2006-11-10 12:48:00.0008 select_time: 1
2006-11-10 12:48:01.9969 select_time: 1
2006-11-10 12:48:02.9994 select_time: 1
2006-11-10 12:48:04.0019 select_time: 0.998130083084106
2006-11-10 12:48:05.0044 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0042879581451416 late.
2006-11-10 12:48:05.0047 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.995285987854 sec
2006-11-10 12:48:05.0050 select_time: 1
2006-11-10 12:48:06.0068 select_time: 1
2006-11-10 12:48:07.0093 select_time: 1
2006-11-10 12:48:08.0118 select_time: 1
2006-11-10 12:48:08.1958 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:08.1964 select_time: 1
2006-11-10 12:48:08.1968 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:08.1973 select_time: 1
2006-11-10 12:48:09.2023 select_time: 0.797681093215942
2006-11-10 12:48:10.0012 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00110411643981934 late.
2006-11-10 12:48:10.0015 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99848198890686 sec
2006-11-10 12:48:10.0018 select_time: 1
2006-11-10 12:48:11.0037 select_time: 1
2006-11-10 12:48:12.0062 select_time: 1
2006-11-10 12:48:13.0087 select_time: 1
2006-11-10 12:48:14.0112 select_time: 0.988830089569092
2006-11-10 12:48:15.0137 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0135838985443115 late.
2006-11-10 12:48:15.0140 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98600101470947 sec
2006-11-10 12:48:15.0142 select_time: 1
2006-11-10 12:48:16.0161 select_time: 1
2006-11-10 12:48:17.0186 select_time: 1
2006-11-10 12:48:18.0211 select_time: 1
2006-11-10 12:48:18.2310 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:18.2316 select_time: 1
2006-11-10 12:48:18.2320 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:18.2324 select_time: 1
2006-11-10 12:48:19.2273 select_time: 0.7727210521698
2006-11-10 12:48:20.0105 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0104000568389893 late.
2006-11-10 12:48:20.0108 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98919010162354 sec
2006-11-10 12:48:20.0110 select_time: 1
2006-11-10 12:48:21.0130 select_time: 1
2006-11-10 12:48:22.0155 select_time: 1
2006-11-10 12:48:23.0180 select_time: 1
2006-11-10 12:48:24.0205 select_time: 0.979537010192871
2006-11-10 12:48:25.0073 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00721597671508789 late.
2006-11-10 12:48:25.0076 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99237108230591 sec
2006-11-10 12:48:25.0079 select_time: 1
2006-11-10 12:48:26.0097 select_time: 1
2006-11-10 12:48:27.0123 select_time: 1
2006-11-10 12:48:28.0148 select_time: 1
2006-11-10 12:48:28.2612 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:28.2618 select_time: 1
2006-11-10 12:48:28.2622 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:28.2627 select_time: 1
2006-11-10 12:48:29.2522 select_time: 0.747759103775024
2006-11-10 12:48:30.0041 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00403189659118652 late.
2006-11-10 12:48:30.0044 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99555492401123 sec
2006-11-10 12:48:30.0047 select_time: 1
2006-11-10 12:48:31.0066 select_time: 1
2006-11-10 12:48:32.0091 select_time: 1
2006-11-10 12:48:33.0116 select_time: 1
2006-11-10 12:48:34.0141 select_time: 0.985907077789307
2006-11-10 12:48:35.0166 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0165119171142578 late.
2006-11-10 12:48:35.0169 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98306202888489 sec
2006-11-10 12:48:35.0172 select_time: 1
2006-11-10 12:48:36.0191 select_time: 1
2006-11-10 12:48:37.0216 select_time: 1
2006-11-10 12:48:38.0241 select_time: 1
2006-11-10 12:48:38.2818 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.2824 select_time: 1
2006-11-10 12:48:38.2828 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.2832 select_time: 1
2006-11-10 12:48:38.7602 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7610 select_time: 1
2006-11-10 12:48:38.7616 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7624 select_time: 1
2006-11-10 12:48:38.7629 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7636 select_time: 1
2006-11-10 12:48:38.7640 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7647 select_time: 1
2006-11-10 12:48:38.7652 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7659 select_time: 1
2006-11-10 12:48:38.7663 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7671 select_time: 1
2006-11-10 12:48:38.7675 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7681 select_time: 1
2006-11-10 12:48:38.7687 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7692 select_time: 1
2006-11-10 12:48:38.7698 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7704 select_time: 1
2006-11-10 12:48:38.7710 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7716 select_time: 1
2006-11-10 12:48:38.7720 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:38.7725 select_time: 1
2006-11-10 12:48:39.7627 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:48:39.7631 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:48:39.7632 It's a Squeezebox
2006-11-10 12:48:39.7634  calculated destruction length: 17
2006-11-10 12:48:39.7637 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:48:39.7641 select_time: 0.23589301109314
2006-11-10 12:48:39.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000523090362548828 late.
2006-11-10 12:48:39.0009 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99905610084534 sec
2006-11-10 12:48:39.0012 select_time: 1
2006-11-10 12:48:41.0002 select_time: 1
2006-11-10 12:48:42.0027 select_time: 1
2006-11-10 12:48:43.0052 select_time: 0.994770050048828
2006-11-10 12:48:44.0077 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00764799118041992 late.
2006-11-10 12:48:44.0081 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99191689491272 sec
2006-11-10 12:48:44.0083 select_time: 1
2006-11-10 12:48:45.0102 select_time: 1
2006-11-10 12:48:46.0127 select_time: 1
2006-11-10 12:48:47.0152 select_time: 1
2006-11-10 12:48:48.0177 select_time: 0.98228907585144
2006-11-10 12:48:48.3013 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:48.3019 select_time: 0.69807505607605
2006-11-10 12:48:48.3023 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:48.3028 select_time: 0.697227954864502
2006-11-10 12:48:49.0045 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00446391105651855 late.
2006-11-10 12:48:49.0049 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99511003494263 sec
2006-11-10 12:48:49.0051 select_time: 1
2006-11-10 12:48:50.0070 select_time: 1
2006-11-10 12:48:51.0095 select_time: 0.990463972091675
2006-11-10 12:48:51.9964 select_time: 0.00363302230834961
2006-11-10 12:48:52.0002 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.000127077102661133 late.
2006-11-10 12:48:52.0005 Prevent Standby plugin: starting timer
2006-11-10 12:48:52.0006 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.999351978302 sec
2006-11-10 12:48:52.0009 select_time: 1
2006-11-10 12:48:53.0145 select_time: 0.985471963882446
2006-11-10 12:48:54.0014 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00128006935119629 late.
2006-11-10 12:48:54.0017 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99829411506653 sec
2006-11-10 12:48:54.0020 select_time: 1
2006-11-10 12:48:54.1588 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:48:54.1603 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:48:54.1607 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:48:54.1609 Accepted connection 1 from 127.0.0.1
2006-11-10 12:48:54.1612 select_time: 1
2006-11-10 12:48:54.1624 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:48:54.1647 reading request...
2006-11-10 12:48:54.1651 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:48:54.1668 Bad Request: [head /status_header.html]
2006-11-10 12:48:54.1673 generating from html/errors/405.html
2006-11-10 12:48:54.1700 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:48:54.1798 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)] Removing read
2006-11-10 12:48:54.1802 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)] Removing write
2006-11-10 12:48:54.1805 Select: [HTTP::Daemon::ClientConn=GLOB(0x4fd63a8)] Removing error
2006-11-10 12:48:54.1810 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x4fd63a8) on connection = close

2006-11-10 12:48:54.1817 select_time: 1
2006-11-10 12:48:55.1761 select_time: 1
2006-11-10 12:48:56.1786 select_time: 1
2006-11-10 12:48:57.1811 select_time: 1
2006-11-10 12:48:58.1836 select_time: 0.81635308265686
2006-11-10 12:48:58.3222 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:58.3228 select_time: 0.677175045013428
2006-11-10 12:48:58.3232 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:48:58.3237 select_time: 0.676321983337402
2006-11-10 12:48:59.0138 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0137600898742676 late.
2006-11-10 12:48:59.0142 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98580098152161 sec
2006-11-10 12:48:59.0145 select_time: 0.759570121765137
2006-11-10 12:48:59.7657 select_time: 0.00834012031555176
2006-11-10 12:48:59.7745 [norm] firing Plugins::xPL::sendxplhbeat 0.00033879280090332 late.
2006-11-10 12:48:59.7749 [norm] set Plugins::xPL::sendxplhbeat, in 299.999980926514 sec
2006-11-10 12:48:59.7751 select_time: 1
2006-11-10 12:49:00.7839 select_time: 0.18744421005249
2006-11-10 12:49:00.9713 select_time: 0
2006-11-10 12:49:00.9718 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.000456809997558594 late.
2006-11-10 12:49:00.9721 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999799728394 sec
2006-11-10 12:49:00.9724 select_time: 0.0153908729553223
2006-11-10 12:49:00.9879 [norm] firing Plugins::Rescan::checkScanTimer 6.60419464111328e-005 late.
2006-11-10 12:49:00.9883 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999840259552 sec
2006-11-10 12:49:00.9886 select_time: 1
2006-11-10 12:49:01.9900 select_time: 1
2006-11-10 12:49:02.9925 select_time: 1
2006-11-10 12:49:03.9950 select_time: 0.00501108169555664
2006-11-10 12:49:04.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000746965408325195 late.
2006-11-10 12:49:04.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99883008003235 sec
2006-11-10 12:49:04.0014 select_time: 1
2006-11-10 12:49:05.0131 select_time: 1
2006-11-10 12:49:06.0156 select_time: 1
2006-11-10 12:49:07.0181 select_time: 1
2006-11-10 12:49:08.0206 select_time: 0.979363918304443
2006-11-10 12:49:08.3530 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:08.3536 select_time: 0.646395921707153
2006-11-10 12:49:08.3540 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:08.3545 select_time: 0.645481109619141
2006-11-10 12:49:08.9918 select_time: 0.00819492340087891
2006-11-10 12:49:09.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000540018081665039 late.
2006-11-10 12:49:09.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99903106689453 sec
2006-11-10 12:49:09.0012 select_time: 1
2006-11-10 12:49:10.0099 select_time: 1
2006-11-10 12:49:11.0124 select_time: 1
2006-11-10 12:49:12.0149 select_time: 1
2006-11-10 12:49:13.0174 select_time: 0.982546091079712
2006-11-10 12:49:14.0043 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00420808792114258 late.
2006-11-10 12:49:14.0046 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99536609649658 sec
2006-11-10 12:49:14.0049 select_time: 1
2006-11-10 12:49:15.0068 select_time: 1
2006-11-10 12:49:16.0093 select_time: 1
2006-11-10 12:49:17.0118 select_time: 1
2006-11-10 12:49:18.0143 select_time: 0.985733032226563
2006-11-10 12:49:18.3735 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:18.3741 select_time: 0.625900030136108
2006-11-10 12:49:18.3746 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:18.3750 select_time: 0.624947071075439
2006-11-10 12:49:19.0011 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00102400779724121 late.
2006-11-10 12:49:19.0015 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99853897094727 sec
2006-11-10 12:49:19.0017 select_time: 1
2006-11-10 12:49:19.9095 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:49:19.9099 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:49:19.9101 It's a Squeezebox
2006-11-10 12:49:19.9102  calculated destruction length: 17
2006-11-10 12:49:19.9106 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:49:19.9113 select_time: 1
2006-11-10 12:49:20.9121 select_time: 1
2006-11-10 12:49:21.9146 select_time: 1
2006-11-10 12:49:22.9171 select_time: 1
2006-11-10 12:49:23.9196 select_time: 0.0804018974304199
2006-11-10 12:49:24.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000559091567993164 late.
2006-11-10 12:49:24.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.9990119934082 sec
2006-11-10 12:49:24.0012 select_time: 1
2006-11-10 12:49:25.0161 select_time: 1
2006-11-10 12:49:26.0186 select_time: 1
2006-11-10 12:49:27.0210 select_time: 1
2006-11-10 12:49:28.0236 select_time: 0.976430892944336
2006-11-10 12:49:28.4028 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:28.4040 select_time: 0.596030950546265
2006-11-10 12:49:28.4046 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:28.4051 select_time: 0.594939947128296
2006-11-10 12:49:28.9947 select_time: 0.0052640438079834
2006-11-10 12:49:29.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000475883483886719 late.
2006-11-10 12:49:29.0009 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99910807609558 sec
2006-11-10 12:49:29.0012 select_time: 1
2006-11-10 12:49:30.0129 select_time: 1
2006-11-10 12:49:31.0154 select_time: 1
2006-11-10 12:49:32.0179 select_time: 1
2006-11-10 12:49:33.0204 select_time: 0.979618072509766
2006-11-10 12:49:33.9915 select_time: 0.00845003128051758
2006-11-10 12:49:34.0003 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000267982482910156 late.
2006-11-10 12:49:34.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99930500984192 sec
2006-11-10 12:49:34.0010 select_time: 1
2006-11-10 12:49:35.0097 select_time: 1
2006-11-10 12:49:36.0122 select_time: 1
2006-11-10 12:49:37.0147 select_time: 1
2006-11-10 12:49:38.0172 select_time: 0.982803106307983
2006-11-10 12:49:38.4253 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.4259 select_time: 0.574096918106079
2006-11-10 12:49:38.4264 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.4270 select_time: 0.572963953018188
2006-11-10 12:49:38.9412 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9423 select_time: 0.0577189922332764
2006-11-10 12:49:38.9428 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9435 select_time: 0.0564579963684082
2006-11-10 12:49:38.9440 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9449 select_time: 0.0550870895385742
2006-11-10 12:49:38.9454 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9462 select_time: 0.0537729263305664
2006-11-10 12:49:38.9467 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9474 select_time: 0.0525450706481934
2006-11-10 12:49:38.9479 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9488 select_time: 0.0511479377746582
2006-11-10 12:49:38.9493 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9501 select_time: 0.0498650074005127
2006-11-10 12:49:38.9506 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9514 select_time: 0.0485789775848389
2006-11-10 12:49:38.9519 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9528 select_time: 0.0472300052642822
2006-11-10 12:49:38.9532 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9540 select_time: 0.0459589958190918
2006-11-10 12:49:38.9545 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:38.9552 select_time: 0.0448050498962402
2006-11-10 12:49:39.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00032496452331543 late.
2006-11-10 12:49:39.0008 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99923396110535 sec
2006-11-10 12:49:39.0010 select_time: 1
2006-11-10 12:49:40.0065 select_time: 1
2006-11-10 12:49:41.0090 select_time: 1
2006-11-10 12:49:42.0115 select_time: 1
2006-11-10 12:49:43.0140 select_time: 0.985985994338989
2006-11-10 12:49:44.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000767946243286133 late.
2006-11-10 12:49:44.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99877595901489 sec
2006-11-10 12:49:44.0015 select_time: 1
2006-11-10 12:49:45.0033 select_time: 1
2006-11-10 12:49:46.0058 select_time: 1
2006-11-10 12:49:47.0083 select_time: 1
2006-11-10 12:49:48.0108 select_time: 0.989171028137207
2006-11-10 12:49:48.4418 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:48.4425 select_time: 0.557533979415894
2006-11-10 12:49:48.4429 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:48.4434 select_time: 0.556577920913696
2006-11-10 12:49:49.0133 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0132479667663574 late.
2006-11-10 12:49:49.0137 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98630595207214 sec
2006-11-10 12:49:49.0140 select_time: 1
2006-11-10 12:49:50.0158 select_time: 1
2006-11-10 12:49:51.0183 select_time: 0.981683969497681
2006-11-10 12:49:52.0051 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.00507211685180664 late.
2006-11-10 12:49:52.0055 Prevent Standby plugin: starting timer
2006-11-10 12:49:52.0057 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9942989349365 sec
2006-11-10 12:49:52.0065 select_time: 1
2006-11-10 12:49:53.0076 select_time: 0.992355108261108
2006-11-10 12:49:53.9945 select_time: 0.00552201271057129
2006-11-10 12:49:54.0002 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000176906585693359 late.
2006-11-10 12:49:54.0006 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99942803382874 sec
2006-11-10 12:49:54.0008 select_time: 1
2006-11-10 12:49:54.3403 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:49:54.3417 Select: [HTTP::Daemon::ClientConn=GLOB(0x5043588)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:49:54.3422 Select: [HTTP::Daemon::ClientConn=GLOB(0x5043588)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:49:54.3424 Accepted connection 1 from 127.0.0.1
2006-11-10 12:49:54.3427 select_time: 1
2006-11-10 12:49:54.3438 Select: [HTTP::Daemon::ClientConn=GLOB(0x5043588)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:49:54.3468 reading request...
2006-11-10 12:49:54.3474 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5043588)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:49:54.3490 Bad Request: [head /status_header.html]
2006-11-10 12:49:54.3495 generating from html/errors/405.html
2006-11-10 12:49:54.3524 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:49:54.3617 Select: [HTTP::Daemon::ClientConn=GLOB(0x5043588)] Removing read
2006-11-10 12:49:54.3621 Select: [HTTP::Daemon::ClientConn=GLOB(0x5043588)] Removing write
2006-11-10 12:49:54.3626 Select: [HTTP::Daemon::ClientConn=GLOB(0x5043588)] Removing error
2006-11-10 12:49:54.3632 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5043588) on connection = close

2006-11-10 12:49:54.3639 select_time: 1
2006-11-10 12:49:55.3729 select_time: 1
2006-11-10 12:49:56.3754 select_time: 1
2006-11-10 12:49:57.3778 select_time: 1
2006-11-10 12:49:58.3804 select_time: 0.619600057601929
2006-11-10 12:49:58.4740 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:58.4747 select_time: 0.525315046310425
2006-11-10 12:49:58.4752 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:49:58.4757 select_time: 0.5242919921875
2006-11-10 12:49:59.0070 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00688004493713379 late.
2006-11-10 12:49:59.0073 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99266505241394 sec
2006-11-10 12:49:59.0076 select_time: 1
2006-11-10 12:50:00.0094 select_time: 0.962641000747681
2006-11-10 12:50:00.0696 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:50:00.0707 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:50:00.0711 It's a Squeezebox
2006-11-10 12:50:00.0713  calculated destruction length: 17
2006-11-10 12:50:00.0718 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:50:00.0722 select_time: 0.89989185333252
2006-11-10 12:50:00.9650 select_time: 0.00713896751403809
2006-11-10 12:50:00.9728 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.000589132308959961 late.
2006-11-10 12:50:00.9732 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999830722809 sec
2006-11-10 12:50:00.9735 select_time: 0.0148169994354248
2006-11-10 12:50:00.9894 [norm] firing Plugins::Rescan::checkScanTimer 0.001007080078125 late.
2006-11-10 12:50:00.9898 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999830722809 sec
2006-11-10 12:50:00.9901 select_time: 1
2006-11-10 12:50:01.9988 select_time: 1
2006-11-10 12:50:03.0013 select_time: 0.998723030090332
2006-11-10 12:50:04.0038 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00369596481323242 late.
2006-11-10 12:50:04.0042 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99583911895752 sec
2006-11-10 12:50:04.0045 select_time: 1
2006-11-10 12:50:05.0063 select_time: 1
2006-11-10 12:50:06.0087 select_time: 1
2006-11-10 12:50:07.0112 select_time: 1
2006-11-10 12:50:08.0138 select_time: 0.986242055892944
2006-11-10 12:50:08.5004 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:08.5011 select_time: 0.498927116394043
2006-11-10 12:50:08.5015 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:08.5020 select_time: 0.497960090637207
2006-11-10 12:50:09.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000511884689331055 late.
2006-11-10 12:50:09.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99902701377869 sec
2006-11-10 12:50:09.0013 select_time: 1
2006-11-10 12:50:10.0031 select_time: 1
2006-11-10 12:50:11.0056 select_time: 1
2006-11-10 12:50:12.0081 select_time: 1
2006-11-10 12:50:13.0106 select_time: 0.989425897598267
2006-11-10 12:50:13.9974 select_time: 0.00259208679199219
2006-11-10 12:50:14.0002 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000178098678588867 late.
2006-11-10 12:50:14.0006 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99942708015442 sec
2006-11-10 12:50:14.0009 select_time: 1
2006-11-10 12:50:15.0156 select_time: 1
2006-11-10 12:50:16.0180 select_time: 1
2006-11-10 12:50:17.0205 select_time: 1
2006-11-10 12:50:18.0230 select_time: 0.976946115493774
2006-11-10 12:50:18.5242 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:18.5248 select_time: 0.475157022476196
2006-11-10 12:50:18.5253 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:18.5258 select_time: 0.474191904067993
2006-11-10 12:50:19.0009 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000821113586425781 late.
2006-11-10 12:50:19.0013 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99872994422913 sec
2006-11-10 12:50:19.0016 select_time: 1
2006-11-10 12:50:20.0124 select_time: 1
2006-11-10 12:50:21.0149 select_time: 1
2006-11-10 12:50:22.0174 select_time: 1
2006-11-10 12:50:23.0199 select_time: 0.98012900352478
2006-11-10 12:50:23.9910 select_time: 0.00896191596984863
2006-11-10 12:50:24.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000684022903442383 late.
2006-11-10 12:50:24.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99886894226074 sec
2006-11-10 12:50:24.0014 select_time: 1
2006-11-10 12:50:25.0092 select_time: 1
2006-11-10 12:50:26.0117 select_time: 1
2006-11-10 12:50:26.4760 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:26.4768 UPnP: Notify from new device [uuid:3514bc79-19a2-4e5f-8585-2e61fabfeab0::upnp:rootdevice at http://192.168.13.100:50515/]
2006-11-10 12:50:26.4772 SimpleAsyncHTTP: GETing http://192.168.13.100:50515/
2006-11-10 12:50:26.4792 Async: Connecting to 192.168.13.100:50515
2006-11-10 12:50:26.4828 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:50:26.4833 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:50:26.4836 [norm] set Slim::Networking::Async::_connect_error, in 4.99997520446777 sec
2006-11-10 12:50:26.4840 select_time: 1
2006-11-10 12:50:26.4845 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:26.4851 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:50:26.4856 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244) / Slim::Networking::Async::_connect_error
2006-11-10 12:50:26.4861 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing error
2006-11-10 12:50:26.4865 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing write
2006-11-10 12:50:26.4867 Async: connected, ready to write request
2006-11-10 12:50:26.4876 Async: Sending:
GET / HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.13.100:50515

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:50:26.4885 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:50:26.4890 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:50:26.4894 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Wrote 242 bytes
2006-11-10 12:50:26.4901 [norm] set Slim::Networking::Async::_async_error, in 4.99989914894104 sec
2006-11-10 12:50:26.4909 select_time: 1
2006-11-10 12:50:26.4914 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:50:26.4920 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244) / Slim::Networking::Async::_async_error
2006-11-10 12:50:26.4930 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing error
2006-11-10 12:50:26.4934 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing read
2006-11-10 12:50:26.4943 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:50:26.4955 bless({
  "content-length" => 1713,
  "content-type" => "text/xml ; charset=\"utf-8\"",
  date => "Fri, 10 Nov 2006 17:50:27 GMT",
  server => "WINDOWS/5.1 UPnP/1.0 UPnP-Device-Host/1.0 NeroMediaHome/1.4.0.15",
}, "HTTP::Headers")
2006-11-10 12:50:26.4961 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997496604919 sec
2006-11-10 12:50:26.4967 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:50:26.4971 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:50:26.4975 select_time: 1
2006-11-10 12:50:26.4981 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:50:26.4987 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:50:26.4993 Async::HTTP: Read body: 830 bytes
2006-11-10 12:50:26.4997 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997997283936 sec
2006-11-10 12:50:26.5001 select_time: 1
2006-11-10 12:50:26.5005 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:50:26.5012 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:50:26.5016 Async::HTTP: Read body: 883 bytes
2006-11-10 12:50:26.5021 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997711181641 sec
2006-11-10 12:50:26.5025 select_time: 1
2006-11-10 12:50:26.5029 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:50:26.5036 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:50:26.5042 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing error
2006-11-10 12:50:26.5045 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing read
2006-11-10 12:50:26.5048 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] Removing write
2006-11-10 12:50:26.5051 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a4244)] removing writeNoBlock queue
2006-11-10 12:50:26.5055 Async::HTTP: Body read
2006-11-10 12:50:26.5061 SimpleAsyncHTTP: status for http://192.168.13.100:50515/ is 200 OK
2006-11-10 12:50:26.5066 SimpleAsyncHTTP: Done
2006-11-10 12:50:26.5072 UPnP: New device found: Nero MediaHome (nyghtmare) [http://192.168.13.100:50515/]
2006-11-10 12:50:26.5077 UPnP: Adding new media server: Nero MediaHome (nyghtmare)
2006-11-10 12:50:26.5129 [norm] set Slim::Utils::UPnPMediaServer::checkServerHealth, in 59.487135887146 sec
2006-11-10 12:50:26.5147 select_time: 1
2006-11-10 12:50:26.6417 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:26.6424 select_time: 1
2006-11-10 12:50:26.8370 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:26.8377 select_time: 1
2006-11-10 12:50:26.8535 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:26.8543 select_time: 1
2006-11-10 12:50:27.8600 select_time: 1
2006-11-10 12:50:27.9111 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:27.9119 select_time: 1
2006-11-10 12:50:27.9124 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:27.9136 select_time: 1
2006-11-10 12:50:27.9452 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:27.9461 select_time: 1
2006-11-10 12:50:28.0059 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:28.0067 select_time: 0.993336915969849
2006-11-10 12:50:28.1982 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:28.1990 select_time: 0.801028966903687
2006-11-10 12:50:28.5491 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:28.5498 select_time: 0.450186967849731
2006-11-10 12:50:28.5503 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:28.5508 select_time: 0.449137926101685
2006-11-10 12:50:29.0000 select_time: 2.69412994384766e-005
2006-11-10 12:50:29.0010 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000951051712036133 late.
2006-11-10 12:50:29.0014 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99861598014832 sec
2006-11-10 12:50:29.0017 select_time: 1
2006-11-10 12:50:30.0060 select_time: 1
2006-11-10 12:50:31.0085 select_time: 1
2006-11-10 12:50:32.0110 select_time: 1
2006-11-10 12:50:33.0135 select_time: 0.986496925354004
2006-11-10 12:50:34.0003 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000256061553955078 late.
2006-11-10 12:50:34.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99926495552063 sec
2006-11-10 12:50:34.0010 select_time: 1
2006-11-10 12:50:35.0028 select_time: 1
2006-11-10 12:50:36.0053 select_time: 1
2006-11-10 12:50:37.0078 select_time: 1
2006-11-10 12:50:38.0103 select_time: 0.98968505859375
2006-11-10 12:50:38.5741 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:38.5747 select_time: 0.425246000289917
2006-11-10 12:50:38.5752 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:38.5758 select_time: 0.424232959747314
2006-11-10 12:50:38.0011 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0010230541229248 late.
2006-11-10 12:50:38.0015 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99851202964783 sec
2006-11-10 12:50:38.0018 select_time: 1
2006-11-10 12:50:39.1380 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1389 select_time: 1
2006-11-10 12:50:39.1395 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1403 select_time: 1
2006-11-10 12:50:39.1411 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1419 select_time: 1
2006-11-10 12:50:39.1434 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1442 select_time: 1
2006-11-10 12:50:39.1449 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1456 select_time: 1
2006-11-10 12:50:39.1462 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1469 select_time: 1
2006-11-10 12:50:39.1477 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1485 select_time: 1
2006-11-10 12:50:39.1490 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1499 select_time: 1
2006-11-10 12:50:39.1504 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1512 select_time: 1
2006-11-10 12:50:39.1518 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1526 select_time: 1
2006-11-10 12:50:39.1531 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:39.1537 select_time: 1
2006-11-10 12:50:40.1563 select_time: 1
2006-11-10 12:50:40.2112 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:50:40.2116 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:50:40.2118 It's a Squeezebox
2006-11-10 12:50:40.2120  calculated destruction length: 17
2006-11-10 12:50:40.2125 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:50:40.2129 select_time: 1
2006-11-10 12:50:41.2214 select_time: 1
2006-11-10 12:50:42.2239 select_time: 0.776065111160278
2006-11-10 12:50:43.0071 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00705599784851074 late.
2006-11-10 12:50:43.0075 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99246191978455 sec
2006-11-10 12:50:43.0080 select_time: 1
2006-11-10 12:50:44.0096 select_time: 1
2006-11-10 12:50:45.0121 select_time: 1
2006-11-10 12:50:46.0146 select_time: 1
2006-11-10 12:50:47.0171 select_time: 0.982880115509033
2006-11-10 12:50:48.0039 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00387191772460938 late.
2006-11-10 12:50:48.0043 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99565696716309 sec
2006-11-10 12:50:48.0046 select_time: 1
2006-11-10 12:50:48.5991 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:48.5998 select_time: 1
2006-11-10 12:50:48.6003 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:48.6008 select_time: 1
2006-11-10 12:50:49.6017 select_time: 1
2006-11-10 12:50:50.6042 select_time: 1
2006-11-10 12:50:51.6067 select_time: 0.393330097198486
2006-11-10 12:50:51.0006 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.000538110733032227 late.
2006-11-10 12:50:51.0010 Prevent Standby plugin: starting timer
2006-11-10 12:50:51.0012 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 58.9987959861755 sec
2006-11-10 12:50:51.0015 select_time: 0.998449087142944
2006-11-10 12:50:53.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000688076019287109 late.
2006-11-10 12:50:53.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99884104728699 sec
2006-11-10 12:50:53.0015 select_time: 1
2006-11-10 12:50:54.0189 select_time: 1
2006-11-10 12:50:54.5200 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:50:54.5215 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca44c)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:50:54.5221 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca44c)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:50:54.5224 Accepted connection 1 from 127.0.0.1
2006-11-10 12:50:54.5228 select_time: 1
2006-11-10 12:50:54.5239 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca44c)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:50:54.5262 reading request...
2006-11-10 12:50:54.5267 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x52ca44c)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:50:54.5284 Bad Request: [head /status_header.html]
2006-11-10 12:50:54.5289 generating from html/errors/405.html
2006-11-10 12:50:54.5316 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:50:54.5414 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca44c)] Removing read
2006-11-10 12:50:54.5418 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca44c)] Removing write
2006-11-10 12:50:54.5422 Select: [HTTP::Daemon::ClientConn=GLOB(0x52ca44c)] Removing error
2006-11-10 12:50:54.5429 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x52ca44c) on connection = close

2006-11-10 12:50:54.5437 select_time: 1
2006-11-10 12:50:55.5540 select_time: 1
2006-11-10 12:50:56.5565 select_time: 1
2006-11-10 12:50:57.5590 select_time: 0.44101095199585
2006-11-10 12:50:57.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000335931777954102 late.
2006-11-10 12:50:57.0008 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99919199943542 sec
2006-11-10 12:50:57.0012 select_time: 1
2006-11-10 12:50:58.6240 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:58.6241 select_time: 1
2006-11-10 12:50:58.6247 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:50:58.6252 select_time: 1
2006-11-10 12:50:59.6266 select_time: 1
2006-11-10 12:51:00.6291 select_time: 0.344008922576904
2006-11-10 12:51:00.9739 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.000638961791992188 late.
2006-11-10 12:51:00.9743 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999830722809 sec
2006-11-10 12:51:00.9746 select_time: 0.015146017074585
2006-11-10 12:51:00.9905 [norm] firing Plugins::Rescan::checkScanTimer 0.000619888305664063 late.
2006-11-10 12:51:00.9909 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999821186066 sec
2006-11-10 12:51:00.9912 select_time: 1
2006-11-10 12:51:01.9919 select_time: 0.00809693336486816
2006-11-10 12:51:02.0007 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000605106353759766 late.
2006-11-10 12:51:02.0011 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99892592430115 sec
2006-11-10 12:51:02.0014 select_time: 1
2006-11-10 12:51:03.0100 select_time: 1
2006-11-10 12:51:04.0125 select_time: 1
2006-11-10 12:51:05.0150 select_time: 1
2006-11-10 12:51:06.0175 select_time: 0.982449054718018
2006-11-10 12:51:07.0044 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00430393218994141 late.
2006-11-10 12:51:07.0048 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99522399902344 sec
2006-11-10 12:51:07.0051 select_time: 1
2006-11-10 12:51:08.0069 select_time: 1
2006-11-10 12:51:08.6490 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:08.6496 select_time: 1
2006-11-10 12:51:08.6501 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:08.6507 select_time: 1
2006-11-10 12:51:09.6516 select_time: 1
2006-11-10 12:51:10.6541 select_time: 1
2006-11-10 12:51:11.6566 select_time: 0.343410015106201
2006-11-10 12:51:12.0003 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000256061553955078 late.
2006-11-10 12:51:12.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99926710128784 sec
2006-11-10 12:51:12.0010 select_time: 1
2006-11-10 12:51:13.0037 select_time: 1
2006-11-10 12:51:13.8181 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:13.8189 select_time: 1
2006-11-10 12:51:13.8196 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:13.8203 select_time: 1
2006-11-10 12:51:13.8385 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:13.8393 select_time: 1
2006-11-10 12:51:13.8402 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:13.8409 select_time: 1
2006-11-10 12:51:13.8585 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:13.8595 select_time: 1
2006-11-10 12:51:13.8601 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:13.8607 select_time: 1
2006-11-10 12:51:14.8677 select_time: 1
2006-11-10 12:51:15.8231 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:15.8238 select_time: 1
2006-11-10 12:51:15.8246 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:15.8253 select_time: 1
2006-11-10 12:51:15.8434 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:15.8442 select_time: 1
2006-11-10 12:51:15.8451 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:15.8459 select_time: 1
2006-11-10 12:51:15.8636 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:15.8644 select_time: 1
2006-11-10 12:51:15.8659 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:15.8667 select_time: 1
2006-11-10 12:51:16.8727 select_time: 0.12729811668396
2006-11-10 12:51:16.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000549077987670898 late.
2006-11-10 12:51:16.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.9989800453186 sec
2006-11-10 12:51:16.0013 select_time: 1
2006-11-10 12:51:18.0005 select_time: 1
2006-11-10 12:51:18.6739 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:18.6746 select_time: 1
2006-11-10 12:51:18.6752 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:18.6758 select_time: 1
2006-11-10 12:51:19.6765 select_time: 1
2006-11-10 12:51:20.3656 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:51:20.3661 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:51:20.3663 It's a Squeezebox
2006-11-10 12:51:20.3666  calculated destruction length: 17
2006-11-10 12:51:20.3670 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:51:20.3674 select_time: 0.632543087005615
2006-11-10 12:51:21.0080 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0079200267791748 late.
2006-11-10 12:51:21.0084 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.9916079044342 sec
2006-11-10 12:51:21.0087 select_time: 1
2006-11-10 12:51:22.0105 select_time: 1
2006-11-10 12:51:23.0130 select_time: 1
2006-11-10 12:51:24.0155 select_time: 1
2006-11-10 12:51:25.0180 select_time: 0.982017040252686
2006-11-10 12:51:26.0048 [norm] firing Slim::Utils::UPnPMediaServer::checkServerHealth 0.00473594665527344 late.
2006-11-10 12:51:26.0053 SimpleAsyncHTTP: GETing http://192.168.13.100:50515/
2006-11-10 12:51:26.0072 Async: Connecting to 192.168.13.100:50515
2006-11-10 12:51:26.0105 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:51:26.0109 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:51:26.0112 [norm] set Slim::Networking::Async::_connect_error, in 4.99997496604919 sec
2006-11-10 12:51:26.0116 select_time: 0
2006-11-10 12:51:26.0121 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:51:26.0126 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc) / Slim::Networking::Async::_connect_error
2006-11-10 12:51:26.0131 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing error
2006-11-10 12:51:26.0135 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing write
2006-11-10 12:51:26.0137 Async: connected, ready to write request
2006-11-10 12:51:26.0145 Async: Sending:
GET / HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.13.100:50515

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:51:26.0152 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:51:26.0157 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:51:26.0161 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Wrote 242 bytes
2006-11-10 12:51:26.0167 [norm] set Slim::Networking::Async::_async_error, in 4.99990200996399 sec
2006-11-10 12:51:26.0174 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0170888900756836 late.
2006-11-10 12:51:26.0178 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.98218393325806 sec
2006-11-10 12:51:26.0181 select_time: 1
2006-11-10 12:51:26.0186 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:51:26.0191 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc) / Slim::Networking::Async::_async_error
2006-11-10 12:51:26.0202 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing error
2006-11-10 12:51:26.0207 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing read
2006-11-10 12:51:26.0214 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:51:26.0225 bless({
  "content-length" => 1713,
  "content-type" => "text/xml ; charset=\"utf-8\"",
  date => "Fri, 10 Nov 2006 17:51:26 GMT",
  server => "WINDOWS/5.1 UPnP/1.0 UPnP-Device-Host/1.0 NeroMediaHome/1.4.0.15",
}, "HTTP::Headers")
2006-11-10 12:51:26.0232 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99992108345032 sec
2006-11-10 12:51:26.0238 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:26.0243 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:26.0247 select_time: 1
2006-11-10 12:51:26.0252 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:26.0257 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:26.0263 Async::HTTP: Read body: 830 bytes
2006-11-10 12:51:26.0267 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:51:26.0271 select_time: 1
2006-11-10 12:51:26.0276 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:26.0283 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:26.0287 Async::HTTP: Read body: 883 bytes
2006-11-10 12:51:26.0292 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997687339783 sec
2006-11-10 12:51:26.0295 select_time: 1
2006-11-10 12:51:26.0300 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:26.0306 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:26.0313 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing error
2006-11-10 12:51:26.0317 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing read
2006-11-10 12:51:26.0320 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] Removing write
2006-11-10 12:51:26.0322 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52a42bc)] removing writeNoBlock queue
2006-11-10 12:51:26.0329 Async::HTTP: Body read
2006-11-10 12:51:26.0333 SimpleAsyncHTTP: status for http://192.168.13.100:50515/ is 200 OK
2006-11-10 12:51:26.0337 SimpleAsyncHTTP: Done
2006-11-10 12:51:26.0341 [norm] set Slim::Utils::UPnPMediaServer::checkServerHealth, in 59.9659481048584 sec
2006-11-10 12:51:26.0353 select_time: 1
2006-11-10 12:51:27.0230 select_time: 1
2006-11-10 12:51:28.0255 select_time: 1
2006-11-10 12:51:28.6832 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:28.6833 select_time: 1
2006-11-10 12:51:28.6838 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:28.6844 select_time: 1
2006-11-10 12:51:29.7015 select_time: 1
2006-11-10 12:51:30.7040 select_time: 0.295983076095581
2006-11-10 12:51:31.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000756978988647461 late.
2006-11-10 12:51:31.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99877905845642 sec
2006-11-10 12:51:31.0015 select_time: 1
2006-11-10 12:51:32.0041 select_time: 1
2006-11-10 12:51:33.0066 select_time: 1
2006-11-10 12:51:34.0091 select_time: 1
2006-11-10 12:51:35.0116 select_time: 0.988384962081909
2006-11-10 12:51:35.9984 select_time: 0.00155305862426758
2006-11-10 12:51:35.0003 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000246047973632813 late.
2006-11-10 12:51:35.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99933791160584 sec
2006-11-10 12:51:35.0010 select_time: 1
2006-11-10 12:51:37.0009 select_time: 1
2006-11-10 12:51:38.0034 select_time: 1
2006-11-10 12:51:38.7239 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:38.7245 select_time: 1
2006-11-10 12:51:38.7250 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:38.7255 select_time: 1
2006-11-10 12:51:39.3348 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3357 select_time: 0.664293050765991
2006-11-10 12:51:39.3362 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3372 select_time: 0.662806034088135
2006-11-10 12:51:39.3377 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3386 select_time: 0.661422967910767
2006-11-10 12:51:39.3391 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3399 select_time: 0.660079002380371
2006-11-10 12:51:39.3408 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3415 select_time: 0.65850305557251
2006-11-10 12:51:39.3421 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3429 select_time: 0.657138109207153
2006-11-10 12:51:39.3435 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3442 select_time: 0.655777931213379
2006-11-10 12:51:39.3450 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3457 select_time: 0.654284954071045
2006-11-10 12:51:39.3464 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3472 select_time: 0.652792930603027
2006-11-10 12:51:39.3477 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3484 select_time: 0.651565074920654
2006-11-10 12:51:39.3489 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:39.3496 select_time: 0.650402069091797
2006-11-10 12:51:40.0084 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00835204124450684 late.
2006-11-10 12:51:40.0088 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99117803573608 sec
2006-11-10 12:51:40.0091 select_time: 1
2006-11-10 12:51:41.0109 select_time: 1
2006-11-10 12:51:42.0134 select_time: 1
2006-11-10 12:51:43.0159 select_time: 1
2006-11-10 12:51:44.0184 select_time: 0.981586933135986
2006-11-10 12:51:45.0052 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00516796112060547 late.
2006-11-10 12:51:45.0057 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99434089660645 sec
2006-11-10 12:51:45.0060 select_time: 1
2006-11-10 12:51:46.0077 select_time: 1
2006-11-10 12:51:47.0102 select_time: 1
2006-11-10 12:51:48.0127 select_time: 1
2006-11-10 12:51:48.7332 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:48.7338 select_time: 1
2006-11-10 12:51:48.7343 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:48.7348 select_time: 1
2006-11-10 12:51:49.7514 select_time: 0.248562097549438
2006-11-10 12:51:50.0005 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000381946563720703 late.
2006-11-10 12:51:50.0008 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99915909767151 sec
2006-11-10 12:51:50.0011 select_time: 0.99883508682251
2006-11-10 12:51:51.0046 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.00447988510131836 late.
2006-11-10 12:51:51.0049 Prevent Standby plugin: starting timer
2006-11-10 12:51:51.0051 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9948489665985 sec
2006-11-10 12:51:51.0056 select_time: 1
2006-11-10 12:51:52.0070 select_time: 1
2006-11-10 12:51:53.0095 select_time: 1
2006-11-10 12:51:54.0120 select_time: 0.987951993942261
2006-11-10 12:51:54.7011 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:51:54.7027 Select: [HTTP::Daemon::ClientConn=GLOB(0x500dfd4)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:51:54.7032 Select: [HTTP::Daemon::ClientConn=GLOB(0x500dfd4)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:51:54.7035 Accepted connection 1 from 127.0.0.1
2006-11-10 12:51:54.7038 select_time: 0.296186923980713
2006-11-10 12:51:54.7047 Select: [HTTP::Daemon::ClientConn=GLOB(0x500dfd4)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:51:54.7073 reading request...
2006-11-10 12:51:54.7078 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x500dfd4)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:51:54.7095 Bad Request: [head /status_header.html]
2006-11-10 12:51:54.7100 generating from html/errors/405.html
2006-11-10 12:51:54.7128 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:51:54.7226 Select: [HTTP::Daemon::ClientConn=GLOB(0x500dfd4)] Removing read
2006-11-10 12:51:54.7230 Select: [HTTP::Daemon::ClientConn=GLOB(0x500dfd4)] Removing write
2006-11-10 12:51:54.7234 Select: [HTTP::Daemon::ClientConn=GLOB(0x500dfd4)] Removing error
2006-11-10 12:51:54.7240 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x500dfd4) on connection = close

2006-11-10 12:51:54.7248 select_time: 0.275233030319214
2006-11-10 12:51:54.0001 [norm] firing Slim::Networking::Slimproto::check_all_clients 2.40802764892578e-005 late.
2006-11-10 12:51:54.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99951195716858 sec
2006-11-10 12:51:54.0008 select_time: 1
2006-11-10 12:51:56.0170 select_time: 1
2006-11-10 12:51:57.0195 select_time: 1
2006-11-10 12:51:58.0220 select_time: 0.97796893119812
2006-11-10 12:51:58.7581 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:58.7582 select_time: 0.241765975952148
2006-11-10 12:51:58.7588 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:58.7593 select_time: 0.24065899848938
2006-11-10 12:51:59.0010 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000889062881469727 late.
2006-11-10 12:51:59.0014 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99864196777344 sec
2006-11-10 12:51:59.0017 select_time: 1
2006-11-10 12:51:59.8076 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8083 UPnP: Notify from new device [uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f at http://192.168.13.98:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f]
2006-11-10 12:51:59.8093 SimpleAsyncHTTP: GETing http://192.168.13.98:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f
2006-11-10 12:51:59.8112 Async: Connecting to 192.168.13.98:2869
2006-11-10 12:51:59.8151 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8156 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8159 [norm] set Slim::Networking::Async::_connect_error, in 4.99997591972351 sec
2006-11-10 12:51:59.8163 select_time: 1
2006-11-10 12:51:59.8167 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8173 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8178 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing error
2006-11-10 12:51:59.8183 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing write
2006-11-10 12:51:59.8186 Async: connected, ready to write request
2006-11-10 12:51:59.8195 Async: Sending:
GET /upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.13.98:2869

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:51:59.8201 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:51:59.8206 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:51:59.8210 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Wrote 311 bytes
2006-11-10 12:51:59.8215 [norm] set Slim::Networking::Async::_async_error, in 4.99990081787109 sec
2006-11-10 12:51:59.8220 select_time: 1
2006-11-10 12:51:59.8230 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8237 UPnP: Notify from new device [uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f at http://192.168.196.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f]
2006-11-10 12:51:59.8242 SimpleAsyncHTTP: GETing http://192.168.196.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f
2006-11-10 12:51:59.8261 Async: Connecting to 192.168.196.1:2869
2006-11-10 12:51:59.8303 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8309 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8312 [norm] set Slim::Networking::Async::_connect_error, in 4.99997401237488 sec
2006-11-10 12:51:59.8317 select_time: 1
2006-11-10 12:51:59.8323 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8330 UPnP: Notify from new device [uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f at http://192.168.111.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f]
2006-11-10 12:51:59.8336 SimpleAsyncHTTP: GETing http://192.168.111.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f
2006-11-10 12:51:59.8354 Async: Connecting to 192.168.111.1:2869
2006-11-10 12:51:59.8408 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8412 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8417 [norm] set Slim::Networking::Async::_connect_error, in 4.99997186660767 sec
2006-11-10 12:51:59.8420 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8427 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8433 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing error
2006-11-10 12:51:59.8438 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing write
2006-11-10 12:51:59.8440 Async: connected, ready to write request
2006-11-10 12:51:59.8448 Async: Sending:
GET /upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.196.1:2869

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:51:59.8455 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:51:59.8459 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:51:59.8464 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Wrote 311 bytes
2006-11-10 12:51:59.8471 [norm] set Slim::Networking::Async::_async_error, in 4.9998939037323 sec
2006-11-10 12:51:59.8476 select_time: 1
2006-11-10 12:51:59.8481 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8487 UPnP: Notify from new device [uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f at http://127.0.0.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f]
2006-11-10 12:51:59.8504 SimpleAsyncHTTP: GETing http://127.0.0.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f
2006-11-10 12:51:59.8538 Async: Connecting to 127.0.0.1:2869
2006-11-10 12:51:59.8574 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8585 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8589 [norm] set Slim::Networking::Async::_connect_error, in 4.99996304512024 sec
2006-11-10 12:51:59.8593 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8599 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8604 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing error
2006-11-10 12:51:59.8607 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing write
2006-11-10 12:51:59.8610 Async: connected, ready to write request
2006-11-10 12:51:59.8620 Async: Sending:
GET /upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.111.1:2869

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:51:59.8627 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:51:59.8631 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:51:59.8635 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Wrote 311 bytes
2006-11-10 12:51:59.8641 [norm] set Slim::Networking::Async::_async_error, in 4.99990200996399 sec
2006-11-10 12:51:59.8645 select_time: 1
2006-11-10 12:51:59.8651 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8659 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:51:59.8666 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::_connect_error
2006-11-10 12:51:59.8671 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing error
2006-11-10 12:51:59.8675 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing write
2006-11-10 12:51:59.8677 Async: connected, ready to write request
2006-11-10 12:51:59.8685 Async: Sending:
GET /upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 127.0.0.1:2869

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:51:59.8692 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:51:59.8698 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:51:59.8702 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Wrote 307 bytes
2006-11-10 12:51:59.8708 [norm] set Slim::Networking::Async::_async_error, in 4.99989795684814 sec
2006-11-10 12:51:59.8712 select_time: 1
2006-11-10 12:51:59.8717 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8724 select_time: 1
2006-11-10 12:51:59.8729 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8736 select_time: 1
2006-11-10 12:51:59.8742 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8749 select_time: 1
2006-11-10 12:51:59.8755 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8762 select_time: 1
2006-11-10 12:51:59.8768 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8775 select_time: 1
2006-11-10 12:51:59.8780 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8788 select_time: 1
2006-11-10 12:51:59.8793 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8799 select_time: 1
2006-11-10 12:51:59.8822 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8832 select_time: 1
2006-11-10 12:51:59.8837 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8846 select_time: 1
2006-11-10 12:51:59.8852 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8860 select_time: 1
2006-11-10 12:51:59.8868 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8875 select_time: 1
2006-11-10 12:51:59.8881 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8889 select_time: 1
2006-11-10 12:51:59.8895 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8907 select_time: 1
2006-11-10 12:51:59.8913 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8920 select_time: 1
2006-11-10 12:51:59.8925 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8932 select_time: 1
2006-11-10 12:51:59.8937 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8945 select_time: 1
2006-11-10 12:51:59.8950 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8957 select_time: 1
2006-11-10 12:51:59.8962 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8969 select_time: 1
2006-11-10 12:51:59.8975 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:51:59.8983 select_time: 1
2006-11-10 12:51:59.9010 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:51:59.9018 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::_async_error
2006-11-10 12:51:59.9029 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing error
2006-11-10 12:51:59.9033 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing read
2006-11-10 12:51:59.9041 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:51:59.9053 bless({
  connection => "close",
  "content-length" => 5566,
  "content-type" => "text/xml",
  date => "Fri, 10 Nov 2006 17:51:59 GMT",
  server => "Microsoft-Windows-NT/5.1 UPnP/1.0 UPnP-Device-Host/1.0 Microsoft-HTTPAPI/1.0",
}, "HTTP::Headers")
2006-11-10 12:51:59.9060 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997496604919 sec
2006-11-10 12:51:59.9066 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9070 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9074 select_time: 1
2006-11-10 12:51:59.9083 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9090 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9098 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:51:59.9102 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:51:59.9106 select_time: 1
2006-11-10 12:51:59.9111 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9127 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.9133 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:51:59.9138 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997687339783 sec
2006-11-10 12:51:59.9142 select_time: 1
2006-11-10 12:51:59.9148 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9156 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.9161 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:51:59.9165 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:51:59.9169 select_time: 1
2006-11-10 12:51:59.9173 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9182 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.9187 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:51:59.9192 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:51:59.9196 select_time: 1
2006-11-10 12:51:59.9200 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9208 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.9213 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:51:59.9217 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997711181641 sec
2006-11-10 12:51:59.9221 select_time: 1
2006-11-10 12:51:59.9228 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9237 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.9241 Async::HTTP: Read body: 446 bytes
2006-11-10 12:51:59.9245 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997615814209 sec
2006-11-10 12:51:59.9249 select_time: 1
2006-11-10 12:51:59.9254 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9262 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.9269 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing error
2006-11-10 12:51:59.9273 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing read
2006-11-10 12:51:59.9276 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] Removing write
2006-11-10 12:51:59.9278 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x4fd7590)] removing writeNoBlock queue
2006-11-10 12:51:59.9284 Async::HTTP: Body read
2006-11-10 12:51:59.9287 SimpleAsyncHTTP: status for http://192.168.13.98:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f is 200 OK
2006-11-10 12:51:59.9291 SimpleAsyncHTTP: Done
2006-11-10 12:51:59.9617 UPnP: New device found: DESTRUCTION: 1 : Windows Media Connect [http://192.168.13.98:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f]
2006-11-10 12:51:59.9622 UPnP: Adding new media server: DESTRUCTION: 1 : Windows Media Connect
2006-11-10 12:51:59.9705 [norm] set Slim::Utils::UPnPMediaServer::checkServerHealth, in 59.0295310020447 sec
2006-11-10 12:51:59.9719 select_time: 1
2006-11-10 12:51:59.9725 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:51:59.9732 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::_async_error
2006-11-10 12:51:59.9751 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing error
2006-11-10 12:51:59.9756 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing read
2006-11-10 12:51:59.9764 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:51:59.9776 bless({
  connection => "close",
  "content-length" => 5566,
  "content-type" => "text/xml",
  date => "Fri, 10 Nov 2006 17:51:59 GMT",
  server => "Microsoft-Windows-NT/5.1 UPnP/1.0 UPnP-Device-Host/1.0 Microsoft-HTTPAPI/1.0",
}, "HTTP::Headers")
2006-11-10 12:51:59.9788 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997401237488 sec
2006-11-10 12:51:59.9794 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9798 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9802 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:51:59.9808 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::_async_error
2006-11-10 12:51:59.9818 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing error
2006-11-10 12:51:59.9834 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing read
2006-11-10 12:51:59.9842 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:51:59.9854 bless({
  connection => "close",
  "content-length" => 5566,
  "content-type" => "text/xml",
  date => "Fri, 10 Nov 2006 17:51:59 GMT",
  server => "Microsoft-Windows-NT/5.1 UPnP/1.0 UPnP-Device-Host/1.0 Microsoft-HTTPAPI/1.0",
}, "HTTP::Headers")
2006-11-10 12:51:59.9863 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997401237488 sec
2006-11-10 12:51:59.9868 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9873 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9876 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:51:59.9883 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::_async_error
2006-11-10 12:51:59.9894 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing error
2006-11-10 12:51:59.9900 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing read
2006-11-10 12:51:59.9909 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:51:59.9921 bless({
  connection => "close",
  "content-length" => 5566,
  "content-type" => "text/xml",
  date => "Fri, 10 Nov 2006 17:51:59 GMT",
  server => "Microsoft-Windows-NT/5.1 UPnP/1.0 UPnP-Device-Host/1.0 Microsoft-HTTPAPI/1.0",
}, "HTTP::Headers")
2006-11-10 12:51:59.9928 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997401237488 sec
2006-11-10 12:51:59.9933 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9939 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9944 select_time: 0.979814052581787
2006-11-10 12:51:59.9949 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9956 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9962 Async::HTTP: Read body: 817 bytes
2006-11-10 12:51:59.9966 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:51:59.9970 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9976 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.9983 Async::HTTP: Read body: 817 bytes
2006-11-10 12:51:59.9990 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997591972351 sec
2006-11-10 12:51:59.9993 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.9999 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:51:59.0006 Async::HTTP: Read body: 817 bytes
2006-11-10 12:51:59.0010 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:51:59.0014 select_time: 0.972876071929932
2006-11-10 12:51:59.0020 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.0029 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:51:59.0034 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:51:59.0038 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:51:59.0041 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:51:59.0049 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0059 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0067 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997186660767 sec
2006-11-10 12:52:00.0071 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0079 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0084 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0088 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997997283936 sec
2006-11-10 12:52:00.0092 select_time: 0.965046167373657
2006-11-10 12:52:00.0098 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0110 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0116 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0120 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997878074646 sec
2006-11-10 12:52:00.0124 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0132 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0136 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0140 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:52:00.0147 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0156 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0160 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0164 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:52:00.0168 select_time: 0.95741605758667
2006-11-10 12:52:00.0173 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0183 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0188 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0192 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:52:00.0195 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0205 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0210 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0214 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:52:00.0217 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0226 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0232 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0236 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:52:00.0240 select_time: 0.950252056121826
2006-11-10 12:52:00.0245 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0253 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0258 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0264 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:52:00.0267 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0275 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0280 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0284 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:52:00.0287 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0295 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0302 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:00.0306 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:52:00.0312 select_time: 0.943097114562988
2006-11-10 12:52:00.0316 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0325 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0330 Async::HTTP: Read body: 653 bytes
2006-11-10 12:52:00.0442 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997401237488 sec
2006-11-10 12:52:00.0448 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0458 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0463 Async::HTTP: Read body: 653 bytes
2006-11-10 12:52:00.0470 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:52:00.0474 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0482 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0486 Async::HTTP: Read body: 653 bytes
2006-11-10 12:52:00.0490 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:52:00.0495 select_time: 0.924718141555786
2006-11-10 12:52:00.0500 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0509 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0516 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing error
2006-11-10 12:52:00.0520 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing read
2006-11-10 12:52:00.0524 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] Removing write
2006-11-10 12:52:00.0527 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52ccb88)] removing writeNoBlock queue
2006-11-10 12:52:00.0532 Async::HTTP: Body read
2006-11-10 12:52:00.0536 SimpleAsyncHTTP: status for http://127.0.0.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f is 200 OK
2006-11-10 12:52:00.0540 SimpleAsyncHTTP: Done
2006-11-10 12:52:00.0550 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0559 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0565 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing error
2006-11-10 12:52:00.0570 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing read
2006-11-10 12:52:00.0573 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] Removing write
2006-11-10 12:52:00.0575 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc6d8)] removing writeNoBlock queue
2006-11-10 12:52:00.0580 Async::HTTP: Body read
2006-11-10 12:52:00.0585 SimpleAsyncHTTP: status for http://192.168.111.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f is 200 OK
2006-11-10 12:52:00.0590 SimpleAsyncHTTP: Done
2006-11-10 12:52:00.0597 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:00.0605 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:00.0611 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing error
2006-11-10 12:52:00.0615 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing read
2006-11-10 12:52:00.0618 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] Removing write
2006-11-10 12:52:00.0622 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cc228)] removing writeNoBlock queue
2006-11-10 12:52:00.0628 Async::HTTP: Body read
2006-11-10 12:52:00.0633 SimpleAsyncHTTP: status for http://192.168.196.1:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f is 200 OK
2006-11-10 12:52:00.0637 SimpleAsyncHTTP: Done
2006-11-10 12:52:00.0655 select_time: 0.90872597694397
2006-11-10 12:52:00.5125 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:52:00.5129 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:52:00.5131 It's a Squeezebox
2006-11-10 12:52:00.5134  calculated destruction length: 17
2006-11-10 12:52:00.5138 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:52:00.5143 select_time: 0.459969043731689
2006-11-10 12:52:00.9749 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.000538825988769531 late.
2006-11-10 12:52:00.9753 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999821186066 sec
2006-11-10 12:52:00.9756 select_time: 0.015221118927002
2006-11-10 12:52:00.9915 [norm] firing Plugins::Rescan::checkScanTimer 0.000530004501342773 late.
2006-11-10 12:52:00.9919 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999830722809 sec
2006-11-10 12:52:00.9922 select_time: 1
2006-11-10 12:52:02.0007 select_time: 1
2006-11-10 12:52:02.8777 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.8785 select_time: 1
2006-11-10 12:52:02.8894 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.8902 select_time: 1
2006-11-10 12:52:02.8910 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.8917 select_time: 1
2006-11-10 12:52:02.8925 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.8932 select_time: 1
2006-11-10 12:52:02.9201 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9209 select_time: 1
2006-11-10 12:52:02.9217 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9224 select_time: 1
2006-11-10 12:52:02.9232 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9239 select_time: 1
2006-11-10 12:52:02.9247 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9253 select_time: 1
2006-11-10 12:52:02.9263 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9270 select_time: 1
2006-11-10 12:52:02.9278 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9285 select_time: 1
2006-11-10 12:52:02.9292 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9299 select_time: 1
2006-11-10 12:52:02.9307 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9315 select_time: 1
2006-11-10 12:52:02.9324 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9331 select_time: 1
2006-11-10 12:52:02.9338 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9346 select_time: 1
2006-11-10 12:52:02.9354 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9362 select_time: 1
2006-11-10 12:52:02.9368 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9376 select_time: 1
2006-11-10 12:52:02.9385 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9392 select_time: 1
2006-11-10 12:52:02.9399 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9407 select_time: 1
2006-11-10 12:52:02.9413 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9420 select_time: 1
2006-11-10 12:52:02.9430 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9437 select_time: 1
2006-11-10 12:52:02.9445 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9452 select_time: 1
2006-11-10 12:52:02.9459 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9466 select_time: 1
2006-11-10 12:52:02.9474 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9481 select_time: 1
2006-11-10 12:52:02.9488 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:02.9495 select_time: 1
2006-11-10 12:52:03.9430 select_time: 0.0569770336151123
2006-11-10 12:52:04.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000540018081665039 late.
2006-11-10 12:52:04.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99899005889893 sec
2006-11-10 12:52:04.0013 select_time: 1
2006-11-10 12:52:05.0082 select_time: 1
2006-11-10 12:52:05.9009 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9017 select_time: 1
2006-11-10 12:52:05.9026 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9034 select_time: 1
2006-11-10 12:52:05.9040 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9047 select_time: 1
2006-11-10 12:52:05.9058 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9065 select_time: 1
2006-11-10 12:52:05.9693 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9701 select_time: 1
2006-11-10 12:52:05.9707 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9714 select_time: 1
2006-11-10 12:52:05.9721 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9728 select_time: 1
2006-11-10 12:52:05.9737 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9744 select_time: 1
2006-11-10 12:52:05.9754 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9762 select_time: 1
2006-11-10 12:52:05.9780 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9788 select_time: 1
2006-11-10 12:52:05.9794 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9801 select_time: 1
2006-11-10 12:52:05.9809 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9817 select_time: 1
2006-11-10 12:52:05.9831 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9839 select_time: 1
2006-11-10 12:52:05.9845 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9852 select_time: 1
2006-11-10 12:52:05.9862 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9869 select_time: 1
2006-11-10 12:52:05.9876 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9883 select_time: 1
2006-11-10 12:52:05.9892 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9900 select_time: 1
2006-11-10 12:52:05.9909 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9916 select_time: 1
2006-11-10 12:52:05.9923 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9930 select_time: 1
2006-11-10 12:52:05.9938 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9946 select_time: 1
2006-11-10 12:52:05.9954 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9961 select_time: 1
2006-11-10 12:52:05.9968 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9976 select_time: 1
2006-11-10 12:52:05.9990 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.9998 select_time: 1
2006-11-10 12:52:05.0006 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:05.0014 select_time: 1
2006-11-10 12:52:06.9975 select_time: 1
2006-11-10 12:52:07.0000 select_time: 1
2006-11-10 12:52:08.7831 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:08.7838 select_time: 0.216211080551147
2006-11-10 12:52:08.7843 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:08.7864 select_time: 0.213547945022583
2006-11-10 12:52:09.0006 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000504970550537109 late.
2006-11-10 12:52:09.0010 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99903297424316 sec
2006-11-10 12:52:09.0013 select_time: 1
2006-11-10 12:52:10.0050 select_time: 1
2006-11-10 12:52:11.0075 select_time: 1
2006-11-10 12:52:12.0100 select_time: 1
2006-11-10 12:52:13.0125 select_time: 0.987520933151245
2006-11-10 12:52:14.0150 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.0148959159851074 late.
2006-11-10 12:52:14.0154 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.9846179485321 sec
2006-11-10 12:52:14.0158 select_time: 1
2006-11-10 12:52:15.0175 select_time: 1
2006-11-10 12:52:16.0199 select_time: 1
2006-11-10 12:52:17.0224 select_time: 1
2006-11-10 12:52:18.0250 select_time: 0.975042104721069
2006-11-10 12:52:18.8237 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:18.8243 select_time: 0.175652027130127
2006-11-10 12:52:18.8249 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:18.8254 select_time: 0.174555063247681
2006-11-10 12:52:18.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00068211555480957 late.
2006-11-10 12:52:18.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.9988420009613 sec
2006-11-10 12:52:18.0015 select_time: 1
2006-11-10 12:52:19.9986 select_time: 1
2006-11-10 12:52:21.0011 select_time: 1
2006-11-10 12:52:22.0036 select_time: 0.996385097503662
2006-11-10 12:52:23.0061 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00603199005126953 late.
2006-11-10 12:52:23.0065 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99348092079163 sec
2006-11-10 12:52:23.0068 select_time: 1
2006-11-10 12:52:24.0086 select_time: 1
2006-11-10 12:52:25.0111 select_time: 0.988894939422607
2006-11-10 12:52:25.9979 select_time: 0.00206708908081055
2006-11-10 12:52:26.0008 [norm] firing Slim::Utils::UPnPMediaServer::checkServerHealth 0.000686883926391602 late.
2006-11-10 12:52:26.0012 SimpleAsyncHTTP: GETing http://192.168.13.100:50515/
2006-11-10 12:52:26.0031 Async: Connecting to 192.168.13.100:50515
2006-11-10 12:52:26.0066 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:52:26.0071 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:52:26.0074 [norm] set Slim::Networking::Async::_connect_error, in 4.99997496604919 sec
2006-11-10 12:52:26.0078 select_time: 1
2006-11-10 12:52:26.0083 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:52:26.0088 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80) / Slim::Networking::Async::_connect_error
2006-11-10 12:52:26.0093 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing error
2006-11-10 12:52:26.0097 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing write
2006-11-10 12:52:26.0100 Async: connected, ready to write request
2006-11-10 12:52:26.0108 Async: Sending:
GET / HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.13.100:50515

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:52:26.0115 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:52:26.0119 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:52:26.0122 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Wrote 242 bytes
2006-11-10 12:52:26.0128 [norm] set Slim::Networking::Async::_async_error, in 4.99990105628967 sec
2006-11-10 12:52:26.0136 select_time: 1
2006-11-10 12:52:26.0142 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:52:26.0148 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80) / Slim::Networking::Async::_async_error
2006-11-10 12:52:26.0158 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing error
2006-11-10 12:52:26.0163 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing read
2006-11-10 12:52:26.0170 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:52:26.0181 bless({
  "content-length" => 1713,
  "content-type" => "text/xml ; charset=\"utf-8\"",
  date => "Fri, 10 Nov 2006 17:52:26 GMT",
  server => "WINDOWS/5.1 UPnP/1.0 UPnP-Device-Host/1.0 NeroMediaHome/1.4.0.15",
}, "HTTP::Headers")
2006-11-10 12:52:26.0191 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997496604919 sec
2006-11-10 12:52:26.0196 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:52:26.0200 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:26.0205 select_time: 1
2006-11-10 12:52:26.0210 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:26.0216 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:52:26.0222 Async::HTTP: Read body: 830 bytes
2006-11-10 12:52:26.0226 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997687339783 sec
2006-11-10 12:52:26.0230 select_time: 1
2006-11-10 12:52:26.0235 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:26.0242 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:26.0247 Async::HTTP: Read body: 883 bytes
2006-11-10 12:52:26.0251 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:52:26.0255 select_time: 1
2006-11-10 12:52:26.0259 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:26.0267 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:26.0273 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing error
2006-11-10 12:52:26.0277 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing read
2006-11-10 12:52:26.0280 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] Removing write
2006-11-10 12:52:26.0283 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x52cca80)] removing writeNoBlock queue
2006-11-10 12:52:26.0288 Async::HTTP: Body read
2006-11-10 12:52:26.0293 SimpleAsyncHTTP: status for http://192.168.13.100:50515/ is 200 OK
2006-11-10 12:52:26.0298 SimpleAsyncHTTP: Done
2006-11-10 12:52:26.0303 [norm] set Slim::Utils::UPnPMediaServer::checkServerHealth, in 59.9696869850159 sec
2006-11-10 12:52:26.0316 select_time: 1
2006-11-10 12:52:27.0474 select_time: 0.952574014663696
2006-11-10 12:52:28.0029 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00284790992736816 late.
2006-11-10 12:52:28.0033 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99667692184448 sec
2006-11-10 12:52:28.0036 select_time: 1
2006-11-10 12:52:28.8487 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:28.8488 select_time: 1
2006-11-10 12:52:28.8493 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:28.8498 select_time: 1
2006-11-10 12:52:29.8513 select_time: 1
2006-11-10 12:52:30.8538 select_time: 1
2006-11-10 12:52:31.8563 select_time: 1
2006-11-10 12:52:32.8588 select_time: 0.141233921051025
2006-11-10 12:52:32.0004 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000272989273071289 late.
2006-11-10 12:52:32.0007 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99924993515015 sec
2006-11-10 12:52:32.0011 select_time: 1
2006-11-10 12:52:34.0022 select_time: 1
2006-11-10 12:52:35.0047 select_time: 1
2006-11-10 12:52:36.0072 select_time: 0.992769002914429
2006-11-10 12:52:36.9941 select_time: 0.00593805313110352
2006-11-10 12:52:37.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000694990158081055 late.
2006-11-10 12:52:37.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99883699417114 sec
2006-11-10 12:52:37.0015 select_time: 1
2006-11-10 12:52:38.0122 select_time: 1
2006-11-10 12:52:38.8736 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:38.8743 select_time: 1
2006-11-10 12:52:38.8748 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:38.8753 select_time: 1
2006-11-10 12:52:39.5315 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5324 select_time: 1
2006-11-10 12:52:39.5330 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5338 select_time: 1
2006-11-10 12:52:39.5343 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5351 select_time: 1
2006-11-10 12:52:39.5357 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5365 select_time: 1
2006-11-10 12:52:39.5370 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5378 select_time: 1
2006-11-10 12:52:39.5384 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5392 select_time: 1
2006-11-10 12:52:39.5397 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5406 select_time: 1
2006-11-10 12:52:39.5411 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5419 select_time: 1
2006-11-10 12:52:39.5424 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5433 select_time: 1
2006-11-10 12:52:39.5440 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5453 select_time: 1
2006-11-10 12:52:39.5459 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:39.5465 select_time: 1
2006-11-10 12:52:40.5498 select_time: 1
2006-11-10 12:52:40.6711 Select: [IO::Socket::INET=GLOB(0x2769874)] read, calling Slim::Networking::UDP::readUDP
2006-11-10 12:52:40.6715 gotDiscoveryRequest: deviceid = 2, revision = 2.2, MAC = 00:0d:4b:03:ac:87
2006-11-10 12:52:40.6717 It's a Squeezebox
2006-11-10 12:52:40.6720  calculated destruction length: 17
2006-11-10 12:52:40.6724 gotDiscoveryRequest: Sent discovery response.
2006-11-10 12:52:40.6728 select_time: 1
2006-11-10 12:52:41.6776 select_time: 0.322398900985718
2006-11-10 12:52:41.0008 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000758886337280273 late.
2006-11-10 12:52:41.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99876189231873 sec
2006-11-10 12:52:41.0015 select_time: 1
2006-11-10 12:52:42.9934 select_time: 1
2006-11-10 12:52:43.9959 select_time: 1
2006-11-10 12:52:44.9983 select_time: 1
2006-11-10 12:52:46.0009 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000783920288085938 late.
2006-11-10 12:52:46.0013 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99872088432312 sec
2006-11-10 12:52:46.0016 select_time: 1
2006-11-10 12:52:47.0033 select_time: 1
2006-11-10 12:52:48.0058 select_time: 1
2006-11-10 12:52:48.8829 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:48.8836 select_time: 1
2006-11-10 12:52:48.8842 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:48.8847 select_time: 1
2006-11-10 12:52:49.8855 select_time: 1
2006-11-10 12:52:50.8880 select_time: 0.111968040466309
2006-11-10 12:52:51.0003 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0.000252962112426758 late.
2006-11-10 12:52:51.0007 Prevent Standby plugin: starting timer
2006-11-10 12:52:51.0009 [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9990921020508 sec
2006-11-10 12:52:51.0013 select_time: 0
2006-11-10 12:52:51.0017 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00170207023620605 late.
2006-11-10 12:52:51.0021 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99795603752136 sec
2006-11-10 12:52:51.0025 select_time: 1
2006-11-10 12:52:52.0158 select_time: 1
2006-11-10 12:52:53.0183 select_time: 1
2006-11-10 12:52:54.0208 select_time: 1
2006-11-10 12:52:54.8822 Select: [HTTP::Daemon=GLOB(0x277558c)] read, calling Slim::Web::HTTP::acceptHTTP
2006-11-10 12:52:54.8837 Select: [HTTP::Daemon::ClientConn=GLOB(0x52cc408)] Adding read -> Slim::Web::HTTP::processHTTP
2006-11-10 12:52:54.8842 Select: [HTTP::Daemon::ClientConn=GLOB(0x52cc408)] Adding error -> Slim::Web::HTTP::closeStreamingSocket
2006-11-10 12:52:54.8845 Accepted connection 1 from 127.0.0.1
2006-11-10 12:52:54.8848 select_time: 1
2006-11-10 12:52:54.8862 Select: [HTTP::Daemon::ClientConn=GLOB(0x52cc408)] read, calling Slim::Web::HTTP::processHTTP
2006-11-10 12:52:54.8895 reading request...
2006-11-10 12:52:54.8902 HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x52cc408)) for head HTTP/1.1 /status_header.html 
2006-11-10 12:52:54.8927 Bad Request: [head /status_header.html]
2006-11-10 12:52:54.8933 generating from html/errors/405.html
2006-11-10 12:52:54.8961 idleStreams: select_time: 0, checkTimers: 1
2006-11-10 12:52:54.9057 Select: [HTTP::Daemon::ClientConn=GLOB(0x52cc408)] Removing read
2006-11-10 12:52:54.9061 Select: [HTTP::Daemon::ClientConn=GLOB(0x52cc408)] Removing write
2006-11-10 12:52:54.9065 Select: [HTTP::Daemon::ClientConn=GLOB(0x52cc408)] Removing error
2006-11-10 12:52:54.9071 End request: keepAlive: [] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x52cc408) on connection = close

2006-11-10 12:52:54.9079 select_time: 1
2006-11-10 12:52:55.9162 select_time: 0.0838239192962646
2006-11-10 12:52:55.0001 [norm] firing Slim::Networking::Slimproto::check_all_clients 5.29289245605469e-005 late.
2006-11-10 12:52:55.0005 [norm] set Slim::Networking::Slimproto::check_all_clients, in 3.99947595596313 sec
2006-11-10 12:52:55.0008 select_time: 1
2006-11-10 12:52:56.9970 select_time: 1
2006-11-10 12:52:57.9995 select_time: 1
2006-11-10 12:52:58.9079 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:58.9080 select_time: 0.0920040607452393
2006-11-10 12:52:58.9085 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:52:58.9090 select_time: 0.0909690856933594
2006-11-10 12:52:59.0012 [norm] firing Slim::Utils::UPnPMediaServer::checkServerHealth 0.00111293792724609 late.
2006-11-10 12:52:59.0017 SimpleAsyncHTTP: GETing http://192.168.13.98:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f
2006-11-10 12:52:59.0035 Async: Connecting to 192.168.13.98:2869
2006-11-10 12:52:59.0070 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Adding error -> Slim::Networking::Async::_connect_error
2006-11-10 12:52:59.0075 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Adding write -> Slim::Networking::Async::_async_connect
2006-11-10 12:52:59.0079 [norm] set Slim::Networking::Async::_connect_error, in 4.99997401237488 sec
2006-11-10 12:52:59.0084 select_time: 0.991633892059326
2006-11-10 12:52:59.0089 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] write, calling Slim::Networking::Async::_async_connect
2006-11-10 12:52:59.0094 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::_connect_error
2006-11-10 12:52:59.0103 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing error
2006-11-10 12:52:59.0107 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing write
2006-11-10 12:52:59.0110 Async: connected, ready to write request
2006-11-10 12:52:59.0118 Async: Sending:
GET /upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f HTTP/1.1

Connection: close

Cache-Control: no-cache

Accept: */*

Accept-Encoding: gzip, deflate

Host: 192.168.13.98:2869

User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.0/9916

Icy-MetaData: 1



2006-11-10 12:52:59.0125 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Adding error -> Slim::Networking::Async::_async_error
2006-11-10 12:52:59.0129 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Adding read -> Slim::Networking::Async::_async_read
2006-11-10 12:52:59.0133 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Wrote 311 bytes
2006-11-10 12:52:59.0140 [norm] set Slim::Networking::Async::_async_error, in 4.99989604949951 sec
2006-11-10 12:52:59.0144 select_time: 0.985553026199341
2006-11-10 12:52:59.0165 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::_async_read
2006-11-10 12:52:59.0172 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::_async_error
2006-11-10 12:52:59.0182 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing error
2006-11-10 12:52:59.0187 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing read
2006-11-10 12:52:59.0195 Async::HTTP: Headers read. code: 200 status: OK
2006-11-10 12:52:59.0207 bless({
  connection => "close",
  "content-length" => 5566,
  "content-type" => "text/xml",
  date => "Fri, 10 Nov 2006 17:52:59 GMT",
  server => "Microsoft-Windows-NT/5.1 UPnP/1.0 UPnP-Device-Host/1.0 Microsoft-HTTPAPI/1.0",
}, "HTTP::Headers")
2006-11-10 12:52:59.0214 [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99997401237488 sec
2006-11-10 12:52:59.0219 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:52:59.0224 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0229 select_time: 0.977123022079468
2006-11-10 12:52:59.0246 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0252 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_socket_error
2006-11-10 12:52:59.0259 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:59.0263 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997687339783 sec
2006-11-10 12:52:59.0268 select_time: 0.97318696975708
2006-11-10 12:52:59.0273 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0280 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0285 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:59.0289 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:52:59.0293 select_time: 0.970736026763916
2006-11-10 12:52:59.0297 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0305 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0309 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:59.0313 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:52:59.0317 select_time: 0.968278884887695
2006-11-10 12:52:59.0322 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0329 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0333 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:59.0337 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997806549072 sec
2006-11-10 12:52:59.0341 select_time: 0.96589207649231
2006-11-10 12:52:59.0346 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0353 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0358 Async::HTTP: Read body: 284 bytes
2006-11-10 12:52:59.0377 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99845099449158 sec
2006-11-10 12:52:59.0383 select_time: 0.961642026901245
2006-11-10 12:52:59.0390 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0398 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0403 Async::HTTP: Read body: 1024 bytes
2006-11-10 12:52:59.0407 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997901916504 sec
2006-11-10 12:52:59.0411 select_time: 0.958849906921387
2006-11-10 12:52:59.0416 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0423 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0428 Async::HTTP: Read body: 162 bytes
2006-11-10 12:52:59.0432 [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99997782707214 sec
2006-11-10 12:52:59.0436 select_time: 0.956360101699829
2006-11-10 12:52:59.0441 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] read, calling Slim::Networking::Async::HTTP::_http_read_body
2006-11-10 12:52:59.0448 [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808) / Slim::Networking::Async::HTTP::_http_read_timeout
2006-11-10 12:52:59.0454 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing error
2006-11-10 12:52:59.0458 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing read
2006-11-10 12:52:59.0462 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] Removing write
2006-11-10 12:52:59.0464 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x277b808)] removing writeNoBlock queue
2006-11-10 12:52:59.0469 Async::HTTP: Body read
2006-11-10 12:52:59.0473 SimpleAsyncHTTP: status for http://192.168.13.98:2869/upnphost/udhisapi.dll?content=uuid:02bf66ab-0a0f-4042-8b72-75fab6f8b86f is 200 OK
2006-11-10 12:52:59.0477 SimpleAsyncHTTP: Done
2006-11-10 12:52:59.0481 [norm] set Slim::Utils::UPnPMediaServer::checkServerHealth, in 59.951947927475 sec
2006-11-10 12:52:59.0493 select_time: 0.950690031051636
2006-11-10 12:53:00.0045 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00440001487731934 late.
2006-11-10 12:53:00.0049 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99511790275574 sec
2006-11-10 12:53:00.0052 select_time: 0.970062017440796
2006-11-10 12:53:00.9756 [norm] firing Slim::Buttons::AlarmClock::checkAlarms 0.00029301643371582 late.
2006-11-10 12:53:00.9761 [norm] set Slim::Buttons::AlarmClock::checkAlarms, in 59.9999821186066 sec
2006-11-10 12:53:00.9764 select_time: 0.0154571533203125
2006-11-10 12:53:00.9922 [norm] firing Plugins::Rescan::checkScanTimer 0.000294923782348633 late.
2006-11-10 12:53:00.9926 [norm] set Plugins::Rescan::checkScanTimer, in 59.9999828338623 sec
2006-11-10 12:53:01.9930 select_time: 1
2006-11-10 12:53:02.0095 select_time: 1
2006-11-10 12:53:03.0120 select_time: 1
2006-11-10 12:53:04.0145 select_time: 0.985538005828857
2006-11-10 12:53:05.0013 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.00121593475341797 late.
2006-11-10 12:53:05.0017 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99830889701843 sec
2006-11-10 12:53:05.0020 select_time: 1
2006-11-10 12:53:06.0038 select_time: 1
2006-11-10 12:53:07.0063 select_time: 1
2006-11-10 12:53:07.6640 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:07.6647 select_time: 1
2006-11-10 12:53:07.7088 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:07.7095 select_time: 1
2006-11-10 12:53:08.6979 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:08.6985 select_time: 1
2006-11-10 12:53:08.9381 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:08.9388 select_time: 1
2006-11-10 12:53:08.9393 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:08.9398 select_time: 1
2006-11-10 12:53:09.9354 select_time: 0.0645461082458496
2006-11-10 12:53:10.0009 [norm] firing Slim::Networking::Slimproto::check_all_clients 0.000787019729614258 late.
2006-11-10 12:53:10.0012 [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99875593185425 sec
2006-11-10 12:53:10.0015 select_time: 1
2006-11-10 12:53:10.8752 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:10.8757 UPnP: Read search result failed: recv failed: Unknown error at /PerlApp/Slim/Networking/UPnP/ControlPoint.pm line 106.

2006-11-10 12:53:10.8761 select_time: 1
2006-11-10 12:53:10.9228 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:10.9234 UPnP: Read search result failed: recv failed: Unknown error at /PerlApp/Slim/Networking/UPnP/ControlPoint.pm line 106.

2006-11-10 12:53:10.9239 select_time: 1
2006-11-10 12:53:10.9836 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x277132c)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult
2006-11-10 12:53:10.9841 UPnP: Read search result failed: recv failed: Unknown error at /PerlApp/Slim/Networking/UPnP/ControlPoint.pm line 106.

2006-11-10 12:53:10.9845 select_time: 1
2006-11-10 12:53:11.9874 select_time: 1
2006-11-10 12:53:12.9899 select_time: 1
2006-11-10 12:53:13.9985 Terminating on signal SIGALRM(14)