Amateurs – They give us professionals a bad name

Any person with half a brain would see from the error messages below that the MySQL server is not operating optimally, or more specifically the MySQL upgrade has not completely successfully and let users can go happily use the website. It amazing me when web hosting providers tell their paying client that an upgrade has been performed yet they did not have the intelligence to actually look at the error log for confirmation. Got a mysql> prompt, it’s all good. One of the first things I check is the error log.

When will people learn the MySQL error log is a valuable resource both for what it contains, and what it should not contain.

120426 17:36:00 [Note] /usr/libexec/mysqld: Shutdown complete

120426 17:36:00 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
120426 17:36:00 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
120426 17:36:00 [Note] Plugin 'FEDERATED' is disabled.
/usr/libexec/mysqld: Table 'mysql.plugin' doesn't exist
120426 17:36:00 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
120426 17:36:00 InnoDB: The InnoDB memory heap is disabled
120426 17:36:00 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120426 17:36:00 InnoDB: Compressed tables use zlib 1.2.3
120426 17:36:00 InnoDB: Using Linux native AIO
120426 17:36:00 InnoDB: Initializing buffer pool, size = 128.0M
120426 17:36:00 InnoDB: Completed initialization of buffer pool
120426 17:36:00 InnoDB: highest supported file format is Barracuda.
120426 17:36:00  InnoDB: Waiting for the background threads to start
120426 17:36:01 InnoDB: 1.1.8 started; log sequence number 232577699
120426 17:36:01 [ERROR] Missing system table mysql.proxies_priv; please run mysql_upgrade to create it
120426 17:36:01 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
120426 17:36:01 [ERROR] Native table 'performance_schema'.'events_waits_current' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'events_waits_history' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'events_waits_history_long' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'setup_consumers' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'setup_instruments' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'setup_timers' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'performance_timers' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'threads' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'events_waits_summary_by_thread_by_event_name' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'events_waits_summary_by_instance' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'events_waits_summary_global_by_event_name' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'file_summary_by_event_name' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'file_summary_by_instance' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'mutex_instances' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'rwlock_instances' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'cond_instances' has the wrong structure
120426 17:36:01 [ERROR] Native table 'performance_schema'.'file_instances' has the wrong structure
120426 17:36:01 [ERROR] Column count of mysql.db is wrong. Expected 22, found 20. Created with MySQL 50077, now running 50523. Please use mysql_upgrade to fix this error.
120426 17:36:01 [ERROR] mysql.user has no `Event_priv` column at position 29
120426 17:36:01 [ERROR] Cannot open mysql.event
120426 17:36:01 [ERROR] Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
120426 17:36:01 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.23-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL) by Atomicorp
120426 17:46:01 [ERROR] Missing system table mysql.proxies_priv; please run mysql_upgrade to create it
120426 17:46:01 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
120426 17:46:01 [ERROR] Column count of mysql.proc is wrong. Expected 20, found 16. Created with MySQL 50077, now running 50523. Please use mysql_upgrade to fix this error.

Some more light reading at Have you checked your MySQL error log today? and Monitoring MySQL – The error log

Monitoring MySQL – The error log

It is important that you monitor the MySQL error log. There are a few different options available for defining the details of the log. If not specified the default is [datadir]/[hostname].err. This is not an ideal location for 2 reasons.

First, a correctly configured MySQL datadir will have permissions only for the mysql user, and this is generally restrictive access to the user only and no group or world permissions. Other users/groups should have limited access to the mysql error log.

Second, the datadir is for data, not logs, especially logs that can potentially fill file systems. I am referring here to more then just the error log.

I would recommend you create a separate directory for MySQL logs such as the error, slow and general logs. An example I implement for single installation environments using Linux mysql packages is:

mkdir /var/log/mysql
chown mysql:mysql /var/log/mysql
chmod 750 /var/log/mysql

There does not seem to be a consensus over whether to include the hostname or not in the error log filename. My preference is to not include. I would rather the filename to be consistent across multiple servers. The argument is what about when consolidating logs from multiple servers. I discount this because you have to connect to the server to retrieve logs, create a sub directory of that hostname for consolidated logs.

With Linux distributions you may not find log files where you expect. Ubuntu packages for example has the log going to syslog. While the theory is to make system logging and monitoring easier, it makes MySQL specific monitoring more difficult. You also suffer a logrotate problem where you may only have 7 days of log. I prefer to have access to all historical MySQL log information.

The best choice is to define the error log with log-error, in both the [mysqld_safe] and [mysqld] section of your servers my.cnf

[mysqld_safe]
log-error=/var/log/mysql/error.log

[mysqld]
log-error=/var/log/mysql/error.log

In MySQL 5.1 you have the luxury of different output sources, FILE, TABLE or BOTH for the general log and the slow log with –log-output. No option exists for the error log.

Other my.cnf options to be aware of include:

  • log-warnings | skip-log-warnings
  • syslog | skip-syslog

There is generally also lacking in the standard monitoring products/plugins that present MySQL status information. In my monitoring MySQL solutions I provide a line count of the MySQL error log, so that a delta can be easily detected and then reviewed more proactively.

One issue with a recent client is the lack of access to the physical box by different parties and therefore the lack of access to the log. The identification that something needs to be viewed, then the ability to be able to view is an important problem to be solved.

References

Some other references for MySQL error log monitoring.