[MDEV-24758] ASAN use-after-poison in ut_memcpy / page_cur_insert_rec_low Created: 2021-02-02  Updated: 2022-06-27  Resolved: 2021-04-26

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.3
Fix Version/s: 10.3.29

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: not-10.4, not-10.5

Issue Links:
Relates
relates to MDEV-23295 Assertion `fields[i].same(instant.fie... Closed
relates to MDEV-26577 InnoDB: Failing assertion: dict_tf2_i... Closed

 Description   

Setting to minor, because only 10.3 is affected, and besides the dynamic change of innodb_default_row_format is probably not a very common use case.

The same ASAN stack trace can be found in MDEV-24570, but otherwise there isn't much similarity: versions, test cases, error messages – all is different, so I doubt it's the same issue.

--source include/have_innodb.inc
 
set @row_format= @@innodb_default_row_format;
 
CREATE TABLE t1 (pk INT PRIMARY KEY) CHARACTER SET utf8 ENGINE=InnoDB;
INSERT INTO t1 VALUES (1);
SET GLOBAL innodb_default_row_format= REDUNDANT;
ALTER TABLE t1 ADD a CHAR(8) DEFAULT '';
 
# Cleanup
DROP TABLE t1;
SET GLOBAL innodb_default_row_format= @row_format;

10.3 bdae8bb6 ASAN

==2337522==ERROR: AddressSanitizer: use-after-poison on address 0x611000059aa8 at pc 0x7f6f850d7480 bp 0x7f6f6e14dd30 sp 0x7f6f6e14d4d8
READ of size 48 at 0x611000059aa8 thread T27
    #0 0x7f6f850d747f  (/lib/x86_64-linux-gnu/libasan.so.5+0x9b47f)
    #1 0x55ebc66664c4 in ut_memcpy /data/src/10.3/storage/innobase/include/ut0mem.ic:40
    #2 0x55ebc666a142 in rec_copy /data/src/10.3/storage/innobase/include/rem0rec.ic:1340
    #3 0x55ebc66746c8 in page_cur_insert_rec_low(unsigned char*, dict_index_t*, unsigned char const*, unsigned short*, mtr_t*) /data/src/10.3/storage/innobase/page/page0cur.cc:1365
    #4 0x55ebc69dd91e in page_cur_tuple_insert /data/src/10.3/storage/innobase/include/page0cur.ic:288
    #5 0x55ebc69f5664 in btr_cur_optimistic_insert(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /data/src/10.3/storage/innobase/btr/btr0cur.cc:3444
    #6 0x55ebc674a79e in row_ins_clust_index_entry_low(unsigned long, unsigned long, dict_index_t*, unsigned long, dtuple_t*, unsigned long, que_thr_t*) /data/src/10.3/storage/innobase/row/row0ins.cc:2764
    #7 0x55ebc64f4366 in innobase_add_instant_try /data/src/10.3/storage/innobase/handler/handler0alter.cc:4564
    #8 0x55ebc652bd4b in commit_try_norebuild(Alter_inplace_info*, ha_innobase_inplace_ctx*, TABLE*, TABLE const*, trx_t*, char const*) /data/src/10.3/storage/innobase/handler/handler0alter.cc:8974
    #9 0x55ebc651a7fc in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.3/storage/innobase/handler/handler0alter.cc:9646
    #10 0x55ebc5eeb291 in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.3/sql/handler.cc:4602
    #11 0x55ebc59aa226 in mysql_inplace_alter_table /data/src/10.3/sql/sql_table.cc:7735
    #12 0x55ebc59ba5f8 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:9980
    #13 0x55ebc5b2662c in Sql_cmd_alter_table::execute(THD*) /data/src/10.3/sql/sql_alter.cc:512
    #14 0x55ebc576b361 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6052
    #15 0x55ebc5777991 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7840
    #16 0x55ebc574e7d5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1852
    #17 0x55ebc574b30c in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1398
    #18 0x55ebc5b15a9f in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
    #19 0x55ebc5b15359 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
    #20 0x55ebc712e9de in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
    #21 0x7f6f84be2608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
    #22 0x7f6f847bc292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
 
0x611000059ac8 is located 0 bytes to the right of 200-byte region [0x611000059a00,0x611000059ac8)
allocated by thread T27 here:
    #0 0x7f6f85149bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
    #1 0x55ebc6629c7d in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned int, unsigned long) /data/src/10.3/storage/innobase/mem/mem0mem.cc:277
    #2 0x55ebc69d28fc in mem_heap_create_func /data/src/10.3/storage/innobase/include/mem0mem.ic:375
    #3 0x55ebc69dd6a3 in page_cur_tuple_insert /data/src/10.3/storage/innobase/include/page0cur.ic:271
    #4 0x55ebc69f5664 in btr_cur_optimistic_insert(unsigned long, btr_cur_t*, unsigned short**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /data/src/10.3/storage/innobase/btr/btr0cur.cc:3444
    #5 0x55ebc674a79e in row_ins_clust_index_entry_low(unsigned long, unsigned long, dict_index_t*, unsigned long, dtuple_t*, unsigned long, que_thr_t*) /data/src/10.3/storage/innobase/row/row0ins.cc:2764
    #6 0x55ebc64f4366 in innobase_add_instant_try /data/src/10.3/storage/innobase/handler/handler0alter.cc:4564
    #7 0x55ebc652bd4b in commit_try_norebuild(Alter_inplace_info*, ha_innobase_inplace_ctx*, TABLE*, TABLE const*, trx_t*, char const*) /data/src/10.3/storage/innobase/handler/handler0alter.cc:8974
    #8 0x55ebc651a7fc in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.3/storage/innobase/handler/handler0alter.cc:9646
    #9 0x55ebc5eeb291 in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.3/sql/handler.cc:4602
    #10 0x55ebc59aa226 in mysql_inplace_alter_table /data/src/10.3/sql/sql_table.cc:7735
    #11 0x55ebc59ba5f8 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:9980
    #12 0x55ebc5b2662c in Sql_cmd_alter_table::execute(THD*) /data/src/10.3/sql/sql_alter.cc:512
    #13 0x55ebc576b361 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6052
    #14 0x55ebc5777991 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7840
    #15 0x55ebc574e7d5 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1852
    #16 0x55ebc574b30c in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1398
    #17 0x55ebc5b15a9f in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
    #18 0x55ebc5b15359 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
    #19 0x55ebc712e9de in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
    #20 0x7f6f84be2608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
 
Thread T27 created by T0 here:
    #0 0x7f6f85076805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
    #1 0x55ebc712edcf in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
    #2 0x55ebc547615e in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
    #3 0x55ebc548eb2d in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6658
    #4 0x55ebc548f2c8 in create_new_thread /data/src/10.3/sql/mysqld.cc:6728
    #5 0x55ebc549045a in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6986
    #6 0x55ebc548de1e in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6280
    #7 0x55ebc547495c in main /data/src/10.3/sql/main.cc:25
    #8 0x7f6f846c10b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
SUMMARY: AddressSanitizer: use-after-poison (/lib/x86_64-linux-gnu/libasan.so.5+0x9b47f) 
Shadow bytes around the buggy address:
  0x0c2280003300: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
  0x0c2280003310: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
  0x0c2280003320: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c2280003330: fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa
  0x0c2280003340: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c2280003350: f7 00 00 00 00[f7]f7 f7 f7 fa fa fa fa fa fa fa
  0x0c2280003360: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c2280003370: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c2280003380: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c2280003390: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c22800033a0: 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
==2337522==ABORTING

Could not reproduce on 10.4.
No obvious immediate problem on a non-ASAN build.



 Comments   
Comment by Marko Mäkelä [ 2021-04-26 ]

This is indeed not reproducible in later versions, not even with nnodb-instant-alter-column-allowed=add_last.
We allocated 7+25 bytes of memory a little earlier. In 10.6, where the test does not crash, we are allocating 8+25 bytes. In 10.3, the counterpart of rec_get_converted_size_comp_prefix_low() is not being executed:

		} else if (len < 128 || !DATA_BIG_COL(field->col)) {
			extra_size++;

The cause of the omission is that field->fixed_len is 24 bytes in 10.3 but 8 bytes in later versions. That in turn is caused by another difference in dict_index_add_col():

#0  0x00000000023911f1 in dict_index_add_col (index=0x618000038508, table=0x6190000d8a08, col=0x61d0001f7d28, prefix_len=0) at /mariadb/10.3/storage/innobase/dict/dict0dict.cc:2354
#1  0x000000000238eebe in dict_index_build_internal_clust (index=0x618000038108) at /mariadb/10.3/storage/innobase/dict/dict0dict.cc:2625
#2  0x000000000238ac21 in dict_index_add_to_cache (index=@0x6190000d8740: 0x618000038108, page_no=4294967295, add_v=0x0) at /mariadb/10.3/storage/innobase/dict/dict0dict.cc:2045
#3  0x0000000001b87a3f in prepare_inplace_alter_table_dict (ha_alter_info=0x7ff9c384e7f0, altered_table=0x61f000043688, old_table=0x61f000042888, table_name=0x61a0000179e5 "t1", flags=0, flags2=80, 
    fts_doc_id_col=18446744073709551615, add_fts_doc_id=false, add_fts_doc_id_idx=false) at /mariadb/10.3/storage/innobase/handler/handler0alter.cc:5468

Note: we wrongly have flags=0 here (corresponding to ROW_FORMAT=REDUNDANT); in later versions we would have the correct flags=33 (ROW_FORMAT=DYNAMIC).

In 10.4.14, 10.5.5 or later, we would adjust the flags parameter in prepare_inplace_alter_table_dict() thanks to the fix of MDEV-23295. Backporting that fix to 10.3 fixes the test case.

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