| Bug #33251 | MySQL segfault after select in optimizer opt_range.cc -Field_string:type method. | ||
|---|---|---|---|
| Submitted: | 14 Dec 2007 19:41 | Modified: | 14 Oct 2008 16:18 |
| Reporter: | Dave Juntgen | Email Updates: | |
| Status: | No Feedback | Impact on me: | |
| Category: | MySQL Server: Optimizer | Severity: | S2 (Serious) |
| Version: | 5.0.52 5.0.54 5.0.58 5.0.66a | OS: | Linux (x86) |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | field.h get_mm_leaf, opt_range.cc, query, segfault | ||
[14 Dec 2007 19:41]
Dave Juntgen
[17 Dec 2007 14:22]
Susanne Ebrecht
Sorry, but we are not able to verify this, without the knowing, how to repeat it. Many thanks for choosing MySQL.
[17 Dec 2007 14:22]
Hartmut Holzgraefe
Stack trace after running it through "c++filt" to revert C++ linker symbol name mangling: 0x80a6843 handle_segfault + 511 0x8316168 pthread_sighandler + 184 0x83c8fe2 Field_string::type(void) const + 26 0x81354f7 get_mm_leaf(st_qsel_param *, Item *, Field *, st_key_part *, Item_func::Functy pe, Item *) + 1255 0x8134f44 get_mm_parts(st_qsel_param *, Item *, Field *, Item_func::Functype, Item *, It em_result) + 388 0x8134c7f get_mm_tree(st_qsel_param *, Item *) + 1599 0x8131d94 SQL_SELECT::test_quick_select(THD *, Bitmap<64>, unsigned long long, unsigned long long, bool) + 1436 0x80eae6d get_quick_record_count(THD *, SQL_SELECT *, st_table *, Bitmap<64> const *, un signed long long) + 69 0x80ec17e make_join_statistics(JOIN *, TABLE_LIST *, Item *, st_dynamic_array *) + 4822 0x80e7cb5 JOIN::optimize(void) + 1185 0x80ead2f mysql_select__FP3THDPPP4ItemP10TABLE_LISTUiRt4List1Z4ItemP4ItemUiP8st_orderT7T5T7UxP13se le ct_resultP18st_select_lex_unitP13st_s + 815 0x80e6b44 handle_select(THD *, st_lex *, select_result *, unsigned long) + 244 0x80b8ce8 mysql_execute_command(THD *) + 1508 0x80bf18f mysql_parse(THD *, char const *, unsigned int, char const **) + 255 0x80b726b dispatch_command(enum_server_command, THD *, char *, unsigned int) + 1803 0x80b6b53 do_command(THD *) + 203 0x80b602b handle_one_connection + 819 0x831391c pthread_start_thread + 220 0x83629ca thread_start + 4
[29 Dec 2007 19:32]
Valeriy Kravchuk
Please, send the results of: EXPLAIN SELECT rule_id,rule_name,warning,macro,resolve_layout_id FROM scripted_rules WHERE rule_name='MI : Aspirin'\G SHOW CREATE TABLE scripted_rules; SHOW TABLE STATUS LIKE 'scripted_rules';
[21 Jan 2008 23:00]
Dave Juntgen
Hi Valeriy,
Thanks for the response. I'm curious to how you got the query from the dump? Is there away I can do this?
I can't directly answer your question because there are several databases on the system that have the scripted_rules table. I can tell you that I am now having the same problem on a 32bit system.
Here is its stack dump / trace from a 32bit system running 5.0.52:
0x81263b4 handle_segfault + 356
0x4004f67e _end + 934745582
0x819c611 filesort(THD*, st_table*, st_sort_field*, unsigned, SQL_SELECT*, unsigned long, unsigned long*) + 669
0x8166820 create_sort_index(THD*, JOIN*, st_order*, unsigned long, unsigned long) + 276
0x815d650 JOIN::exec() + 3492
0x815e25c mysql_select(THD*, Item***, st_table_list*, unsigned, List<Item>&, Item*, unsigned, st_order*, st_order*, Item*, st_order*
, uns + 380
0x815a8d2 handle_select(THD*, st_lex*, select_result*) + 210
0x8138fe2 mysql_execute_command(THD*) + 902
0x813e2a6 mysql_parse(THD*, char*, unsigned) + 166
0x8137c6a dispatch_command(enum_server_command, THD*, char*, unsigned) + 846
0x81378de do_command(THD*) + 122
0x81370d5 handle_one_connection + 829
0x4004aa21 _end + 934726033
0x401dd527 _end + 936375447
I have taken one database from that system that I know the query you listed is being used and here are the results:
mysql> SHOW CREATE TABLE scripted_rules;
+----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| scripted_rules | CREATE TABLE `scripted_rules` (
`rule_id` int(10) unsigned NOT NULL auto_increment,
`rule_name` char(255) NOT NULL default '',
`warning` char(255) NOT NULL default '',
`macro` tinyint(3) unsigned NOT NULL default '0',
`resolve_layout_id` int(10) unsigned NOT NULL default '0',
PRIMARY KEY (`rule_id`),
KEY `idx2` (`rule_name`(10))
) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
+----------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
mysql> SHOW TABLE STATUS LIKE 'scripted_rules';
+----------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+----------+----------------+---------+
| Name | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time | Update_time | Check_time | Collation | Checksum | Create_options | Comment |
+----------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+----------+----------------+---------+
| scripted_rules | MyISAM | 7 | Fixed | 0 | 0 | 0 | 2233382993919 | 1024 | 0 | 1 | 2005-04-21 12:03:02 | 2007-11-09 18:31:27 | 2007-11-09 18:31:27 | latin1_swedish_ci | NULL | | |
+----------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+----------+----------------+---------+
1 row in set (0.00 sec)
mysql> EXPLAIN SELECT rule_id,rule_name,warning,macro,resolve_layout_id FROM scripted_rules WHERE rule_name='MI : Aspirin'\G
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: NULL
type: NULL
possible_keys: NULL
key: NULL
key_len: NULL
ref: NULL
rows: NULL
Extra: Impossible WHERE noticed after reading const tables
1 row in set (0.00 sec)
Thanks for your help!
--Dave
[21 Jan 2008 23:37]
Dave Juntgen
Hi - the stack trace for the 32bit system is wrong...this is the correct one: 0x80a6843 handle_segfault + 511 0x8316168 pthread_sighandler + 184 0x83c8fe2 Field_string::type(void) const + 26 0x81354f7 get_mm_leaf(st_qsel_param *, Item *, Field *, st_key_part *, Item_func::Functype, Item *) + 1255 0x8134f44 get_mm_parts(st_qsel_param *, Item *, Field *, Item_func::Functype, Item *, Item_result) + 388 0x8134c7f get_mm_tree(st_qsel_param *, Item *) + 1599 0x8131d94 SQL_SELECT::test_quick_select(THD *, Bitmap<64>, unsigned long long, unsigned long long, bool) + 1436 0x80eae6d get_quick_record_count(THD *, SQL_SELECT *, st_table *, Bitmap<64> const *, unsigned long long) + 69 0x80ec17e make_join_statistics(JOIN *, TABLE_LIST *, Item *, st_dynamic_array *) + 4822 0x80e7cb5 JOIN::optimize(void) + 1185 0x80ead2f mysql_select(THD *, Item ***, TABLE_LIST *, unsigned int, List<Item> &, Item *, unsigned int, st_order *, st_order *, Item *, s + 815 0x80e6b44 handle_select(THD *, st_lex *, select_result *, unsigned long) + 244 0x80b8ce8 mysql_execute_command(THD *) + 1508 0x80bf18f mysql_parse(THD *, char const *, unsigned int, char const **) + 255 0x80b726b dispatch_command(enum_server_command, THD *, char *, unsigned int) + 1803 0x80b6b53 do_command(THD *) + 203 0x80b602b handle_one_connection + 819 0x831391c pthread_start_thread + 220 0x83629ca thread_start + 4
[22 Jan 2008 0:01]
Dave Juntgen
Hi - please ingore the question regarding how to find the query, its in the stack trace. ;) Also - could this bug be related to <a href="http://bugs.mysql.com/bug.php?id=31694">31694</a>?
[17 Feb 2008 17:50]
Valeriy Kravchuk
Can you try to repeat with a newer version, 5.0.54a? In case of the same crash, please, upload data for your scripted_rules table (as private file or to our FTP site).
[18 Mar 2008 0:02]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
[20 Mar 2008 10:03]
Susanne Ebrecht
We still need to know if you tried this with newer version and don't have this problems anymore.
[20 Apr 2008 23:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
[22 Apr 2008 20:24]
Dave Juntgen
It took a while but I have more detail. I have 3 different systems runn 5.0.52, 54 and 58. I even have a debug core (See attached). The funny thing is that I don't see this problem the two 64bit machines that I have been running for almost a year now. I just can't make sense to why I wouldn't see problem there too... Anyway - there are plenty of examples...
[23 Apr 2008 13:53]
Dave Juntgen
Another crash but no core file. Question, If I have the following in my.cnf and the ulimit set to dump core I should get core right? [mysqld_safe] core-file-size=10000000 mysqld=mysqld-debug ----------------------------------------------------------------------------- 080423 7:14:16 - 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=524288000 read_buffer_size=10485760 max_used_connections=22 max_connections=100 threads_connected=9 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 2560000 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x95a526e8 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=0x972977e8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x8191827 0x817f2a1 0x823abf8 0x823a61e 0x823a2ce 0x8236a00 0x81dd259 0x81de5e1 0x81d997c 0x81dd077 0x81d84eb 0x81a8257 0x81ae9f0 0x81a6a4e 0x81a63c4 0x81a5672 0xb7f1c3db 0xb7e3a26e New value of fp=(nil) failed sanity check, terminating stack trace! Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.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 Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x95bcef0 = SELECT code FROM mrxdb_diseases WHERE short_desc='Lung mass' thd->thread_id=73635 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash. Number of processes running now: 0 080423 07:14:17 mysqld restarted 080423 7:14:17 [Note] /usr/local/mysql/bin/mysqld-debug: ready for connections. Version: '5.0.54-enterprise-debug-log' socket: '/tmp/mysql.sock' port: 3306 MySQL Enterprise Server - Debug (Commercial) ------------------------------------------------------------------------------ STACK TRACE: 0x8191827 handle_segfault + 427 0x817f2a1 Field_string::type() const + 23 0x823abf8 get_mm_leaf(st_qsel_param*, Item*, Field*, st_key_part*, Item_func::Functype, Item*) + 1226 0x823a61e get_mm_parts(st_qsel_param*, Item*, Field*, Item_func::Functype, Item*, Item_result) + 482 0x823a2ce get_mm_tree(st_qsel_param*, Item*) + 1590 0x8236a00 SQL_SELECT::test_quick_select(THD*, Bitmap<64u>, unsigned long long, unsigned long long, bool) + 1828 0x81dd259 get_quick_record_count(THD*, SQL_SELECT*, st_table*, Bitmap<64u> const*, unsigned long long) + 179 0x81de5e1 make_join_statistics(JOIN*, TABLE_LIST*, Item*, st_dynamic_array*) + 4799 0x81d997c JOIN::optimize() + 1754 0x81dd077 mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order* + 417 0x81d84eb handle_select(THD*, st_lex*, select_result*, unsigned long) + 251 0x81a8257 mysql_execute_command(THD*) + 1721 0x81ae9f0 mysql_parse(THD*, char const*, unsigned int, char const**) + 334 0x81a6a4e dispatch_command(enum_server_command, THD*, char*, unsigned int) + 1662 0x81a63c4 do_command(THD*) + 436 0x81a5672 handle_one_connection + 812 0xb7f1c3db _end + -1349751797 0xb7e3a26e _end + -1350677858
[29 Apr 2008 22:39]
Dave Juntgen
Update: I think I may have found the bug, I had another crash occur on our dev system which also produced a core file. I'm starting to think that its a cross database query problem. I always keep seeing a query outside of the connected database.
============
[root@zeus /tmp]# gdb /usr/local/mysql/bin/mysqld-debug core.mysqld-debug.29465
GNU gdb Red Hat Linux (6.5-15.fc6rh)
Copyright (C) 2006 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu"...Using host libthread_db library "/lib/libthread_db.so.1".
warning: exec file is newer than core file.
Core was generated by `/usr/local/mysql/bin/mysqld-debug --basedir=/usr/local/mysql --datadir=/usr/loc'.
Program terminated with signal 11, Segmentation fault.
#0 0x0841cdd4 in Field_string::type (this=0x8a231e8) at field.h:1076
1076 field.h: No such file or directory.
in field.h
(gdb) where
#0 0x0841cdd4 in Field_string::type (this=0x8a231e8) at field.h:1076
#1 0x081560c7 in get_mm_leaf (param=0xbfa7cad8, conf_func=0x8b7ab30, field=0x8a231e8, key_part=0x8b46a60, type=EQ_FUNC,
value=0x8b79ad8) at opt_range.cc:4396
#2 0x08155af4 in get_mm_parts (param=0xbfa7cad8, cond_func=0x8b7ab30, field=0x898de58, type=EQ_FUNC, value=0x8b79ad8,
cmp_type=STRING_RESULT) at opt_range.cc:4211
#3 0x08155774 in get_mm_tree (param=0xbfa7cad8, cond=0x8b7ab30) at opt_range.cc:4157
#4 0x081518a0 in SQL_SELECT::test_quick_select (this=0x8b7af58, thd=0x8864510, keys_to_use={map = 2}, prev_tables=0,
limit=18446744073709551615, force_quick_range=false) at opt_range.cc:2066
#5 0x080fe57f in get_quick_record_count (thd=0x8864510, select=0x8b7af58, table=0x8850578, keys=0x8b7ad38,
limit=18446744073709551615) at sql_select.cc:2340
#6 0x080ff7e1 in make_join_statistics (join=<incomplete type>, tables=0x8b79880, conds=0x8b7ab30, keyuse_array=0x8b7a9d8)
at sql_select.cc:2736
#7 0x080fa9b8 in JOIN::optimize (this=<incomplete type>) at sql_select.cc:926
#8 0x080fe3f9 in mysql_select (thd=0x8864510, rref_pointer_array=0x88655f8, tables=0x8b79880, wild_num=0, fields=@0x886554c,
conds=0x8b79b38, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2156153344,
result=<incomplete type>, unit=0x8865274, select_lex=<incomplete type>) at sql_select.cc:2282
#9 0x080f93fb in handle_select (thd=0x8864510, lex=0x8865220, result=<incomplete type>, setup_tables_done_option=0)
at sql_select.cc:256
#10 0x080c6767 in mysql_execute_command (thd=0x8864510) at sql_parse.cc:2675
#11 0x080cd839 in mysql_parse (thd=0x8864510,
inBuf=0x8b796e0 "SELECT duplicate_id FROM rxdb_test.rxdb_duplicate WHERE description='3885'", length=74,
found_semicolon=0xbfa7f524) at sql_parse.cc:6097
#12 0x080c4b10 in dispatch_command (command=COM_QUERY, thd=0x8864510,
packet=0x89f7b89 "SELECT duplicate_id FROM rxdb_test.rxdb_duplicate WHERE description='3885'", packet_length=75)
at sql_parse.cc:1821
#13 0x080c43ec in do_command (thd=0x8864510) at sql_parse.cc:1595
#14 0x080c3604 in handle_one_connection (arg=0x8b71e78) at sql_parse.cc:1201
#15 0x083680ac in pthread_start_thread (arg=0xbfa7fc00) at manager.c:291
#16 0x083b5bea in thread_start ()
(gdb) frame 0
#0 0x0841cdd4 in Field_string::type (this=0x8a231e8) at field.h:1076
1076 in field.h
(gdb) print this.orig_table.s
$1 = (TABLE_SHARE *) 0x0 <<<<<<<<<<<<<<<<<<< Bad, its NULL that can't be right.
(gdb)
----------------------------------------------------------------
From src: mysqlcom-5.0.52/sql/field.h
enum_field_types type() const
{
return ((can_alter_field_type && orig_table &&
orig_table->s->db_create_options & HA_OPTION_PACK_RECORD && <<<< HERE
field_length >= 4) &&
orig_table->s->frm_version < FRM_VER_TRUE_VARCHAR ?
MYSQL_TYPE_VAR_STRING : MYSQL_TYPE_STRING);
}
====
BUG??: You can't access an element in a structure when the pointer is NULL!
BUG??: orig_table->s->db_create_options
====
[29 Apr 2008 22:48]
Dave Juntgen
Here is some info about the table being queried.
mysql> explain SELECT duplicate_id FROM rxdb_test.rxdb_duplicate WHERE description='3885';
+----+-------------+----------------+------+---------------+-------------+---------+-------+------+-------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+----------------+------+---------------+-------------+---------+-------+------+-------------+
| 1 | SIMPLE | rxdb_duplicate | ref | description | description | 11 | const | 1 | Using where |
+----+-------------+----------------+------+---------------+-------------+---------+-------+------+-------------+
1 row in set (0.00 sec)
mysql> SHOW CREATE TABLE rxdb_duplicate;
+----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| rxdb_duplicate | CREATE TABLE `rxdb_duplicate` (
`duplicate_id` int(11) NOT NULL default '0',
`description` char(60) default NULL,
`allowance` int(11) default NULL,
PRIMARY KEY (`duplicate_id`),
KEY `description` (`description`(10))
) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
+----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
mysql> SHOW TABLE STATUS LIKE 'rxdb_duplicate'\G
*************************** 1. row ***************************
Name: rxdb_duplicate
Engine: MyISAM
Version: 10
Row_format: Fixed
Rows: 679
Avg_row_length: 69
Data_length: 46851
Max_data_length: 19421773393035263
Index_length: 19456
Data_free: 0
Auto_increment: NULL
Create_time: 2008-02-08 15:23:56
Update_time: 2008-02-11 10:16:23
Check_time: 2008-04-22 17:09:04
Collation: latin1_swedish_ci
Checksum: NULL
Create_options:
Comment:
1 row in set (0.00 sec)
mysql>
[7 May 2008 16:47]
Dave Juntgen
Hi, Its been a while since I posted my bug report, is anyone listening? Your help would be greatly appreciated. Thanks, --Dave
[18 Jun 2008 5:42]
Valeriy Kravchuk
Can you, please, try to create a single, repeatable test case for this bug report? I am not sure how initial description is related to the example from the last comment, for example.
[18 Jun 2008 15:30]
Dave Juntgen
Hi, That's the problem i'm having, I can't reproduce it on demand. I know this makes it difficult for you...sorry. If you gdb the last core dump that I attached its obvious that a null pointer is be referenced. Thanks for your help.
[9 Aug 2008 6:28]
Valeriy Kravchuk
Please, check if this problem happens with a newer version, 5.0.66a or 5.0.67.
[9 Sep 2008 18:18]
Dave Juntgen
Upgraded master and slave to 5.0.66a. Replication up for 12 hours and haven't seen the typical corrupt bin-log errors but...I now have many of the following errors: [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013) 080908 22:32:42 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mysql-bin.001212' position 254187156 080908 22:32:42 [Note] Slave: connected to master 'wc_dbslave@wcdb.med-web.com:3306',replication resumed in log 'mysql-bin.001212' at position 254187156 This error is new to me, I haven't seen this before so I'm assuming it is related to the fix in 5.0.66a. Just so you know, the master/slave isn't communicating over a WAN but on a gigabit switch. I'm starting to wonder if this is a bad driver with the kernel or even hardware. So I guess that its working *now* but the errors are scary, whats next? Thanks, --Dave
[14 Sep 2008 16:18]
Valeriy Kravchuk
Next steps would be to check error log on master for restarts at the same times, upgrade kernel and drivers, and, finally, if it does not help to eliminate the problem, to check on other hardware. In any case, it seems that this bug, in optimizer, is fixed somehow in 5.0.66a. Am I correct?
[14 Oct 2008 23:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
