Bug 14894 - Unable to scan FF or REW when playing Podcast
: Unable to scan FF or REW when playing Podcast
Status: RESOLVED FIXED
Product: SB Radio
Classification: Unclassified
Component: Audio
: Include FW version in comment
: PC Windows XP
: P3 major with 1 vote (vote)
: 7.4.2
Assigned To: Alan Young
:
Depends on: 15197
Blocks:
  Show dependency treegraph
 
Reported: 2009-10-22 10:02 UTC by Alice Shimmin
Modified: 2010-02-26 07:00 UTC (History)
6 users (show)

See Also:
Category: Bug


Attachments
SqueezeCenter log file (172.61 KB, text/plain)
2009-10-23 01:34 UTC, Alice Shimmin
Details
Permissions on the Cache directory (18.59 KB, image/gif)
2009-10-26 14:23 UTC, Alice Shimmin
Details
Plugins enabled (54.01 KB, image/gif)
2009-10-26 14:24 UTC, Alice Shimmin
Details
7.4.0 SqueezeCenter log file (44.20 KB, text/plain)
2009-10-27 23:14 UTC, Alice Shimmin
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Alice Shimmin 2009-10-22 10:02:46 UTC
Not really sure how to classify this problem so just picked audio although audio playback quality is fine.

The issue is that if I hold down FF ore REW to scan though a track then I get the bar pop up on screen to indicate position in the track but the time counter just progresses forward at normal play rate. This is with an MP3 from my SqueezeCenter but is also the case when playing an MP3 Podcast. Scanning through the same content with my Slimp3 or Squeezebox everything is fine so this seems to be a problem specific to the Squeezebox Radio.

Installation info follows: 

Player Model: baby
Firmware: 7.4.0-r7790
Player IP Address: 192.168.1.102
Player MAC Address: 00:04:20:26:10:6a
Wireless Signal Strength: 100%

Version: 7.4.0 - r28672 @ Mon Sep 28 19:51:11 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
Comment 1 Alice Shimmin 2009-10-22 10:14:22 UTC
Hmmm, been experimenting a bit more. It seems that scanning can be done. You need to press FF or REW once to get the progress bar up and then you need to release the FF or REW button and then press it again before the bar disappears. This is rather counter-intuitive and not how the SqueezeBox and Slimp3 behave where a single press and hold of the FF or REW key down brings up the bar and then scans.
Comment 2 James Richardson 2009-10-22 17:49:27 UTC
Just tested with 7.4.1 r28947, Radio r7915.  works in that version.  Please update your SBS and Radio firmware and retest.

If you still have the issue, reopen the bug and include a Server log with (player.source) - Player Source Audio & Conversion Logging set to debug
Comment 3 Alice Shimmin 2009-10-23 01:34:32 UTC
Created attachment 6191 [details]
SqueezeCenter log file
Comment 4 Alice Shimmin 2009-10-23 01:38:18 UTC
I upgraded to 7.4.1 and now I am definitely not able to scan podcasts on the Radio which can just fine on the Slimp3 and Squeezebox. The attached log file shows the errors as requested. Lines 363 and 220 are interesting as is line 38. I'm running XP on an NTFS formatted disc but it's hard to see why the software should be getting Permission Denied when trying to rename a file or is this just a generic Microsoft catchall type of error?

The config for the system is now:

Squeezebox Server Status
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: 3


SLIMP3
Player Model: slimp3
Firmware: 2.3
Player IP Address: 192.168.1.10
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.1-r7915
Player IP Address: 192.168.1.102
Player MAC Address: 00:04:20:26:10:6a
Wireless Signal Strength: 68%
Comment 5 James Richardson 2009-10-26 09:29:24 UTC
Not all podcasts are supported with song scanner (ff/rr) there is nothing we can do about that, as it's all based on the podcast server.
Comment 6 Alice Shimmin 2009-10-26 13:26:48 UTC
I think you miss my point. The podcasts in question DO scan fine on my Slimp3 and Squeezebox it is just the SqueezeBox Radio that doesn't scan them. See the log file. The podcast referenced in there does scan fine except on the SB Radio.
Comment 7 Alice Shimmin 2009-10-26 13:31:20 UTC
At the point this screenshot was taken the sound coming out of the Radio was actually track #3 'I Turn To You'.

When Track #4 started playing the screen on the SB Radio doesn't change and the Web interface still shows exactly as it does in the attached screenshot. However, the progress bar for position in the track gets mighty confused. At the point the new track starts playing the progress bar jumps to something like a minute or so into the track (although it is playing from the beginning) and the progress bar hits the end way before the track actually finishes.
Comment 8 Andy Grundman 2009-10-26 13:37:58 UTC
There are a lot of errors in your log that may be causing this issue.  Please remove all 3rd party plugins as well as verify the directory permissions on your cache directory.  "Unable to scan bitrate" due to a permission issue would definitely lead to problems with seeking (don't know where to seek if we don't know the bitrate).
Comment 9 Alice Shimmin 2009-10-26 14:23:51 UTC
Created attachment 6209 [details]
Permissions on the Cache directory

I disabled all 3rd Party plugins and still have the problem. I tried to scan http://www.podtrac.com/pts/redirect.mp3/aolradio.podcast.aol.com/twit/TWiT0217H.mp3 and this worked fine the first time. I then came back and tried it again and it wouldn't scan.

I have two user accounts on my PC and they are both Administrators so I don't see where the permissions trouble would be coming from.

Should I delete the entire contents of the Cache directory and see what happens??
Comment 10 Alice Shimmin 2009-10-26 14:24:38 UTC
Created attachment 6210 [details]
Plugins enabled

Here's the current state of play WRT plugins
Comment 11 James Richardson 2009-10-27 14:37:30 UTC
Andy: see updated information from customer.
Comment 12 Alice Shimmin 2009-10-27 15:46:37 UTC
Ok, I'm having so much trouble with the Radio on so many fronts that I decided to nuke my installation and start again with a fresh install of 7.4.1 so no additional plugins now and cache cleared etc etc.

I still can't scan the podcast. Looking in the log file I see:

[09-10-27 22:11:31.2201] Slim::Utils::Scanner::Remote::streamAudioData (717) Unable to scan bitrate for http://aolradio.podcast.aol.com/twit/TWiT0218Hb.mp3: Couldn't rename C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\uUQ7csjuoO to C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\0e731fa5e650589100613b07ee03254d137cd004: Permission denied at /<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Cache/FileBackend.pm line 580.
[09-10-27 22:11:47.9938] Slim::Utils::Scanner::Remote::streamAudioData (717) Unable to scan bitrate for http://aolradio.podcast.aol.com/twit/TWiT0218Hb.mp3: Couldn't rename C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\fft20psXRn to C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\0e731fa5e650589100613b07ee03254d137cd004: Permission denied at /<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Cache/FileBackend.pm line 580.
[09-10-27 22:12:06.3309] Slim::Utils::Scanner::Remote::streamAudioData (717) Unable to scan bitrate for http://aolradio.podcast.aol.com/twit/TWiT0217H.mp3: Couldn't rename C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\6\1\d\FMq9zjeEIg to C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\6\1\d\61d76f76743fccdbccd373f060e0863a9a42bb94: Permission denied at /<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Cache/FileBackend.pm line 580.


Sure enough the podcast plays, but without it's artwork. I can see the artwork file in the Cache/Artwork directory.

For fun I tried to do the rename from DOS myself

C:\>rename "C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\uUQ7csjuoO" "C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\0e731fa5e650589100613b07ee03254d137cd004"
The syntax of the command is incorrect.

so using the full pathname in source and target fails. However, using the full pathname on the source and just the leafname for the target it does work

C:\>rename "C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\uUQ7csjuoO" "0e731fa5e650589100613b07ee03254d137cd004"

C:\

So, it doesn't look to be a permissions issue. SYSTEM and Administrators both have full control over the Cache directory and its sub-directories.
Comment 13 Andy Grundman 2009-10-27 16:15:02 UTC
There must be something wrong with your system if you're getting "Permission denied" errors, I don't think this is a bug.
Comment 14 Alice Shimmin 2009-10-27 16:33:09 UTC
I've no idea where to look next. This is a new PC which I installed XP on from scratch and all I use it for is running SqueezeCenter which is pretty much all that is installed on it other than Firefox. I do wonder if the permission denied is a catch all type of error and may be misleading and the error is actually something else. Sometimes for these podcasts the artwork does appear and it can be scanned. So, this is an intermittent problem. If there truely was a permissions issue I'd expect it to be a problem every time. Maybe there is some sort of race condition? Is it possible the rename is being done too soon? IE before the source artwork file is in place and closed?
Comment 15 Andy Grundman 2009-10-27 17:00:21 UTC
Do you have any sort of virus scanner running?
Comment 16 Alice Shimmin 2009-10-27 17:03:34 UTC
I'm running AVG Free 8.5.423
Comment 17 Andy Grundman 2009-10-27 17:14:21 UTC
Maybe try turning it off and see if it helps?  All I can think of.
Comment 18 Alice Shimmin 2009-10-27 17:17:42 UTC
Removed AVG totally. Problem still exactly the same with same type of errors in the log.

I'm going to revert to 7.4.0. My feeling is that things in general have been very wobbly on several fronts since going to 7.4.1.
Comment 19 Alice Shimmin 2009-10-27 23:14:34 UTC
Created attachment 6228 [details]
7.4.0 SqueezeCenter log file

This is starting to drive me nuts. 7.4.0 is installed from scratch and things are sort of better. Scanning of podcasts is now reliable but there's still the permission denied when trying to rename the artwork and I don't ever get the artwork in the Now Playing screen. However, More Info does always show the Bitrate and scanning is always possible.

Errors look a bit different now though:

[09-10-28 05:31:03.8421] Slim::Networking::IO::Select::__ANON__ (140) Error: Select task failed calling Slim::Networking::Async::HTTP::_http_read_body: Couldn't rename C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\MwwqnHFEh4 to C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\e\7\0e731fa5e650589100613b07ee03254d137cd004: Permission denied at /<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Cache/FileBackend.pm line 580.
; fh=Slim::Networking::Async::Socket::HTTP=GLOB(0x81bb9e4)


There's also this error:

[09-10-28 05:29:44.5646] Slim::Web::Graphics::processCoverArtRequest (262) Error: Unable to resize music/17915/cover_41x41_m: Can't resize unknown type, magic: "\0\0\0\0"

Not sure howto idetnify which file this is related to. Where is the music/17915 directory located??

I have another bug open which is Bug 14934. My Now Playing screen on the Radio doesn't update when moving to the next track.

I don't have problems with my Slimp3 and Squeezebox so I'm starting to think that these two bugs are possibly related and are to do with the whatever the server is doing to process the artwork for the Radio.

What level of debug can I set to try and dig out some more information about this?

The Now Playing issue didn't use to happen when I first installed 7.4.0 a few days ago when my Radio first arrived. What has changed that can have caused the problem which can have survived a complete uninstall and and revert back to 7.4.0? Registry entries??? Apps in MySqueezebox.com???


There are errors 

[09-10-28 05:52:20.6406] Slim::Display::Display::string (808) Error: missing string BBC
[09-10-28 05:52:20.6413] Slim::Display::Display::string (808) Backtrace:

   frame 0: Slim::Utils::Log::logBacktrace (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Display/Display.pm line 808)
   frame 1: Slim::Display::Display::string (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Player/Player.pm line 186)
   frame 2: Slim::Player::Player::string (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Control/Jive.pm line 3328)
   frame 3: Slim::Control::Jive::_localizeMenuItemText (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Control/Jive.pm line 1978)
   frame 4: Slim::Control::Jive::_notifyJive (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Control/Jive.pm line 391)
   frame 5: Slim::Control::Jive::mainMenu (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/SqueezeNetwork/Players.pm line 151)
   frame 6: Slim::Networking::SqueezeNetwork::Players::_players_done (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/SimpleAsyncHTTP.pm line 358)
   frame 7: Slim::Networking::SimpleAsyncHTTP::onBody (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/Async/HTTP.pm line 474)
   frame 8: Slim::Networking::Async::HTTP::_http_read_body (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 133)
   frame 9: (eval) (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 119)
   frame 10: Slim::Networking::IO::Select::__ANON__ (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 177)
   frame 11: (eval) (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 177)
   frame 12: Slim::Networking::IO::Select::loop (slimserver.pl line 620)
   frame 13: main::idle (slimserver.pl line 574)
   frame 14: main::main (slimserver.pl line 98)
   frame 15: PerlSvc::Interactive (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>PerlSvc.pm line 99)
   frame 16: PerlSvc::_interactive (slimserver.pl line 0)
   frame 17: (eval) (slimserver.pl line 0)


and 

[09-10-28 00:21:53.7549] Slim::Display::Display::string (808) Error: missing string FACEBOOK
[09-10-28 00:21:53.7557] Slim::Display::Display::string (808) Backtrace:

   frame 0: Slim::Utils::Log::logBacktrace (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Display/Display.pm line 808)
   frame 1: Slim::Display::Display::string (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Player/Player.pm line 186)
   frame 2: Slim::Player::Player::string (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Control/Jive.pm line 3328)
   frame 3: Slim::Control::Jive::_localizeMenuItemText (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Control/Jive.pm line 1978)
   frame 4: Slim::Control::Jive::_notifyJive (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Control/Jive.pm line 391)
   frame 5: Slim::Control::Jive::mainMenu (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/SqueezeNetwork/Players.pm line 151)
   frame 6: Slim::Networking::SqueezeNetwork::Players::_players_done (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/SimpleAsyncHTTP.pm line 358)
   frame 7: Slim::Networking::SimpleAsyncHTTP::onBody (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/Async/HTTP.pm line 474)
   frame 8: Slim::Networking::Async::HTTP::_http_read_body (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 133)
   frame 9: (eval) (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 119)
   frame 10: Slim::Networking::IO::Select::__ANON__ (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 177)
   frame 11: (eval) (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Slim/Networking/IO/Select.pm line 177)
   frame 12: Slim::Networking::IO::Select::loop (slimserver.pl line 620)
   frame 13: main::idle (slimserver.pl line 574)
   frame 14: main::main (slimserver.pl line 98)
   frame 15: PerlSvc::Interactive (/<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>PerlSvc.pm line 99)
   frame 16: PerlSvc::_interactive (slimserver.pl line 0)
   frame 17: (eval) (slimserver.pl line 0)

plus others which are clearly App related.

I'm a long time user of the Slim Server and my experience with the Radio is the first time I've ever run into any real difficulty. I've been really looking forward to this product to repace my DAB radio and Slimp3 which I have next to my bed.
Comment 20 Alice Shimmin 2009-11-04 16:09:46 UTC
With much regret a combination of bugs 13181, 14894 and 14934 have led me to return my Squeezebox Radio for a refund.
Comment 21 Alan Young 2009-12-04 01:44:52 UTC
Update hours
Comment 22 Alice Shimmin 2009-12-04 02:00:31 UTC
As an update I am still seeing this issue with my Slimp3 and Squeezebox in 7.4.1. With repeated plays of the SAME podcast it will sometime allow me to scan and sometimes not. I would say 7 out of 10 times it does scan. When it doesn't scan I always get an associated 'Permission denied' error in the server log. I don't see how it can actually be a permissions error when it works most of the time.

[09-12-04 00:49:43.5467] Slim::Utils::Scanner::Remote::streamAudioData (717) Unable to scan bitrate for http://downloads.bbc.co.uk/podcasts/radio4/feedback/feedback_20091127-1400a.mp3: Couldn't rename C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\1\b\1\7Z2M4zYuAN to C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\1\b\1\1b1a73663a0fa0de44afdfbf2fbb81f678918b3c: Permission denied at /<C:\PROGRA~1\SQUEEZ~2\server\SQUEEZ~3.EXE>Cache/FileBackend.pm line 580.

Difficult to be 100% sure but I think I've observed that when I get a podcast that won't scan repeated attempts to play it again always result in it not being able to scan until I play another podcast successfully and then come back to the original one.

Also, I believe I've observed the same sort of problem playing streams with the iPlayer plugin.

Alice
Comment 23 Paul Trunley 2009-12-29 10:59:16 UTC
I see this problem as well, with similar entries in the log file when the error occurs:

[09-12-29 08:41:34.0034] Slim::Utils::Scanner::Remote::streamAudioData (717) Unable to scan bitrate for http://downloads.bbc.co.uk/podcasts/worldservice/docarchive/docarchive_20091224-1006a.mp3: Couldn't rename C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\8\7\bw0xw6tUEm to C:\Documents and Settings\All Users\Application Data\Squeezebox\Cache\Artwork\0\8\7\08733cc07c27c4f21952a48880da07d4e72e15f7: Permission denied at /<C:\PROGRA~1\SQUEEZ~2\server\SqueezeSvr.exe>Cache/FileBackend.pm line 580.

This is running 7.4.1 as a service on Windows Server 2003.  The same problem will occur on my Radio and SB3.
Comment 24 Chris Owens 2010-01-04 16:00:42 UTC
Changing priorities due to management guidance.
Comment 25 Alan Young 2010-02-26 07:00:37 UTC
Fixed by fix for bug 15197