Bugzilla – Bug 14166
SC Hangs for several minutes then recovers
Last modified: 2009-10-05 14:37:24 UTC
I've seen this several times, both on an SB3 and controller. I try to navigate into a music folder. The interface hangs. On the controller, I see the spinning wheel. I've seen something "funny" in the logs that I believe is coincident to the hangs. A long sequence of: [09-09-20 21:40:16.3100] Slim::Utils::Scanner::scanDirectory (352) ERROR SCANNING /home/marc/BigStuff/RIPDIR/ExpMusic/ExMu_09_08_07_18_58_WBAA_E.mp3: Unable to read tags from file [09-09-20 21:40:19.2009] Slim::Utils::Misc::msg (1160) Warning: [21:40:19.2004] buffer_consume_ret: trying to get more bytes 1 than in buffer 0 at /usr/share/perl5/Slim/Formats/MP3.pm line 118. [09-09-20 21:40:19.2015] Slim::Formats::readTags (180) Error: While trying to ->getTag(/home/marc/BigStuff/RIPDIR/ExpMusic/ExMu_09_08_12_18_58_WBAA.mp3) : buffer_consume: buffer error at /usr/share/perl5/Slim/Formats/MP3.pm line 118. [09-09-20 21:40:19.2022] Slim::Formats::readTags (180) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Formats.pm line 180) frame 1: Slim::Formats::readTags (/usr/share/perl5/Slim/Schema.pm line 917) frame 2: Slim::Schema::newTrack (/usr/share/perl5/Slim/Schema.pm line 1228) frame 3: Slim::Schema::updateOrCreate (/usr/share/perl5/Slim/Utils/Scanner.pm line 342) frame 4: Slim::Utils::Scanner::scanDirectory (/usr/share/perl5/Slim/Utils/Scanner.pm line 99) frame 5: Slim::Utils::Scanner::scanPathOrURL (/usr/share/perl5/Slim/Control/Commands.pm line 1481) frame 6: Slim::Control::Commands::playlistXitemCommand (/usr/share/perl5/Slim/Control/Request.pm line 1914) frame 7: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1914) frame 8: Slim::Control::Request::execute (/usr/share/perl5/Slim/Control/Request.pm line 877) frame 9: Slim::Control::Request::executeRequest (/usr/share/perl5/Slim/Control/Commands.pm line 1771) frame 10: Slim::Control::Commands::playlistcontrolCommand (/usr/share/perl5/Slim/Control/Request.pm line 1914) frame 11: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1914) frame 12: Slim::Control::Request::execute (/usr/share/perl5/Slim/Web/Cometd.pm line 806) frame 13: Slim::Web::Cometd::handleRequest (/usr/share/perl5/Slim/Web/Cometd.pm line 548) frame 14: Slim::Web::Cometd::handler (/usr/share/perl5/Slim/Web/Cometd.pm line 108) frame 15: Slim::Web::Cometd::webHandler (/usr/share/perl5/Slim/Web/HTTP.pm line 488) frame 16: Slim::Web::HTTP::processHTTP (/usr/share/perl5/Slim/Networking/IO/Select.pm line 133) frame 17: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 119) frame 18: Slim::Networking::IO::Select::__ANON__ (/usr/share/perl5/Slim/Networking/IO/Select.pm line 177) frame 19: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 177) frame 20: Slim::Networking::IO::Select::loop (/usr/sbin/squeezeboxserver line 620) frame 21: main::idle (/usr/sbin/squeezeboxserver line 574) frame 22: main::main (/usr/sbin/squeezeboxserver line 1103) [09-09-20 21:40:19.2028] Slim::Utils::Scanner::scanDirectory (352) ERROR SCANNING /home/marc/BigStuff/RIPDIR/ExpMusic/ExMu_09_08_12_18_58_WBAA.mp3: Unable to read tags from file [09-09-20 21:40:20.9711] Slim::Utils::Misc::msg (1160) Warning: [21:40:20.9706] buffer_consume_ret: trying to get more bytes 1 than in buffer 0 at /usr/share/perl5/Slim/Formats/MP3.pm line 118. [09-09-20 21:40:20.9717] Slim::Formats::readTags (180) Error: While trying to ->getTag(/home/marc/BigStuff/RIPDIR/ExpMusic/ExMu_09_08_14_18_58_WBAA.mp3) : buffer_consume: buffer error at /usr/share/perl5/Slim/Formats/MP3.pm line 118. [09-09-20 21:40:20.9724] Slim::Formats::readTags (180) Backtrace: ...
I should add that once SC recovers, there is no problem playing the tracks.
Is this a particularly slow system, Marc? Could you attach that file noted in the log?
Looks like the scanner doesn't like that file ExMu_09_08_07_18_58_WBAA_E.mp3. Can you please attach it?
Created attachment 5882 [details] front of a file that fails to scan in its full size I can't attach a failing sample because the failing files are too big, and if I truncate one it doesn't fail. I've attached a truncated file anyhow. I suspect this is my fault - all though I'm unhappy that some change causes this failure. I believe all the failing files are VBR but without a proper VBR mp3 header frame. In the past, SC played them, but got confused about positioning. Some recent change has broken it totally. Is it possible only big files fail because it takes that long for some confusion to accumulate? Would be nice if it could be fixed. Winamp will play these, as you used to. For all I know, the SB3 or receiver will still play them!
Hmm, yeah, that file scans OK with no errors. Are you using the very latest 7.4 build? How big are those files, do you have a smaller one that fails?
Sorry. I rip one and two hour internet programs for later listening. So the files are pretty big. If you want to pursue this before 7.4 ship (I'd understand if you don't) then either point me to an ftp upload site, or have me turn on whatever debugging might be useful.
As for me - I'll just relame them as CBR and be done with it. And I doubt many people will remove the VBR header - you need to write an MP3 parser to do that! Only caveat is that I'm guessing that VBR sans header is the problem. If its not, or if its exposing a bug, you might want to make sure.
Your file still exposed a bug and crash in Audio::Scan so I'd like to take a look at the file that caused it. Lack of a VBR header is fully supported (it just causes the code to scan every frame to determine the bitrate). Of course, using a proper header is best. :) Will send you upload details by email.
OK this was a simple fix, I left a stupid bug in there. I am curious why it causes your system to hang for several minutes. How fast is your server? On my laptop it takes only 0.2 seconds to scan your larger 106M file (reading every single frame to calculate the average bitrate).
== Auto-comment from SVN commit #434 to the opensource repo by andy == == https://svn.slimdevices.com/opensource?view=revision&revision=434 == Fixed bug 14166, fix crasher in average bitrate detection logic
I think the delay is caused by the failure. Normally, I scan 400 odd of these in just a few seconds or less - I don't notice a delay. But 80 odd failures took a number of minutes. Only the failures took a long time. Thanks for fixing it. To answer your question - my machine is an old Dell with a 2.5Ghz Pentium 4 cpu and 1 gig of memory, running Debian Lenny.
This bug has been marked as fixed in the 7.4.0 release version of SqueezeBox Server! * SqueezeCenter: 28672 * Squeezebox 2 and 3: 130 * Transporter: 80 * Receiver: 65 * Boom: 50 * Controller: 7790 * Radio: 7790 Please see the Release Notes for all the details: http://wiki.slimdevices.com/index.php/Release_Notes If you haven't already, please download and install the new version from http://www.logitechsqueezebox.com/support/download-squeezebox-server.html If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.