Bug #31389 MySQL 5.1 server crashes on normal shutdown if you have installed plugins
Submitted: 4 Oct 2007 7:38 Modified: 16 Oct 2007 8:14
Reporter: Jan Lindström Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.1.23-bk OS:Linux
Assigned to: CPU Architecture:Any

[4 Oct 2007 7:38] Jan Lindström
Description:
I have installed soliddb dynamic plugin:

Server version: 5.1.23-beta-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> show plugins;
+------------+--------+----------------+---------------+---------+
| Name       | Status | Type           | Library       | License |
+------------+--------+----------------+---------------+---------+
| binlog     | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| partition  | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| ARCHIVE    | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| BLACKHOLE  | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| CSV        | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| FEDERATED  | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| MEMORY     | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| InnoDB     | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| MRG_MYISAM | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| MyISAM     | ACTIVE | STORAGE ENGINE | NULL          | GPL     | 
| solidDB    | ACTIVE | STORAGE ENGINE | ha_soliddb.so | GPL     | 
+------------+--------+----------------+---------------+---------+
11 rows in set (0.00 sec)

Now if I do a normal shutdown:

jan@jan-laptop:~$ mysql-5.1/client/mysqladmin -u root shutdown

I get the following crash:
jan@jan-laptop:~/mysql-5.1/sql$ ./mysqld --defaults-file=/home/jan/.my.cnf
071004 10:29:40 [Warning] Changed limits: max_open_files: 1024  max_connections: 886  table_cache: 64
071004 10:29:40  InnoDB: Started; log sequence number 0 50832
solidDB Storage Engine for MySQL 5.1.23-beta - 06.01.0078 DEBUG   (Linux 2.6.20 ix86 MT)
This is a solidDB for MySQL build.
Copyright (C) Solid Information Technology Ltd 1993-2007
Using log write mode 2
Database started.
071004 10:29:41 [Note] Event Scheduler: Loaded 0 events
071004 10:29:41 [Note] ./mysqld: ready for connections.
Version: '5.1.23-beta-debug'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
071004 10:30:19 [Note] Got signal 15 to shutdown mysqld
071004 10:30:19 [Note] ./mysqld: Normal shutdown

071004 10:30:19 [Note] Event Scheduler: Purging the queue. 0 events
solidDB Storage Engine for MySQL is shut down
Total of 0 allocated pointers.
071004 10:30:21  InnoDB: Starting shutdown...
071004 10:30:23  InnoDB: Shutdown completed; log sequence number 0 50832
071004 10:30:23 [Note] ./mysqld: Shutdown complete

071004 10:30:23 - 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=2408550287
read_buffer_size=131072
max_used_connections=1
max_threads=2000
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2514761 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 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...
Cannot determine thread, fp=0xa52e1028, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x8269e10
0xb6c10e59
0xb7ee3329
0xb7de757e
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/refman/5.1/en/resolve-stack-dump.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
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.
*** glibc detected *** ./mysqld: double free or corruption (!prev): 0x0887ee78 ***
======= Backtrace: =========
Segmentation fault (core dumped)
jan@jan-laptop:~/mysql-5.1/sql$ ./mysqld --defaults-file=/home/jan/.my.cnf
071004 10:30:42 [Warning] Changed limits: max_open_files: 1024  max_connections: 886  table_cache: 64
071004 10:30:42  InnoDB: Started; log sequence number 0 50832
solidDB Storage Engine for MySQL 5.1.23-beta - 06.01.0078 DEBUG   (Linux 2.6.20 ix86 MT)
This is a solidDB for MySQL build.
Copyright (C) Solid Information Technology Ltd 1993-2007
Using log write mode 2
Database started.
071004 10:30:42 [Note] Event Scheduler: Loaded 0 events
071004 10:30:42 [Note] ./mysqld: ready for connections.
Version: '5.1.23-beta-debug'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
071004 10:31:07 [Note] Got signal 15 to shutdown mysqld
071004 10:31:07 [Note] ./mysqld: Normal shutdown

071004 10:31:07 [Note] Event Scheduler: Purging the queue. 0 events
solidDB Storage Engine for MySQL is shut down
Total of 0 allocated pointers.
071004 10:31:11  InnoDB: Starting shutdown...
071004 10:31:12  InnoDB: Shutdown completed; log sequence number 0 50832
071004 10:31:12 [Note] ./mysqld: Shutdown complete

071004 10:31:12 - 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=2408550287
read_buffer_size=131072
max_used_connections=1
max_threads=2000
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2514761 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 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...
Cannot determine thread, fp=0xa5174028, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x8269e10
0xb6c6ce59
0xb7f3f329
0xb7e4357e
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/refman/5.1/en/resolve-stack-dump.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
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.
*** glibc detected *** ./mysqld: double free or corruption (!prev): 0x0887f088 ***

How to repeat:
Install plugin and do a shutdown.

If I use killall mysqld I get also a crash:

jan@jan-laptop:~/mysql-5.1/sql$ ./mysqld --defaults-file=/home/jan/.my.cnf
071004 10:35:17 [Warning] Changed limits: max_open_files: 1024  max_connections: 886  table_cache: 64
071004 10:35:17  InnoDB: Started; log sequence number 0 50832
solidDB Storage Engine for MySQL 5.1.23-beta - 06.01.0078 DEBUG   (Linux 2.6.20 ix86 MT)
This is a solidDB for MySQL build.
Copyright (C) Solid Information Technology Ltd 1993-2007
Using log write mode 2
Merge started, 3 keys to remove
Database started.
071004 10:35:17 [Note] Event Scheduler: Loaded 0 events
071004 10:35:17 [Note] ./mysqld: ready for connections.
Version: '5.1.23-beta-debug'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
071004 10:35:19 [Note] Got signal 15 to shutdown mysqld
071004 10:35:19 [Note] ./mysqld: Normal shutdown

071004 10:35:19 [Note] Event Scheduler: Purging the queue. 0 events
solidDB Storage Engine for MySQL is shut down
Total of 0 allocated pointers.
071004 10:35:21  InnoDB: Starting shutdown...
071004 10:35:21  InnoDB: Shutdown completed; log sequence number 0 50832
071004 10:35:21 [Note] ./mysqld: Shutdown complete

071004 10:35:21 - 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=2408550287
read_buffer_size=131072
max_used_connections=0
max_threads=2000
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2514761 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 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...
Cannot determine thread, fp=0xa52c1028, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x8269e10
0xb6ca0e59
0xb7f73329
0xb7e7757e
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/refman/5.1/en/resolve-stack-dump.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
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.
Segmentation fault (core dumped)

I could not repeat the problem using the ddd or gdb so this smells like a race condition problem at shutdown.
[8 Oct 2007 11:41] Jan Lindström
This bug seems to be because of this in ctype-utf8.c:

static void my_hash_sort_utf8(CHARSET_INFO *cs, const uchar *s, size_t slen,
                              ulong *n1, ulong *n2)
{
  my_wc_t wc;
  int res;
  const uchar *e=s+slen;
  MY_UNICASE_INFO **uni_plane= cs->caseinfo;

  /*
    Remove end space. We have to do this to be able to compare
    'A ' and 'A' as identical
  */
  while (e > s && e[-1] == ' ') /* NOTE here indexing by -1 */ 
    e--;

  while ((s < e) && (res=my_utf8_uni(cs,&wc, (uchar *)s, (uchar*)e))>0 )
  {
    int plane = (wc>>8) & 0xFF;
    wc = uni_plane[plane] ? uni_plane[plane][wc & 0xFF].sort : wc;
    n1[0]^= (((n1[0] & 63)+n2[0])*(wc & 0xFF))+ (n1[0] << 8);
    n2[0]+=3;
    n1[0]^= (((n1[0] & 63)+n2[0])*(wc >> 8))+ (n1[0] << 8);
    n2[0]+=3;
    s+=res;
  }
}

Suggested fix: Fix indexing to positive values
[16 Oct 2007 8:14] Jan Lindström
This problem was solved by changing compiler options. Bug can be closed.