Bug #40416 Maria: Memory allocated at trnman.c:129 was underrun
Submitted: 30 Oct 2008 7:31 Modified: 9 Jan 2009 15:26
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Maria storage engine Severity:S3 (Non-critical)
Version:6.0 OS:Any
Assigned to: Sergei Golubchik CPU Architecture:Any

[30 Oct 2008 7:31] Philip Stoev
Description:
When executing a concurrent CREATE TABLE ... SELECT workload, the error log is filled with tens of thousands of messages like:

Error: Memory allocated at trnman.c:129 was underrun, discovered at ma_close.c:65

The server eventually crashes in:

#0  0x00110416 in __kernel_vsyscall ()
#0  0x00110416 in __kernel_vsyscall ()
#1  0x00581c78 in pthread_kill () from /lib/libpthread.so.0
#2  0x087e1813 in my_write_core (sig=6) at stacktrace.c:307
#3  0x082b628a in handle_segfault (sig=6) at mysqld.cc:2673
#4  <signal handler called>
#5  0x00110416 in __kernel_vsyscall ()
#6  0x003e6660 in raise () from /lib/libc.so.6
#7  0x003e8028 in abort () from /lib/libc.so.6
#8  0x003df57e in __assert_fail () from /lib/libc.so.6
#9  0x082a9796 in net_end_statement (thd=0xad208e8) at protocol.cc:467
#10 0x082d0b64 in dispatch_command (command=COM_QUERY, thd=0xad208e8, packet=0xab06c49 "CREATE TABLE IF NOT EXISTS q SELECT * FROM `s` LIMIT 5",
    packet_length=54) at sql_parse.cc:1407
#11 0x082d0feb in do_command (thd=0xad208e8) at sql_parse.cc:689
#12 0x082bf70b in handle_one_connection (arg=0xad208e8) at sql_connect.cc:1156
#13 0x0057d32f in start_thread () from /lib/libpthread.so.0
#14 0x0049a27e in clone () from /lib/libc.so.6

How to repeat:
Grammar for the random query generator:

query:
        CREATE TABLE IF NOT EXISTS _letter SELECT * FROM _table LIMIT _digit |
        CREATE TABLE IF NOT EXISTS _letter SELECT * FROM _table LIMIT _digit |
        DROP TABLE IF EXISTS _letter ;

Please paste it into an empty file named maria_create.yy and execute:

$ bzr checkout lp:~randgen/randgen/main randgen
$ cd rangden
$ perl runall.pl \
  --basedir=/path/to/mysql-6.0 \
  --engine=Maria \
  --grammar=maria_create.yy
[6 Nov 2008 12:56] Guilhem Bichot
pushed to 5.1-maria  http://lists.mysql.com/maria/257
[6 Nov 2008 13:04] Guilhem Bichot
This is also queued to 6.0-maria.
[6 Nov 2008 14:03] Guilhem Bichot
Back to "verified" because Serg is unsure about his patch.
[6 Nov 2008 21:07] Guilhem Bichot
Something which looks related.
I'm using the latest mysql-maria, and running on Linux 32-bit:
(i=0; while true; do i=`expr $i + 1`; echo $i; ./mtr --debug --mysqld=--default-storage-engine=maria mysqlslap || exit 1; done; )
On i=4 it crashed in trnman_destroy(), this line:
  my_free((void *)(short_trid_to_active_trn+1), MYF(0));
with this message:
*** glibc detected *** /home/mysql_src/bzrrepos/mysql-maria/sql/mysqld: free(): invalid pointer: 0xb6828008 ***
======= Backtrace: =========
/lib/libc.so.6[0xb7e296e1]
/lib/libc.so.6(cfree+0x89)[0xb7e2ad79]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld(my_no_flags_free+0x5d)[0x861ec3d]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld(trnman_destroy+0x228)[0x84f81a3]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld(maria_end+0x7e)[0x85199a6]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld(maria_panic+0x281)[0x854e0a1]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld[0x8514670]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld(_Z22ha_finalize_handlertonP13st_plugin_int+0x61)[0x8333063]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld[0x83cc126]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld[0x83cd6a5]
/home/mysql_src/bzrrepos/mysql-maria/sql/mysqld(_Z15plugin_shutdownv+0xe3)[0x83cdc19
Note that the allocation in trnman_init() had gone ok:
T@1    : | | | | | | >trnman_init
T@1    : | | | | | | | >my_malloc
T@1    : | | | | | | | | my: size: 262140  my_flags: 48
T@1    : | | | | | | | | exit: ptr: 0xb6828008
T@1    : | | | | | | | <my_malloc
and note that the my_free() in trnman_destroy() wants to free the same pointer value, which makes sense too:
T@704  : | | | | | info: pthread_mutex_destroy LOCK_trn_list
T@704  : | | | | | >my_free
T@704  : | | | | | | my: ptr: 0xb6828008
A grep for this 0xb6828008 in the trace showed no other occurence than trnman_init() and trnman_destroy().
[17 Nov 2008 22:03] Guilhem Bichot
The error in my previous post was Linux-32-bit, and I just saw it on Linux-64-bit too.
[27 Nov 2008 8:33] Guilhem Bichot
saw it again (same mysqlslap test, latest 5.1-maria)
[15 Dec 2008 10:08] Bugs System
Pushed into 6.0.9-alpha  (revid:serg@mysql.com-20081205102011-ef1exxc10yz68ov9) (version source revid:guilhem@mysql.com-20081213204800-0nubni3t4ihn4hv9) (pib:5)
[9 Jan 2009 15:26] MC Brown
Added a note to the 6.0.9 changelog: 

When executing concurrent CREATE TABLE ... SELECT statements on a Maria table, the error Error: Memory allocated at trnman.c:129 was underrun, discovered at ma_close.c:65 error would be logged in the error file, and the server would eventually crash.