[Maia-users] web pages hang on maia, forced to reboot server. ..

[Kurt Buff]

Robert LeBlanc wrote:
> Kurt Buff wrote:
> 
> > OK - I've looked at the log 
> (/var/db/mysql/zmx1.zetron.com.err), and find
> > the follwing from the most recent two reboots. I'm not 
> seeing anything that
> > tells me what happened, but that may be due to my 
> inexperience. Prior to the
> > 24th, the last message in the error log is from the 18th. 
> Are the logs below
> > indicating any particular kind of corruption? Is the error 
> logging in MySQL
> > set high enough to tell, and if not, how do I set it higher?
> 
> The log excerpts you posted look essentially fine.  They show 
> that your
> server (or at least mysqld) shut down uncleanly on a couple 
> of occasions
> and had some cleanup to do at startup, but from the look of it the
> cleanup was straightforward and successful both times.  This doesn't
> look like a corruption problem--in a corruption scenario you'd see the
> server try the cleanup at startup and fail, shut down and restart
> itself, try the cleanup at startup and fail, shut down and restart
> itself, and so on, filling your error log with such messages until you
> eventually run out of disk space in /var/log and that would 
> finally get
> your attention ;)
> 
> On the other hand, if you don't know what caused mysqld to improperly
> shut itself down on those two occasions, that's probably the 
> next thing
> to investigate.  Was the server powered off without a clean shutdown?
> Power failure?  Did someone do a "kill -9" on the mysqld process for
> some reason?  You might want to check some of your other 
> system logs for
> events that occurred around the same time as these two 
> incidents, to see
> if they might have been a side-effect of something else going on in
> another application.

OK - I got a call at 3am from our UK office, saying they weren't getting any
mail from the world. I logged into the server from home, and found about
2500 messages in the postfix queues

I rebooted the box, noted that emails were being delivered to Exchange, and
went to bed. In the morning, I find the output from the hourly/daily jobs
that were delayed and/or not completed during the hangup.

This is the output from the first hourly job that should have completed, but
for which I didn't receive output until the reboot (and, incidentally, this
message comes last - it seems that the queue is cleaned out in reverse
chronological order):

----------
DBD::mysql::st execute failed: MySQL server has gone away at
/var/amavisd/maia/scripts/process-quarantine-sub.pl line 629.
2007-07-31 20:00:01 Maia: [process-quarantine-sub] Warning: --report not
specified, reporting is disabled.
2007-08-01 03:47:40 Maia: [process-quarantine-sub] 0 spam items processed (0
learned, 0 reported)
2007-08-01 03:47:40 Maia: [process-quarantine-sub] FATAL ERROR: Couldn't
execute query: MySQL server has gone away
2007-08-01 03:47:40 Maia: [process-quarantine] FATAL ERROR: Subroutine
terminated with a fatal error.
DBI connect('maia:localhost:3306','vscan',...) failed: Can't connect to
local MySQL server through socket '/tmp/mysql.sock' (2) at
/var/amavisd/maia/scripts/send-quarantine-digests.pl line 122
2007-08-01 03:47:40 Maia: [send-quarantine-digests] FATAL ERROR: Can't
connect to the Maia database (verify $dsn, $username, and $password in
maia.conf)
DBI connect('maia:localhost:3306','vscan',...) failed: Can't connect to
local MySQL server through socket '/tmp/mysql.sock' (2) at
/var/amavisd/maia/scripts/stats-snapshot.pl line 100
2007-08-01 03:47:40 Maia: [stats-snapshot] FATAL ERROR: Can't connect to the
Maia database (verify $dsn, $username, and $password in maia.conf)
-----------

Note the gap in the time/date stamps from the second line to the 3rd line.
Now take a look at the output from the next message:

----------
2007-07-31 21:00:00 Maia: [process-quarantine] Another instance [77929] is
currently running.
DBD::mysql::st execute failed: Lost connection to MySQL server during query
at /var/amavisd/maia/scripts/send-quarantine-digests.pl line 398.
2007-08-01 03:47:40 Maia: [send-quarantine-digests] FATAL ERROR: Couldn't
execute query: Lost connection to MySQL server during query
DBI connect('maia:localhost:3306','vscan',...) failed: Can't connect to
local MySQL server through socket '/tmp/mysql.sock' (2) at
/var/amavisd/maia/scripts/stats-snapshot.pl line 100
2007-08-01 03:47:40 Maia: [stats-snapshot] FATAL ERROR: Can't connect to the
Maia database (verify $dsn, $username, and $password in maia.conf)
----------

Note the first line - I'm betting that instance 77929 is PID of the job that
launched at 20:00 and hung while trying to find MySQL, though I can't be
sure because it's not logged in the email. In agreement with what was noted
previously, MySQL was still running when I rebooted the machine.

Kurt