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

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: N/A
Fix Version/s: N/A
Component/s: Optimizer
Labels:
None

Description

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

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

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

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

++variations:

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

=================================================================

==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

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]

Attachments

Issue Links

causes

MDEV-31432 tmp_table field accessed after free

Closed

is caused by

MDEV-27021 Extend SHOW EXPLAIN to support SHOW ANALYZE [FORMAT=JSON]

Closed

Activity

Ascending order - Click to sort in descending order

View 9 older comments

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

People

Assignee:: Alice Sherepa

Reporter:: Alice Sherepa

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: 2022-03-30 15:15

Updated:: 2023-08-25 07:14

Resolved:: 2022-04-27 11:01

Git Integration

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

MariaDB Server