Percona Server moved to https://jira.percona.com/projects/PS

  1. Series 5.1
  2. Bug #904714
  3. Comment #5

Comment 5 for bug 904714

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

An instance of failure:

CURRENT_TEST: rpl.percona_bug860910
mysqltest: In included file "./include/check_slave_param.inc":
included from ./include/check_slave_param.inc at line 32:
At line 31: Wrong value for slave parameter

The result from queries just before the failure was:
*** Set up master (server_1) <-> master (server_2) replication ***
include/rpl_init.inc [topology=1->2->1]

SELECT @@global.log_slave_updates;
@@global.log_slave_updates
1
SELECT @@global.log_slave_updates;
@@global.log_slave_updates
1
CREATE TABLE t1(a INT);
SET @var:=0;
INSERT INTO t1 VALUES (@var);
INSERT INTO t1 VALUES (1);
DROP TABLE t1;
include/rpl_sync.inc
include/check_slave_param.inc [Exec_Master_Log_Pos]

############################## server_1 ##############################

**** SHOW WARNINGS on server_1 ****
SHOW WARNINGS;
Level Code Message

**** SELECT replication-related variables on server_1 ****
SELECT NOW(), @@SERVER_ID;
NOW() @@SERVER_ID
2016-08-30 19:44:31 1

**** SHOW SLAVE STATUS on server_1 ****
SHOW SLAVE STATUS;
Slave_IO_State Waiting for master to send event
Master_Host 127.0.0.1
Master_User root
Master_Port 13022
Connect_Retry 1
Master_Log_File slave-bin.000001
Read_Master_Log_Pos 107
Relay_Log_File mysqld-relay-bin.000002
Relay_Log_Pos 253
Relay_Master_Log_File slave-bin.000001
Slave_IO_Running Yes
Slave_SQL_Running Yes
Replicate_Do_DB
Replicate_Ignore_DB
Replicate_Do_Table
Replicate_Ignore_Table
Replicate_Wild_Do_Table
Replicate_Wild_Ignore_Table
Last_Errno 0
Last_Error
Skip_Counter 0
Exec_Master_Log_Pos 107
Relay_Log_Space 410
Until_Condition None
Until_Log_File
Until_Log_Pos 0
Master_SSL_Allowed No
Master_SSL_CA_File
Master_SSL_CA_Path
Master_SSL_Cert
Master_SSL_Cipher
Master_SSL_Key
Seconds_Behind_Master 0
Master_SSL_Verify_Server_Cert No
Last_IO_Errno 0
Last_IO_Error
Last_SQL_Errno 0
Last_SQL_Error
Replicate_Ignore_Server_Ids
Master_Server_Id 2

**** SHOW MASTER STATUS on server_1 ****
SHOW MASTER STATUS;
File master-bin.000001
Position 720
Binlog_Do_DB
Binlog_Ignore_DB

**** SHOW SLAVE HOSTS on server_1 ****
SHOW SLAVE HOSTS;
Server_id 2
Host 127.0.0.1
Port 13022
Master_id 1

**** SHOW PROCESSLIST on server_1 ****
SHOW PROCESSLIST;
Id User Host db Command Time State Info Rows_sent Rows_examined Rows_read
11 root localhost test Sleep 0 NULL 1 0 0
12 root localhost:40023 test Query 0 NULL SHOW PROCESSLIST 0 0 0
13 root localhost:40024 test Sleep 0 NULL 1 0 0
14 root localhost:40025 NULL Binlog Dump 0 Master has sent all binlog to slave; waiting for binlog to be updated NULL 0 0 0
15 system user NULL Connect 0 Waiting for master to send event NULL 0 0 0
16 system user NULL Connect 0 Slave has read all relay log; waiting for the slave I/O thread to update it NULL 0 0 0

**** SHOW BINARY LOGS on server_1 ****
SHOW BINARY LOGS;
Log_name File_size
master-bin.000001 720

**** SHOW BINLOG EVENTS on server_1 ****
binlog_name = 'master-bin.000001'
SHOW BINLOG EVENTS IN 'master-bin.000001';
Log_name Pos Event_type Server_id End_log_pos Info
master-bin.000001 4 Format_desc 1 107 Server ver: 5.5.51-38.1-log, Binlog ver: 4
master-bin.000001 107 Query 1 192 use `test`; CREATE TABLE t1(a INT)
master-bin.000001 192 Query 1 260 BEGIN
master-bin.000001 260 Table_map 1 301 table_id: 44 (test.t1)
master-bin.000001 301 Write_rows 1 335 table_id: 44 flags: STMT_END_F
master-bin.000001 335 Query 1 404 COMMIT
master-bin.000001 404 Query 1 472 BEGIN
master-bin.000001 472 Table_map 1 513 table_id: 44 (test.t1)
master-bin.000001 513 Write_rows 1 547 table_id: 44 flags: STMT_END_F
master-bin.000001 547 Query 1 616 COMMIT
master-bin.000001 616 Query 1 720 use `test`; DROP TABLE `t1` /* generated by server */

**** SHOW RELAYLOG EVENTS on server_1 ****
relaylog_name = 'mysqld-relay-bin.000002'
SHOW RELAYLOG EVENTS IN 'mysqld-relay-bin.000002';
Log_name Pos Event_type Server_id End_log_pos Info
mysqld-relay-bin.000002 4 Format_desc 1 107 Server ver: 5.5.51-38.1-log, Binlog ver: 4
mysqld-relay-bin.000002 107 Rotate 2 0 slave-bin.000001;pos=4
mysqld-relay-bin.000002 150 Format_desc 2 107 Server ver: 5.5.51-38.1-log, Binlog ver: 4

############################## server_2 ##############################

**** SHOW WARNINGS on server_2 ****
SHOW WARNINGS;
Level Code Message

**** SELECT replication-related variables on server_2 ****
SELECT NOW(), @@SERVER_ID;
NOW() @@SERVER_ID
2016-08-30 19:44:31 2

**** SHOW SLAVE STATUS on server_2 ****
SHOW SLAVE STATUS;
Slave_IO_State Waiting for master to send event
Master_Host 127.0.0.1
Master_User root
Master_Port 13021
Connect_Retry 1
Master_Log_File master-bin.000001
Read_Master_Log_Pos 720
Relay_Log_File slave-relay-bin.000002
Relay_Log_Pos 867
Relay_Master_Log_File master-bin.000001
Slave_IO_Running Yes
Slave_SQL_Running Yes
Replicate_Do_DB
Replicate_Ignore_DB
Replicate_Do_Table
Replicate_Ignore_Table
Replicate_Wild_Do_Table
Replicate_Wild_Ignore_Table
Last_Errno 0
Last_Error
Skip_Counter 0
Exec_Master_Log_Pos 720
Relay_Log_Space 1023
Until_Condition None
Until_Log_File
Until_Log_Pos 0
Master_SSL_Allowed No
Master_SSL_CA_File
Master_SSL_CA_Path
Master_SSL_Cert
Master_SSL_Cipher
Master_SSL_Key
Seconds_Behind_Master 0
Master_SSL_Verify_Server_Cert No
Last_IO_Errno 0
Last_IO_Error
Last_SQL_Errno 0
Last_SQL_Error
Replicate_Ignore_Server_Ids
Master_Server_Id 1

**** SHOW MASTER STATUS on server_2 ****
SHOW MASTER STATUS;
File slave-bin.000001
Position 684
Binlog_Do_DB
Binlog_Ignore_DB

**** SHOW SLAVE HOSTS on server_2 ****
SHOW SLAVE HOSTS;
Server_id 1
Host
Port 13021
Master_id 2

**** SHOW PROCESSLIST on server_2 ****
SHOW PROCESSLIST;
Id User Host db Command Time State Info Rows_sent Rows_examined Rows_read
10 root localhost:43675 test Query 0 NULL SHOW PROCESSLIST 0 0 0
11 root localhost:43676 test Sleep 0 NULL 1 0 0
12 system user NULL Connect 0 Waiting for master to send event NULL 0 0 0
13 system user NULL Connect 0 Slave has read all relay log; waiting for the slave I/O thread to update it NULL 0 0 0
14 root localhost:43680 NULL Binlog Dump 0 Master has sent all binlog to slave; waiting for binlog to be updated NULL 0 0 0

**** SHOW BINARY LOGS on server_2 ****
SHOW BINARY LOGS;
Log_name File_size
slave-bin.000001 684

**** SHOW BINLOG EVENTS on server_2 ****
binlog_name = 'slave-bin.000001'
SHOW BINLOG EVENTS IN 'slave-bin.000001';
Log_name Pos Event_type Server_id End_log_pos Info
slave-bin.000001 4 Format_desc 2 107 Server ver: 5.5.51-38.1-log, Binlog ver: 4
slave-bin.000001 107 Query 1 192 use `test`; CREATE TABLE t1(a INT)
slave-bin.000001 192 Query 1 251 BEGIN
slave-bin.000001 251 Table_map 1 292 table_id: 44 (test.t1)
slave-bin.000001 292 Write_rows 1 326 table_id: 44 flags: STMT_END_F
slave-bin.000001 326 Query 1 386 COMMIT
slave-bin.000001 386 Query 1 445 BEGIN
slave-bin.000001 445 Table_map 1 486 table_id: 44 (test.t1)
slave-bin.000001 486 Write_rows 1 520 table_id: 44 flags: STMT_END_F
slave-bin.000001 520 Query 1 580 COMMIT
slave-bin.000001 580 Query 1 684 use `test`; DROP TABLE `t1` /* generated by server */

**** SHOW RELAYLOG EVENTS on server_2 ****
relaylog_name = 'slave-relay-bin.000002'
SHOW RELAYLOG EVENTS IN 'slave-relay-bin.000002';
Log_name Pos Event_type Server_id End_log_pos Info
slave-relay-bin.000002 4 Format_desc 2 107 Server ver: 5.5.51-38.1-log, Binlog ver: 4
slave-relay-bin.000002 107 Rotate 1 0 master-bin.000001;pos=4
slave-relay-bin.000002 151 Format_desc 1 107 Server ver: 5.5.51-38.1-log, Binlog ver: 4
slave-relay-bin.000002 254 Query 1 192 use `test`; CREATE TABLE t1(a INT)
slave-relay-bin.000002 339 Query 1 260 BEGIN
slave-relay-bin.000002 407 Table_map 1 301 table_id: 44 (test.t1)
slave-relay-bin.000002 448 Write_rows 1 335 table_id: 44 flags: STMT_END_F
slave-relay-bin.000002 482 Query 1 404 COMMIT
slave-relay-bin.000002 551 Query 1 472 BEGIN
slave-relay-bin.000002 619 Table_map 1 513 table_id: 44 (test.t1)
slave-relay-bin.000002 660 Write_rows 1 547 table_id: 44 flags: STMT_END_F
slave-relay-bin.000002 694 Query 1 616 COMMIT
slave-relay-bin.000002 763 Query 1 720 use `test`; DROP TABLE `t1` /* generated by server */
Wrong value for Exec_Master_Log_Pos. Expected '684', got '107'
safe_process[24228]: Child process: 24231, exit: 1

Server [mysqld.1 - pid: 24055, winpid: 24055] log:
Server log from this test:
----------SERVER LOG START-----------
160830 19:44:31 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13022', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13022', master_log_file='slave-bin.000001', master_log_pos='4'.
160830 19:44:31 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13022',replication started in log 'slave-bin.000001' at position 4
160830 19:44:31 [Note] Slave SQL thread initialized, starting replication in log 'slave-bin.000001' at position 4, relay log './mysqld-relay-bin.000001' position: 4
----------SERVER LOG END-------------

Server [mysqld.2 - pid: 24058, winpid: 24058] log:
Server log from this test:
----------SERVER LOG START-----------
160830 19:44:31 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='13021', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='13021', master_log_file='master-bin.000001', master_log_pos='4'.
160830 19:44:31 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:13021',replication started in log 'master-bin.000001' at position 4
160830 19:44:31 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
----------SERVER LOG END-------------