In MySQL QA Episode #12, “MySQL is Crashing, now what?,” Roel demonstrated how to collect crash-related information that will help Percona discover what the issue is that you are experiencing, and fix it.
As a Support Engineer I (Sveta) am very happy to see this post – but as a person who better understands writing than recording – I’d like to have same information, in textual form. We discussed it, and decided to do a joint blog post. Hence, this post
If you haven’t seen the video yet, or you do not have any experience with gdb, core files and crashes, I highly recommend to watch it first.
Once you have an idea of why crashes happen, what to do after it happens in your environment, and how to open a Support issue and/or a bug report, you’re ready for the next step: which information do you need to provide? Note that the more complete and comprehensive information you provide, the quicker the evaluation and potential fix process will go – it’s a win-win situation!
At first we need the MySQL error log file. If possible, please send us the full error log file. Often users like to send only the part which they think is relevant, but the error log file can contain other information, recorded before the crash happened. For example, records about table corruptions, lack of disk space, issues with InnoDB dictionary, etc.
If your error log is quite large, please note it would compress very well using a standard compression tool like gzip. If for some reason you cannot send the full error log file, please sent all lines, written after the words “mysqld: ready for connections” (as seen the last time before the actual crash), until the end of the error log file (alternatively, you can also search for rows, started with word “Version:”). Or, if you use scripts (or mysqld_safe) which automatically restart MySQL Server in case of disaster, obviously please search for the one-previous server start after the crash.
An example which includes an automatic restart as mentioned above:
2015-08-03 14:24:03 9911 [Note] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld: ready for connections. Version: '5.6.25-73.1-log' socket: '/tmp/mysql_sandbox21690.sock' port: 21690 Percona Server (GPL), Release 73.1, Revision 07b797f 2015-08-03 14:24:25 7f5b193f9700 InnoDB: Buffer pool(s) load completed at 150803 14:24:25 11:25:12 UTC - mysqld got signal 4 ; 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=268435456 read_buffer_size=131072 max_used_connections=1 max_threads=216 thread_count=1 connection_count=1 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 348059 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x0 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 = 0 thread_stack 0x40000 /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(my_print_stacktrace+0x2e)[0x8dd38e] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(handle_fatal_signal+0x491)[0x6a5dc1] /lib64/libpthread.so.0(+0xf890)[0x7f5c58ac8890] /lib64/libc.so.6(__poll+0x2d)[0x7f5c570fbc5d] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(_Z26handle_connections_socketsv+0x1c2)[0x5f64c2] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(_Z11mysqld_mainiPPc+0x1b5d)[0x5fd87d] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f5c57040b05] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld[0x5f10fd] 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. 150803 14:25:12 mysqld_safe Number of processes running now: 0 150803 14:25:12 mysqld_safe mysqld restarted /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld: /lib64/libssl.so.1.0.0: no version information available (required by /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld) /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld: /lib64/libcrypto.so.1.0.0: no version information available (required by /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld) 2015-08-03 14:25:12 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2015-08-03 14:25:12 0 [Note] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld (mysqld 5.6.25-73.1-log) starting as process 10038 ... 2015-08-03 14:25:12 10038 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 50005) 2015-08-03 14:25:12 10038 [Warning] Buffered warning: Changed limits: max_connections: 214 (requested 10000) 2015-08-03 14:25:12 10038 [Warning] Buffered warning: Changed limits: table_open_cache: 400 (requested 4096) 2015-08-03 14:25:12 10038 [Note] Plugin 'FEDERATED' is disabled. 2015-08-03 14:25:12 10038 [Note] InnoDB: Using atomics to ref count buffer pool pages 2015-08-03 14:25:12 10038 [Note] InnoDB: The InnoDB memory heap is disabled 2015-08-03 14:25:12 10038 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-08-03 14:25:12 10038 [Note] InnoDB: Memory barrier is not used 2015-08-03 14:25:12 10038 [Note] InnoDB: Compressed tables use zlib 1.2.3 2015-08-03 14:25:12 10038 [Note] InnoDB: Using Linux native AIO 2015-08-03 14:25:12 10038 [Note] InnoDB: Using CPU crc32 instructions 2015-08-03 14:25:12 10038 [Note] InnoDB: Initializing buffer pool, size = 4.0G 2015-08-03 14:25:13 10038 [Note] InnoDB: Completed initialization of buffer pool 2015-08-03 14:25:13 10038 [Note] InnoDB: Highest supported file format is Barracuda. 2015-08-03 14:25:13 10038 [Note] InnoDB: The log sequence numbers 514865622 and 514865622 in ibdata files do not match the log sequence number 514865742 in the ib_logfiles! 2015-08-03 14:25:13 10038 [Note] InnoDB: Database was not shutdown normally! 2015-08-03 14:25:13 10038 [Note] InnoDB: Starting crash recovery. 2015-08-03 14:25:13 10038 [Note] InnoDB: Reading tablespace information from the .ibd files... 2015-08-03 14:25:14 10038 [Note] InnoDB: Restoring possible half-written data pages 2015-08-03 14:25:14 10038 [Note] InnoDB: from the doublewrite buffer... InnoDB: Last MySQL binlog file position 0 150866, file name mysql-bin.000006 2015-08-03 14:25:16 10038 [Note] InnoDB: 128 rollback segment(s) are active. 2015-08-03 14:25:16 10038 [Note] InnoDB: Waiting for purge to start 2015-08-03 14:25:16 10038 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.25-rel73.1 started; log sequence number 514865742 2015-08-03 14:25:16 7f67ceff9700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool 2015-08-03 14:25:16 10038 [Note] Recovering after a crash using mysql-bin 2015-08-03 14:25:16 10038 [Note] Starting crash recovery... 2015-08-03 14:25:16 10038 [Note] Crash recovery finished. 2015-08-03 14:25:17 10038 [Note] RSA private key file not found: /home/sveta/sandboxes/rsandbox_Percona-Server-5_6_25/master/data//private_key.pem. Some authentication plugins will not work. 2015-08-03 14:25:17 10038 [Note] RSA public key file not found: /home/sveta/sandboxes/rsandbox_Percona-Server-5_6_25/master/data//public_key.pem. Some authentication plugins will not work. 2015-08-03 14:25:17 10038 [Note] Server hostname (bind-address): '127.0.0.1'; port: 21690 2015-08-03 14:25:17 10038 [Note] - '127.0.0.1' resolves to '127.0.0.1'; 2015-08-03 14:25:17 10038 [Note] Server socket created on IP: '127.0.0.1'. 2015-08-03 14:25:17 10038 [Warning] 'proxies_priv' entry '@ root@thinkie' ignored in --skip-name-resolve mode. 2015-08-03 14:25:17 10038 [Note] Event Scheduler: Loaded 0 events 2015-08-03 14:25:17 10038 [Note] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld: ready for connections. Version: '5.6.25-73.1-log' socket: '/tmp/mysql_sandbox21690.sock' port: 21690 Percona Server (GPL), Release 73.1, Revision 07b797f
Usually the error log file contains the actual query which caused the crash. If it does not and you know the query (for example, if your application logs errors / query problems), please send us this query too. Additionally, if possible, include the CREATE TABLE statements for any tables mentioned in the query. Actually working with the query is the first thing which you can do to resolve the issue: try to run this query (on a non-production/test server which is as close a copy to your production server as possible), to ensure it crashes MySQL Server consistently. If so, you can try and create a temporary workaround by avoiding this kind of queries in your application.
If you have doubts as to which query caused the crash, but have the general query log turned ON, you can use utility
parse_general_log.pl
from percona-qa to create a potential test case. Simply execute:
$ sudo yum install bzr $ cd ~ $ bzr branch lp:percona-qa $ cp /path_that_contains_your_general_log/your_log_file.sql ~ $ ~/percona-qa/parse_general_log.pl -i./your_log_file.sql -o./output.sql
And subsequently execute output.sql against mysqld on a non-production test server to see if a crash is produced. Alternatively, you may mail us the output.sql file (provided your company privacy etc. policies allow for this). If you want to try and reduce the testcase further, please see QA Episode #7 on reducing testcases.
The next thing which we need is a backtrace. You usually have a simple backtrace showing in the error log directly after crash. An example (extracted from an error log) of what this looks like:
stack_bottom = 0 thread_stack 0x40000 /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(my_print_stacktrace+0x2e)[0x8dd38e] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(handle_fatal_signal+0x491)[0x6a5dc1] /lib64/libpthread.so.0(+0xf890)[0x7f5c58ac8890] /lib64/libc.so.6(__poll+0x2d)[0x7f5c570fbc5d] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(_Z26handle_connections_socketsv+0x1c2)[0x5f64c2] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(_Z11mysqld_mainiPPc+0x1b5d)[0x5fd87d] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f5c57040b05] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld[0x5f10fd]
Note that the above backtrace is mangled. You can send us the file like this (we can demangle it). However, if you want to work with it yourself more comfortably you can unmangle it with help of
c++filt
utility:
sveta@linux-85fm:~/sandboxes/rsandbox_Percona-Server-5_6_25> cat master/data/msandbox.err | c++filt ... terribly wrong... stack_bottom = 0 thread_stack 0x40000 /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(my_print_stacktrace+0x2e)[0x8dd38e] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(handle_fatal_signal+0x491)[0x6a5dc1] /lib64/libpthread.so.0(+0xf890)[0x7f5c58ac8890] /lib64/libc.so.6(__poll+0x2d)[0x7f5c570fbc5d] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(handle_connections_sockets()+0x1c2)[0x5f64c2] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld(mysqld_main(int, char**)+0x1b5d)[0x5fd87d] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f5c57040b05] /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld[0x5f10fd] ...
Now the backtrace looks much nicer. When sending error log reports to us, please to not use
c++filt
on them before sending. We have a list of known bugs, and to scan the known bugs list we need to receive the error log unaltered.
You can also turn core files ON. Core files are memory dump files, created when a process crashes. They are very helpful for debugging, because they contain not only the backtrace of crashing thread, but backtraces of all threads, and much of what was in memory at the time the crash occurred.
Sidenote: Please note it is always a good idea to have the debuginfo (for example Percona-Server-56-debuginfo.x86_64 from the Percona Repository) package installed. This package provides the debugging symbols for Percona server (there are similar packages for other distributions) and ensures that stack traces are more readable and contain more information. It is important to ensure that you have the right package version etc. as symbols are different for each version of mysqld. If you have installed Percona Server from our repository, you can simply install the debuginfo package, the version will be correct, and the package will be auto-updated when Percona Server is updated.
By default the MySQL server does not create core files. To let it do so, you can follow instructions from the “GDB Cheat sheet” (page 2 under header ‘Core Files Cheat Sheet’). In short:
- Add the option core-file under the [mysqld] section of your configuration file
- Tune your OS options, so it allows mysqld to create core files as described in the cheat sheet
echo "core.%p.%e.%s" > /proc/sys/kernel/core_pattern ulimit -c unlimited sudo sysctl -w fs.suid_dumpable=2
Note: some systems use ‘kernel’ instead of ‘fs’: use kernel.suid_dumpable=2 instead if you get key or file warnings/errors. - Restart the MySQL server
Besides the core file which is generated by the MySQL server, you can also setup the operating system to dump a core file. These are two different core files (for a single crash of the mysqld binary), and the amount of information contained within may differ. The procedure above shows how to setup the one for the MySQL Server alone.
If you like your operating system to dump a core file as well, please see the MySQL QA Episode #12 video. Also, please note that changing the ulimit and fs.suid_dumpable settings may alter the security of your system. Please read more about these options online before using them or leaving them permanently on a production system.
Once a core file is generated, you can use the GDB utility to debug the core file (also called a ‘coredump’). GDB allows you to better resolve backtraces (also called ‘stack traces’ or ‘stacks’), for example by taking a back trace of all threads instead of only the crashing threads. This is off-course better then the single backtrace available in the error log file. To use GDB, you need to first start it:
gdb /path_to_mysqld /path_to_core
/path_to_core is usually your data directory (for coredumps produced by mysqld as a result of using the –core-file option in your my.cnf file), or sometimes in the same directory where the crashing binary is (for coredumps produced by the OS) – though you can specify an alternate fixed location for OS coredumps as the cheat sheet. Note that OS generated dumps are sometimes written with very few privileges and so you may have to use chown/chmod/sudo to access it.
Once you’re into GDB, and all looks fine, run the commands
bt
(backtrace) and
bt thread apply all
(get backtrace for all threads) to get the stacktraces. bt should more or less match the backtrace seen in the error log, but sometimes this may differ.
For us, ideally you would run the following commands in GDB (as seen in the cheat sheet):
set trace-commands on set pagination off set print pretty on set print array on set print array-indexes on set print elements 4096 set logging file gdb_standard.txt set logging on thread apply all bt set logging off set logging file gdb_full.txt set logging on thread apply all bt full
After you run these commands and have existed ( quit ) GDB, please send us the
./gdb_standard.txt
and
./gdb_full.txt
files.
Finally, we would be happy to receive the actual core file from you. In terms of security and privacy, please note that a core file often contains fragments, or sections, or even the full memory of your server.
However, a core file without mysqld is useless, thus please add the mysqld binary together with the core file. If you use our compiled binaries you can also specify the exact package and file name which you downloaded, but if you use a self-compiled version of the server, the mysqld binary is required for us to resolve backtrace and other necessary information (like varialbes) from your core file. Generally speaking, it’s easier just to sent mysqld along.
Also, it would be really nice, if you send us library files which are dynamically linked with mysqld you use. You can get them by using a tool, called
ldd_files.sh
from the percona-qa suite. Just create a temporary directory, copy your
mysqld
binary to it and run the tool on it:
sveta@thinkie:~/tmp> wget http://bazaar.launchpad.net/~percona-core/percona-qa/trunk/download/head:/ldd_files.sh-20150713030145-8xdk0llrd3skfsan-1/ldd_files.sh sveta@thinkie:~/tmp> mkdir tmp sveta@thinkie:~/tmp> cd tmp/ sveta@thinkie:~/tmp/tmp> cp /home/sveta/SharedData/Downloads/5.6.25/bin/mysqld . # Copy of your mysqld sveta@thinkie:~/tmp/tmp> ../ldd_files.sh mysqld # Run the tool on it cp: cannot stat ‘./mysqld: /lib64/libssl.so.1.0.0: no version information available’: No such file or directory # Ignore cp: cannot stat ‘./mysqld: /lib64/libcrypto.so.1.0.0: no version information available’: No such file or directory # Ignore sveta@thinkie:~/tmp/tmp> ls ld-linux-x86-64.so.2 libaio.so.1 libcrypto.so.1.0.0 libcrypt.so.1 libc.so.6 libdl.so.2 libgcc_s.so.1 libm.so.6 libpthread.so.0 librt.so.1 libssl.so.1.0.0 libstdc++.so.6 libz.so.1 mysqld # Files to supply in combination with mysqld
These library files are needed if case some of the frames from the stacktrace are system calls, so that our developers can resolve/check those frames also.
Summary
If you hit a crash, please send us (in order of preference, but even better ‘all of these’):
- The error log file (please sent it unaltered – i.e. before c++filt was executed – which allows us to scan for known bugs)
- The crashing query (from your application logs and/or extracted from the core file – ref the query extraction blog post)
- Please include the matching CREATE TABLE statements
- A resolved backtrace (and/or preferably the ./gdb_standard.txt and ./gdb_full.txt files)
- The core file together with the mysqld binary and preferably the ldd files
Thank you!
The post MySQL is crashing: a support engineer’s point of view appeared first on MySQL Performance Blog.
