Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1(EOL), 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5
-
None
Description
To repeat:
=========
LD_LIBRARY_PATH=/bug_repo/llvm-toolchain-9-9/libc++msan/lib/ ./mtr rpl_parallel_conflicts --repeat 3
Logging: bug_repo/test-10.5-msan/mysql-test/mysql-test-run.pl rpl_parallel_conflicts --repeat 3
|
vardir: /bug_repo/test-10.5-msan/bld/mysql-test/var
|
Checking leftover processes...
|
Removing old var directory...
|
Creating var directory '/bug_repo/test-10.5-msan/bld/mysql-test/var'...
|
Checking supported features...
|
MariaDB Version 10.5.4-MariaDB-debug
|
- SSL connections supported
|
- binaries are debug compiled
|
- binaries built with wsrep patch
|
Collecting tests...
|
Installing system database...
|
|
|
==============================================================================
|
|
|
TEST RESULT TIME (ms) or COMMENT
|
--------------------------------------------------------------------------
|
|
|
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
|
rpl.rpl_parallel_conflicts 'innodb,mix' [ pass ] 4165
|
rpl.rpl_parallel_conflicts 'innodb,mix' [ 2 pass ] 4391
|
rpl.rpl_parallel_conflicts 'innodb,mix' [ 3 pass ] 4616
|
rpl.rpl_parallel_conflicts 'innodb,row' [ fail ]
|
Test ended at 2020-06-05 11:14:48
|
|
|
CURRENT_TEST: rpl.rpl_parallel_conflicts
|
mysqltest: In included file "./include/sync_with_master_gtid.inc":
|
included from /home/sujatha/bug_repo/test-10.5-msan/mysql-test/suite/rpl/t/rpl_parallel_conflicts.test at line 203:
|
At line 43: query 'let $_result= `SELECT master_gtid_wait('$master_pos', $_slave_timeout)`' failed: 2013: Lost connection to MySQL server during query
|
|
|
The result from queries just before the failure was:
|
< snip >
|
81 81
|
83 83
|
85 85
|
87 87
|
88 88
|
89 89
|
90 90
|
91 91
|
92 92
|
93 93
|
94 94
|
95 95
|
96 96
|
97 97
|
98 98
|
99 99
|
include/save_master_gtid.inc
|
connection server_2;
|
include/start_slave.inc
|
include/sync_with_master_gtid.inc
|
2020-06-05 11:14:47 5 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='16000', master_log_file='master-bin.000001', master_log_pos='4'.
|
2020-06-05 11:14:47 7 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16000' in log 'master-bin.000001' at position 4
|
2020-06-05 11:14:47 8 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
|
2020-06-05 11:14:47 7 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication started in log 'master-bin.000001' at position 4
|
2020-06-05 11:14:48 8 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 814
|
2020-06-05 11:14:48 7 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 814
|
2020-06-05 11:14:48 11 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16000' in log 'master-bin.000001' at position 814
|
2020-06-05 11:14:48 11 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication started in log 'master-bin.000001' at position 814
|
2020-06-05 11:14:48 12 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 814, relay log './slave-relay-bin.000002' position: 1114
|
Uninitialized bytes in __interceptor_write at offset 57 inside [0x725000041018, 114)
|
Uninitialized bytes in __interceptor_write at offset 57 inside [0x725000041018, 114)
|
==17820==WARNING: MemorySanitizer: use-of-uninitialized-value
|
#0 0x5586cf8317ec in my_write /home/sujatha/bug_repo/test-10.5-msan/mysys/my_write.c:49:19
|
#1 0x5586cf75c126 in inline_mysql_file_write /home/sujatha/bug_repo/test-10.5-msan/include/mysql/psi/mysql_file.h:1166:13
|
#2 0x5586cf75c126 in _my_b_cache_write /home/sujatha/bug_repo/test-10.5-msan/mysys/mf_iocache.c:1768:7
|
#3 0x5586cf74fa78 in my_b_flush_io_cache /home/sujatha/bug_repo/test-10.5-msan/mysys/mf_iocache.c:1967:18
|
#4 0x5586ccc37e07 in Relay_log_info::flush() /home/sujatha/bug_repo/test-10.5-msan/sql/rpl_rli.cc:2595:7
|
#5 0x5586ccc40cdf in Relay_log_info::stmt_done(unsigned long long, THD*, rpl_group_info*) /home/sujatha/bug_repo/test-10.5-msan/sql/rpl_rli.cc:1476:11
|
#6 0x5586cd8cd65b in Log_event::do_update_pos(rpl_group_info*) /home/sujatha/bug_repo/test-10.5-msan/sql/log_event_server.cc:628:12
|
#7 0x5586cc25e1b7 in Log_event::update_pos(rpl_group_info*) /home/sujatha/bug_repo/test-10.5-msan/sql/log_event.h:1512:12
|
#8 0x5586cc25e1b7 in apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int) /home/sujatha/bug_repo/test-10.5-msan/sql/slave.cc:4055:20
|
#9 0x5586cce63536 in rpt_handle_event(rpl_parallel_thread::queued_event*, rpl_parallel_thread*) /home/sujatha/bug_repo/test-10.5-msan/sql/rpl_parallel.cc:61:8
|
#10 0x5586cce554e8 in handle_rpl_parallel_thread /home/sujatha/bug_repo/test-10.5-msan/sql/rpl_parallel.cc:1342:18
|
#11 0x5586ce145b29 in pfs_spawn_thread /home/sujatha/bug_repo/test-10.5-msan/storage/perfschema/pfs.cc:2201:3
|
#12 0x7f48d68796da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
|
#13 0x7f48d53c588e in clone /build/glibc-OTsEL5/glibc-2.27/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
Memory was marked as uninitialized
|
#0 0x5586cc0ffa4e in __msan_allocated_memory (/home/sujatha/bug_repo/test-10.5-msan/bld/sql/mariadbd+0x6dfa4e)
|
#1 0x5586cf81e2b6 in my_malloc /home/sujatha/bug_repo/test-10.5-msan/mysys/my_malloc.c:111:7
|
|
|
SUMMARY: MemorySanitizer: use-of-uninitialized-value /home/sujatha/bug_repo/test-10.5-msan/mysys/my_write.c:49:19 in my_write
|
Exiting
|
==17820==WARNING: MemorySanitizer: use-of-uninitialized-value
|
----------SERVER LOG END-------------
|
Attachments
Activity
Hello Andrei,
Thank you for the suggestion.
Please review the 10.1 changes.
Patch: https://github.com/MariaDB/server/commit/ad14a2821883b11228885253672ce4967ef4d55d
BuildBot: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha
Left this on GH:
The patch is good and does not need any changes to 10.1-10.5. Yet in 10.6
I suggest relocate `flush_relay_log_info()` into `inc_group_relay_log_pos()`
to avoid two times mysql_mutex_lock(&data_lock).
The patch approved for 10.1, but in 10.6 we should try to improve it.
Fix is pushed into 10.1.46.
In 10.2 minor merge conflict will be there, as function name has changed.
Function name in 10.1 "flush_relay_log_info(this)" has been changed to "flush()" in 10.2.
10.2 Patch: https://github.com/MariaDB/server/commit/0e0d8d6dd01c2ff4ce85929f447077dfa85eb821
Patch remains the same for higher versions. All have been tested on buildbot.
10.3: https://github.com/MariaDB/server/commit/64f217e26b1310094dab1fc01b514244aa3f3bbd
10.4: https://github.com/MariaDB/server/commit/d9370e21e00d2af64fb0e2fd2a848dd2bfde3c10
10.5: https://github.com/MariaDB/server/commit/697b6c5a6280da10ccde095f5ccb936588f54e9a
The bug is in that flush() (of 10.5) or flush_relay_log_info() (of 10.1) are invoked by Workers
concurrently.
Unlike the slave execution status which may be updated by Workers in Relay_log_info::stmt_done() after they
acquire mutex on rgi->rli->data_lock. That suggests how to fix.