View Full Version : Server Power Control Shutdown after Scan results in LMS Crash

2015-01-14, 07:06
On ubuntu 14.04, 64 bit, using "Logitech Media Server Version: 7.9.0 - 1420550541 @ Wed Jan 7 04:04:59 UTC 2015" with Server Power Control plugin v20141101.163656.

When I need to rescan my library I normally do this overnight (because Custom Scans take several hours). I use the very useful Server Power Control (SPC) plugin to ensure LMS is awake well before the scheduled rescan start time, and to shut down when all is done. This has normally worked well.

At some point in the last few months I started to notice that the server log had crashes in it at shutdown time, and ubuntu was complaining about crashes the next morning. An example of such a crash reported on the log is shown below.

To cut quite a long story short, with many different tests, I think I have managed to fix it by changing the shutdown command in SPC slightly, from

sudo /sbin/shutdown -h now

sudo /sbin/shutdown -h now &
The idea being that maybe SPC was blocking LMS (not just squeezeboxserver_safe) from shutting down properly, and the trailing "&" would allow SPC to relinquish control to let LMS shut down.

Has anyone else had this problem, or is able to shed light on the log entry? (Sometimes the crash log seems to suggest the scan hasn't finished, but it has. I repeated the process during the day is several different ways, and the scan was definitely done (I also tried stopping including the Custom Scan and manually ran the SPC shutdown command and still got a crash).

[15-01-10 06:14:11.1576] Plugins::SrvrPowerCtrl::Util::SystemExecCmd (892) SrvrPowerCtrl executing command: /storage/Scripts/wakealarm.sh 1420935600 --verbose --log
[15-01-10 06:14:17.0042] Plugins::SrvrPowerCtrl::Util::SystemExecCmd (892) SrvrPowerCtrl executing command: sudo /sbin/shutdown -h now
2015-01-10 06:14:20 squeezeboxserver_safe stopped.
[15-01-10 06:14:20.9061] Slim::Schema::Storage::throw_exception (122) Error: DBI Exception: DBD::SQLite::st execute failed: attempt to execute on inactive database handle [for Statement "SELECT value FROM metainformation WHERE name = 'isScanning'"]
[15-01-10 06:14:20.9313] 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/Music/Import.pm line 656)
frame 3: Slim::Music::Import::stillScanning (/usr/sbin/squeezeboxserver line 1155)
frame 4: main::cleanup (/usr/share/perl5/Slim/bootstrap.pm line 417)
frame 5: Slim::bootstrap::sigterm (/usr/share/perl5/Slim/Schema.pm line 331)
frame 6: (eval) (/usr/share/perl5/Slim/Schema.pm line 331)
frame 7: (eval) (/usr/share/perl5/Slim/Schema.pm line 331)
frame 8: Slim::Schema::disconnect (/usr/sbin/squeezeboxserver line 1161)
frame 9: main::cleanup (/usr/sbin/squeezeboxserver line 1140)
frame 10: main::stopServer (/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SrvrPowerCtrl/Util.pm line 985)
frame 11: Plugins::SrvrPowerCtrl::Util::__ANON__ (/usr/share/perl5/Slim/Utils/Timers.pm line 266)
frame 12: (eval) (/usr/share/perl5/Slim/Utils/Timers.pm line 266)
frame 13: Slim::Utils::Timers::__ANON__ (/usr/share/perl5/Slim/Networking/IO/Select.pm line 168)
frame 14: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 168)
frame 15: Slim::Networking::IO::Select::loop (/usr/sbin/squeezeboxserver line 715)
frame 16: main::idle (/usr/sbin/squeezeboxserver line 665)
frame 17: main::main (/usr/sbin/squeezeboxserver line 1200)

[15-01-10 06:14:21.9315] Plugins::SrvrPowerCtrl::Util::SystemExecCmd (892) SrvrPowerCtrl executing command: /storage/Scripts/wakealarm.sh 1420935600 --verbose --log
[15-01-10 06:14:23.6360] Slim::Schema::forceCommit (2147) Warning: Trying to commit transactions before DB is initialized!
[15-01-10 06:14:23.6437] Plugins::SrvrPowerCtrl::Util::SystemExecCmd (892) SrvrPowerCtrl executing command: /storage/Scripts/wakealarm.sh 1420935600 --verbose --log
2015-01-10 08:47:50 squeezeboxserver_safe started.

2015-01-20, 23:26
Thanks. You've confirmed that forking shutdown with & solves the problem? If so, I'll put that into the code. Thanks.

2015-01-21, 01:22
Thanks. You've confirmed that forking shutdown with & solves the problem? If so, I'll put that into the code. Thanks.
I haven't had a crash report in the server log since I added the &, so I guess that fixed it.

Did my rationale for the cause make any sense?

When you make the fix to 'code' will I need to take the & off my command line, or will you be adding it to the default value shown on the settings page?

This got a bit confusing since I also had a crash of the LMS scanner (not reported in the server log, but as a segfault in the ubuntu kern.log) that I thought was related. That turned out to be a separate problem introduced a while ago in the LMS 'full text search' plugin. I'm testing the fix for that right now.