MySQL Bugs: #37850: Solaris debug crashes when starting with --debug option

Bug #37850	Solaris debug crashes when starting with --debug option
Submitted:	3 Jul 2008 20:02	Modified:	11 Jul 2011 9:37
Reporter:	Sveta Smirnova	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Stored Routines	Severity:	S1 (Critical)
Version:	5.0, 5.1 bzr	OS:	Solaris (10, SPARC)
Assigned to:		CPU Architecture:	Any

Description:
Verifying bug #37789 found debug binaries crashes on Solaris if start with --debug option.

Error log from 5.0.58 package, but bug is repeatable with current BZR sources:

Version: '5.0.58-enterprise-gpl-debug'  socket: '/tmp/mysql_ssmirnova_sol.sock'  port: 33051  MySQL Enterprise Server - Debug (GPL)
080703 21:58:09 - 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=16384
read_buffer_size=262144
max_used_connections=1
max_connections=100
threads_connected=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 32016 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

How to repeat:
Start mysqld as:

./libexec/mysqld --defaults-file=support-files/my-small.cnf --basedir=. --datadir=./data --socket=/tmp/mysql_ssmirnova_sol.sock --port=33051 --log-error --debug &

Connect to it, then create a table:

$  ./bin/mysql -uroot --socket=/tmp/mysql_ssmirnova_sol.sock test                 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.0.58-enterprise-gpl-debug

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

mysql> CREATE TABLE `t1` (`id` int(11) NOT NULL auto_increment,`c0` int(11) NOT NULL,`c1` char(24) default NULL,PRIMARY KEY  (`id`)) ENGINE=MyISAM;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql_ssmirnova_sol.sock' (146)
ERROR: 
Can't connect to the server

mysql> \q

I just filed a new bug report Bug #43445 which might be the same as this.

Bug #43445 was marked as duplicate of this one.

Bug #43445 contains patch for this.

To avoid misunderstanding: server crashed executing almost any SQL statement.

Referring to the comment on 43445: it's not relevant what the test (in this case 'alias') does, the server crashes during the pre-test check_testcase. Any test would fail, even a noop test.

Also, my "patch" in this report is not a patch to fix the bug, it just shows what I had to do to circumvent it on Solaris.

Bug #58380 was marked as duplicate of this one.

Can we please have a callstack ?

Here's a recent call stack from running test '1st' on 5.1. When I've tested this before, I found that if I patched this call, it would fail somewhere else.

--------------
current thread: t@3
  [1] _lwp_kill(0x3, 0xb, 0xffffff4c2b7543a0, 0x0, 0x0, 0x0), at 0xfffffd7fff2242aa 
  [2] thr_kill(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff2188cd 
=>[3] my_write_core(sig = 11), line 426 in "stacktrace.c"
  [4] handle_segfault(sig = 11), line 2609 in "mysqld.cc"
  [5] __sighndlr(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff21b076 
  [6] call_user_handler(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff20dfaf 
  [7] sigacthandler(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff20e1be 
  ---- called from signal handler with signal 11 (SIGSEGV) ------
  [8] strlen(0x0, 0x0, 0xe60592, 0x0, 0x0, 0x73), at 0xfffffd7fff18a9e0 
  [9] _ndoprnt(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff1db906 
  [10] vfprintf(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff1df5a7 
  [11] _db_doprnt_(format = 0xe6058b "name: '%s'", ... = 0xa47426, ...), line 1164 in "dbug.c"
  [12] mysql_change_db(thd = 0x11ee3b0, new_db_name = 0xfffffd7fff028880, force_switch = true), line 1605 in "sql_db.cc"
  [13] db_load_routine(thd = 0x11ee3b0, type = 2, name = 0xfffffd7fff029d60, sphp = 0xfffffd7fff029d50, sql_mode = 0, params = 0xe82017 "", returns = 0xe82018 "", body = 0x1207f48 "BEGIN    SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES     WHERE variable_name != 'timestamp' ORDER BY VARIABLE_NAME;    SELECT * FROM INFORMATION_SCHEMA.SCHEMATA;    SELECT table_name AS tables_in_test FROM INFORMATION_SCHEMA.TABLES     WHERE table_schema='test';    SELECT CONCAT(table_schema, '.', table_name) AS tables_in_mysql     FROM INFORMATION_SCHEMA.TABLES       WHERE table_schema='mysql' AND table_name != 'ndb_apply_status'         ORDER BY tables_in_mysql;   SELECT CONCAT(table_schema, '.', ta" ..., chistics = STRUCT, definer = 0x1208490 "root@localhost", created = 20110203164350LL, modified = 20110203164350LL, creation_ctx = 0x12084f0), line 804 in "sp.cc"
  [14] db_find_routine(thd = 0x11ee3b0, type = 2, name = 0xfffffd7fff029d60, sphp = 0xfffffd7fff029d50), line 670 in "sp.cc"
  [15] sp_cache_routines_and_add_tables_aux(thd = 0x11ee3b0, lex = 0x11efd70, start = 0x1207ee0, first_no_prelock = true), line 1938 in "sp.cc"
  [16] sp_cache_routines_and_add_tables(thd = 0x11ee3b0, lex = 0x11efd70, first_no_prelock = true), line 1977 in "sp.cc"
  [17] open_tables(thd = 0x11ee3b0, start = 0xfffffd7fff02a220, counter = 0xfffffd7fff02a208, flags = 0), line 4538 in "sql_base.cc"
  [18] open_and_lock_tables_derived(thd = 0x11ee3b0, tables = (nil), derived = true), line 5042 in "sql_base.cc"
  [19] mysql_execute_command(thd = 0x11ee3b0), line 4419 in "sql_parse.cc"
  [20] mysql_parse(thd = 0x11ee3b0, rawbuf = 0x1207dc0 "call mtr.check_testcase()", length = 25U, found_semicolon = 0xfffffd7fff02ea20), line 6075 in "sql_parse.cc"
  [21] dispatch_command(command = COM_QUERY, thd = 0x11ee3b0, packet = 0x11ffd71 "call mtr.check_testcase()", packet_length = 25U), line 1261 in "sql_parse.cc"
  [22] do_command(thd = 0x11ee3b0), line 889 in "sql_parse.cc"
  [23] handle_one_connection(arg = 0x11ee3b0), line 1149 in "sql_connect.cc"
  [24] _thrp_setup(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff21acf5 
  [25] _lwp_start(0x0, 0x0, 0x0, 0x0, 0x0, 0x0), at 0xfffffd7fff21afb0 
--------------------

Thanks Bjorn !

This crash is most likely caused by calling vfprintf() with a NULL pointer as the value for a string argument ("%s"). This seems to be handled on most platforms (eg. Linux) but not on some Solaris versions.

The same problem has been fixed in MySQL 5.5 in Bug#54478. This fix replaces the calls to vfprintf() with our own "platform independent" version of my_vsnprintf. This fix relies on several dbug extensions that was implemented for 6.0 and which have been backported to 5.5 (see change set 
serg@mysql.com-20091030181358-215e0ghcyjohzl09).

My guess is that for fixing this in MySQL 5.1 the easiest is to find all places where this crash occurs and do changes like this:

Before (line 1605 in sql_db.cc):

  DBUG_PRINT("enter",("name: '%s'", new_db_name->str));

after:

  DBUG_PRINT("enter",("name: '%s'", new_db_name->str ? new_db_name->str : "(NULL)"));

(yes, it does look ugly) - and please do not merge these changes to 5.5.

Ah, OK. For the record, I stumbled on this (again) when testing a fix in 5.1 but it just means I have to test it on Linux instead. It's not critical for me to have this fixed in 5.1 as long as it's in 5.5.

Closing this bug as duplicate of Bug#54478.
Bug#54478 was fixed in 5.5.7 and since this bug is triaged for trunk,
there is nothing left to do here.