[MDEV-31996] Segfault when setting spider_delete_all_rows to 0 and delete all rows of a spider table, ASAN heap-use-after-free in spider_db_delete_all_rows Created: 2023-08-24  Updated: 2023-12-07  Resolved: 2023-10-11

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - Spider
Affects Version/s: 10.5, 10.6, 10.9, 10.10, 10.11, 11.0, 11.1, 11.2
Fix Version/s: 10.4.32, 10.5.23, 10.6.16, 10.10.7, 10.11.6, 11.0.4, 11.1.3

Type: Bug Priority: Critical
Reporter: Yuchen Pei Assignee: Yuchen Pei
Resolution: Fixed Votes: 0
Labels: not-10.5, regression-10.6

Issue Links:
PartOf
is part of MDEV-29962 SIGSEGV in ha_spider::lock_tables on ... Stalled
Problem/Incident
is caused by MDEV-19002 Partition performance optimization Stalled
Relates
relates to MDEV-27902 Spider: Crashes, asserts, hangs, corr... Stalled
relates to MDEV-28683 Spider: SIGSEGV in spider_db_direct_d... Closed

 Description   

Affects 11.2 73915d2cdad2d539ce984529bb6e64dc082ecd52 and does not affect 10.4 e9f3ca612528c5f917e27ef6113fd1deda2aef26

Test to reproduce (put under say spider/bugfix suite):

--disable_query_log
--disable_result_log
--source ../../t/test_init.inc
--enable_result_log
--enable_query_log
 
evalp CREATE SERVER srv FOREIGN DATA WRAPPER mysql
OPTIONS (SOCKET "$MASTER_1_MYSOCK", DATABASE 'test',user 'root');
 
set session spider_delete_all_rows_type=0;
create table t2 (c int);
create table t1 (c int) ENGINE=Spider
COMMENT='WRAPPER "mysql", srv "srv",TABLE "t2", delete_all_rows_type "0"';
insert ignore into t1 values (42), (378);
select * from t1;
delete from t1;
select * from t1;
 
drop table t1, t2;
 
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 tmp
--echo #

Trace in mtr output:

mysys/stacktrace.c:215(my_print_stacktrace)[0x55bf85b4b891]
sql/signal_handler.cc:241(handle_fatal_signal)[0x55bf852ce514]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x13140)[0x7fcad4843140]
/lib/x86_64-linux-gnu/libc.so.6(+0x15e319)[0x7fcad4078319]
/lib/x86_64-linux-gnu/libc.so.6(+0x68f76)[0x7fcad3f82f76]
/lib/x86_64-linux-gnu/libc.so.6(+0x69f44)[0x7fcad3f83f44]
/lib/x86_64-linux-gnu/libc.so.6(+0x670d4)[0x7fcad3f810d4]
/lib/x86_64-linux-gnu/libc.so.6(_IO_fprintf+0x96)[0x7fcad3f6dcc6]
mysys/thr_mutex.c:296(safe_mutex_lock)[0x55bf85b5013b]
mysys/my_thr_init.c:487(psi_mutex_lock)[0x55bf85b49a1d]
psi/mysql_thread.h:746(inline_mysql_mutex_lock)[0x7fcac0277fdb]
spider/spd_db_conn.cc:6701(spider_db_delete_all_rows(ha_spider*))[0x7fcac029a508]
spider/ha_spider.cc:8422(ha_spider::delete_all_rows())[0x7fcac0341e4c]
sql/handler.cc:5272(handler::ha_delete_all_rows())[0x55bf852e0a30]
sql/sql_delete.cc:438(Sql_cmd_delete::delete_from_single_table(THD*))[0x55bf84e80b99]
sql/sql_delete.cc:1794(Sql_cmd_delete::execute_inner(THD*))[0x55bf84e85a95]
sql/sql_select.cc:33356(Sql_cmd_dml::execute(THD*))[0x55bf84fa76f5]
sql/sql_parse.cc:4394(mysql_execute_command(THD*, bool))[0x55bf84ee9c51]
sql/sql_parse.cc:7799(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55bf84ef4fe7]
sql/sql_parse.cc:1895(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55bf84ee2592]
sql/sql_parse.cc:1406(do_command(THD*, bool))[0x55bf84ee0f60]
sql/sql_connect.cc:1445(do_handle_one_connection(CONNECT*, bool))[0x55bf850c8c0a]
sql/sql_connect.cc:1349(handle_one_connection)[0x55bf850c8975]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55bf855dc062]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7ea7)[0x7fcad4837ea7]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fcad4016a2f]



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

Bug confirmed present in:
MariaDB: 10.6.15 (dbg), 10.9.8 (dbg), 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 (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)

Plain SQL testcase (change socket):

INSTALL PLUGIN Spider SONAME 'ha_spider.so';
CREATE USER Spider@localhost IDENTIFIED BY 'pwd';
CREATE SERVER s FOREIGN DATA WRAPPER MYSQL OPTIONS (SOCKET "./socket.sock",DATABASE 'test',user 'Spider',PASSWORD 'pwd');
SET SESSION spider_delete_all_rows_type=0;
CREATE TABLE t2 (c INT);
CREATE TABLE t1 (c INT) ENGINE=Spider
COMMENT='WRAPPER "mysql", SERVER "s",TABLE "t2", delete_all_rows_type "0"';
INSERT IGNORE INTO t1 VALUES (42),(378);
SELECT * FROM t1;
DELETE FROM t1;

Note: the crash happens on the DELETE

Comment by Roel Van de Paar [ 2023-08-24 ]

ASAN sees a heap-use-after-free in spider_db_delete_all_rows in spd_db_conn.cc in both optimized and debug builds (same issue):

11.2.0 e81fa345020ec6a067583db6a7019d6404b26f93 (Optimized, UBASAN)

==3200369==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0001d1b30 at pc 0x14abeeeffb14 bp 0x14abefb4cf20 sp 0x14abefb4cf10
WRITE of size 8 at 0x61d0001d1b30 thread T36
    #0 0x14abeeeffb13 in spider_db_delete_all_rows(ha_spider*) /data/11.2_opt_san/storage/spider/spd_db_conn.cc:6701
    #1 0x14abef09195a in ha_spider::delete_all_rows() /data/11.2_opt_san/storage/spider/ha_spider.cc:8422
    #2 0x55bac50d6be3 in Sql_cmd_delete::delete_from_single_table(THD*) /data/11.2_opt_san/sql/sql_delete.cc:438
    #3 0x55bac50e3c68 in Sql_cmd_delete::execute_inner(THD*) /data/11.2_opt_san/sql/sql_delete.cc:1794
    #4 0x55bac5522f50 in Sql_cmd_dml::execute(THD*) /data/11.2_opt_san/sql/sql_select.cc:33356
    #5 0x55bac5395da4 in mysql_execute_command(THD*, bool) /data/11.2_opt_san/sql/sql_parse.cc:4393
    #6 0x55bac53b4fc2 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/11.2_opt_san/sql/sql_parse.cc:7800
    #7 0x55bac53c05e5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/11.2_opt_san/sql/sql_parse.cc:1892
    #8 0x55bac53cc1f8 in do_command(THD*, bool) /data/11.2_opt_san/sql/sql_parse.cc:1405
    #9 0x55bac5ced4ac in do_handle_one_connection(CONNECT*, bool) /data/11.2_opt_san/sql/sql_connect.cc:1445
    #10 0x55bac5cefaac in handle_one_connection /data/11.2_opt_san/sql/sql_connect.cc:1347
    #11 0x14ac14c94b42 in start_thread nptl/pthread_create.c:442
    #12 0x14ac14d269ff  (/lib/x86_64-linux-gnu/libc.so.6+0x1269ff)
 
0x61d0001d1b30 is located 176 bytes inside of 2432-byte region [0x61d0001d1a80,0x61d0001d2400)
freed by thread T36 here:
    #0 0x55bac4b13507 in free (/test/UBASAN_MD030823-mariadb-11.2.0-linux-x86_64-opt/bin/mariadbd+0x7c40507)
    #1 0x14abef041837 in spider_free_mem(st_spider_transaction*, void*, unsigned long) /data/11.2_opt_san/storage/spider/spd_malloc.cc:183
    #2 0x14abeef426f5 in spider_free_conn(st_spider_conn*) /data/11.2_opt_san/storage/spider/spd_conn.cc:860
    #3 0x14abeee56362 in spider_free_trx_conn(st_spider_transaction*, bool) /data/11.2_opt_san/storage/spider/spd_trx.cc:114
    #4 0x14abeee70087 in spider_rollback(handlerton*, THD*, bool) /data/11.2_opt_san/storage/spider/spd_trx.cc:3304
    #5 0x55bac6965240 in ha_rollback_trans(THD*, bool) /data/11.2_opt_san/sql/handler.cc:2253
    #6 0x55bac5d71f20 in trans_rollback_stmt(THD*) /data/11.2_opt_san/sql/transaction.cc:535
    #7 0x55bac5393464 in mysql_execute_command(THD*, bool) /data/11.2_opt_san/sql/sql_parse.cc:5845
    #8 0x55bac53b4fc2 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/11.2_opt_san/sql/sql_parse.cc:7800
    #9 0x55bac53c05e5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/11.2_opt_san/sql/sql_parse.cc:1892
    #10 0x55bac53cc1f8 in do_command(THD*, bool) /data/11.2_opt_san/sql/sql_parse.cc:1405
    #11 0x55bac5ced4ac in do_handle_one_connection(CONNECT*, bool) /data/11.2_opt_san/sql/sql_connect.cc:1445
    #12 0x55bac5cefaac in handle_one_connection /data/11.2_opt_san/sql/sql_connect.cc:1347
    #13 0x14ac14c94b42 in start_thread nptl/pthread_create.c:442
 
previously allocated by thread T36 here:
    #0 0x55bac4b13857 in __interceptor_malloc (/test/UBASAN_MD030823-mariadb-11.2.0-linux-x86_64-opt/bin/mariadbd+0x7c40857)
    #1 0x55bac8fb7454 in my_malloc /data/11.2_opt_san/mysys/my_malloc.c:89
    #2 0x14abef041ccb in spider_bulk_alloc_mem(st_spider_transaction*, unsigned int, char const*, char const*, unsigned long, unsigned long, ...) /data/11.2_opt_san/storage/spider/spd_malloc.cc:231
    #3 0x14abeef5638c in spider_create_conn(st_spider_share*, ha_spider*, int, int, int*) /data/11.2_opt_san/storage/spider/spd_conn.cc:412
    #4 0x14abeef600d2 in spider_get_conn(st_spider_share*, int, char*, st_spider_transaction*, ha_spider*, bool, bool, int*) /data/11.2_opt_san/storage/spider/spd_conn.cc:767
    #5 0x14abeee862f9 in spider_check_trx_and_get_conn(THD*, ha_spider*) /data/11.2_opt_san/storage/spider/spd_trx.cc:3580
    #6 0x14abef13b69d in ha_spider::info(unsigned int) /data/11.2_opt_san/storage/spider/ha_spider.cc:6656
    #7 0x55bac5785339 in make_join_statistics /data/11.2_opt_san/sql/sql_select.cc:5493
    #8 0x55bac57bdfcb in JOIN::optimize_inner() /data/11.2_opt_san/sql/sql_select.cc:2618
    #9 0x55bac57c4225 in JOIN::optimize() /data/11.2_opt_san/sql/sql_select.cc:1944
    #10 0x55bac57c49c6 in mysql_select(THD*, TABLE_LIST*, 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/11.2_opt_san/sql/sql_select.cc:5229
    #11 0x55bac57c8890 in handle_select(THD*, LEX*, select_result*, unsigned long long) /data/11.2_opt_san/sql/sql_select.cc:628
    #12 0x55bac53440a0 in execute_sqlcom_select /data/11.2_opt_san/sql/sql_parse.cc:6056
    #13 0x55bac53a64aa in mysql_execute_command(THD*, bool) /data/11.2_opt_san/sql/sql_parse.cc:3944
    #14 0x55bac53b4fc2 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/11.2_opt_san/sql/sql_parse.cc:7800
    #15 0x55bac53c05e5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/11.2_opt_san/sql/sql_parse.cc:1892
    #16 0x55bac53cc1f8 in do_command(THD*, bool) /data/11.2_opt_san/sql/sql_parse.cc:1405
    #17 0x55bac5ced4ac in do_handle_one_connection(CONNECT*, bool) /data/11.2_opt_san/sql/sql_connect.cc:1445
    #18 0x55bac5cefaac in handle_one_connection /data/11.2_opt_san/sql/sql_connect.cc:1347
    #19 0x14ac14c94b42 in start_thread nptl/pthread_create.c:442
 
Thread T36 created by T0 here:
    #0 0x55bac4ab7675 in pthread_create (/test/UBASAN_MD030823-mariadb-11.2.0-linux-x86_64-opt/bin/mariadbd+0x7be4675)
    #1 0x55bac4b6c34e in create_thread_to_handle_connection(CONNECT*) /data/11.2_opt_san/sql/mysqld.cc:6169
    #2 0x55bac4b7f2af in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/11.2_opt_san/sql/mysqld.cc:6293
    #3 0x55bac4b80207 in handle_connections_sockets() /data/11.2_opt_san/sql/mysqld.cc:6417
    #4 0x55bac4b831ed in mysqld_main(int, char**) /data/11.2_opt_san/sql/mysqld.cc:6064
    #5 0x14ac14c29d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/11.2_opt_san/storage/spider/spd_db_conn.cc:6701 in spider_db_delete_all_rows(ha_spider*)
Shadow bytes around the buggy address:
  0x0c3a80032310: fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3a80032320: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3a80032330: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3a80032340: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3a80032350: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c3a80032360: fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd fd fd
  0x0c3a80032370: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a80032380: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a80032390: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a800323a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a800323b0: 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
==3200369==ABORTING
230825  8:13:40 [ERROR] mysqld got signal 6 ;
qa-roel-2:/test/UBASAN_MD030823-mariadb-11.2.0-linux-x86_64-opt$ m

Comment by Roel Van de Paar [ 2023-08-24 ]

Note that the dbg (first) and opt (second) ASAN call stacks are slightly different:

ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_delete_all_rows|ha_spider::delete_all_rows|handler::ha_delete_all_rows|Sql_cmd_delete::delete_from_single_table # dbg
ASAN|heap-use-after-free|storage/spider/spd_db_conn.cc|spider_db_delete_all_rows|ha_spider::delete_all_rows|Sql_cmd_delete::delete_from_single_table|Sql_cmd_delete::execute_inner # opt

And (unrelated) for standard builds only a single UniqueID/stack was observed for all versions 10.6-11.2:

SIGSEGV|__strlen_avx2|safe_mutex_lock|inline_mysql_mutex_lock|spider_db_delete_all_rows

Comment by Yuchen Pei [ 2023-09-15 ]

Raising prio because it crashes the server, and is a 10.6 regression

Comment by Yuchen Pei [ 2023-09-20 ]

I tried to git bisect a few days ago, and found the issue seems to be
present in 10.5 as well including 10.5.22. Unfortunately the automated
git bisect with a script got stuck at building earlier versions as I
did not specify -DMYSQL_MAINTAINER_MODE=OFF, so will need to try
again...

Comment by Yuchen Pei [ 2023-10-06 ]

I can confirm the following commit causes the regression:

commit e954d9de886aebc68c39240304fe97ae88276dbb
Author: Kentoku SHIBA <kentokushiba@gmail.com>
Date:   Tue Mar 3 02:50:40 2020 +0900
 
    MDEV-19002 Spider performance optimization with partition
    
    Change the following function for batch call instead of each partition
    - store_lock
    - external_lock
    - start_stmt
    - extra
    - cond_push
    - info_push
    - top_table

Comment by Yuchen Pei [ 2023-10-06 ]

Hi holyfoot, ptal thanks

8694d80de2a bb-11.0-ycp-mdev-31996 MDEV-31996 Create connection on demand in spider_db_delete_all_rows

The above patch is based on 11.0. The following is based on 10.4

aff5e8b843d upstream/bb-10.4-mdev-31996 MDEV-31996 Create connection on demand in spider_db_delete_all_rows

Comment by Alexey Botchkov [ 2023-10-09 ]

ok to push.

Comment by Yuchen Pei [ 2023-10-11 ]

Thanks for the review. In the previous commit I forgot to keep the check on spider_param_delete_all_rows_type(thd, share->delete_all_rows_type), which is why the result files of the spider_fixes tests were changed. But that is now fixed. Pushing...

Comment by Yuchen Pei [ 2023-10-11 ]

Pushed a314aa1217849f36d66a78f80275a2e7aa51626a to 10.4

Conflicts and solutions:

  • 10.4->10.5 (no need to assign to wide_handler->sql_command) 3c8631ae5c5eafa89944ebe04db2008d721cf0cc
  • 10.11->11.0 (one fewer arg in spider_check_trx_and_get_conn()) cbb0d0232f50050447620a37972518ae536c1e71
Generated at Thu Feb 08 10:28:01 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.