Test rpl.rpl_server_uuid is unstable
Affects | Status | Importance | Assigned to | Milestone | ||
---|---|---|---|---|---|---|
Percona Server moved to https://jira.percona.com/projects/PS | Status tracked in 5.7 | |||||
5.5 |
New
|
Undecided
|
Unassigned | |||
5.6 |
Fix Released
|
Low
|
Laurynas Biveinis | |||
5.7 |
Fix Released
|
Low
|
Laurynas Biveinis |
Bug Description
On 5.6 trunk:
rpl.rpl_server_uuid 'mix' w3 [ fail ]
Test ended at 2017-04-04 09:00:00
CURRENT_TEST: rpl.rpl_server_uuid
mysqltest: In included file "./include/
included from ./include/
At line 149: assert_grep.inc failed.
...
**** SHOW SLAVE STATUS on server_2 ****
...
Slave_IO_Running No
...
Last_IO_Errno 1236
Last_IO_Error Got fatal error 1236 from master when reading data from binary log: 'A slave with the same server_
...
**** SHOW SLAVE STATUS on server_3 ****
SHOW SLAVE STATUS;
Slave_IO_State Waiting for master to send event
...
**** SHOW PROCESSLIST on server_1 ****
SHOW PROCESSLIST;
Id User Host db Command Time State Info Rows_sent Rows_examined
1 root localhost test Sleep 8 NULL 411 411
2 root localhost:36026 test Sleep 7 NULL 1 0
3 root localhost:36027 test Sleep 7 NULL 411 411
4 root localhost:36036 test Query 0 init SHOW PROCESSLIST 0 0
5 root localhost:36037 test Sleep 7 NULL 1 0
11 root localhost:36209 NULL Binlog Dump 0 Master has sent all binlog to slave; waiting for binlog to be updated NULL 0 0
...
include/
assert_text: 'Found the expected line in master's error log for server 2 disconnection'
assert_file: '/mnt/workspace
assert_select: 'found a zombie dump thread with the same UUID'
assert_match: ''
assert_count: '1'
assert_only_after: 'Start binlog_dump to master_
number of matching lines: 2
...
Server [mysqld.1 - pid: 18799, winpid: 18799] log:
Server log from this test:
----------SERVER LOG START-----------
...
2017-04-04 15:59:53 18800 [Note] Start binlog_dump to master_thread_id(9) slave_server(2), pos(master-
2017-04-04 15:59:53 18800 [Note] While initializing dump thread for slave with UUID <80fa2b30-
2017-04-04 15:59:53 18800 [Note] Start binlog_dump to master_
2017-04-04 16:00:00 18800 [Note] While initializing dump thread for slave with UUID <80fa2b30-
2017-04-04 16:00:00 18800 [Note] Start binlog_dump to master_
----------SERVER LOG END-------------
Server [mysqld.2 - pid: 17691, winpid: 17691] log:
Server log from this test:
----------SERVER LOG START-----------
...
2017-04-04 15:59:53 17692 [Note] Slave I/O thread: connected to master 'root@127.
2017-04-04 15:59:53 17692 [Warning] Slave SQL: If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
2017-04-04 15:59:53 17692 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 120, relay log './slave-
2017-04-04 16:00:00 17692 [ERROR] Error reading packet from server: A slave with the same server_
2017-04-04 16:00:00 17692 [ERROR] Slave I/O: Got fatal error 1236 from master when reading data from binary log: 'A slave with the same server_
2017-04-04 16:00:00 17692 [Note] Slave I/O thread exiting, read up to log 'master-
----------SERVER LOG END-------------
Server [mysqld.3 - pid: 19039, winpid: 19039] log:
Server log from this test:
----------SERVER LOG START-----------
...
2017-04-04 16:00:00 19040 [Note] Slave I/O thread: connected to master 'root@127.
The testcase connects server 2 to server 1 as a slave and then server 3 with the same UUID connects, disconnecting server 2. The testcase greps that there is one binlog zombie dump thread kill, but finds two. This can happen if server 3 receives ER_NET_ READ_INTERRUPTE D soon after its connect and is forced to silently reconnect.