Bugzilla – Bug 3656
6.3.0 Logs filling up with backtraces
Last modified: 2011-03-16 04:39:12 UTC
My Slimserver log is filling up with the following (listed over and over again): 2006-06-29 08:13:12.3273 Backtrace: frame 0: Slim::Utils::Misc::assert (/usr/local/slimserver/Slim/Buttons/ScreenSaver.pm line 60) frame 1: Slim::Buttons::ScreenSaver::screenSaver (/usr/local/slimserver/Slim/Utils/Timers.pm line 105) frame 2: Slim::Utils::Timers::checkTimers (/usr/local/slimserver/slimserver.pl line 707) frame 3: main::idle (/usr/local/slimserver/slimserver.pl line 638) frame 4: main::main (/usr/local/slimserver/slimserver.pl line 1276) Here's the problem. /usr/local/slimserver/Slim/Buttons/ScreenSaver.pm, line 60: 50 my $now = Time::HiRes::time(); 51 52 $::d_time && msg("screenSaver idle display " . ( 53 $now - Slim::Hardware::IR::lastIRTime($client) - 54 $client->prefGet("screensavertimeout")) . 55 "(mode:" . Slim::Buttons::Common::mode($client) . ")\n" 56 ); 57 58 my $mode = Slim::Buttons::Common::mode($client); 59 60 assert($mode); 61 62 # some variables, so save us calling the same functions multiple times. 63 my $saver = Slim::Player::Source::playmode($client) eq 'play' ? $client->prefGet('screensaver') : $client->prefGet('idlesaver'); 64 my $dim = $client->prefGet('idleBrightness'); 65 my $timeout = $client->prefGet("screensavertimeout"); 66 my $irtime = Slim::Hardware::IR::lastIRTime($client); 67 68 # if we are already in now playing, jump back screensaver is redundant and confusing 69 if ($saver eq 'screensaver' && $mode eq 'playlist') { 70 $saver = 'playlist';
is there no client connected? This report indicates that the $mode or state that the player is in, is not valid. If there is a player connected, what is it doing at the time/what is showing on the display?
The player being used is Softsqueeze 2.7. Various Internet Radio Plugins are being used. I noticed these backtraces while debugging a login problem. They are not effecting playback/usage, but the quickly expanding log could fill up disk space on a user's computer.
Which radio plugin were you using forlogin at the time? a missing mode could be the result of a bad plugin state. This backtrace is there for a good reason. There really shouldn't be any point in normal operation where it gets triggered. As I've mentioned on another report, these backtraces are not showing up on my system. The average user would never see them, so the log expansion isn't really a big concern. a logrotate script would suffice, but is probably not a high priority.
I had been using RadioIO, LastFM, and SiriusRadio. Don't know which one was causing issues. I know the latter two are user community contributions, but they are listed on your plugin section, so I assume they are somewhat "certified" (albeit by the author) to work with a given release. Perhaps it's time to start a certification program, so you guys don't have to be accountable support/fix other's errors.
Just for clarity...I'm not "you guys". I'm a third party as well. Certification is a tough thing when it comes to open source. Anyone can do anything, really. The wiki covers plugins, and users can add their own notes as to what versions work with what server versions. If I had to make a guess, I'd try taking sirius radio plugin off the system to see if that makes a difference. I use LastFM, and haven't noticed backtraces. I don't, however, have any access to sirius, so I'll go with the unknown. I am aware that the author has posted recently about doing some cleanup work on the plugin, but I am not sure if this applies to 6.3 or 6.5 builds. 6.3 isn't all that different from 6.2, so most plugins should be fine. you could try running manually: slimserver.pl --d_plugins and see if there are any warnings given when loading the plugins. If we narrow down the source of the problem, we can notify the author, or post in the Plugins forum to see if others are having this issues with lastFM or Sirius. I'll try RadioIO, and I'm sure Chris (assigned above) will be better able to try to reproduce this will all three plugins.
Sorry to have lead you on a chase. I should have searched earlier on this. This, too, has come up in the past, albeit, when connected to SqueezeNetwork. Chris, make sure to have a look at bug 3143 when you get a chance to review this. The assert backtrace is eactly the same, but Dan/Andy haven't left any more comments as ot whether this is seen often or not. This looks like we have a case that might be reproduceable. Bradley, I'm less certain now that this is plugin related. I'll have to leave this for Chris and SD gang to sort out.
I'll add it to my list.
Dan, can you work with this or would you like me to do something with it?
If you can find a way to reproduce it Chris, that would be great.
Created attachment 1375 [details] test case I noticed this when I was trying to fix another bug. This is a diff to force a test case that might explain what is going wrong here. I think that this is most likely a bad plugin mode, but I suppose there could be other cases. After applyging this patch, you can press SEARCH to go into browse menu (so that this will work with existing harware). The modestack isforced to top, then the jump to menu. Pressing LEFT at this point will start the backtraces. If a plugin were set to the top level, it's possible that the setMode function might not be protecting against backing into nothing. We may be able to block this from happening with some changes to popMode, but I am not secure in my knowledge of the modestack enough to do it all on my own. ideas?
So I poked at this a bit with your test case, but couldn't make heads or tails of it.. Dean?
I think you are looking for feedback from KDF?
the test is a force and should never really occur but it causes the matching backtrace. Were you not able to see the results or not make sense of the results? basically any plugin or mode that pops too far, say a double pop mode to overcompensate for a jump to an INPUT.* mode (we used to run into this initially before we got used to it), you end up with a NULL mode and the backtrace. I was thinking, just to protect against this that perhaps popMode would lock at 'home' since we should never pop that mode anyway.
Subject: Re: 6.3.0 Logs filling up with backtraces A pop mode that essentially pushes home if the mode stack gets empty would be great, but it doesn't address the root bug this guy saw (and we can't reproduce).
Well, it's hard to fix when we can't reproduce.. kdf's idea is a good start. Kevin - do you have a patch, or shall I look at it? Thanks
I'm going to mark this as fixed, since we've been unable to reproduce it here using 6.5 Please reopen if you see it again using 6.5 Thanks.