[MDEV-29027] ASAN errors in spider_db_free_result after partition DDL Created: 2022-07-04  Updated: 2023-11-28

Status: Stalled
Project: MariaDB Server
Component/s: Partitioning, Storage Engine - Spider
Affects Version/s: 10.5, 10.6, 10.7, 10.8, 10.9, 10.10
Fix Version/s: 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Yuchen Pei
Resolution: Unresolved Votes: 0
Labels: None


 Description   

--source plugin/spider/spider/include/init_spider.inc
--source include/have_partition.inc
 
SET spider_same_server_link= on;
eval create server s foreign data wrapper mysql options (host "127.0.0.1", database "test", user "root", port $MASTER_MYPORT);
 
CREATE TABLE t1 (a INT);
CREATE TABLE t_spider (a INT) ENGINE=SPIDER PARTITION BY HASH(a) (PARTITION p1 COMMENT = "wrapper 'mysql', srv 's', table 't1'");
CREATE TABLE t2 (a INT);
ALTER TABLE t_spider ADD PARTITION (PARTITION p2 COMMENT = "wrapper 'mysql', srv 's', table 't2'");
 
# Cleanup
DROP TABLE t_spider, t1, t2;
 
--source plugin/spider/spider/include/deinit_spider.inc

10.5 b546913b

==4132956==ERROR: AddressSanitizer: heap-use-after-free on address 0x6140000110c8 at pc 0x7f10a2f04c5a bp 0x7f10a33d0230 sp 0x7f10a33d0228
READ of size 8 at 0x6140000110c8 thread T5
    #0 0x7f10a2f04c59 in spider_db_free_result(ha_spider*, bool) /data/src/10.5/storage/spider/spd_db_conn.cc:3728
    #1 0x7f10a300c442 in ha_spider::close() /data/src/10.5/storage/spider/ha_spider.cc:711
    #2 0x556cc0f0ad78 in ha_partition::close() /data/src/10.5/sql/ha_partition.cc:4060
    #3 0x556cc0c6b1cc in alter_close_table /data/src/10.5/sql/sql_partition.cc:6838
    #4 0x556cc0c8e77c in fast_alter_partition_table(THD*, TABLE*, Alter_info*, HA_CREATE_INFO*, TABLE_LIST*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*) /data/src/10.5/sql/sql_partition.cc:7402
    #5 0x556cc02af8e5 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) /data/src/10.5/sql/sql_table.cc:10557
    #6 0x556cc03ee7f5 in Sql_cmd_alter_table::execute(THD*) /data/src/10.5/sql/sql_alter.cc:543
    #7 0x556cc0062187 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:6056
    #8 0x556cc006f23b in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:8100
    #9 0x556cc0075554 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1891
    #10 0x556cc007ae52 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1375
    #11 0x556cc03dcc5e in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1418
    #12 0x556cc03dd30c in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1312
    #13 0x556cc0f29cf4 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
    #14 0x7f10ac77cea6 in start_thread nptl/pthread_create.c:477
    #15 0x7f10ac379dee in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xfddee)
 
0x6140000110c8 is located 136 bytes inside of 416-byte region [0x614000011040,0x6140000111e0)
freed by thread T5 here:
    #0 0x7f10acd10b6f in __interceptor_free ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:123
    #1 0x7f10a2fed0d1 in spider_free_mem(st_spider_transaction*, void*, unsigned long) /data/src/10.5/storage/spider/spd_malloc.cc:188
    #2 0x7f10a300ca9a in ha_spider::close() /data/src/10.5/storage/spider/ha_spider.cc:722
    #3 0x556cc0f0ad78 in ha_partition::close() /data/src/10.5/sql/ha_partition.cc:4060
    #4 0x556cc0c6b1cc in alter_close_table /data/src/10.5/sql/sql_partition.cc:6838
    #5 0x556cc0c8e77c in fast_alter_partition_table(THD*, TABLE*, Alter_info*, HA_CREATE_INFO*, TABLE_LIST*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*) /data/src/10.5/sql/sql_partition.cc:7402
    #6 0x556cc02af8e5 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) /data/src/10.5/sql/sql_table.cc:10557
    #7 0x556cc03ee7f5 in Sql_cmd_alter_table::execute(THD*) /data/src/10.5/sql/sql_alter.cc:543
    #8 0x556cc0062187 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:6056
    #9 0x556cc006f23b in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:8100
    #10 0x556cc0075554 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1891
    #11 0x556cc007ae52 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1375
    #12 0x556cc03dcc5e in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1418
    #13 0x556cc03dd30c in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1312
    #14 0x556cc0f29cf4 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
    #15 0x7f10ac77cea6 in start_thread nptl/pthread_create.c:477
 
previously allocated by thread T5 here:
    #0 0x7f10acd10e8f in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x556cc18da748 in my_malloc /data/src/10.5/mysys/my_malloc.c:90
    #2 0x7f10a2fed3fd in spider_bulk_alloc_mem(st_spider_transaction*, unsigned int, char const*, char const*, unsigned long, unsigned long, ...) /data/src/10.5/storage/spider/spd_malloc.cc:236
    #3 0x7f10a30336a1 in ha_spider::open(char const*, int, unsigned int) /data/src/10.5/storage/spider/ha_spider.cc:379
    #4 0x556cc0726d3f in handler::ha_open(TABLE*, char const*, int, unsigned int, st_mem_root*, List<String>*) /data/src/10.5/sql/handler.cc:3013
    #5 0x556cc0f14ff2 in ha_partition::open_read_partitions(char*, unsigned long) /data/src/10.5/sql/ha_partition.cc:8792
    #6 0x556cc0f16754 in ha_partition::open(char const*, int, unsigned int) /data/src/10.5/sql/ha_partition.cc:3784
    #7 0x556cc0726d3f in handler::ha_open(TABLE*, char const*, int, unsigned int, st_mem_root*, List<String>*) /data/src/10.5/sql/handler.cc:3013
    #8 0x556cc0346390 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.5/sql/table.cc:4322
    #9 0x556cbfef26ed in open_table(THD*, TABLE_LIST*, Open_table_context*) /data/src/10.5/sql/sql_base.cc:2014
    #10 0x556cbfefb261 in open_and_process_table /data/src/10.5/sql/sql_base.cc:3805
    #11 0x556cbfefb261 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /data/src/10.5/sql/sql_base.cc:4288
    #12 0x556cc02a8385 in open_tables /data/src/10.5/sql/sql_base.h:263
    #13 0x556cc02a8385 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) /data/src/10.5/sql/sql_table.cc:10066
    #14 0x556cc03ee7f5 in Sql_cmd_alter_table::execute(THD*) /data/src/10.5/sql/sql_alter.cc:543
    #15 0x556cc0062187 in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:6056
    #16 0x556cc006f23b in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:8100
    #17 0x556cc0075554 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1891
    #18 0x556cc007ae52 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1375
    #19 0x556cc03dcc5e in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1418
    #20 0x556cc03dd30c in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1312
    #21 0x556cc0f29cf4 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
    #22 0x7f10ac77cea6 in start_thread nptl/pthread_create.c:477
 
Thread T5 created by T0 here:
    #0 0x7f10accbc2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
    #1 0x556cc0f29f82 in my_thread_create /data/src/10.5/storage/perfschema/my_thread.h:52
    #2 0x556cc0f29f82 in pfs_spawn_thread_v1 /data/src/10.5/storage/perfschema/pfs.cc:2252
    #3 0x556cbfdd422b in inline_mysql_thread_create /data/src/10.5/include/mysql/psi/mysql_thread.h:1323
    #4 0x556cbfdd422b in create_thread_to_handle_connection(CONNECT*) /data/src/10.5/sql/mysqld.cc:6051
    #5 0x556cbfddfaa2 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.5/sql/mysqld.cc:6175
    #6 0x556cbfde04b3 in handle_connections_sockets() /data/src/10.5/sql/mysqld.cc:6302
    #7 0x556cbfde219b in mysqld_main(int, char**) /data/src/10.5/sql/mysqld.cc:5697
    #8 0x7f10ac2a2d09 in __libc_start_main ../csu/libc-start.c:308
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.5/storage/spider/spd_db_conn.cc:3728 in spider_db_free_result(ha_spider*, bool)
Shadow bytes around the buggy address:
  0x0c287fffa1c0: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
  0x0c287fffa1d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c287fffa1e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c287fffa1f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 fa fa
  0x0c287fffa200: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
=>0x0c287fffa210: fd fd fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd
  0x0c287fffa220: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c287fffa230: fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa
  0x0c287fffa240: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c287fffa250: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c287fffa260: 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
  Shadow gap:              cc

Couldn't reproduce on 10.4.



 Comments   
Comment by Nayuta Yanagisawa (Inactive) [ 2022-07-05 ]

A simplified test case:

--echo #
--echo # MDEV-29027 ASAN errors in spider_db_free_result after partition DDL
--echo #
 
--disable_query_log
--disable_result_log
--source ../../t/test_init.inc
--enable_result_log
--enable_query_log
 
CREATE DATABASE auto_test_local;
USE auto_test_local;
 
eval CREATE TABLE tbl_a (
    c INT
) $MASTER_1_ENGINE $MASTER_1_CHARSET PARTITION BY HASH(c) (
    PARTITION pt1
);
 
ALTER TABLE tbl_a ADD PARTITION (PARTITION pt2);
 
DROP DATABASE auto_test_local;
 
--disable_query_log
--disable_result_log
--source ../../t/test_deinit.inc
--enable_result_log
--enable_query_log

Comment by Nayuta Yanagisawa (Inactive) [ 2022-07-05 ]

Spider calls ha_spider::close() (at least) twice on ALTER TABLE. The first call frees wide_handler->trx and the second call accesses wide_handler->trx->thd (heap-use-after-free). Here, thd is only used for checking the value of the plugin variable spider_reset_sql_alloc. I'm now investigating there is any reason to use trx->thd not current_thd.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-07-06 ]

holyfoot Please review. The patch is formatted by clang-format-diff. https://github.com/MariaDB/server/commit/eb93b5350d024212658428ca8ded87d171e408bf

Comment by Alexey Botchkov [ 2022-12-05 ]

ok to push.
The current_thd function considered to be slow. But since the spider_db_free_result isn't called that often it's tolerable.

Generated at Thu Feb 08 10:05:19 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.