[MDEV-23679] Server crashes in base_list_iterator::next_fast upon 2nd execution of SP after adding system versioning between calls Created: 2020-09-06  Updated: 2023-04-27

Status: Confirmed
Project: MariaDB Server
Component/s: Stored routines, Versioned Tables
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Dmitry Shulga
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-19194 Server crash or ASAN use-after-poison... Confirmed

 Description    

CREATE TABLE t (a INT, b INT);
 
INSERT INTO t VALUES (1,2),(2,3);
 
 
 
CREATE PROCEDURE sp() SELECT t1.* FROM t AS t1 LEFT JOIN t AS t2 ON t1.b = t2.a;
 
CALL sp;
 
ALTER TABLE t ADD SYSTEM VERSIONING;
 
CALL sp;
 
 
 
# Cleanup
 
DROP PROCEDURE sp;
 
DROP TABLE t;

10.3 debug c5cb59ce

 
#3  <signal handler called>
 
#4  0x000055dd59bf392f in base_list_iterator::next_fast (this=0x7f6fbd674050) at /data/src/10.3/sql/sql_list.h:442
 
#5  0x000055dd59db8651 in List_iterator_fast<Item_equal>::operator++ (this=0x7f6fbd674050) at /data/src/10.3/sql/sql_list.h:562
 
#6  0x000055dd59d8ba71 in substitute_for_best_equal_field (thd=0x7f6fac000d90, context_tab=0x1, cond=0x7f6fac09c0c0, cond_equal=0x7f6fac09e948, table_join_idx=0x7f6fac0ab340) at /data/src/10.3/sql/sql_select.cc:15144
 
#7  0x000055dd59d66d67 in JOIN::optimize_stage2 (this=0x7f6fac0aa518) at /data/src/10.3/sql/sql_select.cc:2117
 
#8  0x000055dd59d664bd in JOIN::optimize_inner (this=0x7f6fac0aa518) at /data/src/10.3/sql/sql_select.cc:1977
 
#9  0x000055dd59d648ea in JOIN::optimize (this=0x7f6fac0aa518) at /data/src/10.3/sql/sql_select.cc:1497
 
#10 0x000055dd59d6e9de in mysql_select (thd=0x7f6fac000d90, tables=0x7f6fac09b0d8, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147749632, result=0x7f6fac0aa4f0, unit=0x7f6fac038848, select_lex=0x7f6fac038fd0) at /data/src/10.3/sql/sql_select.cc:4301
 
#11 0x000055dd59d6009e in handle_select (thd=0x7f6fac000d90, lex=0x7f6fac038788, result=0x7f6fac0aa4f0, setup_tables_done_option=0) at /data/src/10.3/sql/sql_select.cc:370
 
#12 0x000055dd59d26c4c in execute_sqlcom_select (thd=0x7f6fac000d90, all_tables=0x7f6fac09b0d8) at /data/src/10.3/sql/sql_parse.cc:6286
 
#13 0x000055dd59d1d3b3 in mysql_execute_command (thd=0x7f6fac000d90) at /data/src/10.3/sql/sql_parse.cc:3812
 
#14 0x000055dd59c3b2c4 in sp_instr_stmt::exec_core (this=0x7f6fac03a5c8, thd=0x7f6fac000d90, nextp=0x7f6fbd6751ac) at /data/src/10.3/sql/sp_head.cc:3702
 
#15 0x000055dd59c3a746 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7f6fac03a610, thd=0x7f6fac000d90, nextp=0x7f6fbd6751ac, open_tables=false, instr=0x7f6fac03a5c8) at /data/src/10.3/sql/sp_head.cc:3434
 
#16 0x000055dd59c3ae8c in sp_instr_stmt::execute (this=0x7f6fac03a5c8, thd=0x7f6fac000d90, nextp=0x7f6fbd6751ac) at /data/src/10.3/sql/sp_head.cc:3608
 
#17 0x000055dd59c34758 in sp_head::execute (this=0x7f6fac09a228, thd=0x7f6fac000d90, merge_da_on_success=true) at /data/src/10.3/sql/sp_head.cc:1377
 
#18 0x000055dd59c374bd in sp_head::execute_procedure (this=0x7f6fac09a228, thd=0x7f6fac000d90, args=0x7f6fac005a18) at /data/src/10.3/sql/sp_head.cc:2404
 
#19 0x000055dd59d1aa30 in do_execute_sp (thd=0x7f6fac000d90, sp=0x7f6fac09a228) at /data/src/10.3/sql/sql_parse.cc:2983
 
#20 0x000055dd59d1b6eb in Sql_cmd_call::execute (this=0x7f6fac012b70, thd=0x7f6fac000d90) at /data/src/10.3/sql/sql_parse.cc:3223
 
#21 0x000055dd59d25751 in mysql_execute_command (thd=0x7f6fac000d90) at /data/src/10.3/sql/sql_parse.cc:6022
 
#22 0x000055dd59d2afb6 in mysql_parse (thd=0x7f6fac000d90, rawbuf=0x7f6fac012ab8 "CALL sp", length=7, parser_state=0x7f6fbd6765c0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7810
 
#23 0x000055dd59d17777 in dispatch_command (command=COM_QUERY, thd=0x7f6fac000d90, packet=0x7f6fac008f11 "CALL sp", packet_length=7, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1847
 
#24 0x000055dd59d16117 in do_command (thd=0x7f6fac000d90) at /data/src/10.3/sql/sql_parse.cc:1393
 
#25 0x000055dd59e936b8 in do_handle_one_connection (connect=0x55dd5dd0aa40) at /data/src/10.3/sql/sql_connect.cc:1403
 
#26 0x000055dd59e93414 in handle_one_connection (arg=0x55dd5dd0aa40) at /data/src/10.3/sql/sql_connect.cc:1308
 
#27 0x000055dd5a8563d9 in pfs_spawn_thread (arg=0x55dd5dd3b830) at /data/src/10.3/storage/perfschema/pfs.cc:1869
 
#28 0x00007f6fc3b60609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#29 0x00007f6fc373a103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Non-debug version crashes the same way, only sporadically, which means that other debug builds may not crash too, even though for me it's reproducible every time on a debug build.
If you are not getting the crash, try running with ASAN (debug or non-debug):

10.3 ASAN c5cb59ce

 
==29051==ERROR: AddressSanitizer: heap-use-after-free on address 0x625000102488 at pc 0x559908a7c8e3 bp 0x7efc287d2fa0 sp 0x7efc287d2f90
 
READ of size 8 at 0x625000102488 thread T5
 
    #0 0x559908a7c8e2 in base_list_iterator::next_fast() /data/src/10.3/sql/sql_list.h:440
 
    #1 0x559908ec64aa in List_iterator_fast<Item_equal>::operator++(int) /data/src/10.3/sql/sql_list.h:562
 
    #2 0x559908e4c2c8 in substitute_for_best_equal_field /data/src/10.3/sql/sql_select.cc:15144
 
    #3 0x559908dea033 in JOIN::optimize_stage2() /data/src/10.3/sql/sql_select.cc:2117
 
    #4 0x559908de87a7 in JOIN::optimize_inner() /data/src/10.3/sql/sql_select.cc:1977
 
    #5 0x559908de39d4 in JOIN::optimize() /data/src/10.3/sql/sql_select.cc:1497
 
    #6 0x559908e00aeb in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /data/src/10.3/sql/sql_select.cc:4301
 
    #7 0x559908dd7ae2 in handle_select(THD*, LEX*, select_result*, unsigned long) /data/src/10.3/sql/sql_select.cc:370
 
    #8 0x559908d4adb8 in execute_sqlcom_select /data/src/10.3/sql/sql_parse.cc:6286
 
    #9 0x559908d38769 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:3812
 
    #10 0x559908b20b2d in sp_instr_stmt::exec_core(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3702
 
    #11 0x559908b1f377 in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /data/src/10.3/sql/sp_head.cc:3434
 
    #12 0x559908b202bf in sp_instr_stmt::execute(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3608
 
    #13 0x559908b11bc7 in sp_head::execute(THD*, bool) /data/src/10.3/sql/sp_head.cc:1377
 
    #14 0x559908b17b8a in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.3/sql/sp_head.cc:2404
 
    #15 0x559908d325b3 in do_execute_sp /data/src/10.3/sql/sql_parse.cc:2983
 
    #16 0x559908d34181 in Sql_cmd_call::execute(THD*) /data/src/10.3/sql/sql_parse.cc:3223
 
    #17 0x559908d484e3 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6022
 
    #18 0x559908d54a64 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7810
 
    #19 0x559908d2bad0 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1847
 
    #20 0x559908d28624 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1393
 
    #21 0x5599090edb84 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
 
    #22 0x5599090ed43e in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #23 0x55990a6dfaba in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #24 0x7efc33694608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
 
    #25 0x7efc3326e102 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122102)
 
 
 
0x625000102488 is located 2952 bytes inside of 8268-byte region [0x625000101900,0x62500010394c)
 
freed by thread T5 here:
 
    #0 0x7efc337fc7cf in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0x10d7cf)
 
    #1 0x55990a8f1325 in free_memory /data/src/10.3/mysys/safemalloc.c:279
 
    #2 0x55990a8f08f2 in sf_free /data/src/10.3/mysys/safemalloc.c:197
 
    #3 0x55990a8befef in my_free /data/src/10.3/mysys/my_malloc.c:223
 
    #4 0x55990a89b902 in free_root /data/src/10.3/mysys/my_alloc.c:421
 
    #5 0x559908b12126 in sp_head::execute(THD*, bool) /data/src/10.3/sql/sp_head.cc:1482
 
    #6 0x559908b17b8a in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.3/sql/sp_head.cc:2404
 
    #7 0x559908d325b3 in do_execute_sp /data/src/10.3/sql/sql_parse.cc:2983
 
    #8 0x559908d34181 in Sql_cmd_call::execute(THD*) /data/src/10.3/sql/sql_parse.cc:3223
 
    #9 0x559908d484e3 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6022
 
    #10 0x559908d54a64 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7810
 
    #11 0x559908d2bad0 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1847
 
    #12 0x559908d28624 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1393
 
    #13 0x5599090edb84 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
 
    #14 0x5599090ed43e in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #15 0x55990a6dfaba in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #16 0x7efc33694608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
 
 
 
previously allocated by thread T5 here:
 
    #0 0x7efc337fcbc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
 
    #1 0x55990a8f02b6 in sf_malloc /data/src/10.3/mysys/safemalloc.c:118
 
    #2 0x55990a8be50d in my_malloc /data/src/10.3/mysys/my_malloc.c:101
 
    #3 0x55990a89a824 in alloc_root /data/src/10.3/mysys/my_alloc.c:251
 
    #4 0x559908d65332 in Query_arena::memdup_w_gap(void const*, unsigned long, unsigned long) /data/src/10.3/sql/sql_class.h:1035
 
    #5 0x559908d30c19 in alloc_query(THD*, char const*, unsigned long) /data/src/10.3/sql/sql_parse.cc:2718
 
    #6 0x559908b2019c in sp_instr_stmt::execute(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3595
 
    #7 0x559908b11bc7 in sp_head::execute(THD*, bool) /data/src/10.3/sql/sp_head.cc:1377
 
    #8 0x559908b17b8a in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.3/sql/sp_head.cc:2404
 
    #9 0x559908d325b3 in do_execute_sp /data/src/10.3/sql/sql_parse.cc:2983
 
    #10 0x559908d34181 in Sql_cmd_call::execute(THD*) /data/src/10.3/sql/sql_parse.cc:3223
 
    #11 0x559908d484e3 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6022
 
    #12 0x559908d54a64 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7810
 
    #13 0x559908d2bad0 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1847
 
    #14 0x559908d28624 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1393
 
    #15 0x5599090edb84 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
 
    #16 0x5599090ed43e in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #17 0x55990a6dfaba in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
 
    #18 0x7efc33694608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T5 created by T0 here:
 
    #0 0x7efc33729805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x55990a6dfeab in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
 
    #2 0x559908a56fc2 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x559908a6f7a2 in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6609
 
    #4 0x559908a6ff33 in create_new_thread /data/src/10.3/sql/mysqld.cc:6679
 
    #5 0x559908a710be in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6937
 
    #6 0x559908a6eab4 in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6231
 
    #7 0x559908a557ec in main /data/src/10.3/sql/main.cc:25
 
    #8 0x7efc331730b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.3/sql/sql_list.h:440 in base_list_iterator::next_fast()
 
Shadow bytes around the buggy address:
 
  0x0c4a80018440: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a80018450: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a80018460: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a80018470: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a80018480: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c4a80018490: fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a800184a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a800184b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a800184c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a800184d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c4a800184e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
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
 
  Shadow gap:              cc
 
==29051==ABORTING

Reproducible on 10.3-10.5 with at least MyISAM, InnoDB, Aria.
The test case is not applicable to earlier versions due to system versioning.
Generated at Thu Feb 08 09:24:13 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.