Story of a MySQL crash (memory issue)

Today we faced an important issue with MySQL 5.5
Server stalled after aborting a TRUNCATE on a big table. Yes, this is bad to abort a TRUNCATE 😉 But this is not the issue I want to speak about. Server crashed, that’s a point. mysqld process restarted automatically, and started loading data into memory (massive use of InnoDB tables). This server has 128GB of memory, so buffer pool was set to 100GB (yes, that’s quite huge). Data set is ~ 100GB. After a few minutes, server crashed again, but this time complaining about memory.

Error log gave this :
*** glibc detected *** /usr/sbin/mysqld-5.5: malloc(): memory corruption: 0x00007f5ffc9affa0 ***
======= Backtrace: =========
/lib64/libc.so.6[0x7f7a46163e96]
/lib64/libc.so.6[0x7f7a46166b4e]
[...]
08:45:24 UTC - mysqld got signal 6 ;

The biggest problem is that this behaviour happened three times in a row. As it needs ~ 30 minutes to warm buffer pool, this was quite a downtime.

Memory usage looked like this (pink is pagecache) :
Memory usage

And dmesg reported this :

[28524726.820222] INFO: rcu_bh detected stall on CPU 32 (t=0 jiffies)
[28524726.820230] Pid: 53878, comm: mysqld-5.5 Not tainted 3.2.0-oxeva #8
[28524726.820237] Call Trace:
[28524726.820244] [] __rcu_pending+0x89/0x35b
[28524726.820285] [] rcu_check_callbacks+0xef/0x110
[28524726.820301] [] update_process_times+0x41/0x77
[28524726.820314] [] tick_sched_timer+0x6f/0x98
[28524726.820329] [] __run_hrtimer+0x95/0x120
[28524726.820337] [] ? tick_nohz_handler+0xd8/0xd8
[28524726.820341] [] hrtimer_interrupt+0xda/0x1a4
[28524726.820350] [] smp_apic_timer_interrupt+0x7e/0x91
[28524726.820365] [] apic_timer_interrupt+0x6b/0x70
[28524726.820367]

So RCU seems the one responsible for killing mysqld.

What is RCU ?
Let’s explain this in a few words : when you deallocate memory, the memory is not released immediately but marked as « can be deallocated ». The deallocation itself is asynchronous and handled by RCU.
(Well, this is a big shortcut, but if you’re interested, you can have full explanation here : http://www.rdrop.com/users/paulmck/RCU/whatisRCU.html)

So, what is happening here ?
When we have allocated all the memory (user space + page cache), and Mysql makes a malloc() to ask for more, kernel is faced to a dilemma : he has allocated 100%, but he knows some memory can be reclaimed. This is RCU job, but deallocation takes time, and malloc() needs to have an answer fast. This is a zone of undefined behaviour, and in our case, this results to a corruption with malloc() call (and mysqld crashed).

How can we fix this ?
As we have a majority of InnoDB tables, page cache is not very useful (innodb handles cache itself). So we can disable it by opening files with flag O_DIRECT.
This is handled with mysql variable innodb_flush_method

We launch mysql again with this variable set to O_DIRECT, and result is OK :
Memory usage after
See ? No more pagecache used, and plenty of memory available.

We did not use O_DIRECT before because of incompatibilities with NFS, but this has been fixed since.

Laisser un commentaire

Votre adresse e-mail ne sera pas publiée. Les champs obligatoires sont indiqués avec *