Bugzilla – Bug 16142
Scanner crashes repeatedly during directory scan, "Music scan terminated unexpectedly" error
Last modified: 2011-11-06 18:00:29 UTC
I upgraded to 7.5 from 7.3.4 on my ReadyNAS NVX using the wiki procedure (Clean DB, remove, install upgrade, clean DB again). I had to revert because of severe problems with the scanner crashing. 7.3.4 works perfectly on the same library, even after a reinstall. A full scan terminates with a "Music scan terminated unexpectedly (Directory Scan)" error after a couple of minutes of scanning in versions of Squeezebox Server >7.3.4. This doesn't happen at a predefined point -- it randomly cuts out, perhaps after thousands of files scanned, perhaps three. The last file scanned is different each time. There doesn't appear to be a particular track or directory that it's having trouble with, and it doesn't appear related to a particular amount of time. In the logs, there wasn't an error message specific to the crash, even with logging set to "Info." It would merely say "scanner is not running, but no progress data available - scanner crashed." Doing a Clean DB, remove, install of 7.3.4, clean DB and rescan allows me to successfully scan and play all of my music collection. I'm running RAIDiator 4.2.9. Music library stats: Total Tracks: 26,632 Total Albums: 5,017 Total Artists: 3,335 Total Genres: 273 The following threads describe problems with 7.4.1 (which I also tried reverting to without success) that seem very similar to the ones I experienced, one on ReadyNAS, one not: http://www.readynas.com/forum/viewtopic.php?f=22&t=34836 http://www.audionervosa.com/index.php?topic=1957.0 Let me know if there are specific tests/logs that would help on your side.
I have the same setup except on a ReadyNAS DUO. Upgrading to 7.5.1 has caused the scanner to randomly, but always, crash. I've been through all the remove, re-install, clean routines but to no avail. Log: frame 10: Slim::Music::MusicFolderScan::init (/usr/sbin/squeezeboxserver line 435) frame 11: main::init (/usr/sbin/squeezeboxserver line 578) frame 12: main::main (/usr/sbin/squeezeboxserver line 1072) [10-07-25 20:50:49.0447] Slim::Schema::Storage::throw_exception (82) Error: DBI Exception: DBD::mysql::st execute failed: Table 'slimserver.dbix_migration' doesn't exist [for Statement "SELECT value FROM dbix_migration WHERE name = ?; "] [10-07-25 20:50:49.0540] Slim::Schema::Storage::throw_exception (82) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 82) frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 957) frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 237) frame 3: (eval) (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 233) frame 4: DBIx::Migration::_version (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 78) frame 5: DBIx::Migration::migrate (/usr/share/perl5/Slim/Schema.pm line 480) frame 6: Slim::Schema::migrateDB (/usr/share/perl5/Slim/Schema.pm line 161) frame 7: Slim::Schema::init (/usr/share/perl5/Slim/Music/Import.pm line 744) frame 8: Slim::Music::Import::_checkLibraryStatus (/usr/share/perl5/Slim/Music/Import.pm line 677) frame 9: Slim::Music::Import::useImporter (/usr/share/perl5/Slim/Music/MusicFolderScan.pm line 48) frame 10: Slim::Music::MusicFolderScan::init (/usr/sbin/squeezeboxserver line 435) frame 11: main::init (/usr/sbin/squeezeboxserver line 578) frame 12: main::main (/usr/sbin/squeezeboxserver line 1072) [10-07-25 20:51:12.7087] main::checkDataSource (974) Warning: Schema updated or no tracks in the database, initiating scan. [10-07-25 20:51:18.2765] Slim::Schema::Storage::throw_exception (82) Error: DBI Exception: DBD::mysql::st execute failed: MySQL server has gone away [for Statement "SELECT me.name, me.value FROM metainformation me WHERE ( name = ? )"] [10-07-25 20:51:18.2877] Slim::Schema::Storage::throw_exception (82) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 82) frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 957) frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1217) frame 3: DBIx::Class::Storage::DBI::_dbh_execute (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 547) frame 4: (eval) (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 540) frame 5: DBIx::Class::Storage::DBI::dbh_do (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1227) frame 6: DBIx::Class::Storage::DBI::_execute (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1451) frame 7: DBIx::Class::Storage::DBI::_select (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1905) frame 8: DBIx::Class::Storage::DBI::select_single (/usr/share/squeezeboxserver/CPAN/DBIx/Class/ResultSet.pm line 740) frame 9: DBIx::Class::ResultSet::single (/usr/share/perl5/Slim/Schema.pm line 584) frame 10: Slim::Schema::single (/usr/share/perl5/Slim/Music/Import.pm line 729) frame 11: Slim::Music::Import::stillScanning (/usr/share/perl5/Slim/Music/Import.pm line 232) frame 12: Slim::Music::Import::checkScanningStatus (/usr/share/perl5/Slim/Utils/Timers.pm line 255) frame 13: (eval) (/usr/share/perl5/Slim/Utils/Timers.pm line 255) frame 14: Slim::Utils::Timers::__ANON__ (/usr/share/perl5/Slim/Networking/IO/Select.pm line 183) frame 15: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 183) frame 16: Slim::Networking::IO::Select::loop (/usr/sbin/squeezeboxserver line 620) frame 17: main::idle (/usr/sbin/squeezeboxserver line 580) frame 18: main::main (/usr/sbin/squeezeboxserver line 1072) [10-07-25 20:51:28.2687] Slim::Web::Graphics::processCoverArtRequest (273) Error: Unable to resize plugins/cache/icons/radiomusic_41x41_m.png (original file: /var/lib/squeezeboxserver/cache/icons/radiomusic.png): Can't call method "width" on an undefined value at /usr/share/perl5/Slim/Utils/ImageResizer.pm line 139. [10-07-25 20:52:58.7145] Slim::Utils::Firmware::downloadAsyncError (557) Warning: Firmware: Failed to download http://update.mysqueezebox.com/update/firmware/7.5.1/jive_7.5.1_r8885.bin.sha (Connect timed out: Inappropriate ioctl for device), will try again in 10 minutes. [10-07-25 20:56:09.0854] Slim::Networking::SqueezeNetwork::_error (471) Unable to login to SN: Invalid mysqueezebox.com username or password.
This issue persists with Squeezebox Server 7.5.2 - r31632 on Radiator 4.2.15 for ReadyNAS NVX. Squeezebox Server 7.3.4 continues to scan without difficulty. This is especially disappointing, as we just picked up a Squeezebox Radio to complement our two Booms and Duet -- but it won't work with Squeezebox Server 7.3.4. That essentially makes the Squeezebox Radio a paperweight, as we're caught in a Catch-22 of it requiring a version of Squeezebox Server that can't complete a directory scan on our NVX. (The Booms and Duet continue to work without difficulty with 7.3.4.) The specific error is: Music scan terminated unexpectedly (Directory Scan) Log entries: [10-12-24 18:18:58.4691] Slim::Schema::init (147) Warning: Creating new database - empty database or database from 6.3.x found [10-12-24 18:18:58.4725] Slim::Schema::Storage::throw_exception (82) Error: DBI Exception: DBD::mysql::st execute failed: Table 'slimserver.dbix_migration' doesn't exist [for Statement "SELECT value FROM dbix_migration WHERE name = ?; " with ParamValues: 0='version'] [10-12-24 18:18:58.5830] Slim::Schema::Storage::throw_exception (82) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 82) frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 957) frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 237) frame 3: (eval) (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 233) frame 4: DBIx::Migration::_version (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 149) frame 5: DBIx::Migration::version (/usr/share/perl5/Slim/Schema.pm line 478) frame 6: Slim::Schema::migrateDB (/usr/share/perl5/Slim/Schema.pm line 161) frame 7: Slim::Schema::init (/usr/share/perl5/Slim/Music/Import.pm line 744) frame 8: Slim::Music::Import::_checkLibraryStatus (/usr/share/perl5/Slim/Music/Import.pm line 677) frame 9: Slim::Music::Import::useImporter (/usr/share/perl5/Slim/Music/MusicFolderScan.pm line 48) frame 10: Slim::Music::MusicFolderScan::init (/usr/sbin/squeezeboxserver line 435) frame 11: main::init (/usr/sbin/squeezeboxserver line 578) frame 12: main::main (/usr/sbin/squeezeboxserver line 1072) [10-12-24 18:18:58.6111] Slim::Schema::Storage::throw_exception (82) Error: DBI Exception: DBD::mysql::st execute failed: Table 'slimserver.dbix_migration' doesn't exist [for Statement "SELECT value FROM dbix_migration WHERE name = ?; " with ParamValues: 0='version'] [10-12-24 18:18:58.6120] Slim::Schema::Storage::throw_exception (82) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 82) frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 957) frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 237) frame 3: (eval) (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 233) frame 4: DBIx::Migration::_version (/usr/share/squeezeboxserver/lib/DBIx/Migration.pm line 78) frame 5: DBIx::Migration::migrate (/usr/share/perl5/Slim/Schema.pm line 480) frame 6: Slim::Schema::migrateDB (/usr/share/perl5/Slim/Schema.pm line 161) frame 7: Slim::Schema::init (/usr/share/perl5/Slim/Music/Import.pm line 744) frame 8: Slim::Music::Import::_checkLibraryStatus (/usr/share/perl5/Slim/Music/Import.pm line 677) frame 9: Slim::Music::Import::useImporter (/usr/share/perl5/Slim/Music/MusicFolderScan.pm line 48) frame 10: Slim::Music::MusicFolderScan::init (/usr/sbin/squeezeboxserver line 435) frame 11: main::init (/usr/sbin/squeezeboxserver line 578) frame 12: main::main (/usr/sbin/squeezeboxserver line 1072)
I'm seeing exactly the same symptoms though on Windows XP. Seems likely to be the same bug, but I'm not completely certain so maybe I should raise a new one? My problems are described here: http://forums.slimdevices.com/showthread.php?t=86962 I am seeing the bug with a couple of versions of 7.5.4 including the release. I don't know how far back I would need to go to find one that works, but it used to work, for example, I think 7.3 used to work fine. The place it crashes appears to be random and once it even got all the way through. This is on "clear library and rescan everything".
(In reply to comment #3) > I'm seeing exactly the same symptoms though on Windows XP. Seems likely to be > the same bug, but I'm not completely certain so maybe I should raise a new one? OK, mine perhaps isn't the same bug, since in my case it is definitely fixed by downgrading to 7.5.2 I've raised a separate bug report: 17173
Need more details.
(In reply to comment #5) > Need more details. Hi, Andy -- Thanks for taking this bug. I'd be happy to provide any diagnostic information that you'd like. Please specify any log file information that I didn't provide that might be useful, or diagnostic procedures you'd like me to follow. Dave
Created attachment 7311 [details] log from a bunch of failed scans I ran the scanner 5 times, each time, removing files/folders that appeared to bork the scan.
Andy, Trevor (T2 Support) recommended I contact you with my issue as it may be exactly the same as this bug. My situation is as follows: When using 7.5.2 or 7.5.4 (I have not tried 7.5.1 or 7.5.3) the scanner cannot perform a complete scan of my library on ReadyNAS+. Important: for me, the scanner always works flawlessly on 7.5.0, just not on later 7.5.x versions. On 7.5.2 and 7.5.4, the scanner aborts with the "terminated unexpectedly" error no more than 1% into the scan. It *looks* like the scan fails when it gets to a filename/directory that it has trouble with. Included as an attachment are the notes from my various scan attempts. As you can see, I remove some potentially difficult directory names, and the scan often gets passed that point, but fails again quickly. Based on various forum threads, I've read, it seems like something broke in 7.5.1. Now this bug specifies "7.5.x" as the version. Dave Cowen says at the top of the bug: > I upgraded to 7.5 from 7.3.4 on my ReadyNAS NVX using the wiki procedure (Clean > DB, remove, install upgrade, clean DB again). I had to revert because of > severe problems with the scanner crashing. 7.3.4 works perfectly on the same > library, even after a reinstall. Do we know if he means 7.5.0? If he does, then we have a different problem since 7.5.0 *works* for me. If he means 7.5.1 or above, then we're talking about the same problem. Assuming some restriction was introduced in 7.5.1 and has still not been fixed, can we: 1) Identify the change that was made and revert it? or 2) Change the scanner code so that if it chokes on a file, it simply skips that file and continues? <--- this seems like behavior you'd want anyway, right? Then you could report: "Scan Completed, the following x directories couldn't be parsed; the following y files couldn't be parsed;" Please let me know how I can help. Thanks, -jg
Created attachment 7312 [details] jpg of my terminated scan
*** This bug has been confirmed by popular vote. ***
Forget it. Even though it's not the *right* way to do it, I've decided to run 7.5.4 (with the 7.5.3 scanner) on the PC. The ReadyNAS NV+ with 256Mb is just underpowered to serve my library. SBS is about 10x faster (in every respect) on my 6 year-old PC. Go figure. For details see: http://forums.slimdevices.com/showthread.php?p=636401#post636401 Thanks, anyway. -jg
Hi, Jay -- I'm the original individual who compiled this ticket, and who is still stuck on SqueezeCenter 7.3.4 because of the similar scan problems that we've both experienced with the later versions. While the NV+ may well be slow, the newer ReadyNAS NVX (and the x86 versions of ReadyNAS released since) runs SqueezeCenter 7.3.4 very well. So, I'm still hoping that Logitech will one day wake up and pay attention to this issue. Andy from SlimDevices -- Both Jay and I have posted quite a bit of diagnostic information, and I've offered to provide whatever you need to help troubleshoot this issue -- but you never wrote back after you said "Need more details." If you could clarify what you need, I'd be happy to get you that information. Dave
Please retest with the latest nightly, and enable scan.scanner logging. If you find a specific file that causes this, please send it to me: http://wiki.slimdevices.com/index.php/Large_File_Upload
Well, I'll be. I got back from an extended vacation, saw your e-mail, and by that time, Logitech Media Server 7.7 had been released. Thankfully, 7.7 will now scan (short of a handful of problem MP3s) the entire collection on my ReadyNAS NVX. As above, I did find a few files which caused it to stall, but these failures were obvious and logged in a way I could hunt down the files. 7.4 through 7.6 would fail at seemingly arbitrary points, and rarely on the same file. I'll upload some of the problematic MP3s in the near future. Andy, I'm extremely encouraged by the assortment of releases in the past few months, and that you've been watching this ticket.