Bugzilla – Bug 6901
Now Playing Menu option lost after upgrade until reboot
Last modified: 2009-09-08 09:12:44 UTC
This has happened several times now after different firmware updates. After the update the Now Playing menu item is missing from the menu (and the now playing screen saver doesn't work - usually how I notice it). After another reboot the Now Playing menu option returns. Is there any logging that I can turn on to get more details?
hi Doug-- first thing I'll do is ask you to do is sanity check...sometimes Now Playing in menu slot 1 is off the top of the screen. I know that when I see that happen I often have a "hey! Now Playing is gone!" reaction. Have you tried scrolling the menu up to the top to see if it was just off screen? Next thing you can do is let us know both the version of jive firmware you have running (Settings->Advanced->About) and the version of SC you are running and the OS you are running it on. if you are savvy with ssh, you could enable remote login on your jive (Settings->Advanced->Remote Login), ssh into a console and type `tail -f /var/log/messages`. While leaving that running, on the jive hardware go to Settings->Screen->Screensavers->While Playing and select Now Playing from the menu and hit the PLAY key (this will "preview" the screensaver). Look at the ssh console and see if any errors printed to the screen during that time. If so, copy them and paste them into the bug. cheers, #!/ben
Yes, I did scroll up but it wasn't there - sorry I didn't mention this here, I should know better. My main indicator that it is missing is that the now playing screensaver doesn't operate either. I've gone in a couple of times and changed the screensaver settings and it hasn't had any impact, then I've noticed that the now playing menu item wasn't listed, and then I've rebooted. I'm a bit quicker now and when the Now Playing SS doesn't work I check for the missing menu item and reboot. Going from memory (sorry I don't remember the numbers off hand): SC 7 is running on Windows XP with Wednesday's nightly. Controller updated last night (US Central time) to yesterday's build. I've seen this on previous builds during the last week or so. I'm mainly a Windows guy now and my Unix background is very old but I should be able to get the log. I'm assuming that I should do this the next time there is a problem before the reboot, right? Or do you want one when it is working as well?
I only need to see the log when it fails. I think this shouldn't be too hard, even for Windows guy ;) On windows there is a nice stand-alone ssh client available, just google 'putty.exe' and download it. when this issue is reproduced, follow these instructions: On the Jive, go to Setting->Advanced->Remote Login and enable it. When you do that, a message at the bottom will appear that lets you know the IP address and password for login. Launch putty.exe and connect to the IP of your Jive. Username to use is 'root'. From there you will be given a command-line prompt, and you only need to type one command: tail -f /var/log/messages this will give you the bottom 10 lines or so of the messages file, plus any that are written to it while you have the pipe open. then go back to the Jive, and activate the screensaver with Settings->Screen->Screensavers->When Playing->Now Playing (hit 'play' to preview) then check to see if anything gets printed to your putty window when the screensaver (presumably) fails. I'm esp. interested in anything that looks like a big fat error in the lua code. Paste whatever you see into this bug. cheers, #!/ben
Of course it didn't have the issue yesterday... I'll keep looking for it for a few more times and close it as working if it doesn't occur again.
It occurred again, obviously. Hitting the play button in the setup screensaver option doesn't cause any entries in the log. The dropped frame message occurs a lot without any key activity. Feb 2 16:52:13 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=11ms Feb 2 16:52:18 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:52:21 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=62ms Feb 2 16:52:23 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:52:25 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=45ms Feb 2 16:52:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:52:33 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:52:38 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=dimmed acpower=false Feb 2 16:52:38 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:52:43 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:52:48 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:52:53 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms ^[[A^[[A^[[A^[[AFeb 2 16:52:58 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms # tail -f /var/log/messages Feb 2 16:53:03 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:53:03 (none) user.info jive: (NetworkThread.lua:245) - NOTIFY playerTrackChange: Player {Main Level}, 4442 Feb 2 16:53:03 (none) user.warn jive: (NowPlayingApplet.lua:185) - PLAYER TRACK NOTIFICATION RECEIVED Feb 2 16:53:03 (none) user.err jive: (RequestHttp.lua:67) - Response sink:...r/share/jive/applets/NowPlaying/NowPlayingApplet.lua:265: attempt to call method 'getId' (a nil value) stack traceback: /usr/share/jive/jive/utils/coxpcall.lua:28: in function </usr/share/ Feb 2 16:53:03 (none) user.warn jive: (Framework.lua:201) - SocketHttp {Office-Sony_Chunked}(R) took 34 ms Feb 2 16:53:08 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:53:13 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:53:18 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=6ms Feb 2 16:53:21 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=active acpower=false Feb 2 16:53:23 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:53:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:53:29 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=27ms Feb 2 16:53:30 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=170ms Feb 2 16:53:33 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=5ms Feb 2 16:53:38 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=10ms Feb 2 16:53:43 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:53:48 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=13ms -sh: cls: not found # tail -f /var/log/messages Feb 2 16:54:23 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:54:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:54:31 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=active acpower=false Feb 2 16:54:33 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:54:38 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:54:43 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=17ms Feb 2 16:54:48 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:54:48 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=19ms Feb 2 16:54:53 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=16ms Feb 2 16:54:58 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=16ms Feb 2 16:55:03 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:55:08 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=10ms Feb 2 16:55:13 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=6ms Feb 2 16:55:18 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:55:19 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=3ms Feb 2 16:55:23 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:55:23 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=10ms Feb 2 16:55:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:55:31 (none) user.info jive: (AppletManager.lua:505) - Store settings: ScreenSavers Feb 2 16:55:33 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:55:35 (none) user.warn jive: (Framework.lua:201) - SocketHttp {Office-Sony_Chunked}(R) took 27 ms Feb 2 16:55:38 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:55:40 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=26ms Feb 2 16:55:40 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=88ms Feb 2 16:55:43 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:55:48 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Notice this error whenever a track changes: Feb 2 16:57:43 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=10ms Feb 2 16:57:48 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=6ms Feb 2 16:57:53 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:57:58 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 16:58:00 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=active acpower=false Feb 2 16:58:02 (none) user.info jive: (AppletManager.lua:505) - Store settings: ScreenSavers Feb 2 16:58:03 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 16:58:07 (none) user.info jive: (NetworkThread.lua:245) - NOTIFY playerTrackChange: Player {Main Level}, 4502 Feb 2 16:58:07 (none) user.warn jive: (NowPlayingApplet.lua:185) - PLAYER TRACK NOTIFICATION RECEIVED Feb 2 16:58:07 (none) user.err jive: (RequestHttp.lua:67) - Response sink:...r/share/jive/applets/NowPlaying/NowPlayingApplet.lua:265: attempt to call method 'getId' (a nil value) stack traceback: /usr/share/jive/jive/utils/coxpcall.lua:28: in function </usr/share/ Feb 2 16:58:07 (none) user.warn jive: (Framework.lua:201) - SocketHttp {Office-Sony_Chunked}(R) took 24 ms Feb 2 16:58:08 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 16:58:13 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms
The above was after today's (02/02) update. I haven't been tracking this, but from memory a pattern of every other one seems to be emerging. Again, power off/on restores the menu option and screen saver functionality. This is the log after the reboot: # tail -f /var/log/messages Feb 2 17:03:24 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=36ms Feb 2 17:03:24 (none) authpriv.info dropbear[929]: Child connection from 192.16 8.111.7:53732 Feb 2 17:03:29 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=39ms Feb 2 17:03:31 (none) authpriv.notice dropbear[929]: password auth succeeded fo r 'root' from 192.168.111.7:53732 Feb 2 17:03:31 (none) authpriv.warn dropbear[932]: lastlog_perform_login: Could n't stat /var/log/lastlog: No such file or directory Feb 2 17:03:31 (none) authpriv.warn dropbear[932]: lastlog_openseek: /var/log/l astlog is not a file or directory! Feb 2 17:03:34 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=40ms Feb 2 17:03:39 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=37ms Feb 2 17:03:44 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=45ms Feb 2 17:03:49 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=37ms Feb 2 17:03:54 (none) user.warn jive: (Framework.lua:237) - Dropped frame. dela y=41ms Feb 2 17:03:59 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=36ms Feb 2 17:04:04 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=39ms Feb 2 17:04:09 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=40ms Feb 2 17:04:14 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=40ms Feb 2 17:04:16 (none) daemon.notice wpa_supplicant[803]: WPA: Group rekeying completed with 00:11:50:20:5d:12 [GTK=CCMP] Feb 2 17:04:19 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=41ms Feb 2 17:04:19 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=sleep acpower=false Feb 2 17:04:23 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=active acpower=false Feb 2 17:04:24 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=6ms Feb 2 17:04:29 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=6ms Feb 2 17:04:34 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=16ms Feb 2 17:04:39 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=5ms Feb 2 17:04:44 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=9ms Feb 2 17:04:49 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 17:04:54 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=8ms Feb 2 17:04:56 (none) user.info jive: (AppletManager.lua:558) - Freeing: SetupSSH Feb 2 17:04:59 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=43ms Feb 2 17:05:04 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 17:05:09 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 17:05:14 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=5ms Feb 2 17:05:19 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 17:05:24 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=7ms Feb 2 17:05:28 (none) user.warn jive: (NowPlayingApplet.lua:554) - player=Player {Main Level} status=table: 0x4e0de0 Feb 2 17:05:28 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=dimmed acpower=false Feb 2 17:05:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=28ms Feb 2 17:05:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=15ms Feb 2 17:05:28 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=1ms Feb 2 17:05:29 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=5ms Feb 2 17:05:33 (none) user.info jive: (SqueezeboxJiveApplet.lua:521) - setPowerState=active acpower=false Feb 2 17:05:34 (none) user.warn jive: (Framework.lua:237) - Dropped frame. delay=10ms
okay, this is the line that jumps out at me. I put in a small fix for this (r1791) that might fix it. Feb 5 daily should have this change. I'm calling this "FIXED", but since I can't reproduce it I also can't test it. Reopen at will if you still see a problem... Feb 2 16:53:03 (none) user.err jive: (RequestHttp.lua:67) - Response sink:...r/share/jive/applets/NowPlaying/NowPlayingApplet.lua:265: attempt to call method 'getId' (a nil value) stack traceback:
Great!! I was afraid that I hadn't been able to give you much to go on. I'll keep an eye on it. Thanks.
This has not reoccurred in the last several updates.
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