w state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=91 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563206889 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0102169513702393 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989599943161011 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0136041641235352 select_time: 9.60826873779297e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000780820846557617 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000773906707763672 late. screenSaver idle display 243.361937999725(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999733924865723 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000664234161376953 late. screenSaver idle display 243.73477101326(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999741077423096 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000613927841186523 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000651121139526367 late. screenSaver idle display 243.473781824112(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999749898910522 sec select_time: 0.971112966537476 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999732971191406 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00198602676391602 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997829914093018 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.022791862487793 select_time: 4.1961669921875e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000838994979858398 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000884056091308594 late. screenSaver idle display 244.362953186035(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999731063842773 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000919103622436523 late. screenSaver idle display 244.735806941986(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999737977981567 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000911951065063477 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000904083251953125 late. screenSaver idle display 244.47479891777(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999750137329102 sec select_time: 0.970098972320557 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00201201438903809 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997803926467896 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.023655891418457 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000854015350341797 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000939846038818359 late. screenSaver idle display 245.364021062851(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999733924865723 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000934123992919922 late. screenSaver idle display 245.736856937408(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000915050506591797 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000926971435546875 late. screenSaver idle display 245.475838899612(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.969062089920044 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999749898910522 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00253200531005859 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997281074523926 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0242950916290283 select_time: 0.000142097473144531 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00073695182800293 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000725030899047852 late. screenSaver idle display 246.364870071411(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99973201751709 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000724077224731445 late. screenSaver idle display 246.737698078156(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00070500373840332 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00072789192199707 late. screenSaver idle display 246.476677894592(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999753952026367 sec select_time: 0.968223094940186 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999742984771729 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00230693817138672 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997468948364258 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0251860618591309 select_time: 6.103515625e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000813007354736328 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000833034515380859 late. screenSaver idle display 247.365828037262(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99973201751709 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00084686279296875 late. screenSaver idle display 247.738659143448(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99974513053894 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000825881958007813 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000855922698974609 late. screenSaver idle display 247.477649927139(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999750137329102 sec select_time: 0.967247009277344 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99871206283569 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00159692764282227 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998224973678589 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=88 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455820261 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=91 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10088843 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=91 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563211889 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00995492935180664 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989865064620972 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0186350345611572 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000900983810424805 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00102806091308594 late. screenSaver idle display 248.366984128952(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999685049057007 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0010979175567627 late. screenSaver idle display 248.73987698555(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999738931655884 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00111007690429688 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999992847442627 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00110507011413574 late. screenSaver idle display 248.478867769241(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999755859375 sec select_time: 0.966033935546875 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999747037887573 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0021209716796875 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997688055038452 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0276260375976563 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000751018524169922 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000824928283691406 late. screenSaver idle display 249.367936134338(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999730110168457 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000782012939453125 late. screenSaver idle display 249.740775108337(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999744176864624 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000755071640014648 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000796079635620117 late. screenSaver idle display 249.479777812958(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999749898910522 sec select_time: 0.96511697769165 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999743938446045 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00196599960327148 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997852087020874 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0287671089172363 select_time: 0.000172138214111328 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000731945037841797 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991178512573 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000711917877197266 late. screenSaver idle display 250.368772029877(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999733924865723 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00222492218017578 late. screenSaver idle display 250.743166923523(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999689817428589 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00232315063476563 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00240206718444824 late. screenSaver idle display 250.482301950455(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999741077423096 sec select_time: 0.962578058242798 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99974799156189 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00197005271911621 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997844934463501 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0296730995178223 select_time: 4.69684600830078e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000834941864013672 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.99999213218689 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000874042510986328 late. screenSaver idle display 251.369771957397(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999733924865723 sec select_time: 0.000803947448730469 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000211000442504883 late. screenSaver idle display 251.743497133255(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999740123748779 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000164985656738281 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000144004821777344 late. screenSaver idle display 251.482709884644(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999721050262451 sec select_time: 0.962143898010254 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999713897705078 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00200390815734863 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997812986373901 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0306460857391357 select_time: 4.41074371337891e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00106191635131836 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00114822387695313 late. screenSaver idle display 252.371047019959(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999727010726929 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000321865081787109 late. screenSaver idle display 252.743938922882(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742984771729 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.0002899169921875 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000138998031616211 late. screenSaver idle display 252.482966899872(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99974799156189 sec select_time: 0.961905002593994 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99872207641602 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00158500671386719 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998236894607544 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=87 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455825261 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=91 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10093845 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=92 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563216890 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0103380680084229 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.98947811126709 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0235080718994141 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000581979751586914 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991178512573 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000645160675048828 late. screenSaver idle display 253.371819972992(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999736785888672 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000614166259765625 late. screenSaver idle display 253.744669914246(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999738931655884 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000567913055419922 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000686883926391602 late. screenSaver idle display 253.48378276825(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999736785888672 sec select_time: 0.961092948913574 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00195789337158203 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997859001159668 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0326540470123291 select_time: 0.000132083892822266 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000761032104492188 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000786066055297852 late. screenSaver idle display 254.37273311615(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999732971191406 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00080418586730957 late. screenSaver idle display 254.745589971542(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.9997398853302 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000789880752563477 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000683069229125977 late. screenSaver idle display 254.484579801559(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999753952026367 sec select_time: 0.960319995880127 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00210809707641602 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997708082199097 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0333878993988037 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000834226608276367 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.99999213218689 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000908851623535156 late. screenSaver idle display 255.373769044876(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999732971191406 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000903129577636719 late. screenSaver idle display 255.746608972549(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999745845794678 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000884056091308594 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994993209839 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000900030136108398 late. screenSaver idle display 255.485592842102(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.959306955337524 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)) for GET HTTP/1.1 /html/ping.html?d=0.6478045027170428&_= HTTP parameter d = 0.6478045027170428 HTTP parameter _ = processURL Clients: 192.168.1.6:20946 192.168.1.5:49229 192.168.1.3:18110 Generating response for (htm, text/html) html/ping.html generating from include.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 generating from html/ping.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\html\ping.html Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [13] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8) on connection = Keep-Alive select_time: 0.551706075668335 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] write, calling Slim::Web::HTTP::sendResponse Sent 176 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.550770998001099 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] write, calling Slim::Web::HTTP::sendResponse Sent 12 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.549731969833374 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] Removing write select_time: 0.549192905426025 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)) for GET HTTP/1.1 /status_header.html?player=00%3A04%3A20%3A05%3Acb%3A18 HTTP parameter player = 00:04:20:05:cb:18 processURL Clients: 192.168.1.6:20946 192.168.1.5:49229 192.168.1.3:18110 Generating response for (htm, text/html) status_header.html generating from include.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\include.html generating from select_option.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\select_option.html idleStreams: select_time: 0, checkTimers: 1 generating from select_option.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\select_option.html generating from select_option.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\select_option.html Reading firmware version file: C:\Program Files\SlimServer6.4\server\Firmware\squeezebox2.version squeezebox2 firmware is up-to-date, v. 81 songTime: rate:1 -songtime:0 -startStream:0 songTime: rate:1 -songtime:0 -startStream:0 generating from status_header.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\Default\status_header.html Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [13] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5d8f05c) on connection = Keep-Alive select_time: 0.478440046310425 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] write, calling Slim::Web::HTTP::sendResponse Sent 285 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.477564096450806 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] write, calling Slim::Web::HTTP::sendResponse Sent 19087 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.476085901260376 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] Removing write select_time: 0.475536108016968 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)) for GET HTTP/1.1 /playlist.html?player=00%3A04%3A20%3A05%3Acb%3A18&d=1196615077578 HTTP parameter player = 00:04:20:05:cb:18 HTTP parameter d = 1196615077578 processURL Clients: 192.168.1.6:20946 192.168.1.5:49229 192.168.1.3:18110 Generating response for (htm, text/html) playlist.html generating from include.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1 Reading firmware version file: C:\Program Files\SlimServer6.4\server\Firmware\squeezebox2.version squeezebox2 firmware is up-to-date, v. 81 generating from playlist.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\Default\playlist.html Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] Adding write -> Slim::Web::HTTP::sendResponse End request: keepAlive: [14] - waiting for next request for HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8) on connection = Keep-Alive select_time: 0.378829002380371 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] write, calling Slim::Web::HTTP::sendResponse Sent 284 to 127.0.0.1 More to send to 127.0.0.1 select_time: 0.378025054931641 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] write, calling Slim::Web::HTTP::sendResponse Sent 5248 to 127.0.0.1 No more messages to send to 127.0.0.1 select_time: 0.376671075820923 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] write, calling Slim::Web::HTTP::sendResponse No segment to send to 127.0.0.1, waiting for next request.. Select: [HTTP::Daemon::ClientConn=GLOB(0x5d6c0b8)] Removing write select_time: 0.376075983047485 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00201010704040527 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99780797958374 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0345859527587891 select_time: 0.000129938125610352 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000762939453125 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000757932662963867 late. screenSaver idle display 256.374655008316(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999728918075562 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000769138336181641 late. screenSaver idle display 256.747496128082(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999741077423096 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000761985778808594 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000792026519775391 late. screenSaver idle display 256.48650097847(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999746084213257 sec select_time: 0.958390951156616 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00196099281311035 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99785590171814 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0353488922119141 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000857114791870117 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00104308128356934 late. screenSaver idle display 257.375835180283(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999701023101807 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00109291076660156 late. screenSaver idle display 257.748707056046(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742031097412 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00108599662780762 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00108098983764648 late. screenSaver idle display 257.487692832947(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999755859375 sec select_time: 0.957210063934326 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99871301651001 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00159502029418945 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998225927352905 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=88 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455830265 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=87 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10098847 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=91 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563221894 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0202269554138184 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.979525089263916 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0182008743286133 select_time: 0.000129938125610352 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000771045684814453 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000742912292480469 late. screenSaver idle display 258.376708030701(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999731063842773 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000735044479370117 late. screenSaver idle display 258.749558925629(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999745845794678 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000710964202880859 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00104498863220215 late. screenSaver idle display 258.488860845566(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999670028686523 sec select_time: 0.955946922302246 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999742031097412 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0022881031036377 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99752402305603 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0371618270874023 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000810146331787109 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000884056091308594 late. screenSaver idle display 259.377721071243(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999725103378296 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000885009765625 late. screenSaver idle display 259.750564098358(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999696016311646 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000664949417114258 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000632047653198242 late. screenSaver idle display 259.489607810974(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999752044677734 sec select_time: 0.955290079116821 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999744892120361 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00199794769287109 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997817993164063 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0384979248046875 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000756025314331055 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000878095626831055 late. screenSaver idle display 260.378729104996(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999726057052612 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000886917114257813 late. screenSaver idle display 260.75156712532(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999740123748779 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000815868377685547 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993801116943 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000854969024658203 late. screenSaver idle display 260.490580797195(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999749898910522 sec select_time: 0.954313039779663 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999742984771729 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00219011306762695 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997626066207886 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0391891002655029 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000748872756958008 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000819921493530273 late. screenSaver idle display 261.379762172699(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99971604347229 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000938892364501953 late. screenSaver idle display 261.752624034882(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999740123748779 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000913143157958984 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000922203063964844 late. screenSaver idle display 261.491615772247(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.953262090682983 Select: [Slim::Networking::Async::Socket::UDP=GLOB(0x4fd6c80)] read, calling Slim::Networking::UPnP::ControlPoint::_readResult select_time: 0.929322004318237 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999742984771729 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00197792053222656 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997838973999023 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0404419898986816 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000689029693603516 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000805854797363281 late. screenSaver idle display 262.380707025528(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99970006942749 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000837087631225586 late. screenSaver idle display 262.753579139709(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742031097412 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000824928283691406 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000838994979858398 late. screenSaver idle display 262.492569923401(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999756097793579 sec select_time: 0.952332019805908 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99852991104126 sec select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=85 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455835266 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00423097610473633 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.995587110519409 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=89 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10103849 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=92 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563226895 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.010807991027832 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989006042480469 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.032459020614624 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000828027725219727 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000808954238891602 late. screenSaver idle display 263.381644010544(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999703884124756 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000842809677124023 late. screenSaver idle display 263.754545927048(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999737977981567 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000849008560180664 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000949859619140625 late. screenSaver idle display 263.49363899231(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999741077423096 sec select_time: 0.951241970062256 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.9997398853302 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00205206871032715 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997764110565186 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0423219203948975 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000700950622558594 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999989986419678 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000777959823608398 late. screenSaver idle display 264.382551193237(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99973201751709 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000727176666259766 late. screenSaver idle display 264.755388975143(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742984771729 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000697851181030273 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000644922256469727 late. screenSaver idle display 264.494398832321(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999752044677734 sec select_time: 0.950392961502075 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999588012695313 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00212192535400391 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99769401550293 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0432159900665283 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000810146331787109 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999989986419678 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000884771347045898 late. screenSaver idle display 265.383566141129(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999731063842773 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000900983810424805 late. screenSaver idle display 265.756406068802(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000864028930664063 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999992847442627 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00106906890869141 late. screenSaver idle display 265.49560379982(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999728918075562 sec select_time: 0.94923996925354 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00194811820983887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997868061065674 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0444169044494629 select_time: 0.000154018402099609 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000741004943847656 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.99999213218689 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000733852386474609 late. screenSaver idle display 266.384426116943(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999736070632935 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00073695182800293 late. screenSaver idle display 266.757256984711(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000687122344970703 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994993209839 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000574111938476563 late. screenSaver idle display 266.496295928955(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999750137329102 sec select_time: 0.94859790802002 [norm] firing Plugins::PreventStandby::Plugin::checkClientActivity 0 late. Prevent Standby plugin: client LR in playmode stop Prevent Standby plugin: client Bedroom in playmode stop Prevent Standby plugin: client Den in playmode stop Prevent Standby plugin: starting timer [norm] set Plugins::PreventStandby::Plugin::checkClientActivity, in 59.9994459152222 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.000837087631225586 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998991012573242 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00268292427062988 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.99712610244751 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0446009635925293 select_time: 6.29425048828125e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000814914703369141 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.99999213218689 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000849008560180664 late. screenSaver idle display 267.385401964188(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999687910079956 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000916957855224609 late. screenSaver idle display 267.758291006088(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000905990600585938 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993801116943 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000862836837768555 late. screenSaver idle display 267.497272968292(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999755144119263 sec select_time: 0.947628974914551 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 5 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.000294923782348633 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999443054199219 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=87 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455840269 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=90 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10108852 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=91 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563231898 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00849699974060059 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.991322994232178 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0397469997406006 select_time: 0.000399112701416016 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000496864318847656 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991893768311 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000509023666381836 late. screenSaver idle display 268.386038064957(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999734878540039 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00144791603088379 late. screenSaver idle display 268.759897947311(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999697923660278 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00154900550842285 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00156998634338379 late. screenSaver idle display 268.498954772949(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999750852584839 sec select_time: 0.292820930480957 select_time: 0.000432014465332031 [norm] firing Plugins::xPL::sendxplhbeat 0.000420093536376953 late. [norm] set Plugins::xPL::sendxplhbeat, in 299.99998497963 sec select_time: 0.649385929107666 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999736070632935 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00203895568847656 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997775077819824 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0468549728393555 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00124812126159668 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00137710571289063 late. screenSaver idle display 269.387542009354(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999721050262451 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000372171401977539 late. screenSaver idle display 269.76038813591(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743223190308 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000283002853393555 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994993209839 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000303030014038086 late. screenSaver idle display 269.49937081337(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.945529937744141 [norm] firing Slim::Utils::UPnPMediaServer::checkServerHealth 0 late. SimpleAsyncHTTP: GETing http://192.168.1.2:2869/upnphost/udhisapi.dll?content=uuid:83446da8-93d8-4602-a5b6-bff81c1c9fb0 Async: Connecting to 192.168.1.2:2869 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Adding error -> Slim::Networking::Async::_connect_error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Adding write -> Slim::Networking::Async::_async_connect [norm] set Slim::Networking::Async::_connect_error, in 4.99998688697815 sec select_time: 0 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] write, calling Slim::Networking::Async::_async_connect [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::_connect_error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing write Async: connected, ready to write request Async: Sending: GET /upnphost/udhisapi.dll?content=uuid:83446da8-93d8-4602-a5b6-bff81c1c9fb0 HTTP/1.1 Connection: close Cache-Control: no-cache Accept: */* Accept-Encoding: gzip, deflate Host: 192.168.1.2:2869 User-Agent: iTunes/4.7.1 (Windows; N; Windows XP; 586; EN; cp1252) SlimServer/6.5.4/12568 Icy-Metadata: 1 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Adding error -> Slim::Networking::Async::_async_error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Adding read -> Slim::Networking::Async::_async_read Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Wrote 310 bytes [norm] set Slim::Networking::Async::_async_error, in 4.99995803833008 sec [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00515508651733398 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.994669914245605 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00703310966491699 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.992783069610596 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0432710647583008 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::_async_read [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::_async_error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing read Async::HTTP: Headers read. code: 200 status: OK bless({ connection => "close", "content-length" => 5639, "content-type" => "text/xml", date => "Sun, 02 Dec 2007 17:04:52 GMT", server => "Microsoft-Windows-NT/5.1 UPnP/1.0 UPnP-Device-Host/1.0 Microsoft-HTTPAPI/1.0", }, "HTTP::Headers") [norm] set Slim::Networking::Async::HTTP::_http_socket_error, in 4.99998903274536 sec Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Adding error -> Slim::Networking::Async::HTTP::_http_socket_error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Adding read -> Slim::Networking::Async::HTTP::_http_read_body select_time: 0.0394449234008789 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_socket_error Async::HTTP: Read body: 1024 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99998998641968 sec select_time: 0.0376410484313965 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Async::HTTP: Read body: 1024 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99998998641968 sec select_time: 0.0364480018615723 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Async::HTTP: Read body: 1024 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99999117851257 sec select_time: 0.0354299545288086 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Async::HTTP: Read body: 1024 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99999189376831 sec select_time: 0.0343170166015625 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Async::HTTP: Read body: 284 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99999189376831 sec select_time: 0.0333189964294434 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Async::HTTP: Read body: 1024 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99999094009399 sec select_time: 0.031898021697998 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Async::HTTP: Read body: 235 bytes [norm] set Slim::Networking::Async::HTTP::_http_read_timeout, in 4.99999094009399 sec select_time: 0.030832052230835 Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] read, calling Slim::Networking::Async::HTTP::_http_read_body [norm] Killed 1 timer(s) for Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c) / Slim::Networking::Async::HTTP::_http_read_timeout Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing error Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing read Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] Removing write Select: [Slim::Networking::Async::Socket::HTTP=GLOB(0x5d9da8c)] removing writeNoBlock queue Async::HTTP: Body read SimpleAsyncHTTP: status for http://192.168.1.2:2869/upnphost/udhisapi.dll?content=uuid:83446da8-93d8-4602-a5b6-bff81c1c9fb0 is 200 OK SimpleAsyncHTTP: Done [norm] set Slim::Utils::UPnPMediaServer::checkServerHealth, in 59.9768390655518 sec select_time: 0.0281939506530762 select_time: 0.000159025192260742 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000673055648803711 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991893768311 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000664949417114258 late. screenSaver idle display 270.38845705986(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999727010726929 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00202584266662598 late. screenSaver idle display 270.762546062469(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999701976776123 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00208210945129395 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999992847442627 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00230216979980469 late. screenSaver idle display 270.50180888176(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999658107757568 sec select_time: 0.942975997924805 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999742031097412 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00197696685791016 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997822999954224 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0491888523101807 select_time: 6.98566436767578e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00170111656188965 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0016779899597168 late. screenSaver idle display 271.390267133713(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999729156494141 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00044703483581543 late. screenSaver idle display 271.763108968735(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00035405158996582 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000174045562744141 late. screenSaver idle display 271.502095937729(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999752998352051 sec select_time: 0.942801952362061 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999743938446045 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00195908546447754 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997858047485352 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0511360168457031 select_time: 6.91413879394531e-006 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000879049301147461 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000895977020263672 late. screenSaver idle display 272.391290187836(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999731063842773 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000902175903320313 late. screenSaver idle display 272.764127016068(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742984771729 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000890970230102539 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000905036926269531 late. screenSaver idle display 272.503114938736(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999757051467896 sec select_time: 0.941787958145142 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99837493896484 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00194811820983887 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997870922088623 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=89 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455845271 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=89 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10113853 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=91 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563236900 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0100870132446289 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989732980728149 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0440011024475098 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000843048095703125 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999989986419678 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.0010077953338623 late. screenSaver idle display 273.392431974411(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999696016311646 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00106096267700195 late. screenSaver idle display 273.765304088593(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999741077423096 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00105690956115723 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00106287002563477 late. screenSaver idle display 273.504290819168(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999757051467896 sec select_time: 0.940613031387329 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999743938446045 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00199198722839355 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997822999954224 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.053217887878418 select_time: 0.000200033187866211 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000833034515380859 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999989986419678 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000950098037719727 late. screenSaver idle display 274.393512010574(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999722957611084 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000936985015869141 late. screenSaver idle display 274.766356945038(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000924110412597656 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993801116943 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000940084457397461 late. screenSaver idle display 274.505346775055(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.93955397605896 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999742984771729 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00197196006774902 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997844934463501 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.054311990737915 select_time: 0.000310897827148438 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000559091567993164 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000622987747192383 late. screenSaver idle display 275.394263982773(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999680995941162 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000710964202880859 late. screenSaver idle display 275.767189025879(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000699996948242188 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993801116943 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000724077224731445 late. screenSaver idle display 275.506185770035(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999753952026367 sec select_time: 0.938713073730469 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999747037887573 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00195097923278809 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997865915298462 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0551528930664063 select_time: 9.89437103271484e-005 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000761032104492188 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991178512573 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000773191452026367 late. screenSaver idle display 276.395163059235(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999729871749878 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000695943832397461 late. screenSaver idle display 276.768001079559(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999743938446045 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000669002532958984 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000684022903442383 late. screenSaver idle display 276.506984949112(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999755144119263 sec select_time: 0.93791389465332 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999726057052612 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00204896926879883 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997767925262451 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0559720993041992 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000862836837768555 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999989986419678 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000984907150268555 late. screenSaver idle display 277.396278142929(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999722003936768 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00100588798522949 late. screenSaver idle display 277.769124031067(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742031097412 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000998973846435547 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00101399421691895 late. screenSaver idle display 277.508115768433(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.936784029006958 [norm] firing Slim::Networking::Slimproto::check_all_clients 0 late. Checking if 00:04:20:06:b0:44 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] Wrote 6 bytes Checking if 00:04:20:05:cb:18 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 6 bytes Checking if 00:04:20:06:ce:70 is still alive sending squeezebox frame: stat, length: 0 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 6 bytes [norm] set Slim::Networking::Slimproto::check_all_clients, in 4.99865698814392 sec select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00165390968322754 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.998069047927856 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 Select: [IO::Socket::INET=GLOB(0x5831f40)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.6:20946 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:b0:44 signalstrength=87 00:04:20:06:b0:44 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 455850271 output size: 3528000 output fullness: 3523840 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x5832b7c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.3:18110 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:06:ce:70 signalstrength=87 00:04:20:06:ce:70 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 10118854 output size: 3528000 output fullness: 0 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. Select: [IO::Socket::INET=GLOB(0x581e68c)] read, calling Slim::Networking::Slimproto::client_readable Slimproto client readable: 192.168.1.5:49229 state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining got op: STAT new state: LENGTH state: LENGTH, framelen: 0, inbuflen: 0 attempting to read 4 bytes Got 4 bytes from client, 0 remaining new state: DATA state: DATA, framelen: 43, inbuflen: 0 attempting to read 43 bytes Got 43 bytes from client, 0 remaining FACTORYTEST event=stat mac=00:04:20:05:cb:18 signalstrength=92 00:04:20:05:cb:18 Squeezebox stream status: event_code: stat bytes_rec_H 0 bytes_rec_L 0 fullness: 0 (0%) bufferSize 3145728 bytes_received 0 jiffies: 563241900 output size: 3528000 output fullness: 2936960 elapsed seconds: 0 new state: OP state: OP, framelen: 0, inbuflen: 0 attempting to read 4 bytes no more to read. [norm] firing Slim::Buttons::Common::_periodicUpdate 0.0100119113922119 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.989808082580566 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0490589141845703 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000807046890258789 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000896930694580078 late. screenSaver idle display 278.397349119186(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999719142913818 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00100493431091309 late. screenSaver idle display 278.770246982574(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999740839004517 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00104284286499023 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00120902061462402 late. screenSaver idle display 278.509442806244(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.9997398853302 sec select_time: 0.935439109802246 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999744892120361 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00202703475952148 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997785091400146 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0579159259796143 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000716209411621094 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000741004943847656 late. screenSaver idle display 279.398220062256(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999731063842773 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000699043273925781 late. screenSaver idle display 279.771064996719(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742031097412 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.00049281120300293 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999994039535522 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00049901008605957 late. screenSaver idle display 279.510054826736(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999750852584839 sec select_time: 0.934842109680176 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999737977981567 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00202608108520508 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997710943222046 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0588381290435791 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000757932662963867 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991178512573 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000821113586425781 late. screenSaver idle display 280.399170160294(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999732971191406 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00082707405090332 late. screenSaver idle display 280.772006988525(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999741077423096 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000805139541625977 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000901937484741211 late. screenSaver idle display 280.511074781418(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999742984771729 sec select_time: 0.933811902999878 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999747037887573 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00197196006774902 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997845888137817 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0600051879882813 select_time: 0.00012516975402832 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000789880752563477 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999990940093994 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000840902328491211 late. screenSaver idle display 281.400140047073(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999729871749878 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000896930694580078 late. screenSaver idle display 281.773020982742(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999744892120361 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000809907913208008 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000812053680419922 late. screenSaver idle display 281.512002944946(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999751091003418 sec select_time: 0.932892084121704 [norm] firing Slim::Buttons::Common::_periodicUpdate 0 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.999746084213257 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x581e68c)] Wrote 1290 bytes select_time: 0 [norm] firing Slim::Buttons::Common::_periodicUpdate 0.00202202796936035 late. [norm] set Slim::Buttons::Common::_periodicUpdate, in 0.997793912887573 sec sending squeezebox frame: grfe, length: 1284 Select: [IO::Socket::INET=GLOB(0x5832b7c)] Wrote 1290 bytes select_time: 0.0608229637145996 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000786066055297852 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999991178512573 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000869989395141602 late. screenSaver idle display 282.401139974594(mode:INPUT.List) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.99973201751709 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.000859975814819336 late. screenSaver idle display 282.773998975754(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.9997398853302 sec select_time: 0 [norm] firing Plugins::WeatherTime::Plugin::tictac 0.000856876373291016 late. [norm] set Plugins::WeatherTime::Plugin::tictac, in 0.999993085861206 sec select_time: 0 [norm] firing Slim::Buttons::ScreenSaver::screenSaver 0.00087285041809082 late. screenSaver idle display 282.512987852097(mode:OFF.weathertime) [norm] set Slim::Buttons::ScreenSaver::screenSaver, in 0.999754905700684 sec select_time: 0.931914091110229 Select: [HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)] read, calling Slim::Web::HTTP::processHTTP reading request... HTTP request: from 127.0.0.1 (HTTP::Daemon::ClientConn=GLOB(0x5d8f05c)) for GET HTTP/1.1 /log.txt processURL Clients: 192.168.1.6:20946 192.168.1.5:49229 192.168.1.3:18110 Generating response for (txt, text/plain) log.txt generating from include.html type: fill found path: C:\Program Files\SlimServer6.4\server\HTML\EN\include.html idleStreams: select_time: 0, checkTimers: 1