O2 Joggler Forum

This is doing my head in. I upgraded my NAS to a WD MyBookLive and installed LMS 7.7.3 but whenever I tried to play music the server wouldn't allow it as it was always scanning. It appears to be hanging whilst scanning and a quick google search has confirmed that this is a very common problem. I upgraded to 7.8.0 but with the same results. The music folder it scans is a carbon copy of the music folder on my PC's hard drive and LMS 7.8.0 on Windoze scans that without any complaints. The WD LMS error message is " Media scan terminated unexpectedly" and the scanner & server log files don't give too many clues. I've tried deleting the server prefs file & cache then reinstalling but that didn't help. I suspect that there's something about the albumart that is causing it to fall over but I have no means of pinpointing the problem. So I thought that I would call on the vast repository of Squeezebox-related knowledge that resides in these parts!

Of it is a problem file then the scanner log will have details of the last file scanned, try moving that folder elsewhere, stop LMS, delete the cache files and restart LMS.

If the scan then completes you know which files are causing the issue.

I had a look at the log file but couldn't spot any rogue files in it:

[14-04-01 16:44:16.4023] main::main (202) Starting Logitech Media Server scanner (v7.8.0, 1395409907, Thu Mar 27 13:20:53 PDT 2014) perl 5.010001
[14-04-01 16:44:20.7840] Slim::Music::Import::runImporter (488) Starting Slim::Media::MediaFolderScan scan
[14-04-01 16:44:20.7860] Slim::Utils::Scanner::Local::rescan (174) Discovering audio files in /shares/Public/Shared Music/Pop
[14-04-01 16:44:27.9328] Slim::Utils::Scanner::Local::__ANON__ (257) Removing deleted audio files (0)
[14-04-01 16:44:27.9469] Slim::Utils::Scanner::Local::__ANON__ (335) Scanning new audio files (1950)
[14-04-01 16:44:51.2765] Slim::Schema::Storage::throw_exception (122) Error: DBI Exception: DBD::SQLite::db commit failed: disk I/O error
[14-04-01 16:44:51.2790] Slim::Schema::Storage::throw_exception (122) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 122)
frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1006)
frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/perl5/Slim/Schema.pm line 2141)
frame 3: (eval) (/usr/share/perl5/Slim/Schema.pm line 2141)
frame 4: Slim::Schema::forceCommit (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 399)
frame 5: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 405)
frame 6: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local/Async.pm line 84)
frame 7: Slim::Utils::Scanner::Local::Async::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local/Async.pm line 165)
frame 8: Slim::Utils::Scanner::Local::Async::find (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 102)
frame 9: Slim::Utils::Scanner::Local::find (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 520)
frame 10: Slim::Utils::Scanner::Local::rescan (/usr/share/perl5/Slim/Media/MediaFolderScan.pm line 64)
frame 11: Slim::Media::MediaFolderScan::startScan (/usr/share/perl5/Slim/Music/Import.pm line 490)
frame 12: Slim::Music::Import::runImporter (/usr/share/perl5/Slim/Music/Import.pm line 327)
frame 13: Slim::Music::Import::runScan (/usr/sbin/squeezeboxserver-scanner line 324)
frame 14: (eval) (/usr/sbin/squeezeboxserver-scanner line 318)
frame 15: main::main (/usr/sbin/squeezeboxserver-scanner line 496)

[14-04-01 16:44:51.2811] Slim::Schema::forceCommit (2144) Warning: Couldn't commit transactions to DB: [Carp::Clan::__ANON__(): DBI Exception: DBD::SQLite::db commit failed: disk I/O error at /usr/share/perl5/Slim/Schema/Storage.pm line 126
]
[14-04-01 16:44:51.3476] Slim::Schema::Storage::throw_exception (122) Error: DBI Exception: DBD::SQLite::st execute failed: constraint failed
foreign key constraint failed [for Statement "INSERT INTO tracks (drm,block_alignment,remote,coverid,url,dlna_profile,samplerate,filesize,titlesearch,title,tagversion,bitrate,audio_offset,audio_size,lyrics,audio,titlesort,cover,timestamp,lossless,urlmd5,channels,primary_artist,secs,added_time,album,updated_time,content_type,tracknum,year) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)"]
[14-04-01 16:44:51.3502] Slim::Schema::Storage::throw_exception (122) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 122)
frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1006)
frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/perl5/Slim/Schema.pm line 3045)
frame 3: Slim::Schema::_insertHash (/usr/share/perl5/Slim/Schema.pm line 1392)
frame 4: Slim::Schema::_createTrack (/usr/share/perl5/Slim/Schema.pm line 1656)
frame 5: Slim::Schema::_newTrack (/usr/share/perl5/Slim/Schema.pm line 1863)
frame 6: Slim::Schema::updateOrCreateBase (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 789)
frame 7: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 854)
frame 8: Slim::Utils::Scanner::Local::new (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 375)
frame 9: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 405)
frame 10: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local/Async.pm line 84)
frame 11: Slim::Utils::Scanner::Local::Async::__ANON__ (/usr/share/perl5/Slim/Utils/Scanner/Local/Async.pm line 165)
frame 12: Slim::Utils::Scanner::Local::Async::find (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 102)
frame 13: Slim::Utils::Scanner::Local::find (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 520)
frame 14: Slim::Utils::Scanner::Local::rescan (/usr/share/perl5/Slim/Media/MediaFolderScan.pm line 64)
frame 15: Slim::Media::MediaFolderScan::startScan (/usr/share/perl5/Slim/Music/Import.pm line 490)
frame 16: Slim::Music::Import::runImporter (/usr/share/perl5/Slim/Music/Import.pm line 327)
frame 17: Slim::Music::Import::runScan (/usr/sbin/squeezeboxserver-scanner line 324)
frame 18: (eval) (/usr/sbin/squeezeboxserver-scanner line 318)
frame 19: main::main (/usr/sbin/squeezeboxserver-scanner line 496)

[14-04-01 16:44:51.3536] main::main (329) Error: Failed when running main scan: [Carp::Clan::__ANON__(): DBI Exception: DBD::SQLite::st execute failed: constraint failed
foreign key constraint failed [for Statement "INSERT INTO tracks (drm,block_alignment,remote,coverid,url,dlna_profile,samplerate,filesize,titlesearch,title,tagversion,bitrate,audio_offset,audio_size,lyrics,audio,titlesort,cover,timestamp,lossless,urlmd5,channels,primary_artist,secs,added_time,album,updated_time,content_type,tracknum,year) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)"] at /usr/share/perl5/Slim/Schema/Storage.pm line 126
]
[14-04-01 16:44:51.3552] main::main (330) Error: Skipping post-process & Not updating lastRescanTime!

I think thats the sever log, you want to check the scanner log instead.

JimbobVFR400 wrote:I think thats the sever log, you want to check the scanner log instead.

That was the file named scanner.log, the server.log file contains:

2014-04-01 16:42:55 squeezeboxserver_safe started.
[14-04-01 16:43:03.2195] main::init (368) Starting Logitech Media Server (v7.8.0, 1395409907, Thu Mar 27 13:20:53 PDT 2014) perl 5.010001
[14-04-01 16:43:08.2512] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[14-04-01 16:43:08.6758] Slim::Schema::init (162) Warning: Creating new database - empty, outdated or invalid database found
[14-04-01 16:43:14.5427] main::checkDataSource (1089) Warning: Schema updated or no media found in the database, initiating scan.
[14-04-01 16:43:32.7838] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[14-04-01 16:44:52.1023] Slim::Utils::SQLiteHelper::postConnect (359) Optimizing DB because of missing or empty sqlite_stat1 table
[14-04-01 16:46:58.8641] Slim::Utils::Scanner::Local::rescan (174) Discovering audio files in
[14-04-01 16:46:58.9323] Slim::Utils::Scanner::Local::__ANON__ (257) Removing deleted audio files (0)
[14-04-01 16:46:58.9341] Slim::Utils::Scanner::Local::__ANON__ (335) Scanning new audio files (0)
[14-04-01 16:46:58.9356] Slim::Utils::Scanner::Local::__ANON__ (413) Rescanning changed audio files (0)
[14-04-01 16:46:58.9518] Slim::Music::Artwork::updateStandaloneArtwork (204) Starting updateStandaloneArtwork for 3 albums
[14-04-01 16:46:59.1894] Slim::Music::Artwork::__ANON__ (302) updateStandaloneArtwork finished in 0.23438286781311
[14-04-01 16:46:59.2183] Slim::Music::Artwork::precacheAllArtwork (608) Starting precacheArtwork for 47 albums
[14-04-01 16:47:03.8561] Slim::Music::Artwork::__ANON__ (727) precacheArtwork finished in 4.63517594337463
[14-04-01 16:47:04.6624] Slim::Utils::Scanner::Local::rescan (174) Discovering audio files in /shares/Public/Shared Music/Pop
[14-04-01 16:47:12.8815] Slim::Utils::Scanner::Local::__ANON__ (257) Removing deleted audio files (0)
[14-04-01 16:47:12.8831] Slim::Utils::Scanner::Local::__ANON__ (335) Scanning new audio files (1685)
[14-04-01 16:47:12.8878] Slim::Utils::Scanner::Local::__ANON__ (413) Rescanning changed audio files (0)
[14-04-01 16:47:29.0756] Slim::Schema::Storage::throw_exception (122) Error: DBI Exception: DBD::SQLite::db commit failed: disk I/O error
[14-04-01 16:47:29.0782] Slim::Schema::Storage::throw_exception (122) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 122)
frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1006)
frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1163)
frame 3: DBIx::Class::Storage::DBI::_dbh_commit (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1150)
frame 4: DBIx::Class::Storage::DBI::txn_commit (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 640)
frame 5: (eval) (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 627)
frame 6: DBIx::Class::Storage::DBI::txn_do (/usr/share/squeezeboxserver/lib/DBIx/Class/Schema.pm line 650)
frame 7: DBIx::Class::Schema::txn_do (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 849)
frame 8: Slim::Utils::Scanner::Local::new (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 375)
frame 9: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scheduler.pm line 156)
frame 10: (eval) (/usr/share/perl5/Slim/Utils/Scheduler.pm line 156)
frame 11: Slim::Utils::Scheduler::run_tasks (/usr/sbin/squeezeboxserver line 691)
frame 12: main::idle (/usr/sbin/squeezeboxserver line 658)
frame 13: main::main (/usr/sbin/squeezeboxserver line 1192)

[14-04-01 16:47:29.0812] Slim::Utils::Misc::msg (1311) Warning: [16:47:29.0796] rollback ineffective with AutoCommit enabled at /usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1200.
[14-04-01 16:47:29.0831] Slim::Schema::Storage::throw_exception (122) Error: Carp::Clan::__ANON__(): DBI Exception: DBD::SQLite::db commit failed: disk I/O error at /usr/share/perl5/Slim/Schema/Storage.pm line 126
[14-04-01 16:47:29.0852] Slim::Schema::Storage::throw_exception (122) Backtrace:

frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 122)
frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 660)
frame 2: DBIx::Class::Storage::DBI::txn_do (/usr/share/squeezeboxserver/lib/DBIx/Class/Schema.pm line 650)
frame 3: DBIx::Class::Schema::txn_do (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 849)
frame 4: Slim::Utils::Scanner::Local::new (/usr/share/perl5/Slim/Utils/Scanner/Local.pm line 375)
frame 5: Slim::Utils::Scanner::Local::__ANON__ (/usr/share/perl5/Slim/Utils/Scheduler.pm line 156)
frame 6: (eval) (/usr/share/perl5/Slim/Utils/Scheduler.pm line 156)
frame 7: Slim::Utils::Scheduler::run_tasks (/usr/sbin/squeezeboxserver line 691)
frame 8: main::idle (/usr/sbin/squeezeboxserver line 658)
frame 9: main::main (/usr/sbin/squeezeboxserver line 1192)

[14-04-01 16:47:29.0873] Slim::Utils::Scheduler::run_tasks (163) Error: Scheduler task failed: Carp::Clan::__ANON__(): Carp::Clan::__ANON__(): DBI Exception: DBD::SQLite::db commit failed: disk I/O error at /usr/share/perl5/Slim/Schema/Storage.pm line 126

I think I'm on the right trail - I discovered that Mediamonkey could now tag music files with lyrics so I re-tagged all of the kids' pop music. Unfortunately the albumart is now a bit of a mess - many files have multiple albumart files attached and many of them are png or jpeg files which LMS doesn't seem to like. Windows LMS doesn't seem to mind them but Linux LMS is obviously a lot fussier. I'm surprised that the scanner.log file was so unhelpful.