Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-430

Server crashes in select_describe on EXPLAIN with materialization+semijoin, 2 nested subqueries, aggregate functions

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 5.5.25
    • Fix Version/s: 5.5.27
    • Component/s: None
    • Labels:
      None

      Description

      Note: It might belong to Timour, because the problem appeared with revno 3445 (MDEV-193), but since it requires semijoin, assigning to Sergei for starters. Please re-assign if needed.

      #3  <signal handler called>
      #4  0x000000000067097e in select_describe (join=0x3acd4b8, need_tmp_table=false, need_order=false, distinct=false, message=0x0) at sql/sql_select.cc:21369
      #5  0x0000000000641e5b in JOIN::exec (this=0x3acd4b8) at sql/sql_select.cc:2336
      #6  0x0000000000644581 in mysql_select (thd=0x39ab110, rref_pointer_array=0x3aef0a0, tables=0x3aefb18, wild_num=0, fields=..., conds=0x3ad3e08, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748612, result=0x3acc458, unit=0x3aef190, select_lex=0x3aeee48) at sql/sql_select.cc:3044
      #7  0x0000000000672e7c in mysql_explain_union (thd=0x39ab110, unit=0x3aef190, result=0x3acc458) at sql/sql_select.cc:21914
      #8  0x0000000000672b93 in select_describe (join=0x3accd38, need_tmp_table=false, need_order=false, distinct=false, message=0x0) at sql/sql_select.cc:21871
      #9  0x0000000000641e5b in JOIN::exec (this=0x3accd38) at sql/sql_select.cc:2336
      #10 0x0000000000644581 in mysql_select (thd=0x39ab110, rref_pointer_array=0x39addc8, tables=0x3aee760, wild_num=1, fields=..., conds=0x3acc2a8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748612, result=0x3acc458, unit=0x39ad498, select_lex=0x39adb70) at sql/sql_select.cc:3044
      #11 0x0000000000672e7c in mysql_explain_union (thd=0x39ab110, unit=0x39ad498, result=0x3acc458) at sql/sql_select.cc:21914
      #12 0x0000000000614255 in execute_sqlcom_select (thd=0x39ab110, all_tables=0x3aee760) at sql/sql_parse.cc:4592
      #13 0x000000000060cf7e in mysql_execute_command (thd=0x39ab110) at sql/sql_parse.cc:2189
      #14 0x0000000000616ca1 in mysql_parse (thd=0x39ab110, rawbuf=0x3aee4c8 "EXPLAIN \nSELECT * FROM t1 WHERE a = ( \nSELECT MAX(b) FROM t2 WHERE c IN ( SELECT MAX(d) FROM t3 ) \n) OR a = 10", length=110, parser_state=0x7f3e9988b500) at sql/sql_parse.cc:5736
      #15 0x000000000060a517 in dispatch_command (command=COM_QUERY, thd=0x39ab110, packet=0x3aa6141 "", packet_length=110) at sql/sql_parse.cc:1055
      #16 0x00000000006097ce in do_command (thd=0x39ab110) at sql/sql_parse.cc:794
      #17 0x000000000070ac27 in do_handle_one_connection (thd_arg=0x39ab110) at sql/sql_connect.cc:1253
      #18 0x000000000070a612 in handle_one_connection (arg=0x39ab110) at sql/sql_connect.cc:1168
      #19 0x0000000000c015ef in pfs_spawn_thread (arg=0x3b2ea30) at storage/perfschema/pfs.cc:1015
      #20 0x00007f3ea4ee8efc in start_thread (arg=0x7f3e9988c700) at pthread_create.c:304
      #21 0x00007f3ea425b59d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
      

      bzr version-info

      revision-id: psergey@askmonty.org-20120725164148-cylxnymo9d37kae7
      date: 2012-07-25 20:41:48 +0400
      build-date: 2012-08-03 23:38:22 +0400
      revno: 3473
      branch-nick: maria-5.5
      

      Also reproducible on revno 3445. Not reproducible on revno 3444.
      Reproducible with MyISAM, Aria, InnoDB.

      Minimal optimizer_switch:
      materialization=on,semijoin=on

      Default optimizer_switch:

      index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=off
      

      Test case:

      SET optimizer_switch = 'materialization=on,semijoin=on';
      
      CREATE TABLE t1 (a INT, KEY(a)) ENGINE=MyISAM;
      INSERT INTO t1 VALUES (8),(0);
      			
      CREATE TABLE t2 (b INT, c VARCHAR(1)) ENGINE=MyISAM;
      INSERT INTO t2 VALUES (4,'j'),(6,'v'); 
      
      CREATE TABLE t3 (d VARCHAR(1)) ENGINE=MyISAM;		
      INSERT INTO t3 VALUES ('b'),('c');
      
      EXPLAIN 
      SELECT * FROM t1 WHERE a = ( 
        SELECT MAX(b) FROM t2 WHERE c IN ( SELECT MAX(d) FROM t3 ) 
      ) OR a = 10;
      
      

        Gliffy Diagrams

          Attachments

            Activity

            Hide
            psergey Sergei Petrunia added a comment -

            The crash is caused by these sequence of actions:

            1. The grand-child subquery is merged into the child subquery (as a JTBM semi-join)
            2. Child subquery is executed. It's uncorrelated, so it is cleaned up right after that (see the stack trace below)
            2.1 In particular, cleanup drops the temp. table where grandchild subquery was materialized into.
            3. select_describe() runs, which attempts to print the plan for the subquery. When it reaches the JTBM-materialized table,
            it crashes because the table has already been freed.

            The stack trace of where the table is freed:
            (gdb) wher
            #0 st_join_table::cleanup (this=0x970d3e8) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:10264
            #1 0x0827ce82 in JOIN::cleanup (this=0x96fd610, full=true) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:10610
            #2 0x0827d15d in JOIN::join_free (this=0x96fd610) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:10527
            #3 0x0827d9ad in do_select (join=0x96fd610, fields=0x96fd854, table=0x0, procedure=0x0) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:15800
            #4 0x08296397 in JOIN::exec (this=0x96fd610) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:2824
            #5 0x0848e19d in subselect_single_select_engine::exec (this=0x966d4f8) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:3167
            #6 0x084908fe in Item_subselect::exec (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:640
            #7 0x084866e9 in Item_singlerow_subselect::val_int (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:1196
            #8 0x0819053c in Item::update_null_value (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item.h:1055
            #9 0x08493a94 in Item_subselect::is_null (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.h:172
            #10 0x082879fd in merge_key_fields (start=0x970e410, new_fields=0x970e42c, end=0x970e448, and_level=3) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3874
            #11 0x08287d7c in add_key_fields (join=0x96fd110, key_fields=0x8568cc08, and_level=0x8568cc14, cond=0x96fcb40, usable_tables=18446744073709551615, sargables=0x8568cebc) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:4255
            #12 0x08288c44 in update_ref_and_keys (thd=0x8b22b608, keyuse=0x96fd2f0, join_tab=0x970ddc8, tables=1, cond=0x96fcb40, normal_tables=18446744073709551615, select_lex=0x8b22d098, sargables=0x8568cebc) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:4803
            #13 0x08289f79 in make_join_statistics (join=0x96fd110, tables_list=..., conds=0x96fcb40, keyuse_array=0x96fd2f0) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3330
            #14 0x0828cca1 in JOIN::optimize (this=0x96fd110) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:1200
            #15 0x0829036c in mysql_select (thd=0x8b22b608, rref_pointer_array=0x8b22d1d8, tables=0x966b8d0, wild_num=1, fields=..., conds=0x96fcb40, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748612, result=0x96fcc68, unit=0x8b22cbe8, select_lex=0x8b22d098) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3030

            Show
            psergey Sergei Petrunia added a comment - The crash is caused by these sequence of actions: 1. The grand-child subquery is merged into the child subquery (as a JTBM semi-join) 2. Child subquery is executed. It's uncorrelated, so it is cleaned up right after that (see the stack trace below) 2.1 In particular, cleanup drops the temp. table where grandchild subquery was materialized into. 3. select_describe() runs, which attempts to print the plan for the subquery. When it reaches the JTBM-materialized table, it crashes because the table has already been freed. The stack trace of where the table is freed: (gdb) wher #0 st_join_table::cleanup (this=0x970d3e8) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:10264 #1 0x0827ce82 in JOIN::cleanup (this=0x96fd610, full=true) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:10610 #2 0x0827d15d in JOIN::join_free (this=0x96fd610) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:10527 #3 0x0827d9ad in do_select (join=0x96fd610, fields=0x96fd854, table=0x0, procedure=0x0) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:15800 #4 0x08296397 in JOIN::exec (this=0x96fd610) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:2824 #5 0x0848e19d in subselect_single_select_engine::exec (this=0x966d4f8) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:3167 #6 0x084908fe in Item_subselect::exec (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:640 #7 0x084866e9 in Item_singlerow_subselect::val_int (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:1196 #8 0x0819053c in Item::update_null_value (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item.h:1055 #9 0x08493a94 in Item_subselect::is_null (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.h:172 #10 0x082879fd in merge_key_fields (start=0x970e410, new_fields=0x970e42c, end=0x970e448, and_level=3) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3874 #11 0x08287d7c in add_key_fields (join=0x96fd110, key_fields=0x8568cc08, and_level=0x8568cc14, cond=0x96fcb40, usable_tables=18446744073709551615, sargables=0x8568cebc) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:4255 #12 0x08288c44 in update_ref_and_keys (thd=0x8b22b608, keyuse=0x96fd2f0, join_tab=0x970ddc8, tables=1, cond=0x96fcb40, normal_tables=18446744073709551615, select_lex=0x8b22d098, sargables=0x8568cebc) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:4803 #13 0x08289f79 in make_join_statistics (join=0x96fd110, tables_list=..., conds=0x96fcb40, keyuse_array=0x96fd2f0) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3330 #14 0x0828cca1 in JOIN::optimize (this=0x96fd110) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:1200 #15 0x0829036c in mysql_select (thd=0x8b22b608, rref_pointer_array=0x8b22d1d8, tables=0x966b8d0, wild_num=1, fields=..., conds=0x96fcb40, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748612, result=0x96fcc68, unit=0x8b22cbe8, select_lex=0x8b22d098) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3030
            Hide
            psergey Sergei Petrunia added a comment -

            Another thing:
            (gdb) up
            #6 0x084866e9 in Item_singlerow_subselect::val_int (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:1196
            (gdb) up
            #7 0x0819053c in Item::update_null_value (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item.h:1055
            (gdb) up
            #8 0x08493a94 in Item_subselect::is_null (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.h:172
            (gdb) up
            #9 0x082879fd in merge_key_fields (start=0x970e410, new_fields=0x970e42c, end=0x970e448, and_level=3) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3874
            (gdb) p old
            $147 = (KEY_FIELD *) 0x970e410
            (gdb) p old->val
            $149 = (Item_singlerow_subselect *) 0x966d438
            (gdb) p old->val->is_expensive()
            $151 = true

            That is:

            • the item is "expensive"
            • it is evaluated by merge_key_fields(), i.e. at optimization

            Something for Timour to look at.

            Show
            psergey Sergei Petrunia added a comment - Another thing: (gdb) up #6 0x084866e9 in Item_singlerow_subselect::val_int (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.cc:1196 (gdb) up #7 0x0819053c in Item::update_null_value (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item.h:1055 (gdb) up #8 0x08493a94 in Item_subselect::is_null (this=0x966d438) at /home/psergey/dev2/5.5-look7/sql/item_subselect.h:172 (gdb) up #9 0x082879fd in merge_key_fields (start=0x970e410, new_fields=0x970e42c, end=0x970e448, and_level=3) at /home/psergey/dev2/5.5-look7/sql/sql_select.cc:3874 (gdb) p old $147 = (KEY_FIELD *) 0x970e410 (gdb) p old->val $149 = (Item_singlerow_subselect *) 0x966d438 (gdb) p old->val->is_expensive() $151 = true That is: the item is "expensive" it is evaluated by merge_key_fields(), i.e. at optimization Something for Timour to look at.
            Hide
            pomyk Patryk Pomykalski added a comment -

            I think the problem is JOIN::join_free doing full cleanup during explain (despite what the comment in the code says):

            === modified file 'sql/sql_select.cc'
            — sql/sql_select.cc 2012-06-20 11:01:28 +0000
            +++ sql/sql_select.cc 2012-08-04 15:46:30 +0000
            @@ -10520,7 +10520,7 @@
            Optimization: if not EXPLAIN and we are done with the JOIN,
            free all tables.
            */

            • bool full= !(select_lex->uncacheable);
              + bool full= !(select_lex->uncacheable) && !(thd->lex->describe);
              bool can_unlock= full;
              DBUG_ENTER("JOIN::join_free");
            Show
            pomyk Patryk Pomykalski added a comment - I think the problem is JOIN::join_free doing full cleanup during explain (despite what the comment in the code says): === modified file 'sql/sql_select.cc' — sql/sql_select.cc 2012-06-20 11:01:28 +0000 +++ sql/sql_select.cc 2012-08-04 15:46:30 +0000 @@ -10520,7 +10520,7 @@ Optimization: if not EXPLAIN and we are done with the JOIN, free all tables. */ bool full= !(select_lex->uncacheable); + bool full= !(select_lex->uncacheable) && !(thd->lex->describe); bool can_unlock= full; DBUG_ENTER("JOIN::join_free");
            Hide
            timour Timour Katchaounov added a comment -

            The problem with expensive subquery evaluation during optimize (comment dated 2012-08-04 01:13) will be addressed by https://mariadb.atlassian.net/browse/MDEV-435.

            Show
            timour Timour Katchaounov added a comment - The problem with expensive subquery evaluation during optimize (comment dated 2012-08-04 01:13) will be addressed by https://mariadb.atlassian.net/browse/MDEV-435 .
            Hide
            psergey Sergei Petrunia added a comment -

            Patryk, agree with your suggestion.

            It's interesting that the comment above suggests there was a check for EXPLAIN in the past.
            It got removed by this change:

            timour@askmonty.org-20110704115116-cx7ibyty8uiwrpg7, Fix LP bug lp:802979
            === modified file 'sql/sql_select.cc'
            — sql/sql_select.cc 2011-06-30 03:07:24 +0000
            +++ sql/sql_select.cc 2011-07-04 11:51:16 +0000
            @@ -9620,8 +9620,7 @@ void JOIN::join_free()
            Optimization: if not EXPLAIN and we are done with the JOIN,
            free all tables.
            */

            • bool full= (!(select_lex->uncacheable) &&
            • !thd->lex->describe);
              + bool full= !(select_lex->uncacheable);
              bool can_unlock= full;
              DBUG_ENTER("JOIN::join_free");
              ...
            Show
            psergey Sergei Petrunia added a comment - Patryk, agree with your suggestion. It's interesting that the comment above suggests there was a check for EXPLAIN in the past. It got removed by this change: timour@askmonty.org-20110704115116-cx7ibyty8uiwrpg7, Fix LP bug lp:802979 === modified file 'sql/sql_select.cc' — sql/sql_select.cc 2011-06-30 03:07:24 +0000 +++ sql/sql_select.cc 2011-07-04 11:51:16 +0000 @@ -9620,8 +9620,7 @@ void JOIN::join_free() Optimization: if not EXPLAIN and we are done with the JOIN, free all tables. */ bool full= (!(select_lex->uncacheable) && !thd->lex->describe); + bool full= !(select_lex->uncacheable); bool can_unlock= full; DBUG_ENTER("JOIN::join_free"); ...
            Hide
            psergey Sergei Petrunia added a comment -

            With the change, I am getting result differences like this:
            @@ -6133,7 +6133,7 @@
            EXPLAIN SELECT * FROM t1 WHERE EXISTS (SELECT * FROM t1 WHERE a=7);
            id select_type table type possible_keys key key_len ref rows Extra
            1 PRIMARY t1 ALL NULL NULL NULL NULL 4
            -2 SUBQUERY t1 ref a a 5 const 1
            +2 SUBQUERY t1 ref a a 5 const 1 Using index

            Debugging shows that "Using index" actually is the correct output.

            Show
            psergey Sergei Petrunia added a comment - With the change, I am getting result differences like this: @@ -6133,7 +6133,7 @@ EXPLAIN SELECT * FROM t1 WHERE EXISTS (SELECT * FROM t1 WHERE a=7); id select_type table type possible_keys key key_len ref rows Extra 1 PRIMARY t1 ALL NULL NULL NULL NULL 4 -2 SUBQUERY t1 ref a a 5 const 1 +2 SUBQUERY t1 ref a a 5 const 1 Using index Debugging shows that "Using index" actually is the correct output.
            Hide
            psergey Sergei Petrunia added a comment -

            Ok, the wrong output was introduced by "CHEAP SQ" feature in May 2012. That feature caused a lot of changed EXPLAINs, and these slipped through.

            Show
            psergey Sergei Petrunia added a comment - Ok, the wrong output was introduced by "CHEAP SQ" feature in May 2012. That feature caused a lot of changed EXPLAINs, and these slipped through.
            Hide
            psergey Sergei Petrunia added a comment -

            Fixed, pushed.

            Show
            psergey Sergei Petrunia added a comment - Fixed, pushed.

              People

              • Assignee:
                psergey Sergei Petrunia
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 3 hours, 15 minutes
                  3h 15m