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

    • Bug
    • Status: Closed (View Workflow)
    • Critical
    • Resolution: Fixed
    • 5.5.25
    • 5.5.27
    • None
    • 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;
       

      Attachments

        Activity

          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

          psergei 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

          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.

          psergei 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.

          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");
          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");

          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.

          timour Timour Katchaounov (Inactive) 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 .

          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");
            ...
          psergei 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"); ...

          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.

          psergei 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.

          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.

          psergei 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.

          Fixed, pushed.

          psergei Sergei Petrunia added a comment - Fixed, pushed.

          People

            psergei Sergei Petrunia
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.