[MDEV-28201] Server crashes upon SHOW ANALYZE/EXPLAIN FORMAT=JSON - Jira

Alice Sherepa created issue - 2022-03-30 15:15

Alice Sherepa made changes - 2022-03-30 15:15

Field	Original Value	New Value
Assignee		Sergei Petrunia [ psergey ]

Alice Sherepa made changes - 2022-03-30 15:18

Link

This issue is caused by ~~MDEV-27021~~ [ ~~MDEV-27021~~ ]

Alice Sherepa made changes - 2022-03-30 15:23

Description

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
    SELECT i FROM (SELECT DISTINCT * FROM t1) a1 GROUP BY i ;

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
Version: '10.9.0-MariaDB-debug-log'
220330 17:04:13 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f5d1927a3c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x563a4b0fe850]
sql/sql_explain.cc:1557(append_item_to_str(String*, Item*))[0x563a4af221d0]
sql/sql_explain.cc:1070(Explain_aggr_filesort::print_json_members(Json_writer*, bool))[0x563a4af2032a]
sql/sql_explain.cc:1002(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x563a4af1ffa5]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x563a4af1d203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x563a4acce9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x563a4adcee84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x563a4af5bd94]
sql/my_apc.h:74(Apc_target::disable())[0x563a4af26ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x563a4af1cdea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x563a4ac7a7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x563a4ad10470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x563a4acfc6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x563a4acfb09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x563a4aed4221]
sql/sql_connect.cc:1314(handle_one_connection)[0x563a4aed3eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x563a4b423e4b]
nptl/pthread_create.c:478(start_thread)[0x7f5d1926e609]
??:0(clone)[0x7f5d18e3f163]

Query (0x7f5ce4015420): SHOW EXPLAIN FORMAT=JSON FOR 5
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
    SELECT i FROM (SELECT DISTINCT * FROM t1) a1 GROUP BY i ;

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
Version: '10.9.0-MariaDB-debug-log'
220330 17:04:13 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f5d1927a3c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x563a4b0fe850]
sql/sql_explain.cc:1557(append_item_to_str(String*, Item*))[0x563a4af221d0]
sql/sql_explain.cc:1070(Explain_aggr_filesort::print_json_members(Json_writer*, bool))[0x563a4af2032a]
sql/sql_explain.cc:1002(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x563a4af1ffa5]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x563a4af1d203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x563a4acce9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x563a4adcee84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x563a4af5bd94]
sql/my_apc.h:74(Apc_target::disable())[0x563a4af26ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x563a4af1cdea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x563a4ac7a7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x563a4ad10470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x563a4acfc6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x563a4acfb09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x563a4aed4221]
sql/sql_connect.cc:1314(handle_one_connection)[0x563a4aed3eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x563a4b423e4b]
nptl/pthread_create.c:478(start_thread)[0x7f5d1926e609]
??:0(clone)[0x7f5d18e3f163]

Query (0x7f5ce4015420): SHOW EXPLAIN FORMAT=JSON FOR 5
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
SELECT i FROM (SELECT DISTINCT * FROM t1) a1 WHERE i IN ('v');

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
220330 17:21:40 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f20410413c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x55da53a1f850]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55da53a07b9b]
sql/item_func.cc:631(Item_func::print_op(String*, enum_query_type))[0x55da53a7361e]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x55da534d2df9]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x55da538430d4]
sql/sql_explain.cc:1605(Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag))[0x55da538433d0]
sql/sql_explain.cc:1881(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da538442c0]
sql/sql_explain.cc:1127(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55da538416b7]
sql/sql_explain.cc:1022(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da53841068]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x55da5383e203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x55da535ef9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x55da536efe84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x55da5387cd94]
sql/my_apc.h:74(Apc_target::disable())[0x55da53847ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x55da5383ddea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x55da5359b7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55da53631470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55da5361d6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55da5361c09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55da537f5221]
sql/sql_connect.cc:1314(handle_one_connection)[0x55da537f4eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55da53d44e4b]
nptl/pthread_create.c:478(start_thread)[0x7f2041035609]
??:0(clone)[0x7f2040c06163]

Query (0x7f200c015420): SHOW EXPLAIN FORMAT=JSON FOR 5

{noformat}

Alice Sherepa made changes - 2022-03-30 15:43

Description

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
    SELECT i FROM (SELECT DISTINCT * FROM t1) a1 GROUP BY i ;

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
Version: '10.9.0-MariaDB-debug-log'
220330 17:04:13 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f5d1927a3c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x563a4b0fe850]
sql/sql_explain.cc:1557(append_item_to_str(String*, Item*))[0x563a4af221d0]
sql/sql_explain.cc:1070(Explain_aggr_filesort::print_json_members(Json_writer*, bool))[0x563a4af2032a]
sql/sql_explain.cc:1002(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x563a4af1ffa5]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x563a4af1d203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x563a4acce9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x563a4adcee84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x563a4af5bd94]
sql/my_apc.h:74(Apc_target::disable())[0x563a4af26ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x563a4af1cdea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x563a4ac7a7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x563a4ad10470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x563a4acfc6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x563a4acfb09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x563a4aed4221]
sql/sql_connect.cc:1314(handle_one_connection)[0x563a4aed3eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x563a4b423e4b]
nptl/pthread_create.c:478(start_thread)[0x7f5d1926e609]
??:0(clone)[0x7f5d18e3f163]

Query (0x7f5ce4015420): SHOW EXPLAIN FORMAT=JSON FOR 5
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
SELECT i FROM (SELECT DISTINCT * FROM t1) a1 WHERE i IN ('v');

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
220330 17:21:40 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f20410413c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x55da53a1f850]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55da53a07b9b]
sql/item_func.cc:631(Item_func::print_op(String*, enum_query_type))[0x55da53a7361e]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x55da534d2df9]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x55da538430d4]
sql/sql_explain.cc:1605(Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag))[0x55da538433d0]
sql/sql_explain.cc:1881(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da538442c0]
sql/sql_explain.cc:1127(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55da538416b7]
sql/sql_explain.cc:1022(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da53841068]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x55da5383e203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x55da535ef9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x55da536efe84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x55da5387cd94]
sql/my_apc.h:74(Apc_target::disable())[0x55da53847ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x55da5383ddea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x55da5359b7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55da53631470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55da5361d6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55da5361c09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55da537f5221]
sql/sql_connect.cc:1314(handle_one_connection)[0x55da537f4eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55da53d44e4b]
nptl/pthread_create.c:478(start_thread)[0x7f2041035609]
??:0(clone)[0x7f2040c06163]

Query (0x7f200c015420): SHOW EXPLAIN FORMAT=JSON FOR 5

{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
    SELECT i FROM (SELECT DISTINCT * FROM t1) a1 GROUP BY i ;

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
Version: '10.9.0-MariaDB-debug-log'
220330 17:04:13 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f5d1927a3c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x563a4b0fe850]
sql/sql_explain.cc:1557(append_item_to_str(String*, Item*))[0x563a4af221d0]
sql/sql_explain.cc:1070(Explain_aggr_filesort::print_json_members(Json_writer*, bool))[0x563a4af2032a]
sql/sql_explain.cc:1002(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x563a4af1ffa5]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x563a4af1d203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x563a4acce9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x563a4adcee84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x563a4af5bd94]
sql/my_apc.h:74(Apc_target::disable())[0x563a4af26ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x563a4af1cdea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x563a4ac7a7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x563a4ad10470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x563a4acfc6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x563a4acfb09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x563a4aed4221]
sql/sql_connect.cc:1314(handle_one_connection)[0x563a4aed3eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x563a4b423e4b]
nptl/pthread_create.c:478(start_thread)[0x7f5d1926e609]
??:0(clone)[0x7f5d18e3f163]

Query (0x7f5ce4015420): SHOW EXPLAIN FORMAT=JSON FOR 5
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
SELECT i FROM (SELECT DISTINCT * FROM t1) a1 WHERE i IN ('v');

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
220330 17:21:40 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f20410413c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x55da53a1f850]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55da53a07b9b]
sql/item_func.cc:631(Item_func::print_op(String*, enum_query_type))[0x55da53a7361e]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x55da534d2df9]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x55da538430d4]
sql/sql_explain.cc:1605(Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag))[0x55da538433d0]
sql/sql_explain.cc:1881(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da538442c0]
sql/sql_explain.cc:1127(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55da538416b7]
sql/sql_explain.cc:1022(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da53841068]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x55da5383e203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x55da535ef9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x55da536efe84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x55da5387cd94]
sql/my_apc.h:74(Apc_target::disable())[0x55da53847ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x55da5383ddea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x55da5359b7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55da53631470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55da5361d6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55da5361c09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55da537f5221]
sql/sql_connect.cc:1314(handle_one_connection)[0x55da537f4eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55da53d44e4b]
nptl/pthread_create.c:478(start_thread)[0x7f2041035609]
??:0(clone)[0x7f2040c06163]

Query (0x7f200c015420): SHOW EXPLAIN FORMAT=JSON FOR 5

{noformat}

++variations:
{noformat}
mysqld: /10.9/sql/field.cc:7525: virtual String* Field_string::val_str(String*, String*): Assertion `!table || table->in_use == _current_thd()' failed.
220330 13:20:06 [ERROR] mysqld got signal 6 ;

Server version: 10.9.0-MariaDB-debug-log

linux/raise.c:51(__GI_raise)[0x7ff324cda7bb]
stdlib/abort.c:81(__GI_abort)[0x7ff324cc5535]
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7ff324cc540f]
??:0(__assert_fail)[0x7ff324cd3102]
sql/field.cc:7527(Field_string::val_str(String*, String*))[0x556cb3f697dc]
sql/item.cc:3323(Item_field::val_str(String*))[0x556cb40314cc]
sql/item.cc:526(Item::print_value(String*))[0x556cb40194c3]
sql/item.cc:7825(Item_field::print(String*, enum_query_type))[0x556cb4054640]
sql/item.cc:8331(Item_ref::print(String*, enum_query_type))[0x556cb40588b2]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x556cb4018fdd]
sql/item_func.cc:636(Item_func::print_op(String*, enum_query_type))[0x556cb410d163]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x556cb3428dd1]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x556cb4018fdd]
sql/item_cmpfunc.cc:5286(Item_cond::print(String*, enum_query_type))[0x556cb40b70bb]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x556cb3c52ba7]
sql/sql_explain.cc:974(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x556cb3c4ee52]
sql/sql_explain.cc:737(Explain_node::print_explain_json_for_children(Explain_query*, Json_writer*, bool))[0x556cb3c4d599]
sql/sql_explain.cc:939(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x556cb3c4eb0e]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x556cb3c4a29d]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x556cb36b7d63]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x556cb39234be]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x556cb3ce133d]
sql/my_apc.h:74(Apc_target::disable())[0x556cb3c5ace7]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x556cb3c49874]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x556cb35e9545]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x556cb3744177]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x556cb371a59c]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x556cb3717291]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x556cb3baa786]
sql/sql_connect.cc:1314(handle_one_connection)[0x556cb3baa00b]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x556cb482c03b]
nptl/pthread_create.c:487(start_thread)[0x7ff325192fa3]
x86_64/clone.S:97(clone)[0x7ff324d9beff]

Query (0x6290007994e8): SHOW ANALYZE FORMAT=JSON FOR 18
{noformat}

{noformat}
=================================================================
==69440==ERROR: AddressSanitizer: heap-use-after-free on address 0x61a000555318 at pc 0x55de8fc175da bp 0x7fadb04b5c80 sp 0x7fadb04b5c78
READ of size 8 at 0x61a000555318 thread T32
    #0 0x55de8fc175d9 in Item_field::print(String*, enum_query_type) /10.9/sql/item.cc:7821
    #1 0x55de8fd7fd65 in Item_func_conv_charset::print(String*, enum_query_type) /10.9/sql/item_strfunc.cc:3711
    #2 0x55de8f815ba6 in write_item /10.9/sql/sql_explain.cc:1544
    #3 0x55de8f816046 in Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag) /10.9/sql/sql_explain.cc:1602
    #4 0x55de8f8176ce in Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1883
    #5 0x55de8f812f13 in Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1125
    #6 0x55de8f8122ba in Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1020
    #7 0x55de8f80d29c in Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long) /10.9/sql/sql_explain.cc:248
    #8 0x55de8f27ad62 in LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*) /10.9/sql/sql_lex.cc:5856
    #9 0x55de8f4e64bd in Show_explain_request::call_in_target_thread() /10.9/sql/sql_show.cc:3003
    #10 0x55de8f8a433c in Apc_target::process_apc_requests() /10.9/sql/my_apc.cc:225
    #11 0x55de8f81dce6 in Apc_target::disable() /10.9/sql/my_apc.h:73
    #12 0x55de8f80c873 in Explain_query::notify_item_objects_about_to_be_freed() /10.9/sql/sql_explain.cc:167
    #13 0x55de8f1ac544 in THD::cleanup_after_query() /10.9/sql/sql_class.cc:2245
    #14 0x55de8f307176 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8058
    #15 0x55de8f2dd59b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1895
    #16 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #17 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #18 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #19 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #20 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486
    #21 0x7fadde000efe in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf8efe)

0x61a000555318 is located 664 bytes inside of 1156-byte region [0x61a000555080,0x61a000555504)
freed by thread T31 here:
    #0 0x7faddeb0afb0 in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0xe8fb0)
    #1 0x55de91008ec7 in free_memory /10.9/mysys/safemalloc.c:297
    #2 0x55de91008376 in sf_free /10.9/mysys/safemalloc.c:203
    #3 0x55de90fd7509 in my_free /10.9/mysys/my_malloc.c:211
    #4 0x55de90fb21a0 in root_free /10.9/mysys/my_alloc.c:78
    #5 0x55de90fb4902 in free_root /10.9/mysys/my_alloc.c:495
    #6 0x55de8f69313b in closefrm(TABLE*) /10.9/sql/table.cc:4464
    #7 0x55de8f9c9046 in intern_close_table /10.9/sql/table_cache.cc:220
    #8 0x55de8f9d0fb0 in TDC_element::flush_unused(bool) /10.9/sql/table_cache.cc:1293
    #9 0x55de8f9d0bf0 in TDC_element::flush(THD*, bool) /10.9/sql/table_cache.cc:1258
    #10 0x55de8f13b935 in wait_while_table_is_used(THD*, TABLE*, ha_extra_function) /10.9/sql/sql_base.cc:1318
    #11 0x55de8f5cb8b9 in simple_rename_or_index_change /10.9/sql/sql_table.cc:9395
    #12 0x55de8f5d1c7c in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool) /10.9/sql/sql_table.cc:10298
    #13 0x55de8f78aad2 in Sql_cmd_alter_table::execute(THD*) /10.9/sql/sql_alter.cc:547
    #14 0x55de8f2f9b0d in mysql_execute_command(THD*, bool) /10.9/sql/sql_parse.cc:5995
    #15 0x55de8f306d68 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8034
    #16 0x55de8f2ddfb6 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1992
    #17 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #18 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #19 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #20 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #21 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486

previously allocated by thread T32 here:
    #0 0x7faddeb0b330 in __interceptor_malloc (/lib/x86_64-linux-gnu/libasan.so.5+0xe9330)
    #1 0x55de91007d5c in sf_malloc /10.9/mysys/safemalloc.c:126
    #2 0x55de90fd675b in my_malloc /10.9/mysys/my_malloc.c:90
    #3 0x55de90fb211c in root_alloc /10.9/mysys/my_alloc.c:66
    #4 0x55de90fb38db in alloc_root /10.9/mysys/my_alloc.c:332
    #5 0x55de90fb531b in strmake_root /10.9/mysys/my_alloc.c:584
    #6 0x55de8f68f50a in open_table_from_share(THD*, TABLE_SHARE*, st_mysql_const_lex_string const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, List<String>*) /10.9/sql/table.cc:4033
    #7 0x55de8f13f0bf in open_table(THD*, TABLE_LIST*, Open_table_context*) /10.9/sql/sql_base.cc:2003
    #8 0x55de8f148a66 in open_and_process_table /10.9/sql/sql_base.cc:3809
    #9 0x55de8f14b683 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /10.9/sql/sql_base.cc:4292
    #10 0x55de8f15076b in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /10.9/sql/sql_base.cc:5265
    #11 0x55de8f0accc4 in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /10.9/sql/sql_base.h:509
    #12 0x55de8f2fb454 in execute_sqlcom_select /10.9/sql/sql_parse.cc:6180
    #13 0x55de8f2eaac1 in mysql_execute_command(THD*, bool) /10.9/sql/sql_parse.cc:3950
    #14 0x55de8f306d68 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8034
    #15 0x55de8f2dd59b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1895
    #16 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #17 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #18 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #19 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #20 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486

Thread T32 created by T0 here:
    #0 0x7faddea72db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x55de903eab5a in my_thread_create /10.9/storage/perfschema/my_thread.h:52
    #2 0x55de903ef429 in pfs_spawn_thread_v1 /10.9/storage/perfschema/pfs.cc:2252
    #3 0x55de8ef36546 in inline_mysql_thread_create /10.9/include/mysql/psi/mysql_thread.h:1139
    #4 0x55de8ef4d9d4 in create_thread_to_handle_connection(CONNECT*) /10.9/sql/mysqld.cc:5975
    #5 0x55de8ef4e03f in create_new_thread(CONNECT*) /10.9/sql/mysqld.cc:6034
    #6 0x55de8ef4e3b1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.9/sql/mysqld.cc:6096
    #7 0x55de8ef4edb0 in handle_connections_sockets() /10.9/sql/mysqld.cc:6220
    #8 0x55de8ef4d23b in mysqld_main(int, char**) /10.9/sql/mysqld.cc:5870
    #9 0x55de8ef35794 in main /10.9/sql/main.cc:34
    #10 0x7fadddf2c09a in __libc_start_main ../csu/libc-start.c:308

Thread T31 created by T0 here:
    #0 0x7faddea72db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x55de903eab5a in my_thread_create /10.9/storage/perfschema/my_thread.h:52
    #2 0x55de903ef429 in pfs_spawn_thread_v1 /10.9/storage/perfschema/pfs.cc:2252
    #3 0x55de8ef36546 in inline_mysql_thread_create /10.9/include/mysql/psi/mysql_thread.h:1139
    #4 0x55de8ef4d9d4 in create_thread_to_handle_connection(CONNECT*) /10.9/sql/mysqld.cc:5975
    #5 0x55de8ef4e03f in create_new_thread(CONNECT*) /10.9/sql/mysqld.cc:6034
    #6 0x55de8ef4e3b1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.9/sql/mysqld.cc:6096
    #7 0x55de8ef4edb0 in handle_connections_sockets() /10.9/sql/mysqld.cc:6220
    #8 0x55de8ef4d23b in mysqld_main(int, char**) /10.9/sql/mysqld.cc:5870
    #9 0x55de8ef35794 in main /10.9/sql/main.cc:34
    #10 0x7fadddf2c09a in __libc_start_main ../csu/libc-start.c:308

SUMMARY: AddressSanitizer: heap-use-after-free /10.9/sql/item.cc:7821 in Item_field::print(String*, enum_query_type)
Shadow bytes around the buggy address:
  0x0c34800a2a10: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a50: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c34800a2a60: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a70: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2aa0: fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c34800a2ab0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable: 00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone: fa
  Freed heap region: fd
  Stack left redzone: f1
  Stack mid redzone: f2
  Stack right redzone: f3
  Stack after return: f5
  Stack use after scope: f8
  Global redzone: f9
  Global init order: f6
  Poisoned by user: f7
  Container overflow: fc
  Array cookie: ac
  Intra object redzone: bb
  ASan internal: fe
  Left alloca redzone: ca
  Right alloca redzone: cb
==69440==ABORTING
SHUTDOWN_1648646328
{noformat}

Alice Sherepa made changes - 2022-03-30 16:09

Description

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
    SELECT i FROM (SELECT DISTINCT * FROM t1) a1 GROUP BY i ;

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
Version: '10.9.0-MariaDB-debug-log'
220330 17:04:13 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f5d1927a3c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x563a4b0fe850]
sql/sql_explain.cc:1557(append_item_to_str(String*, Item*))[0x563a4af221d0]
sql/sql_explain.cc:1070(Explain_aggr_filesort::print_json_members(Json_writer*, bool))[0x563a4af2032a]
sql/sql_explain.cc:1002(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x563a4af1ffa5]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x563a4af1d203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x563a4acce9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x563a4adcee84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x563a4af5bd94]
sql/my_apc.h:74(Apc_target::disable())[0x563a4af26ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x563a4af1cdea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x563a4ac7a7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x563a4ad10470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x563a4acfc6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x563a4acfb09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x563a4aed4221]
sql/sql_connect.cc:1314(handle_one_connection)[0x563a4aed3eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x563a4b423e4b]
nptl/pthread_create.c:478(start_thread)[0x7f5d1926e609]
??:0(clone)[0x7f5d18e3f163]

Query (0x7f5ce4015420): SHOW EXPLAIN FORMAT=JSON FOR 5
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
SELECT i FROM (SELECT DISTINCT * FROM t1) a1 WHERE i IN ('v');

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
220330 17:21:40 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f20410413c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x55da53a1f850]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55da53a07b9b]
sql/item_func.cc:631(Item_func::print_op(String*, enum_query_type))[0x55da53a7361e]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x55da534d2df9]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x55da538430d4]
sql/sql_explain.cc:1605(Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag))[0x55da538433d0]
sql/sql_explain.cc:1881(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da538442c0]
sql/sql_explain.cc:1127(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55da538416b7]
sql/sql_explain.cc:1022(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da53841068]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x55da5383e203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x55da535ef9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x55da536efe84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x55da5387cd94]
sql/my_apc.h:74(Apc_target::disable())[0x55da53847ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x55da5383ddea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x55da5359b7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55da53631470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55da5361d6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55da5361c09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55da537f5221]
sql/sql_connect.cc:1314(handle_one_connection)[0x55da537f4eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55da53d44e4b]
nptl/pthread_create.c:478(start_thread)[0x7f2041035609]
??:0(clone)[0x7f2040c06163]

Query (0x7f200c015420): SHOW EXPLAIN FORMAT=JSON FOR 5

{noformat}

++variations:
{noformat}
mysqld: /10.9/sql/field.cc:7525: virtual String* Field_string::val_str(String*, String*): Assertion `!table || table->in_use == _current_thd()' failed.
220330 13:20:06 [ERROR] mysqld got signal 6 ;

Server version: 10.9.0-MariaDB-debug-log

linux/raise.c:51(__GI_raise)[0x7ff324cda7bb]
stdlib/abort.c:81(__GI_abort)[0x7ff324cc5535]
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7ff324cc540f]
??:0(__assert_fail)[0x7ff324cd3102]
sql/field.cc:7527(Field_string::val_str(String*, String*))[0x556cb3f697dc]
sql/item.cc:3323(Item_field::val_str(String*))[0x556cb40314cc]
sql/item.cc:526(Item::print_value(String*))[0x556cb40194c3]
sql/item.cc:7825(Item_field::print(String*, enum_query_type))[0x556cb4054640]
sql/item.cc:8331(Item_ref::print(String*, enum_query_type))[0x556cb40588b2]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x556cb4018fdd]
sql/item_func.cc:636(Item_func::print_op(String*, enum_query_type))[0x556cb410d163]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x556cb3428dd1]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x556cb4018fdd]
sql/item_cmpfunc.cc:5286(Item_cond::print(String*, enum_query_type))[0x556cb40b70bb]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x556cb3c52ba7]
sql/sql_explain.cc:974(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x556cb3c4ee52]
sql/sql_explain.cc:737(Explain_node::print_explain_json_for_children(Explain_query*, Json_writer*, bool))[0x556cb3c4d599]
sql/sql_explain.cc:939(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x556cb3c4eb0e]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x556cb3c4a29d]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x556cb36b7d63]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x556cb39234be]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x556cb3ce133d]
sql/my_apc.h:74(Apc_target::disable())[0x556cb3c5ace7]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x556cb3c49874]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x556cb35e9545]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x556cb3744177]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x556cb371a59c]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x556cb3717291]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x556cb3baa786]
sql/sql_connect.cc:1314(handle_one_connection)[0x556cb3baa00b]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x556cb482c03b]
nptl/pthread_create.c:487(start_thread)[0x7ff325192fa3]
x86_64/clone.S:97(clone)[0x7ff324d9beff]

Query (0x6290007994e8): SHOW ANALYZE FORMAT=JSON FOR 18
{noformat}

{noformat}
=================================================================
==69440==ERROR: AddressSanitizer: heap-use-after-free on address 0x61a000555318 at pc 0x55de8fc175da bp 0x7fadb04b5c80 sp 0x7fadb04b5c78
READ of size 8 at 0x61a000555318 thread T32
    #0 0x55de8fc175d9 in Item_field::print(String*, enum_query_type) /10.9/sql/item.cc:7821
    #1 0x55de8fd7fd65 in Item_func_conv_charset::print(String*, enum_query_type) /10.9/sql/item_strfunc.cc:3711
    #2 0x55de8f815ba6 in write_item /10.9/sql/sql_explain.cc:1544
    #3 0x55de8f816046 in Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag) /10.9/sql/sql_explain.cc:1602
    #4 0x55de8f8176ce in Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1883
    #5 0x55de8f812f13 in Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1125
    #6 0x55de8f8122ba in Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1020
    #7 0x55de8f80d29c in Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long) /10.9/sql/sql_explain.cc:248
    #8 0x55de8f27ad62 in LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*) /10.9/sql/sql_lex.cc:5856
    #9 0x55de8f4e64bd in Show_explain_request::call_in_target_thread() /10.9/sql/sql_show.cc:3003
    #10 0x55de8f8a433c in Apc_target::process_apc_requests() /10.9/sql/my_apc.cc:225
    #11 0x55de8f81dce6 in Apc_target::disable() /10.9/sql/my_apc.h:73
    #12 0x55de8f80c873 in Explain_query::notify_item_objects_about_to_be_freed() /10.9/sql/sql_explain.cc:167
    #13 0x55de8f1ac544 in THD::cleanup_after_query() /10.9/sql/sql_class.cc:2245
    #14 0x55de8f307176 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8058
    #15 0x55de8f2dd59b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1895
    #16 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #17 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #18 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #19 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #20 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486
    #21 0x7fadde000efe in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf8efe)

0x61a000555318 is located 664 bytes inside of 1156-byte region [0x61a000555080,0x61a000555504)
freed by thread T31 here:
    #0 0x7faddeb0afb0 in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0xe8fb0)
    #1 0x55de91008ec7 in free_memory /10.9/mysys/safemalloc.c:297
    #2 0x55de91008376 in sf_free /10.9/mysys/safemalloc.c:203
    #3 0x55de90fd7509 in my_free /10.9/mysys/my_malloc.c:211
    #4 0x55de90fb21a0 in root_free /10.9/mysys/my_alloc.c:78
    #5 0x55de90fb4902 in free_root /10.9/mysys/my_alloc.c:495
    #6 0x55de8f69313b in closefrm(TABLE*) /10.9/sql/table.cc:4464
    #7 0x55de8f9c9046 in intern_close_table /10.9/sql/table_cache.cc:220
    #8 0x55de8f9d0fb0 in TDC_element::flush_unused(bool) /10.9/sql/table_cache.cc:1293
    #9 0x55de8f9d0bf0 in TDC_element::flush(THD*, bool) /10.9/sql/table_cache.cc:1258
    #10 0x55de8f13b935 in wait_while_table_is_used(THD*, TABLE*, ha_extra_function) /10.9/sql/sql_base.cc:1318
    #11 0x55de8f5cb8b9 in simple_rename_or_index_change /10.9/sql/sql_table.cc:9395
    #12 0x55de8f5d1c7c in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool) /10.9/sql/sql_table.cc:10298
    #13 0x55de8f78aad2 in Sql_cmd_alter_table::execute(THD*) /10.9/sql/sql_alter.cc:547
    #14 0x55de8f2f9b0d in mysql_execute_command(THD*, bool) /10.9/sql/sql_parse.cc:5995
    #15 0x55de8f306d68 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8034
    #16 0x55de8f2ddfb6 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1992
    #17 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #18 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #19 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #20 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #21 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486

previously allocated by thread T32 here:
    #0 0x7faddeb0b330 in __interceptor_malloc (/lib/x86_64-linux-gnu/libasan.so.5+0xe9330)
    #1 0x55de91007d5c in sf_malloc /10.9/mysys/safemalloc.c:126
    #2 0x55de90fd675b in my_malloc /10.9/mysys/my_malloc.c:90
    #3 0x55de90fb211c in root_alloc /10.9/mysys/my_alloc.c:66
    #4 0x55de90fb38db in alloc_root /10.9/mysys/my_alloc.c:332
    #5 0x55de90fb531b in strmake_root /10.9/mysys/my_alloc.c:584
    #6 0x55de8f68f50a in open_table_from_share(THD*, TABLE_SHARE*, st_mysql_const_lex_string const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, List<String>*) /10.9/sql/table.cc:4033
    #7 0x55de8f13f0bf in open_table(THD*, TABLE_LIST*, Open_table_context*) /10.9/sql/sql_base.cc:2003
    #8 0x55de8f148a66 in open_and_process_table /10.9/sql/sql_base.cc:3809
    #9 0x55de8f14b683 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /10.9/sql/sql_base.cc:4292
    #10 0x55de8f15076b in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /10.9/sql/sql_base.cc:5265
    #11 0x55de8f0accc4 in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /10.9/sql/sql_base.h:509
    #12 0x55de8f2fb454 in execute_sqlcom_select /10.9/sql/sql_parse.cc:6180
    #13 0x55de8f2eaac1 in mysql_execute_command(THD*, bool) /10.9/sql/sql_parse.cc:3950
    #14 0x55de8f306d68 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8034
    #15 0x55de8f2dd59b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1895
    #16 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #17 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #18 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #19 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #20 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486

Thread T32 created by T0 here:
    #0 0x7faddea72db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x55de903eab5a in my_thread_create /10.9/storage/perfschema/my_thread.h:52
    #2 0x55de903ef429 in pfs_spawn_thread_v1 /10.9/storage/perfschema/pfs.cc:2252
    #3 0x55de8ef36546 in inline_mysql_thread_create /10.9/include/mysql/psi/mysql_thread.h:1139
    #4 0x55de8ef4d9d4 in create_thread_to_handle_connection(CONNECT*) /10.9/sql/mysqld.cc:5975
    #5 0x55de8ef4e03f in create_new_thread(CONNECT*) /10.9/sql/mysqld.cc:6034
    #6 0x55de8ef4e3b1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.9/sql/mysqld.cc:6096
    #7 0x55de8ef4edb0 in handle_connections_sockets() /10.9/sql/mysqld.cc:6220
    #8 0x55de8ef4d23b in mysqld_main(int, char**) /10.9/sql/mysqld.cc:5870
    #9 0x55de8ef35794 in main /10.9/sql/main.cc:34
    #10 0x7fadddf2c09a in __libc_start_main ../csu/libc-start.c:308

Thread T31 created by T0 here:
    #0 0x7faddea72db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x55de903eab5a in my_thread_create /10.9/storage/perfschema/my_thread.h:52
    #2 0x55de903ef429 in pfs_spawn_thread_v1 /10.9/storage/perfschema/pfs.cc:2252
    #3 0x55de8ef36546 in inline_mysql_thread_create /10.9/include/mysql/psi/mysql_thread.h:1139
    #4 0x55de8ef4d9d4 in create_thread_to_handle_connection(CONNECT*) /10.9/sql/mysqld.cc:5975
    #5 0x55de8ef4e03f in create_new_thread(CONNECT*) /10.9/sql/mysqld.cc:6034
    #6 0x55de8ef4e3b1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.9/sql/mysqld.cc:6096
    #7 0x55de8ef4edb0 in handle_connections_sockets() /10.9/sql/mysqld.cc:6220
    #8 0x55de8ef4d23b in mysqld_main(int, char**) /10.9/sql/mysqld.cc:5870
    #9 0x55de8ef35794 in main /10.9/sql/main.cc:34
    #10 0x7fadddf2c09a in __libc_start_main ../csu/libc-start.c:308

SUMMARY: AddressSanitizer: heap-use-after-free /10.9/sql/item.cc:7821 in Item_field::print(String*, enum_query_type)
Shadow bytes around the buggy address:
  0x0c34800a2a10: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a50: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c34800a2a60: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a70: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2aa0: fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c34800a2ab0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable: 00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone: fa
  Freed heap region: fd
  Stack left redzone: f1
  Stack mid redzone: f2
  Stack right redzone: f3
  Stack after return: f5
  Stack use after scope: f8
  Global redzone: f9
  Global init order: f6
  Poisoned by user: f7
  Container overflow: fc
  Array cookie: ac
  Intra object redzone: bb
  ASan internal: fe
  Left alloca redzone: ca
  Right alloca redzone: cb
==69440==ABORTING
SHUTDOWN_1648646328
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
    SELECT i FROM (SELECT DISTINCT * FROM t1) a1 GROUP BY i ;

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
Version: '10.9.0-MariaDB-debug-log'
220330 17:04:13 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f5d1927a3c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x563a4b0fe850]
sql/sql_explain.cc:1557(append_item_to_str(String*, Item*))[0x563a4af221d0]
sql/sql_explain.cc:1070(Explain_aggr_filesort::print_json_members(Json_writer*, bool))[0x563a4af2032a]
sql/sql_explain.cc:1002(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x563a4af1ffa5]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x563a4af1d203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x563a4acce9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x563a4adcee84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x563a4af5bd94]
sql/my_apc.h:74(Apc_target::disable())[0x563a4af26ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x563a4af1cdea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x563a4ac7a7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x563a4ad10470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x563a4acfc6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x563a4acfb09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x563a4aed4221]
sql/sql_connect.cc:1314(handle_one_connection)[0x563a4aed3eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x563a4b423e4b]
nptl/pthread_create.c:478(start_thread)[0x7f5d1926e609]
??:0(clone)[0x7f5d18e3f163]

Query (0x7f5ce4015420): SHOW EXPLAIN FORMAT=JSON FOR 5
{noformat}

{code:sql}
CREATE TABLE t1 (i int) ;
INSERT INTO t1 VALUES (1),(2),(3);

--connect (con1,localhost,root,,test)
--let $conid= `SELECT CONNECTION_ID()`

--let $run=100
while ($run)
{
  send
SELECT i FROM (SELECT DISTINCT * FROM t1) a1 WHERE i IN ('v');

  --connection default
  --let $show=100
  while ($show)
  {
    --error 0,ER_TARGET_NOT_EXPLAINABLE
     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;
     --dec $show
  }
  --connection con1
  --reap
  --dec $run
}

# Cleanup
--disconnect con1
{code}

{noformat:title=preview-10.9-~~MDEV-27021~~-explain afa835568a1623991799830175039816b9ac2681}
220330 17:21:40 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sigaction.c:0(__restore_rt)[0x7f20410413c0]
sql/item.cc:7821(Item_field::print(String*, enum_query_type))[0x55da53a1f850]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x55da53a07b9b]
sql/item_func.cc:631(Item_func::print_op(String*, enum_query_type))[0x55da53a7361e]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x55da534d2df9]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x55da538430d4]
sql/sql_explain.cc:1605(Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag))[0x55da538433d0]
sql/sql_explain.cc:1881(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da538442c0]
sql/sql_explain.cc:1127(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x55da538416b7]
sql/sql_explain.cc:1022(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x55da53841068]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x55da5383e203]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x55da535ef9a4]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x55da536efe84]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x55da5387cd94]
sql/my_apc.h:74(Apc_target::disable())[0x55da53847ad3]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x55da5383ddea]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x55da5359b7a8]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55da53631470]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55da5361d6ff]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55da5361c09b]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55da537f5221]
sql/sql_connect.cc:1314(handle_one_connection)[0x55da537f4eb1]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55da53d44e4b]
nptl/pthread_create.c:478(start_thread)[0x7f2041035609]
??:0(clone)[0x7f2040c06163]

Query (0x7f200c015420): SHOW EXPLAIN FORMAT=JSON FOR 5

{noformat}

++variations:
{noformat}
mysqld: /10.9/sql/field.cc:7525: virtual String* Field_string::val_str(String*, String*): Assertion `!table || table->in_use == _current_thd()' failed.
220330 13:20:06 [ERROR] mysqld got signal 6 ;

Server version: 10.9.0-MariaDB-debug-log

linux/raise.c:51(__GI_raise)[0x7ff324cda7bb]
stdlib/abort.c:81(__GI_abort)[0x7ff324cc5535]
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7ff324cc540f]
??:0(__assert_fail)[0x7ff324cd3102]
sql/field.cc:7527(Field_string::val_str(String*, String*))[0x556cb3f697dc]
sql/item.cc:3323(Item_field::val_str(String*))[0x556cb40314cc]
sql/item.cc:526(Item::print_value(String*))[0x556cb40194c3]
sql/item.cc:7825(Item_field::print(String*, enum_query_type))[0x556cb4054640]
sql/item.cc:8331(Item_ref::print(String*, enum_query_type))[0x556cb40588b2]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x556cb4018fdd]
sql/item_func.cc:636(Item_func::print_op(String*, enum_query_type))[0x556cb410d163]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x556cb3428dd1]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x556cb4018fdd]
sql/item_cmpfunc.cc:5286(Item_cond::print(String*, enum_query_type))[0x556cb40b70bb]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x556cb3c52ba7]
sql/sql_explain.cc:974(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x556cb3c4ee52]
sql/sql_explain.cc:737(Explain_node::print_explain_json_for_children(Explain_query*, Json_writer*, bool))[0x556cb3c4d599]
sql/sql_explain.cc:939(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x556cb3c4eb0e]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x556cb3c4a29d]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x556cb36b7d63]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x556cb39234be]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x556cb3ce133d]
sql/my_apc.h:74(Apc_target::disable())[0x556cb3c5ace7]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x556cb3c49874]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x556cb35e9545]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x556cb3744177]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x556cb371a59c]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x556cb3717291]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x556cb3baa786]
sql/sql_connect.cc:1314(handle_one_connection)[0x556cb3baa00b]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x556cb482c03b]
nptl/pthread_create.c:487(start_thread)[0x7ff325192fa3]
x86_64/clone.S:97(clone)[0x7ff324d9beff]

Query (0x6290007994e8): SHOW ANALYZE FORMAT=JSON FOR 18
{noformat}

{noformat}
=================================================================
==69440==ERROR: AddressSanitizer: heap-use-after-free on address 0x61a000555318 at pc 0x55de8fc175da bp 0x7fadb04b5c80 sp 0x7fadb04b5c78
READ of size 8 at 0x61a000555318 thread T32
    #0 0x55de8fc175d9 in Item_field::print(String*, enum_query_type) /10.9/sql/item.cc:7821
    #1 0x55de8fd7fd65 in Item_func_conv_charset::print(String*, enum_query_type) /10.9/sql/item_strfunc.cc:3711
    #2 0x55de8f815ba6 in write_item /10.9/sql/sql_explain.cc:1544
    #3 0x55de8f816046 in Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag) /10.9/sql/sql_explain.cc:1602
    #4 0x55de8f8176ce in Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1883
    #5 0x55de8f812f13 in Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1125
    #6 0x55de8f8122ba in Explain_select::print_explain_json(Explain_query*, Json_writer*, bool) /10.9/sql/sql_explain.cc:1020
    #7 0x55de8f80d29c in Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long) /10.9/sql/sql_explain.cc:248
    #8 0x55de8f27ad62 in LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*) /10.9/sql/sql_lex.cc:5856
    #9 0x55de8f4e64bd in Show_explain_request::call_in_target_thread() /10.9/sql/sql_show.cc:3003
    #10 0x55de8f8a433c in Apc_target::process_apc_requests() /10.9/sql/my_apc.cc:225
    #11 0x55de8f81dce6 in Apc_target::disable() /10.9/sql/my_apc.h:73
    #12 0x55de8f80c873 in Explain_query::notify_item_objects_about_to_be_freed() /10.9/sql/sql_explain.cc:167
    #13 0x55de8f1ac544 in THD::cleanup_after_query() /10.9/sql/sql_class.cc:2245
    #14 0x55de8f307176 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8058
    #15 0x55de8f2dd59b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1895
    #16 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #17 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #18 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #19 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #20 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486
    #21 0x7fadde000efe in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf8efe)

0x61a000555318 is located 664 bytes inside of 1156-byte region [0x61a000555080,0x61a000555504)
freed by thread T31 here:
    #0 0x7faddeb0afb0 in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0xe8fb0)
    #1 0x55de91008ec7 in free_memory /10.9/mysys/safemalloc.c:297
    #2 0x55de91008376 in sf_free /10.9/mysys/safemalloc.c:203
    #3 0x55de90fd7509 in my_free /10.9/mysys/my_malloc.c:211
    #4 0x55de90fb21a0 in root_free /10.9/mysys/my_alloc.c:78
    #5 0x55de90fb4902 in free_root /10.9/mysys/my_alloc.c:495
    #6 0x55de8f69313b in closefrm(TABLE*) /10.9/sql/table.cc:4464
    #7 0x55de8f9c9046 in intern_close_table /10.9/sql/table_cache.cc:220
    #8 0x55de8f9d0fb0 in TDC_element::flush_unused(bool) /10.9/sql/table_cache.cc:1293
    #9 0x55de8f9d0bf0 in TDC_element::flush(THD*, bool) /10.9/sql/table_cache.cc:1258
    #10 0x55de8f13b935 in wait_while_table_is_used(THD*, TABLE*, ha_extra_function) /10.9/sql/sql_base.cc:1318
    #11 0x55de8f5cb8b9 in simple_rename_or_index_change /10.9/sql/sql_table.cc:9395
    #12 0x55de8f5d1c7c in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool) /10.9/sql/sql_table.cc:10298
    #13 0x55de8f78aad2 in Sql_cmd_alter_table::execute(THD*) /10.9/sql/sql_alter.cc:547
    #14 0x55de8f2f9b0d in mysql_execute_command(THD*, bool) /10.9/sql/sql_parse.cc:5995
    #15 0x55de8f306d68 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8034
    #16 0x55de8f2ddfb6 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1992
    #17 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #18 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #19 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #20 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #21 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486

previously allocated by thread T32 here:
    #0 0x7faddeb0b330 in __interceptor_malloc (/lib/x86_64-linux-gnu/libasan.so.5+0xe9330)
    #1 0x55de91007d5c in sf_malloc /10.9/mysys/safemalloc.c:126
    #2 0x55de90fd675b in my_malloc /10.9/mysys/my_malloc.c:90
    #3 0x55de90fb211c in root_alloc /10.9/mysys/my_alloc.c:66
    #4 0x55de90fb38db in alloc_root /10.9/mysys/my_alloc.c:332
    #5 0x55de90fb531b in strmake_root /10.9/mysys/my_alloc.c:584
    #6 0x55de8f68f50a in open_table_from_share(THD*, TABLE_SHARE*, st_mysql_const_lex_string const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, List<String>*) /10.9/sql/table.cc:4033
    #7 0x55de8f13f0bf in open_table(THD*, TABLE_LIST*, Open_table_context*) /10.9/sql/sql_base.cc:2003
    #8 0x55de8f148a66 in open_and_process_table /10.9/sql/sql_base.cc:3809
    #9 0x55de8f14b683 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /10.9/sql/sql_base.cc:4292
    #10 0x55de8f15076b in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /10.9/sql/sql_base.cc:5265
    #11 0x55de8f0accc4 in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /10.9/sql/sql_base.h:509
    #12 0x55de8f2fb454 in execute_sqlcom_select /10.9/sql/sql_parse.cc:6180
    #13 0x55de8f2eaac1 in mysql_execute_command(THD*, bool) /10.9/sql/sql_parse.cc:3950
    #14 0x55de8f306d68 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.9/sql/sql_parse.cc:8034
    #15 0x55de8f2dd59b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.9/sql/sql_parse.cc:1895
    #16 0x55de8f2da290 in do_command(THD*, bool) /10.9/sql/sql_parse.cc:1403
    #17 0x55de8f76d785 in do_handle_one_connection(CONNECT*, bool) /10.9/sql/sql_connect.cc:1418
    #18 0x55de8f76d00a in handle_one_connection /10.9/sql/sql_connect.cc:1312
    #19 0x55de903ef03a in pfs_spawn_thread /10.9/storage/perfschema/pfs.cc:2201
    #20 0x7fadde3f7fa2 in start_thread /build/glibc-fWwxX8/glibc-2.28/nptl/pthread_create.c:486

Thread T32 created by T0 here:
    #0 0x7faddea72db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x55de903eab5a in my_thread_create /10.9/storage/perfschema/my_thread.h:52
    #2 0x55de903ef429 in pfs_spawn_thread_v1 /10.9/storage/perfschema/pfs.cc:2252
    #3 0x55de8ef36546 in inline_mysql_thread_create /10.9/include/mysql/psi/mysql_thread.h:1139
    #4 0x55de8ef4d9d4 in create_thread_to_handle_connection(CONNECT*) /10.9/sql/mysqld.cc:5975
    #5 0x55de8ef4e03f in create_new_thread(CONNECT*) /10.9/sql/mysqld.cc:6034
    #6 0x55de8ef4e3b1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.9/sql/mysqld.cc:6096
    #7 0x55de8ef4edb0 in handle_connections_sockets() /10.9/sql/mysqld.cc:6220
    #8 0x55de8ef4d23b in mysqld_main(int, char**) /10.9/sql/mysqld.cc:5870
    #9 0x55de8ef35794 in main /10.9/sql/main.cc:34
    #10 0x7fadddf2c09a in __libc_start_main ../csu/libc-start.c:308

Thread T31 created by T0 here:
    #0 0x7faddea72db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x55de903eab5a in my_thread_create /10.9/storage/perfschema/my_thread.h:52
    #2 0x55de903ef429 in pfs_spawn_thread_v1 /10.9/storage/perfschema/pfs.cc:2252
    #3 0x55de8ef36546 in inline_mysql_thread_create /10.9/include/mysql/psi/mysql_thread.h:1139
    #4 0x55de8ef4d9d4 in create_thread_to_handle_connection(CONNECT*) /10.9/sql/mysqld.cc:5975
    #5 0x55de8ef4e03f in create_new_thread(CONNECT*) /10.9/sql/mysqld.cc:6034
    #6 0x55de8ef4e3b1 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.9/sql/mysqld.cc:6096
    #7 0x55de8ef4edb0 in handle_connections_sockets() /10.9/sql/mysqld.cc:6220
    #8 0x55de8ef4d23b in mysqld_main(int, char**) /10.9/sql/mysqld.cc:5870
    #9 0x55de8ef35794 in main /10.9/sql/main.cc:34
    #10 0x7fadddf2c09a in __libc_start_main ../csu/libc-start.c:308

SUMMARY: AddressSanitizer: heap-use-after-free /10.9/sql/item.cc:7821 in Item_field::print(String*, enum_query_type)
Shadow bytes around the buggy address:
  0x0c34800a2a10: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a50: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c34800a2a60: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a70: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2a90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c34800a2aa0: fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c34800a2ab0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable: 00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone: fa
  Freed heap region: fd
  Stack left redzone: f1
  Stack mid redzone: f2
  Stack right redzone: f3
  Stack after return: f5
  Stack use after scope: f8
  Global redzone: f9
  Global init order: f6
  Poisoned by user: f7
  Container overflow: fc
  Array cookie: ac
  Intra object redzone: bb
  ASan internal: fe
  Left alloca redzone: ca
  Right alloca redzone: cb
==69440==ABORTING
SHUTDOWN_1648646328
{noformat}

{noformat}
220330 17:06:12 [ERROR] mysqld got signal 11 ;

Server version: 10.9.0-MariaDB-debug-log

sql/sql_class.h:3860(THD::temporal_round_mode() const)[0x560afb9c38e3]
sql/sql_type.cc:322(Temporal::default_round_mode(THD*))[0x560afbbe3050]
sql/sql_type.h:2348(Datetime::Options::Options(date_conv_mode_t, THD*))[0x560afb223d6f]
sql/field.cc:5411(Field_timestamp::val_str(String*, String*))[0x560afbddbdce]
sql/item.cc:3323(Item_field::val_str(String*))[0x560afbebb4cc]
sql/item.cc:526(Item::print_value(String*))[0x560afbea34c3]
sql/item.cc:7825(Item_field::print(String*, enum_query_type))[0x560afbede640]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x560afbea2fdd]
sql/item_func.cc:636(Item_func::print_op(String*, enum_query_type))[0x560afbf97163]
sql/item_cmpfunc.h:551(Item_bool_rowready_func2::print(String*, enum_query_type))[0x560afb2b2dd1]
sql/item.cc:497(Item::print_parenthesised(String*, enum_query_type, precedence))[0x560afbea2fdd]
sql/item_cmpfunc.cc:5286(Item_cond::print(String*, enum_query_type))[0x560afbf410bb]
sql/sql_explain.cc:1546(write_item(Json_writer*, Item*))[0x560afbadcba7]
sql/sql_explain.cc:1605(Explain_table_access::tag_to_json(Json_writer*, explain_extra_tag))[0x560afbadd047]
sql/sql_explain.cc:1881(Explain_table_access::print_explain_json(Explain_query*, Json_writer*, bool))[0x560afbade6cf]
sql/sql_explain.cc:1127(Explain_basic_join::print_explain_json_interns(Explain_query*, Json_writer*, bool))[0x560afbad9f14]
sql/sql_explain.cc:1022(Explain_select::print_explain_json(Explain_query*, Json_writer*, bool))[0x560afbad92bb]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, unsigned long long))[0x560afbad429d]
sql/sql_lex.cc:5856(LEX::print_explain(select_result_sink*, unsigned char, bool, bool, bool*))[0x560afb541d63]
sql/sql_show.cc:3005(Show_explain_request::call_in_target_thread())[0x560afb7ad4be]
sql/my_apc.cc:226(Apc_target::process_apc_requests())[0x560afbb6b33d]
sql/my_apc.h:74(Apc_target::disable())[0x560afbae4ce7]
sql/sql_explain.cc:168(Explain_query::notify_item_objects_about_to_be_freed())[0x560afbad3874]
sql/sql_class.cc:2257(THD::cleanup_after_query())[0x560afb473545]
sql/sql_parse.cc:8058(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x560afb5ce177]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x560afb5a459c]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x560afb5a1291]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x560afba34786]
sql/sql_connect.cc:1314(handle_one_connection)[0x560afba3400b]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x560afc6b603b]
nptl/pthread_create.c:487(start_thread)[0x7fac24e95fa3]
x86_64/clone.S:97(clone)[0x7fac24a9eeff]
{noformat}

Sergei Petrunia added a comment - 2022-03-31 07:28

This fix makes the crash go away:

diff --git a/sql/item.cc b/sql/item.cc

index c4ba402db49..52660f4495f 100644

--- a/sql/item.cc

+++ b/sql/item.cc

@@ -3129,6 +3129,8 @@ void Item_field::set_field(Field *field_par)

     any_privileges= 0;

     refers_to_temp_table= true;

+  if (field->table->s->tmp_table == INTERNAL_TMP_TABLE)

+    refers_to_temp_table= true;

but then some explain outputs change in MTR.

Sergei Petrunia added a comment - 2022-03-31 07:28 This fix makes the crash go away: diff --git a/sql/item.cc b/sql/item.cc index c4ba402db49..52660f4495f 100644 --- a/sql/item.cc +++ b/sql/item.cc @@ -3129,6 +3129,8 @@ void Item_field::set_field(Field *field_par) any_privileges= 0; refers_to_temp_table= true; } + if (field->table->s->tmp_table == INTERNAL_TMP_TABLE) + refers_to_temp_table= true; } but then some explain outputs change in MTR.

Sergei Petrunia added a comment - 2022-03-31 07:33 - edited

Generally, when a table field is a constant, it is nicer to print the constant, not the "tableX.columnY". Because of that, I'm hesitant to push the above patch.

Ideas:

Should we introduce another QT_XXXX flag for Item::print method that would indicate that "this is SHOW ANALYZE|EXPLAIN command, so one may not assume the table is present"

If the table is gone, we cannot get the constant value. But we can tell the Item_field was constant by looking at its flags. Should we print {{CONST(tableX.columnY) }} instead?

Typically, SHOW EXPLAIN/ANALYZE is invoked when temp.table is not yet dropped. Can we tell when it is dropped and when it is not? (A: no. temptables in different subqueries can be dropped at different phases)

Sergei Petrunia added a comment - 2022-03-31 07:33 - edited Generally, when a table field is a constant, it is nicer to print the constant, not the "tableX.columnY". Because of that, I'm hesitant to push the above patch. Ideas: Should we introduce another QT_XXXX flag for Item::print method that would indicate that "this is SHOW ANALYZE|EXPLAIN command, so one may not assume the table is present" If the table is gone, we cannot get the constant value. But we can tell the Item_field was constant by looking at its flags. Should we print {{CONST(tableX.columnY) }} instead? Typically, SHOW EXPLAIN/ANALYZE is invoked when temp.table is not yet dropped. Can we tell when it is dropped and when it is not? (A: no. temptables in different subqueries can be dropped at different phases)

Sergei Petrunia made changes - 2022-03-31 07:37

Comment

[ * If the table is gone, we cannot get the constant value. But we can tell the Item_field was constant by looking at its flags. Should we print {{CONST(tableX.columnY) }} instead? ]

Sergei Petrunia added a comment - 2022-04-01 08:30

Second testcase from alice:

CREATE TABLE t1 ( i1 int, a1 varchar(64) NOT NULL, i3 int NOT NULL);

INSERT INTO t1 VALUES (14564,'\'check\'',12736), (4,'\'f\'',5), (-93257728,'\'p\'',1599406080);

CREATE TABLE t2 ( pk int NOT NULL PRIMARY KEY, i2 int NOT NULL, a2 char(2)) ;

INSERT INTO t2 VALUES (1,2014838784,'b');

--connect (con1,localhost,root,,test)

--let $conid= `SELECT CONNECTION_ID()`

--let $run=100

while ($run)

  send

SELECT 1 FROM  t2

WHERE t2.pk IN ((SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2))

  --connection default

  --let $show=100

  while ($show)

    --error 0,ER_TARGET_NOT_EXPLAINABLE

     eval SHOW EXPLAIN FORMAT=JSON FOR $conid;

     --dec $show

  --connection con1

  --reap

  --dec $run

# Cleanup

--disconnect con1

This still crashes with my latest patch.

Sergei Petrunia added a comment - 2022-04-01 08:30 Second testcase from alice : CREATE TABLE t1 ( i1 int , a1 varchar (64) NOT NULL , i3 int NOT NULL ); INSERT INTO t1 VALUES (14564, '\'check\'' ,12736), (4, '\'f\'' ,5), (-93257728, '\'p\'' ,1599406080); CREATE TABLE t2 ( pk int NOT NULL PRIMARY KEY , i2 int NOT NULL , a2 char (2)) ; INSERT INTO t2 VALUES (1,2014838784, 'b' ); --connect (con1,localhost,root,,test) --let $conid= `SELECT CONNECTION_ID()` --let $run=100 while ($run) { send SELECT 1 FROM t2 WHERE t2.pk IN (( SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2)) ; --connection default --let $show=100 while ($show) { --error 0,ER_TARGET_NOT_EXPLAINABLE eval SHOW EXPLAIN FORMAT=JSON FOR $conid; --dec $show } --connection con1 --reap --dec $run } # Cleanup --disconnect con1 This still crashes with my latest patch.

Sergei Petrunia added a comment - 2022-04-01 08:35

The stack trace looks like this

(gdb) up

  #1  0x00007ffff5a847f1 in __GI_abort () at abort.c:79

  #2  0x00007ffff5a743fa in __assert_fail_base (fmt=0x7ffff5bfb6c0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x555556e6b340 "!table || table->in_use == _current_thd()", file=file@entry=0x555556e6ad38 "/home/psergey/dev-git2/10.9-review-analyze-oleg/sql/field.cc", line=line@entry=7525, function=function@entry=0x555556e70200 <Field_string::val_str(String*, String*)::__PRETTY_FUNCTION__> "virtual String* Field_string::val_str(String*, String*)") at assert.c:92

  #3  0x00007ffff5a74472 in __GI___assert_fail (assertion=0x555556e6b340 "!table || table->in_use == _current_thd()", file=0x555556e6ad38 "/home/psergey/dev-git2/10.9-review-analyze-oleg/sql/field.cc", line=7525, function=0x555556e70200 <Field_string::val_str(String*, String*)::__PRETTY_FUNCTION__> "virtual String* Field_string::val_str(String*, String*)") at assert.c:101

  #4  0x0000555556297cc0 in Field_string::val_str (this=0x7fffe007b450, val_buffer=0x7ffff052c670, val_ptr=0x7fffd4016150) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/field.cc:7525

  #5  0x00005555562e8721 in Item_field::val_str (this=0x7fffd4016128, str=0x7ffff052c670) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/item.cc:3324

  #6  0x00005555562df156 in Item::print_value (this=0x7fffd4016128, str=0x7ffff052cc60) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/item.cc:526

  #7  0x00005555562f64f0 in Item_field::print (this=0x7fffd4016128, str=0x7ffff052cc60, query_type=4201) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/item.cc:7826

The query we're getting EXPLAIN for is:

SELECT 1 FROM  t2

WHERE t2.pk IN ((SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2))

We're hitting this assert:

String *Field_string::val_str(String *val_buffer __attribute__((unused)),

			      String *val_ptr)

  DBUG_ASSERT(marked_for_read());

  /* See the comment for Field_long::store(long long) */

  DBUG_ASSERT(!table || table->in_use == current_thd);

because table->in_use=NULL.

Sergei Petrunia added a comment - 2022-04-01 08:35 The stack trace looks like this (gdb) up #1 0x00007ffff5a847f1 in __GI_abort () at abort.c:79 #2 0x00007ffff5a743fa in __assert_fail_base (fmt=0x7ffff5bfb6c0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x555556e6b340 "!table || table->in_use == _current_thd()", file=file@entry=0x555556e6ad38 "/home/psergey/dev-git2/10.9-review-analyze-oleg/sql/field.cc", line=line@entry=7525, function=function@entry=0x555556e70200 <Field_string::val_str(String*, String*)::__PRETTY_FUNCTION__> "virtual String* Field_string::val_str(String*, String*)") at assert.c:92 #3 0x00007ffff5a74472 in __GI___assert_fail (assertion=0x555556e6b340 "!table || table->in_use == _current_thd()", file=0x555556e6ad38 "/home/psergey/dev-git2/10.9-review-analyze-oleg/sql/field.cc", line=7525, function=0x555556e70200 <Field_string::val_str(String*, String*)::__PRETTY_FUNCTION__> "virtual String* Field_string::val_str(String*, String*)") at assert.c:101 #4 0x0000555556297cc0 in Field_string::val_str (this=0x7fffe007b450, val_buffer=0x7ffff052c670, val_ptr=0x7fffd4016150) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/field.cc:7525 #5 0x00005555562e8721 in Item_field::val_str (this=0x7fffd4016128, str=0x7ffff052c670) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/item.cc:3324 #6 0x00005555562df156 in Item::print_value (this=0x7fffd4016128, str=0x7ffff052cc60) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/item.cc:526 #7 0x00005555562f64f0 in Item_field::print (this=0x7fffd4016128, str=0x7ffff052cc60, query_type=4201) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/item.cc:7826 The query we're getting EXPLAIN for is: SELECT 1 FROM t2 WHERE t2.pk IN (( SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2)) We're hitting this assert: String *Field_string::val_str(String *val_buffer __attribute__((unused)), String *val_ptr) { DBUG_ASSERT(marked_for_read()); /* See the comment for Field_long::store(long long) */ DBUG_ASSERT(!table || table->in_use == current_thd); because table->in_use=NULL.

Sergei Petrunia added a comment - 2022-04-01 08:57

EXPLAIN of the query:

MariaDB [test]> explain SELECT 1 FROM  t2 WHERE t2.pk IN ((SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2));

+------+-------------+-------+--------+---------------+------+---------+------+------+-----------------------------+

| id   | select_type | table | type   | possible_keys | key  | key_len | ref  | rows | Extra                       |

+------+-------------+-------+--------+---------------+------+---------+------+------+-----------------------------+

|    1 | PRIMARY     | t2    | system | PRIMARY       | NULL | NULL    | NULL | 1    |                             |

|    1 | PRIMARY     | t1    | ALL    | NULL          | NULL | NULL    | NULL | 3    | Using where; FirstMatch(t2) |

+------+-------------+-------+--------+---------------+------+---------+------+------+-----------------------------+

Debugging the query, I see this sequence of events:

  JOIN::exec();

  close_thread_tables() // (1)

  // here the TABLE objects are closed

  // not directly related to this bug but needs to be

  // checked: is it really safe (or meaningful) to try to

  // print item trees after this?

  thd->Item_change_list::rollback_item_tree_changes();

  THD::cleanup_after_query()

     // (2)

     notify_item_objects_about_to_be_freed();

It seems that after call (1) one cannot access the tables.
However, we allow SHOW EXPLAIN|ANALYZE to work until point (2).

Sergei Petrunia added a comment - 2022-04-01 09:12

Regular ANALYZE FORMAT=JSON command is not affected, because it produces the output at much earlier phase, sometime before the close_thread_tables() call.

Sergei Petrunia added a comment - 2022-04-01 09:12 Regular ANALYZE FORMAT=JSON command is not affected, because it produces the output at much earlier phase, sometime before the close_thread_tables() call.

Sergei Petrunia added a comment - 2022-04-01 15:39 - edited

Having fixed the above issue, I hit a different one.

We hit the same assert in Field_string::val_str, because

  current_thd != table->in_use

They are indeed not equal:

(gdb) p $current_thd->query_string

  $166 = {string = {str = 0x7fffe0017b60 "SHOW EXPLAIN FORMAT=JSON FOR 4"

(gdb) p table->in_use->query_string

  $168 = {string = {str = 0x7fffd4014020 "SELECT 1 FROM  t2\nWHERE t2.pk IN ((SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2))"

We are in the target thread, but Show_explain_request::call_in_target_thread() replaces
the current_thd to point to the SHOW EXPLAIN's THD:

  DBUG_ASSERT(current_thd == target_thd);

  set_current_thd(request_thd);

  if (target_thd->lex->print_explain(explain_buf, 0 /* explain flags*/,

                                     is_analyze, is_json_format,

                                     &printed_anything))

...

  set_current_thd(target_thd);

The reason for changing current_thd was that producing tabular EXPLAIN output
allocates memory on current_thd->mem_root and creates Item objects. (The latter is worse. One can pass/use a different mem_root but one can't prevent Item::Item from adding *this into thd->free_list)

It is better to create them on SHOW EXPLAIN's thd, not on the target query's THD.

But with FORMAT=JSON the situation is different:

It calls Item->print which causes the issue we're having.
Writing JSON doesn't allocate anything on mem_root

Sergei Petrunia added a comment - 2022-04-01 15:39 - edited Having fixed the above issue, I hit a different one. We hit the same assert in Field_string::val_str, because current_thd != table->in_use They are indeed not equal: (gdb) p $current_thd->query_string $166 = {string = {str = 0x7fffe0017b60 "SHOW EXPLAIN FORMAT=JSON FOR 4" (gdb) p table->in_use->query_string $168 = {string = {str = 0x7fffd4014020 "SELECT 1 FROM t2\nWHERE t2.pk IN ((SELECT t1.i3 FROM t1 WHERE t1.i1 = t2.i2 OR t1.a1 = t2.a2))" We are in the target thread, but Show_explain_request::call_in_target_thread() replaces the current_thd to point to the SHOW EXPLAIN's THD: DBUG_ASSERT(current_thd == target_thd); set_current_thd(request_thd); if (target_thd->lex->print_explain(explain_buf, 0 /* explain flags*/ , is_analyze, is_json_format, &printed_anything)) ... set_current_thd(target_thd); The reason for changing current_thd was that producing tabular EXPLAIN output allocates memory on current_thd->mem_root and creates Item objects. (The latter is worse. One can pass/use a different mem_root but one can't prevent Item::Item from adding *this into thd->free_list) It is better to create them on SHOW EXPLAIN's thd, not on the target query's THD. But with FORMAT=JSON the situation is different: It calls Item->print which causes the issue we're having. Writing JSON doesn't allocate anything on mem_root

Sergei Petrunia added a comment - 2022-04-04 11:10

New candidate patch:

commit 0e62bfe92647ab4b5a2a8582979e4d161c43b105 (HEAD -> preview-10.9-MDEV-27021-explain, origin/preview-10.9-MDEV-27021-explain)

Author: Sergei Petrunia <sergey@mariadb.com>

Date:   Mon Apr 4 12:32:22 2022 +0300

    MDEV-28201: Server crashes upon SHOW ANALYZE/EXPLAIN FORMAT=JSON

Sergei Petrunia added a comment - 2022-04-04 11:10 New candidate patch: commit 0e62bfe92647ab4b5a2a8582979e4d161c43b105 (HEAD -> preview-10.9-MDEV-27021-explain, origin/preview-10.9-MDEV-27021-explain) Author: Sergei Petrunia <sergey@mariadb.com> Date: Mon Apr 4 12:32:22 2022 +0300 MDEV-28201: Server crashes upon SHOW ANALYZE/EXPLAIN FORMAT=JSON

Alice Sherepa added a comment - 2022-04-04 16:53

CREATE TABLE t1 ( a varchar(1));

INSERT INTO t1 VALUES ('a'),('b');

ANALYZE format=json SELECT  1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00');

10.9 0e62bfe92647ab4b5a2
/10.9/sql/sql_explain.cc:248: int Explain_query::print_explain_json(select_result_sink*, bool, bool, ulonglong): Assertion `can_print_json' failed.
220404 18:49:16 [ERROR] mysqld got signal 6 ;

Server version: 10.9.0-MariaDB-debug-log

??:0(__assert_fail)[0x7f4424e46006]
sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, bool, unsigned long long))[0x55d296f5be4a]
sql/sql_explain.cc:199(Explain_query::send_explain(THD*))[0x55d296f5b883]
sql/sql_parse.cc:6272(execute_sqlcom_select(THD, TABLE_LIST))[0x55d296a32dcb]
sql/sql_parse.cc:3950(mysql_execute_command(THD*, bool))[0x55d296a21701]
sql/sql_parse.cc:8035(mysql_parse(THD, char, unsigned int, Parser_state*))[0x55d296a3ddf5]
sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD, char, unsigned int, bool))[0x55d296a13fa3]
sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55d296a10cc7]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55d296ebaacd]
sql/sql_connect.cc:1314(handle_one_connection)[0x55d296eba359]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55d297b802a8]
nptl/pthread_create.c:478(start_thread)[0x7f4425360609]
??:0(clone)[0x7f4424f31163]

Query (0x6290001092a8): ANALYZE format=json SELECT 1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00')

Alice Sherepa added a comment - 2022-04-04 16:53 CREATE TABLE t1 ( a varchar (1)); INSERT INTO t1 VALUES ( 'a' ),( 'b' ); ANALYZE format=json SELECT 1 FROM t1 GROUP BY convert_tz( '1969-12-31 22:00:00' ,a, '+10:00' ); 10.9 0e62bfe92647ab4b5a2 /10.9/sql/sql_explain.cc:248: int Explain_query::print_explain_json(select_result_sink*, bool, bool, ulonglong): Assertion `can_print_json' failed. 220404 18:49:16 [ERROR] mysqld got signal 6 ; Server version: 10.9.0-MariaDB-debug-log ??:0(__assert_fail)[0x7f4424e46006] sql/sql_explain.cc:251(Explain_query::print_explain_json(select_result_sink*, bool, bool, unsigned long long))[0x55d296f5be4a] sql/sql_explain.cc:199(Explain_query::send_explain(THD*))[0x55d296f5b883] sql/sql_parse.cc:6272(execute_sqlcom_select(THD*, TABLE_LIST*))[0x55d296a32dcb] sql/sql_parse.cc:3950(mysql_execute_command(THD*, bool))[0x55d296a21701] sql/sql_parse.cc:8035(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55d296a3ddf5] sql/sql_parse.cc:1897(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55d296a13fa3] sql/sql_parse.cc:1403(do_command(THD*, bool))[0x55d296a10cc7] sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x55d296ebaacd] sql/sql_connect.cc:1314(handle_one_connection)[0x55d296eba359] perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55d297b802a8] nptl/pthread_create.c:478(start_thread)[0x7f4425360609] ??:0(clone)[0x7f4424f31163] Query (0x6290001092a8): ANALYZE format=json SELECT 1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00')

Sergei Petrunia added a comment - 2022-04-06 15:11 - edited

The issue in the above is a close_thread_tables() call in the middle of a query:

  #0  close_thread_tables (thd=0x62b00017a288) at /home/psergey/dev-git2/10.7-clean/sql/sql_base.cc:781

  #1  0x0000555557086664 in THD::commit_whole_transaction_and_close_tables (this=0x62b00017a288) at /home/psergey/dev-git2/10.7-clean/sql/sql_class.cc:6068

  #2  0x00005555575a042d in my_tz_find (thd=0x62b00017a288, name=0x62900004c1b8) at /home/psergey/dev-git2/10.7-clean/sql/tztime.cc:2345

  #3  0x0000555557d34a94 in Item_func_convert_tz::get_date (this=0x62900004c3b0, thd=0x62b00017a288, ltime=0x7fffca62e8f0, fuzzydate=...) at /home/psergey/dev-git2/10.7-clean/sql/item_timefunc.cc:2781

  #4  0x0000555557a82821 in Item::save_date_in_field (this=0x62900004c3b0, field=0x61a0000a6f28, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/item.cc:374

  #5  0x00005555577d6ed4 in Type_handler_temporal_with_date::Item_save_in_field (this=0x55555b77b2e0 <type_handler_datetime2>, item=0x62900004c3b0, field=0x61a0000a6f28, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/sql_type.cc:4324

  #6  0x0000555557ab7155 in Item::save_in_field (this=0x62900004c3b0, field=0x61a0000a6f28, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/item.cc:6827

  #7  0x0000555556ea2958 in Item_result_field::save_in_result_field (this=0x62900004c3b0, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/item.h:3435

  #8  0x000055555735e8a0 in copy_funcs (func_ptr=0x61f0000106a8, thd=0x62b00017a288) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:26306

  #9  0x00005555573438cb in end_write (join=0x62900004cea8, join_tab=0x62900004e5b8, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:22584

  #10 0x00005555573770a2 in AGGR_OP::put_record (this=0x62900004eef8, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:29473

  #11 0x000055555738843b in AGGR_OP::put_record (this=0x62900004eef8) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.h:1056

  #12 0x0000555557336953 in sub_select_postjoin_aggr (join=0x62900004cea8, join_tab=0x62900004e5b8, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:20815

  #13 0x0000555557339192 in evaluate_join_record (join=0x62900004cea8, join_tab=0x62900004e208, error=0) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:21329

  #14 0x0000555557337a6a in sub_select (join=0x62900004cea8, join_tab=0x62900004e208, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:21099

  #15 0x0000555557335a9e in do_select (join=0x62900004cea8, procedure=0x0) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:20644

  #16 0x00005555572c2311 in JOIN::exec_inner (this=0x62900004cea8) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:4751

  #17 0x00005555572bf846 in JOIN::exec (this=0x62900004cea8) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:4529

  #18 0x00005555572c3d2d in mysql_select (thd=0x62b00017a288, tables=0x62900004b8f8, fields=..., conds=0x0, og_num=1, order=0x0, group=0x62900004c498, having=0x0, proc_param=0x0, select_options=2147748608, result=0x62900004ce78, unit=0x62b00017e690, select_lex=0x62900004b378) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:5009

  #19 0x0000555557294135 in handle_select (thd=0x62b00017a288, lex=0x62b00017e5b8, result=0x62900004ce78, setup_tables_done_option=0) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:545

  #20 0x00005555571bca98 in execute_sqlcom_select (thd=0x62b00017a288, all_tables=0x62900004b8f8) at /home/psergey/dev-git2/10.7-clean/sql/sql_parse.cc:6268

  #21 0x00005555571ab5a6 in mysql_execute_command (thd=0x62b00017a288, is_called_from_prepared_stmt=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_parse.cc:3959

  #22 0x00005555571c7aee in mysql_parse (thd=0x62b00017a288, rawbuf=0x62900004b2a8 "ANALYZE format=json  SELECT  1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00')", length=92, parser_state=0x7fffca630b10) at /home/psergey/dev-git2/10.7-clean/sql/sql_parse.cc:8043

Sergei Petrunia added a comment - 2022-04-06 15:11 - edited The issue in the above is a close_thread_tables() call in the middle of a query: #0 close_thread_tables (thd=0x62b00017a288) at /home/psergey/dev-git2/10.7-clean/sql/sql_base.cc:781 #1 0x0000555557086664 in THD::commit_whole_transaction_and_close_tables (this=0x62b00017a288) at /home/psergey/dev-git2/10.7-clean/sql/sql_class.cc:6068 #2 0x00005555575a042d in my_tz_find (thd=0x62b00017a288, name=0x62900004c1b8) at /home/psergey/dev-git2/10.7-clean/sql/tztime.cc:2345 #3 0x0000555557d34a94 in Item_func_convert_tz::get_date (this=0x62900004c3b0, thd=0x62b00017a288, ltime=0x7fffca62e8f0, fuzzydate=...) at /home/psergey/dev-git2/10.7-clean/sql/item_timefunc.cc:2781 #4 0x0000555557a82821 in Item::save_date_in_field (this=0x62900004c3b0, field=0x61a0000a6f28, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/item.cc:374 #5 0x00005555577d6ed4 in Type_handler_temporal_with_date::Item_save_in_field (this=0x55555b77b2e0 <type_handler_datetime2>, item=0x62900004c3b0, field=0x61a0000a6f28, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/sql_type.cc:4324 #6 0x0000555557ab7155 in Item::save_in_field (this=0x62900004c3b0, field=0x61a0000a6f28, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/item.cc:6827 #7 0x0000555556ea2958 in Item_result_field::save_in_result_field (this=0x62900004c3b0, no_conversions=true) at /home/psergey/dev-git2/10.7-clean/sql/item.h:3435 #8 0x000055555735e8a0 in copy_funcs (func_ptr=0x61f0000106a8, thd=0x62b00017a288) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:26306 #9 0x00005555573438cb in end_write (join=0x62900004cea8, join_tab=0x62900004e5b8, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:22584 #10 0x00005555573770a2 in AGGR_OP::put_record (this=0x62900004eef8, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:29473 #11 0x000055555738843b in AGGR_OP::put_record (this=0x62900004eef8) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.h:1056 #12 0x0000555557336953 in sub_select_postjoin_aggr (join=0x62900004cea8, join_tab=0x62900004e5b8, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:20815 #13 0x0000555557339192 in evaluate_join_record (join=0x62900004cea8, join_tab=0x62900004e208, error=0) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:21329 #14 0x0000555557337a6a in sub_select (join=0x62900004cea8, join_tab=0x62900004e208, end_of_records=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:21099 #15 0x0000555557335a9e in do_select (join=0x62900004cea8, procedure=0x0) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:20644 #16 0x00005555572c2311 in JOIN::exec_inner (this=0x62900004cea8) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:4751 #17 0x00005555572bf846 in JOIN::exec (this=0x62900004cea8) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:4529 #18 0x00005555572c3d2d in mysql_select (thd=0x62b00017a288, tables=0x62900004b8f8, fields=..., conds=0x0, og_num=1, order=0x0, group=0x62900004c498, having=0x0, proc_param=0x0, select_options=2147748608, result=0x62900004ce78, unit=0x62b00017e690, select_lex=0x62900004b378) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:5009 #19 0x0000555557294135 in handle_select (thd=0x62b00017a288, lex=0x62b00017e5b8, result=0x62900004ce78, setup_tables_done_option=0) at /home/psergey/dev-git2/10.7-clean/sql/sql_select.cc:545 #20 0x00005555571bca98 in execute_sqlcom_select (thd=0x62b00017a288, all_tables=0x62900004b8f8) at /home/psergey/dev-git2/10.7-clean/sql/sql_parse.cc:6268 #21 0x00005555571ab5a6 in mysql_execute_command (thd=0x62b00017a288, is_called_from_prepared_stmt=false) at /home/psergey/dev-git2/10.7-clean/sql/sql_parse.cc:3959 #22 0x00005555571c7aee in mysql_parse (thd=0x62b00017a288, rawbuf=0x62900004b2a8 "ANALYZE format=json SELECT 1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00')", length=92, parser_state=0x7fffca630b10) at /home/psergey/dev-git2/10.7-clean/sql/sql_parse.cc:8043

Sergei Petrunia added a comment - 2022-04-06 17:29

... and surprisingly the rest of the code can still function after commit_whole_transaction_and_close_tables call.

This is because the code "stashes away" the transaction in THD, including the set of open tables, etc. Then, it opens timezone tables, queries, closes them. And then uses calls like start_new_trans::restore_old_transaction(), THD::restore_backup_open_tables_state to restore the previous state.

Sergei Petrunia added a comment - 2022-04-06 17:29 ... and surprisingly the rest of the code can still function after commit_whole_transaction_and_close_tables call. This is because the code "stashes away" the transaction in THD, including the set of open tables, etc. Then, it opens timezone tables, queries, closes them. And then uses calls like start_new_trans::restore_old_transaction() , THD::restore_backup_open_tables_state to restore the previous state.

Sergei Petrunia added a comment - 2022-04-06 17:33

Takeaways from the optimizer call:

can move thd->lex->explain->notify_tables_are_closed(); out of close_thread_tables.
can put away the thd->lex in start_new_trans::start_new_trans. This should not affect anything.

Sergei Petrunia added a comment - 2022-04-06 17:33 Takeaways from the optimizer call: can move thd->lex->explain->notify_tables_are_closed(); out of close_thread_tables . can put away the thd->lex in start_new_trans::start_new_trans. This should not affect anything.

Sergei Petrunia added a comment - 2022-04-06 17:46

.. No, the second suggestion doesn't work.
EITS code calls open_system_tables_for_read which makes use of thd->lex:

bool

open_system_tables_for_read(THD *thd, TABLE_LIST *table_list)

  Query_tables_list query_tables_list_backup;

  LEX *lex= thd->lex;

  DBUG_ENTER("open_system_tables_for_read");

  DBUG_ASSERT(thd->internal_transaction());

/*

    Besides using new Open_tables_state for opening system tables,

    we also have to backup and reset/and then restore part of LEX

    which is accessed by open_tables() in order to determine if

    prelocking is needed and what tables should be added for it.

*/

  lex->reset_n_backup_query_tables_list(&query_tables_list_backup);

  thd->lex->sql_command= SQLCOM_SELECT;

it happens here:

  #0  open_system_tables_for_read (thd=0x7fff98000d78, table_list=0x7ffff010b140) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_base.cc:9114

  #1  0x0000555555ffd5a4 in open_stat_tables (thd=0x7fff98000d78, tables=0x7ffff010b140, for_write=false) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_statistics.cc:250

  #2  0x0000555556000550 in read_statistics_for_tables (thd=0x7fff98000d78, tables=0x7fff98016ec0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_statistics.cc:3319

  #3  0x000055555600016a in read_statistics_for_tables_if_needed (thd=0x7fff98000d78, tables=0x7fff98016ec0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_statistics.cc:3246

  #4  0x0000555555e5b5ed in open_and_lock_tables (thd=0x7fff98000d78, options=..., tables=0x7fff98016ec0, derived=true, flags=0, prelocking_strategy=0x7ffff010d938) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_base.cc:5282

  #5  0x0000555555e12f7b in open_and_lock_tables (thd=0x7fff98000d78, tables=0x7fff98016ec0, derived=true, flags=0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_base.h:511

  #6  0x0000555555f1022b in execute_sqlcom_select (thd=0x7fff98000d78, all_tables=0x7fff98016ec0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_parse.cc:6180

  #7  0x0000555555f07968 in mysql_execute_command (thd=0x7fff98000d78, is_called_from_prepared_stmt=false) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_parse.cc:3950

  #8  0x0000555555f1553f in mysql_parse (thd=0x7fff98000d78, rawbuf=0x7fff980168e0 "ANALYZE format=json  SELECT  1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00')", length=92, parser_state=0x7ffff010e500) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_parse.cc:8035

Sergei Petrunia added a comment - 2022-04-06 17:46 .. No, the second suggestion doesn't work. EITS code calls open_system_tables_for_read which makes use of thd->lex: bool open_system_tables_for_read(THD *thd, TABLE_LIST *table_list) { Query_tables_list query_tables_list_backup; LEX *lex= thd->lex; DBUG_ENTER( "open_system_tables_for_read" ); DBUG_ASSERT(thd->internal_transaction()); /* Besides using new Open_tables_state for opening system tables, we also have to backup and reset/and then restore part of LEX which is accessed by open_tables() in order to determine if prelocking is needed and what tables should be added for it. */ lex->reset_n_backup_query_tables_list(&query_tables_list_backup); thd->lex->sql_command= SQLCOM_SELECT; it happens here: #0 open_system_tables_for_read (thd=0x7fff98000d78, table_list=0x7ffff010b140) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_base.cc:9114 #1 0x0000555555ffd5a4 in open_stat_tables (thd=0x7fff98000d78, tables=0x7ffff010b140, for_write=false) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_statistics.cc:250 #2 0x0000555556000550 in read_statistics_for_tables (thd=0x7fff98000d78, tables=0x7fff98016ec0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_statistics.cc:3319 #3 0x000055555600016a in read_statistics_for_tables_if_needed (thd=0x7fff98000d78, tables=0x7fff98016ec0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_statistics.cc:3246 #4 0x0000555555e5b5ed in open_and_lock_tables (thd=0x7fff98000d78, options=..., tables=0x7fff98016ec0, derived=true, flags=0, prelocking_strategy=0x7ffff010d938) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_base.cc:5282 #5 0x0000555555e12f7b in open_and_lock_tables (thd=0x7fff98000d78, tables=0x7fff98016ec0, derived=true, flags=0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_base.h:511 #6 0x0000555555f1022b in execute_sqlcom_select (thd=0x7fff98000d78, all_tables=0x7fff98016ec0) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_parse.cc:6180 #7 0x0000555555f07968 in mysql_execute_command (thd=0x7fff98000d78, is_called_from_prepared_stmt=false) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_parse.cc:3950 #8 0x0000555555f1553f in mysql_parse (thd=0x7fff98000d78, rawbuf=0x7fff980168e0 "ANALYZE format=json SELECT 1 FROM t1 GROUP BY convert_tz('1969-12-31 22:00:00',a,'+10:00')", length=92, parser_state=0x7ffff010e500) at /home/psergey/dev-git2/10.9-review-analyze-oleg/sql/sql_parse.cc:8035

Sergei Petrunia added a comment - 2022-04-07 15:55

pushed:

commit b904307368298cc2fa2fcb2ecdc0bac85f9c61d0 (HEAD -> preview-10.9-MDEV-27021-explain, origin/preview-10.9-MDEV-27021-explain)

Author: Sergei Petrunia <sergey@mariadb.com>

Date:   Mon Apr 4 12:32:22 2022 +0300

    MDEV-28201: Server crashes upon SHOW ANALYZE/EXPLAIN FORMAT=JSON

Sergei Petrunia added a comment - 2022-04-07 15:55 pushed: commit b904307368298cc2fa2fcb2ecdc0bac85f9c61d0 (HEAD -> preview-10.9-MDEV-27021-explain, origin/preview-10.9-MDEV-27021-explain) Author: Sergei Petrunia <sergey@mariadb.com> Date: Mon Apr 4 12:32:22 2022 +0300 MDEV-28201: Server crashes upon SHOW ANALYZE/EXPLAIN FORMAT=JSON

Sergei Petrunia made changes - 2022-04-08 08:33

Status

Open [ 1 ]

In Progress [ 3 ]

Sergei Petrunia made changes - 2022-04-08 08:33

Status

In Progress [ 3 ]

In Testing [ 10301 ]

Sergei Petrunia made changes - 2022-04-08 08:34

Assignee

Sergei Petrunia [ psergey ]

Alice Sherepa [ alice ]

Alice Sherepa made changes - 2022-04-27 11:01

Status

In Testing [ 10301 ]

Stalled [ 10000 ]

Alice Sherepa made changes - 2022-04-27 11:01

Fix Version/s		N/A [ 14700 ]
Fix Version/s	10.9 [ 26905 ]
Resolution		Fixed [ 1 ]
Status	Stalled [ 10000 ]	Closed [ 6 ]

Roel Van de Paar made changes - 2023-08-25 07:14

Link

This issue causes ~~MDEV-31432~~ [ ~~MDEV-31432~~ ]

MariaDB Server

Server crashes upon SHOW ANALYZE/EXPLAIN FORMAT=JSON

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration