ntpdate can cause mysqld to shut down

[Justin Force]

This is documented at http://bugs.mysql.com/bug.php?id=6263 as MySQL bug #6263, but a developer, Heikki Tuuri, says that this is a Linux bug and should be reported to the distribution maintainers. It doesn't look like it's specifically an ntpdate bug, or a Linux kernel bug, so I'm reporting it as a mysql-server bug.

If ntpdate causes a substantial time step (in my case approximately -8.8 seconds) during a transaction, this can cause an I/O error which causes mysqld to shut down. It shuts down cleanly, but it just shuts down. This server has been up and running these services for more than a year, and this is the first time that a MySQL transaction of sufficient complexity happened to coincide with an ntpdate update of sufficient size, but it could potentially happen again and again with no warning.

I have worked around this by modifying my ntpdate cron job to look like

#!/bin/sh

service mysql stop
ntpdate time.ucsb.edu
service mysql start

Relevant logs:

Email from cron:
/etc/cron.daily/ntpdate: 11 Feb 06:34:19 ntpdate[32101]: step time server 10.0.0.1 offset -8.389688 sec

/var/log/daemon.log:
Feb 11 06:34:19 fez mysqld[2399]: 100211 6:34:19 [Note] /usr/sbin/mysqld: Normal shutdown
Feb 11 06:34:19 fez mysqld[2399]:
Feb 11 06:34:21 fez mysqld[2399]: 100211 6:34:21 InnoDB: Starting shutdown...
Feb 11 06:34:23 fez mysqld[2399]: 100211 6:34:23 InnoDB: Shutdown completed; log sequence number 0 603514990
Feb 11 06:34:23 fez mysqld[2399]: 100211 6:34:23 [Note] /usr/sbin/mysqld: Shutdown complete
Feb 11 06:34:23 fez mysqld[2399]:
Feb 11 06:34:23 fez mysqld_safe[32034]: ended

[Scott Moser (smoser)]

Is there a reason you're using ntpdate instead of ntpd ? In general ntpdate should only be run on boot as many applications can be confused by large or negative changes in time.

[Lars Ljung (larslj)]

An alternative explanation is that you were bitten by Debian bug #415124 (http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=415124). The same thing happened to me this morning. Do you use unattended-upgrade?

[Justin Force (justin-force)]

@Scott Moser: I didn't know ntpd existed. :) Thank you for the suggestion. I will switch.

@Lars Ljung: I AM using unattended updates. The aforementioned Debian bug is the bug that affected me. See?

From /var/log/apt/term.log:

Log started: 2010-02-11 06:34:18
(Reading database ... 67589 files and directories currently installed.)
Preparing to replace mysql-server 5.1.30really5.0.75-0ubuntu10.2 (using .../mysql-server_5.1.30really5.0.75-0ubuntu10.3_all.deb) ...
 * Stopping MySQL database server mysqld
   ...done.
Unpacking replacement mysql-server ...
Setting up mysql-server (5.1.30really5.0.75-0ubuntu10.3) ...
Log ended: 2010-02-11 06:34:26

Thank you! Looks like this bug is invalid?

[Chuck Short (zulcss)]

Closing then.