blog
Understanding the MySQL Error Log
We are yet to see a software that runs perfectly, without any issues. MySQL is no exception there. It’s not the software’s fault – we need to be clear about that. We use MySQL in different places, on different hardware and within different environments. It’s also highly configurable. All those features make it great product but they come with a price – sometimes some settings won’t work correctly under certain conditions. It is also pretty easy to make simple human mistakes like typos in the MySQL configuration. Luckily, MySQL provides us with means to understand what is wrong through the error log. In this blog, we’ll see how to read the information in the error log.
This is the fifteenth installment in the ‘Become a MySQL DBA’ blog series. Our previous posts in the DBA series include:
- Optimizing Hints for faster queries,
- Using EXPLAIN to improve SQL Queries,
- Database Indexing,
- Deep Dive pt-query-digest,
- Analyzing SQL Workload with pt-query-digest,
- Query Tuning Process,
- Configuration Tuning,
- Live Migration using MySQL Replication,
- Database Upgrades,
- Replication Topology Changes,
- Schema Changes,
- High Availability,
- Backup & Restore,
- Monitoring & Trending.
Error log on MySQL – clean startup and shutdown
MySQL’s error log may contain a lot of information about different issues you may encounter. Let’s start with checking what a ‘clean’ start of MySQL looks like. It will make it easier to find any anomalies later.
At first, all plugins (and storage engines, which do work as plugins in MySQL 5.6) are initiated. If something is not right, you’ll see errors on this stage.
2015-10-26 19:35:20 13762 [Note] Plugin 'FEDERATED' is disabled.Next we can see a significant part related to InnoDB initialization.
2015-10-26 19:35:20 13762 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-10-26 19:35:20 13762 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-26 19:35:20 13762 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-26 19:35:20 13762 [Note] InnoDB: Memory barrier is not used
2015-10-26 19:35:20 13762 [Note] InnoDB: Compressed tables use zlib 1.2.8
2015-10-26 19:35:20 13762 [Note] InnoDB: Using Linux native AIO
2015-10-26 19:35:20 13762 [Note] InnoDB: Using CPU crc32 instructions
2015-10-26 19:35:20 13762 [Note] InnoDB: Initializing buffer pool, size = 512.0M
2015-10-26 19:35:21 13762 [Note] InnoDB: Completed initialization of buffer pool
2015-10-26 19:35:21 13762 [Note] InnoDB: Highest supported file format is Barracuda.
2015-10-26 19:35:21 13762 [Note] InnoDB: 128 rollback segment(s) are active.
2015-10-26 19:35:21 13762 [Note] InnoDB: Waiting for purge to start
2015-10-26 19:35:21 13762 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 710963181In the next phase, authentication plugins are initiated (if they are configured correctly).
2015-10-26 19:35:21 13762 [Note] RSA private key file not found: /var/lib/mysql//private_key.pem. Some authentication plugins will not work.
2015-10-26 19:35:21 13762 [Note] RSA public key file not found: /var/lib/mysql//public_key.pem. Some authentication plugins will not work.At the end you’ll see information about binding MySQL to the configured IP and port. Event scheduler is also initialized. Finally, you’ll see ‘ready for connections’ message indicating that MySQL started correctly.
2015-10-26 19:35:21 13762 [Note] Server hostname (bind-address): '*'; port: 33306
2015-10-26 19:35:21 13762 [Note] IPv6 is available.
2015-10-26 19:35:21 13762 [Note] - '::' resolves to '::';
2015-10-26 19:35:21 13762 [Note] Server socket created on IP: '::'.
2015-10-26 19:35:21 13762 [Warning] 'proxies_priv' entry '@ root@ip-172-30-4-23' ignored in --skip-name-resolve mode.
2015-10-26 19:35:21 13762 [Note] Event Scheduler: Loaded 2 events
2015-10-26 19:35:21 13762 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.26-74.0' socket: '/var/run/mysqld/mysqld.sock' port: 33306 Percona Server (GPL), Release 74.0, Revision 32f8dfdHow does the shutdown process look like? Let’s follow it step by step:
2015-10-26 19:35:13 12955 [Note] /usr/sbin/mysqld: Normal shutdownThis line is very important – MySQL can be stopped in many ways – a user can use init scripts, it’s possible to use ‘mysqladmin’ to execute SHUTDOWN command, it’s also possible to send a SIGTERM to MySQL initiating shutdown of the database. At times you’ll be investigating why MySQL instance had stopped – this line is always an indication that someone (or something) triggered clean shutdown. No crash happened, MySQL wasn’t killed either.
2015-10-26 19:35:13 12955 [Note] Giving 12 client threads a chance to die gracefully
2015-10-26 19:35:13 12955 [Note] Event Scheduler: Purging the queue. 2 events
2015-10-26 19:35:13 12955 [Note] Shutting down slave threads
2015-10-26 19:35:15 12955 [Note] Forcefully disconnecting 6 remaining clients
2015-10-26 19:35:15 12955 [Warning] /usr/sbin/mysqld: Forcing close of thread 37 user: 'cmon'
2015-10-26 19:35:15 12955 [Warning] /usr/sbin/mysqld: Forcing close of thread 53 user: 'cmon'
2015-10-26 19:35:15 12955 [Warning] /usr/sbin/mysqld: Forcing close of thread 38 user: 'cmon'
2015-10-26 19:35:15 12955 [Warning] /usr/sbin/mysqld: Forcing close of thread 39 user: 'cmon'
2015-10-26 19:35:15 12955 [Warning] /usr/sbin/mysqld: Forcing close of thread 44 user: 'cmon'
2015-10-26 19:35:15 12955 [Warning] /usr/sbin/mysqld: Forcing close of thread 47 user: 'cmon'In the above, MySQL is closing remaining connections – it allows them to finish on their own but if they do not close, they will be forcefully terminated.
2015-10-26 19:35:15 12955 [Note] Binlog end
2015-10-26 19:35:15 12955 [Note] Shutting down plugin 'partition'
2015-10-26 19:35:15 12955 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2015-10-26 19:35:15 12955 [Note] Shutting down plugin 'ARCHIVE'
...Here MySQL is shutting down all plugins that were enabled in its configuration. There are many of them so we removed some output for the sake of better visibility.
2015-10-26 19:35:15 12955 [Note] Shutting down plugin 'InnoDB'
2015-10-26 19:35:15 12955 [Note] InnoDB: FTS optimize thread exiting.
2015-10-26 19:35:15 12955 [Note] InnoDB: Starting shutdown...
2015-10-26 19:35:17 12955 [Note] InnoDB: Shutdown completed; log sequence number 710963181One of them is InnoDB – this step may take a while as a clean InnoDB shutdown can take some time on a busy server, even with InnoDB fast shutdown enabled (and this is the default setting).
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'MyISAM'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'MRG_MYISAM'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'CSV'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'MEMORY'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'sha256_password'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'mysql_old_password'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'mysql_native_password'
2015-10-26 19:35:17 12955 [Note] Shutting down plugin 'binlog'
2015-10-26 19:35:17 12955 [Note] /usr/sbin/mysqld: Shutdown completeThe shutdown process concludes with ‘Shutdown complete’ message.
Configuration errors
Let’s start with a basic issue – configuration error. It’s really a popular problem. Sometimes we make a typo in a variable name, while editing my.cnf. MySQL parses its configuration files when it starts. If something is wrong, it will refuse to run. Let’s take a look at some examples:
2015-10-27 11:20:05 18858 [Note] Plugin 'FEDERATED' is disabled.
2015-10-27 11:20:05 18858 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-10-27 11:20:05 18858 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-27 11:20:05 18858 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-27 11:20:05 18858 [Note] InnoDB: Memory barrier is not used
2015-10-27 11:20:05 18858 [Note] InnoDB: Compressed tables use zlib 1.2.8
2015-10-27 11:20:05 18858 [Note] InnoDB: Using Linux native AIO
2015-10-27 11:20:05 18858 [Note] InnoDB: Using CPU crc32 instructions
2015-10-27 11:20:05 18858 [Note] InnoDB: Initializing buffer pool, size = 512.0M
2015-10-27 11:20:05 18858 [Note] InnoDB: Completed initialization of buffer pool
2015-10-27 11:20:05 18858 [Note] InnoDB: Highest supported file format is Barracuda.
2015-10-27 11:20:05 18858 [Note] InnoDB: 128 rollback segment(s) are active.
2015-10-27 11:20:05 18858 [Note] InnoDB: Waiting for purge to start
2015-10-27 11:20:06 18858 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 773268083
2015-10-27 11:20:06 18858 [ERROR] /usr/sbin/mysqld: unknown variable '--max-connections=512'
2015-10-27 11:20:06 18858 [ERROR] AbortingAs you can see from the above, we have here a clear copy-paste error with regards to max_connections variable. MySQL doesn’t accept ‘–’ prefix in my.cnf so if you are copying settings from the ‘ps’ output or from MySQL documentation, please keep it in mind. There are many things that can go wrong but it’s important that ‘unknown variable’ error always points you to my.cnf and to some kind of mistake which MySQL can’t understand.
Another problem can be related to misconfigurations. Let’s say we over-allocated memory on our server. Here’s what you might see:
2015-10-27 11:24:41 31325 [Note] Plugin 'FEDERATED' is disabled.
2015-10-27 11:24:41 31325 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-10-27 11:24:41 31325 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-27 11:24:41 31325 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-27 11:24:41 31325 [Note] InnoDB: Memory barrier is not used
2015-10-27 11:24:41 31325 [Note] InnoDB: Compressed tables use zlib 1.2.8
2015-10-27 11:24:41 31325 [Note] InnoDB: Using Linux native AIO
2015-10-27 11:24:41 31325 [Note] InnoDB: Using CPU crc32 instructions
2015-10-27 11:24:41 31325 [Note] InnoDB: Initializing buffer pool, size = 512.0G
InnoDB: mmap(70330089472 bytes) failed; errno 12
2015-10-27 11:24:41 31325 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
2015-10-27 11:24:41 31325 [ERROR] Plugin 'InnoDB' init function returned error.
2015-10-27 11:24:41 31325 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2015-10-27 11:24:41 31325 [ERROR] Unknown/unsupported storage engine: InnoDB
2015-10-27 11:24:41 31325 [ERROR] AbortingAs you can clearly see, we’ve tried to allocate 512G of memory which was not possible on this host. InnoDB is required for MySQL to start, therefore error in initializing InnoDB prevented MySQL from starting.
Permission errors
Below are three examples of three crashes related to permission errors.
/usr/sbin/mysqld: File './binlog.index' not found (Errcode: 13 - Permission denied)
2015-10-27 11:31:40 11469 [ERROR] AbortingThis one is pretty self-explanatory. As stated, MySQL couldn’t find an index file for binary logs due to ‘permission denied’ error. This is also a hard stop for MySQL, it has to be able to read and write to binary logs.
2015-10-27 11:32:46 13601 [Note] Plugin 'FEDERATED' is disabled.
2015-10-27 11:32:46 13601 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-10-27 11:32:46 13601 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-27 11:32:46 13601 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-27 11:32:46 13601 [Note] InnoDB: Memory barrier is not used
2015-10-27 11:32:46 13601 [Note] InnoDB: Compressed tables use zlib 1.2.8
2015-10-27 11:32:46 13601 [Note] InnoDB: Using Linux native AIO
2015-10-27 11:32:46 13601 [Note] InnoDB: Using CPU crc32 instructions
2015-10-27 11:32:46 13601 [Note] InnoDB: Initializing buffer pool, size = 512.0M
2015-10-27 11:32:46 13601 [Note] InnoDB: Completed initialization of buffer pool
2015-10-27 11:32:46 13601 [ERROR] InnoDB: ./ibdata1 can't be opened in read-write mode
2015-10-27 11:32:46 13601 [ERROR] InnoDB: The system tablespace must be writable!
2015-10-27 11:32:46 13601 [ERROR] Plugin 'InnoDB' init function returned error.
2015-10-27 11:32:46 13601 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2015-10-27 11:32:46 13601 [ERROR] Unknown/unsupported storage engine: InnoDB
2015-10-27 11:32:46 13601 [ERROR] AbortingThe above is another permission issue, this time the problem is related to ibdata1 file – shared system tablespace which is used for InnoDB to store its internal data (InnoDB dictionary and, by default, undo logs). Even if you use innodb_file_per_table, which is a default setting in MySQL 5.6, InnoDB still requires this file so it can intialize.
2015-10-27 11:35:21 17826 [Note] Plugin 'FEDERATED' is disabled.
/usr/sbin/mysqld: Can't find file: './mysql/plugin.frm' (errno: 13 - Permission denied)
2015-10-27 11:35:21 17826 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
2015-10-27 11:35:21 17826 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-10-27 11:35:21 17826 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-27 11:35:21 17826 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-27 11:35:21 17826 [Note] InnoDB: Memory barrier is not used
2015-10-27 11:35:21 17826 [Note] InnoDB: Compressed tables use zlib 1.2.8
2015-10-27 11:35:21 17826 [Note] InnoDB: Using Linux native AIO
2015-10-27 11:35:21 17826 [Note] InnoDB: Using CPU crc32 instructions
2015-10-27 11:35:21 17826 [Note] InnoDB: Initializing buffer pool, size = 512.0M
2015-10-27 11:35:21 17826 [Note] InnoDB: Completed initialization of buffer pool
2015-10-27 11:35:21 17826 [Note] InnoDB: Highest supported file format is Barracuda.
2015-10-27 11:35:21 7fa02e97d780 InnoDB: Operating system error number 13 in a file operation.
InnoDB: The error means mysqld does not have the access rights to
InnoDB: the directory.
2015-10-27 11:35:21 17826 [ERROR] InnoDB: Could not find a valid tablespace file for 'mysql/innodb_index_stats'. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2015-10-27 11:35:21 17826 [ERROR] InnoDB: Tablespace open failed for '"mysql"."innodb_index_stats"', ignored.
2015-10-27 11:35:21 7fa02e97d780 InnoDB: Operating system error number 13 in a file operation.
InnoDB: The error means mysqld does not have the access rights to
InnoDB: the directory.
2015-10-27 11:35:21 17826 [ERROR] InnoDB: Could not find a valid tablespace file for 'mysql/innodb_table_stats'. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2015-10-27 11:35:21 17826 [ERROR] InnoDB: Tablespace open failed for '"mysql"."innodb_table_stats"', ignored.
2015-10-27 11:35:21 7fa02e97d780 InnoDB: Operating system error number 13 in a file operation.
InnoDB: The error means mysqld does not have the access rights to
InnoDB: the directory.Here we have an example of permission issues related to system schema (‘mysql’ schema). As you can see, InnoDB reported it does not have access rights to open tables in this schema. Again, this is serious problem which is a hard stop for MySQL.
Out of memory errors
Another set of frequent issues related to MySQL servers running out of memory. It can manifest in many different ways but the most popular is this one:
Killed
151027 12:18:58 mysqld_safe Number of processes running now: 0mysqld_safe is an ‘angel’ process which monitors mysqld and restarts it when it dies. It’s true for MySQL but not for recent Galera nodes – in this case it won’t restart MySQL but you’ll see following sequence:
Killed
151027 12:18:58 mysqld_safe Number of processes running now: 0
151027 12:18:58 mysqld_safe WSREP: not restarting wsrep node automatically
151027 12:18:58 mysqld_safe mysqld from pid file /var/lib/mysql/mysql.pid endedAnother way memory issue may show up is through the following messages in the error log:
InnoDB: mmap(3145728 bytes) failed; errno 12
InnoDB: mmap(3145728 bytes) failed; errno 12What’s important to keep in mind is that error codes can easily be checked using ‘perror’ utility. In this case, it makes perfectly clear what exactly happened:
$ perror 12
OS error code 12: Cannot allocate memoryIf you suspect a memory problem or we’d even say – if you are encountering unexpected MySQL crashes, you can also run dmesg to get some more data. If you see output like below, you can be certain that the problem was caused by OOM Killer terminating MySQL:
[ 4165.802544] Out of memory: Kill process 8143 (mysqld) score 938 or sacrifice child
[ 4165.808329] Killed process 8143 (mysqld) total-vm:5101492kB, anon-rss:3789388kB, file-rss:0kB
[ 4166.226410] init: mysql main process (8143) killed by KILL signal
[ 4166.226437] init: mysql main process ended, respawningInnoDB crashes
InnoDB, most of the time, is a very solid and durable storage engine. Unfortunately, under some circumstances, data may become corrupted. Usually it’s related to either misconfiguration (for example, disabling double-write buffer) or some kind of faulty hardware (faulty memory modules, unstable I/O layer). In those cases it can happen that InnoDB will crash. Crashes can also be triggered by InnoDB bugs. It’s not common but it happens from time to time. No matter the reason of a crash, the error log usually looks in a similar way. Let’s go over a live example.
2015-10-13 15:08:06 7f53f0658700 InnoDB: Assertion failure in thread 139998492198656 in file btr0pcur.cc line 447
InnoDB: Failing assertion: btr_page_get_prev(next_page, mtr) == buf_block_get_page_no(btr_pcur_get_block(cursor))InnoDB code is full of sanity checks – assertions are very frequent and, if one of them fails, InnoDB intentionally crashes MySQL. At the beginning you’ll see information about exact location of the assertion which failed. This gives you information about what exactly may have happened – MySQL source code is available on the internet and it’s pretty easy to download code related to your particular version. It may sounds scary but it’s not – MySQL code is properly documented and it’s not a problem to figure out at least what kind of activity triggers your issue.
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.InnoDB logging tries to be as helpful as possible – as you can see, there’s information about InnoDB recovery process. Under some circumstances it may allow you to start MySQL and dump the InnoDB data. It’s used as “almost a last resort” – one step further and you’ll end up digging in InnoDB files using hex editor.
13:08:06 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/
key_buffer_size=67108864
read_buffer_size=131072
max_used_connections=36
max_threads=514
thread_count=27
connection_count=26
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 269997 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.In the next step you’ll see some of the status counters printed. It’s supposed to give you some idea about configuration – maybe you configured MySQL to use too much resources? Once you go over this data, we’ll reach the backtrace. This piece of information will guide you through the stack and show you what kind of calls were executed when crash happened. Let’s check what exactly happened in this particular case.
Thread pointer: 0xa985960
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f53f0657d40 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x8cd37c]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x6555a1]
/lib64/libpthread.so.0(+0xf710)[0x7f540f978710]
/lib64/libc.so.6(gsignal+0x35)[0x7f540dfd4625]
/lib64/libc.so.6(abort+0x175)[0x7f540dfd5e05]
/usr/sbin/mysqld[0xa0277b]
/usr/sbin/mysqld[0x567f88]
/usr/sbin/mysqld[0x99afde]
/usr/sbin/mysqld[0x8eb926]
/usr/sbin/mysqld(_ZN7handler11ha_rnd_nextEPh+0x5d)[0x59a6ed]
/usr/sbin/mysqld(_Z13rr_sequentialP11READ_RECORD+0x20)[0x800cd0]
/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyy+0xc88)[0x8128c8]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x1bc5)[0x6d6d15]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x5a8)[0x6dc228]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x108c)[0x6dda4c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x162)[0x6ab002]
/usr/sbin/mysqld(handle_one_connection+0x40)[0x6ab0f0]
/usr/sbin/mysqld(pfs_spawn_thread+0x143)[0xaddd73]
/lib64/libpthread.so.0(+0x79d1)[0x7f540f9709d1]
/lib64/libc.so.6(clone+0x6d)[0x7f540e08a8fd]We can see that problem was triggered when MySQL was executing a DELETE command. Records were read sequentially and full table scan was performed (handler read_rnd_next). Combined with information from the beginning:
InnoDB: Failing assertion: btr_page_get_prev(next_page, mtr) == buf_block_get_page_no(btr_pcur_get_block(cursor))we can tell the crash happened when InnoDB was performing a scan of the buffer pool (assertion was triggered in btr_pcur_move_to_next_page method).
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (a991d40): DELETE FROM cmon_stats WHERE cid = 2 AND ts < 1444482484
Connection ID (thread ID): 5
Status: NOT_KILLEDFinally, we can see (sometimes, it’s not always printed) which thread triggered the assertion. In our case we can confirm that indeed it was a DELETE query which caused some kind of problem.
You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
151013 15:08:06 mysqld_safe Number of processes running now: 0
As we said, usually MySQL is pretty verbose when it comes to the error log. Sometimes, though, things go so wrong that MySQL can’t really collect much of the information. It still gives a pretty clear indication that something went very wrong (signal 11). Please take a look at the following real life example:
22:31:40 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona XtraDB Cluster better by reporting any
bugs at https://bugs.launchpad.net/percona-xtradb-cluster
key_buffer_size=33554432
read_buffer_size=131072
max_used_connections=10
max_threads=202
thread_count=9
connection_count=7
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 113388 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x1fb7050
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
Segmentation fault (core dumped)
150119 23:48:08 mysqld_safe Number of processes running now: 0As you can see, we have clear information that MySQL crashed. There’s no additional information, though. Segmentation faults can also be logged in diagnostic messages. In this particular case dmesg returned:
[370591.200799] mysqld[5462]: segfault at 51 ip 00007fe624e3e688 sp 00007fe4f4099c30 error 4 in libgcc_s.so.1[7fe624e2f000+16000]It’s not much, as you can see, but such information can prove to be very useful if you decide to file a bug against the software provider, be it Oracle, MariaDB, Percona or Codership. It can also be helpful in finding relevant bugs already reported.
It’s not always possible to fix the problem based only on the information written in the error log. It’s definitely a good place to start debugging problems in your database, though. If you are hitting some kind of very common, simple misconfiguration, information you’d find in the error log should be enough to pinpoint a cause and find a solution. If we are talking about serious MySQL crashes, things are definitely different – most likely you won’t be able to fix the issue on your own (unless you are a developer familiar with MySQL code, that is) On the other hand, this data may be more than enough to identify the culprit and locate existing bug reports which cover it. Such bug reports contain lots of discussion and tips or workarounds – it’s likely that you’ll be able to implement one of them. Even information that the given bug was fixed in version x.y.z is useful – you’ll be able to verify it and, if it does solve your problem, to plan for upgrade. In the worst case scenario, you should have enough data to create a bug report on your own.
In the next post in the series, we are going to take a guided tour through the error log (and other logs) you may find in your Galera cluster. We’ll cover what kind of issues you may encounter and how to solve them.
