Bugzilla – Bug 3860
RSS newsfeed screensaver kicking in whilst browsing
Last modified: 2008-09-15 14:39:24 UTC
This morning whilst browsing through my music library via Player UI, I experienced error messages from the RSS plugin. It was reporting that it couldn't get a feed (sorry, I can't remember exactly what the message said). It was annoying though that the error message came up very frequently whilst trying to browse the library. It was almost after every remote keypress that the screensaver reported the problem. My scrensavers are set up as: when playing: Now Playing (Jump back on wake) not playing: RSS News Ticker powered off: Date and Time Screensaver Screensaver delay time in seconds: 30 The screensaver was trying to display itself (or at least report a timeout problem) whilst I was using the unit. I think it should wait for 30 seconds of inactivity before reporting the problem, and then if the user starts interacting again, it should wait another 30 seconds of inactivity before reporting the problem again. NB. The previous night I tried to browse newsfeeds manually. Several of my feeds were accessible, whilst a couple (I think Slashdot and certainly my weather feed http://www.mopoke.co.uk/weather/2045.xml reported parse errors).
I tried just giving it a totally invalid feed, and didn't get the kind of interruptions you reported. I also tried disconnecting the Internet connection for the PC (while leaving the connection to the Squeezebox intact, of course). I'll leave this one open for now so you or any other users that see this issue can add information about what kind of quirks in an RSS feed might cause this. I'll also cc Dan in case it rings any bells for him.
I THINK this is somewhat related to bug 3066. It isn't so much a case of an unparseable feed, but of one that is unreachable. I've noticed this on softsqueeze when I'm at work and stupidly leave rss running when idle. Nothing is reachable from behind the firewall. Occasionally if I start to browse in mid-request, the error does seem to come back some time later while I'm browsing. Perhaps it could be as simple as the errorCallback having a check for the current mode, that it matches xmlbrowser or that there has been some X seconds since IR input.
Dean suggests that we detect if the user is doing stuff and kill the timer for the error.
One reasonable place to do this would be Power::wakeup I think. This way the ir processing has already done the preliminary work of determining that the activity is legitimate IR meant for squeezebox and is a valid button. After all, if the wakeup function is good enough to monitor activity for screensaver timing, it should be good enough to determine activity for killing an rss error timer. However, there is also the leaveScreenSaverRSSNews, which probably could kill it too. The final call would depend on what timer is the right one to kill. XMLBrowser error is a server function, so if the error is in the server, it should be a server function to kill it. If the err callback in in the plugin, then the screensaver should do the killing. What I don't know offhand is where the offending timer is that is bringing up the persistent display.
I'm afraid I can't duplicate this. Can anyone provide some steps to reproduce? I don't think the RSS screensaver ever reports errors, it just skips over bad feeds. Is this actually referring to errors that show up when manually browsing RSS?
I will try to find some repeatable sequence later when I am at a squeezebox. Essentially I think I left my squeezebox in idle. Nothing was playing, so the RSS feed screen saver would have kicked in. I guess my Internet connection went down, so it couldn't get the feeds. When I started to browse for music to play, I kept getting the error report that it couldn't get the feed.
I had an occurance of this again this morning. Frequently when I tried to navigate on a squeezebox with the remote control, I got a message saying it was requesting a feed. The funny thing was it would get the feed and start scrolling the news across the display, and then jump back to the menu I was trying to access. Looking in my log file, I saw the following lines. This was the first line in the log file - must have been when I restarted the server: 2006-09-02 23:45:19.0468 Aysnc: No DNS servers responded, you may have trouble with network connections. Please check your network settings. 2006-09-02 23:45:19.1244 UPnP: Error adding multicast membership, UPnP may not work properly: Unknown error I don't recall noticing any other network problems around that time. My broadband connection isn't good at the moment, due to an "upgrade" to ADSL Max that has caused my downstream rate to go up to 2.5Mb, but my throughput has dropped to 0.25Mb. I can still access web sites and haven't had any DNS issues though. I then see loads of log lines like the following, which correspond to the time I was experiencing the problem this morning: 2006-09-03 09:37:02.7501 current rss feed not set 2006-09-03 09:37:02.7877 Backtrace: frame 0: Slim::Utils::Misc::assert (P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 595) frame 1: Plugins::RssNews::tickerLines (P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 537) frame 2: Plugins::RssNews::tickerUpdateContinue (P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 461) frame 3: Plugins::RssNews::tickerUpdate (P:\Music\SlimServer\trunk\server/Slim/Utils/Timers.pm line 181) frame 4: Slim::Utils::Timers::checkTimers (P:\Music\SlimServer\trunk\server\slimserver.pl line 506) frame 5: main::idle (P:\Music\SlimServer\trunk\server\slimserver.pl line 456) frame 6: main::main (P:\Music\SlimServer\trunk\server\slimserver.pl line 1055) Here's the problem. P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm, line 595: 585 # lines for tickerUpdate to add to ticker 586 sub tickerLines { 587 my $client = shift; 588 589 my $parts = {}; 590 my $new_feed_next = 0; # use new feed next call 591 592 # the current RSS feed 593 my $feed = $client->param('PLUGIN.RssNews.current_feed'); 594 595 assert( ref $feed eq 'HASH', "current rss feed not set\n"); 596 597 # the current item within each feed. 598 my $current_items = $client->param('PLUGIN.RssNews.current_items'); 599 600 if ( !defined $current_items ) { 601 602 $current_items = { 603 $feed => { 604 'next_item' => 0, 605 'first_item' => 0, 2006-09-03 09:37:02.7882 Use of uninitialized value in anonymous hash ({}) at P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 602, <SRC> line 912. 2006-09-03 09:37:02.7887 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 684, <SRC> line 912. Hope there's something in there that will help fix this problem!
Can you list all of the feeds you are using, assuming you're not using just the default feeds?
plugin_RssNews_feeds: - http://newsrss.bbc.co.uk/rss/newsonline_uk_edition/uk/rss.xml - http://newsrss.bbc.co.uk/rss/sportonline_uk_edition/football/rss.xml - http://rss.slashdot.org/Slashdot/slashdot - http://news.com.com/2547-1_3-0-5.xml - http://www.mopoke.co.uk/weather/2045.xml plugin_RssNews_feeds_modified: 1 plugin_RssNews_feeds_version: 1 plugin_RssNews_items_per_feed: 3 plugin_RssNews_names: - BBC News | UK | UK Edition - BBC Sport | Football | UK Edition - Slashdot - CNET News.com - "BBC weather : Farnborough, United Kingdom"
Can you try the latest nightly and see if the problem still occurs?
I still had problems last night. The squeezebox seemed to be getting feeds, but was still interrupting menu navigation. I saw a message that it was going to get feeds, and pressed an arrow key to resume navigation. A second or so later, the feed started to scroll across the display, so I pressed an arrow key again. A few seconds later, the feed reappeared. I can still see various trace errors and warnings in the log. I've cut out a load of identical error sections: 2006-09-06 00:02:07.5123 Use of uninitialized value in hash element at P:\Music\SlimServer\trunk\server/Slim/Player/Client.pm line 1445. 2006-09-06 00:03:34.6999 Use of uninitialized value in split at P:\Music\SlimServer\trunk\server/Slim/Display/Display.pm line 459. 2006-09-06 00:03:50.4474 current rss feed not set 2006-09-06 00:03:50.4490 Backtrace: frame 0: Slim::Utils::Misc::assert (P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 602) frame 1: Plugins::RssNews::tickerLines (P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 544) frame 2: Plugins::RssNews::tickerUpdateContinue (P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 461) frame 3: Plugins::RssNews::tickerUpdate (P:\Music\SlimServer\trunk\server/Slim/Utils/Timers.pm line 181) frame 4: Slim::Utils::Timers::checkTimers (P:\Music\SlimServer\trunk\server\slimserver.pl line 488) frame 5: main::idle (P:\Music\SlimServer\trunk\server\slimserver.pl line 438) frame 6: main::main (P:\Music\SlimServer\trunk\server\slimserver.pl line 1037) Here's the problem. P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm, line 602: 592 # lines for tickerUpdate to add to ticker 593 sub tickerLines { 594 my $client = shift; 595 596 my $parts = {}; 597 my $new_feed_next = 0; # use new feed next call 598 599 # the current RSS feed 600 my $feed = $client->param('PLUGIN.RssNews.current_feed'); 601 602 assert( ref $feed eq 'HASH', "current rss feed not set\n"); 603 604 # the current item within each feed. 605 my $current_items = $client->param('PLUGIN.RssNews.current_items'); 606 607 if ( !defined $current_items ) { 608 609 $current_items = { 610 $feed => { 611 'next_item' => 0, 612 'first_item' => 0, 2006-09-06 00:03:50.4491 Use of uninitialized value in anonymous hash ({}) at P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 609, <SRC> line 919. 2006-09-06 00:03:50.4492 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 691, <SRC> line 919. 2006-09-06 00:13:37.9601 Use of uninitialized value in anonymous hash ({}) at P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 609, <SRC> line 13785. 2006-09-06 00:13:37.9602 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/RssNews.pm line 691, <SRC> line 13785. 2006-09-06 00:16:18.3360 getpeername() on closed socket GEN1418 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:16:31.4616 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 00:16:54.9539 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:16:54.9543 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:19:00.8055 getpeername() on closed socket GEN1451 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:19:38.5463 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:19:38.5466 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:24:06.3624 getpeername() on closed socket GEN1470 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:24:43.5374 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:24:43.5378 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:28:04.8278 getpeername() on closed socket GEN1507 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:28:22.4123 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 00:28:44.9845 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:28:44.9849 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:29:17.3705 getpeername() on closed socket GEN1537 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:29:57.1564 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:29:57.1567 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:31:54.5499 getpeername() on closed socket GEN1547 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:32:33.2580 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:32:33.2583 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:35:25.3130 getpeername() on closed socket GEN1567 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:36:07.0208 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:36:07.0212 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:36:07.0282 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:36:07.0284 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:38:28.2503 getpeername() on closed socket GEN1592 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:39:10.3100 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:39:10.3104 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:40:10.8345 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 00:42:07.9090 getpeername() on closed socket GEN1613 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:42:49.4304 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:42:49.4308 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:43:34.0309 getpeername() on closed socket GEN1639 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:44:10.9257 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:44:10.9260 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:46:55.1457 getpeername() on closed socket GEN1650 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:47:31.4733 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:47:31.4736 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:51:59.2453 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 00:53:22.2077 getpeername() on closed socket GEN1674 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:54:02.9358 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:54:02.9361 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 00:57:41.6123 getpeername() on closed socket GEN1718 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 00:58:21.9376 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 00:58:21.9380 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 01:01:02.8309 getpeername() on closed socket GEN1747 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 01:01:42.6785 Use of uninitialized value in string eq at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1053. 2006-09-06 01:01:42.6789 Use of uninitialized value in concatenation (.) or string at P:\Music\SlimServer\trunk\server/Plugins/DynamicPlayList/Plugin.pm line 1057. 2006-09-06 01:03:47.6997 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 01:04:57.6142 getpeername() on closed socket GEN1772 at P:/Programming/Perl/lib/IO/Socket.pm line 206. 2006-09-06 01:20:49.3003 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 01:34:35.7188 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 01:48:20.8787 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 02:02:05.8472 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 02:15:50.7103 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 02:27:44.9624 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 02:40:50.7499 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 02:53:53.5112 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 03:06:56.2848 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 03:19:58.9137 Use of uninitialized value in pattern match (m//) at P:\Music\SlimServer\trunk\server/Slim/Formats/XML.pm line 213. 2006-09-06 03:31:44.4699 ERROR: Async: Couldn't resolve IP address for: newsrss.bbc.co.uk
I see you're using the DynamicPlayList plugin. Can you try disabling all 3rd party plugins and see if the problem still occurs?
I have lots of third-party plugins installed/enabled. The bug doesn't happen all the time; so it's going to be hard to test. It's not going to be easy to confirm that another plugin causes the issue. Another oddity that may be related happened this morning. My slimserver was left playing ambient music through the night. The playlist probably ran out of music to play, so the RSS newsfeed would have activated as it is my screensaver to use when not playing. I have the alarm configured to play random songs in the morning. When I woke up, several random songs had played, and my now-playing (jump back on wake) screensaver was showing the current track. When I pressed right-arrow to wake up the screensaver, it then displayed the RSS newsfeed, rather than jumping back to the last used menu. I think it should have jumped to the last menu I was in, not the RSS newsfeed, as I never actually visited the RSS newsfeed plugin menu.
OK, this time I think I have finally solved this bug in change 9476. Please try tonight's nightly and reopen this bug if you still see this problem. The problem was that if you left screensaver mode during the time it was fetching the initial feed, this was not detected and the screensaver would still display. You'd get the 'current rss feed not set' error if you changed modes during this time. I've done away with the use of mode params for the screensaver state as well.