Bugzilla – Bug 5504
Slimserver loses database connection.
Last modified: 2008-12-18 11:12:53 UTC
Slimserver seems to lose connection to database every night. I searched forums and saw this is rather old bug, which must be fixed. Thread in forum: http://forums.slimdevices.com/showthread.php?p=227464#post227464 VERSION INFO SlimServer Version: 6.5.4 - 12568 - Debian - EN - utf8 Perl Version: 5.8.8 i486-linux-gnu-thread-multi MySQL Version: 5.0.45-Debian_1-log 2007-09-16 23:24:26.6919 ERROR: DBI Exception: DBD::mysql::st execute failed: MySQL server has gone away [for Statement "SELECT COUNT( * ) FROM tracks me WHERE ( content_type IN ( ? ) )" with ParamValues: 0='ssp'] 2007-09-16 23:24:26.6921 ERROR: Backtrace follows: 2007-09-16 23:24:26.6924 Backtrace: frame 0: Slim::Schema::Storage::throw_exception (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 772) frame 1: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 898) frame 2: DBIx::Class::Storage::DBI::_dbh_execute (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 542) frame 3: DBIx::Class::Storage::DBI::dbh_do (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 912) frame 4: DBIx::Class::Storage::DBI::_execute (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 1026) frame 5: DBIx::Class::Storage::DBI::_select (/usr/share/perl5/DBIx/Class/Storage/DBI/Cursor.pm line 78) frame 6: DBIx::Class::Storage::DBI::Cursor::_dbh_next (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 542) frame 7: DBIx::Class::Storage::DBI::dbh_do (/usr/share/perl5/DBIx/Class/Storage/DBI/Cursor.pm line 97) frame 8: DBIx::Class::Storage::DBI::Cursor::next (/usr/share/perl5/DBIx/Class/ResultSet.pm line 974) frame 9: DBIx::Class::ResultSet::_count (/usr/share/perl5/DBIx/Class/ResultSet.pm line 933) frame 10: DBIx::Class::ResultSet::count (/usr/share/perl5/Slim/Web/Pages/Home.pm line 75) frame 11: Slim::Web::Pages::Home::home (/usr/share/perl5/Slim/Web/Pages/Home.pm line 19) frame 12: Slim::Web::Pages::Home::__ANON__ (/usr/share/perl5/Slim/Web/HTTP.pm line 843) frame 13: Slim::Web::HTTP::generateHTTPResponse (/usr/share/perl5/Slim/Web/HTTP.pm line 709) frame 14: Slim::Web::HTTP::processURL (/usr/share/perl5/Slim/Web/HTTP.pm line 555) frame 15: Slim::Web::HTTP::processHTTP (/usr/share/perl5/Slim/Networking/Select.pm line 238) frame 16: (eval) (/usr/share/perl5/Slim/Networking/Select.pm line 238) frame 17: Slim::Networking::Select::select (/usr/sbin/slimserver line 499) frame 18: main::idle (/usr/sbin/slimserver line 452) frame 19: main::main (/usr/sbin/slimserver line 1076) 2007-09-16 23:24:26.6934 Select task failed: Carp::Clan::__ANON__(): DBI Exception: DBD::mysql::st execute failed: MySQL server has gone away [for Statement "SELECT COUNT( * ) FROM tracks me WHERE ( content_type IN ( ? ) )" with ParamValues: 0='ssp'] at /usr/share/perl5/Slim/Schema/Storage.pm line 74
It is indeed an old bug, but also reported as fixed two years ago (bug 947). d_info debugging should give an indication that the server is trying to reconnect with mysql unless this handler is no longer working. Also possible that whatever attempt is being made to restart mysql is failing.
Seems it happens on logrotate. Until that time slimbox was playing normally. 2007-09-18 07:36:53.3217 ERROR: forceCommit: Trying to commit transactions before DB is initialized! 2007-09-18 07:36:53 slimserver_safe stopped. 2007-09-18 07:36:53 slimserver_safe started. 2007-09-18 07:37:03.2459 ERROR: DBI Exception: DBD::mysql::db begin_work failed: Already in a transaction 2007-09-18 07:37:03.2461 ERROR: Backtrace follows: 2007-09-18 07:37:03.2463 Backtrace: frame 0: Slim::Schema::Storage::throw_exception (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 772) frame 1: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 798) frame 2: DBIx::Class::Storage::DBI::txn_begin (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 596) frame 3: (eval) (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 592) frame 4: DBIx::Class::Storage::DBI::txn_do (/usr/share/perl5/DBIx/Class/Schema.pm line 728) frame 5: DBIx::Class::Schema::txn_do (/usr/share/perl5/Slim/Schema/Playlist.pm line 46) frame 6: (eval) (/usr/share/perl5/Slim/Schema/Playlist.pm line 39) frame 7: Slim::Schema::Playlist::setTracks (/usr/share/perl5/Slim/Player/Playlist.pm line 757) frame 8: Slim::Player::Playlist::modifyPlaylistCallback (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 9: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 10: Slim::Control::Request::notify (/usr/share/perl5/Slim/Control/Request.pm line 751) frame 11: Slim::Control::Request::checkNotifications (/usr/sbin/slimserver line 476) frame 12: main::idle (/usr/sbin/slimserver line 452) frame 13: main::main (/usr/sbin/slimserver line 1076) 2007-09-18 07:37:03.2469 ERROR: Carp::Clan::__ANON__(): DBI Exception: DBD::mysql::db begin_work failed: Already in a transaction at /usr/share/perl5/Slim/Schema/Storage.pm line 74
(In reply to comment #2) > Seems it happens on logrotate. Until that time slimbox was playing normally. On my box SlimServer-Version: 6.5.5 - 13024 - Debian - DE - utf8 Perl-Version: 5.8.8 i486-linux-gnu-thread-multi MySQL-Version: 5.0.45-Debian_1 not only then. If webserver forking is enabled, it freezes quite often while browsing the database. Now, with forking disabled, I still can find messages like this in the logfile after adding items to the playlist on a freshly started slimserver (I crosschecked that no processes owned by the slimserver are running prior to the slimserver start) 2007-09-18 16:22:12 slimserver_safe started. 2007-09-18 16:24:29.6726 ERROR: DBI Exception: DBD::mysql::db begin_work failed: Already in a transaction 2007-09-18 16:24:29.6731 ERROR: Backtrace follows: 2007-09-18 16:24:29.6742 Backtrace: frame 0: Slim::Schema::Storage::throw_exception (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 833) frame 1: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 861) frame 2: DBIx::Class::Storage::DBI::txn_begin (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 626) frame 3: (eval) (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 622) frame 4: DBIx::Class::Storage::DBI::txn_do (/usr/share/perl5/DBIx/Class/Schema.pm line 729) frame 5: DBIx::Class::Schema::txn_do (/usr/share/perl5/Slim/Schema/Playlist.pm line 46) frame 6: (eval) (/usr/share/perl5/Slim/Schema/Playlist.pm line 39) frame 7: Slim::Schema::Playlist::setTracks (/usr/share/perl5/Slim/Player/Playlist.pm line 757) frame 8: Slim::Player::Playlist::modifyPlaylistCallback (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 9: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 10: Slim::Control::Request::notify (/usr/share/perl5/Slim/Control/Request.pm line 751) frame 11: Slim::Control::Request::checkNotifications (/usr/sbin/slimserver line 476) frame 12: main::idle (/usr/sbin/slimserver line 452) frame 13: main::main (/usr/sbin/slimserver line 1076) 2007-09-18 16:24:29.6765 ERROR: DBIx::Class::Storage::NESTED_ROLLBACK_EXCEPTION=HASH(0xacf9284) 2007-09-18 16:24:29.6770 ERROR: Backtrace follows: 2007-09-18 16:24:29.6779 Backtrace: frame 0: Slim::Schema::Storage::throw_exception (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 902) frame 1: DBIx::Class::Storage::DBI::txn_rollback (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 643) frame 2: (eval) (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 643) frame 3: DBIx::Class::Storage::DBI::txn_do (/usr/share/perl5/DBIx/Class/Schema.pm line 729) frame 4: DBIx::Class::Schema::txn_do (/usr/share/perl5/Slim/Schema/Playlist.pm line 46) frame 5: (eval) (/usr/share/perl5/Slim/Schema/Playlist.pm line 39) frame 6: Slim::Schema::Playlist::setTracks (/usr/share/perl5/Slim/Player/Playlist.pm line 757) frame 7: Slim::Player::Playlist::modifyPlaylistCallback (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 8: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 9: Slim::Control::Request::notify (/usr/share/perl5/Slim/Control/Request.pm line 751) frame 10: Slim::Control::Request::checkNotifications (/usr/sbin/slimserver line 476) frame 11: main::idle (/usr/sbin/slimserver line 452) frame 12: main::main (/usr/sbin/slimserver line 1076) 2007-09-18 16:24:29.6786 ERROR: Carp::Clan::__ANON__(): DBI Exception: DBD::mysql::db begin_work failed: Already in a transaction at /usr/share/perl5/Slim/Schema/Storage.pm line 74 2007-09-18 16:24:29.6790 ERROR: Backtrace follows: 2007-09-18 16:24:29.6799 Backtrace: frame 0: Slim::Schema::Storage::throw_exception (/usr/share/perl5/DBIx/Class/Storage/DBI.pm line 647) frame 1: DBIx::Class::Storage::DBI::txn_do (/usr/share/perl5/DBIx/Class/Schema.pm line 729) frame 2: DBIx::Class::Schema::txn_do (/usr/share/perl5/Slim/Schema/Playlist.pm line 46) frame 3: (eval) (/usr/share/perl5/Slim/Schema/Playlist.pm line 39) frame 4: Slim::Schema::Playlist::setTracks (/usr/share/perl5/Slim/Player/Playlist.pm line 757) frame 5: Slim::Player::Playlist::modifyPlaylistCallback (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 6: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1645) frame 7: Slim::Control::Request::notify (/usr/share/perl5/Slim/Control/Request.pm line 751) frame 8: Slim::Control::Request::checkNotifications (/usr/sbin/slimserver line 476) frame 9: main::idle (/usr/sbin/slimserver line 452) frame 10: main::main (/usr/sbin/slimserver line 1076) 2007-09-18 16:24:29.6807 ERROR: setTracks: Failed to add tracks to playlist: [Carp::Clan::__ANON__(): Carp::Clan::__ANON__(): DBI Exception: DBD::mysql::db begin_work failed: Already in a transaction at /usr/share/perl5/Slim/Schema/Storage.pm line 74 ========================================================================= It just doesn't seem to be normal.
Yes, you are correct. Indeed it was freezing all the time when threading was enabled.
Konstantin: Does this still happen with SqueezeCenter 7?
No, I do not see this error in SC7, but Squezebox stops every night, if I leave it playing. Perhaps on some scheduled job.
Debian, I think, does a logrotate daily (6:30am on my system). This stops and restarts the server in order to have access to the logs for rotation. Check /etc/logrotate.d
Indeed. I did not think about server restart. :))
Cool. So, we can call this one fixed?
Thanks KDF!
This bug is being closed since it was resolved for a version which is now released! Please download the new version of SqueezeCenter (formerly SlimServer) at http://www.slimdevices.com/su_downloads.html If you are still seeing this bug, please re-open it and we will consider it for a future release.