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

Server crashes in Explain_union::print_explain with explain in slow log, tis620 charset

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.0.12, 10.1.0
    • Fix Version/s: 10.1, 10.0
    • Component/s: None
    • Labels:
      None

      Description

      #2  0x0000000000864189 in handle_fatal_signal (sig=11) at 10.0/sql/signal_handler.cc:262
      #3  <signal handler called>
      #4  0x00000000007c4f24 in Explain_union::print_explain (this=0x7fee28b77b68, query=0x7fee28b77aa8, output=0x7fee325b4d10, explain_flags=0 '\000') at 10.0/sql/sql_explain.cc:228
      #5  0x00000000007c53cc in Explain_node::print_explain_for_children (this=0x7fee28b78ff0, query=0x7fee28b77aa8, output=0x7fee325b4d10, explain_flags=0 '\000') at 10.0/sql/sql_explain.cc:327
      #6  0x00000000007c57a7 in Explain_select::print_explain (this=0x7fee28b78ff0, query=0x7fee28b77aa8, output=0x7fee325b4d10, explain_flags=0 '\000') at 10.0/sql/sql_explain.cc:390
      #7  0x00000000007c4c9c in Explain_query::print_explain (this=0x7fee28b77aa8, output=0x7fee325b4d10, explain_flags=0 '\000') at 10.0/sql/sql_explain.cc:175
      #8  0x00000000007c4d63 in Explain_query::print_explain_str (this=0x7fee28b77aa8, thd=0x7fee2b32f070, out_str=0x7fee325b4e70) at 10.0/sql/sql_explain.cc:197
      #9  0x00000000007c4cd0 in print_explain_query (lex=0x7fee2b332cc0, thd=0x7fee2b32f070, str=0x7fee325b4e70) at 10.0/sql/sql_explain.cc:182
      #10 0x000000000093552b in MYSQL_QUERY_LOG::write (this=0x7fee2c3d6150, thd=0x7fee2b32f070, current_time=1405123297, user_host=0x7fee325b52a0 "root[root] @ localhost []", user_host_len=25, query_utime=1563, lock_utime=733, is_command=false, sql_text=0x7fee28819088 "SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' )", sql_text_len=67) at 10.0/sql/log.cc:2926
      #11 0x000000000093088b in Log_to_file_event_handler::log_slow (this=0x7fee2c3d5c00, thd=0x7fee2b32f070, current_time=..., user_host=0x7fee325b52a0 "root[root] @ localhost []", user_host_len=25, query_utime=1563, lock_utime=733, is_command=false, sql_text=0x7fee28819088 "SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' )", sql_text_len=67) at 10.0/sql/log.cc:1018
      #12 0x000000000093129e in LOGGER::slow_log_print (this=0x18a1600, thd=0x7fee2b32f070, query=0x7fee28819088 "SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' )", query_length=67, current_utime=52081142100) at 10.0/sql/log.cc:1309
      #13 0x000000000093d254 in slow_log_print (thd=0x7fee2b32f070, query=0x7fee28819088 "SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' )", query_length=67, current_utime=52081142100) at 10.0/sql/log.cc:6020
      #14 0x000000000067708c in log_slow_statement (thd=0x7fee2b32f070) at 10.0/sql/sql_parse.cc:1823
      #15 0x0000000000676d62 in dispatch_command (command=COM_QUERY, thd=0x7fee2b32f070, packet=0x7fee2c3f6071 "", packet_length=67) at 10.0/sql/sql_parse.cc:1743
      #16 0x0000000000674be2 in do_command (thd=0x7fee2b32f070) at 10.0/sql/sql_parse.cc:1006
      #17 0x0000000000790ab5 in do_handle_one_connection (thd_arg=0x7fee2b32f070) at 10.0/sql/sql_connect.cc:1379
      #18 0x0000000000790808 in handle_one_connection (arg=0x7fee2b32f070) at 10.0/sql/sql_connect.cc:1293
      #19 0x0000000000cc22f6 in pfs_spawn_thread (arg=0x7fee2a6a0970) at 10.0/storage/perfschema/pfs.cc:1860
      #20 0x00007fee321a0b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
      #21 0x00007fee30698a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
      

      Stack trace from:

      revision-id: knielsen@knielsen-hq.org-20140711100647-nf3rdaf5ep26pgty
      revno: 4290
      branch-nick: 10.0
      

      Test case:

      SET NAMES tis620;
      SET GLOBAL slow_query_log = 1;
      SET long_query_time = 0.000001;
      SET log_slow_verbosity = 'explain';
      
      CREATE TABLE t1 (a VARCHAR(3)) ENGINE=MyISAM;
      SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' );
      

        Gliffy Diagrams

          Attachments

            Activity

            Hide
            psergey Sergei Petrunia added a comment -

            Debugging, I can see this:

              #0  JOIN::optimize_inner (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1071
              #1  0x0000000000693696 in JOIN::optimize (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1023
              #2  0x000000000072776e in st_select_lex_unit::optimize (this=0x7fffc8c47d40) at /home/psergey/dev2/10.0/sql/sql_union.cc:611
              #3  0x0000000000727973 in st_select_lex_unit::exec (this=0x7fffc8c47d40) at /home/psergey/dev2/10.0/sql/sql_union.cc:644
              #4  0x00000000008fd3ab in subselect_union_engine::exec (this=0x7fffc8c48e48) at /home/psergey/dev2/10.0/sql/item_subselect.cc:3711
              #5  0x00000000008f4259 in Item_subselect::exec (this=0x7fffc8cd65c0) at /home/psergey/dev2/10.0/sql/item_subselect.cc:667
              #6  0x00000000008f5af0 in Item_singlerow_subselect::val_str (this=0x7fffc8cd65c0, str=0x7ffff7f36990) at /home/psergey/dev2/10.0/sql/item_subselect.cc:1264
              #7  0x0000000000885c11 in Item_func_conv_charset::Item_func_conv_charset (this=0x7fffc8cd69b8, a=0x7fffc8cd65c0, cs=0x188b200, cache_if_const=true) at /home/psergey/dev2/10.0/sql/item_strfunc.h:932
              #8  0x0000000000869fb7 in Item::safe_charset_converter (this=0x7fffc8cd65c0, tocs=0x188b200) at /home/psergey/dev2/10.0/sql/item.cc:1169
              #9  0x000000000086cf1f in agg_item_set_converter (coll=..., fname=0x10e887d "<=", args=0x7fffc8cd67b0, nargs=2, flags=7, item_sep=1) at /home/psergey/dev2/10.0/sql/item.cc:2231
              #10 0x000000000086d164 in agg_item_charsets (coll=..., fname=0x10e887d "<=", args=0x7fffc8cd67b0, nargs=2, flags=7, item_sep=1) at /home/psergey/dev2/10.0/sql/item.cc:2312
              #11 0x000000000089cf3c in agg_item_charsets_for_comparison (c=..., name=0x10e887d "<=", items=0x7fffc8cd67b0, nitems=2, item_sep=1) at /home/psergey/dev2/10.0/sql/item.h:1949
              #12 0x000000000089d0d6 in Item_func::agg_arg_charsets_for_comparison (this=0x7fffc8cd6720, c=..., items=0x7fffc8cd67b0, nitems=2, item_sep=1) at /home/psergey/dev2/10.0/sql/item_func.h:225
              #13 0x000000000088a702 in Item_bool_func2::fix_length_and_dec (this=0x7fffc8cd6720) at /home/psergey/dev2/10.0/sql/item_cmpfunc.cc:554
              #14 0x00000000008b78aa in Item_func::fix_fields (this=0x7fffc8cd6720, thd=0x7fffd1ec2070, ref=0x7ffff7f36e28) at /home/psergey/dev2/10.0/sql/item_func.cc:229
              #15 0x00000000008f76e7 in Item_allany_subselect::transform_into_max_min (this=0x7fffc8c48c88, join=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/item_subselect.cc:1933
              #16 0x00000000007c6c1a in JOIN::transform_max_min_subquery (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/opt_subselect.cc:891
              #17 0x0000000000693a96 in JOIN::optimize_inner (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1113
              #18 0x0000000000693696 in JOIN::optimize (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1023
              #19 0x0000000000651f93 in st_select_lex::optimize_unflattened_subqueries (this=0x7fffd1ec6468, const_only=false) at /home/psergey/dev2/10.0/sql/sql_lex.cc:3489
              #20 0x00000000007cff68 in JOIN::optimize_unflattened_subqueries (this=0x7fffc8ce8088) at /home/psergey/dev2/10.0/sql/opt_subselect.cc:4952
              #21 0x000000000069680d in JOIN::optimize_inner (this=0x7fffc8ce8088) at /home/psergey/dev2/10.0/sql/sql_select.cc:1916
              #22 0x0000000000693696 in JOIN::optimize (this=0x7fffc8ce8088) at /home/psergey/dev2/10.0/sql/sql_select.cc:1023
              #23 0x000000000069b517 in mysql_select (thd=0x7fffd1ec2070, rref_pointer_array=0x7fffd1ec66e0, tables=0x7fffc8c472d0, wild_num=1, fields=..., conds=0x7fffc8c48e80, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fffc8c48ff0, unit=0x7fffd1ec5d80, select_lex=0x7fffd1ec6468) at /home/psergey/dev2/10.0/sql/sql_select.cc:3293
              #24 0x00000000006918a0 in handle_select (thd=0x7fffd1ec2070, lex=0x7fffd1ec5cb8, result=0x7fffc8c48ff0, setup_tables_done_option=0) at /home/psergey/dev2/10.0/sql/sql_select.cc:372
              #25 0x0000000000665204 in execute_sqlcom_select (thd=0x7fffd1ec2070, all_tables=0x7fffc8c472d0) at /home/psergey/dev2/10.0/sql/sql_parse.cc:5265
              #26 0x000000000065d238 in mysql_execute_command (thd=0x7fffd1ec2070) at /home/psergey/dev2/10.0/sql/sql_parse.cc:2552
              #27 0x0000000000667a75 in mysql_parse (thd=0x7fffd1ec2070, rawbuf=0x7fffc8c47088 "SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' )", length=67, parser_state=0x7ffff7f384b0) at /home/psergey/dev2/10.0/sql/sql_parse.cc:6411
            

            JOIN::optimize() is called for " select 'foo'" (select_number=2). Then, it calls Item_allany_subselect::transform_into_max_min, which calls agg_item_set_converter... which eventually sees the item as inexpensive and calls Item_singlerow_subselect::val_str, which tries to execute the UNION. That is, JOIN::optimize() indirectly calls itself for the same object.

            Show
            psergey Sergei Petrunia added a comment - Debugging, I can see this: #0 JOIN::optimize_inner (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1071 #1 0x0000000000693696 in JOIN::optimize (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1023 #2 0x000000000072776e in st_select_lex_unit::optimize (this=0x7fffc8c47d40) at /home/psergey/dev2/10.0/sql/sql_union.cc:611 #3 0x0000000000727973 in st_select_lex_unit::exec (this=0x7fffc8c47d40) at /home/psergey/dev2/10.0/sql/sql_union.cc:644 #4 0x00000000008fd3ab in subselect_union_engine::exec (this=0x7fffc8c48e48) at /home/psergey/dev2/10.0/sql/item_subselect.cc:3711 #5 0x00000000008f4259 in Item_subselect::exec (this=0x7fffc8cd65c0) at /home/psergey/dev2/10.0/sql/item_subselect.cc:667 #6 0x00000000008f5af0 in Item_singlerow_subselect::val_str (this=0x7fffc8cd65c0, str=0x7ffff7f36990) at /home/psergey/dev2/10.0/sql/item_subselect.cc:1264 #7 0x0000000000885c11 in Item_func_conv_charset::Item_func_conv_charset (this=0x7fffc8cd69b8, a=0x7fffc8cd65c0, cs=0x188b200, cache_if_const=true) at /home/psergey/dev2/10.0/sql/item_strfunc.h:932 #8 0x0000000000869fb7 in Item::safe_charset_converter (this=0x7fffc8cd65c0, tocs=0x188b200) at /home/psergey/dev2/10.0/sql/item.cc:1169 #9 0x000000000086cf1f in agg_item_set_converter (coll=..., fname=0x10e887d "<=", args=0x7fffc8cd67b0, nargs=2, flags=7, item_sep=1) at /home/psergey/dev2/10.0/sql/item.cc:2231 #10 0x000000000086d164 in agg_item_charsets (coll=..., fname=0x10e887d "<=", args=0x7fffc8cd67b0, nargs=2, flags=7, item_sep=1) at /home/psergey/dev2/10.0/sql/item.cc:2312 #11 0x000000000089cf3c in agg_item_charsets_for_comparison (c=..., name=0x10e887d "<=", items=0x7fffc8cd67b0, nitems=2, item_sep=1) at /home/psergey/dev2/10.0/sql/item.h:1949 #12 0x000000000089d0d6 in Item_func::agg_arg_charsets_for_comparison (this=0x7fffc8cd6720, c=..., items=0x7fffc8cd67b0, nitems=2, item_sep=1) at /home/psergey/dev2/10.0/sql/item_func.h:225 #13 0x000000000088a702 in Item_bool_func2::fix_length_and_dec (this=0x7fffc8cd6720) at /home/psergey/dev2/10.0/sql/item_cmpfunc.cc:554 #14 0x00000000008b78aa in Item_func::fix_fields (this=0x7fffc8cd6720, thd=0x7fffd1ec2070, ref=0x7ffff7f36e28) at /home/psergey/dev2/10.0/sql/item_func.cc:229 #15 0x00000000008f76e7 in Item_allany_subselect::transform_into_max_min (this=0x7fffc8c48c88, join=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/item_subselect.cc:1933 #16 0x00000000007c6c1a in JOIN::transform_max_min_subquery (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/opt_subselect.cc:891 #17 0x0000000000693a96 in JOIN::optimize_inner (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1113 #18 0x0000000000693696 in JOIN::optimize (this=0x7fffc8ce8850) at /home/psergey/dev2/10.0/sql/sql_select.cc:1023 #19 0x0000000000651f93 in st_select_lex::optimize_unflattened_subqueries (this=0x7fffd1ec6468, const_only=false) at /home/psergey/dev2/10.0/sql/sql_lex.cc:3489 #20 0x00000000007cff68 in JOIN::optimize_unflattened_subqueries (this=0x7fffc8ce8088) at /home/psergey/dev2/10.0/sql/opt_subselect.cc:4952 #21 0x000000000069680d in JOIN::optimize_inner (this=0x7fffc8ce8088) at /home/psergey/dev2/10.0/sql/sql_select.cc:1916 #22 0x0000000000693696 in JOIN::optimize (this=0x7fffc8ce8088) at /home/psergey/dev2/10.0/sql/sql_select.cc:1023 #23 0x000000000069b517 in mysql_select (thd=0x7fffd1ec2070, rref_pointer_array=0x7fffd1ec66e0, tables=0x7fffc8c472d0, wild_num=1, fields=..., conds=0x7fffc8c48e80, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fffc8c48ff0, unit=0x7fffd1ec5d80, select_lex=0x7fffd1ec6468) at /home/psergey/dev2/10.0/sql/sql_select.cc:3293 #24 0x00000000006918a0 in handle_select (thd=0x7fffd1ec2070, lex=0x7fffd1ec5cb8, result=0x7fffc8c48ff0, setup_tables_done_option=0) at /home/psergey/dev2/10.0/sql/sql_select.cc:372 #25 0x0000000000665204 in execute_sqlcom_select (thd=0x7fffd1ec2070, all_tables=0x7fffc8c472d0) at /home/psergey/dev2/10.0/sql/sql_parse.cc:5265 #26 0x000000000065d238 in mysql_execute_command (thd=0x7fffd1ec2070) at /home/psergey/dev2/10.0/sql/sql_parse.cc:2552 #27 0x0000000000667a75 in mysql_parse (thd=0x7fffd1ec2070, rawbuf=0x7fffc8c47088 "SELECT * FROM t1 WHERE a >= ANY ( SELECT 'foo' UNION SELECT 'bar' )", length=67, parser_state=0x7ffff7f384b0) at /home/psergey/dev2/10.0/sql/sql_parse.cc:6411 JOIN::optimize() is called for " select 'foo'" (select_number=2). Then, it calls Item_allany_subselect::transform_into_max_min, which calls agg_item_set_converter... which eventually sees the item as inexpensive and calls Item_singlerow_subselect::val_str, which tries to execute the UNION. That is, JOIN::optimize() indirectly calls itself for the same object.
            Hide
            psergey Sergei Petrunia added a comment -

            The inner JOIN::optimize() call doesn't save the query plan. this branch

              if (was_optimized != optimized && !res && have_query_plan != QEP_DELETED)
            

            is not taken, because was_optimized != optimized.

            Then, the UNION is executed. It calls JOIN::exec() which calls JOIN::join_free()
            which computes

              bool full= !(select_lex->uncacheable) &&  !(thd->lex->describe);
            

            to be true, calls JOIN::cleanup(full=true) which deletes the query plan and
            sets have_query_plan= QEP_DELETED. This will prevent the outer-most
            JOIN::optimize from saving the query plan (it will be already deleted).

            When we arrive at the phase where EXPLAIN should be printed, we will crash
            because one part of UNION will not have the query plan.

            Show
            psergey Sergei Petrunia added a comment - The inner JOIN::optimize() call doesn't save the query plan. this branch if (was_optimized != optimized && !res && have_query_plan != QEP_DELETED) is not taken, because was_optimized != optimized. Then, the UNION is executed. It calls JOIN::exec() which calls JOIN::join_free() which computes bool full= !(select_lex->uncacheable) && !(thd->lex->describe); to be true, calls JOIN::cleanup(full=true) which deletes the query plan and sets have_query_plan= QEP_DELETED. This will prevent the outer-most JOIN::optimize from saving the query plan (it will be already deleted). When we arrive at the phase where EXPLAIN should be printed, we will crash because one part of UNION will not have the query plan.
            Hide
            psergey Sergei Petrunia added a comment -

            Why not change the condition in JOIN::optimize() to be
            1. We have the query plan ( we might not have it if optimization failed with an error), AND
            2. "explain data structure has no query plan for this select yet".

            This should cover all cases.. or it seems so at first glance.

            Show
            psergey Sergei Petrunia added a comment - Why not change the condition in JOIN::optimize() to be 1. We have the query plan ( we might not have it if optimization failed with an error), AND 2. "explain data structure has no query plan for this select yet". This should cover all cases.. or it seems so at first glance.

              People

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

                Dates

                • Created:
                  Updated: