[MDEV-21045] AddressSanitizer: use-after-poison in mem_heap_dup / row_log_table_get_pk_col Created: 2019-11-13  Updated: 2019-11-21  Resolved: 2019-11-21

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Storage Engine - InnoDB
Affects Version/s: 10.3, 10.4
Fix Version/s: 10.3.21, 10.4.11

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Eugene Kosov (Inactive)
Resolution: Fixed Votes: 0
Labels: None


 Description   

Note: The test case is very non-deterministic, run with big --repeat (thousands). Usually it fails for me within 20-80 attempts, but sometimes on no apparent reasons it takes hundreds. It seems to be happening somewhat more readily on disk, as opposed to in memory, but it can be a false observation.

--source include/have_innodb.inc
 
 
 
--connect (con1,localhost,root,,test)
 
--connect (con2,localhost,root,,test)
 
 
 
CREATE TABLE t1 (a TEXT) ENGINE = InnoDB ROW_FORMAT=REDUNDANT;
 
INSERT INTO t1 (a) VALUES ('foo');
 
 
 
--connection con1
 
ALTER TABLE t1 ADD COLUMN b INT;
 
 
 
--connection con2
 
--send
 
    ALTER TABLE t1 ADD PRIMARY KEY (b);
 
 
 
--connection con1
 
UPDATE t1 SET b = 1;
 
 
 
--connection default
 
DROP TABLE t1;

10.3 ASAN 5098d708

 
==6319==ERROR: AddressSanitizer: use-after-poison on address 0x7fd49f65c000 at pc 0x7fd4aa7a1f7f bp 0x7fd492d6b920 sp 0x7fd492d6b0d0
 
READ of size 4294967294 at 0x7fd49f65c000 thread T27
 
    #0 0x7fd4aa7a1f7e  (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x5cf7e)
 
    #1 0x55f3594bed20 in mem_heap_dup(mem_block_info_t*, void const*, unsigned long) /data/src/10.3/storage/innobase/include/mem0mem.h:242
 
    #2 0x55f359788418 in row_log_table_get_pk_col /data/src/10.3/storage/innobase/row/row0log.cc:1204
 
    #3 0x55f359789430 in row_log_table_get_pk(unsigned char const*, dict_index_t*, unsigned long const*, unsigned char*, mem_block_info_t**) /data/src/10.3/storage/innobase/row/row0log.cc:1341
 
    #4 0x55f359826da9 in row_upd_clust_rec /data/src/10.3/storage/innobase/row/row0upd.cc:2861
 
    #5 0x55f359828c79 in row_upd_clust_step /data/src/10.3/storage/innobase/row/row0upd.cc:3206
 
    #6 0x55f359829716 in row_upd /data/src/10.3/storage/innobase/row/row0upd.cc:3307
 
    #7 0x55f35982a503 in row_upd_step(que_thr_t*) /data/src/10.3/storage/innobase/row/row0upd.cc:3451
 
    #8 0x55f3597659f3 in row_update_for_mysql(row_prebuilt_t*) /data/src/10.3/storage/innobase/row/row0mysql.cc:1888
 
    #9 0x55f359484887 in ha_innobase::update_row(unsigned char const*, unsigned char const*) /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8849
 
    #10 0x55f358f6eba2 in handler::ha_update_row(unsigned char const*, unsigned char const*) /data/src/10.3/sql/handler.cc:6478
 
    #11 0x55f358abf7d1 in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /data/src/10.3/sql/sql_update.cc:954
 
    #12 0x55f35885508c in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4301
 
    #13 0x55f35886c1f8 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7815
 
    #14 0x55f358846f1e in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1856
 
    #15 0x55f358843dfd in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1401
 
    #16 0x55f358bb8d68 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
 
    #17 0x55f358bb872f in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
 
    #18 0x55f35a01b625 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
 
    #19 0x7fd4aa52f4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
 
    #20 0x7fd4a8a76d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
 
 
AddressSanitizer can not describe address in more detail (wild memory access suspected).
 
SUMMARY: AddressSanitizer: use-after-poison (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x5cf7e) 
Shadow bytes around the buggy address:
 
  0x0ffb13ec37b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0ffb13ec37c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0ffb13ec37d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0ffb13ec37e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0ffb13ec37f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
=>0x0ffb13ec3800:[f7]f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0ffb13ec3810: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0ffb13ec3820: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0ffb13ec3830: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0ffb13ec3840: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0ffb13ec3850: 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
 
  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
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
Thread T27 created by T0 here:
 
    #0 0x7fd4aa775f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
 
    #1 0x55f35a01ba61 in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1912
 
    #2 0x55f3585b2be0 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1268
 
    #3 0x55f3585c7eec in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6600
 
    #4 0x55f3585c85cf in create_new_thread /data/src/10.3/sql/mysqld.cc:6670
 
    #5 0x55f3585c95e7 in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6945
 
    #6 0x55f3585c73bc in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6222
 
    #7 0x55f3585b12ff in main /data/src/10.3/sql/main.cc:25
 
    #8 0x7fd4a89ae2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
 
 
 
==6319==ABORTING

Reproducible on 10.3-10.5.
Couldn't reproduce on 10.2.

 Comments   
Comment by Marko Mäkelä [ 2019-11-13 ]

I can repeat this, although not ver easily:

10.3 5098d708a07f90484c9e13fe3ab58113a8a10191

 
mysqltest: At line 14: query 'UPDATE t1 SET b = 1' failed: 2013: Lost connection to MySQL server during query
 
 
 
The result from queries just before the failure was:
 
connect  con1,localhost,root,,test;
 
connect  con2,localhost,root,,test;
 
CREATE TABLE t1 (a TEXT) ENGINE = InnoDB ROW_FORMAT=REDUNDANT;
 
INSERT INTO t1 (a) VALUES ('foo');
 
connection con1;
 
ALTER TABLE t1 ADD COLUMN b INT;
 
connection con2;
 
ALTER TABLE t1 ADD PRIMARY KEY (b);
 
connection con1;
 
UPDATE t1 SET b = 1;
 
 
 
 
 
Server [mysqld.1 - pid: 2326273, winpid: 2326273, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
=================================================================
 
==2326282==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x7f1b87740000 at pc 0x000000661b2a bp 0x7f1b7abaa730 sp 0x7f1b7aba9ef8
 
READ of size 4294967294 at 0x7f1b87740000 thread T27
 
    #0 0x661b29 in __asan_memcpy (/dev/shm/10.3/sql/mysqld+0x661b29)
 
    #1 0x1aa0c29 in mem_heap_dup(mem_block_info_t*, void const*, unsigned long) /mariadb/10.3/storage/innobase/include/mem0mem.h:242:5
 
    #2 0x1aa0c29 in row_log_table_get_pk_col(dict_field_t const*, dfield_t*, mem_block_info_t*, unsigned char const*, unsigned long const*, unsigned long, page_size_t const&, unsigned long, row_log_t const*) /mariadb/10.3/storage/innobase/row/row0log.cc:1204:27
 
    #3 0x1aa0c29 in row_log_table_get_pk(unsigned char const*, dict_index_t*, unsigned long const*, unsigned char*, mem_block_info_t**) /mariadb/10.3/storage/innobase/row/row0log.cc:1341:18
 
    #4 0x1b850f6 in row_upd_clust_rec(unsigned long, upd_node_t*, dict_index_t*, unsigned long*, mem_block_info_t**, que_thr_t*, mtr_t*) /mariadb/10.3/storage/innobase/row/row0upd.cc:2860:20
 
    #5 0x1b8163d in row_upd_clust_step(upd_node_t*, que_thr_t*) /mariadb/10.3/storage/innobase/row/row0upd.cc:3206:9
 
    #6 0x1b79e95 in row_upd(upd_node_t*, que_thr_t*) /mariadb/10.3/storage/innobase/row/row0upd.cc:3307:9
 
    #7 0x1b79e95 in row_upd_step(que_thr_t*) /mariadb/10.3/storage/innobase/row/row0upd.cc:3451:8
 
    #8 0x1a7e1b7 in row_update_for_mysql(row_prebuilt_t*) /mariadb/10.3/storage/innobase/row/row0mysql.cc:1888:3
 
    #9 0x171d7f5 in ha_innobase::update_row(unsigned char const*, unsigned char const*) /mariadb/10.3/storage/innobase/handler/ha_innodb.cc:8849:11
 
    #10 0x10d5f68 in handler::ha_update_row(unsigned char const*, unsigned char const*) /mariadb/10.3/sql/handler.cc:6478:3
 
    #11 0xc1d89c in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /mariadb/10.3/sql/sql_update.cc:954:31
 
    #12 0x987ec2 in mysql_execute_command(THD*) /mariadb/10.3/sql/sql_parse.cc:4294:21
 
    #13 0x973f8f in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /mariadb/10.3/sql/sql_parse.cc:7815:18
 
    #14 0x966b2d in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /mariadb/10.3/sql/sql_parse.cc:1855:7
 
    #15 0x96e4e7 in do_command(THD*) /mariadb/10.3/sql/sql_parse.cc:1401:17
 
    #16 0xd18973 in do_handle_one_connection(CONNECT*) /mariadb/10.3/sql/sql_connect.cc:1403:11
 
    #17 0xd181b3 in handle_one_connection /mariadb/10.3/sql/sql_connect.cc:1308:3
 
    #18 0x2472d35 in pfs_spawn_thread /mariadb/10.3/storage/perfschema/pfs.cc:1862:3
 
    #19 0x7f1b91ec0fb6 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x8fb6)
 
    #20 0x7f1b913252ce in clone (/lib/x86_64-linux-gnu/libc.so.6+0xfa2ce)
 
 
 
0x7f1b87740000 is located 6144 bytes to the left of 406136-byte region [0x7f1b87741800,0x7f1b877a4a78)
 
allocated by thread T0 here:
 
    #0 0x6626ed in malloc (/dev/shm/10.3/sql/mysqld+0x6626ed)
 
    #1 0x1fdfe5c in hash0_create(unsigned long) /mariadb/10.3/storage/innobase/ha/hash0hash.cc:110:3
 
…
 
#5  0x00000000006801a7 in __sanitizer::Abort() ()
 
#6  0x000000000067eb81 in __sanitizer::Die() ()
 
#7  0x0000000000666709 in __asan::ScopedInErrorReport::~ScopedInErrorReport() ()
 
#8  0x0000000000667e7f in __asan::ReportGenericError(unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long, unsigned int, bool) ()
 
#9  0x0000000000661b49 in __asan_memcpy ()
 
#10 0x0000000001aa0c2a in mem_heap_dup (heap=<optimized out>, data=0x7f1b8745409d, len=4294967294) at /mariadb/10.3/storage/innobase/include/mem0mem.h:242
 
#11 row_log_table_get_pk_col (ifield=<optimized out>, dfield=<optimized out>, heap=0x612000084c40, rec=0x7f1b87454087 "", offsets=<optimized out>, i=<optimized out>, page_size=..., log=<optimized out>, max_len=<optimized out>) at /mariadb/10.3/storage/innobase/row/row0log.cc:1204
 
#12 row_log_table_get_pk (rec=<optimized out>, index=<optimized out>, offsets=<optimized out>, sys=<optimized out>, heap=<optimized out>) at /mariadb/10.3/storage/innobase/row/row0log.cc:1341
 
#13 0x0000000001b850f7 in row_upd_clust_rec (flags=<optimized out>, node=<optimized out>, index=<optimized out>, offsets=0x0, offsets_heap=<optimized out>, thr=<optimized out>, mtr=<optimized out>) at /mariadb/10.3/storage/innobase/row/row0upd.cc:2860
 
#14 0x0000000001b8163e in row_upd_clust_step (node=<optimized out>, thr=<optimized out>) at /mariadb/10.3/storage/innobase/row/row0upd.cc:3206
 
#15 0x0000000001b79e96 in row_upd (node=<optimized out>, thr=0x620000012c28) at /mariadb/10.3/storage/innobase/row/row0upd.cc:3307
 
#16 row_upd_step (thr=<optimized out>) at /mariadb/10.3/storage/innobase/row/row0upd.cc:3451
 
#17 0x0000000001a7e1b8 in row_update_for_mysql (prebuilt=0x620000012110) at /mariadb/10.3/storage/innobase/row/row0mysql.cc:1888
 
#18 0x000000000171d7f6 in ha_innobase::update_row (this=0x61c0000730a8, old_row=<optimized out>, new_row=<optimized out>) at /mariadb/10.3/storage/innobase/handler/ha_innodb.cc:8849
 
#19 0x00000000010d5f69 in handler::ha_update_row (this=0x61c0000730a8, old_data=<optimized out>, new_data=<optimized out>) at /mariadb/10.3/sql/handler.cc:6478
 
#20 0x0000000000c1d89d in mysql_update (thd=<optimized out>, table_list=<optimized out>, fields=..., values=..., conds=<optimized out>, order_num=<optimized out>, order=0x62b000000fe0, limit=18446744073709551615, ignore=<optimized out>, found_return=<optimized out>, updated_return=<optimized out>) at /mariadb/10.3/sql/sql_update.cc:954
 
#21 0x0000000000987ec3 in mysql_execute_command (thd=0x62a0000ba208) at /mariadb/10.3/sql/sql_parse.cc:4294

I cannot immediately recognize any wrongdoing. row_upd_clust_rec() should be passing a pointer to NULL, and row_log_table_get_pk() should have assigned *heap = mem_heap_create(…);. I do not see any call to mem_heap_free() in between.

kevg, could we have some bug in our use of ASAN_POISON_MEMORY_REGION or MEM_NOACCESS or TRASH_FREE or UNIV_MEM_FREE?

Comment by Eugene Kosov (Inactive) [ 2019-11-14 ]

I can repeat it too. Here is another one bug variation:

==8346==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x7f5a323f9000 at pc 0x0000010b5c3a bp 0x7f5a25622bb0 sp 0x7f5a25622378
 
READ of size 4294967294 at 0x7f5a323f9000 thread T28
 
    #0 0x10b5c39 in __asan_memcpy (/home/kevg/work/m/bb-10.3-kevgs/build_asan/sql/mysqld+0x10b5c39)
 
    #1 0x276fb2f in mem_heap_dup(mem_block_info_t*, void const*, unsigned long) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/include/mem0mem.h:242:5
 
    #2 0x2feb693 in row_log_table_get_pk_col(dict_field_t const*, dfield_t*, mem_block_info_t*, unsigned char const*, unsigned long const*, unsigned long, page_size_t const&, unsigned long, row_log_t const*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0log.cc:1204:27
 
    #3 0x2fe5115 in row_log_table_get_pk(unsigned char const*, dict_index_t*, unsigned long const*, unsigned char*, mem_block_info_t**) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0log.cc:1341:18
 
    #4 0x30f79dc in row_upd_clust_rec(unsigned long, upd_node_t*, dict_index_t*, unsigned long*, mem_block_info_t**, que_thr_t*, mtr_t*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0upd.cc:2860:20
 
    #5 0x30f408b in row_upd_clust_step(upd_node_t*, que_thr_t*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0upd.cc:3206:9
 
    #6 0x30ec760 in row_upd(upd_node_t*, que_thr_t*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0upd.cc:3307:9
 
    #7 0x30eb97a in row_upd_step(que_thr_t*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0upd.cc:3451:8
 
    #8 0x2fb663c in row_update_for_mysql(row_prebuilt_t*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/row/row0mysql.cc:1888:3
 
    #9 0x26e9ac9 in ha_innobase::update_row(unsigned char const*, unsigned char const*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/handler/ha_innodb.cc:8849:11
 
    #10 0x11e3195 in handler::ha_update_row(unsigned char const*, unsigned char const*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/handler.cc:6478:3
 
    #11 0x2035fe5 in mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_update.cc:954:31
 
    #12 0x1c2d9de in mysql_execute_command(THD*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_parse.cc:4294:21
 
    #13 0x1c1966c in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_parse.cc:7815:18
 
    #14 0x1c0a131 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_parse.cc:1855:7
 
    #15 0x1c1350c in do_command(THD*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_parse.cc:1401:17
 
    #16 0x21edd39 in do_handle_one_connection(CONNECT*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_connect.cc:1403:11
 
    #17 0x21ed3e3 in handle_one_connection /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_connect.cc:1308:3
 
    #18 0x37ffa11 in pfs_spawn_thread /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/perfschema/pfs.cc:1862:3
 
    #19 0x7f5a3cb8e668 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x9668)
 
    #20 0x7f5a3c057322 in clone /build/glibc-4WA41p/glibc-2.30/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
 
 
0x7f5a323f9000 is located 6144 bytes to the left of 406136-byte region [0x7f5a323fa800,0x7f5a3245da78)
 
allocated by thread T0 here:
 
    #0 0x10b67fd in malloc (/home/kevg/work/m/bb-10.3-kevgs/build_asan/sql/mysqld+0x10b67fd)
 
    #1 0x27e3f19 in hash0_create(unsigned long) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/ha/hash0hash.cc:110:3
 
    #2 0x27a6c76 in fil_system_t::create(unsigned long) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/fil/fil0fil.cc:1701:11
 
    #3 0x3139b34 in srv_start(bool) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/srv/srv0start.cc:1576:13
 
    #4 0x272dafd in innodb_init(void*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/innobase/handler/ha_innodb.cc:4261:8
 
    #5 0x11a2f0a in ha_initialize_handlerton(st_plugin_int*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/handler.cc:549:31
 
    #6 0x1cc8582 in plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_plugin.cc:1433:9
 
    #7 0x1cc71b4 in plugin_init(int*, char**, int) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/sql_plugin.cc:1715:15
 
    #8 0x10fb3db in init_server_components() /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/mysqld.cc:5416:7
 
    #9 0x10f4b03 in mysqld_main(int, char**) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/mysqld.cc:6023:7
 
    #10 0x10e8f11 in main /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/main.cc:25:10
 
    #11 0x7f5a3bf5c1e2 in __libc_start_main /build/glibc-4WA41p/glibc-2.30/csu/../csu/libc-start.c:308:16
 
 
 
Thread T28 created by T0 here:
 
    #0 0x10a0e7a in pthread_create (/home/kevg/work/m/bb-10.3-kevgs/build_asan/sql/mysqld+0x10a0e7a)
 
    #1 0x3805e99 in spawn_thread_v1(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../storage/perfschema/pfs.cc:1912:15
 
    #2 0x10f1e6a in inline_mysql_thread_create(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../include/mysql/psi/mysql_thread.h:1268:11
 
    #3 0x11027ff in create_thread_to_handle_connection(CONNECT*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/mysqld.cc:6600:15
 
    #4 0x1104ade in create_new_thread(CONNECT*) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/mysqld.cc:6670:3
 
    #5 0x1101fbe in handle_connections_sockets() /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/mysqld.cc:6945:5
 
    #6 0x10f5803 in mysqld_main(int, char**) /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/mysqld.cc:6222:3
 
    #7 0x10e8f11 in main /home/kevg/work/m/bb-10.3-kevgs/build_asan/../sql/main.cc:25:10
 
    #8 0x7f5a3bf5c1e2 in __libc_start_main /build/glibc-4WA41p/glibc-2.30/csu/../csu/libc-start.c:308:16
 
 
 
SUMMARY: AddressSanitizer: heap-buffer-overflow (/home/kevg/work/m/bb-10.3-kevgs/build_asan/sql/mysqld+0x10b5c39) in __asan_memcpy
 
Shadow bytes around the buggy address:
 
  0x0febc64771b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0febc64771c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0febc64771d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0febc64771e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0febc64771f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
=>0x0febc6477200:[fa]fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0febc6477210: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0febc6477220: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0febc6477230: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0febc6477240: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0febc6477250: 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
 
==8346==ABORTING
 
----------SERVER LOG END-------------

Comment by Eugene Kosov (Inactive) [ 2019-11-14 ]

I was also able to catch this without ASAN. So no, it's not our instrumentation failure.

#0  __pthread_kill (threadid=<optimized out>, signo=11) at pthread_kill.c:56
 
#1  0x00000000018f6ddb in my_write_core (sig=11) at stacktrace.c:481
 
#2  0x0000000000c136be in handle_fatal_signal (sig=11) at signal_handler.cc:343
 
#3  <signal handler called>
 
#4  __memmove_avx_unaligned_erms () at memmove-vec-unaligned-erms.S:384
 
#5  0x00000000011d347b in mem_heap_dup (heap=0x7fc2300b1120, data=0x7fc27f91409d, len=4294967294) at mem0mem.h:242
 
#6  0x00000000015a9f3d in row_log_table_get_pk_col (ifield=0x7fc22405f760, dfield=0x7fc2300b11f0, heap=0x7fc2300b1120, rec=0x7fc27f914087 "", offsets=0x7fc2840c7f50, i=4, page_size=..., max_len=767, log=0x7fc2240aebc0) at row0log.cc:1204
 
#7  0x00000000015a6fe2 in row_log_table_get_pk (rec=0x7fc27f914087 "", index=0x7fc22401a168, offsets=0x7fc2840c7f50, sys=0x0, heap=0x7fc2840c7d98) at row0log.cc:1341
 
#8  0x0000000001625f12 in row_upd_clust_rec (flags=0, node=0x7fc2300090b0, index=0x7fc22401a168, offsets=0x7fc2840c7f50, offsets_heap=0x7fc2840c8270, thr=0x7fc2300093b8, mtr=0x7fc2840c8280) at row0upd.cc:2860
 
#9  0x0000000001624701 in row_upd_clust_step (node=0x7fc2300090b0, thr=0x7fc2300093b8) at row0upd.cc:3206
 
#10 0x0000000001620523 in row_upd (node=0x7fc2300090b0, thr=0x7fc2300093b8) at row0upd.cc:3307
 
#11 0x0000000001620043 in row_upd_step (thr=0x7fc2300093b8) at row0upd.cc:3451
 
#12 0x0000000001591e2d in row_update_for_mysql (prebuilt=0x7fc2300088f8) at row0mysql.cc:1888
 
#13 0x00000000011a0a82 in ha_innobase::update_row (this=0x7fc2300272d0, old_row=0x7fc230019a58 "\376\003", new_row=0x7fc230019a48 "\374\003") at ha_innodb.cc:8849
 
#14 0x0000000000a4ce41 in handler::ha_update_row (this=0x7fc2300272d0, old_data=0x7fc230019a58 "\376\003", new_data=0x7fc230019a48 "\374\003") at handler.cc:6478
 
#15 0x0000000000f2e7dc in mysql_update (thd=0x7fc230000d28, table_list=0x7fc230010c68, fields=class List<Item> with 1 elements, values=class List<Item> with 1 elements, conds=0x0, order_num=0, order=0x0, limit=18446744073709551615, ignore=false, found_return=0x7fc2840cb178, updated_return=0x7fc2840cb170) at sql_update.cc:954
 
#16 0x0000000000de1448 in mysql_execute_command (thd=0x7fc230000d28) at sql_parse.cc:4294
 
#17 0x0000000000dd906a in mysql_parse (thd=0x7fc230000d28, rawbuf=0x7fc230010b90 "UPDATE t1 SET b = 1", length=19, parser_state=0x7fc2840cc548, is_com_multi=false, is_next_command=false) at sql_parse.cc:7815
 
#18 0x0000000000dd34d8 in dispatch_command (command=COM_QUERY, thd=0x7fc230000d28, packet=0x7fc2300678c9 "UPDATE t1 SET b = 1", packet_length=19, is_com_multi=false, is_next_command=false) at sql_parse.cc:1855
 
#19 0x0000000000dd715c in do_command (thd=0x7fc230000d28) at sql_parse.cc:1401
 
#20 0x0000000000fc2ae0 in do_handle_one_connection (connect=0x451da38) at sql_connect.cc:1403
 
#21 0x0000000000fc28aa in handle_one_connection (arg=0x451da38) at sql_connect.cc:1308
 
#22 0x0000000001844005 in pfs_spawn_thread (arg=0x4526378) at pfs.cc:1862
 
#23 0x00007fc28ae9c669 in start_thread (arg=<optimized out>) at pthread_create.c:479
 
#24 0x00007fc28a370323 in clone () at clone.S:95

Comment by Eugene Kosov (Inactive) [ 2019-11-14 ]

Reading field of a size 4294967294 which is UNIV_SQL_DEFAULT. ROW_FORMAT matters. And INSTANT ADD COLUMN too.

Comment by Thirunarayanan Balathandayuthapani [ 2019-11-20 ]

OK to push

Comment by Marko Mäkelä [ 2019-11-20 ]

Thank you, very simple fix. But, I think that the test case is lacking synchronization before the DEBUG_SYNC=RESET. OK to push after addressing that.

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