[MDEV-13942] Potential InnoDB SPATIAL INDEX corruption during root page split Created: 2017-09-28  Updated: 2023-03-15  Resolved: 2019-05-07

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.2, 10.3.0, 10.4.0
Fix Version/s: 10.2.24, 10.3.15, 10.4.5

Type: Bug Priority: Major
Reporter: Marko Mäkelä Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: ASAN, upstream, valgrind

Issue Links:
Duplicate
is duplicated by MDEV-22389 SPATIAL INDEX corruption on INSERT Closed
Relates
relates to MDEV-11369 Instant add column for InnoDB Closed
relates to MDEV-14209 innodb_gis.rtree_debug and innodb_gis... Closed
relates to MDEV-30856 Reproducible crash when inserting dat... Confirmed

 Description   

This was reported by Valgrind when I ran the test innodb.instant_alter that is part of the MDEV-11369 development.

==28026== Conditional jump or move depends on uninitialised value(s)
 
==28026==    at 0x100CC24: dtuple_get_nth_field(dtuple_t const*, unsigned long) (data0data.ic:433)
 
==28026==    by 0x1011D79: rtr_page_split_initialize_nodes(mem_block_info_t*, btr_cur_t*, unsigned long**, dtuple_t const*, double**) (gis0rtree.cc:108)
 
==28026==    by 0x1014828: rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (gis0rtree.cc:1064)
 
==28026==    by 0xEA8B36: btr_root_raise_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (btr0btr.cc:2101)
 
==28026==    by 0xECF378: btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) (btr0cur.cc:3352)
 
==28026==    by 0x1013763: rtr_adjust_upper_level(btr_cur_t*, unsigned long, buf_block_t*, buf_block_t*, rtr_mbr*, rtr_mbr*, unsigned long, mtr_t*) (gis0rtree.cc:730)
 
==28026==    by 0x101529E: rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (gis0rtree.cc:1275)

The problem is in rtr_adjust_upper_level(), which allocates node_ptr from heap, and then passes the same heap to btr_cur_pessimistic_insert(). The documentation of btr_cur_pessimistic_insert() says that the heap can be emptied. If the heap is emptied and something else is allocated from the heap, the node_ptr can become corrupted.

 Comments   
Comment by Marko Mäkelä [ 2019-01-23 ]

Thanks to the ASAN memory poisoning (MDEV-17797, ), there now are multiple tests in the innodb_gis suite that fail like this:

10.2 37ffdb44ef96bacac8981cf180bb47be5da486df

 
CURRENT_TEST: innodb_gis.rtree_compress
 
mysqltest: At line 37: query 'insert into t1 select * from t1' failed: 2013: Lost connection to MySQL server during query
 
…
 
Version: '10.2.22-MariaDB-debug-log'  socket: '/dev/shm/10.2/mysql-test/var/tmp/3/mysqld.1.sock'  port: 16040  Source distribution
 
=================================================================
 
==13372==ERROR: AddressSanitizer: use-after-poison on address 0x61a000256fe8 at pc 0x000001d9852e bp 0x7fd69c6899d0 sp 0x7fd69c6899c8
 
READ of size 8 at 0x61a000256fe8 thread T27
 
    #0 0x1d9852d in dtuple_get_nth_field(dtuple_t const*, unsigned long) /mariadb/10.2/storage/innobase/include/data0data.ic:430:2
 
    #1 0x1d9852d in rtr_page_split_initialize_nodes(mem_block_info_t*, btr_cur_t*, unsigned long**, dtuple_t const*, double**) /mariadb/10.2/storage/innobase/gis/gis0rtree.cc:108
 
    #2 0x1d9852d in rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/gis/gis0rtree.cc:1064
 
    #3 0x1a5d2e4 in btr_root_raise_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/btr/btr0btr.cc:2149:10
 
    #4 0x1ac1515 in btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /mariadb/10.2/storage/innobase/btr/btr0cur.cc:3403:10
 
    #5 0x1d94895 in rtr_adjust_upper_level(btr_cur_t*, unsigned long, buf_block_t*, buf_block_t*, rtr_mbr*, rtr_mbr*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/gis/gis0rtree.cc:730:9
 
    #6 0x1d94895 in rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/gis/gis0rtree.cc:1275
 
    #7 0x1a65a5b in btr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/btr/btr0btr.cc:2934:10
 
    #8 0x1ac153c in btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /mariadb/10.2/storage/innobase/btr/btr0cur.cc:3406:10
 
    #9 0x17db488 in row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*, bool) /mariadb/10.2/storage/innobase/row/row0ins.cc:3097:11
 
    #10 0x17e0573 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /mariadb/10.2/storage/innobase/row/row0ins.cc:3269:9
 
    #11 0x17e2da7 in row_ins_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3303:10
 
    #12 0x17e2da7 in row_ins_index_entry_step(ins_node_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3451
 
    #13 0x17e2da7 in row_ins(ins_node_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3594
 
    #14 0x17e2da7 in row_ins_step(que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3820
 
    #15 0x1823538 in row_insert_for_mysql(unsigned char const*, row_prebuilt_t*) /mariadb/10.2/storage/innobase/row/row0mysql.cc:1413:2
 
    #16 0x153889b in ha_innobase::write_row(unsigned char*) /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:8235:10
 
    #17 0xef8b26 in handler::ha_write_row(unsigned char*) /mariadb/10.2/sql/handler.cc:5961:3
 
    #18 0x865abb in write_record(THD*, TABLE*, st_copy_info*) /mariadb/10.2/sql/sql_insert.cc:1930:32
 
    #19 0x878d12 in select_insert::send_data(List<Item>&) /mariadb/10.2/sql/sql_insert.cc:3758:10
 
    #20 0x9a9715 in end_send(JOIN*, st_join_table*, bool) /mariadb/10.2/sql/sql_select.cc:19936:33
 
    #21 0x9f8b00 in evaluate_join_record(JOIN*, st_join_table*, int) /mariadb/10.2/sql/sql_select.cc:18984:11
 
    #22 0x9f668d in AGGR_OP::end_send() /mariadb/10.2/sql/sql_select.cc:26726:11
 
    #23 0x9abacf in sub_select_postjoin_aggr(JOIN*, st_join_table*, bool) /mariadb/10.2/sql/sql_select.cc:18479:15
 
    #24 0x9f6abf in sub_select(JOIN*, st_join_table*, bool) /mariadb/10.2/sql/sql_select.cc:18715:7
 
    #25 0x9b8dce in do_select(JOIN*, Procedure*) /mariadb/10.2/sql/sql_select.cc:18310:14
 
    #26 0x9b8dce in JOIN::exec_inner() /mariadb/10.2/sql/sql_select.cc:3623
 
    #27 0x9b673e in JOIN::exec() /mariadb/10.2/sql/sql_select.cc:3418:3
 
    #28 0x95f9a9 in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /mariadb/10.2/sql/sql_select.cc:3818:9
 
    #29 0x95ef4d in handle_select(THD*, LEX*, select_result*, unsigned long) /mariadb/10.2/sql/sql_select.cc:364:10
 
    #30 0x8d5b32 in mysql_execute_command(THD*) /mariadb/10.2/sql/sql_parse.cc:4545:16
 
    #31 0x8be376 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /mariadb/10.2/sql/sql_parse.cc:8015:18
 
    #32 0x8b2fc4 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /mariadb/10.2/sql/sql_parse.cc:1825:7
 
    #33 0x8b97aa in do_command(THD*) /mariadb/10.2/sql/sql_parse.cc:1378:17
 
    #34 0xc13f3e in do_handle_one_connection(CONNECT*) /mariadb/10.2/sql/sql_connect.cc:1335:11
 
    #35 0xc13653 in handle_one_connection /mariadb/10.2/sql/sql_connect.cc:1241:3
 
    #36 0x2175bf5 in pfs_spawn_thread /mariadb/10.2/storage/perfschema/pfs.cc:1862:3
 
    #37 0x7fd6b5be6fa2 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7fa2)
 
    #38 0x7fd6b4e857ee in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf97ee)
 
 
 
0x61a000256fe8 is located 360 bytes inside of 1160-byte region [0x61a000256e80,0x61a000257308)
 
allocated by thread T27 here:
 
    #0 0x65db73 in __interceptor_malloc (/dev/shm/10.2/sql/mysqld+0x65db73)
 
    #1 0x16da4cc in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned int, unsigned long) /mariadb/10.2/storage/innobase/mem/mem0mem.cc:294:37
 
    #2 0x1d93db3 in mem_heap_create_func(unsigned long, char const*, unsigned int, unsigned long) /mariadb/10.2/storage/innobase/include/mem0mem.ic:483:10
 
    #3 0x1d93db3 in rtr_adjust_upper_level(btr_cur_t*, unsigned long, buf_block_t*, buf_block_t*, rtr_mbr*, rtr_mbr*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/gis/gis0rtree.cc:664
 
    #4 0x1d93db3 in rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/gis/gis0rtree.cc:1275
 
    #5 0x1a65a5b in btr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/10.2/storage/innobase/btr/btr0btr.cc:2934:10
 
    #6 0x1ac153c in btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /mariadb/10.2/storage/innobase/btr/btr0cur.cc:3406:10
 
    #7 0x17db488 in row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*, bool) /mariadb/10.2/storage/innobase/row/row0ins.cc:3097:11
 
    #8 0x17e0573 in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /mariadb/10.2/storage/innobase/row/row0ins.cc:3269:9
 
    #9 0x17e2da7 in row_ins_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3303:10
 
    #10 0x17e2da7 in row_ins_index_entry_step(ins_node_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3451
 
    #11 0x17e2da7 in row_ins(ins_node_t*, que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3594
 
    #12 0x17e2da7 in row_ins_step(que_thr_t*) /mariadb/10.2/storage/innobase/row/row0ins.cc:3820
 
    #13 0x1823538 in row_insert_for_mysql(unsigned char const*, row_prebuilt_t*) /mariadb/10.2/storage/innobase/row/row0mysql.cc:1413:2
 
    #14 0x153889b in ha_innobase::write_row(unsigned char*) /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:8235:10
 
    #15 0xef8b26 in handler::ha_write_row(unsigned char*) /mariadb/10.2/sql/handler.cc:5961:3
 
    #16 0x865abb in write_record(THD*, TABLE*, st_copy_info*) /mariadb/10.2/sql/sql_insert.cc:1930:32
 
    #17 0x878d12 in select_insert::send_data(List<Item>&) /mariadb/10.2/sql/sql_insert.cc:3758:10
 
    #18 0x9a9715 in end_send(JOIN*, st_join_table*, bool) /mariadb/10.2/sql/sql_select.cc:19936:33
 
    #19 0x9f8b00 in evaluate_join_record(JOIN*, st_join_table*, int) /mariadb/10.2/sql/sql_select.cc:18984:11
 
    #20 0x9f668d in AGGR_OP::end_send() /mariadb/10.2/sql/sql_select.cc:26726:11
 
 
 
Thread T27 created by T0 here:
 
    #0 0x64648d in pthread_create (/dev/shm/10.2/sql/mysqld+0x64648d)
 
    #1 0x2179281 in spawn_thread_v1(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /mariadb/10.2/storage/perfschema/pfs.cc:1912:15
 
 
 
SUMMARY: AddressSanitizer: use-after-poison /mariadb/10.2/storage/innobase/include/data0data.ic:430:2 in dtuple_get_nth_field(dtuple_t const*, unsigned long)
 
Shadow bytes around the buggy address:
 
  0x0c3480042da0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3480042db0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3480042dc0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3480042dd0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c3480042de0: 00 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
=>0x0c3480042df0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]f7 f7
 
  0x0c3480042e00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c3480042e10: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c3480042e20: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c3480042e30: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c3480042e40: 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
 
  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

Other such tests:
innodb_gis.rtree_compress2
innodb_gis.rtree_rollback1
innodb_gis.rtree_split
innodb_gis.rtree_debug
innodb_gis.update_root
innodb_gis.multi_pk

Comment by Marko Mäkelä [ 2019-03-04 ]

I ported some minimal ASAN instrumentation from MariaDB to MySQL 5.7.25 in order to reproduce the problem more easily there:

diff --git a/storage/innobase/include/mem0mem.ic b/storage/innobase/include/mem0mem.ic
 
index a12c58b542c..a209a11202a 100644
 
--- a/storage/innobase/include/mem0mem.ic
 
+++ b/storage/innobase/include/mem0mem.ic
 
@@ -24,6 +24,7 @@ Created 6/8/1994 Heikki Tuuri
 
 *************************************************************************/
 
 
 #include "ut0new.h"
 
+#include <sanitizer/asan_interface.h>
 
 
 #ifdef UNIV_DEBUG
 
 # define mem_heap_create_block(heap, n, type, file_name, line)		\
 
@@ -215,6 +216,7 @@ mem_heap_alloc(
 
 
 	mem_block_set_free(block, free + MEM_SPACE_NEEDED(n));
 
 
+	ASAN_UNPOISON_MEMORY_REGION(buf, n);
 
 	UNIV_MEM_ALLOC(buf, n);
 
 	return(buf);
 
 }
 
@@ -283,6 +285,8 @@ mem_heap_free_heap_top(
 
 	ut_ad(mem_block_get_start(block) <= mem_block_get_free(block));
 
 	UNIV_MEM_ASSERT_W(old_top, (byte*) block + block->len - old_top);
 
 	UNIV_MEM_ALLOC(old_top, (byte*) block + block->len - old_top);
 
+	ASAN_POISON_MEMORY_REGION(old_top,
 
+				  (byte*) block + block->len - old_top);
 
 
 	/* If free == start, we may free the block if it is not the first
 
 	one */

This would cause test failures like this:

mysql-5.7.25

 
CURRENT_TEST: innodb_gis.rtree_rollback1
 
mysqltest: At line 39: query 'insert into t1 select * from t1' failed: 2013: Lost connection to MySQL server during query
 
…
 
Version: '5.7.25-debug-log-asan'  socket: '/dev/shm/5.7/mysql-test/var/tmp/1/mysqld.1.sock'  port: 13010  Source distribution
 
=================================================================
 
==40778==ERROR: AddressSanitizer: use-after-poison on address 0x61a00100a600 at pc 0x55e7f16d77f6 bp 0x7fd79abb7fe0 sp 0x7fd79abb7fd8
 
READ of size 8 at 0x61a00100a600 thread T24
 
    #0 0x55e7f16d77f5 in dtuple_get_nth_field /mariadb/mysql-server/storage/innobase/include/data0data.ic:431
 
    #1 0x55e7f16d77f5 in rtr_page_split_initialize_nodes /mariadb/mysql-server/storage/innobase/gis/gis0rtree.cc:111
 
    #2 0x55e7f16d77f5 in rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/mysql-server/storage/innobase/gis/gis0rtree.cc:1062
 
    #3 0x55e7f13c8f29 in btr_root_raise_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/mysql-server/storage/innobase/btr/btr0btr.cc:1768
 
    #4 0x55e7f13df677 in btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /mariadb/mysql-server/storage/innobase/btr/btr0cur.cc:3424
 
    #5 0x55e7f16d8603 in rtr_adjust_upper_level /mariadb/mysql-server/storage/innobase/gis/gis0rtree.cc:730
 
    #6 0x55e7f16d8603 in rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/mysql-server/storage/innobase/gis/gis0rtree.cc:1275
 
    #7 0x55e7f13c37ba in btr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/mysql-server/storage/innobase/btr/btr0btr.cc:2546
 
    #8 0x55e7f13df4dc in btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /mariadb/mysql-server/storage/innobase/btr/btr0cur.cc:3427
 
    #9 0x55e7f10cfba1 in row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*, bool) /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3193
 
    #10 0x55e7f10d1aae in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3443
 
    #11 0x55e7f10d3914 in row_ins_index_entry /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3477
 
    #12 0x55e7f10d3914 in row_ins_index_entry_step /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3625
 
    #13 0x55e7f10d3914 in row_ins /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3767
 
    #14 0x55e7f10d3914 in row_ins_step(que_thr_t*) /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3952
 
    #15 0x55e7f110dc24 in row_insert_for_mysql_using_ins_graph /mariadb/mysql-server/storage/innobase/row/row0mysql.cc:1738
 
    #16 0x55e7f11149db in row_insert_for_mysql(unsigned char const*, row_prebuilt_t*) /mariadb/mysql-server/storage/innobase/row/row0mysql.cc:1860
 
    #17 0x55e7f0e22059 in ha_innobase::write_row(unsigned char*) /mariadb/mysql-server/storage/innobase/handler/ha_innodb.cc:7598
 
    #18 0x55e7ef1e5544 in handler::ha_write_row(unsigned char*) /mariadb/mysql-server/sql/handler.cc:8048
 
    #19 0x55e7f0a6c18f in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) /mariadb/mysql-server/sql/sql_insert.cc:1873
 
    #20 0x55e7f0a6d7e4 in Query_result_insert::send_data(List<Item>&) /mariadb/mysql-server/sql/sql_insert.cc:2271
 
    #21 0x55e7f03df219 in end_send /mariadb/mysql-server/sql/sql_executor.cc:2914
 
    #22 0x55e7f03d1ab3 in evaluate_join_record /mariadb/mysql-server/sql/sql_executor.cc:1645
 
    #23 0x55e7f03e5bb5 in QEP_tmp_table::end_send() /mariadb/mysql-server/sql/sql_executor.cc:4705
 
    #24 0x55e7f03e7a6d in sub_select_op(JOIN*, QEP_TAB*, bool) /mariadb/mysql-server/sql/sql_executor.cc:1069
 
    #25 0x55e7f03e60e1 in sub_select(JOIN*, QEP_TAB*, bool) /mariadb/mysql-server/sql/sql_executor.cc:1226
 
    #26 0x55e7f03cbdd1 in do_select /mariadb/mysql-server/sql/sql_executor.cc:952
 
    #27 0x55e7f03cbdd1 in JOIN::exec() /mariadb/mysql-server/sql/sql_executor.cc:199
 
    #28 0x55e7f057de60 in handle_query(THD*, LEX*, Query_result*, unsigned long long, unsigned long long) /mariadb/mysql-server/sql/sql_select.cc:184
 
    #29 0x55e7f0a68fb0 in Sql_cmd_insert_select::execute(THD*) /mariadb/mysql-server/sql/sql_insert.cc:3214
 
    #30 0x55e7f04a2bfe in mysql_execute_command(THD*, bool) /mariadb/mysql-server/sql/sql_parse.cc:3596
 
    #31 0x55e7f04b2b21 in mysql_parse(THD*, Parser_state*) /mariadb/mysql-server/sql/sql_parse.cc:5570
 
    #32 0x55e7f04b7e04 in dispatch_command(THD*, COM_DATA const*, enum_server_command) /mariadb/mysql-server/sql/sql_parse.cc:1484
 
    #33 0x55e7f04bdbd6 in do_command(THD*) /mariadb/mysql-server/sql/sql_parse.cc:1025
 
    #34 0x55e7f07ab383 in handle_connection /mariadb/mysql-server/sql/conn_handler/connection_handler_per_thread.cc:306
 
    #35 0x55e7f18962ef in pfs_spawn_thread /mariadb/mysql-server/storage/perfschema/pfs.cc:2190
 
    #36 0x7fd7b03affa2 in start_thread /build/glibc-d2N3Ld/glibc-2.28/nptl/pthread_create.c:486
 
    #37 0x7fd7aff6a82e in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf982e)
 
 
 
0x61a00100a600 is located 384 bytes inside of 1184-byte region [0x61a00100a480,0x61a00100a920)
 
allocated by thread T24 here:
 
    #0 0x7fd7b04b2350 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.5+0xe9350)
 
    #1 0x55e7f0fa3b0d in ut_allocator<unsigned char>::allocate(unsigned long, unsigned char const*, char const*, bool, bool) /mariadb/mysql-server/storage/innobase/include/ut0new.h:351
 
    #2 0x55e7f0fa3b0d in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned long, unsigned long) /mariadb/mysql-server/storage/innobase/mem/mem0mem.cc:302
 
    #3 0x55e7f16c4ad8 in mem_heap_create_func /mariadb/mysql-server/storage/innobase/include/mem0mem.ic:497
 
    #4 0x55e7f16d6260 in rtr_adjust_upper_level /mariadb/mysql-server/storage/innobase/gis/gis0rtree.cc:665
 
    #5 0x55e7f16d6260 in rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/mysql-server/storage/innobase/gis/gis0rtree.cc:1275
 
    #6 0x55e7f13c37ba in btr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) /mariadb/mysql-server/storage/innobase/btr/btr0btr.cc:2546
 
    #7 0x55e7f13df4dc in btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) /mariadb/mysql-server/storage/innobase/btr/btr0cur.cc:3427
 
    #8 0x55e7f10cfba1 in row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*, bool) /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3193
 
    #9 0x55e7f10d1aae in row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3443
 
    #10 0x55e7f10d3914 in row_ins_index_entry /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3477
 
    #11 0x55e7f10d3914 in row_ins_index_entry_step /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3625
 
    #12 0x55e7f10d3914 in row_ins /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3767
 
    #13 0x55e7f10d3914 in row_ins_step(que_thr_t*) /mariadb/mysql-server/storage/innobase/row/row0ins.cc:3952
 
    #14 0x55e7f110dc24 in row_insert_for_mysql_using_ins_graph /mariadb/mysql-server/storage/innobase/row/row0mysql.cc:1738
 
    #15 0x55e7f11149db in row_insert_for_mysql(unsigned char const*, row_prebuilt_t*) /mariadb/mysql-server/storage/innobase/row/row0mysql.cc:1860
 
    #16 0x55e7f0e22059 in ha_innobase::write_row(unsigned char*) /mariadb/mysql-server/storage/innobase/handler/ha_innodb.cc:7598
 
    #17 0x55e7ef1e5544 in handler::ha_write_row(unsigned char*) /mariadb/mysql-server/sql/handler.cc:8048
 
    #18 0x55e7f0a6c18f in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) /mariadb/mysql-server/sql/sql_insert.cc:1873
 
    #19 0x55e7f0a6d7e4 in Query_result_insert::send_data(List<Item>&) /mariadb/mysql-server/sql/sql_insert.cc:2271
 
    #20 0x55e7f03df219 in end_send /mariadb/mysql-server/sql/sql_executor.cc:2914
 
    #21 0x55e7f03d1ab3 in evaluate_join_record /mariadb/mysql-server/sql/sql_executor.cc:1645
 
    #22 0x55e7f03e5bb5 in QEP_tmp_table::end_send() /mariadb/mysql-server/sql/sql_executor.cc:4705
 
    #23 0x55e7f03e7a6d in sub_select_op(JOIN*, QEP_TAB*, bool) /mariadb/mysql-server/sql/sql_executor.cc:1069
 
    #24 0x55e7f03e60e1 in sub_select(JOIN*, QEP_TAB*, bool) /mariadb/mysql-server/sql/sql_executor.cc:1226
 
    #25 0x55e7f03cbdd1 in do_select /mariadb/mysql-server/sql/sql_executor.cc:952
 
    #26 0x55e7f03cbdd1 in JOIN::exec() /mariadb/mysql-server/sql/sql_executor.cc:199
 
    #27 0x55e7f057de60 in handle_query(THD*, LEX*, Query_result*, unsigned long long, unsigned long long) /mariadb/mysql-server/sql/sql_select.cc:184
 
    #28 0x55e7f0a68fb0 in Sql_cmd_insert_select::execute(THD*) /mariadb/mysql-server/sql/sql_insert.cc:3214
 
    #29 0x55e7f04a2bfe in mysql_execute_command(THD*, bool) /mariadb/mysql-server/sql/sql_parse.cc:3596
 
    #30 0x55e7f04b2b21 in mysql_parse(THD*, Parser_state*) /mariadb/mysql-server/sql/sql_parse.cc:5570
 
    #31 0x55e7f04b7e04 in dispatch_command(THD*, COM_DATA const*, enum_server_command) /mariadb/mysql-server/sql/sql_parse.cc:1484
 
    #32 0x55e7f04bdbd6 in do_command(THD*) /mariadb/mysql-server/sql/sql_parse.cc:1025
 
    #33 0x55e7f07ab383 in handle_connection /mariadb/mysql-server/sql/conn_handler/connection_handler_per_thread.cc:306
 
    #34 0x55e7f18962ef in pfs_spawn_thread /mariadb/mysql-server/storage/perfschema/pfs.cc:2190
 
    #35 0x7fd7b03affa2 in start_thread /build/glibc-d2N3Ld/glibc-2.28/nptl/pthread_create.c:486
 
 
 
Thread T24 created by T0 here:
 
    #0 0x7fd7b0419db0 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
 
    #1 0x55e7f0d5cc0b in my_thread_create /mariadb/mysql-server/mysys/my_thread.c:92
 
    #2 0x55e7f189d7d6 in pfs_spawn_thread_v1 /mariadb/mysql-server/storage/perfschema/pfs.cc:2241
 
    #3 0x55e7f07ac382 in inline_mysql_thread_create /mariadb/mysql-server/include/mysql/psi/mysql_thread.h:1297
 
    #4 0x55e7f07ac382 in Per_thread_connection_handler::add_connection(Channel_info*) /mariadb/mysql-server/sql/conn_handler/connection_handler_per_thread.cc:410
 
    #5 0x55e7ef0fc90d in Connection_handler_manager::process_new_connection(Channel_info*) /mariadb/mysql-server/sql/conn_handler/connection_handler_manager.cc:268
 
    #6 0x55e7ef07ddce in Connection_acceptor<Mysqld_socket_listener>::connection_event_loop() /mariadb/mysql-server/sql/conn_handler/connection_acceptor.h:68
 
    #7 0x55e7ef07ddce in mysqld_main(int, char**) /mariadb/mysql-server/sql/mysqld.cc:5149
 
    #8 0x55e7ef061bbd in main /mariadb/mysql-server/sql/main.cc:25
 
    #9 0x7fd7afe9509a in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: use-after-poison /mariadb/mysql-server/storage/innobase/include/data0data.ic:431 in dtuple_get_nth_field
 
Shadow bytes around the buggy address:
 
  0x0c34801f9470: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c34801f9480: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c34801f9490: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c34801f94a0: 00 00 00 00 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c34801f94b0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
=>0x0c34801f94c0:[f7]f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c34801f94d0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c34801f94e0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c34801f94f0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c34801f9500: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c34801f9510: 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
 
  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
 
==40778==ABORTING

I invoked the tests with

ASAN_OPTIONS=abort_on_error=1,disable_coredump=0 ./mtr --parallel=auto --big-test --suite=innodb_gis rtree_{compress{,2},rollback1,split,debug} update_root multi_pk

If you prefer to run ‘live’ with --manual-gdb instead of examining core dumps after the crash, I recommend the following in gdb:

set environment ASAN_OPTIONS=abort_on_error=1
 
run

The failures could be reproducible without any additional instrumentation, using Valgrind, but it is much slower (over 16 minutes of wall-clock time for innodb_gis.rtree_rollback1). Also, all these tests are disabled under Valgrind, maybe because of this extremely long running time. You would have to remove lines like the following from the test files:

--source include/not_valgrind.inc

Or you would have to run with --manual-gdb and manually start valgrind --vgdb=yes --vgdb-error=0 sql/mysqld … and then target remote |vgdb from gdb.

Note: the Valgrind instrumentation in MySQL is not as strict as it could be. mem_heap_free_heap_top() started using UNIV_MEM_ALLOC uinstead of UNIV_MEM_FREE here, likely in order to avoid the need to call UNIV_MEM_ALLOC later if the memory is reused (which is what my above patch does).

Comment by Marko Mäkelä [ 2019-03-04 ]

I tested MySQL 5.7.25 with the following modification:

diff --git a/mysql-test/suite/innodb_gis/t/rtree_rollback1.test b/mysql-test/suite/innodb_gis/t/rtree_rollback1.test
 
index 123bccf76a1..94f30d89b98 100644
 
--- a/mysql-test/suite/innodb_gis/t/rtree_rollback1.test
 
+++ b/mysql-test/suite/innodb_gis/t/rtree_rollback1.test
 
@@ -6,7 +6,6 @@
 
 
 --source include/have_innodb.inc
 
 --source include/big_test.inc
 
---source include/not_valgrind.inc
 
 --source include/have_innodb_16k.inc
 
 
 # Create table with R-tree index.

The test ran almost exactly for 1 hour (I would say more than 100 times slower than the ASAN failure) to produce the following:

mysql-5.7.25

 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
 
worker[1] Test still running: innodb_gis.rtree_rollback1
 
worker[1] Test still running: innodb_gis.rtree_rollback1
 
[100%] innodb_gis.rtree_rollback1               [ fail ]
 
        Test ended at 2019-03-04 14:26:03
 
 
 
CURRENT_TEST: innodb_gis.rtree_rollback1
 
==13916== Memcheck, a memory error detector
 
==13916== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
 
==13916== Using Valgrind-3.14.0 and LibVEX; rerun with -h for copyright info
 
==13916== Command: /dev/shm/5.7/client//mysqltest --defaults-file=/dev/shm/5.7/mysql-test/var/my.cnf --silent --tmpdir=/dev/shm/5.7/mysql-test/var/tmp --character-sets-dir=/mariadb/mysql-server/sql/share/charsets --logdir=/dev/shm/5.7/mysql-test/var/log --plugin_dir=/dev/shm/5.7/plugin/auth --database=test --timer-file=/dev/shm/5.7/mysql-test/var/log/timer --test-file=/mariadb/mysql-server/mysql-test/suite/innodb_gis/t/rtree_rollback1.test --tail-lines=20 --result-file=/mariadb/mysql-server/mysql-test/suite/innodb_gis/r/rtree_rollback1.result
 
==13916== 
==13916== 
==13916== HEAP SUMMARY:
 
==13916==     in use at exit: 0 bytes in 0 blocks
 
==13916==   total heap usage: 1,117 allocs, 1,117 frees, 999,905 bytes allocated
 
==13916== 
==13916== All heap blocks were freed -- no leaks are possible
 
==13916== 
==13916== For counts of detected and suppressed errors, rerun with: -v
 
==13916== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
 
 
 
 
 
Timeout for 'check warnings' expired after 900 seconds
 
 
 
 - the logfile can be found in '/dev/shm/5.7/mysql-test/var/log/innodb_gis.rtree_rollback1/rtree_rollback1.log'
 
[200%] valgrind_report                          [ pass ]       
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 0.000 of 3490 seconds executing testcases
 
 
 
Completed: Failed 1/2 tests, 50.00% were successful.
 
 
 
Failing test(s): innodb_gis.rtree_rollback1

The server error log mysql-test/var/log/mysqld.1.err contains some damning evidence:

5.7

 
CURRENT_TEST: innodb_gis.rtree_rollback1
 
==13854== Memcheck, a memory error detector
 
==13854== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
 
==13854== Using Valgrind-3.14.0 and LibVEX; rerun with -h for copyright info
 
==13854== Command: /dev/shm/5.7/sql/mysqld --defaults-group-suffix=.1 --defaults-file=/dev/shm/5.7/mysql-test/var/my.cnf --log-output=file --loose-debug-sync-timeout=6000 --loose-skip-log-bin --log-syslog=0 --core-file
 
==13854== 
2019-03-04T11:27:58.788505Z 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4161)
 
…
 
2019-03-04T11:44:18.274840Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 7335ms. The settings might not be optimal. (flushed=1 and evicted=0, during the time.)
 
==13854== Thread 24:
 
==13854== Conditional jump or move depends on uninitialised value(s)
 
==13854==    at 0x1C8988D: dtuple_get_nth_field(dtuple_t const*, unsigned long) (data0data.ic:431)
 
==13854==    by 0x1C8E89A: rtr_page_split_initialize_nodes(mem_block_info_t*, btr_cur_t*, unsigned long**, dtuple_t const*, double**) (gis0rtree.cc:111)
 
==13854==    by 0x1C90D43: rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (gis0rtree.cc:1062)
 
==13854==    by 0x1B5BADA: btr_root_raise_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (btr0btr.cc:1768)
 
==13854==    by 0x1B766EC: btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) (btr0cur.cc:3424)
 
==13854==    by 0x1C8FF63: rtr_adjust_upper_level(btr_cur_t*, unsigned long, buf_block_t*, buf_block_t*, rtr_mbr*, rtr_mbr*, unsigned long, mtr_t*) (gis0rtree.cc:730)
 
==13854==    by 0x1C916C4: rtr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (gis0rtree.cc:1275)
 
==13854==    by 0x1B5D6CD: btr_page_split_and_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t const*, unsigned long, mtr_t*) (btr0btr.cc:2546)
 
==13854==    by 0x1B76729: btr_cur_pessimistic_insert(unsigned long, btr_cur_t*, unsigned long**, mem_block_info_t**, dtuple_t*, unsigned char**, big_rec_t**, unsigned long, que_thr_t*, mtr_t*) (btr0cur.cc:3427)
 
==13854==    by 0x1A43DAE: row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*, bool) (row0ins.cc:3193)
 
==13854==    by 0x1A447F2: row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) (row0ins.cc:3443)
 
==13854==    by 0x1A448EA: row_ins_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) (row0ins.cc:3477)
 
==13854==    by 0x1A44E29: row_ins_index_entry_step(ins_node_t*, que_thr_t*) (row0ins.cc:3625)
 
==13854==    by 0x1A451B9: row_ins(ins_node_t*, que_thr_t*) (row0ins.cc:3767)
 
==13854==    by 0x1A457DC: row_ins_step(que_thr_t*) (row0ins.cc:3952)
 
==13854==    by 0x1A647E2: row_insert_for_mysql_using_ins_graph(unsigned char const*, row_prebuilt_t*) (row0mysql.cc:1738)

I am only including the first warning here. The UNIV_MEM_ALLOC would declare the memory uninitialized, but addressable. The stack trace seems equivalent to what was reported by AddressSanitizer. In MariaDB, UNIV_MEM_FREE would declare the memory non-addressable in both Valgrind and AddressSanitizer.

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