[MDEV-15458] Segfault in heap_scan() upon UPDATE after ADD SYSTEM VERSIONING Created: 2018-03-03  Updated: 2019-08-20  Resolved: 2019-08-20

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Data Manipulation - Update, Storage Engine - Memory, Versioned Tables
Affects Version/s: 10.3, 10.4
Fix Version/s: 10.2.27, 10.3.18, 10.4.8

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Relates
relates to MDEV-15380 Index for versioned table gets corrup... Closed

 Description   

Server crash or ASAN heap-buffer-overflow in heap_scan upon concurrent UPDATE and ALTER with XA and versioning

Note: I'm not sure it's genuinely related to versioning, but it's the only way I was able to reproduce it so far.

Note: Run with --repeat=N if it doesn't fail right away. N=5 has always been enough for me, but it can vary on different machines.

XA BEGIN 'xid';
 
 
 
--connect (con1,localhost,root,,test)
 
 
 
CREATE TABLE t1 (a INT) ENGINE=MEMORY;
 
INSERT INTO t1 VALUES (1),(2),(3),(4),(5),(6),(7),(8);
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
INSERT INTO t1 SELECT * FROM t1;
 
 
 
--send
 
  ALTER TABLE t1 ADD SYSTEM VERSIONING;
 
 
 
--connection default
 
 
 
--error ER_XAER_RMFAIL
 
ALTER TABLE t1 ORDER BY a;
 
 
 
UPDATE t1 SET a = 6;
 
 
 
--connection con1
 
--error 0,ER_LOCK_WAIT_TIMEOUT
 
--reap

10.3 13cd4cf436 ASAN build

 
==30594==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x63300016a21b at pc 0x55c495d15e48 bp 0x7eff56905620 sp 0x7eff56905618
 
READ of size 1 at 0x63300016a21b thread T5
 
    #0 0x55c495d15e47 in heap_scan /data/src/10.3/storage/heap/hp_scan.c:65
 
    #1 0x55c495d00b22 in ha_heap::rnd_next(unsigned char*) /data/src/10.3/storage/heap/ha_heap.cc:348
 
    #2 0x55c494d05e17 in handler::ha_rnd_next(unsigned char*) /data/src/10.3/sql/handler.cc:2765
 
    #3 0x55c4950b25b5 in rr_sequential(READ_RECORD*) /data/src/10.3/sql/records.cc:481
 
    #4 0x55c49448bf63 in READ_RECORD::read_record() /data/src/10.3/sql/records.h:73
 
    #5 0x55c494862b60 in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, enum_duplicates, bool, unsigned long long*, unsigned long long*) /data/src/10.3/sql/sql_update.cc:866
 
    #6 0x55c4945fbb19 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4579
 
    #7 0x55c494612532 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:8090
 
    #8 0x55c4945ec65a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1850
 
    #9 0x55c4945e96e2 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1395
 
    #10 0x55c49495ac76 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1402
 
    #11 0x55c49495a682 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #12 0x55c495479a7d in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
 
    #13 0x7eff62ee4493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #14 0x7eff612c293e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
 
 
0x63300016a21b is located 15 bytes to the right of 104972-byte region [0x633000150800,0x63300016a20c)
 
allocated by thread T6 here:
 
    #0 0x7eff6314e73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
 
    #1 0x55c495e29e68 in sf_malloc /data/src/10.3/mysys/safemalloc.c:118
 
    #2 0x55c495dfa7e5 in my_malloc /data/src/10.3/mysys/my_malloc.c:101
 
    #3 0x55c495d1a31f in hp_get_new_block /data/src/10.3/storage/heap/hp_block.c:81
 
    #4 0x55c495d186f3 in next_free_record_pos /data/src/10.3/storage/heap/hp_write.c:165
 
    #5 0x55c495d1726c in heap_write /data/src/10.3/storage/heap/hp_write.c:45
 
    #6 0x55c495cffb22 in ha_heap::write_row(unsigned char*) /data/src/10.3/storage/heap/ha_heap.cc:239
 
    #7 0x55c494d1f0cb in handler::ha_write_row(unsigned char*) /data/src/10.3/sql/handler.cc:6237
 
    #8 0x55c494824334 in copy_data_between_tables /data/src/10.3/sql/sql_table.cc:10446
 
    #9 0x55c494820722 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) /data/src/10.3/sql/sql_table.cc:9883
 
    #10 0x55c494969c3f in Sql_cmd_alter_table::execute(THD*) /data/src/10.3/sql/sql_alter.cc:497
 
    #11 0x55c494607634 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6283
 
    #12 0x55c494612532 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:8090
 
    #13 0x55c4945ec65a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1850
 
    #14 0x55c4945e96e2 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1395
 
    #15 0x55c49495ac76 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1402
 
    #16 0x55c49495a682 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #17 0x55c495479a7d in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
 
    #18 0x7eff62ee4493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
 
 
Thread T5 created by T0 here:
 
    #0 0x7eff6311dbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
 
    #1 0x55c49547a045 in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1912
 
    #2 0x55c494354c18 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1268
 
    #3 0x55c49436ada5 in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6572
 
    #4 0x55c49436b4aa in create_new_thread /data/src/10.3/sql/mysqld.cc:6642
 
    #5 0x55c49436c4c1 in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6917
 
    #6 0x55c49436a262 in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6194
 
    #7 0x55c494352c9f in main /data/src/10.3/sql/main.cc:25
 
    #8 0x7eff611fa2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
 
 
Thread T6 created by T0 here:
 
    #0 0x7eff6311dbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
 
    #1 0x55c49547a045 in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1912
 
    #2 0x55c494354c18 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1268
 
    #3 0x55c49436ada5 in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6572
 
    #4 0x55c49436b4aa in create_new_thread /data/src/10.3/sql/mysqld.cc:6642
 
    #5 0x55c49436c4c1 in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6917
 
    #6 0x55c49436a262 in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6194
 
    #7 0x55c494352c9f in main /data/src/10.3/sql/main.cc:25
 
    #8 0x7eff611fa2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
 
 
SUMMARY: AddressSanitizer: heap-buffer-overflow /data/src/10.3/storage/heap/hp_scan.c:65 heap_scan
 
Shadow bytes around the buggy address:
 
  0x0c66800253f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c6680025400: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c6680025410: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c6680025420: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c6680025430: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
=>0x0c6680025440: 00 04 fa[fa]fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c6680025450: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c6680025460: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c6680025470: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c6680025480: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c6680025490: 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
 
  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
 
==30594==ABORTING
 
----------SERVER LOG END-------------

10.3 13cd4cf436 non-ASAN

 
#3  <signal handler called>
 
#4  0x0000561da4f47316 in heap_scan (info=0x7f1bc0122b20, record=0x7f1bc006f600 '\245' <repeats 16 times>, "h4z\245\245\245\245\245\375\001") at /data/src/10.3/storage/heap/hp_scan.c:65
 
#5  0x0000561da4f41188 in ha_heap::rnd_next (this=0x7f1bc0122628, buf=0x7f1bc006f600 '\245' <repeats 16 times>, "h4z\245\245\245\245\245\375\001") at /data/src/10.3/storage/heap/ha_heap.cc:348
 
#6  0x0000561da47fbaa7 in handler::ha_rnd_next (this=0x7f1bc0122628, buf=0x7f1bc006f600 '\245' <repeats 16 times>, "h4z\245\245\245\245\245\375\001") at /data/src/10.3/sql/handler.cc:2765
 
#7  0x0000561da497cb3b in rr_sequential (info=0x7f1bdc0a4170) at /data/src/10.3/sql/records.cc:481
 
#8  0x0000561da446a63d in READ_RECORD::read_record (this=0x7f1bdc0a4170) at /data/src/10.3/sql/records.h:73
 
#9  0x0000561da45fe6f6 in mysql_update (thd=0x7f1bc0000b00, table_list=0x7f1bc0014db0, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551614, handle_duplicates=DUP_ERROR, ignore=false, found_return=0x7f1bdc0a46f0, updated_return=0x7f1bdc0a47b0) at /data/src/10.3/sql/sql_update.cc:866
 
#10 0x0000561da4505f8f in mysql_execute_command (thd=0x7f1bc0000b00) at /data/src/10.3/sql/sql_parse.cc:4579
 
#11 0x0000561da45113ab in mysql_parse (thd=0x7f1bc0000b00, rawbuf=0x7f1bc0014cd8 "UPDATE t1 SET a = 6", length=19, parser_state=0x7f1bdc0a55f0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:8090
 
#12 0x0000561da44fe571 in dispatch_command (command=COM_QUERY, thd=0x7f1bc0000b00, packet=0x7f1bc000b1e1 "UPDATE t1 SET a = 6", packet_length=19, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1850
 
#13 0x0000561da44fcf95 in do_command (thd=0x7f1bc0000b00) at /data/src/10.3/sql/sql_parse.cc:1395
 
#14 0x0000561da4664a1c in do_handle_one_connection (connect=0x561da85eaf70) at /data/src/10.3/sql/sql_connect.cc:1402
 
#15 0x0000561da46647a0 in handle_one_connection (arg=0x561da85eaf70) at /data/src/10.3/sql/sql_connect.cc:1308
 
#16 0x0000561da4af98e7 in pfs_spawn_thread (arg=0x561da852f620) at /data/src/10.3/storage/perfschema/pfs.cc:1862
 
#17 0x00007f1be31f5494 in start_thread (arg=0x7f1bdc0a6700) at pthread_create.c:333
 
#18 0x00007f1be15d393f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Both debug and non-debug builds crash.

 Comments   
Comment by Aleksey Midenkov [ 2018-12-17 ]

XA and concurrency doesn't matter. Reproducible with:

create or replace table t1 (a int) engine memory;
 
insert into t1 values (1),(2),(3),(4),(5),(6),(7),(8);
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
insert into t1 select * from t1;
 
 
 
alter table t1 add system versioning;
 
 
 
update t1 set a= 6;
 
drop table t1;

Comment by Aleksey Midenkov [ 2018-12-17 ]

Cause

Broken current record position after history row insert.

Similar to MDEV-15380.

Comment by Aleksey Midenkov [ 2018-12-18 ]

Analysis

Comment by Sergei Golubchik [ 2019-08-19 ]

now it fails for a different reason. And it looks like the "original fix" doesn't help, it only works by chance and will fail if you add more rows to the table. The problem seems to be here:

int heap_scan(register HP_INFO *info, uchar *record)
 
{
 
  HP_SHARE *share=info->s;
 
  ulong pos;
 
  DBUG_ENTER("heap_scan");
 
 
 
  pos= ++info->current_record;
 
  if (pos < info->next_block)
 
  {
 
    info->current_ptr+=share->block.recbuffer;
 
  }
 
  else
 
  {
 
    info->next_block+=share->block.records_in_block;
 
    if (info->next_block >= share->records+share->deleted)
 
    {
 
      info->next_block= share->records+share->deleted;
 
      if (pos >= info->next_block)
 
      {
 
	info->update= 0;
 
	DBUG_RETURN(my_errno= HA_ERR_END_OF_FILE);
 
      }
 
    }
 
    hp_find_record(info, pos);
 
  }

On the first invocation, info->next_block is 0. It's set to the number of records in block, but no more than the total number of records. The problem is that "total number of records" is increased later.

The original fix simply sets info->next_block to 0, so it's set to the "number of records in block", and that kind of works, as longs as there are only two blocks in the table.

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