MySQL shutdown via service reporting ERROR

Working with MySQL 5.6 under CentOS 6.4 I came across the following problem with MySQL reporting it did not shutdown successfully.

$ sudo su -
$ service mysql stop
Shutting down MySQL................................................................................................................................................................................................................................................................................................
.........................................................................................................................................................................................................................................................................................................
.........................................................................................................................................................................................................................................................................................................
................. ERROR!

However, you have to look into the problem in the all important MySQL Error Log where I found a different story.

$ tail -100 /mysql/log/error.log
...
2013-11-04 14:43:40 32351 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2013-11-04 14:43:40 32351 [Note] Shutting down plugin 'INNODB_LOCKS'
2013-11-04 14:43:40 32351 [Note] Shutting down plugin 'INNODB_TRX'
2013-11-04 14:43:40 32351 [Note] Shutting down plugin 'InnoDB'
2013-11-04 14:43:40 32351 [Note] InnoDB: FTS optimize thread exiting.
2013-11-04 14:43:40 32351 [Note] InnoDB: Starting shutdown...
2013-11-04 14:44:41 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:45:41 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:46:41 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:47:41 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:48:41 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:49:41 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:50:42 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:51:42 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:52:42 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:53:42 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:54:42 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:55:42 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:56:43 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:57:43 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:58:43 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 14:59:43 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 15:00:43 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 15:01:43 32351 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-04 15:02:01 32351 [Note] InnoDB: Shutdown completed; log sequence number 109188218872
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'MRG_MYISAM'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'CSV'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'MEMORY'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'MyISAM'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'sha256_password'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'mysql_old_password'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'mysql_native_password'
2013-11-04 15:02:01 32351 [Note] Shutting down plugin 'binlog'
2013-11-04 15:02:01 32351 [Note] /usr/sbin/mysqld: Shutdown complete

131104 15:02:01 mysqld_safe mysqld from pid file /var/run/mysqld/mysql.pid ended

The log indicates that the server is actually shutdown, an attempt to try again results in

$ service mysql stop
 ERROR! MySQL server PID file could not be found!

Doing some more investigation to pinpoint if the issue is “service” (i.e. “init.d”) related, I found that the command took suspiciously exactly 15 minutes (on several occasions) and MySQL was indeed not shutdown. For example:

$ sudo su -
$ time service mysql stop; tail /mysql/log/error.log
Shutting down MySQL................................................................................................................................................................................................................................................................................................
..........................................................................................................................................................................................................................................................................................................
..........................................................................................................................................................................................................................................................................................................
................ ERROR!

real	15m4.003s
user	0m0.561s
sys	0m2.194s
2013-11-06 16:50:37 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:51:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:52:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:53:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:54:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:55:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:56:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:57:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:58:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:59:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool

However, waiting it did indeed complete successfully.

tail -f /mysql/log/error.log
2013-11-06 16:51:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:52:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:53:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:54:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:55:38 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:56:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:57:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:58:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 16:59:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 17:00:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 17:01:39 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 17:02:40 19887 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2013-11-06 17:03:03 19887 [Note] InnoDB: Shutdown completed; log sequence number 109974145720
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'MRG_MYISAM'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'CSV'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'MEMORY'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'MyISAM'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'sha256_password'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'mysql_old_password'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'mysql_native_password'
2013-11-06 17:03:03 19887 [Note] Shutting down plugin 'binlog'
2013-11-06 17:03:03 19887 [Note] /usr/sbin/mysqld: Shutdown complete

131106 17:03:03 mysqld_safe mysqld from pid file /var/run/mysqld/mysql.pid ended
Tagged with: Databases MySQL

Related Posts

Fixing Old Software Bugs Without Thinking

I previously came across an issue in my benchmarking work where I relied on the Latency Histogram section of sysbench output. On Linux it worked fine — I generally ran my workload there, so it never mattered.

Read more

Curating DuckDB Datasets Leveraging AI

In Curated MySQL Data Sets for Realistic Testing I described datasets assembled the manual way — download, schema, load, validate, document — over hours or days per source. This post is the follow-up I promised: what changes when AI assists the same workflow, using DuckDB as the target engine and GeoNames as the first example.

Read more

Why INSERT IGNORE should not be used

Let’s say you’re building a reference table from source data, e.g. a silver medallion table from a primary source. In this example I am using a file of random locations on the globe extracted from OpenStreetMap (OSM) as my primary source.

Read more