Bugzilla – Bug 14025
PrefPane locks up when accessing Squeezebox Control Panel
Last modified: 2010-04-08 17:25:48 UTC
I have seen this periodically in the last week or two. I saw it on 10.5 and still see it after upgrading to 10.6. Last time I saw it was on Friday, 9/11 which would have been build 28494. I have not been able to reliably reproduce it. Usually it happens while opening the Squeezebox CP. System Prefs just hangs there, and does not open/display the SB CP. Accessing "Force Quit" reports the SysPrefs as "unresponsive". Sometimes quitting SysPrefs and reopening solves it. Sometimes quitting and reopening sees it hang again. If there are any specific logging that would help, let me know and I'll attach next time I see this.
Do you know whether SC is running or not when you encounter this issue? There _might_ be some information in the OSX console application.
If you could create a clearly reproducible case I could probably add some debugging code to get more information out of the logs. But I'm at a loss here. Did you get customer feedback on this issue?
== Auto-comment from SVN commit #28524 to the slim repo by michael == == https://svn.slimdevices.com/slim?view=revision&revision=28524 == Bug: 14025 +2 Description: add some logging to the preference pane
Dan - as of revision 28524 the preference pane is now pretty verbose about its activity. If you see lock ups again, please open OSX' console application and filter the log for "squeezebox". You should then see some traces of what it's doing.
Thanks, Michael. When I see this again I'll check the Squeezebox log and post it here.
> Thanks, Michael. When I see this again I'll check the Squeezebox log > and post it here. Great! Just don't forget to update to today's build (manually if needed...), as it will contain additional logging.
Created attachment 5869 [details] Log of console while CP locked up Not much to see here, I think. at 4:57 I clicked "Stop" in the CP and SysPrefs locked up. ("Not responding") about 5 mins prior, I started the server and saw SysPrefs lock up, but I waited a minute or so and it recovered and worked normally. Then I tried stopped it and saw the above behavior.
Hmm... I think we're getting closer: do you see the lock when starting/stopping SC? There seems to be a hard coded timeout of 240 seconds(!) in the method I'm using to communicate with SC. Whenever you encounter this lockup again, please be patient. Maybe it will recover after four minutes. I'd like to know whether this is the case. I'll need to change this to using async communication. But this needs major refactoring which I won't do before the 7.4 release.
http://forums.macrumors.com/showthread.php?t=766470 - reference to the 240 seconds timeout
== Auto-comment from SVN commit #28564 to the slim repo by michael == == https://svn.slimdevices.com/slim?view=revision&revision=28564 == Bug: 14025 +0.5 Description: don't do JSON requests if SBS is not running. Use "stopserver" command instead of killing the perl task to gracefully stop the server. This might reduce the risk of locking up the preference pane.
Created attachment 5871 [details] Log of console while CP locked up I agree that I only seem to see this when I start/stop the server. I tried this again this morning. At about 12:19 I stopped the server. Activity Monitor showed SysPrefs as "not responding" for about 60 seconds, then it recovered. But I was not able to interact with SysPrefs. Anytime I tried selecting it or alt-tab'ing to it, it'd go "not responding" again for 30-60 seconds then appear to recover. But never was I able to truly open it.
I then tried starting the server after the above test. Again it locked up but... after a couple minutes it recovered _and_ I was able to access everything.
Dan - please try again with something later than r28564
Dan - any news?
[ from thread: http://forums.slimdevices.com/showthread.php?t=68246 ] >> When I try to stop SbS, the control panel hangs about 3 out of 4 times. > > What revision? I've (what I hoped) improved this behaviour a few days ago. The problem occurs routinely, so I have not been tracking the revision numbers. I updated early evening on both the 22nd and the 23rd. The hang occurred most recently last night, when I posted the forum thread mentioned above. So it would have been the nightly that was built in the wee hours of the 23rd. Sorry, I'll track revisions now that I see others notice the issue too. I'll test tonight (with the existing install, and with last night's build after the update). > What OSX version? Both 10.5.6, 10.6 > > If you just left it hanging, would it eventually recover (keep waiting up > to five minutes)? I have no patience to wait 5 minutes! :-) Seriously, I wouldn't have anticipated much longer than a minute. It really is too long to take control of a portion of the UI. >> I think I've seen this for a couple of months, and I figured it would >> probably get resolved when Michael became tired of having his CP hang >> too many times. Apparently it doesn't bother him. :-) > > It would if I saw it :-). But while I see it sometimes be a bit on the > slower side (a few seconds delay) it wouldn't hang on my system. Ok, well, there's a data point. I wonder why you've not experienced it as many times as I have. I would have expected the opposite, since you probably cycled the start/stop many more times than I. > Does it _hang_ or _crash_? Only hangs, where "hang" means spiny, colored apple ball spinning for > 1 minute. :-)
Created attachment 5925 [details] Another console log watching prefpane hang I am still seeing this hanging in the prefpane. Using build 28624. In the attached log, I stopped the server and it stopped successfully-- no hang. Then started the server-- it did hang. Activity monitor reported it "not responding" for a time. Then after about 1.5 to 2.0 mins it recovered and was usable.
Created attachment 5926 [details] Log of CP hang, immediately following above attachment Right after the above I tried shutting down the server. (to test bug 13805) This time the prefpane hung indefinitely. Server was stopped at 6:31. Log attached.
Thanks for the updates. Case not closed :-( Mike - I know you're not patient enough to do this. But could you still try to wait some 6 minutes or so next time you see this happen? I'd really like to understand whether it's that hard-coded timeout we're hitting here. Just let it sit there, take a break and check later again. Ok? Thanks!
I'm having trouble reproducing it this morning, but will continue to try throughout the day. Ok, Ok, I'll wait __6__ minutes...but not one second longer! :-)
Created attachment 5933 [details] console log from SB pref hang
Ok, posted a log. I think it has been spinning for about 10 minutes.
Curious, at some point, the CP became usable again, and the server seems to have stopped. I think the stop event was registered at 8:55, and as of the time I posted the log (9:12), it was still hung. There were no more Squeezebox log entries until 10:29. At 9:14, there was a throttled respawn of com.apple.pbs (launchd.peruser). The only other messages are GrowlHelperApps and a couple of Dashboard entries.
not a sky-is-falling problem
Dan have you seen this since the first report?
I'm not Dan, but I did report also on this. I was able to reproduce this in about 10 minutes of trial. The CP has been hung spinning away for over 15 minutes now.
Mike: Can you retest with 7.4.1, are you still able to get the CP to lock up?
I retested this afternoon w/7.4.1 v28807. I reproduced the problem within 3 attempts. The beachball is still spinning 23 minutes later.
(In reply to comment #27) > I retested this afternoon w/7.4.1 v28807. I reproduced the problem within 3 > attempts. The beachball is still spinning 23 minutes later. Same issue with 7.4.1 - 28913, but have not timed it.
I'm sorry, not critical enough to hold off the Touch release.
*** Bug 14790 has been marked as a duplicate of this bug. ***
== Auto-comment from SVN commit #30286 to the slim repo by mherger == == https://svn.slimdevices.com/slim?view=revision&revision=30286 == Bug: 14025 Description: start moving json requests to async methods. Start with the most frequently used rescanprogress query. Reduce logging.
== Auto-comment from SVN commit #30287 to the slim repo by mherger == == https://svn.slimdevices.com/slim?view=revision&revision=30287 == Bug: 14025 Description: use async JSON requests whenever we don't need the returned values
Dan/Mike - I've replaced some of the blocking code, and imho behaviour on 10.6 is now _much_ better. This code is only in 7.5/embedded so far, but I'd like to see it tested by users who have experienced this issue. What SBS versions/builds are you running now? I could easily do a 7.5/trunk build with these improvements if you were interested and willing to give 7.5 a try. I'm not sure I can get this in to the 7.5 release. But if you could test and confirm it's considerably better than before, then chances are much higher.
== Auto-comment from SVN commit #30289 to the slim repo by mherger == == https://svn.slimdevices.com/slim?view=revision&revision=30289 == Bug: 14025 Description: reduce timeout on regular scan progress query - it's being called soon again anyway. Disable rescan button when server is down.
== Auto-comment from SVN commit #30290 to the slim repo by mherger == == https://svn.slimdevices.com/slim?view=revision&revision=30290 == Bug: 14025 Description: make music library stats update use async calls
== Auto-comment from SVN commit #30291 to the slim repo by mherger == == https://svn.slimdevices.com/slim?view=revision&revision=30291 == Bug: 14025 Description: there are still synchronous requests being used. Minimize risk of running any of them while SBS isn't available by not only checking for the pid, but the availability of the http port too. Use async results to update availability status as quickly as possible: set webState to false if async request fails. Don't hardcode port 9000 - use the result of the web port check instead.
Time used
== Auto-comment from SVN commit #30304 to the slim repo by mherger == == https://svn.slimdevices.com/slim?view=revision&revision=30304 == Fixed Bug: 14025 Description: pulling back prefpane async changes from embedded branch to trunk
Michael-- I'm currently on beta 7.5 r30285. It updated yesterday. (and it was the bumpiest update I've seen in a while.) I'd be happy to test this. Just let me know what build I should use. Also can you clarify what you mean by "embedded"? are you referring to tinysbs?
Dan - I've backported the changes to 7.5/trunk. If you install the latest nightly 7.5 build, you should already get it.
This bug has been marked fixed in a released version of Squeezebox Server or the accompanying firmware or mysqueezebox.com release. If you are still seeing this issue, please let us know!