PDA

View Full Version : Mysql reconnect



sbbr
2007-09-16, 13:34
Hello!

Slimserver seems to lose connection to database every night. I searched forums and saw this is rather old bug, which must be fixed. Anybody sees this?


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

mrfantasy
2007-09-16, 16:12
This seems to be happening in Debian Etch/Lenny. I'm running it at home and seeing this issue. I was able to connect directly to the socket file with the mysql client when SlimServer stopped responding, so it's apparently not mysql crashing or becoming unresponsive. SlimServer doesn't completely crash (SuperDateTime still runs) but the web interface just hangs and you can't select music.

I think it's time for a bug report. . .

sbbr
2007-09-17, 00:35
Submitted bug report.

mrfantasy
2007-09-17, 12:32
What's the bug ID? I'll see what information I can add.

sbbr
2007-09-17, 14:33
http://bugs.slimdevices.com/show_bug.cgi?id=5504

sbbr
2007-09-18, 00:13
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

lerouxt
2007-09-18, 19:32
are you sure it happens on logrotate?

I also have similar probs, but logs for slimserver in etch are rotated once a week.. plus, the logrotate script on etch stops slimserver prerotate, and starts postrotate (see /etc/logrotate.d/slimserver)

sbbr
2007-09-18, 23:12
Yes, it is supposed to be rotated weekly, but actually rotates daily because size of logfile must be less than 200k.

cat /etc/logrotate.d/slimserver
/var/log/slimserver/slimserver.log {
weekly
rotate 5
size 200k
compress
missingok
prerotate
invoke-rc.d slimserver stop || true
endscript

postrotate
# Only starts slimserver if it is supposed to
# run in the current run-level
invoke-rc.d slimserver start || true
endscript
}

Mark Miksis
2007-09-19, 07:31
"size 200k" means to rotate when the logfile is 200k or larger. This shouldn't cause it to rotate daily.

Hering
2007-09-19, 08:26
I dont know if this is relevant, but my Debian Etch seems to rotate the log also daily:

slim:~# tail -150 /var/log/messages
Sep 18 06:25:13 slim syslogd 1.4.1#18: restart.
[...]
Sep 19 06:25:46 slim syslogd 1.4.1#18: restart.

BTW, I use a seperate MySQL instance and get the similar error messages as sbbr.

sbbr
2007-09-20, 05:54
It grows >200K daily :)



"size 200k" means to rotate when the logfile is 200k or larger. This shouldn't cause it to rotate daily.