| Bug #49487 | crash with explain extended and group_concat in a derived table \o/ | ||
|---|---|---|---|
| Submitted: | 6 Dec 2009 10:24 | Modified: | 20 Jun 2010 17:51 |
| Reporter: | Shane Bester (Platinum Quality Contributor) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Optimizer | Severity: | S1 (Critical) |
| Version: | 5.0.88,5.1.41, 5.1.43 | OS: | Any |
| Assigned to: | Tatiana Azundris Nuernberg | CPU Architecture: | Any |
| Tags: | explain extended, group_concat, valgrind | ||
[6 Dec 2009 10:24]
Shane Bester
[6 Dec 2009 10:28]
Valeriy Kravchuk
Verified just as described: Version: '5.1.43-debug-log' socket: '/tmp/mysql.sock' port: 3306 Source distribution 091206 12:26:25 - 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=8384512 read_buffer_size=131072 max_used_connections=2 max_threads=151 threads_connected=1 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337715 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd: 0x10a3418 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... stack_bottom = 0xb026af64 thread_stack 0x30000 0 mysqld 0x0058bdc2 my_print_stacktrace + 45 1 mysqld 0x000fd932 handle_segfault + 882 2 libSystem.B.dylib 0x940472bb _sigtramp + 43 3 ??? 0xffffffff 0x0 + 4294967295 4 mysqld 0x000430d3 _ZN22Item_func_group_concat5printEP6String15enum_query_type + 181 5 mysqld 0x0001c0c6 _ZN4Item17print_item_w_nameEP6String15enum_query_type + 48 6 mysqld 0x001b042c _ZN13st_select_lex5printEP3THDP6String15enum_query_type + 700 7 mysqld 0x00005ea5 _ZN18st_select_lex_unit5printEP6String15enum_query_type + 225 8 mysqld 0x001afcb7 _ZN10TABLE_LIST5printEP3THDP6String15enum_query_type + 337 9 mysqld 0x001b003a _ZN10TABLE_LIST5printEP3THDP6String15enum_query_type + 1236 10 mysqld 0x001b0490 _ZN13st_select_lex5printEP3THDP6String15enum_query_type + 800 11 mysqld 0x00005ea5 _ZN18st_select_lex_unit5printEP6String15enum_query_type + 225 12 mysqld 0x0010fbd8 _Z20prepare_schema_tableP3THDP6st_lexP11Table_ident18enum_schema_tables + 1822 13 mysqld 0x00116cfc _Z21mysql_execute_commandP3THD + 2970 14 mysqld 0x00120e8c _Z11mysql_parseP3THDPKcjPS2_ + 622 15 mysqld 0x00121c7a _Z16dispatch_command19enum_server_commandP3THDPcj + 3106 16 mysqld 0x00123084 _Z10do_commandP3THD + 666 17 mysqld 0x0010d7df handle_one_connection + 385 18 libSystem.B.dylib 0x9400c095 _pthread_start + 321 19 libSystem.B.dylib 0x9400bf52 thread_start + 34 Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x109da28 = explain extended select 1 from (select distinct group_concat(`td`.`a`) from `t1`,`t1` as `td` group by `td`.`a` ) as `d`,`t1` thd->thread_id=32 thd->killed=NOT_KILLED
[9 Dec 2009 8:03]
Tatiana Azundris Nuernberg
le sigh. 0x0000000100028646 in Item_field::print (this=0x101079a18, str=0x1034549e0) at item.cc:5296 (gdb) print field->table $1 = (st_table *) 0x8f8f8f8f8f8f8f8f 0x0000000100028646 in Item_field::print (this=0x101079a18, str=0x1034549e0) at item.cc:5296 (gdb) print field->table $1 = (st_table *) 0x8f8f8f8f8f8f8f8f (gdb) bt #0 0x0000000100028646 in Item_field::print (this=0x101079a18, str=0x1034549e0) at item.cc:5296 #1 0x0000000100035c28 in Item_func_group_concat::print (this=0x10385b8b8, str=0x1034549e0) at item_sum.cc:3548 #2 0x00000001000212ec in Item::print_item_w_name (this=0x10385b8b8, str=0x1034549e0) at item.cc:446 #3 0x000000010014c086 in st_select_lex::print (this=0x10385b0b8, thd=0x103821228, str=0x1034549e0) at sql_select.cc:16081 #4 0x000000010000f76e in st_select_lex_unit::print (this=0x10385b3b0, str=0x1034549e0) at sql_lex.cc:1626 #5 0x000000010014b924 in TABLE_LIST::print (this=0x10385c7f8, thd=0x103821228, str=0x1034549e0) at sql_select.cc:15974 #6 0x000000010014bd7c in print_join (thd=0x103821228, str=0x1034549e0, tables=0x103822b78) at sql_select.cc:15863 #7 0x000000010014c0df in st_select_lex::print (this=0x1038229d0, thd=0x103821228, str=0x1034549e0) at sql_select.cc:16092 #8 0x000000010000f76e in st_select_lex_unit::print (this=0x103822628, str=0x1034549e0) at sql_lex.cc:1626 #9 0x00000001000f4f97 in mysql_execute_command (thd=0x103821228) at sql_parse.cc:2886 #10 0x00000001000fdc38 in mysql_parse (thd=0x103821228, inBuf=0x10385ac38 "explain extended select 1 from (select distinct group_concat(`td`.`a`) from `t1`,`t1` as `td` group by `td`.`a` ) as `d`,`t1`", length=126, found_semicolon=0x103455a38) at sql_parse.cc:6459 #11 0x00000001000fea75 in dispatch_command (command=COM_QUERY, thd=0x103821228, packet=0x103851029 "", packet_length=127) at sql_parse.cc:1959 Interestingly, #9 0x00000001000f4f97 in mysql_execute_command (thd=0x103821228) at sql_parse.cc:2886 (gdb) print res $2 = 0 This implies that this is, after a fashion, different from the last EXPLAIN EXTENDED bug; that one resulted because we had detected the query being bogus during the setup phase and had consequently stopped processing it; trying to print/deref the only partly setup query let to badness. As the !res above suggests, this time, the query is valid -- to whit: mysql> select 1 from (select distinct group_concat(`td`.`a`) from `t1`,`t1` as `td` group by `td`.`a` ) as `d`,`t1`; +---+ | 1 | +---+ | 1 | | 1 | +---+ 2 rows in set (0.02 sec) mysql> explain select 1 from (select distinct group_concat(`td`.`a`) from `t1`,`t1` as `td` group by `td`.`a` ) as `d`,`t1`; +----+-------------+------------+--------+---------------+------+---------+------+------+-------------------------------------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+------------+--------+---------------+------+---------+------+------+-------------------------------------------+ | 1 | PRIMARY | <derived2> | system | NULL | NULL | NULL | NULL | 1 | | | 1 | PRIMARY | t1 | ALL | NULL | NULL | NULL | NULL | 2 | | | 2 | DERIVED | t1 | ALL | NULL | NULL | NULL | NULL | 2 | Using temporary; Using filesort; Distinct | | 2 | DERIVED | td | ALL | NULL | NULL | NULL | NULL | 2 | Distinct | +----+-------------+------------+--------+---------------+------+---------+------+------+-------------------------------------------+ 4 rows in set (0.05 sec) This shows that having been more conservative on the previous fix (ie, always failing EXPLAIN EXTENDED if the query's wonky) would not have prevented this bug from occurring.
[9 Dec 2009 8:31]
Tatiana Azundris Nuernberg
3539 void Item_func_group_concat::print(String *str)
3540 {
3541 str->append(STRING_WITH_LEN("group_concat("));
3542 if (distinct)
3543 str->append(STRING_WITH_LEN("distinct "));
3544 for (uint i= 0; i < arg_count_field; i++)
3545 {
3546 if (i)
3547 str->append(',');
3548 args[i]->print(str);
This is where we drop out. args0 is set up well enough (td.a), except that the Item_field does not, in fact, reference a proper field. Which may mean that there are other EXPLAIN EXTENDEDs that may run into this.
[9 Dec 2009 10:02]
Tatiana Azundris Nuernberg
OK, so wie set up this item_field (it's worth remembering this/f for a change).
Breakpoint 1, Item_field::Item_field (this=0x1010b9c18, f=0x102a5eb58) at item.cc:1777
As we see, not only does f look sane, it also points to a "believable record":
(gdb) print *f
$4 = {
_vptr$Field = 0x100736610,
ptr = 0x102e02e71 "",
null_ptr = 0x102e02e70 "ΓΏ",
table = 0x1010bea38,
orig_table = 0x10381aa28,
table_name = 0x10381aad0,
field_name = 0x102e02eb9 "a",
comment = {
str = 0x100535c40 "",
length = 0
},
query_id = 5,
key_start = {
map = 0
},
part_of_key = {
map = 0
},
part_of_sortkey = {
map = 0
},
unireg_check = NONE,
field_length = 11,
field_index = 1,
flags = 0,
null_bit = 2 '\002',
is_created_from_null_item = false
}
(gdb) bt
#0 Item_field::Item_field (this=0x1010b9c18, f=0x102a5eb58) at item.cc:1777
#1 0x000000010015a4eb in create_tmp_table (thd=0x101092828, param=0x1010bd6a0, fields=@0x1010bd7d0, group=0x0, distinct=false, save_sum_fields=false, select_options=2424588801, rows_limit=18446744073709551615, table_alias=0x100535c40 "") at sql_select.cc:9623
#2 0x000000010016d208 in JOIN::optimize (this=0x1010bc5d0) at sql_select.cc:1419
#3 0x000000010016efce in mysql_select (thd=0x101092828, rref_pointer_array=0x1038034e0, tables=0x103803f78, wild_num=0, fields=@0x1038033c0, conds=0x0, og_num=1, order=0x0, group=0x103804668, having=0x0, proc_param=0x0, select_options=2424588801, result=0x1010bc4e8, unit=0x1038035b0, select_lex=0x1038032b8) at sql_select.cc:2334
#4 0x0000000100284f45 in mysql_derived_filling (thd=0x101092828, lex=0x101093b98, orig_table_list=0x1038049f8) at sql_derived.cc:264
#5 0x0000000100284cbe in mysql_handle_derived (lex=0x101093b98, processor=0x100284d4e <mysql_derived_filling(THD*, st_lex*, TABLE_LIST*)>) at sql_derived.cc:56
#6 0x000000010013bfe0 in open_and_lock_tables (thd=0x101092828, tables=0x1038049f8) at sql_base.cc:3049
#7 0x00000001000f4e55 in mysql_execute_command (thd=0x101092828) at sql_parse.cc:2866
#8 0x00000001000fdc38 in mysql_parse (thd=0x101092828, inBuf=0x103802e38 "explain extended select 1 from (select distinct group_concat(`td`.`a`) from `t1`,`t1` as `td` group by `td`.`a` ) as `d`,`t1`", length=126, found_semicolon=0x103455a38) at sql_parse.cc:6459
#9 0x00000001000fea75 in dispatch_command (command=COM_QUERY, thd=0x101092828, packet=0x1010b4629 "explain extended select 1 from (select distinct group_concat(`td`.`a`) from `t1`,`t1` as `td` group by `td`.`a` ) as `d`,`t1`", packet_length=127) at sql_parse.cc:1959
Now this after we ran into the error (so take with a dose of salt):
Looks like this is the same variable:
(gdb) print this
$11 = (Item_field * const) 0x1010b9c18
(gdb) print this->field
$12 = (Field *) 0x102a5eb58
However while this/f are the same, the memory/record for field looks like rubbish:
(gdb) print *this->field
$13 = {
_vptr$Field = 0x8f8f8f8f8f8f8f8f,
ptr = 0x8f8f8f8f8f8f8f8f <Address 0x8f8f8f8f8f8f8f8f out of bounds>,
null_ptr = 0x8f8f8f8f8f8f8f8f <Address 0x8f8f8f8f8f8f8f8f out of bounds>,
table = 0x8f8f8f8f8f8f8f8f,
orig_table = 0x8f8f8f8f8f8f8f8f,
table_name = 0x8f8f8f8f8f8f8f8f,
field_name = 0x8f8f8f8f8f8f8f8f <Address 0x8f8f8f8f8f8f8f8f out of bounds>,
etc.
So by that token it looks like the field got set up properly, but maybe dested along the way?
[9 Dec 2009 10:18]
MySQL Verification Team
for what it's worth, group_concat() is the only function that causes this crash in my random tests with all functions.
[10 Dec 2009 2:12]
Tatiana Azundris Nuernberg
I can add some random pointers from last night to that (which I hope to yea or nay today): - the probablem is in the warning/note that has the re-created query in it, not the regular EXPLAIN table. (Duh.) - we go kablooie because the Item_field's field is no longer good. - it appears at first glance like the sum-function (and possibly other group-related fu) in create-temp-table allocate the item and its field on different mem-roots, which leads to different lifetimes (with the create_temp_field-generated field going out of scope when the temp table goes). - independent of how many contexts we set up such a short-lived field for, the group_concat()-print may (or may not) be the only context wherein we actually try to deref/print that field. - interestingly, if field==NULL in such a context, the query in the Note is perfectly fine (i.e., complete and correct), which implies that if the field wouldn't expire prematurely in the test-case, it would satisfy the first part of the if() in Item_field::print() but not the second (as in, ->field would be set (and for a change, pointing to still-valid memory), but field->table->const_table would be false). - this of course warrants some more investigation into the const-case before we decide between trying a different, NULLing the ref when the field goes out of scope, etc. Nu, that's enough last episode recap, someone play the title theme already!
[17 Feb 2010 11:22]
Tatiana Azundris Nuernberg
We could
if ((tmp_table_param != NULL) && (args[i]->type() == FIELD_ITEM))
((Item_ident *) args[i])->Item_ident::print(str);
else
args[i]->print(str);
but we should probably port the fix for Bug#43354 instead.
[17 Feb 2010 17:03]
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/100652 2844 Tatiana A. Nurnberg 2010-02-17 Bug#49487: crash with explain extended and group_concat in a derived table When EXPLAIN EXTENDED tries to print column names, it checks whether the referenced table is CONST (in which case, the column's value rather than its name will be printed). If no proper table is reference (i.e. because a derived table was used that has since gone out of scope), this will fail spectacularly. This ports an equivalent of the fix for Bug 43354. @ mysql-test/r/func_gconcat.result Show that EXPLAIN EXTENDED on a GROUP_CONCAT() on a derived table no longer crashes the server. @ mysql-test/t/func_gconcat.test Show that EXPLAIN EXTENDED on a GROUP_CONCAT() on a derived table no longer crashes the server. @ sql/item_sum.cc Do not de-ref what cannot be, that is, temp-tables that have gone away. This is of questionable utility anyway, since our deref has the sole purpose of checking whether the table is const (in which case, we'll substitute the column with its value in EXPLAIN EXTENDED - that is all).
[17 Feb 2010 17:03]
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/100653 2844 Tatiana A. Nurnberg 2010-02-17 Bug#49487: crash with explain extended and group_concat in a derived table In EXPLAIN EXTENDED, we tried to print item-fields that no longer were referring to a proper table at that time. This happened when the table was derived and had gone out of scope at the time of the printing. Ports a variant of Bug 43354. @ mysql-test/r/func_gconcat.result Show that the #49487 no longer exists / crashes the server (and that the output of similar-but-different tests, i.e. those that don't use temp-tables, remains unchanged). @ mysql-test/t/func_gconcat.test Show that the #49487 no longer exists / crashes the server (and that the output of similar-but-different tests, i.e. those that don't use temp-tables, remains unchanged). @ sql/item_sum.cc use the argument list copy only if it's initialized
[19 Feb 2010 15:17]
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/100885 2844 Tatiana A. Nurnberg 2010-02-19 Bug#49487: crash with explain extended and group_concat in a derived table When EXPLAIN EXTENDED tries to print column names, it checks whether the referenced table is CONST (in which case, the column's value rather than its name will be printed). If no proper table is reference (i.e. because a derived table was used that has since gone out of scope), this will fail spectacularly. This ports an equivalent of the fix for Bug 43354. @ mysql-test/r/func_gconcat.result Show that EXPLAIN EXTENDED on a GROUP_CONCAT() on a derived table no longer crashes the server. @ mysql-test/t/func_gconcat.test Show that EXPLAIN EXTENDED on a GROUP_CONCAT() on a derived table no longer crashes the server. @ sql/item_sum.cc Do not de-ref what cannot be, that is, temp-tables that have gone away. This is of questionable utility anyway, since our deref has the sole purpose of checking whether the table is const (in which case, we'll substitute the column with its value in EXPLAIN EXTENDED - that is all).
[20 Feb 2010 16:57]
Tatiana Azundris Nuernberg
Concat ... is the answer ... is the reason that everything happens.
[22 Feb 2010 12:51]
Tatiana Azundris Nuernberg
queued for 5.1.45, 6.0.14
[1 Mar 2010 8:46]
Bugs System
Pushed into 5.1.45 (revid:joro@sun.com-20100301083827-xnimmrjg6bh33o1o) (version source revid:azundris@mysql.com-20100222123150-0dgmbmlh2tu7zinq) (merge vers: 5.1.45) (pib:16)
[2 Mar 2010 14:34]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100302142746-u1gxdf5yk2bjrq3e) (version source revid:alik@sun.com-20100225090938-2j5ybqoau570mytu) (merge vers: 6.0.14-alpha) (pib:16)
[2 Mar 2010 14:40]
Bugs System
Pushed into 5.5.3-m2 (revid:alik@sun.com-20100302072233-t3uqgjzdukt1pyhe) (version source revid:alexey.kopytov@sun.com-20100223132645-fj9ybhpzs9fl1voe) (merge vers: 5.5.2-m2) (pib:16)
[2 Mar 2010 14:45]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100302072432-k8xvfkgcggkwgi94) (version source revid:alik@sun.com-20100224135227-rcqs9pe9b2in80pf) (pib:16)
[9 Mar 2010 6:26]
Tatiana Azundris Nuernberg
pushed also to -bugteam for 5.0.91 (and NULL-merged upwards)
[26 Mar 2010 16:40]
MySQL Verification Team
see bug #52397 ...
[8 Apr 2010 18:24]
Paul DuBois
Noted in 5.1.45, 5.5.3, 6.0.14 changelogs. EXPLAIN EXTENDED crashed trying to print column names for a subquery in the FROM clause when the table had gone out of scope.
[18 May 2010 15:37]
Paul DuBois
Noted in 5.0.91 changelog.
[17 Jun 2010 11:50]
Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:28]
Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100609140708-52rvuyq4q500sxkq) (merge vers: 5.1.45-ndb-6.2.19) (pib:16)
[17 Jun 2010 13:15]
Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
