[MDEV-31860] SIGSEGV in Binary_string::free_buffer and ASAN use-after-poison in TMP_TABLE_PARAM::cleanup Created: 2023-08-07  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Server, Storage Engine - Spider
Affects Version/s: 10.9, 10.10, 10.11, 11.0, 11.1
Fix Version/s: 10.11, 11.0, 11.1

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Yuchen Pei
Resolution: Unresolved Votes: 0
Labels: ASAN, memory_corruption, regression

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

 Description   

While the crashing stack, but not the ASAN stack, looks very similar to MDEV-31024 the testcase is very different, and the ASAN stack includes spider frames near the top. Additionally no views nor SFORMAT are involved here. This issue is 10.9+ for the crash and 10.10+ for the ASAN bug. It is possible that the underlying issue is the same or related.

INSTALL PLUGIN Spider SONAME 'ha_spider.so';
CREATE USER Spider@localhost IDENTIFIED BY '';
CREATE SERVER srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET '../socket.sock',DATABASE 'test',user 'Spider',PASSWORD '');
CREATE TABLE t (c INT) ENGINE=InnoDB;
CREATE TABLE t1 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "srv",TABLE "t"';
INSERT INTO t VALUES (1),(2),(3);
SET SESSION spider_quick_page_size=1;
HANDLER t1 OPEN;
HANDLER t1 READ NEXT;
CREATE TABLE t1 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "srv",TABLE "t"';

Leads to:

11.1.2 adc13e2c167c90f4b287efa7b1165c68d441be8d (Debug)

Core was generated by `/test/MD010823-mariadb-11.1.2-linux-x86_64-dbg/bin/mariadbd --no-defaults --cor'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  Binary_string::free_buffer (this=0x4b4b5fcf434c8c90)
    at /test/11.1_dbg/sql/sql_string.h:305
[Current thread is 1 (Thread 0x148468093640 (LWP 235689))]
(gdb) bt
#0  Binary_string::free_buffer (this=0x4b4b5fcf434c8c90) at /test/11.1_dbg/sql/sql_string.h:305
#1  Binary_string::free (this=0x4b4b5fcf434c8c90) at /test/11.1_dbg/sql/sql_string.h:769
#2  Binary_string::~Binary_string (this=0x4b4b5fcf434c8c90, __in_chrg=<optimized out>) at /test/11.1_dbg/sql/sql_string.h:352
#3  String::~String (this=0x4b4b5fcf434c8c88, __in_chrg=<optimized out>) at /test/11.1_dbg/sql/sql_string.h:881
#4  Copy_field::~Copy_field (this=0x4b4b5fcf434c8c40, __in_chrg=<optimized out>) at /test/11.1_dbg/sql/field.h:5861
#5  TMP_TABLE_PARAM::cleanup (this=0x1483f80c3910) at /test/11.1_dbg/sql/sql_class.h:6381
#6  spider_rm_sys_tmp_table_for_result (thd=<optimized out>, tmp_table=<optimized out>, tmp_tbl_prm=tmp_tbl_prm@entry=0x1483f80c3910) at /test/11.1_dbg/storage/spider/spd_sys_table.cc:3710
#7  0x000014843e725a54 in spider_db_free_result (spider=spider@entry=0x1483f8087860, final=final@entry=false) at /test/11.1_dbg/storage/spider/spd_db_conn.cc:2895
#8  0x000014843e785540 in ha_spider::reset (this=0x1483f8087860) at /test/11.1_dbg/storage/spider/ha_spider.cc:1013
#9  0x000056486a75d736 in handler::ha_reset (this=this@entry=0x1483f8087860) at /test/11.1_dbg/sql/handler.cc:7378
#10 0x000056486a3f4313 in close_thread_table (thd=thd@entry=0x1483f8000d58, table_ptr=table_ptr@entry=0x148468091c70) at /test/11.1_dbg/sql/sql_base.cc:1019
#11 0x000056486a42dce4 in mysql_ha_close_table (handler=handler@entry=0x1483f80c3390) at /test/11.1_dbg/sql/sql_handler.cc:221
#12 0x000056486a42fdab in mysql_ha_rm_tables (thd=thd@entry=0x1483f8000d58, tables=<optimized out>) at /test/11.1_dbg/sql/sql_handler.cc:1120
#13 0x000056486a47447f in mysql_execute_command (thd=thd@entry=0x1483f8000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.1_dbg/sql/sql_parse.cc:3798
#14 0x000056486a47ae54 in mysql_parse (thd=thd@entry=0x1483f8000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x148468092200) at /test/11.1_dbg/sql/sql_parse.cc:7774
#15 0x000056486a47cfe8 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1483f8000d58, packet=packet@entry=0x1483f800ae99 "CREATE TABLE t1 (c INT) ENGINE=Spider COMMENT='WRAPPER \"mysql\",srv \"srv\",TABLE \"t\"'", packet_length=packet_length@entry=83, blocking=blocking@entry=true) at /test/11.1_dbg/sql/sql_class.h:243
#16 0x000056486a47eec3 in do_command (thd=0x1483f8000d58, blocking=blocking@entry=true) at /test/11.1_dbg/sql/sql_parse.cc:1405
#17 0x000056486a5d2d82 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56486d722848, put_in_cache=put_in_cache@entry=true) at /test/11.1_dbg/sql/sql_connect.cc:1416
#18 0x000056486a5d2fe1 in handle_one_connection (arg=0x56486d722848) at /test/11.1_dbg/sql/sql_connect.cc:1318
#19 0x0000148480894b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#20 0x0000148480926a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

11.2.0 e81fa345020ec6a067583db6a7019d6404b26f93 (Debug, UBASAN)

==381158==ERROR: AddressSanitizer: use-after-poison on address 0x6290000d82a8 at pc 0x150ebb0753f8 bp 0x150ebbdd8460 sp 0x150ebbdd8450
READ of size 8 at 0x6290000d82a8 thread T13
    #0 0x150ebb0753f7 in TMP_TABLE_PARAM::cleanup() /data/11.2_dbg_san/sql/sql_class.h:6378
    #1 0x150ebb0753f7 in spider_rm_sys_tmp_table_for_result(THD*, TABLE*, TMP_TABLE_PARAM*) /data/11.2_dbg_san/storage/spider/spd_sys_table.cc:3710
    #2 0x150ebb0d20ed in spider_db_free_result(ha_spider*, bool) /data/11.2_dbg_san/storage/spider/spd_db_conn.cc:2895
    #3 0x150ebb2ffaea in ha_spider::reset() /data/11.2_dbg_san/storage/spider/ha_spider.cc:1013
    #4 0x560dfbb093fe in handler::ha_reset() /data/11.2_dbg_san/sql/handler.cc:7378
    #5 0x560df9e57c7e in close_thread_table(THD*, TABLE**) /data/11.2_dbg_san/sql/sql_base.cc:1019
    #6 0x560dfa02f025 in mysql_ha_close_table /data/11.2_dbg_san/sql/sql_handler.cc:221
    #7 0x560dfa03b6b5 in mysql_ha_rm_tables(THD*, TABLE_LIST*) /data/11.2_dbg_san/sql/sql_handler.cc:1120
    #8 0x560dfa2ab399 in mysql_execute_command(THD*, bool) /data/11.2_dbg_san/sql/sql_parse.cc:3798
    #9 0x560dfa2d9c10 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/11.2_dbg_san/sql/sql_parse.cc:7800
    #10 0x560dfa2e9986 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/11.2_dbg_san/sql/sql_parse.cc:1892
    #11 0x560dfa2f78cd in do_command(THD*, bool) /data/11.2_dbg_san/sql/sql_parse.cc:1405
    #12 0x560dfacd1577 in do_handle_one_connection(CONNECT*, bool) /data/11.2_dbg_san/sql/sql_connect.cc:1445
    #13 0x560dfacd2a92 in handle_one_connection /data/11.2_dbg_san/sql/sql_connect.cc:1347
    #14 0x150ede094b42 in start_thread nptl/pthread_create.c:442
    #15 0x150ede1269ff  (/lib/x86_64-linux-gnu/libc.so.6+0x1269ff)
 
0x6290000d82a8 is located 4264 bytes inside of 16400-byte region [0x6290000d7200,0x6290000db210)
allocated by thread T13 here:
    #0 0x560df999d367 in __interceptor_malloc (/test/UBASAN_MD030823-mariadb-11.2.0-linux-x86_64-dbg/bin/mariadbd+0x7b96367)
    #1 0x560dfe172af8 in my_malloc /data/11.2_dbg_san/mysys/my_malloc.c:89
    #2 0x560dfe151336 in root_alloc /data/11.2_dbg_san/mysys/my_alloc.c:71
    #3 0x560dfe1521f4 in reset_root_defaults /data/11.2_dbg_san/mysys/my_alloc.c:250
    #4 0x560df9f13873 in THD::init_for_queries() /data/11.2_dbg_san/sql/sql_class.cc:1389
    #5 0x560dfaccd28e in prepare_new_connection_state(THD*) /data/11.2_dbg_san/sql/sql_connect.cc:1274
    #6 0x560dfaccea3c in thd_prepare_connection(THD*) /data/11.2_dbg_san/sql/sql_connect.cc:1368
    #7 0x560dfacd1df6 in do_handle_one_connection(CONNECT*, bool) /data/11.2_dbg_san/sql/sql_connect.cc:1435
    #8 0x560dfacd2a92 in handle_one_connection /data/11.2_dbg_san/sql/sql_connect.cc:1347
    #9 0x150ede094b42 in start_thread nptl/pthread_create.c:442
 
Thread T13 created by T0 here:
    #0 0x560df9941185 in __interceptor_pthread_create (/test/UBASAN_MD030823-mariadb-11.2.0-linux-x86_64-dbg/bin/mariadbd+0x7b3a185)
    #1 0x560df99f5c4e in create_thread_to_handle_connection(CONNECT*) /data/11.2_dbg_san/sql/mysqld.cc:6169
    #2 0x560df9a0740f in create_new_thread(CONNECT*) /data/11.2_dbg_san/sql/mysqld.cc:6231
    #3 0x560df9a07c8f in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/11.2_dbg_san/sql/mysqld.cc:6293
    #4 0x560df9a08cd6 in handle_connections_sockets() /data/11.2_dbg_san/sql/mysqld.cc:6417
    #5 0x560df9a0d7e9 in mysqld_main(int, char**) /data/11.2_dbg_san/sql/mysqld.cc:6064
    #6 0x560df99e2f0a in main /data/11.2_dbg_san/sql/main.cc:34
    #7 0x150ede029d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
 
SUMMARY: AddressSanitizer: use-after-poison /data/11.2_dbg_san/sql/sql_class.h:6378 in TMP_TABLE_PARAM::cleanup()
Shadow bytes around the buggy address:
  0x0c5280013000: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013010: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013020: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013030: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013040: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
=>0x0c5280013050: f7 f7 f7 f7 f7[f7]f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013060: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013070: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013080: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c5280013090: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c52800130a0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
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
==381158==ABORTING
230807 17:30:32 [ERROR] mysqld got signal 6 ;

Crashing bug confirmed present in 10.9+:
MariaDB: 10.9.8 (dbg), 10.10.6 (dbg), 10.11.5 (dbg), 11.0.3 (dbg), 11.1.2 (dbg), 11.2.0 (dbg)

ASAN bug confirmed present in 10.10+:
MariaDB: 10.10.6 (dbg), 10.11.5 (dbg), 11.0.3 (dbg), 11.1.2 (dbg), 11.2.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.4.31 (dbg), 10.4.31 (opt), 10.5.22 (dbg), 10.5.22 (opt), 10.6.15 (dbg), 10.6.15 (opt), 10.9.8 (opt), 10.10.6 (opt), 10.11.5 (opt), 11.0.3 (opt), 11.1.2 (opt), 11.2.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.40 (dbg), 8.0.33 (dbg), 8.0.33 (opt)



 Comments   
Comment by Roel Van de Paar [ 2023-08-07 ]

MTR Testcase, updated w/ thanks ycp

--echo
--echo MDEV-31860
--echo
 
--disable_query_log
--disable_result_log
--source ../../t/test_init.inc
--enable_result_log
--enable_query_log
 
--let $srv=srv_mdev_31860
evalp CREATE SERVER $srv FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET "$MASTER_1_MYSOCK", DATABASE 'test',user 'root');
 
CREATE TABLE t (c INT) ENGINE=InnoDB;
eval CREATE TABLE t1 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "$srv",TABLE "t"';
INSERT INTO t VALUES (1),(2),(3);
SET SESSION spider_quick_page_size=1;
HANDLER t1 OPEN;
HANDLER t1 READ NEXT;
CREATE TABLE t1 (c INT) ENGINE=Spider COMMENT='WRAPPER "mysql",srv "srv",TABLE "t"';
 
drop table t1, t;
 
eval drop server $srv;
--disable_query_log
--disable_result_log
--source ../../t/test_deinit.inc
--enable_result_log
--enable_query_log
 
--echo
--echo end of test
--echo

Comment by Yuchen Pei [ 2023-08-08 ]

I did a little bit of debugging, the destructing String and the
tmp_tbl_prm->copy_field->tmp are different strings, and no
apparent visibility as to which String is being freed.

(rr) p &tmp_tbl_prm->copy_field->tmp
$6 = (String *) 0x7f727401c8b8
(rr) p this
$7 = (String * const) 0x4b4bcabdbf4d1348
(rr) p *this
Cannot access memory at address 0x4b4bcabdbf4d1348

Binary_string::free_buffer > Binary_string::free > Binary_string::~Binary_string > String::~String > Copy_field::~Copy_field > TMP_TABLE_PARAM::cleanup > spider_rm_sys_tmp_table_for_result > spider_db_free_result > ha_spider::reset > handler::ha_reset > close_thread_table > mysql_ha_close_table > mysql_ha_rm_tables > mysql_execute_command > mysql_parse > dispatch_command > do_command > do_handle_one_connection > handle_one_connection > pfs_spawn_thread

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