MySQL Bugs: #37642: Mysql Crash Suddently

Bug #37642	Mysql Crash Suddently
Submitted:	25 Jun 2008 19:31	Modified:	6 Aug 2008 10:17
Reporter:	Julien CHAMPSEIX	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: MyISAM storage engine	Severity:	S1 (Critical)
Version:	mysql Ver 14.12 Distrib 5.0.51a, for re	OS:	Linux (Ubuntu Hardy 64 Bits)
Assigned to:		CPU Architecture:	Any
Tags:	crash, shutdown

Description:
My hardware settings: 

2 * Quad Core Intel(R) Xeon(R) CPU X7350 2.93GHz 
32Go RAM

My distro settings: 

Distro: Ubuntu Hardy 64 bits 
Kernel: 2.6.24-16-server #1 SMP x86_64 GNU/Linux 

My settings into my.cnf: 

[mysqld] 
log-bin 
replicate-ignore-db=mysql 

server-id = 52001001 
set-variable = max_connections=2500 
set-variable = back_log=20 
set-variable = key_buffer=8000M 
set-variable = table_cache=350 
set-variable = max_allowed_packet=4M 
set-variable = sort_buffer=2M 
set-variable = record_buffer=4M 
set-variable = myisam_sort_buffer_size=64M 
set-variable = thread_cache=50 
set-variable = long_query_time=10 
set-variable = query_cache_size=256M 
set_variable = wait_timeout=60 
#set_variable = wait_timeout=600 
skip-innodb 

log-bin = /var/lib/mysql/DB-new-bin 

log-slow-queries = /var/lib/mysql/slow.log 
skip-name-resolve 
tmpdir = /var/lib/mysql/tmp 

datadir=/var/lib/mysql 
socket=/var/lib/mysql/mysql.sock 

old_passwords=1 

[mysql.server] 
user=mysql 

[mysqld_safe] 
log-error=/var/log/mysqld.log 
log=/var/log/mysqld.log 
pid-file=/var/run/mysqld/mysqld.pid 

The log generated by the crash: 

080623 11:17:52 - 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. 

key_buffer_size=8388608000 
read_buffer_size=4190208 
max_used_connections=445 
max_connections=2500 
threads_connected=437 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 23541980 K 
bytes of memory 
Hope that's ok; if not, decrease some variables in the equation. 

thd=0x7fe37865e280 
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... 
Cannot determine thread, fp=0x4135b098, backtrace may not be correct. 
Stack range sanity check OK, backtrace follows: 
(nil) 
Stack trace seems successful - bottom reached 
Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved 
stack trace is much more helpful in diagnosing the problem, so please do 
resolve it 
Trying to get some variables. 
Some pointers may be invalid and cause the dump to abort... 
thd->query at 0x7fe37020f3b0 is invalid pointer 
thd->thread_id=2439729 
The manual page at http://www.mysql.com/doc/en/Crashing.html contains 
information that should help you find out what is causing the crash. 
-e 
Number of processes running now: 0 

How to repeat:
Dont arrive to reproduce it manually.

Important information:

this server mysql is a slave (based into a distro 64 bits) whereas the master is using distro 32 Bits Fedora Core realese 6.

Thank you for the report.

There is not much information in the error log file as no backtrace, because of invalid pointers. Only one thing which can matters is estimated size of RAM allocated which is 22GB. I hope it is OK with your 32GB RAM.

To find what is wrong could you please use debug binary, enable core files and upload us core file created next time server crashes?

More information:

1. This is a dedicated database server. MySQL is the only application running. So 22GB leaves 10GB free for the O/S, even if we were using all 2500 connections (which we aren't - in fact a max of 445 are used).

2. This same error is happening regularly on another similar server. We are seeing it approximately once a week.

3. Both servers are operating as replication slaves to a heavily loaded master. The master typically receives 500,000 write updates per hour.

Thank you for the feedback.

Debug binary should be in same bin directory where mysqld is located. Its name is mysqld-debug. For how-to enable core files please consult ulimit and your operating system manual. Most likely you just should run `ulimit -c unlimited`

I installed the debug binary package MySQL-debuginfo-5.0.51a-0.glibc23

But when i'm trying to launch command mysql-debug, i got this error :

[root@db mysql]# mysqld-debug
080626 16:25:16 [ERROR] Fatal error: Please read "Security" section of the manual to find out how to run mysqld as root!

080626 16:25:16 [ERROR] Aborting

080626 16:25:16 [Note] mysqld-debug: Shutdown complete

I tested too the option debug (by this line debug=/var/lib/mysql/debug.log) in /etc/my.cnf but i saw in mysqld.log this option is invalid.

Strange because i saw this option:

-#, --debug[=name]  Debug log.

by the following command: 

mysqld-debug --verbose --help | more

Any idea for launch mysqld-debug command ?

Thank you for the feedback.

Please read at http://dev.mysql.com/doc/refman/5.0/en/changing-mysql-user.html about how to change user mysqld is running as. Also you should specify option --core-file to get core, not --debug.

I'll apply the new setting with the new option core-file in file /etc/my.cnf by restart mysql server and i'll apply "ulimit -c unlimited" tomorrow and i'll see if we'll have more information about this crash bug.

Thanks in advance.

We will wait data from you.

I have two questions:

1) how did you install MySQL? I mean, did you just use the Ubuntu packages or did you use our source that you can download from http://dev.mysql.com/downloads/

2) I need output from the owner of your mysqld ... default this is user mysql:

$ ulimit -a

I need the output of open files here.

* MySQL installed from mysql source http://dev.mysql.com/downloads/

* i applied ulimit -c unlimited

* mysql server running currently with the default user :

[mysql.server] 
user=mysql

Output:

root@b2db09:~# ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 278528
max locked memory       (kbytes, -l) 32
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 278528
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

max_connections=2500 
open files                      (-n) 1024

1024 is less then 2500.

The open files always have to be more then the max_cennections.

Please try to set your open files to a hire value. Or set max_connection to less then 1024.

Change done :

root@b2db09:~# ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 278528
max locked memory       (kbytes, -l) 32
max memory size         (kbytes, -m) unlimited
open files                      (-n) 2500
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 278528
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

FYI i dont think the problem come from this point because an the other server 64bits where we have the same problem, we have an max_connection to 500 whereas the open files = 1024.

Following link i used for install :

http://dev.mysql.com/get/Downloads/MySQL-5.0/MySQL-server-5.0.51a-0.glibc23.x86_64.rpm/fro...

does key_buffer_size > 4GB work reliably in 5.0.51 ? That change was only added to 5-0-56sp1 afaik.

When that will be added into version 5.0.51 ? is there a bug fix planned ? its a really big problem for work with a big setting.

As you can see in the documentation it will get into next release.

http://dev.mysql.com/doc/refman/5.0/en/server-system-variables.html

"The maximum allowable setting for key_buffer_size is 4GB on 32-bit platforms. As of MySQL 5.0.52, values larger than 4GB are allowed for 64-bit platforms (except 64-bit Windows, for which large values are truncated to 4GB with a warning)"

Where can we find this package 5.0.52 cuz in the follwoing URL http://dev.mysql.com/downloads/mysql/5.0.html i didnt see it.

Or is there a patch in order to test it in order to be sure this bug is due the option key_buffer_size ?

There is no community version 5.0.52.

The comment at the documentation means, that it will be in version 5.0.52 and higher. So it will be in the next community that we will release.

The server crashed again and witht he debug mode we have those information:

080702 17:27:33 - 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.

key_buffer_size=8388608000
read_buffer_size=4190208
max_used_connections=385
max_connections=2500
threads_connected=378
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 23541980 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x7ff91ca736e0
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...
Cannot determine thread, fp=0x41140098, backtrace may not be correct.
Bogus stack limit or frame pointer, fp=0x41140098, stack_bottom=0x41140000, thread_stack=262144, aborting backtrace.
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x7ff91814da00 is invalid pointer
thd->thread_id=2036344
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.

Memory status:
Non-mmapped space allocated from system: 30531584
Number of free chunks: 301
Number of fastbin blocks: 0
Number of mmapped regions: 4
Space in mmapped regions: 67297280
Maximum total allocated space: 0
Space available in freed fastbin blocks: 0
Total allocated space: 13091328
Total free space: 17440256
Top-most, releasable space: 2889088
Estimated memory (with thread stack): 196657152

-e
Number of processes running now: 0
080702 17:27:34 mysqld restarted

Where should based the core file when mysql crashed like it (because i enable core-file in my.cnf)

what those debug information are enough to help you to find where is the bug crash problem ?

Thank you for the feedback.

For location of core file see your operating system documentation. For Ubuntu it probably would be in the /var/crash directory.

the core file dont exist because the user which runnin mysql is user=mysql so i gonna apply some change for the next crash as following:

Currently settings:
user=mysql

Future settings:
user=root

and i'll restart mysql server.

the new debug information posted today is more explicit for you ? Do you have more idea about this bug crash?

Thank you for the feedback.

> Some pointers may be invalid and cause the dump to abort...
> thd->query at 0x7ff91814da00  is invalid pointer
> thd->thread_id=2036344

This is same as before: no real query, no trace, invalid pointer. This is why I ask you about core file.

I applied the change with user=root and restarted mysqld server but the mysqld running again with the user=mysql :

root     20120  0.0  0.0   3944   608 pts/1    S    07:43   0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --pid-file=/var/lib/mysql/b2db09.pid
mysql    20166  5.2  5.2 4519828 1723516 pts/1 Sl   07:43   2:51  \_ /usr/sbin/mysqld --basedir=/ --datadir=/var/lib/mysql --user=mysql --pid-file=/var/lib/mysql/b2db09.pid --skip-external-l

Normally for run mysqld as root i should just change this setting user=mysql by user=root and restart mysql server.

see my current my.cnf:

[mysqld] 
log-bin 
replicate-ignore-db=mysql 

server-id = 52001001 
set-variable = max_connections=2500 
set-variable = back_log=20 
set-variable = key_buffer=8000M 
set-variable = table_cache=350 
set-variable = max_allowed_packet=4M 
set-variable = sort_buffer=2M 
set-variable = record_buffer=4M 
set-variable = myisam_sort_buffer_size=64M 
set-variable = thread_cache=50 
set-variable = long_query_time=10 
set-variable = query_cache_size=256M 
set_variable = wait_timeout=60 
#set_variable = wait_timeout=600 
skip-innodb 

log-bin = /var/lib/mysql/DB-new-bin 

log-slow-queries = /var/lib/mysql/slow.log 
skip-name-resolve 
tmpdir = /var/lib/mysql/tmp 

datadir=/var/lib/mysql 
socket=/var/lib/mysql/mysql.sock 

old_passwords=1 

[mysql.server] 
user=root 

[mysqld_safe] 
log-error=/var/log/mysqld.log 
log=/var/log/mysqld.log 
pid-file=/var/run/mysqld/mysqld.pid 

Something is wrong ?

OK now mysql is running with root user i added in good section [mysqld] cuz in previous post i had added user=root in [mysqld_safe] section.

Now i'm waiting the next crash for publish the core file into this bug report.

Julien, the cause of this crash is very likely key_buffer_size=8000M. So, reduce that to 4095M first.

Then, you have to put core-file in [mysqld] section and core_file_size=unlimited in [mysqld_safe] section.   If a crash happens core file should be left in the data directory, or whatever the current directory of mysqld is...

OK but in order to be sure i would have a core file with the current config and after i'll reduce the variable key_buffer_size to key_buffer_size=4095 and if the server crash with the new settings i'll post the core file too.

With both test, we'll have a complete test with the 2 settings (our settings and the settings with key_buffer_size=4095) in order to be sure about the source of this bug.

This morning the mysql server crashed again :

080707  8:38:30 - 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.

key_buffer_size=8388608000
read_buffer_size=4190208
max_used_connections=358
max_connections=2500
threads_connected=327
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 23541980 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x7f3ff439fe80
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...
Cannot determine thread, fp=0x44829098, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
(nil)
Stack trace seems successful - bottom reached
Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x7f3ffc29c440  is invalid pointer
thd->thread_id=2146616
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
Segmentation fault (core dumped)
-e
Number of processes running now: 0
080707 08:38:50  mysqld restarted

Current my.cnf:

root@b2db09:~# cat /etc/my.cnf
[mysqld]
log-bin
replicate-ignore-db=mysql

server-id       = 52001001
set-variable    = max_connections=2500
set-variable    = back_log=20
set-variable    = key_buffer=8000M
set-variable    = table_cache=350
set-variable    = max_allowed_packet=4M
set-variable    = sort_buffer=2M
set-variable    = record_buffer=4M
set-variable    = myisam_sort_buffer_size=64M
set-variable    = thread_cache=50
set-variable    = long_query_time=10
set-variable    = query_cache_size=256M
set_variable    = wait_timeout=60
skip-innodb

log-bin         = /var/lib/mysql/b2db01-new-bin

relay-log       = /var/lib/mysql/b2db09-relay-bin

log-slow-queries = /var/lib/mysql/slow.log
skip-name-resolve
tmpdir = /var/lib/mysql/tmp

core-file

datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Default to using old password format for compatibility with mysql 3.x
# clients (those using the mysqlclient10 compatibility package).
old_passwords=1
user=root

[mysql.server]
user=root
core_file_size  = unlimited

[mysqld_safe]
log-error=/var/log/mysqld.log
log=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

I'll post an ftp link to acceess to the core file because the core size file is around 4Go.

As asked by Shane Bester, now i'll apply new settings into my.cnf with key_buffer_size=4095M in order to see if there is the server mysql will crash and if yes, an other core file will be post.

Core file available here :

ftp://mysqlbug:mysqlbug@84.233.204.181/core.22720

Keep us inform asap please when you analysed the core file.

Did you check the core file ?

What you have more information about those crash ?

Thank you for the core file.

gdb outputs "Core was generated by `/usr/sbin/mysqld --basedir=/ --datadir=/var/lib/mysql --user=root --pid-file=/v'" mysqld does not contain debugging symbols, so it would be hard to use this core file again. Did you try mysqld-debug? Also please indicate version of glibc you use. You can find it with command `getconf GNU_LIBC_VERSION;`

root@b2db09:~# getconf GNU_LIBC_VERSION
glibc 2.7

i'm using /etc/init.d/mysql start with this following my.cnf during the crash :

[mysqld]
log-bin
replicate-ignore-db=mysql

server-id       = 52001001
set-variable    = max_connections=2500
set-variable    = back_log=20
set-variable    = key_buffer=8000M
set-variable    = table_cache=350
set-variable    = max_allowed_packet=4M
set-variable    = sort_buffer=2M
set-variable    = record_buffer=4M
set-variable    = myisam_sort_buffer_size=64M
set-variable    = thread_cache=50
set-variable    = long_query_time=10
set-variable    = query_cache_size=256M
set_variable    = wait_timeout=60
skip-innodb

log-bin         = /var/lib/mysql/b2db01-new-bin

relay-log       = /var/lib/mysql/b2db09-relay-bin

log-slow-queries = /var/lib/mysql/slow.log
skip-name-resolve
tmpdir = /var/lib/mysql/tmp

core-file

datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Default to using old password format for compatibility with mysql 3.x
# clients (those using the mysqlclient10 compatibility package).
old_passwords=1
user=root

[mysql.server]
user=root
core_file_size  = unlimited

[mysqld_safe]
log-error=/var/log/mysqld.log
log=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

Thank you for the feedback.

Please use mysqld-debug to get core file. You can do it with following sequence of actions:

1. mv mysqld mysqld_backup
2. ln -s mysqld-debug mysqld
3. restart mysqld
4. mysqld crashes, new core created
5. rm mysqld
6. mv mysqld_backup mysqld
7. send us core file

Thx i'll apply it tomorrow morning in order to monitor this one.

Server crashed this morning, so i'll put there the ftp link in order to access at the coredump.

file my.cnf during the crash :

[mysqld]
log-bin
replicate-ignore-db=mysql

server-id       = 52001001
set-variable    = max_connections=2500
set-variable    = back_log=20
set-variable    = key_buffer=8000M
set-variable    = table_cache=350
set-variable    = max_allowed_packet=4M
set-variable    = sort_buffer=2M
set-variable    = record_buffer=4M
set-variable    = myisam_sort_buffer_size=64M
set-variable    = thread_cache=50
set-variable    = long_query_time=10
set-variable    = query_cache_size=256M
set_variable    = wait_timeout=60
skip-innodb

log-bin         = /var/lib/mysql/b2db01-new-bin

relay-log       = /var/lib/mysql/b2db09-relay-bin

log-slow-queries = /var/lib/mysql/slow.log
skip-name-resolve
tmpdir = /var/lib/mysql/tmp

core-file

datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Default to using old password format for compatibility with mysql 3.x
# clients (those using the mysqlclient10 compatibility package).
old_passwords=1
user=root

[mysql.server]
user=root
core_file_size  = unlimited

[mysqld_safe]
log-error=/var/log/mysqld.log
log=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

Log Mysql during the crash:

ftp://mysqlbug:mysqlbug@84.233.204.181/mysqld.log

Core file generated during the crash:

ftp://mysqlbug:mysqlbug@84.233.204.181/core.30930

Thx to inform me because it's really important to know if this bug is really from the variable key_buffer_size.

Did you check the core file and mysqld.log include in my previous post? Do you have some news about this crash bug ?

Some News about this bug crash ?

julien, please put the stack trace from the core file here - that's all we need to check if key_buffer_size was a cause:  On your system, simply do this:

gdb /path/to/mysqld -c /path/to/corefile
bt full

thanks!

Ah, I see in the error log this:
Error: Memory allocated at my_largepage.c:64 was overrun, discovered at 'mi_dynrec.c:81'
Error: Memory allocated at my_largepage.c:64 was overrun, discovered at 'mi_dynrec.c:93'
Error: Memory allocated at my_largepage.c:64 was overrun, discovered at 'mi_dynrec.c:81'

my_largepage.c is the key_buffer.  so, yes, this crash is due to having a key_buffer_size greater than 4GB, as I suspected right in the beginning :)

I'll run gdb command tomorrow and i'll give the result there.

Just for my information, is there a date planned for the release 5.0.52 or a beta version of 5.0.52 which could fix this memory bug ?

Result debug command:

root@b2db09:~# gdb /usr/sbin/mysqld -c /var/lib/mysql/core.30930
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...
(no debugging symbols found)
Cannot access memory at address 0x344e3455
(gdb) bt full
#0  0x00007f68dc37e9c2 in ?? ()
No symbol table info available.
#1  0x0000000000583902 in handle_bootstrap ()
No symbol table info available.
#2  0x7efefefefefefeff in ?? ()
No symbol table info available.
#3  0x0000000000000206 in ?? ()
No symbol table info available.
#4  0x0000000000000117 in ?? ()
No symbol table info available.
#5  0x02002eb916009cf4 in ?? ()
No symbol table info available.
#6  0x00000000008c4bf0 in ?? ()
No symbol table info available.
#7  0x0000000000000000 in ?? ()
No symbol table info available.
(gdb)

What those infos are enough for you ?

Julien,

as you can see this is not a bug. Please, just shrink the key_buffer_size to a lower value.

i did with value equal 4092, and idd the server didnt crash anymore.

But do you have a date for the next release or a roadmap please.

Thx.

Hi,

the bug is fixed into the release 5.0.67 ?

Thx for your feedback.