[MDEV-27239] Spider: Assertion `thd->transaction->stmt.ha_list == __null || trans == &thd->transaction->stmt' failed in ha_commit_trans on BEGIN WORK after FTWRL Created: 2021-12-12  Updated: 2022-11-07  Resolved: 2022-04-20

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - Spider
Affects Version/s: 10.5, 10.6, 10.7, 10.8
Fix Version/s: 10.5.16, 10.6.8, 10.7.4, 10.8.3

Type: Bug Priority: Critical
Reporter: Roel Van de Paar Assignee: Nayuta Yanagisawa (Inactive)
Resolution: Fixed Votes: 0
Labels: ftwrl, regression, spider

Issue Links:
Duplicate
is duplicated by MDEV-27526 Spider: SIGSEGV in ha_spider::lock_ta... Closed
Problem/Incident
is caused by MDEV-19002 Partition performance optimization Stalled
Relates
relates to MDEV-27040 Was: Assertion `thd->transaction->stm... Open
relates to MDEV-27526 Spider: SIGSEGV in ha_spider::lock_ta... Closed
relates to MDEV-28352 Spider: heap-use-after-free in ha_spi... Closed
relates to MDEV-29962 SIGSEGV in ha_spider::lock_tables on ... Stalled

 Description   

Possibly connected with MDEV-27240 but versions are different, and issue does not reproduce with InnoDB.

INSTALL PLUGIN spider SONAME 'ha_spider.so';
 
CREATE TABLE t0 (s0 INT) ENGINE=SPIDER;
 
FLUSH TABLE t0 WITH READ LOCK;
 
BEGIN WORK;

Leads to:

10.7.2 979b23d5bfb11bb698ea65c9468b374978737ec0 (Debug)

 
mysqld: /test/10.7_dbg/sql/handler.cc:1635: int ha_commit_trans(THD*, bool): Assertion `thd->transaction->stmt.ha_list == __null || trans == &thd->transaction->stmt' failed.

10.7.2 979b23d5bfb11bb698ea65c9468b374978737ec0 (Debug)

 
Core was generated by `/test/MD121221-mariadb-10.7.2-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
[Current thread is 1 (Thread 0x14a93adc8700 (LWP 482208))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014a958a4f859 in __GI_abort () at abort.c:79
 
#2  0x000014a958a4f729 in __assert_fail_base (fmt=0x14a958be5588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x558d98e9f7c0 "thd->transaction->stmt.ha_list == __null || trans == &thd->transaction->stmt", file=0x558d98e9df93 "/test/10.7_dbg/sql/handler.cc", line=1635, function=<optimized out>) at assert.c:92
 
#3  0x000014a958a60f36 in __GI___assert_fail (assertion=assertion@entry=0x558d98e9f7c0 "thd->transaction->stmt.ha_list == __null || trans == &thd->transaction->stmt", file=file@entry=0x558d98e9df93 "/test/10.7_dbg/sql/handler.cc", line=line@entry=1635, function=function@entry=0x558d98ea1d30 "int ha_commit_trans(THD*, bool)") at assert.c:101
 
#4  0x0000558d98356652 in ha_commit_trans (thd=thd@entry=0x14a8c0000db8, all=all@entry=true) at /test/10.7_dbg/sql/handler.cc:1635
 
#5  0x0000558d981cf6d5 in trans_begin (thd=thd@entry=0x14a8c0000db8, flags=0) at /test/10.7_dbg/sql/transaction.cc:127
 
#6  0x0000558d980461e0 in mysql_execute_command (thd=thd@entry=0x14a8c0000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.7_dbg/sql/sql_parse.cc:5597
 
#7  0x0000558d9802de0f in mysql_parse (thd=thd@entry=0x14a8c0000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14a93adc7400) at /test/10.7_dbg/sql/sql_parse.cc:8028
 
#8  0x0000558d9803caab in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14a8c0000db8, packet=packet@entry=0x14a8c000b879 "BEGIN WORK", packet_length=packet_length@entry=10, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_class.h:1360
 
#9  0x0000558d9803feea in do_command (thd=0x14a8c0000db8, blocking=blocking@entry=true) at /test/10.7_dbg/sql/sql_parse.cc:1402
 
#10 0x0000558d981b9902 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558d9b28bd78, put_in_cache=put_in_cache@entry=true) at /test/10.7_dbg/sql/sql_connect.cc:1418
 
#11 0x0000558d981b9f07 in handle_one_connection (arg=arg@entry=0x558d9b28bd78) at /test/10.7_dbg/sql/sql_connect.cc:1312
 
#12 0x0000558d9863a33e in pfs_spawn_thread (arg=0x558d9b19d608) at /test/10.7_dbg/storage/perfschema/pfs.cc:2201
 
#13 0x000014a958f5e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#14 0x000014a958b4c293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.14 (dbg), 10.6.6 (dbg), 10.7.2 (dbg), 10.8.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.42 (dbg), 10.2.42 (opt), 10.3.33 (dbg), 10.3.33 (opt), 10.4.23 (dbg), 10.4.23 (opt), 10.5.14 (opt), 10.6.6 (opt), 10.7.2 (opt), 10.8.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.36 (dbg), 5.7.36 (opt), 8.0.27 (dbg), 8.0.27 (opt)

 Comments   
Comment by Roel Van de Paar [ 2021-12-26 ]

This stack can (presumed) also be seen in connection with this bug:

10.6.6 e0e24b180d090d7ee378c097ab02df891b61a965 (Debug)

 
Core was generated by `/test/MD031221-mariadb-10.6.6-linux-x86_64-dbg/bin/mysqld --no-defaults --max_a'.
 
Program terminated with signal SIGSEGV, Segmentation fault.
 
#0  0x000014e6881435d9 in ha_spider::lock_tables (
 
    this=this@entry=0x14e5d830a7d0)
 
    at /test/10.6_dbg/storage/spider/ha_spider.cc:16410
 
 
 
warning: Source file is more recent than executable.
 
16410           if (
 
[Current thread is 1 (Thread 0x14e69c482700 (LWP 3771259))]
 
(gdb) bt
 
#0  0x000014e6881435d9 in ha_spider::lock_tables (this=this@entry=0x14e5d830a7d0) at /test/10.6_dbg/storage/spider/ha_spider.cc:16410
 
#1  0x000014e688143907 in ha_spider::external_lock (this=0x14e5d830a7d0, thd=<optimized out>, lock_type=2) at /test/10.6_dbg/storage/spider/ha_spider.cc:1350
 
#2  0x000055ceedb3afee in handler::ha_external_lock (this=0x14e5d830a7d0, thd=thd@entry=0x14e5d8000db8, lock_type=lock_type@entry=2) at /test/10.6_dbg/sql/handler.cc:7045
 
#3  0x000055ceedc96318 in handler::ha_external_unlock (thd=0x14e5d8000db8, this=<optimized out>) at /test/10.6_dbg/sql/handler.h:3590
 
#4  unlock_external (thd=thd@entry=0x14e5d8000db8, table=0x14e5d831df08, count=<optimized out>) at /test/10.6_dbg/sql/lock.cc:727
 
#5  0x000055ceedc96545 in mysql_unlock_tables (thd=0x14e5d8000db8, sql_lock=0x14e5d831ded8, free_lock=<optimized out>) at /test/10.6_dbg/sql/lock.cc:432
 
#6  0x000055ceedc96e46 in mysql_unlock_tables (thd=thd@entry=0x14e5d8000db8, sql_lock=<optimized out>) at /test/10.6_dbg/sql/lock.cc:415
 
#7  0x000055ceed7a9e2d in close_thread_tables (thd=thd@entry=0x14e5d8000db8) at /test/10.6_dbg/sql/sql_base.cc:913
 
#8  0x000055ceed7ab32a in Locked_tables_list::unlock_locked_tables (this=this@entry=0x14e5d8004f58, thd=thd@entry=0x14e5d8000db8) at /test/10.6_dbg/sql/sql_base.cc:2378
 
#9  0x000055ceed9bbb3d in trans_begin (thd=thd@entry=0x14e5d8000db8, flags=0) at /test/10.6_dbg/sql/transaction.cc:115
 
#10 0x000055ceed8471df in mysql_execute_command (thd=thd@entry=0x14e5d8000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.6_dbg/sql/sql_parse.cc:5599
 
#11 0x000055ceed82edec in mysql_parse (thd=thd@entry=0x14e5d8000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14e69c481400) at /test/10.6_dbg/sql/sql_parse.cc:8030
 
#12 0x000055ceed83dab1 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14e5d8000db8, packet=packet@entry=0x14e5d800b889 "start transaction;", packet_length=packet_length@entry=18, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1358
 
#13 0x000055ceed840eeb in do_command (thd=0x14e5d8000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1404
 
#14 0x000055ceed9a6018 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55cef152dbc8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1418
 
#15 0x000055ceed9a661d in handle_one_connection (arg=arg@entry=0x55cef152dbc8) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#16 0x000055ceede57e4e in pfs_spawn_thread (arg=0x55cef159e9e8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#17 0x000014e69dc3f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#18 0x000014e69d82d293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

The bestcase for this, thus far, is:

# mysqld options required for replay:  --init-file=/home/roel/mariadb-qa/spiderinit2.sql
 
;
 
SELECT DISTINCT CHARSET(CONVERT(`�b�P` USING ujis)) FROM `�s�S`;#ERROR: 0 - Table 'test.�s�S' doesn't exist;
 
create TABLE t0(a int primary key,b char(0),c char(0),d char(0),e char(0)) ENGINE=SPIDER;
 
select test.f0(0);
 
UPDATE mysql.innodb_index_stats SET stat_value = 0 WHERE table_name = 'test_ps_fetch' AND index_name = 'PRIMARY' AND stat_name = 'n_diff_pfx0';
 
SELECT SUM(a)FROM t0 GROUP BY b,a;
 
INSERT INTO InnoDB.t0(name,other)VALUES ('Sixth Name',0);
 
FLUSH TABLES t0 WITH READ LOCK;
 
INSERT INTO t VALUES(0,0,'rBuyZqkEgGkVTPLBWvqkrYT0NrHbk0OU0eGj','j0ps0rhfB0FKvvPsT0TZ0pFO','ui0WfrUDPVVPr0QeRelZl','OzHE0LguyCqvSP0ph','Di','Y',0);
 
start transaction;

But the same can likely be reduced much further. The issue is that the testcase generally crashes on the stack in the OP. C based client may be required.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-01-20 ]

The bug still reproduces on 10.5 HEAD, which includes the fix for MDEV-27240.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-01-20 ]

The following without WORK keyword is enough for the crash:

INSTALL PLUGIN spider SONAME 'ha_spider.so';
 
CREATE TABLE t0 (s0 INT) ENGINE=SPIDER;
 
FLUSH TABLE t0 WITH READ LOCK;
 
BEGIN;

Comment by Nayuta Yanagisawa (Inactive) [ 2022-01-20 ]

On 6646591, which is just before the patch for MDEV-19002, thd->transaction->stmt.ha_list == NULL holds.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-01-20 ]

thd->transaction->stmt.ha_list is set in spider_internal_start_trx(), which is not called on the OK commit (because !conns[roop_count]->join_trx == false).

(rr) watch -l thd->transaction->stmt.ha_list                                                                                                                              
Hardware watchpoint 1: -location thd->transaction->stmt.ha_list                                                                                                           
(rr) rc                                                                              
Continuing.                                                                                                                                                         
                                                                                                                                                                          
Thread 2 hit Hardware watchpoint 1: -location thd->transaction->stmt.ha_list                                                                                              
                                                                                                                                                                          
Old value = (Ha_trx_info *) 0x7f8318004d98                                                                                                                                
New value = (Ha_trx_info *) 0x0                                                      
                                                                       
0x0000564b08a2d2f5 in Ha_trx_info::register_ha (this=0x7f8318004d98, trans=0x7f8318005b40, ht_arg=0x7f8318034a78)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/handler.h:1961                                                                                                   
1961        trans->ha_list= this;                                                    
(rr) bt                                                                              
#0  0x0000564b08a2d2f5 in Ha_trx_info::register_ha (this=0x7f8318004d98, trans=0x7f8318005b40, ht_arg=0x7f8318034a78)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/handler.h:1961                                                                                                   
#1  0x0000564b08a14c38 in trans_register_ha (thd=0x7f83180023b8, all=false, ht_arg=0x7f8318034a78, trxid=0)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/handler.cc:1323
 
#2  0x00007f830fb0095e in spider_internal_start_trx (spider=0x7f83180e7ac0) at /home/nayuta_mariadb/repo/mariadb-server/10.5/storage/spider/spd_trx.cc:2002
 
#3  0x00007f830fbb4f7d in ha_spider::external_lock (this=0x7f83180e7ac0, thd=0x7f83180023b8, lock_type=2)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/storage/spider/ha_spider.cc:1242
 
#4  0x0000564b08a266ae in handler::ha_external_lock (this=0x7f83180e7ac0, thd=0x7f83180023b8, lock_type=2)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/handler.cc:6697
 
#5  0x0000564b087b293c in handler::ha_external_unlock (this=0x7f83180e7ac0, thd=0x7f83180023b8) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/handler.h:3456
 
#6  0x0000564b08b6f9d9 in unlock_external (thd=0x7f83180023b8, table=0x7f8318156038, count=1) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/lock.cc:727
 
#7  0x0000564b08b6ecf6 in mysql_unlock_tables (thd=0x7f83180023b8, sql_lock=0x7f8318156008, free_lock=true)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/lock.cc:432
 
#8  0x0000564b08b6ec43 in mysql_unlock_tables (thd=0x7f83180023b8, sql_lock=0x7f8318156008) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/lock.cc:415
 
#9  0x0000564b085efa4c in close_thread_tables (thd=0x7f83180023b8) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_base.cc:911
 
#10 0x0000564b085f30be in Locked_tables_list::unlock_locked_tables (this=0x7f8318006398, thd=0x7f83180023b8)
 
    at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_base.cc:2376
 
#11 0x0000564b08866779 in trans_begin (thd=0x7f83180023b8, flags=0) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/transaction.cc:115
 
#12 0x0000564b086a741f in mysql_execute_command (thd=0x7f83180023b8) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_parse.cc:5658
 
#13 0x0000564b086aee0b in mysql_parse (thd=0x7f83180023b8, rawbuf=0x7f83180155c0 "BEGIN", length=5, parser_state=0x7f830fffe3f0, is_com_multi=false, 
    is_next_command=false) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_parse.cc:8100
 
#14 0x0000564b0869ad8b in dispatch_command (command=COM_QUERY, thd=0x7f83180023b8, packet=0x7f831800ccd9 "BEGIN", packet_length=5, is_com_multi=false, 
    is_next_command=false) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_parse.cc:1891
 
#15 0x0000564b08699583 in do_command (thd=0x7f83180023b8) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_parse.cc:1370
 
#16 0x0000564b0884b583 in do_handle_one_connection (connect=0x564b0cb5d358, put_in_cache=true) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_connect.cc:1418
 
#17 0x0000564b0884b239 in handle_one_connection (arg=0x564b0cb5d358) at /home/nayuta_mariadb/repo/mariadb-server/10.5/sql/sql_connect.cc:1312
 
#18 0x0000564b08d7290e in pfs_spawn_thread (arg=0x564b0cb378b8) at /home/nayuta_mariadb/repo/mariadb-server/10.5/storage/perfschema/pfs.cc:2201
 
#19 0x00007f83384ad450 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
 
#20 0x00007f8338046d53 in clone () from /lib/x86_64-linux-gnu/libc.so.6

Comment by Nayuta Yanagisawa (Inactive) [ 2022-01-20 ]

holyfoot Please review: https://github.com/MariaDB/server/commit/2ada51ccd0d4368eea7d173163c36e2792990a10

The bug is also due to e954d9de. The patch is large but I think you could see the check (I mentioned in the commit message) is actually removed.

Comment by Alexey Botchkov [ 2022-04-02 ]

see email for comments.

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

Fixed along with the review comment. I also did some refactoring on ha_spider::external_lock().
https://github.com/MariaDB/server/commit/96dbcea0faf5bf82ee22a5c63f96ac81d625fad8

Comment by Alexey Botchkov [ 2022-04-08 ]

ok to push.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-04-15 ]

ASAN build failed on the test added by the present issue: https://buildbot.askmonty.org/buildbot/builders/kvm-asan/builds/7972/steps/mtr_nm/logs/stdio

Comment by Nayuta Yanagisawa (Inactive) [ 2022-04-15 ]

I disabled the test temporarily.

heap-use-after-free seems not to be due to my refactoring. The server too fails on 2ada51ccd0d4368eea7d173163c36e2792990a10.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-04-19 ] 

=================================================================
 
==153765==ERROR: AddressSanitizer: heap-use-after-free on address 0x61f0000541ec at pc 0x7f218e572770 bp 0x7f218ec926b0 sp 0x7f218ec926a0
 
READ of size 4 at 0x61f0000541ec thread T16
 
    #0 0x7f218e57276f in ha_spider::lock_tables() /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/ha_spider.cc:16309
 
    #1 0x7f218e4d6a3b in ha_spider::external_lock(THD*, int) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/ha_spider.cc:1286
 
    #2 0x55d928ec682c in handler::ha_external_lock(THD*, int) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/handler.cc:6718
 
    #3 0x55d92892ebe1 in handler::ha_external_unlock(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/handler.h:3392
 
    #4 0x55d9291dd20b in unlock_external /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/lock.cc:727
 
    #5 0x55d9291da8ec in mysql_unlock_tables(THD*, st_mysql_lock*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/lock.cc:432
 
    #6 0x55d9291da70f in mysql_unlock_tables(THD*, st_mysql_lock*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/lock.cc:415
 
    #7 0x55d9284b5694 in close_thread_tables(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.cc:911
 
    #8 0x55d9284be26f in Locked_tables_list::unlock_locked_tables(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.cc:2376
 
    #9 0x55d928aebf43 in trans_begin(THD*, unsigned int) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/transaction.cc:115
 
    #10 0x55d928672e8d in mysql_execute_command(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:5674
 
    #11 0x55d928683719 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:8116
 
    #12 0x55d928658e7f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:1907
 
    #13 0x55d928655583 in do_command(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:1375
 
    #14 0x55d928aaaf38 in do_handle_one_connection(CONNECT*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_connect.cc:1418
 
    #15 0x55d928aaa76f in handle_one_connection /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_connect.cc:1312
 
    #16 0x55d92973bbba in pfs_spawn_thread /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/perfschema/pfs.cc:2201
 
    #17 0x7f219d563946  (/lib/x86_64-linux-gnu/libc.so.6+0x94946)
 
    #18 0x7f219d5f3a43 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x124a43)
 
 
 
0x61f0000541ec is located 364 bytes inside of 3120-byte region [0x61f000054080,0x61f000054cb0)
 
freed by thread T16 here:
 
    #0 0x7f219e090517 in __interceptor_free ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:127
 
    #1 0x55d92a3ef560 in my_free /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/mysys/my_malloc.c:211
 
    #2 0x7f218e4a50c7 in spider_free_mem(st_spider_transaction*, void*, unsigned long) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_malloc.cc:188
 
    #3 0x7f218e3bfa38 in spider_free_conn(st_spider_conn*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_conn.cc:1404
 
    #4 0x7f218e3b80ab in spider_free_conn_from_trx(st_spider_transaction*, st_spider_conn*, bool, bool, int*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_conn.cc:420
 
    #5 0x7f218e2ee987 in spider_free_trx_conn(st_spider_transaction*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_trx.cc:117
 
    #6 0x7f218e30c0b8 in spider_commit(handlerton*, THD*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_trx.cc:3486
 
    #7 0x55d928e9bc95 in commit_one_phase_2 /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/handler.cc:1971
 
    #8 0x55d928e9b9a3 in ha_commit_one_phase(THD*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/handler.cc:1950
 
    #9 0x55d928e99c6a in ha_commit_trans(THD*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/handler.cc:1744
 
    #10 0x55d928aeed06 in trans_commit_stmt(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/transaction.cc:472
 
    #11 0x55d92867650e in mysql_execute_command(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:6132
 
    #12 0x55d928683719 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:8116
 
    #13 0x55d928658e7f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:1907
 
    #14 0x55d928655583 in do_command(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:1375
 
    #15 0x55d928aaaf38 in do_handle_one_connection(CONNECT*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_connect.cc:1418
 
    #16 0x55d928aaa76f in handle_one_connection /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_connect.cc:1312
 
    #17 0x55d92973bbba in pfs_spawn_thread /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/perfschema/pfs.cc:2201
 
    #18 0x7f219d563946  (/lib/x86_64-linux-gnu/libc.so.6+0x94946)
 
 
 
previously allocated by thread T16 here:
 
    #0 0x7f219e090867 in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:145
 
    #1 0x55d92a3ee6d9 in my_malloc /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/mysys/my_malloc.c:90
 
    #2 0x7f218e4a5833 in spider_bulk_alloc_mem(st_spider_transaction*, unsigned int, char const*, char const*, unsigned long, unsigned long, ...) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_malloc.cc:236
 
    #3 0x7f218e3b9162 in spider_create_conn(st_spider_share*, ha_spider*, int, int, unsigned int, int*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_conn.cc:593
 
    #4 0x7f218e3be84b in spider_get_conn(st_spider_share*, int, char*, st_spider_transaction*, ha_spider*, bool, bool, unsigned int, int*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_conn.cc:1218
 
    #5 0x7f218e432d07 in spider_get_share(char const*, TABLE*, THD*, ha_spider*, int*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/spd_table.cc:5356
 
    #6 0x7f218e4cd66b in ha_spider::open(char const*, int, unsigned int) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/ha_spider.cc:444
 
    #7 0x55d928ea3f66 in handler::ha_open(TABLE*, char const*, int, unsigned int, st_mem_root*, List<String>*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/handler.cc:3013
 
    #8 0x55d9289c64b1 in open_table_from_share(THD*, TABLE_SHARE*, st_mysql_const_lex_string const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, List<String>*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/table.cc:4252
 
    #9 0x55d9284bb4e8 in open_table(THD*, TABLE_LIST*, Open_table_context*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.cc:2001
 
    #10 0x55d9284c51dc in open_and_process_table /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.cc:3788
 
    #11 0x55d9284c7e29 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.cc:4271
 
    #12 0x55d9284cd177 in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.cc:5218
 
    #13 0x55d928b46ea7 in open_and_lock_tables /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_base.h:276
 
    #14 0x55d928b493cb in flush_tables_with_read_lock(THD*, TABLE_LIST*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_reload.cc:584
 
    #15 0x55d928671a2c in mysql_execute_command(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:5481
 
    #16 0x55d928683719 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:8116
 
    #17 0x55d928658e7f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:1907
 
    #18 0x55d928655583 in do_command(THD*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_parse.cc:1375
 
    #19 0x55d928aaaf38 in do_handle_one_connection(CONNECT*, bool) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_connect.cc:1418
 
    #20 0x55d928aaa76f in handle_one_connection /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/sql_connect.cc:1312
 
    #21 0x55d92973bbba in pfs_spawn_thread /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/perfschema/pfs.cc:2201
 
    #22 0x7f219d563946  (/lib/x86_64-linux-gnu/libc.so.6+0x94946)
 
 
 
Thread T16 created by T0 here:
 
    #0 0x7f219e034685 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:216
 
    #1 0x55d929737644 in my_thread_create /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/perfschema/my_thread.h:52
 
    #2 0x55d92973bfad in pfs_spawn_thread_v1 /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/perfschema/pfs.cc:2252
 
    #3 0x55d92833c702 in inline_mysql_thread_create /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/include/mysql/psi/mysql_thread.h:1323
 
    #4 0x55d928352f90 in create_thread_to_handle_connection(CONNECT*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/mysqld.cc:6018
 
    #5 0x55d928353626 in create_new_thread(CONNECT*) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/mysqld.cc:6077
 
    #6 0x55d928353989 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/mysqld.cc:6142
 
    #7 0x55d9283545d4 in handle_connections_sockets() /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/mysqld.cc:6269
 
    #8 0x55d928352764 in mysqld_main(int, char**) /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/mysqld.cc:5664
 
    #9 0x55d92833b1cc in main /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/sql/main.cc:25
 
    #10 0x7f219d4f8fcf  (/lib/x86_64-linux-gnu/libc.so.6+0x29fcf)
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /home/nayuta_mariadb/repo/mariadb-server/bb-10.5-MDEV-27239/storage/spider/ha_spider.cc:16309 in ha_spider::lock_tables()
 
Shadow bytes around the buggy address:
 
  0x0c3e800027e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3e800027f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3e80002800: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3e80002810: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3e80002820: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c3e80002830: fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd fd
 
  0x0c3e80002840: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3e80002850: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3e80002860: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3e80002870: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3e80002880: 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
 
==153765==ABORTING
 
----------SERVER LOG END-------------

Comment by Nayuta Yanagisawa (Inactive) [ 2022-04-19 ]

ASAN build doesn't fail on 8e6e5ace.

Further, even if I cherry-picked the fix, db1a7cf, on the first bad commit, e954d9d, the ASAN build doesn't fail with the test case. So, use-after-free is introduced between e954d9d and 10.5 HEAD.

Comment by Nayuta Yanagisawa (Inactive) [ 2022-04-20 ]

The ASAN build failure seems to be a different bug and is handled by MDEV-28352.

Comment by Roel Van de Paar [ 2022-11-07 ]

Also see MDEV-29962

Generated at Thu Feb 08 09:51:25 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.