MySQL Bugs: #51081: Mysql died unexpectedly with "Normal shutdown"

Bug #51081	Mysql died unexpectedly with "Normal shutdown"
Submitted:	11 Feb 2010 9:20	Modified:	11 Feb 2010 9:31
Reporter:	Jose Vazquez	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: General	Severity:	S2 (Serious)
Version:	5.0.51	OS:	Linux (Ubuntu)
Assigned to:		CPU Architecture:	Any
Tags:	died, MySQL, no reason, normal shutdown, unexpectedly

Description:
One ubuntu mysql died in one server unexpectedly doing a "normal shutdown" according to syslog at 6:42 am before anyone was in the office:

Feb 11 06:42:23 madmy02ubu mysqld[5748]: 100211  6:42:23 [Note] /usr/sbin/mysqld: Normal shutdown
Feb 11 06:42:23 madmy02ubu mysqld[5748]: 
Feb 11 06:42:23 madmy02ubu mysqld[5748]: 100211  6:42:23 [Note] Slave I/O thread killed while reading event
Feb 11 06:42:23 madmy02ubu mysqld[5748]: 100211  6:42:23 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000133', position 67308444
Feb 11 06:42:23 madmy02ubu mysqld[5748]: 100211  6:42:23 [Note] Error reading relay log event: slave SQL thread was killed
Feb 11 06:42:23 madmy02ubu mysqld[5748]: 100211  6:42:23  InnoDB: Starting shutdown...
Feb 11 06:42:26 madmy02ubu mysqld[5748]: 100211  6:42:26  InnoDB: Shutdown completed; log sequence number 1 2665921338
Feb 11 06:42:26 madmy02ubu mysqld[5748]: 100211  6:42:26 [Note] /usr/sbin/mysqld: Shutdown complete
Feb 11 06:42:26 madmy02ubu mysqld[5748]: 
Feb 11 06:42:26 madmy02ubu mysqld_safe[6527]: ended

There was no cron task nor any log about the cause of it's dead. It was NOT an automatic upgrade beacause the upgrade should have restarted the server automatically and ubuntu had upgrades pending this morning after that.

Another mysql server doing replication for the first one detected the shut down:

Feb 11 06:42:23 madmy01ubu mysqld[4455]: 100211  6:42:23 [Note] Slave: received end packet from server, apparent master shutdown: 
Feb 11 06:42:23 madmy01ubu mysqld[4455]: 100211  6:42:23 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mysql-bin.000084' position 98
Feb 11 06:42:23 madmy01ubu mysqld[4455]: 100211  6:42:23 [ERROR] Slave I/O thread: error reconnecting to master 'replicant@madmy02ubu.rfranco.com:3306': Error: 'Lost connection to MySQL server at 'reading initial communication packet', system error: 111'  errno: 2013  retry-time: 60  retries: 86400

... AND 10MINUTES LATER DECIDES TO SHOWDOWN ALSO:

Feb 11 06:53:22 madmy01ubu mysqld[4455]: 100211  6:53:22 [Note] /usr/sbin/mysqld: Normal shutdown
Feb 11 06:53:22 madmy01ubu mysqld[4455]: 
Feb 11 06:53:22 madmy01ubu mysqld[4455]: 100211  6:53:22 [Note] Slave I/O thread killed during or after a reconnect done to recover from failed read
Feb 11 06:53:22 madmy01ubu mysqld[4455]: 100211  6:53:22 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000084', position 98
Feb 11 06:53:22 madmy01ubu mysqld[4455]: 100211  6:53:22 [Note] Error reading relay log event: slave SQL thread was killed
Feb 11 06:53:22 madmy01ubu mysqld[4455]: 100211  6:53:22  InnoDB: Starting shutdown...
Feb 11 06:53:24 madmy01ubu mysqld[4455]: 100211  6:53:24  InnoDB: Shutdown completed; log sequence number 1 4260337259
Feb 11 06:53:24 madmy01ubu mysqld[4455]: 100211  6:53:24 [Note] /usr/sbin/mysqld: Shutdown complete
Feb 11 06:53:24 madmy01ubu mysqld[4455]: 
Feb 11 06:53:24 madmy01ubu mysqld_safe[22491]: ended

Other Mysql servers in the office were not affected. Only these two that wehre joined in a loop-replciation (server a replicated b and b replicated a).
Does replication make the servers unstable? (no error was reported in the replication till the first server decided to shut down)
How can I know why did mysql decided to shutdown?
Anyideas of what to do or what to check?

How to repeat:
I don't know!
I hope it doesn't happen again!

Suggested fix:
Make MySQL explain itself better why it decides to shutdown?

Thank you for taking the time to write to us, but this is not a bug. Please double-check the documentation available at http://dev.mysql.com/doc/ and the instructions on
how to report a bug at http://bugs.mysql.com/how-to-report.php

Record

> Feb 11 06:42:23 madmy02ubu mysqld[5748]: 100211  6:42:23 [Note] /usr/sbin/mysqld: Normal shutdown

means one stopped server either with `mysqladmin shutdown` or /etc/init.d/mysql stop command. You have to find yourself why this happened on you system. MySQL can not report in the error log more anyway.

Mysql died unexpectedly with "Normal shutdown".
OS: Windows server 2008
MySQL: 5.1.44

What I did? 
Nothing. 
One read-only web server running against the database. 
No user logged onto the server at the time.

What I expected to happen? 
I expected the database to continue running.

What happened? 
The database stopped running.

Log shows: 
The description for Event ID 100 from source MySQL cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.
...

The following information was included with the event: 
C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqld: Normal shutdown

How to repeat:
No idea.

Not a bug?  Funny thing is this just happened at my office also.  NO one was in the building, and only 3 of us have access to the server.  The error log is identical to what the OP experienced in his first server crash.

mysql  Ver 14.12 Distrib 5.0.45, for redhat-linux-gnu (x86_64)

Confirming the bug mentioned above.

Using version 5.5.24 under Ubuntu 12.04 LTS (x86_64).

The server has just stopped all of a sudden (there was no person logged in to the server & there is no message from system that a process is being killed).

Here's the logs output:

120910  1:15:01 [Note] /usr/sbin/mysqld: Normal shutdown

120910  1:15:01 [Note] Event Scheduler: Killing the scheduler thread, thread id 3
120910  1:15:01 [Note] Event Scheduler: Waiting for the scheduler thread to reply
120910  1:15:01 [Note] Event Scheduler: Stopped
120910  1:15:01 [Note] Event Scheduler: Purging the queue. 0 events
120910  1:15:01 [Note] Error reading relay log event: slave SQL thread was killed
120910  1:15:01 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013)
120910  1:15:01 [Note] Slave I/O thread killed while reading event
120910  1:15:01 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000041', position 46655
120910  1:15:03  InnoDB: Starting shutdown...
120910  1:15:07  InnoDB: Shutdown completed; log sequence number 73266617
120910  1:15:07 [Note] /usr/sbin/mysqld: Shutdown complete

120910 01:15:07 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

So I had already filed a feature request.  The goal is I wanted to know exactly how/who shutdown a server. It is:
Bug 14601686 - MYSQLD SHOULD LOG WHICH USER INITIATED SERVER SHUTDOWN

ER_NORMAL_SHUTDOWN is written in function "kill_server".
SIGTERM can cause a normal shutdown.
SIGTERM, SIGQUIT, SIGKILL, and SHUTDOWN_ACL privileges will all cause a shutdown.

However,  if you set system datetime to be > year 2038 the server will also shutdown with normal shutdown message.

This issue has been lingering for some time, and causes a great deal of confusion when it pops up.  Is there any timeline on when this will be addressed?  Manual shutdowns really should log what user initiated it, and abnormal shutdowns should be so notated in the log at a bare minimum.

Incidentally, this is still an issue in 5.5.20-enterprise-commercial-advanced-log.