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:
None 
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
Description:
Y.A.E.E.C (Yet Another Explain Extended Crash):

5.1.41 stack trace:

mysqld.exe!Item_field::print()[item.cc:5674]
mysqld.exe!Item_func_group_concat::print()[item_sum.cc:3584]
mysqld.exe!Item::print_item_w_name()[item.cc:456]
mysqld.exe!st_select_lex::print()[sql_select.cc:16840]
mysqld.exe!st_select_lex_unit::print()[sql_lex.cc:2014]
mysqld.exe!TABLE_LIST::print()[sql_select.cc:16733]
mysqld.exe!print_join()[sql_select.cc:16637]
mysqld.exe!st_select_lex::print()[sql_select.cc:16851]
mysqld.exe!st_select_lex_unit::print()[sql_lex.cc:2014]
mysqld.exe!execute_sqlcom_select()[sql_parse.cc:5036]
mysqld.exe!mysql_execute_command()[sql_parse.cc:2246]
mysqld.exe!mysql_parse()[sql_parse.cc:5974]
mysqld.exe!dispatch_command()[sql_parse.cc:1233]
mysqld.exe!do_command()[sql_parse.cc:872]
mysqld.exe!handle_one_connection()[sql_connect.cc:1127]
mysqld.exe!pthread_start()[my_winthread.c:85]
mysqld.exe!_callthreadstart()[thread.c:295]
mysqld.exe!_threadstart()[thread.c:275]
kernel32.dll!BaseThreadStart()

there are multiple invalid reads reported by valgrind too.

How to repeat:
drop table if exists `t1`;
create table `t1`(`a` int)engine=myisam;
insert into `t1` values (),();

explain extended select 1 from
(select distinct group_concat(`td`.`a`)
 from `t1`,`t1` as `td` group by `td`.`a`
) as `d`,`t1`
;
[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)