Bug #43357 Server crash when selecting from INFORMATION_SCHEMA
Submitted: 4 Mar 2009 9:35 Modified: 25 Feb 2010 0:19
Reporter: Rafal Somla Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Backup Severity:S3 (Non-critical)
Version:6.0,5.4 OS:Any
Assigned to: Sergei Glukhov CPU Architecture:Any
Tags: crash, pushbuild, sporadic, test failure

[4 Mar 2009 9:35] Rafal Somla
Description:
In some backup tests (e.g., backup_bml) we use selects from INFORMATION_SCHEMA.PROCESSLIST table. I come across a server crash during such a select. I could not repeat this crash, but I saved debug info.

Here is a backtrace from gdb:

#3  <signal handler called>
#4  0x088155df in add_to_locked_mutex (locked_mutex=0x9ed8550, current_mutex=0x8b9a9a0) at thr_mutex.c:676
#5  0x087febb5 in my_hash_iterate (hash=0x9e84260, action=0x8815512 <add_to_locked_mutex>, argument=0x8b9a9a0) at hash.c:701
#6  0x088154f5 in add_used_to_locked_mutex (used_mutex=0x8b9a9a0, locked_mutex=0x9d52ae8) at thr_mutex.c:649
#7  0x08814981 in safe_mutex_lock (mp=0x9efb628, my_flags=0, file=0x899a418 "sql_show.cc", line=1887) at thr_mutex.c:319
#8  0x084487a5 in fill_schema_processlist (thd=0x9cb2790, tables=0x9e82058, cond=0x9f27018) at sql_show.cc:1887
#9  0x0843b7fe in get_schema_tables_result (join=0x9f1d3a8, executed_place=PROCESSED_BY_JOIN_EXEC) at sql_show.cc:6480
#10 0x083689c6 in JOIN::exec (this=0x9f1d3a8) at sql_select.cc:2393
#11 0x08364f85 in mysql_select (thd=0x9cb2790, rref_pointer_array=0x9cb3ab8, tables=0x9e82058, wild_num=0, fields=@0x9cb3a48, 
    conds=0x9e82a08, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684635648, result=0x9e83768, 
    unit=0x9cb371c, select_lex=0x9cb39b4) at sql_select.cc:3062
#12 0x0836a7ea in handle_select (thd=0x9cb2790, lex=0x9cb36c0, result=0x9e83768, setup_tables_done_option=0) at sql_select.cc:314
#13 0x082ceb6b in execute_sqlcom_select (thd=0x9cb2790, all_tables=0x9e82058) at sql_parse.cc:4817
#14 0x082cfc42 in mysql_execute_command (thd=0x9cb2790) at sql_parse.cc:2142
#15 0x082d821b in mysql_parse (thd=0x9cb2790, 
    inBuf=0x9e81a60 "SELECT state, info FROM INFORMATION_SCHEMA.PROCESSLIST\nWHERE info LIKE \"BACKUP DATABASE%\"\n     OR info LIKE \"RE
STORE FROM%\"\n     OR info LIKE \"RENAME USER bml_u2_renamed TO bml_u2%\"\n     OR info LIKE "..., length=236, 
    found_semicolon=0x5ec7ff20) at sql_parse.cc:5812

(gdb) f 4
#4  0x088155df in add_to_locked_mutex (locked_mutex=0x9ed8550, current_mutex=0x8b9a9a0) at thr_mutex.c:676
676       if (my_hash_insert(locked_mutex->mutex->used_mutex,
Current language:  auto; currently c
(gdb) l
671       {
672         /* Got mutex through two paths; ignore */
673         DBUG_RETURN(0);
674       }
675       locked_mutex->count++;
676       if (my_hash_insert(locked_mutex->mutex->used_mutex,
677                          (uchar*) current_mutex))
678       {
679         DBUG_ASSERT(0);
680       }
(gdb) p locked_mutex->mutex
$1 = (safe_mutex_t *) 0x8f8f8f8f

So the crash was caused by an access to invalid memory.

How to repeat:
Could not repeat it in realiable way. I got the crash when runnig backup_bml test.
[6 Mar 2009 7:58] Rafal Somla
Here is another crash I got in the same code area:

#3  <signal handler called>
#4  0x401d6947 in raise () from /lib/tls/libc.so.6
#5  0x401d80c9 in abort () from /lib/tls/libc.so.6
#6  0x0893d014 in safe_mutex_lock (mp=0x9f293b8, my_flags=0, file=0x8afde58 "sql_show.cc", line=1887) at thr_mutex.c:179
#7  0x084a4c31 in fill_schema_processlist (thd=0x9e53a30, tables=0x9fe2660, cond=0xa1acea8) at sql_show.cc:1887
#8  0x08497c8a in get_schema_tables_result (join=0xa1a7a08, executed_place=PROCESSED_BY_JOIN_EXEC) at sql_show.cc:6480
#9  0x083c47ae in JOIN::exec (this=0xa1a7a08) at sql_select.cc:2393
#10 0x083c0d6d in mysql_select (thd=0x9e53a30, rref_pointer_array=0x9e54e70, tables=0x9fe2660, wild_num=0, fields=@0x9e54e00, conds=0x9fe3010, og_num=0, order=0x0, 
    group=0x0, having=0x0, proc_param=0x0, select_options=2684635648, result=0x9fe3ce0, unit=0x9e54ad4, select_lex=0x9e54d6c) at sql_select.cc:3062
#11 0x083c65d2 in handle_select (thd=0x9e53a30, lex=0x9e54a78, result=0x9fe3ce0, setup_tables_done_option=0) at sql_select.cc:314
#12 0x0832a407 in execute_sqlcom_select (thd=0x9e53a30, all_tables=0x9fe2660) at sql_parse.cc:4817
#13 0x0832b4de in mysql_execute_command (thd=0x9e53a30) at sql_parse.cc:2142
#14 0x08333ab7 in mysql_parse (thd=0x9e53a30, 
    inBuf=0x9fe2098 "SELECT state, info FROM INFORMATION_SCHEMA.PROCESSLIST\nWHERE info LIKE \"BACKUP DATABASE%\"\n     OR info LIKE \"RESTORE FROM%\"\n     OR info LIKE \"CREATE DATABASE bml_test_db1%\"\n     OR info LIKE \"DROP TA"..., length=208, found_semicolon=0x5ec30f20) at sql_parse.cc:5812

Crash is due to abort() call here:

173       if (!mp->file)
174       {
175         fprintf(stderr,
176                 "safe_mutex: Trying to lock unitialized mutex at %s, line %d\n",
177                 file, line);
178         fflush(stderr);
179         abort();	<----------------
180       }

(gdb) p *mp
$2 = {global = {__m_reserved = 0, __m_count = 0, __m_owner = 0x0, __m_kind = 2, __m_lock = {__status = 0, __spinlock = 0}}, mutex = {__m_reserved = 0, 
    __m_count = 0, __m_owner = 0x0, __m_kind = 3, __m_lock = {__status = 0, __spinlock = 0}}, file = 0x0, name = 0x8a77825 "LOCK_delete", line = 799, count = 0, 
  create_flags = 2, active_flags = 0, id = 53824, thread = 0, locked_mutex = 0xa186748, used_mutex = 0xa186780, prev = 0x0, next = 0x0}

This is in a call to safe_mutex_lock() with file="sql_show.cc" and line=1887.

I obtained this crash after running "mtr backup_bml" several times in an 
infinite loop.
[24 Mar 2009 9:04] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/70145

2792 Rafal Somla	2009-03-23
      Remove SELECTs from I_S.PROCESSLIST from tests, because such selects are unstable
      in the current server (see bug#37990, bug#41346, bug#43357). These selects increase
      feedback given by test and thus increases chances of detecting problems, but are
      not essential for test purposes.
     @ mysql-test/suite/backup/include/bml_test.inc
        Comment-out SELECTs from I_S.PROCESSLIST.
     @ mysql-test/suite/backup/t/backup_bml.test
        Comment-out SELECTs from I_S.PROCESSLIST.
     @ mysql-test/suite/backup_engines/include/backup_restore_interrupt.inc
        Comment-out SELECTs from I_S.PROCESSLIST.
[24 Mar 2009 9:10] Rafal Somla
Moving back to verified - the patch does not fix this bug, only modifies test cases to not use I_S selects.
[24 Mar 2009 10:39] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/70165

2793 Rafal Somla	2009-03-23
      Remove SELECTs from I_S.PROCESSLIST from tests, because such selects are unstable
      in the current server (see bug#37990, bug#41346, bug#43357). These selects increase
      feedback given by test and thus increases chances of detecting problems, but are
      not essential for test purposes.
     @ mysql-test/suite/backup/include/bml_test.inc
        Comment-out SELECTs from I_S.PROCESSLIST.
     @ mysql-test/suite/backup/t/backup_bml.test
        Comment-out SELECTs from I_S.PROCESSLIST.
     @ mysql-test/suite/backup_engines/include/backup_restore_interrupt.inc
        Comment-out SELECTs from I_S.PROCESSLIST.
[24 Mar 2009 10:48] Rafal Somla
Not fixed yet.
[23 Apr 2009 7:19] Bugs System
Pushed into 6.0.11-alpha (revid:alik@sun.com-20090423070920-e5lq3vrrqi016z2c) (version source revid:alik@sun.com-20090423070920-e5lq3vrrqi016z2c) (merge vers: 6.0.11-alpha) (pib:6)
[30 Apr 2009 12:45] Rafal Somla
I tried it on the recent clone of our main-6.0 tree (6.0.11-alpha, revid:jperkin@sun.com-20090423215644-h7ssug9w1hdgzn39). After enabling selects from INFORMATION_SCHEMA in suite/backup/include/bml_test.inc I get crash each time I run backup_bml test.
[17 Jun 2009 8:47] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/76427

3367 Sergey Glukhov	2009-06-17
      Bug#43357 Server crash when selecting from INFORMATION_SCHEMA
      The crash happens due to thd->mysys_var which is cleaned up in
      'delete thd'. 'delete thd' should be called under LOCK_thread_count
      lock but it does not happen for backup thread.
      The fix is:
      -move 'delete thd' under LOCK_thread_count lock.
      -removed unnecessary net_end() call as it is
       performed in 'delete thd'
      
      Note: backup_bml.result is not updated as it reqires FALCON engine
      which does not work at the moment.
     @ mysql-test/suite/backup/include/bml_test.inc
        uncomment I_S.processlist test
     @ mysql-test/suite/backup/r/backup_intr_errors.result
        result fix
     @ mysql-test/suite/backup/t/backup_bml.test
        uncomment I_S.processlist test
     @ mysql-test/suite/backup_engines/include/backup_restore_interrupt.inc
        uncomment I_S.processlist test
     @ sql/backup/be_thread.cc
        -move 'delete thd' under LOCK_thread_count lock.
        -removed unnecessary net_end() call as it is
         performed in 'delete thd'.
[27 Jul 2009 15:57] Ingo Strüwing
Some time ago I sent some questions by email. I set this back to "in progress" to get it from my todo list until the questions are answered.
[25 Nov 2009 10:22] Philip Stoev
Grammar file for bug 43357

Attachment: bug43357.yy (application/octet-stream, text), 179 bytes.

[25 Nov 2009 10:24] Philip Stoev
To reproduce within a few seconds:

perl runall.pl \
--grammar=conf/bug43357.yy \
--mysqld=--mysql-backup \
--basedir=/build/bzr/6.0-codebase-bugfixing

This particular test uses non-concurrent BACKUP/RESTORE and concurrent SHOW PROCESSLIST, but this crash has been observed when SHOW PROCESSLIST was ran only once every 10 seconds. This tells me that there is a big opportunity for crashes in production systems if a monitoring tool is running and backups are being taken.
[2 Dec 2009 15:56] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/92511

3733 Sergey Glukhov	2009-12-02
      Bug#43357 Server crash when selecting from INFORMATION_SCHEMA
      Server crashes in mysqld_list_processes() function on 
      pthread_mutex_unlock(&tmp->LOCK_thd_data) call.
      It happens because threads after its delete are still visible
      in thread list with destroyed LOCK_thd_data mutex.
      Another problem is that 'delete thd' in backup threads is called
      outside of LOCK_thread_count lock/unlock which can cause the 
      crash as well.
      The fix is to protect 'delete thd' call with LOCK_thread_count
      and remove deleted thd from thread list.
     @ sql/backup/be_thread.cc
        protect 'delete thd' call with LOCK_thread_count
     @ sql/sql_class.cc
        added deleted thd removal from thread list
     @ sql/sql_list.h
        added is_linked() method
     @ storage/myisam/myisam_backup_engine.cc
        protect 'delete thd' call with LOCK_thread_count
[9 Dec 2009 14:58] Rafal Somla
Good to push. Note however that myisam_backup_egnine.cc is also fixed in BUG#49342.
[10 Dec 2009 9:55] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/93466

2906 Sergey Glukhov	2009-12-10
      Bug#43357 Server crash when selecting from INFORMATION_SCHEMA
      Server crashes in mysqld_list_processes() function on 
      pthread_mutex_unlock(&tmp->LOCK_thd_data) call.
      It happens because threads after its delete are still visible
      in thread list with destroyed LOCK_thd_data mutex.
      The fix is to remove deleted thd from thread list.
     @ sql/sql_class.cc
        added deleted thd removal from thread list
     @ sql/sql_list.h
        added is_linked() method
[15 Dec 2009 17:04] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/94213

2907 Chuck Bell	2009-12-15
      BUG#43357 Server crash when selecting from INFORMATION_SCHEMA
      
      Server crashes in mysqld_list_processes() function on 
      pthread_mutex_unlock(&tmp->LOCK_thd_data) call.
      It happens because threads after its delete are still visible
      in thread list with destroyed LOCK_thd_data mutex.
      The fix is to remove deleted thd from thread list.
     @ sql/sql_class.cc
        added deleted thd removal from thread list
     @ sql/sql_list.h
        added is_linked() method
[20 Feb 2010 9:18] Bugs System
Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100119103538-wtp5alpz4p2jayl5) (merge vers: 6.0.14-alpha) (pib:16)
[25 Feb 2010 0:19] Paul DuBois
Noted in 6.0.14 changelog.

MySQL Backup sometimes crashed when selecting information from
INFORMATION_SCHEMA.