There are times where you need to know exactly how much memory the mysqld server (or any other program) is using, where (i.e. for what function) it was allocated, how it got there (a backtrace, please!), and at what point in time the allocation happened.
For example; you may have noticed a sharp memory increase after executing a particular query. Or, maybe mysqld is seemingly using too much memory overall. Or again, maybe you noticed mysqld’s memory profile slowly growing overtime, indicating a possible memory bug.
Whatever the reason, there is a simple but powerful way to profile MySQL memory usage; the Massif tool from Valgrind. An excerpt from the Massif manual page (Heap memory being simply the allotted pool of memory for use by programs);
Massif tells you not only how much heap memory your program is using, it also gives very detailed information that indicates which parts of your program are responsible for allocating the heap memory.
Firstly, we need to get the Valgrind program. Though you could use the latest version which comes with your OS (think yum or apt-get install Valgrind), I prefer to obtain & compile the latest release (3.8.1 at the moment):
|
1 |
sudo yum remove valgrind* # or apt-get etc.<br>sudo yum install wget make gcc gcc-c++ libtool libaio-devel bzip2 glibc*<br>wget http://valgrind.org/downloads/valgrind-3.8.1.tar.bz2 # Or newer<br>tar -xf valgrind-3.8.1.tar.bz2<br>cd valgrind-3.8.1<br>./configure<br>make<br>sudo make install<br>valgrind --version # check version to be same as what was downloaded (3.8.1 here) |
There are several advantages to self-compiling:
Once ‘valgrind –version’ returns the correct installed version, you’re ready to go. In this example, we’ll write the output to /tmp/massif.out. If you prefer to use another location (and are therefore bound to set proper file rights etc.) use:
|
1 |
$ touch /your_location/massif.out<br>$ chown user:group /your_location/massif.out # Use the user mysqld will now run under (check 'user' setting in my.cnf also) (see <a title="Changing MySQL User" href="http://dev.mysql.com/doc/refman/5.5/en/changing-mysql-user.html" target="_blank" rel="noopener noreferrer">here</a> if this is not clear) |
Now, before you run mysqld under Valgrind, make sure debug symbols are present. Debug symbols are present when the binary is not stripped of them (downloaded ‘GA’ [generally available] packages may contain optimized or stripped binaries, which are optimized for speed rather than debugging). If the binaries you have are stripped, you have a few options to get a debug build of mysqld to use for memory profiling purposes:
Valgrind Massif needs the debug symbol information to be present, so that it can print stack traces that show where memory is consumed. Without debug symbols available, you would not be able to see the actual function call responsible for memory usage. If you’re not sure if you have stripped binaries, simply test the procedure below and see what output you get.
Once you’re all set with debug symbols, shutdown your mysqld server using your standard shutdown procedure, and then re-start it manually under Valgrind using the Massif tool:
|
1 |
$ valgrind --tool=massif --massif-out-file=/tmp/massif.out /path/to/mysqld {mysqld options...} |
Note that ‘{mysqld options}’ could for instance include –default-file=/etc/my.cnf (if this is where your my.cnf file is located) in order to point mysqld to your settings file etc. After mysqld is properly started (check if you can login with your mysql client), you would execute whatever steps you think are necessary to increase memory usage/trigger the memory problem. You could also just leave the server running for some time (for example, if you have experienced memory increase over time).
Once you’ve done that, shutdown mysqld (again using your normal shutdown procedure), and then use the ms_print tool on the masif.out file to output a textual graph of memory usage:
|
1 |
ms_print /tmp/massif.out |
An partial example output from a recent customer problem we worked on:
|
1 |
96.51% (<strong>68,180,839B</strong>) (<strong>heap allocation functions</strong>) malloc/new/new[], --alloc-fns, etc.<br> -><strong>50.57%</strong> (<strong>35,728,995B</strong>) 0x7A3CB0: <strong>my_malloc</strong> (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br> | -><strong>10.10%</strong> (<strong>7,135,744B</strong>) 0x7255BB: <strong>Log_event::read_log_event</strong>(char const*, unsigned int, char const**, Format_description_log_event const*) (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br> | | ->10.10% (7,135,744B) 0x728DAA: Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*) (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br> | | ->10.10% (7,135,744B) 0x5300A8: ??? (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br> | | | ->10.10% (7,135,744B) 0x5316EC: handle_slave_sql (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br> | | | ->10.10% (7,135,744B) 0x3ECF60677B: start_thread (in /lib64/libpthread-2.5.so)<br> | | | ->10.10% (7,135,744B) 0x3ECEAD325B: clone (in /lib64/libc-2.5.so)<br> [...] |
And, a few snapshots later:
|
1 |
92.81% (<strong>381,901,760B</strong>) (<strong>heap allocation functions</strong>) malloc/new/new[], --alloc-fns, etc.<br>-><strong>84.91%</strong> (<strong>349,404,796B</strong>) 0x7A3CB0: <strong>my_malloc</strong> (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br>| -><strong>27.73%</strong> (<strong>114,084,096B</strong>) 0x7255BB: <strong>Log_event::read_log_event</strong>(char const*, unsigned int, char const**, Format_description_log_event const*) (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br>| | ->27.73% (114,084,096B) 0x728DAA: Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*) (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br>| | ->27.73% (114,084,096B) 0x5300A8: ??? (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br>| | | ->27.73% (114,084,096B) 0x5316EC: handle_slave_sql (in /usr/local/percona/mysql-5.5.28/usr/sbin/mysqld)<br>| | | ->27.73% (114,084,096B) 0x3ECF60677B: start_thread (in /lib64/libpthread-2.5.so)<br>| | | ->27.73% (114,084,096B) 0x3ECEAD325B: clone (in /lib64/libc-2.5.so) |
As you can see, a fair amount of (and in this case ‘too much’) memory is being allocated to the Log_event::read_log_event function. You can also see the memory allocated to the function grow significantly accross the snapshots. This example helped to pin down a memory leak bug on a filtered slave (read more in the actual bug report).
Besides running Valgrind Massif in the way above, you can also change Massif’s snapshot options and other cmd line options to match the snapshot frequency etc. to your specific requirements. However, you’ll likely find that the default options will perform well in most scenario’s.
For the technically advanced, you can take things one step further: use Valgrind’s gdbserver to obtain Massif snapshots on demand (i.e. you can command-line initiate Massif snapshots just before, during and after executing any commands which may alter memory usage significantly).
Conclusion: using Valgrind Massif, and potentially Valgrind’s gdbserver (which was not used in the resolution of the example bug discussed), will help you to analyze the ins and outs of mysqld’s (or any other programs) memory usage.
Credits: Staff @ a Percona customer, Ovais, Laurynas, Sergei, George, Vladislav, Raghavendra, Ignacio, myself & others at Percona all combined efforts leading to the information you can read above.
Resources
RELATED POSTS