Bug 8110 - Massive logging for error in Select
: Massive logging for error in Select
Status: RESOLVED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Misc
: 7.2
: PC Debian Linux
: -- normal with 1 vote (vote)
: ---
Assigned To: Adrian Smith
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2008-05-10 01:39 UTC by Adrian Smith
Modified: 2008-05-11 15:09 UTC (History)
2 users (show)

See Also:
Category: ---


Attachments
zipped log file (2.17 KB, application/x-zip-compressed)
2008-05-11 11:04 UTC, Ken
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Adrian Smith 2008-05-10 01:39:02 UTC
Seen on 7.2 by aubuti:

SqueezeCenter Version: 7.2 - 19575 @ Fri May 9 00:15:58 PDT 2008 - Debian - EN - utf8
Perl Version: 5.8.8 powerpc-linux-gnu-thread-multi
MySQL Version: 5.0.22-Debian_4
Platform Architecture: ppc-linux
Server Port Number: 9000
Total Players Recognized: 4


[08-05-09 16:02:33.3067] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at /mnt/usr/local/slimserver/Slim/Networking/Select.pm line 282.
[08-05-09 16:02:33.3155] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at /mnt/usr/local/slimserver/Slim/Networking/Select.pm line 282.
[08-05-09 16:02:33.3243] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at /mnt/usr/local/slimserver/Slim/Networking/Select.pm line 282.
[08-05-09 16:02:33.3331] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at 

More detail suggesting related to async:

[08-05-09 21:36:39.9784] Slim::Networking::SimpleAsyncHTTP::onBody (203) status for http://post.audioscrobbler.com/<deleted> is 200 OK
[08-05-09 21:36:39.9858] Slim::Networking::SimpleAsyncHTTP::onBody (313) Done
[08-05-09 21:36:40.0000] Slim::Networking::SimpleAsyncHTTP::_createHTTPRequest (105) POSTing http://87.117.229.205:80/protocol_1.2
[08-05-09 21:36:40.0221] Slim::Networking::Async::connect (117) Connecting to 87.117.229.205:80
[08-05-09 21:36:40.0376] Slim::Networking::Select::_updateSelect (147) fileno: [19] Adding error -> Slim::Networking::Async::_connect_error
[08-05-09 21:36:40.0450] Slim::Networking::Select::_updateSelect (147) fileno: [19] Adding write -> Slim::Networking::Async::_async_connect
[08-05-09 21:36:40.1311] Slim::Networking::Select::select (232) fileno [19] write, calling Slim::Networking::Async::_async_connect
[08-05-09 21:36:40.1438] Slim::Networking::Select::_updateSelect (180) fileno: [19] Removing error
[08-05-09 21:36:40.1511] Slim::Networking::Select::_updateSelect (180) fileno: [19] Removing write
[08-05-09 21:36:40.1574] Slim::Networking::Async::_async_connect (189) connected, ready to write request
[08-05-09 21:36:40.1814] Slim::Networking::Async::write_async (219) Sending: [POST /protocol_1.2 HTTP/1.1
Connection: close
Cache-Control: no-cache
Accept: */*
Accept-Encoding: gzip, deflate
Host: 87.117.229.205
User-Agent: SqueezeScrobbler/0.38
Content-Type: application/x-www-form-urlencoded
Icy-Metadata: 1
Content-Length: 61179

<deleted>
[08-05-09 21:36:40.1993] Slim::Networking::Select::_updateSelect (147) fileno: [19] Adding error -> Slim::Networking::Async::_async_error
[08-05-09 21:36:40.2067] Slim::Networking::Select::_updateSelect (147) fileno: [19] Adding read -> Slim::Networking::Async::_async_read
[08-05-09 21:36:40.2137] Slim::Networking::Select::writeNoBlock (296) fileno: [19] Wrote 61445 bytes
[08-05-09 21:36:40.2205] Slim::Networking::Select::writeNoBlock (325) fileno: [19] Incomplete message, sent only: 14480
[08-05-09 21:36:40.2283] Slim::Networking::Select::_updateSelect (147) fileno: [19] Adding write -> Slim::Networking::Select::writeNoBlock
[08-05-09 21:36:40.3735] Slim::Networking::Select::select (232) fileno [14] read, calling Slim::Networking::Slimproto::client_readable
[08-05-09 21:36:40.4409] Slim::Networking::Select::select (232) fileno [19] write, calling Slim::Networking::Select::writeNoBlock
[08-05-09 21:36:40.4476] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at /mnt/usr/local/slimserver/Slim/Networking/Select.pm line 282.
[08-05-09 21:36:40.4563] Slim::Networking::Select::select (232) fileno [19] write, calling Slim::Networking::Select::writeNoBlock
[08-05-09 21:36:40.4630] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at /mnt/usr/local/slimserver/Slim/Networking/Select.pm line 282.
[08-05-09 21:36:40.4718] Slim::Networking::Select::select (232) fileno [19] write, calling Slim::Networking::Select::writeNoBlock
[08-05-09 21:36:40.4785] Slim::Networking::Select::select (245) Error: Select task failed: Not a SCALAR reference at /mnt/usr/local/slimserver/Slim/Networking/Select.pm line 282.
[08-05-09 21:36:40.4872] Slim::Networking::Select::select (232) fileno [19] write, calling Slim::Networking::Select::writeNoBlock
Comment 1 Adrian Smith 2008-05-10 01:41:33 UTC
I believe this to be due to writeNoBlock getting called with passback parameters from select when the socket can't write everything in one go.  This looks to me to be a risk with writeNoBlock at present so will look to avoid it and see if it fixes aubuti's problem.
Comment 2 Adrian Smith 2008-05-10 01:51:26 UTC
potential fix in change 19626
Comment 3 Adrian Smith 2008-05-11 04:23:15 UTC
Ken - this fix should be in the latest 7.2 build so please try and report back if it fixes the problem.
Comment 4 Ken 2008-05-11 11:04:07 UTC
Created attachment 3334 [details]
zipped log file
Comment 5 Ken 2008-05-11 11:05:57 UTC
Sorry for the fumbling in bugzilla. I had meant to include this message with the zipped log file. Thanks again for getting right on this problem.

Comment 6 Ken 2008-05-11 11:09:51 UTC
Okay, let's see if 3rd try does it: Thanks, that seems to have cleaned things up quite a bit. I've been listening for a few hours to local flac tracks and internet radio. Still getting a few Async http errors that appear to be connected with SqueezeScrobbler and finding one of the internet radio streams (that's my uneducated guess at least), but nothing like the errors it was throwing before. Log is attached.
Comment 7 Adrian Smith 2008-05-11 11:19:38 UTC
This looks to have cleared the original error which was due to a server bug.

The remaining entries are either down to timeouts connecting to remote servers or looking for dns names which don't appear to exist.  These are normal, though you may be able to reduce the timeout ones by increasing the radiostation timeout setting.

Other than that I consider this fixed and will close the bug.  Please reopen if you see significant log messages again.
Comment 8 Ken 2008-05-11 15:09:26 UTC
sounds good to me.