Bug #18467 memlock causes to MySQL crash
Submitted: 23 Mar 2006 18:56 Modified: 18 Nov 2006 10:20
Reporter: Kayra Otaner Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.0.19 OS:Linux (Rhel4 Update 1)
Assigned to: CPU Architecture:Any

[23 Mar 2006 18:56] Kayra Otaner
Description:
We've been using MySQL 5.0.18 for long time with 'memlock' option enabled on several boxes. I did download and install 5.0.19 2 days ago and upgraded existing MySQL on one box by using rpms. When upgade finished, MySQL starts restarting itself by saying :

Number of processes running now: 0
060323 18:49:02  mysqld restarted
060323 18:49:03  InnoDB: Started; log sequence number 45 700500691
060323 18:49:03 [Note] Recovering after a crash using tope-bin
060323 18:49:03 [Note] Starting crash recovery...
060323 18:49:03 [Note] Crash recovery finished.

Number of processes running now: 0
060323 18:49:06  mysqld restarted
060323 18:49:07  InnoDB: Started; log sequence number 45 700500691
060323 18:49:07 [Note] Recovering after a crash using tope-bin
060323 18:49:07 [Note] Starting crash recovery...
060323 18:49:07 [Note] Crash recovery finished.

and goes into a loop. I've rolled back to 5.0.18 on that box. Today I'm installing it to 2 different boxes and it does the same. I've spend some time and noticed that when I comment memlock out, 5.0.19 works fine. But when I put it back, MySQL keeps restarting and no client can connect to it.

These boxes are clean and as I've said, we've been using them with 5.0.18 for 2 months no problem.

How to repeat:
Add 'memlock' to my.cnf and restart MySQL.

Number of processes running now: 0
060323 18:49:06  mysqld restarted
060323 18:49:07  InnoDB: Started; log sequence number 45 700500691
060323 18:49:07 [Note] Recovering after a crash using tope-bin
060323 18:49:07 [Note] Starting crash recovery...
060323 18:49:07 [Note] Crash recovery finished.
[23 Mar 2006 21:08] Hartmut Holzgraefe
couldn't reproduce this with 5.0.19 (self compiled, SuSE 9.3)

can you provide the following additional information?

- the exact binary download package you are using
- your my.cnf file
- the ammount of memory and swap available on your system
[23 Mar 2006 21:27] Kayra Otaner
Here is the package we're using :
MySQL-server-standard-5.0.19-0.rhel4.i386.rpm

I've downloaded this from your web site. Box has 4G ram and 4G swap. I'm also uploading my.cnf through this interface as a separate file.
[24 Mar 2006 10:20] Valeriy Kravchuk
Please, send the results of 'top' Linux command before starting MySQL server.

I found two suspicious values in your my.cnf:

myisam_sort_buffer_size = 128M

(it is allocated per thread, and is really large in your case), and:

innodb_buffer_pool_size = 1900M

So, maybe, memlock option is not ignored by 5.0.19 on Linux now, thus the result...
[24 Mar 2006 16:39] Kayra Otaner
Here is first couple lines from top :

top - 16:36:18 up 108 days, 22:42,  2 users,  load average: 0.42, 0.40, 0.31
Tasks:  70 total,   1 running,  69 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0% us,  0.1% sy,  0.0% ni, 99.9% id,  0.0% wa,  0.0% hi,  0.0% si
Mem:   4147260k total,  2121888k used,  2025372k free,    53252k buffers
Swap:  2040244k total,      252k used,  2039992k free,  2002268k cached

This is the fourth box I'm observing same problem. This one has 4G ram + 2 G swap while first one I submitted has 4G swap.  I've reduced all MyISAM related buffers to lower values, including myisam_sort_buffer_size. Now I have :

myisam_sort_buffer_size = 8M

and same problem happens. Please note, same exact my.cnf was fine with memlock enabled with 5.0.18 but 5.0.19 is refusing to start with memlock on.

Kayra Otaner
[24 Mar 2006 16:45] Kayra Otaner
One small thing I forgot to add : 
I've reduced innodb buffer to :
innodb_buffer_pool_size = 1600M
and still experiencing same problem. 
About linux kernels : One box has hugemem kernel with 3/1G memory split, all others are standard 2/2G kernels. I can observe same problem on all of them.
[27 Apr 2006 11:17] Valeriy Kravchuk
Please,try to repeat with a newer version, 5.0.20a, and inform about the results.
[27 May 2006 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[17 Nov 2006 2:01] Andrew Houghton
I can confirm this is still an issue.  Running RHES 4 update 4 on a SunFire X4100; portion of uname:

2.6.9-42.0.3.ELsmp #1 SMP Mon Sep 25 17:24:31 EDT 2006 x86_64 x86_64 x86_64 GNU/Linux

Confirmed on both 5.0.24a-0 and 5.0.27.  In both cases, commenting out "memlock" in my.cnf allowed the server to start.  With memlock in, the server continually restarts with no useful error output:

Number of processes running now: 0
061116 17:43:35  mysqld restarted
061116 17:43:36  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
061116 17:43:36  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 43656.
InnoDB: Doing recovery: scanned up to log sequence number 0 43656
061116 17:43:36  InnoDB: Started; log sequence number 0 43656
061116 17:43:36 [Note] Recovering after a crash using /var/lib/mysql-logs/mdb-bin
061116 17:43:36 [Note] Starting crash recovery...
061116 17:43:36 [Note] Crash recovery finished.

repeat forever, etc.
[17 Nov 2006 6:42] Andrew Houghton
I should have said, using stock RPMs:

[root@helen lib]# mysql --versionmysql  Ver 14.12 Distrib 5.0.27, for unknown-linux-gnu (x86_64) using readline 5.0

Also, I can supply an strace file (not the whole thing, I attached somewhere in the middle of the initial startup -- most of the trace is filling the innodb data files).
[17 Nov 2006 7:20] Hartmut Holzgraefe
reopened due to comment in http://bugs.mysql.com/bug.php?id=24383
[18 Nov 2006 10:20] Sergei Golubchik
It's a duplicate of BUG#22860
[2 Jun 2007 11:35] George Barnett
I'm experiencing the same issue on RHEL4U4 using both the stock RPM's of 5.0.41 and the Intel compiled binaries.

Linux prdpctmammoth01.prd.lastminute.com 2.6.9-55.ELsmp #1 SMP Fri Apr 20 16:36:54 EDT 2007 x86_64 x86_64 x86_64 GNU/Linux
[30 Sep 2007 7:51] Kevin Burton
Could someone expand on why this is unstable?  Does it fail at runtime hours after the mysqld is running or does it just fail on startup?

I tested memlock on 4.0.22 on Debian Etch 2.6.18 and everything SEEMS to be stable.

If someone could not WHICH versions are having a problem this would help a LOT.
[30 Sep 2007 9:58] George Barnett
It happens at startup.  Given your post about this setting working fine on debian64, this may be confined to rhel.  I dont have access to another 64bit box to test this theory since the boxes I had used are in production now.
[30 Sep 2007 14:16] Sergei Golubchik
Two most common cases:

1. MySQL crashing on startup, in all (six?) cases it's 2.6.9 SMP kernel (and where the vendor was specified it was RedHat). Often x86_64, but not always.

2. MySQL crashes later, not a bug, it's killed by the kernel when the memory is exhausted.