Bug #54478 mysqld crashes during boot when running mtr with --debug option
Submitted: 14 Jun 2010 8:23 Modified: 17 Nov 2010 1:23
Reporter: Olav Sandstå Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: General Severity:S3 (Non-critical)
Version:5.5.5,5.6.99 OS:Solaris
Assigned to: Olav Sandstå CPU Architecture:Any

[14 Jun 2010 8:23] Olav Sandstå
Description:
When running mtr with the --debug option the mysqld server crashes during the boot phase with the following call stack:

(dbx) where
current thread: t@3
  [1] _lwp_kill(0x3, 0xb, 0x0, 0xfecba9fa), at 0xfecc22a5 
  [2] thr_kill(0x3, 0xb), at 0xfecbaa1c 
=>[3] my_write_core(sig = 11), line 326 in "stacktrace.c"
  [4] handle_segfault(sig = 11), line 2791 in "mysqld.cc"
  [5] __sighndlr(0xb, 0x0, 0xfea8b50c, 0x831a520), at 0xfecbd0cf 
  [6] call_user_handler(0xb), at 0xfecb01bf 
  [7] sigacthandler(0xb, 0x0, 0xfea8b50c, 0xf, 0x0, 0x807007), at 0xfecb03ef 
  ---- called from signal handler with signal 11 (SIGSEGV) ------
  [8] strlen(0x8e0cb70, 0xfea8c988, 0xfea8c510, 0x0), at 0xfec347a0 
  [9] vsnprintf(0xfea8c554, 0x400, 0x8e0cb70, 0xfea8c988, 0x0, 0x0), at 0xfec831bd 
  [10] DbugVfprintf(stream = 0x9368ea0, format = 0x8e0cb70 "db_name='%s', table_name='%s'", args = 0xfea8c988), line 1369 in "dbug.c"
  [11] _db_doprnt_(format = 0x8e0cb70 "db_name='%s', table_name='%s'", ... = 0x9bf0bc8, ...), line 1350 in "dbug.c"
  [12] fill_schema_schemata(thd = 0x9bdd7f0, tables = 0x9bef518, cond = 0x9befa00), line 3658 in "sql_show.cc"
  [13] get_schema_tables_result(join = 0x9bfd2c8, executed_place = PROCESSED_BY_JOIN_EXEC), line 6653 in "sql_show.cc"
  [14] JOIN::exec(this = 0x9bfd2c8), line 1872 in "sql_select.cc"
  [15] subselect_single_select_engine::exec(this = 0x9befb88), line 1992 in "item_subselect.cc"
  [16] Item_subselect::exec(this = 0x9befaf0), line 288 in "item_subselect.cc"
  [17] Item_singlerow_subselect::val_int(this = 0x9befaf0), line 598 in "item_subselect.cc"
  [18] Item_func_set_user_var::check(this = 0x9befbb0, use_result_field = false), line 4437 in "item_func.cc"
  [19] set_var_user::check(this = 0x9beff98, thd = 0x9bdd7f0), line 677 in "set_var.cc"
  [20] sql_set_variables(thd = 0x9bdd7f0, var_list = 0x9bdee80), line 560 in "set_var.cc"
  [21] mysql_execute_command(thd = 0x9bdd7f0), line 3497 in "sql_parse.cc"
  [22] mysql_parse(thd = 0x9bdd7f0, inBuf = 0x9beeca0 "set @have_old_pfs= (select count(*) from information_schema.schemata where schema_name='performance_schema')", length = 108U, parser_state = 0xfea8eea4), line 5851 in "sql_parse.cc"
  [23] handle_bootstrap_impl(thd = 0x9bdd7f0), line 563 in "sql_parse.cc"
  [24] do_handle_bootstrap(thd = 0x9bdd7f0), line 613 in "sql_parse.cc"
  [25] handle_bootstrap(arg = 0x9bdd7f0), line 596 in "sql_parse.cc"
  [26] _thrp_setup(0xfea90a00), at 0xfecbcd66 
  [27] _lwp_start(0x3, 0xb, 0x0, 0xfecba9fa, 0xfea8b3e4, 0x9009a4c), at 0xfecbcff0 

How to repeat:
1. Using the latest source from mysql-trunk-bugfixing

2. Build (on Solaris with Sun Studio compiler):

    cmake . -DWITH_DEBUG=1 -DWITH_INNOBASE_STORAGE_ENGINE=1
    make

3. Run test:

    ./mtr --debug --suite=main

   This make the test fail almost immediately during booting before starting running the first test case.
[15 Jun 2010 7:37] Sveta Smirnova
Thank you for the report.

Verified as described.
[15 Jun 2010 7:38] Sveta Smirnova
Looks like duplicate of bug #52884
[15 Jun 2010 7:39] Sveta Smirnova
Backtrace:

/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:0x1044e40
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:_db_doprnt_+0x188
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cUfill_schema_schemata6FpnDTHD_pnKTABLE_LIST_pnEItem__i_+0x118
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cYget_schema_tables_result6FpnEJOIN_nXenum_schema_table_state__b_+0x334
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cEJOINEexec6M_v_+0x888
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cbEsubselect_single_select_engineEexec6M_i_+0x604
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cOItem_subselectEexec6M_b_+0x9c
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cYItem_singlerow_subselectHval_int6M_x_+0x58
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cWItem_func_set_user_varFcheck6Mb_b_+0x130
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cMset_var_userFcheck6MpnDTHD__i_+0x54
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cRsql_set_variables6FpnDTHD_pnEList4nMset_var_base____i_+0x84
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cVmysql_execute_command6FpnDTHD__i_+0x4678
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cLmysql_parse6FpnDTHD_pkcIpnMParser_state__v_+0x298
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:0x220d2c
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:__1cTdo_handle_bootstrap6FpnDTHD__v_+0x7c
/users/ssmirnova/src/mysql-trunk-bugfixing/sql/mysqld:handle_bootstrap+0x24
/lib/libc.so.1:0xc88ac
[15 Jun 2010 7:59] Olav Sandstå
Thanks for verifying this bug. I agree that it looks the same as reported in Bug#52884. Still, I believe this is a different bug based on that Bug#52884 is fixed/closed and that the fix for it (with revision id sergey.glukhov@sun.com-20100520063103-0cwsyi6bwh88t68f) is already present in mysql-trunk-bugfixing.
[22 Jun 2010 19:17] Omer Barnir
triage: setting to SR55RC (needed for testing I3 - needed for testing) D2 start-up crash
[3 Sep 2010 10:22] Olav Sandstå
Based on the stack from the core file posted in the initial bug report it seems like the crash occurs when:

1. In fill_schema_schemata() we do the following DBG trace:

      DBUG_PRINT("INDEX VALUES",("db_name='%s', table_name='%s'",
                             lookup_field_vals.db_value.str,
                             lookup_field_vals.table_value.str));

2. This results in a call to _db_doprnt_() where the format parameter points to 0x8e0cb70 "db_name='%s', table_name='%s'"

3. In the call to DbugVfprintf() and vsnprintf() the format parameter still points to address 0x8e0cb70.

4. When vsnprintf() calls strlen() the argument to strlen is also 0x8e0cb70. 

So it seems like strlen() is called with a pointer to the string "db_name='%s', table_name='%s'" which should be a statically allocated. This makes it hard to understand why this should cause a segmentation fault in strlen.
[7 Sep 2010 10:24] Olav Sandstå
The crash occurs when the following DBUG statement in fill_schema_schemata() (line 3721 in sql_show.cc) is run:

  DBUG_PRINT("INDEX VALUES",("db_name='%s', table_name='%s'",
                             lookup_field_vals.db_value.str,
                             lookup_field_vals.table_value.str));

and the value of lookup_field_vals.table_value.str is NULL. 

This DBUG statement eventually ends up in the following code in dbug.c:

  static void DbugVfprintf(FILE *stream, const char* format, va_list args)
  {
    char cvtbuf[1024];
    size_t len;
    /* Do not use my_vsnprintf, it does not support "%g". */
    len = vsnprintf(cvtbuf, sizeof(cvtbuf), format, args);
    (void) fprintf(stream, "%s\n", cvtbuf);
  }

where the crash occurs in the call to vsnprintf. This crash is caused by we calling vsnprintf with a format string containing "%s" with a NULL pointer as the corresponding argument.

The fix for this crash is to ensure we do not give a NULL pointer as the value for %s entries in the format string when calling DBUG_PRINT.
[7 Sep 2010 10:44] Olav Sandstå
Test program for illustrating the vsnprintf crash

Attachment: vsnprintf-test.cc (text/x-c++src), 348 bytes.

[7 Sep 2010 10:46] Olav Sandstå
The attached program can be used for showing that vsnprintf called with a NULL pointer argument to a %s format string can crash. This program will result in a crash on most versions of Solaris while complete without crash on most Linux versions.
[8 Sep 2010 8:38] 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/117758

3204 Olav Sandstaa	2010-09-08
      Fix for Bug#54478 "mysqld crashes during boot when running mtr with --debug option"
      
      The crash during boot was caused by a DBUG_PRINT statement in fill_schema_schemata() (in
      sql_show.cc). This DBUG_PRINT statement contained several instances of %s in the format 
      string and for one of these we gave a NULL pointer as the argument. This caused the
      call to vsnprintf() to crash when running on Solaris.
      
      The fix for this problem is to ensure we do not give a NULL pointer as argument. If the
      variable to be printed is NULL we instead give a "(null)" string as argument.
      
      This patch also contains fixes for several other places where we gave a NULL pointer
      as argument to %s fields in the format string for DBUG_PRINT. These caused several
      individual tests to fail.
     @ client/mysqltest.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ mysys/mf_format.c
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/field.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/handler.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "NULL". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/sql_class.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/sql_db.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/sql_insert.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/sql_select.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
     @ sql/sql_show.cc
        Add a test for that string arguments to DBUG_PRINT() is not NULL pointers. If that
        is the case we instead supply a string containing "(null)". This problem caused
        vsnprintf() to crash on Solaris.
[9 Sep 2010 13:24] 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/117878

3206 Olav Sandstaa	2010-09-09
      Fix for Bug#54478 "mysqld crashes during boot when running mtr with --debug option"
            
      The crash during boot was caused by a DBUG_PRINT statement in fill_schema_schemata() (in
      sql_show.cc). This DBUG_PRINT statement contained several instances of %s in the format 
      string and for one of these we gave a NULL pointer as the argument. This caused the
      call to vsnprintf() to crash when running on Solaris.
            
      The fix for this problem is to replace the call to vsnprintf() with my_vsnprintf()
      which handles that a NULL pointer is passed as argumens for %s.
      
      This patch also extends my_vsnprintf() to support %i in the format string.
     @ dbug/dbug.c
        Replace the use of vsnprintf() with my_vsnprintf(). On some platforms
        vsnprintf() did not handle that a NULL pointer was given as an argument.
     @ strings/my_vsnprintf.c
        Add support for %i in format string to my_vsnprintf().
     @ unittest/mysys/my_vsnprintf-t.c
        Add unit tests for %i in format string to my_vsnprintf().
[15 Sep 2010 11:33] 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/118297

3206 Olav Sandstaa	2010-09-15
      Fix for Bug#54478 "mysqld crashes during boot when running mtr with --debug option"
            
      The crash during boot was caused by a DBUG_PRINT statement in fill_schema_schemata() (in
      sql_show.cc). This DBUG_PRINT statement contained several instances of %s in the format 
      string and for one of these we gave a NULL pointer as the argument. This caused the
      call to vsnprintf() to crash when running on Solaris.
            
      The fix for this problem is to replace the call to vsnprintf() with my_vsnprintf()
      which handles that a NULL pointer is passed as argumens for %s.
      
      This patch also extends my_vsnprintf() to support %i in the format string.
     @ dbug/dbug.c
        Replace the use of vsnprintf() with my_vsnprintf(). On some platforms
        vsnprintf() did not handle that a NULL pointer was given as an argument
        for a %s in the format string.
     @ include/mysql/service_my_snprintf.h
        Add support for %i in format string to my_vsnprintf().
     @ strings/my_vsnprintf.c
        Add support for %i in format string to my_vsnprintf().
     @ unittest/mysys/my_vsnprintf-t.c
        Add unit tests for %i in format string to my_vsnprintf().
[15 Sep 2010 11:52] 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/118298

3266 Olav Sandstaa	2010-09-15 [merge]
      Merging fix for Bug#54478 from mysql-5.5-bugfixing
[15 Sep 2010 11:58] 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/118301

3288 Olav Sandstaa	2010-09-15 [merge]
      Merging fix for Bug#54478 from mysql-trunk-bugfixing
[15 Sep 2010 12:05] Olav Sandstå
Pushed into mysql-5.5-bugfixing, merged to mysql-trunk-bugfixing and mysql-next-mr-bugfixing.
Revision id: olav.sandstaa@oracle.com-20100915113322-io8n04jkw0o7dack
[2 Oct 2010 18:12] Bugs System
Pushed into mysql-trunk 5.6.1-m4 (revid:alexander.nozdrin@oracle.com-20101002180948-852x1cuv7c6i85ea) (version source revid:alexander.nozdrin@oracle.com-20101002180857-an32jpuwzemsp4f2) (merge vers: 5.6.1-m4) (pib:21)
[2 Oct 2010 18:13] Bugs System
Pushed into mysql-next-mr (revid:alexander.nozdrin@oracle.com-20101002181053-6iotvl26uurcoryp) (version source revid:alexander.nozdrin@oracle.com-20101002180917-h0n62akupm3z20nt) (pib:21)
[2 Oct 2010 18:16] Bugs System
Pushed into mysql-5.5 5.5.7-rc (revid:alexander.nozdrin@oracle.com-20101002180831-590ka2tuit9qoxbb) (version source revid:alexander.nozdrin@oracle.com-20101002180831-590ka2tuit9qoxbb) (merge vers: 5.5.7-rc) (pib:21)
[12 Nov 2010 0:37] Paul DuBois
Noted in 5.5.7, 5.6.1 changelogs.

A bad DBUG_PRINT statement in fill_schema_schemata() caused server
crashes on Solaris.
[13 Nov 2010 16:19] Bugs System
Pushed into mysql-trunk 5.6.99-m5 (revid:alexander.nozdrin@oracle.com-20101113155825-czmva9kg4n31anmu) (version source revid:vasil.dimov@oracle.com-20100629074804-359l9m9gniauxr94) (merge vers: 5.6.99-m4) (pib:21)