Bugzilla – Bug 14934
Now Playing status does not update correctly
Last modified: 2010-10-20 02:00:56 UTC
Created attachment 6201 [details] Web interface screenshot When a playlist is playing the Now Playing does not update correctly when a transition to a new song happens. There seem to be two cases: 1. The Now Playing screen shows the artwork and info for the 1st track in the playlist for the duration of the entire playlist. The web interface Now Playing screen shows the same information, ie always stuck on track #1. 2. The Now Playing screen does update after the second transition to a new song. IE it is always showing one track behind what is actually playing. In the attached screenshot the track actually being played by the radio is #3 I Turn To You. In both cases the progress dot on the SqueezeRadio and the track position bar in the web interface gets mighty confused and shows totally the wrong position. Everything does seem to work correctly with the Now Playing for my Squeezebox. I suspect this might have been introduced with the transition from 7.4.0 to 7.4.1 Version: 7.4.1 - r28947 @ Tue Oct 20 08:13:15 PDT 2009 Hostname: hp-tower Server IP Address: 192.168.1.1 Server HTTP Port Number: 9000 Operating system: Windows XP - EN - cp1252 Platform Architecture: 586 Perl Version: 5.10.0 - MSWin32-x86-multi-thread MySQL Version: 5.0.22-community-nt Total Players Recognized: 2 Player Model: baby Firmware: 7.4.1-r7915 Player IP Address: 192.168.1.102 Player MAC Address: 00:04:20:26:10:6a Wireless Signal Strength: 53%
Created attachment 6202 [details] SqueezeLog Not sure what the right debug setting should be for this issue. The tacks played were: Jesusland Into The Fire How Did We End Up Here The audioscrobbler logs show the server thinks it is still playing the last but one song which is indeed what is on the SR Now Playing screen
Alice: I'm confused, as the screen shot you attached shows the proper track playing and being displayed.
I am still unable to replicate this issue.
With much regret a combination of bugs 13181, 14894 and 14934 have led me to return my Squeezebox Radio for a refund.
Now that the new release of SqueezeCenter (7.4.2) has come out I have decided to try the Squeeze Radio again. Prior to doing this I used SqueezePlay to see if the behaviour was now correct and it seemed to be. However, now I have attached the Radio I have precisely this problem again. Basically the Now Playing display seems to lag one track behind what is actually playing. I get the same behaviour when using the Radio or SqueezePlay. The Web GUI for SquuezeCenter shows the same as the Radio/SqueezePlay. I have recorded a video which shows what happens. I really hopes this helps you see what I'm seeing. Let me know what debug I can turn on to help get to the bottom of this problem. It shows me simply trying to play a short playlist of 4 tracks: 1. Ever Fallen In Love 2. Help! 3. I Get Around 4. Suffragete City The video can be accessed at https://docs.google.com/leaf?id=0B-ukxJ2cIU8fMzc2YjAyOTAtMWI4Mi00MzBhLTg5NWYtNzk3ODk2YzgyNzAw&hl=en_GB Of the numerous problems that I had with the Radio and SW 7.4.1 this seems to be the only one of the problems which still exists in 7.4.2 Thanks Alice Version: 7.4.2 - r30215 @ Mon Feb 22 10:11:12 PST 2010 Hostname: hp-tower Server IP Address: 192.168.1.1 Server HTTP Port Number: 9000 Operating system: Windows XP - EN - cp1252 Platform Architecture: 586 Perl Version: 5.10.0 - MSWin32-x86-multi-thread MySQL Version: 5.0.22-community-nt Total Players Recognized: 3 Library Statistics Total Tracks: 25,242 Total Albums: 2,352 Total Artists: 2,933 Total Genres: 159 Total Playing Time: 1710:01:11 Player Information Information on all identified devices connected to Squeezebox Server SLIMP3 Player Model: slimp3 Firmware: 2.3 Player IP Address: 192.168.1.8 Player MAC Address: 00:04:20:04:11:b6 Squeezebox Player Model: squeezebox3 Firmware: 130 Player IP Address: 192.168.1.9 Player MAC Address: 00:04:20:12:56:ae Squeezebox Radio Player Model: baby Firmware: 7.4.2-r8423 Player IP Address: 192.168.1.102 Player MAC Address: 00:04:20:26:1d:f1 Wireless Signal Strength: 80%
QA to reproduce this issue. Alice you are seeing this issue with local music, correct? Not Pandora or some other music service, which have a more complex screen update mechanism? Is the Radio synced to one or the other (or both) of your other squeezeboxes? I'm just trying to make sure we are trying to reproduce this correctly. Thanks for any info.
Yes, as far as I can see this ONLY happens with locally stored music. Also, it does not happen 100% of the time. I would say it goes wrong 90%-95% of the time. I have played the same album twice in a row and seen it be OK and then go wrong on the second play of the album. My observation is that if the Now Playing screen transitions correctly after the first track of an album/playlist then generally from that point everything is fine for the rest of that album/playlist. The only music service I use is last.fm. Playing of stations from there seems fine. I've not yet been able to find a set of actions where I can predict whether things the Now Playing will work correctly or not. Sorry, the worst kind of thing for you to have to try and reproduce. No, the Radio is not being synced. Also, this problem only happens with the Radio. The Now Playing screen on the Slimp3 and the SqueezeBox continue to behave correctly 100% of the time. Did you download the video I posted to GoogleDocs? Thanks Alice
Your question about synchronization set me thinking. I am not using synchronization at all but I did some experiments and I found a few odd things when using the Web GUI 1. The right pane pulldown menu was still showing the Slimp3 even though this was unplugged from the network 2. When I tried to play something on the SqueezeBox the same thing did play on the Radio! I checked the Radio's own UI and it was not showing it as being synchronised to anything so this was truely bizarre and unexpected behaviour. Given the above I decided to simplify my setup and disconnected the SqueezeBox as well so that all I have in operation is the Radio. In this situation the Now Playing issue still exists. I also looked at \Documents and Settings\All Users\Application Data\Squeezebox\prefs\clientplaylist_000420261df1.m3u I can see that The CURTRACK value at the top of this file is not being updated with the track being played at all. IE it's not lagging one behind which is what I was expecting to see, the file is just not being updated at all. The timestamp does not change. The only time the timestamp changes is when I first start the playlist at which point the track streamed is the one specified by CURTRACK which is not the one last being streamed.
Created attachment 6690 [details] database.info logging I turned on database.info logging. The attached file shows the results. The first track played was 'Ever fallen in love with' and the second track 'Help!' The Now Playing screen was correct for both of these tracks. When 'I Get Around' played the Now Playing screen still showed the info for Help!. When 'Suffragette City' streamed the Now Playing screen updated to show 'I Get Around'. When 'Suffragette City' finished (at 08:41:01) the Now Playing screen updated to show 'Suffragette City' in a stopped state. This logging does seem to show something going quite awry server side.
Created attachment 6691 [details] database.info logging (for SquuezeBox) For comparison I got the database.info logging for when playing the same playlist with the SqueezeBox where the Now Playing display is always correct. It seems clear that when things go right you get entries such as: [10-03-24 09:02:24.4051] Slim::Schema::Track::artistid (154) Using cached primary artist [10-03-24 09:03:15.3707] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/David%20Bowie/Singles%20Collection,%20Vol.%201/David%20Bowie%20-%20Suffragette%20City.mp3 has changed. [10-03-24 09:03:15.3714] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\David Bowie\Singles Collection, Vol. 1\David Bowie - Suffragette City.mp3] - size & timestamp. [10-03-24 09:03:25.6957] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/The%20Beach%20Boys/Summer%20Dreams/THE%20BEACH%20BOYS%20-%20I%20Get%20Around.mp3 has changed. [10-03-24 09:03:25.6963] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\The Beach Boys\Summer Dreams\THE BEACH BOYS - I Get Around.mp3] - size & timestamp. [10-03-24 09:03:25.9855] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/David%20Bowie/Singles%20Collection,%20Vol.%201/David%20Bowie%20-%20Suffragette%20City.mp3 has changed. [10-03-24 09:03:25.9860] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\David Bowie\Singles Collection, Vol. 1\David Bowie - Suffragette City.mp3] - size & timestamp. [10-03-24 09:03:25.9926] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/David%20Bowie/Singles%20Collection,%20Vol.%201/David%20Bowie%20-%20Suffragette%20City.mp3 has changed. [10-03-24 09:03:25.9932] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\David Bowie\Singles Collection, Vol. 1\David Bowie - Suffragette City.mp3] - size & timestamp. [10-03-24 09:03:25.9983] Slim::Schema::Track::artistid (154) Using cached primary artist and when things go wrong you get entries such as: [10-03-24 08:36:47.1090] Slim::Schema::Track::artistid (154) Using cached primary artist [10-03-24 08:37:06.9873] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/David%20Bowie/Singles%20Collection,%20Vol.%201/David%20Bowie%20-%20Suffragette%20City.mp3 has changed. [10-03-24 08:37:06.9880] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\David Bowie\Singles Collection, Vol. 1\David Bowie - Suffragette City.mp3] - size & timestamp. [10-03-24 08:37:24.6325] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/The%20Beach%20Boys/Summer%20Dreams/THE%20BEACH%20BOYS%20-%20I%20Get%20Around.mp3 has changed. [10-03-24 08:37:24.6330] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\The Beach Boys\Summer Dreams\THE BEACH BOYS - I Get Around.mp3] - size & timestamp. [10-03-24 08:37:24.6455] Slim::Schema::_checkValidity (1796) Checking to see if file:////192.168.1.7/Music/Slimp3/The%20Beach%20Boys/Summer%20Dreams/THE%20BEACH%20BOYS%20-%20I%20Get%20Around.mp3 has changed. [10-03-24 08:37:24.6460] Slim::Schema::_hasChanged (1841) Checking for [\\192.168.1.7\Music\Slimp3\The Beach Boys\Summer Dreams\THE BEACH BOYS - I Get Around.mp3] - size & timestamp. [10-03-24 08:37:24.6541] Slim::Schema::Track::artistid (154) Using cached primary artist IE the first line of the log section always reflects what is actually being streamed and the last line of the log section reflects what's displayed as 'Now Playing'
I have just upgraded to server 7.50 and firmware 7.5.0-r8673 and I can confirm that this bug still exists with the same symptoms. Is there any debug I can get you to help? Regards Alice Version: 7.5.0 - r30464 @ Thu Apr 1 05:51:56 PDT 2010 Hostname: hp-tower Server IP Address: 192.168.1.1 Server HTTP Port Number: 9000 Operating system: Windows XP - EN - cp1252 Platform Architecture: 586 Perl Version: 5.10.0 - MSWin32-x86-multi-thread MySQL Version: 5.0.22-community-nt Total Players Recognized: 2 Player Model: Squeezebox Radio Firmware: 7.5.0-r8673 Player IP Address: 192.168.1.102 Player MAC Address: 00:04:20:26:1d:f1 Wireless Signal Strength: 80% Player Model: Squeezebox Classic Firmware: 130 Player IP Address: 192.168.1.9 Player MAC Address: 00:04:20:12:56:ae
This bug still exists in the new 7.5.1 release. Is there any debug I can get you to help with this issue? It's a very annoying bug and I'd like to see it fixed and am happy to help in any way I can. Regards Alice
One year since I first reported this bug! It's still present in the current release. Again, I'm happy to send you whatever debug you'd like to help get to the bottom of this very irritating problem. Version: 7.5.1 - r30836 @ Tue Jun 1 06:02:45 PDT 2010 Hostname: hp-tower Server IP Address: 192.168.1.1 Server HTTP Port Number: 9000 Operating system: Windows XP - EN - cp1252 Platform Architecture: 586 Perl Version: 5.10.0 - MSWin32-x86-multi-thread MySQL Version: 5.0.22-community-nt Total Players Recognized: 2 Player Model: Squeezebox Radio Firmware: 7.5.1-r9009 Player IP Address: 192.168.1.102 Player MAC Address: 00:04:20:26:1d:f1 Wireless Signal Strength: 68%