[MDEV-18157] Server crashes in Explain_node::print_explain_for_children upon SHOW EXPLAIN on UNION Created: 2019-01-06  Updated: 2022-11-14  Resolved: 2022-10-23

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.3.37, 10.4.27, 10.5.18, 10.6.11, 10.7.7, 10.8.6, 10.9.4, 10.10.2, 10.11.1

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Petrunia
Resolution: Duplicate Votes: 2
Labels: UBSAN

Issue Links:
Relates
relates to MDEV-23160 SIGSEGV in Explain_node::print_explai... Closed

 Description   

Notes:

  • The test case is for reproducing purposes only, don't put it into the regression suite as is, create a properly synchronized one instead!
  • The test case represents a race condition and thus is non-deterministic. It crashes for me every time on every affected build, but it can vary on different machines. Try to increase the value of $run variable if it doesn't right away.
  • Compound statements in the test case are used to produce concurrency in MTR. They are not essential for the problem.

--let $con_select= `SELECT CONNECTION_ID()`
 
CREATE TABLE t1 (a INT, b INT, PRIMARY KEY (a));
INSERT INTO t1 VALUES (1,1),(2,2);
 
--connect (con1,localhost,root,,)
--let $con_explain= `SELECT CONNECTION_ID()`
--delimiter |
send_eval
    BEGIN NOT ATOMIC
    DECLARE CONTINUE HANDLER FOR 1933 BEGIN END;
    LOOP
      SHOW EXPLAIN FOR $con_select;
    END LOOP;
    END |
--delimiter ;
 
--connection default
--let $run= 1000
while ($run)
{
    SELECT a, b FROM t1 UNION ( SELECT a, b FROM ( SELECT a, COUNT(*) AS b FROM t1 GROUP BY a ) AS sq LIMIT 0 );
    --dec $run
}
 
eval KILL $con_explain;
 
# Cleanup
DROP TABLE t1;

10.3 803d0521

#3  <signal handler called>
#4  0x000055a271233448 in Explain_node::print_explain_for_children (this=0x7fb68016fa80, query=0x7fb6800178b0, output=0x7fb674049348, explain_flags=0 '\000', is_analyze=false) at /data/src/10.3/sql/sql_explain.cc:640
#5  0x000055a271233cc1 in Explain_select::print_explain (this=0x7fb68016fa80, query=0x7fb6800178b0, output=0x7fb674049348, explain_flags=0 '\000', is_analyze=false) at /data/src/10.3/sql/sql_explain.cc:824
#6  0x000055a271232b20 in Explain_union::print_explain (this=0x7fb68016fb98, query=0x7fb6800178b0, output=0x7fb674049348, explain_flags=0 '\000', is_analyze=false) at /data/src/10.3/sql/sql_explain.cc:487
#7  0x000055a2712317c5 in Explain_query::print_explain (this=0x7fb6800178b0, output=0x7fb674049348, explain_flags=0 '\000', is_analyze=false) at /data/src/10.3/sql/sql_explain.cc:208
#8  0x000055a27105f5ba in LEX::print_explain (this=0x7fb680004908, output=0x7fb674049348, explain_flags=0 '\000', is_analyze=false, printed_anything=0x7fb690d1637f) at /data/src/10.3/sql/sql_lex.cc:4922
#9  0x000055a271129297 in Show_explain_request::call_in_target_thread (this=0x7fb690cca330) at /data/src/10.3/sql/sql_show.cc:2987
#10 0x000055a2712645e8 in Apc_target::process_apc_requests (this=0x7fb6800048b8) at /data/src/10.3/sql/my_apc.cc:222
#11 0x000055a27102dea5 in THD::check_killed (this=0x7fb680000b00, dont_send_error_message=false) at /data/src/10.3/sql/sql_class.h:3063
#12 0x000055a2711004ed in evaluate_join_record (join=0x7fb680015cc8, join_tab=0x7fb68016e118, error=0) at /data/src/10.3/sql/sql_select.cc:19613
#13 0x000055a27110031d in sub_select (join=0x7fb680015cc8, join_tab=0x7fb68016e118, end_of_records=false) at /data/src/10.3/sql/sql_select.cc:19566
#14 0x000055a2710ff5cf in do_select (join=0x7fb680015cc8, procedure=0x0) at /data/src/10.3/sql/sql_select.cc:19067
#15 0x000055a2710d64d7 in JOIN::exec_inner (this=0x7fb680015cc8) at /data/src/10.3/sql/sql_select.cc:4040
#16 0x000055a2710d58aa in JOIN::exec (this=0x7fb680015cc8) at /data/src/10.3/sql/sql_select.cc:3834
#17 0x000055a2711856fc in st_select_lex_unit::exec (this=0x7fb6800049d0) at /data/src/10.3/sql/sql_union.cc:1497
#18 0x000055a271180165 in mysql_union (thd=0x7fb680000b00, lex=0x7fb680004908, result=0x7fb680015bb8, unit=0x7fb6800049d0, setup_tables_done_option=0) at /data/src/10.3/sql/sql_union.cc:41
#19 0x000055a2710c854a in handle_select (thd=0x7fb680000b00, lex=0x7fb680004908, result=0x7fb680015bb8, setup_tables_done_option=0) at /data/src/10.3/sql/sql_select.cc:360
#20 0x000055a271090110 in execute_sqlcom_select (thd=0x7fb680000b00, all_tables=0x7fb680012bf0) at /data/src/10.3/sql/sql_parse.cc:6291
#21 0x000055a271086b45 in mysql_execute_command (thd=0x7fb680000b00) at /data/src/10.3/sql/sql_parse.cc:3821
#22 0x000055a27109441b in mysql_parse (thd=0x7fb680000b00, rawbuf=0x7fb680012818 "SELECT a, b FROM t1 UNION ( SELECT a, b FROM ( SELECT a, COUNT(*) AS b FROM t1 GROUP BY a ) AS sq LIMIT 0 )", length=107, parser_state=0x7fb690d175e0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7834
#23 0x000055a271080f8d in dispatch_command (command=COM_QUERY, thd=0x7fb680000b00, packet=0x7fb68011de81 "SELECT a, b FROM t1 UNION ( SELECT a, b FROM ( SELECT a, COUNT(*) AS b FROM t1 GROUP BY a ) AS sq LIMIT 0 )", packet_length=107, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1856
#24 0x000055a27107f8d5 in do_command (thd=0x7fb680000b00) at /data/src/10.3/sql/sql_parse.cc:1401
#25 0x000055a2711f6894 in do_handle_one_connection (connect=0x55a274b69ab0) at /data/src/10.3/sql/sql_connect.cc:1403
#26 0x000055a2711f65f6 in handle_one_connection (arg=0x55a274b69ab0) at /data/src/10.3/sql/sql_connect.cc:1308
#27 0x000055a271ba4c2c in pfs_spawn_thread (arg=0x55a274ac7190) at /data/src/10.3/storage/perfschema/pfs.cc:1862
#28 0x00007fb69868e4a4 in start_thread (arg=0x7fb690d18700) at pthread_create.c:456
#29 0x00007fb696bd5d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

All of non-debug, debug and ASAN builds crash the same way.
Reproducible on 10.3-10.5, with at least MyISAM and InnoDB.
Couldn't reproduce on 10.2.



 Comments   
Comment by Roel Van de Paar [ 2022-04-21 ]

UBSAN: runtime error: member call on null pointer of type 'struct Explain_node' in Explain_node::print_explain_for_children on EXPLAIN...UNION

CREATE TABLE t (c INT) ENGINE=InnoDB;
EXPLAIN SELECT * FROM t WHERE c in (SELECT c FROM t UNION SELECT c FROM t ORDER BY (SELECT c)) UNION SELECT * FROM t ORDER BY (SELECT c);

Leads to:

10.9.0 161fd2d29cc2f8390fa3bf7e739c52bc8d5c39df (Optimized)

/test/10.9_opt_san/sql/sql_explain.cc:665:28: runtime error: member call on null pointer of type 'struct Explain_node'

10.9.0 161fd2d29cc2f8390fa3bf7e739c52bc8d5c39df (Optimized)

    #0 0x5557334a0405 in Explain_node::print_explain_for_children(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_opt_san/sql/sql_explain.cc:665
    #1 0x5557334af2e0 in Explain_union::print_explain(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_opt_san/sql/sql_explain.cc:590
    #2 0x5557334a0254 in Explain_node::print_explain_for_children(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_opt_san/sql/sql_explain.cc:665
    #3 0x5557334b6df4 in Explain_select::print_explain(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_opt_san/sql/sql_explain.cc:857
    #4 0x5557334adc76 in Explain_union::print_explain(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_opt_san/sql/sql_explain.cc:505
    #5 0x555732a67872 in execute_sqlcom_select /test/10.9_opt_san/sql/sql_parse.cc:6223
    #6 0x555732aa588b in mysql_execute_command(THD*, bool) /test/10.9_opt_san/sql/sql_parse.cc:3959
    #7 0x555732a350a8 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.9_opt_san/sql/sql_parse.cc:8043
    #8 0x555732a8b439 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.9_opt_san/sql/sql_parse.cc:1910
    #9 0x555732a96c92 in do_command(THD*, bool) /test/10.9_opt_san/sql/sql_parse.cc:1407
    #10 0x555733381d3d in do_handle_one_connection(CONNECT*, bool) /test/10.9_opt_san/sql/sql_connect.cc:1418
    #11 0x555733384834 in handle_one_connection /test/10.9_opt_san/sql/sql_connect.cc:1312
    #12 0x5557354821f9 in pfs_spawn_thread /test/10.9_opt_san/storage/perfschema/pfs.cc:2201
    #13 0x14800fec3608 in start_thread /build/glibc-sMfBJT/glibc-2.31/nptl/pthread_create.c:477
    #14 0x14800f138162 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f162)

10.9.0 161fd2d29cc2f8390fa3bf7e739c52bc8d5c39df (Debug)

/test/10.9_dbg_san/sql/sql_explain.cc:665:28: runtime error: member call on null pointer of type 'struct Explain_node'

10.9.0 161fd2d29cc2f8390fa3bf7e739c52bc8d5c39df (Debug)

    #0 0x557e24a2647f in Explain_node::print_explain_for_children(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_dbg_san/sql/sql_explain.cc:665
    #1 0x557e24a2d313 in Explain_union::print_explain(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_dbg_san/sql/sql_explain.cc:590
    #2 0x557e24a263b2 in Explain_node::print_explain_for_children(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_dbg_san/sql/sql_explain.cc:665
    #3 0x557e24a4777b in Explain_select::print_explain(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_dbg_san/sql/sql_explain.cc:857
    #4 0x557e24a2711f in Explain_union::print_explain(Explain_query*, select_result_sink*, unsigned char, bool) /test/10.9_dbg_san/sql/sql_explain.cc:505
    #5 0x557e24a24993 in Explain_query::print_explain(select_result_sink*, unsigned char, bool) /test/10.9_dbg_san/sql/sql_explain.cc:213
    #6 0x557e23d94be6 in execute_sqlcom_select /test/10.9_dbg_san/sql/sql_parse.cc:6223
    #7 0x557e23dfb216 in mysql_execute_command(THD*, bool) /test/10.9_dbg_san/sql/sql_parse.cc:3959
    #8 0x557e23d5d728 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.9_dbg_san/sql/sql_parse.cc:8043
    #9 0x557e23dd344e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.9_dbg_san/sql/sql_parse.cc:1910
    #10 0x557e23de9fa9 in do_command(THD*, bool) /test/10.9_dbg_san/sql/sql_parse.cc:1407
    #11 0x557e248b6c4b in do_handle_one_connection(CONNECT*, bool) /test/10.9_dbg_san/sql/sql_connect.cc:1418
    #12 0x557e248b9ae5 in handle_one_connection /test/10.9_dbg_san/sql/sql_connect.cc:1312
    #13 0x557e26e12c62 in pfs_spawn_thread /test/10.9_dbg_san/storage/perfschema/pfs.cc:2201
    #14 0x14d784f50608 in start_thread /build/glibc-sMfBJT/glibc-2.31/nptl/pthread_create.c:477
    #15 0x14d7841c5162 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f162)

Setup:

Compiled with GCC >=7.5.0 (I use GCC 9.4.0) and:
    -DWITH_ASAN=ON -DWITH_ASAN_SCOPE=ON -DWITH_UBSAN=ON -DWITH_RAPID=OFF -DWSREP_LIB_WITH_ASAN=ON
Set before execution:
    export UBSAN_OPTIONS=print_stacktrace=1

Bug confirmed present in:
MariaDB: 10.2.44 (dbg), 10.2.44 (opt), 10.3.35 (dbg), 10.3.35 (opt), 10.4.25 (dbg), 10.4.25 (opt), 10.5.16 (dbg), 10.5.16 (opt), 10.6.8 (dbg), 10.6.8 (opt), 10.7.4 (dbg), 10.7.4 (opt), 10.8.3 (dbg), 10.8.3 (opt), 10.9.0 (dbg), 10.9.0 (opt)

Comment by Sergei Petrunia [ 2022-10-23 ]

Fixed by fix for MDEV-23160.

Generated at Thu Feb 08 08:41:56 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.