Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.3(EOL), 10.4(EOL)
Description
10.3 f130adbf non-debug ASAN |
==1376958==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x60200002292f at pc 0x558682dfb7f2 bp 0x7f0b08d88bb0 sp 0x7f0b08d88ba0
|
READ of size 1 at 0x60200002292f thread T29
|
#0 0x558682dfb7f1 in rec_init_offsets_comp_ordinary /data/src/10.3/storage/innobase/rem/rem0rec.cc:404
|
#1 0x558682dfb7f1 in rec_init_offsets /data/src/10.3/storage/innobase/rem/rem0rec.cc:610
|
#2 0x558682dfb7f1 in rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned short*, bool, unsigned long, mem_block_info_t**) /data/src/10.3/storage/innobase/rem/rem0rec.cc:869
|
#3 0x558682e008bf in rec_copy_prefix_to_dtuple(dtuple_t*, unsigned char const*, dict_index_t const*, bool, unsigned long, mem_block_info_t*) /data/src/10.3/storage/innobase/rem/rem0rec.cc:1761
|
#4 0x5586831580d6 in dict_index_build_data_tuple(unsigned char const*, dict_index_t const*, bool, unsigned long, mem_block_info_t*) /data/src/10.3/storage/innobase/dict/dict0dict.cc:5106
|
#5 0x558683090fed in btr_pcur_restore_position_func(unsigned long, btr_pcur_t*, char const*, unsigned int, mtr_t*) /data/src/10.3/storage/innobase/btr/btr0pcur.cc:360
|
#6 0x558682ec00b5 in sel_restore_position_for_mysql /data/src/10.3/storage/innobase/row/row0sel.cc:3584
|
#7 0x558682ed3048 in row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long) /data/src/10.3/storage/innobase/row/row0sel.cc:5724
|
#8 0x558682c1a4dc in ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function) /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9268
|
#9 0x558682bd1271 in ha_innobase::index_first(unsigned char*) /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9642
|
#10 0x558682613959 in handler::ha_index_first(unsigned char*) /data/src/10.3/sql/handler.cc:2995
|
#11 0x558682a77c7d in rr_index_first /data/src/10.3/sql/records.cc:401
|
#12 0x558682a77c7d in rr_index_first /data/src/10.3/sql/records.cc:391
|
#13 0x5586821fc35a in READ_RECORD::read_record() /data/src/10.3/sql/records.h:70
|
#14 0x5586821fc35a 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:758
|
#15 0x558681f73337 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4320
|
#16 0x558681f87a3f in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7840
|
#17 0x558681f8e6c3 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1852
|
#18 0x558681f9551d in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1398
|
#19 0x5586822d1d16 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
|
#20 0x5586822d259e in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
|
#21 0x5586836568e8 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
|
#22 0x7f0b1f8e7608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
|
#23 0x7f0b1f4c1292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
|
|
0x60200002292f is located 1 bytes to the left of 11-byte region [0x602000022930,0x60200002293b)
|
allocated by thread T29 here:
|
#0 0x7f0b1fe4ebc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
|
#1 0x558682e012a3 in rec_copy_prefix_to_buf(unsigned char const*, dict_index_t const*, unsigned long, unsigned char**, unsigned long*) /data/src/10.3/storage/innobase/rem/rem0rec.cc:1966
|
#2 0x55868308f452 in btr_pcur_store_position(btr_pcur_t*, mtr_t*) /data/src/10.3/storage/innobase/btr/btr0pcur.cc:173
|
#3 0x558682ed4273 in row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long) /data/src/10.3/storage/innobase/row/row0sel.cc:5685
|
#4 0x558682c1a4dc in ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function) /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9268
|
#5 0x558682bd1271 in ha_innobase::index_first(unsigned char*) /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9642
|
#6 0x558682613959 in handler::ha_index_first(unsigned char*) /data/src/10.3/sql/handler.cc:2995
|
#7 0x558682a77c7d in rr_index_first /data/src/10.3/sql/records.cc:401
|
#8 0x558682a77c7d in rr_index_first /data/src/10.3/sql/records.cc:391
|
#9 0x5586821fc35a in READ_RECORD::read_record() /data/src/10.3/sql/records.h:70
|
#10 0x5586821fc35a 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:758
|
#11 0x558681f73337 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4320
|
#12 0x558681f87a3f in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7840
|
#13 0x558681f8e6c3 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1852
|
#14 0x558681f9551d in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1398
|
#15 0x5586822d1d16 in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
|
#16 0x5586822d259e in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
|
#17 0x5586836568e8 in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
|
#18 0x7f0b1f8e7608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
|
|
Thread T29 created by T0 here:
|
#0 0x7f0b1fd7b805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
|
#1 0x55868365e43e in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
|
#2 0x558681d03a9e in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
|
#3 0x558681d03a9e in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6658
|
#4 0x558681d14415 in create_new_thread /data/src/10.3/sql/mysqld.cc:6728
|
#5 0x558681d14415 in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6986
|
#6 0x558681d163a5 in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6280
|
#7 0x7f0b1f3c60b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
|
|
SUMMARY: AddressSanitizer: heap-buffer-overflow /data/src/10.3/storage/innobase/rem/rem0rec.cc:404 in rec_init_offsets_comp_ordinary
|
Shadow bytes around the buggy address:
|
0x0c047fffc4d0: fa fa fd fa fa fa fd fa fa fa fd fa fa fa fd fd
|
0x0c047fffc4e0: fa fa fd fa fa fa fd fa fa fa fd fd fa fa fd fa
|
0x0c047fffc4f0: fa fa fd fa fa fa fd fa fa fa fd fd fa fa 00 00
|
0x0c047fffc500: fa fa fd fa fa fa fd fd fa fa fd fa fa fa fd fa
|
0x0c047fffc510: fa fa fd fd fa fa fd fa fa fa fd fa fa fa 00 00
|
=>0x0c047fffc520: fa fa 00 00 fa[fa]00 03 fa fa fa fa fa fa fa fa
|
0x0c047fffc530: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c047fffc540: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c047fffc550: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c047fffc560: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c047fffc570: 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
|
==1376958==ABORTING
|
Reproducible on 10.3-10.4 at least.
Reproducible both on debug and non-debug ASAN, but easier on a non-debug ASAN, and the test itself is much faster there.
Couldn't reproduce on 10.5, but it's not conclusive, as the test is highly non-deterministic. Run with high value of --repeat (hundreds at least).
Didn't get any crashes on non-ASAN builds.
rr profile is available.
--source include/have_innodb.inc
|
|
CREATE TABLE t1 (a VARBINARY(542) NOT NULL DEFAULT '', id INT, PRIMARY KEY (a,id)) ENGINE=InnoDB; |
INSERT INTO t1 VALUES (1,1); |
--send
|
ALTER TABLE t1 ADD n INT; |
|
--connect (con1,localhost,root,,test)
|
--send
|
DELETE FROM t1 ORDER BY a LIMIT 5; |
|
--connect (con2,localhost,root,,test)
|
--send
|
DELETE FROM t1 ORDER BY id LIMIT 3; |
|
--connection default
|
--reap
|
UPDATE t1 SET n = 1 ORDER BY a LIMIT 1; |
|
# Cleanup
|
|
--connection con2
|
--reap
|
--disconnect con2
|
--connection con1
|
--reap
|
--disconnect con1
|
--connection default
|
DROP TABLE t1; |
Attachments
Issue Links
- is caused by
-
MDEV-11369 Instant add column for InnoDB
-
- Closed
-
I started checking the rr replay, and the pointer is rather ‘wild’. The ASAN shadow byte was initialized as a red zone for something completely unrelated:
10.3 f130adbf35b5b8ef7ed091549ed764982801480c
#6 0x00007f8af01d9b0b in malloc () from /usr/lib/x86_64-linux-gnu/libasan.so.4
#7 0x00007f8aee54da2a in __GI___strdup (s=s@entry=0x7f8aee665487 "/etc/localtime") at strdup.c:42
#8 0x00007f8aee584281 in tzset_internal (always=1) at tzset.c:403
#9 __tzset () at tzset.c:552
#10 0x0000556a2a6ec3f2 in init_common_variables () at /home/mariadb/MDEV-24620/10.3/sql/mysqld.cc:4261
#11 0x0000556a2a6f2b4c in mysqld_main (argc=147, argv=0x61b000000f58)
The problem is that we are accessing something that was not allocated in the btr_pcur_t::old_rec at all:
#0 0x0000556a2ba05f5b in rec_init_offsets_comp_ordinary (rec=0x6020000073d6 "1\200",
index=0x618000033908, offsets=0x7f8ad3be07a0, n_core=5, def_val=0x0, format=REC_LEAF_ORDINARY)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/rem/rem0rec.cc:404
#1 0x0000556a2ba080de in rec_init_offsets (rec=0x6020000073d6 "1\200", index=0x618000033908,
leaf=true, offsets=0x7f8ad3be07a0)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/rem/rem0rec.cc:610
#2 0x0000556a2ba09e31 in rec_get_offsets_func (rec=0x6020000073d6 "1\200", index=0x618000033908,
offsets=0x7f8ad3be07a0, leaf=true, n_fields=2,
file=0x556a2cd97860 "/home/mariadb/MDEV-24620/10.3/storage/innobase/rem/rem0rec.cc", line=1762,
heap=0x7f8ad3be06f0) at /home/mariadb/MDEV-24620/10.3/storage/innobase/rem/rem0rec.cc:869
#3 0x0000556a2ba11098 in rec_copy_prefix_to_dtuple (tuple=0x6130000fb488, rec=0x6020000073d6 "1\200",
index=0x618000033908, is_leaf=true, n_fields=2, heap=0x6130000fb400)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/rem/rem0rec.cc:1761
#4 0x0000556a2beb39ec in dict_index_build_data_tuple (rec=0x6020000073d6 "1\200",
index=0x618000033908, leaf=true, n_fields=2, heap=0x6130000fb400)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/dict/dict0dict.cc:5106
#5 0x0000556a2bd8289e in btr_pcur_restore_position_func (latch_mode=1, cursor=0x6200000132e0,
file=0x556a2ce0b0e0 "/home/mariadb/MDEV-24620/10.3/storage/innobase/row/row0sel.cc", line=3584,
mtr=0x7f8ad3be2640) at /home/mariadb/MDEV-24620/10.3/storage/innobase/btr/btr0pcur.cc:360
At the time of the out-of-bounds access is detected, we dereferenced lens = 0x6020000073cf, which is right before btr_pcur_t::old_rec_buf. The memory was last modified here, as expected:
#2 0x0000556a2ba1364d in rec_copy_prefix_to_buf (rec=0x7f8ae490407e "1\200", index=0x618000033908,
n_fields=2, buf=0x6200000133c8, buf_size=0x6200000133d0)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/rem/rem0rec.cc:1993
#3 0x0000556a2beb3887 in dict_index_copy_rec_order_prefix (index=0x618000033908,
rec=0x7f8ae490407e "1\200", n_fields=0x620000013390, buf=0x6200000133c8, buf_size=0x6200000133d0)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/dict/dict0dict.cc:5084
#4 0x0000556a2bd8173f in btr_pcur_store_position (cursor=0x6200000132e0, mtr=0x7f8ad3be2640)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/btr/btr0pcur.cc:173
#5 0x0000556a2bb6c9d6 in row_search_mvcc (buf=0x61a000079310 "\377", mode=PAGE_CUR_G,
prebuilt=0x620000013108, match_mode=0, direction=0)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/row/row0sel.cc:5685
At frame 5, we had the offsets of the record indicating that there be 6 record header bytes, corresponding to what was copied to btr_pcur_t::old_rec_buf. We do have index->is_instant() at that point; the column n had been instantly added.
The contents of the record at that point is (note: no instantly added column is present):
(a,id,DB_TRX_ID,DB_ROLL_PTR)=('1',1,0x29,(update))
The problem is that between the time of storing and restoring the cursor, the table ‘lost instantness’, and hence we are expecting to find more header bytes than the 6:
#0 0x0000556a2b818b79 in dict_index_t::remove_instant (this=0x618000033908)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/include/dict0mem.h:1133
#1 0x0000556a2bd67147 in btr_cur_optimistic_delete_func (cursor=0x61a000001fb0, flags=0,
mtr=0x7f8ada3780f0) at /home/mariadb/MDEV-24620/10.3/storage/innobase/btr/btr0cur.cc:5530
#2 0x0000556a2bb1f2e1 in row_purge_remove_clust_if_poss_low (node=0x61a000001f08, mode=2)
at /home/mariadb/MDEV-24620/10.3/storage/innobase/row/row0purge.cc:144
Maybe the simplest fix would be to maintain a copy of dict_index_t::n_core_fields in btr_pcur_t and use that value in btr_pcur_restore_pos().
Here is a repeatable test case for 10.3:
--- a/mysql-test/suite/innodb/t/instant_alter_debug.test
+++ b/mysql-test/suite/innodb/t/instant_alter_debug.test
+
+
+
+
+
+disconnect stop_purge;
+
+
+reap;
+disconnect dml;
+
+
--- a/storage/innobase/row/row0mysql.cc
+++ b/storage/innobase/row/row0mysql.cc
@@ -689,6 +689,7 @@ row_mysql_handle_errors(
dberr_t err;
handle_new_error:
err = trx->error_state;