[MDEV-32519] main.brackets test crashes with --ps-protocol and enabled trace Created: 2023-10-19  Updated: 2023-10-24

Status: Open
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 10.6
Fix Version/s: 10.6

Type: Bug Priority: Major
Reporter: Sergei Petrunia Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Running

./mtr --mysqld=--optimizer_trace=enabled=on main/brackets.test  --ps-protocol

fails:

Thread pointer: 0x7f0ed8000d78
 
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 = 0x7f0eef49ec98 thread_stack 0x49000
 
mysys/stacktrace.c:215(my_print_stacktrace)[0x55dee3cbde75]
 
sql/signal_handler.cc:241(handle_fatal_signal)[0x55dee33de936]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12980)[0x7f0ef9879980]
 
sql/sql_select.cc:29422(st_select_lex::print(THD*, String*, enum_query_type))[0x55dee30ddf93]
 
sql/sql_lex.cc:3700(st_select_lex_unit::print(String*, enum_query_type))[0x55dee3007a25]
 
sql/sql_cte.cc:1683(With_element::print(THD*, String*, enum_query_type))[0x55dee32f3d5f]
 
sql/sql_cte.cc:1634(With_clause::print(THD*, String*, enum_query_type))[0x55dee32f3bf1]
 
sql/item_subselect.cc:4604(subselect_single_select_engine::print(String*, enum_query_type))[0x55dee34e0a53]
 
sql/item_subselect.cc:1075(Item_subselect::print(String*, enum_query_type))[0x55dee34d2c6b]
 
sql/item.cc:498(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55dee340298b]
 
sql/item_func.cc:643(Item_func::print_op(String*, enum_query_type))[0x55dee346dd75]
 
sql/item_func.h:1118(Item_num_op::print(String*, enum_query_type))[0x55dee3023c3d]
 
sql/item.cc:498(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55dee340298b]
 
sql/item_func.cc:643(Item_func::print_op(String*, enum_query_type))[0x55dee346dd75]
 
sql/item_func.h:1118(Item_num_op::print(String*, enum_query_type))[0x55dee3023c3d]
 
sql/item.cc:513(Item::print_item_w_name(String*, enum_query_type))[0x55dee3402a24]
 
sql/sql_select.cc:29105(st_select_lex::print_item_list(THD*, String*, enum_query_type))[0x55dee30dcf57]
 
sql/sql_select.cc:29316(st_select_lex::print(THD*, String*, enum_query_type))[0x55dee30dda98]
 
sql/opt_trace.cc:123(opt_trace_print_expanded_query(THD*, st_select_lex*, Json_writer_object*))[0x55dee330310c]
 
sql/sql_select.cc:1739(JOIN::prepare(TABLE_LIST*, Item*, unsigned int, st_order*, bool, st_order*, Item*, st_order*, st_select_lex*, st_select_lex_unit*))[0x55dee308de95]
 
sql/sql_select.cc:5068(mysql_select(THD*, TABLE_LIST*, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x55dee309a3d6]
 
sql/sql_select.cc:559(handle_select(THD*, LEX*, select_result*, unsigned long))[0x55dee30890df]
 
sql/sql_parse.cc:6285(execute_sqlcom_select(THD*, TABLE_LIST*))[0x55dee304868c]
 
sql/sql_parse.cc:3961(mysql_execute_command(THD*, bool))[0x55dee303f725]
 
sql/sql_prepare.cc:5249(Prepared_statement::execute(String*, bool))[0x55dee306fb45]
 
sql/sql_prepare.cc:4655(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*))[0x55dee306dd5e]
 
sql/sql_prepare.cc:3584(mysql_stmt_execute_common(THD*, unsigned long, unsigned char*, unsigned char*, unsigned long, bool, bool))[0x55dee306b0e2]

...

Query (0x7f0ed812cdd8): select
 
( with t as (select * from t1 where a <=3)
 
select a from t limit 1 ) + t2.b + (values (100)) as r
 
from t2

It crashes in

  void st_select_lex::print(THD *thd, String *str, enum_query_type query_type)


    if (join)
 
      cur_having= join->having;
 
  
    if (cur_having || having_value != Item::COND_UNDEF)
 
    { 
      str->append(STRING_WITH_LEN(" having "));
 
      if (cur_having)
 
=>      cur_having->print(str, query_type); 
      else
 
        str->append(having_value != Item::COND_FALSE ? '1' : '0');
 
    }

Here we have

(gdb) print cur_having
 
  $86 = (Item *) 0xa5a5a5a5a5a5a5a5
 
(gdb) p having
 
  $88 = (Item *) 0x0
 
(gdb) p join->having
 
  $90 = (Item *) 0xa5a5a5a5a5a5a5a5



 Comments   
Comment by Sergei Petrunia [ 2023-10-19 ]

Note that the problem happens only in PS mode. It happens on the second execution.

Debugging the testcase, I see:

mysqld_stmt_prepare()
 
  JOIN::prepare(select_id=2)
 
  JOIN::prepare(select_id=1)
 
  JOIN::prepare(select_id=3)
 
  JOIN::prepare(select_id=5)
 
 
 
  JOIN::destroy(select_id=1)
 
  JOIN::destroy(select_id=5)
 
  JOIN::destroy(select_id=3)
 
  JOIN::destroy(select_id=2)

Ok

mysqld_stmt_execute
 
  JOIN::prepare(select_id=1)
 
  JOIN::prepare(select_id=3)
 
  JOIN::prepare(select_id=2)  // (CALL-1)
 
  JOIN::prepare(select_id=5)
 
  
  JOIN::optimize(select_id=1)
 
  JOIN::optimize(select_id=5)
 
  JOIN::optimize(select_id=3)
 
  # Note the lack of optimize call with id=2!
 
  JOIN::destroy(select_id=1)
 
  JOIN::destroy(select_id=5)
 
  JOIN::destroy(select_id=3)
 
  # and no destroy call either


mysqld_stmt_execute
 
  JOIN::prepare(select_id=1)
 
  JOIN::prepare(select_id=3)
 
  JOIN::prepare(select_id=5)

And now, we crash in st_select_lex::print, because st_select_lex->join still points to the JOIN object we saw at (CALL-1).

Normally, st_select_lex->join is cleaned here:

  JOIN::destroy()
 
  {     
    DBUG_ENTER("JOIN::destroy");                                                                                                                      
    
    DBUG_PRINT("info", ("select %p (%u) <> JOIN %p",
 
                        select_lex, select_lex->select_number, this));
 
    select_lex->join= 0;

but the JOIN::destroy() call was never made for select_id=2.

Comment by Sergei Petrunia [ 2023-10-19 ]

Questions:

  • If a select is merged into its parent, should one call JOIN::destroy() for it?
  • If a select WAS merged to its parent, why are we even trying to print it? Perhaps, we need this logic: "don't print CTEs that have been merged?"
Generated at Thu Feb 08 10:31:58 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.