[MDEV-18693] Server crash or ASAN heap-use-after-free in _ma_remove_table_from_trnman upon FLUSH under combination of locks Created: 2019-02-22  Updated: 2021-02-21  Resolved: 2021-02-21

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Locking, Storage Engine - Aria
Affects Version/s: 10.0, 10.1, 10.2, 10.3
Fix Version/s: 10.2.28, 10.3.19, 10.4.9

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: not-10.4


 Description   

On whatever reason the test case is non-deterministic, run with big enough --repeat=N. Sometimes it fails for me on every attempt, and sometimes it takes dozens to reproduce the problem.

CREATE TABLE t1 (f INT) ENGINE=Aria;
CREATE TABLE t2 (f INT) ENGINE=Aria;
 
LOCK TABLES t1 WRITE, t2 a WRITE CONCURRENT, t2 b WRITE;
FLUSH TABLES t2, t1;
 
# Cleanup
UNLOCK TABLES;
DROP TABLE t1, t2;

10.3 4946eb7b ASAN

==28607==ERROR: AddressSanitizer: heap-use-after-free on address 0x6290000dc280 at pc 0x55582059829a bp 0x7f24e34aebd0 sp 0x7f24e34aebc8
READ of size 8 at 0x6290000dc280 thread T5
    #0 0x555820598299 in _ma_remove_table_from_trnman /data/src/10.3/storage/maria/ma_state.c:608
    #1 0x55582068489d in maria_extra /data/src/10.3/storage/maria/ma_extra.c:412
    #2 0x5558205cf939 in ha_maria::extra(ha_extra_function) /data/src/10.3/storage/maria/ha_maria.cc:2624
    #3 0x55581f84cbf8 in wait_while_table_is_used(THD*, TABLE*, ha_extra_function) /data/src/10.3/sql/sql_base.cc:1256
    #4 0x55581f848434 in close_cached_tables(THD*, TABLE_LIST*, bool, unsigned long) /data/src/10.3/sql/sql_base.cc:426
    #5 0x55581fd7448d in reload_acl_and_cache(THD*, unsigned long long, TABLE_LIST*, int*) /data/src/10.3/sql/sql_reload.cc:344
    #6 0x55581f9b2be8 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:5625
    #7 0x55581f9c1fa8 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:8095
    #8 0x55581f99c080 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1854
    #9 0x55581f999092 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1396
    #10 0x55581fd0c867 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
    #11 0x55581fd0c273 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1309
    #12 0x55582084134f in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
    #13 0x7f24efa85493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
    #14 0x7f24ede6b93e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
0x6290000dc280 is located 128 bytes inside of 18428-byte region [0x6290000dc200,0x6290000e09fc)
freed by thread T5 here:
    #0 0x7f24efcef527 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x54527)
    #1 0x5558211f1275 in free_memory /data/src/10.3/mysys/safemalloc.c:279
    #2 0x5558211f087b in sf_free /data/src/10.3/mysys/safemalloc.c:197
    #3 0x5558211c12c4 in my_free /data/src/10.3/mysys/my_malloc.c:223
    #4 0x555820732fc6 in maria_close /data/src/10.3/storage/maria/ma_close.c:269
    #5 0x5558205c43f1 in ha_maria::close() /data/src/10.3/storage/maria/ha_maria.cc:1275
    #6 0x5558200cc22a in handler::ha_close() /data/src/10.3/sql/handler.cc:2799
    #7 0x55581fc52da1 in closefrm(TABLE*) /data/src/10.3/sql/table.cc:3593
    #8 0x55581feb9ecd in intern_close_table /data/src/10.3/sql/table_cache.cc:222
    #9 0x55581feba133 in tc_remove_table /data/src/10.3/sql/table_cache.cc:260
    #10 0x55581febb40f in tc_release_table(TABLE*) /data/src/10.3/sql/table_cache.cc:474
    #11 0x55581f84b295 in close_thread_table(THD*, TABLE**) /data/src/10.3/sql/sql_base.cc:912
    #12 0x55581f849d2a in close_all_tables_for_name(THD*, TABLE_SHARE*, ha_extra_function, TABLE*) /data/src/10.3/sql/sql_base.cc:680
    #13 0x55581f84848b in close_cached_tables(THD*, TABLE_LIST*, bool, unsigned long) /data/src/10.3/sql/sql_base.cc:432
    #14 0x55581fd7448d in reload_acl_and_cache(THD*, unsigned long long, TABLE_LIST*, int*) /data/src/10.3/sql/sql_reload.cc:344
    #15 0x55581f9b2be8 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:5625
    #16 0x55581f9c1fa8 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:8095
    #17 0x55581f99c080 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1854
    #18 0x55581f999092 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1396
    #19 0x55581fd0c867 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
    #20 0x55581fd0c273 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1309
    #21 0x55582084134f in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
    #22 0x7f24efa85493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
previously allocated by thread T5 here:
    #0 0x7f24efcef73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
    #1 0x5558211effeb in sf_malloc /data/src/10.3/mysys/safemalloc.c:118
    #2 0x5558211c08e6 in my_malloc /data/src/10.3/mysys/my_malloc.c:101
    #3 0x55582119e127 in my_multi_malloc /data/src/10.3/mysys/mulalloc.c:51
    #4 0x5558206619c5 in maria_clone_internal /data/src/10.3/storage/maria/ma_open.c:117
    #5 0x55582066ae9f in maria_open /data/src/10.3/storage/maria/ma_open.c:1056
    #6 0x5558205c3544 in ha_maria::open(char const*, int, unsigned int) /data/src/10.3/storage/maria/ha_maria.cc:1201
    #7 0x5558200cb330 in handler::ha_open(TABLE*, char const*, int, unsigned int, st_mem_root*, List<String>*) /data/src/10.3/sql/handler.cc:2733
    #8 0x55581fc51edf in open_table_from_share(THD*, TABLE_SHARE*, st_mysql_const_lex_string const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, List<String>*) /data/src/10.3/sql/table.cc:3495
    #9 0x55581f84f852 in open_table(THD*, TABLE_LIST*, Open_table_context*) /data/src/10.3/sql/sql_base.cc:1975
    #10 0x55581f856f2e in open_and_process_table /data/src/10.3/sql/sql_base.cc:3596
    #11 0x55581f85990f in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /data/src/10.3/sql/sql_base.cc:4121
    #12 0x55581f993a95 in open_tables /data/src/10.3/sql/sql_base.h:250
    #13 0x55581f9a1303 in lock_tables_open_and_lock_tables /data/src/10.3/sql/sql_parse.cc:2822
    #14 0x55581f9af8b8 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:5207
    #15 0x55581f9c1fa8 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:8095
    #16 0x55581f99c080 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1854
    #17 0x55581f999092 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1396
    #18 0x55581fd0c867 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
    #19 0x55581fd0c273 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1309
    #20 0x55582084134f in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
    #21 0x7f24efa85493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
Thread T5 created by T0 here:
    #0 0x7f24efcbebba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
    #1 0x555820841917 in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1912
    #2 0x55581f703c08 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1268
    #3 0x55581f719d9a in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6573
    #4 0x55581f71a49f in create_new_thread /data/src/10.3/sql/mysqld.cc:6643
    #5 0x55581f71b4b6 in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6918
    #6 0x55581f719257 in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6195
    #7 0x55581f701c8f in main /data/src/10.3/sql/main.cc:25
    #8 0x7f24edda32b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.3/storage/maria/ma_state.c:608 _ma_remove_table_from_trnman
Shadow bytes around the buggy address:
  0x0c5280013800: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c5280013810: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c5280013820: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c5280013830: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c5280013840: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c5280013850:[fd]fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5280013860: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5280013870: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5280013880: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5280013890: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c52800138a0: 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
  Heap right redzone:      fb
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack partial redzone:   f4
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Contiguous container OOB:fc
  ASan internal:           fe
==28607==ABORTING

10.3 4946eb7b debug

#3  <signal handler called>
#4  0x0000562facccc347 in _ma_remove_table_from_trnman (info=0x7f55cc16ed80) at /data/src/10.3/storage/maria/ma_state.c:608
#5  0x0000562facd29262 in maria_extra (info=0x7f55cc16ed80, function=HA_EXTRA_PREPARE_FOR_FORCED_CLOSE, extra_arg=0x0) at /data/src/10.3/storage/maria/ma_extra.c:412
#6  0x0000562facce1492 in ha_maria::extra (this=0x7f55cc099298, operation=HA_EXTRA_PREPARE_FOR_FORCED_CLOSE) at /data/src/10.3/storage/maria/ha_maria.cc:2624
#7  0x0000562fac741c8b in wait_while_table_is_used (thd=0x7f55cc000b00, table=0x7f55cc098650, function=HA_EXTRA_PREPARE_FOR_FORCED_CLOSE) at /data/src/10.3/sql/sql_base.cc:1256
#8  0x0000562fac740080 in close_cached_tables (thd=0x7f55cc000b00, tables=0x7f55cc014dc0, wait_for_refresh=true, timeout=86400) at /data/src/10.3/sql/sql_base.cc:426
#9  0x0000562fac96d4ce in reload_acl_and_cache (thd=0x7f55cc000b00, options=4, tables=0x7f55cc014dc0, write_to_binlog=0x7f55dd6177b0) at /data/src/10.3/sql/sql_reload.cc:344
#10 0x0000562fac7da497 in mysql_execute_command (thd=0x7f55cc000b00) at /data/src/10.3/sql/sql_parse.cc:5625
#11 0x0000562fac7e1a69 in mysql_parse (thd=0x7f55cc000b00, rawbuf=0x7f55cc014ce8 "FLUSH TABLES t2, t1", length=19, parser_state=0x7f55dd6185f0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:8095
#12 0x0000562fac7cec1d in dispatch_command (command=COM_QUERY, thd=0x7f55cc000b00, packet=0x7f55cc00b1f1 "FLUSH TABLES t2, t1", packet_length=19, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1854
#13 0x0000562fac7cd5f5 in do_command (thd=0x7f55cc000b00) at /data/src/10.3/sql/sql_parse.cc:1396
#14 0x0000562fac935d07 in do_handle_one_connection (connect=0x562fafbf9d90) at /data/src/10.3/sql/sql_connect.cc:1403
#15 0x0000562fac935a8b in handle_one_connection (arg=0x562fafbf9d90) at /data/src/10.3/sql/sql_connect.cc:1309
#16 0x0000562facdd1c1f in pfs_spawn_thread (arg=0x562fafc02480) at /data/src/10.3/storage/perfschema/pfs.cc:1862
#17 0x00007f55e5148494 in start_thread (arg=0x7f55dd619700) at pthread_create.c:333
#18 0x00007f55e352e93f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Could not reproduce on 10.4 5b4d6595.



 Comments   
Comment by Alice Sherepa [ 2020-11-18 ]

could not reproduce on current 10.2 9b30212f15e28, 10.3 a00e21c03d76c

Comment by Elena Stepanova [ 2021-02-21 ]

The failure stopped happening on 10.2 after this commit:

commit 3ce14a66efc69a4ed9903ce121f5b0e9f469b12b
Author: Monty
Date:   Wed Oct 16 18:40:31 2019 +0300
 
    Fixed bug in lock tables + alter table with Aria tables.

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