Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2.2, 10.3.0, 10.4.0
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.
Attachments
Issue Links
- is duplicated by
-
-
- Closed
-
- relates to
-
MDEV-11369 Instant add column for InnoDB
-
- Closed
-
-
-
- Closed
-
-
-
- Confirmed
-
Activity
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).
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.
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_compressmysqltest: 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 0x7fd69c6899c8READ 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:11Thread 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:15SUMMARY: 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 fa0x0c3480042db0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa0x0c3480042dc0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa0x0c3480042dd0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 000x0c3480042de0: 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 f70x0c3480042e00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f70x0c3480042e10: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f70x0c3480042e20: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f70x0c3480042e30: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f70x0c3480042e40: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7Shadow byte legend (one shadow byte represents 8 application bytes):Addressable: 00Partially addressable: 01 02 03 04 05 06 07Heap left redzone: faFreed heap region: fdStack left redzone: f1Stack mid redzone: f2Stack right redzone: f3Stack after return: f5Stack use after scope: f8Global redzone: f9Global init order: f6Poisoned by user: f7Other 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