Bugzilla – Bug 7524
Non-blocking connect() fails on win32
Last modified: 2009-07-31 10:18:05 UTC
Audioscrobbler failed to communicate with the LastFM server to send scrobbled track information. This should be a background activity, that tries to resend every so often. However, it is trying every ~25 seconds. This is blocking my server from doing much anything else. Tracks stutter, remote control becomes unresponsive, etc. The resend period seems a little too frequent - perhaps it should back off more and more on consecutive errors (try again in 30 secs, then 1 minute, then 5 minutes, then 1/2 hour, etc). The underlying issue though seems to be that something is blocking when it shouldn't. Eg. perhaps Slim::Networking::Async package blocks on the attempt to connect until the timeout occurs?
Created attachment 3094 [details] Async errors small chunk of my logfile during the period when I get errors from async connection attempts.
connect() is async, nothing should be blocking here.
Can you enable server.select and network.asynchttp debug and make a new log showing the problem?
I don't believe it will block, but run the server with --perfwarn=0.5 to prove whether the main loop has stopped spinning. This will give error messages for any tasks which take longer than 0.5 secs.
Thanks - I will increase logging and add the perfwarn flag. I have only noticed the problem when I play music and lastFM servers are not responding (and possibly when SqueezeNetwork servers are not responding), so I'll have to wait until the next time that occurs.
Assigning back to Phil to provide a log.
Ping Phil....
I haven't forgotten - I'm waiting for a re-occurrence of the LastFM connection errors, which happen from time to time (generally weekends).
Any update, Philip? Time for 7.0.1 is getting close, so we may retarget this shortly :)
I haven't noticed the problem occurring recently; lastFM servers have been behaving themselves. I will try setting up a local alias for a lastfm server to redirect it elsewhere to see if I can simulate the issue and capture the trace. I shall try tonight...
Created attachment 3215 [details] log file I managed to catch some trace when there were connection problems connecting to post.audioscrobbler.com. I've attached a small portion of the log with the requested network.asynchttp and server.select in debug level. With these debug levels enabled, there's loads of trace (many lines logged per second). However, you can see in the log that there is a 20 second pause after 23:52:07.0023, when it attempts a connection, and trace then resumes at 23:52:28.0000 (20 secs later) when it reports a Slim::Networking::Async::_connect_error.
Ack, thanks. I guess I need to do some testing under Windows.
I ran again with --perfmon=0.5: [00:07:43.6887] Slim::Networking::Async::connect (117) Connecting to post.audioscrobbler.com:80 [00:08:04.6562] Slim::Networking::Select::_updateSelect (147) fileno: [18] Adding error -> Slim::Networking::Async::_connect_error [00:08:04.6570] Slim::Networking::Select::_updateSelect (147) fileno: [18] Adding write -> Slim::Networking::Async::_async_connect [00:08:04.6577] Select Task > 0.5 : 20.97559 Slim::Networking::Async::DNS::_dns_read [00:08:04.6591] Slim::Networking::Select::writeNoBlock (296) fileno: [14] Wrote 1290 bytes [00:08:04.6600] Response Time > 0.5 : 20.97781 [00:08:04.6605] Slim::Networking::Select::select (232) fileno [18] error, calling Slim::Networking::Async::_connect_error
Hmm, can you make a new log and include network.asyncdns in addition to server.select and network.asynchttp and --perfwarn=0.5?
Created attachment 3218 [details] log file with more debug stuff includes network.asyncdns.
Hmm, that log does not seem to include either network.asynchttp or network.asyncdns logging. You should have a lot more output.
Created attachment 3220 [details] Another log Includes debug trace for network.asyncdns, network.asynchttp, server.select.
And you're running Windows XP?
Yes, WinXP Pro. Currently running 7.1/trunk, using activePerl, running as a service via servany.exe
SqueezeCenter Version: 7.1 - TRUNK @ UNKNOWN - Windows XP - EN - cp1252 Server IP address: 192.168.1.2 Perl Version: 5.8.8 MSWin32-x86-multi-thread MySQL Version: 5.0.37-community-nt Platform Architecture: 586
OK I've found it, non-blocking connect doesn't work under win32 without a lot of hacks. Luckily, POE seems to have these hacks, so I'll try copying those and see how they work out.
Fixed in change 18662.
(In reply to comment #22) > Fixed in change 18662. > Phil: can you verify this is working for you now. If it is not, please reopen the bug and attach another log file.
I can verify that it appears to be working for me now.
This bug has recently been fixed in the latest release of SqueezeCenter 7.0.1 Please try that version, if you still see the error, then reopen this bug. To download this version, please navigate to: http://www.slimdevices.com/su_downloads.html
Reduce number of active targets for SC