Description:
At moment of rotation of the relay log file the value of Seconds_Behind_Master is wrong. Test with with max-binlog-size=100M shows the following results:
15:29:59. Before rotation: Seconds_Behind_Master = 1
15:30:00. At moment of rotation: Seconds_Behind_Master = 149
15:30:00. After rotation: Seconds_Behind_Master = 2
The dumps below contain the current time and SHOW SLAVE STATUS at three moments in details:
mysql> select now(); show slave status\G
+---------------------+
| now() |
+---------------------+
| 2010-08-30 15:29:59 |
+---------------------+
1 row in set (0.00 sec)
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 127.0.0.1
Master_User: root
Master_Port: 10000
Connect_Retry: 60
Master_Log_File: 1.000002
Read_Master_Log_Pos: 2170
Relay_Log_File: vtop-relay-bin.000002
Relay_Log_Pos: 99195148
Relay_Master_Log_File: 1.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: 99195010
Relay_Log_Space: 101786354
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: 1
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
Master_UUID: 91ca26be-b429-11df-8456-0800272f46ab
Master_Info_File: /home/ksm/oracle/nuts/var/data/rep::general::general_basic-row/2/5.6.99-m5/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Reading event from the relay log
1 row in set (0.00 sec)
mysql> select now(); show slave status\G
+---------------------+
| now() |
+---------------------+
| 2010-08-30 15:30:00 |
+---------------------+
1 row in set (0.00 sec)
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 127.0.0.1
Master_User: root
Master_Port: 10000
Connect_Retry: 60
Master_Log_File: 1.000002
Read_Master_Log_Pos: 2170
Relay_Log_File: vtop-relay-bin.000002
Relay_Log_Pos: 99195148
Relay_Master_Log_File: 1.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: 99195010
Relay_Log_Space: 101786199
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: 149
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
Master_UUID: 91ca26be-b429-11df-8456-0800272f46ab
Master_Info_File: /home/ksm/oracle/nuts/var/data/rep::general::general_basic-row/2/5.6.99-m5/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Reading event from the relay log
1 row in set (0.03 sec)
mysql> select now(); show slave status\G
+---------------------+
| now() |
+---------------------+
| 2010-08-30 15:30:00 |
+---------------------+
1 row in set (0.00 sec)
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 127.0.0.1
Master_User: root
Master_Port: 10000
Connect_Retry: 60
Master_Log_File: 1.000002
Read_Master_Log_Pos: 2170
Relay_Log_File: vtop-relay-bin.000003
Relay_Log_Pos: 210
Relay_Master_Log_File: 1.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: 99195010
Relay_Log_Space: 101786199
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: 2
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
Master_UUID: 91ca26be-b429-11df-8456-0800272f46ab
Master_Info_File: /home/ksm/oracle/nuts/var/data/rep::general::general_basic-row/2/5.6.99-m5/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Reading event from the relay log
1 row in set (0.01 sec)
How to repeat:
1. Run master->slave replication
2. Generate statements on master
3. Run (and store results) on slave several times per second:
select now(); show slave status\G
4. Check results on slave at moment of relay log rotation.
Description: At moment of rotation of the relay log file the value of Seconds_Behind_Master is wrong. Test with with max-binlog-size=100M shows the following results: 15:29:59. Before rotation: Seconds_Behind_Master = 1 15:30:00. At moment of rotation: Seconds_Behind_Master = 149 15:30:00. After rotation: Seconds_Behind_Master = 2 The dumps below contain the current time and SHOW SLAVE STATUS at three moments in details: mysql> select now(); show slave status\G +---------------------+ | now() | +---------------------+ | 2010-08-30 15:29:59 | +---------------------+ 1 row in set (0.00 sec) *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: root Master_Port: 10000 Connect_Retry: 60 Master_Log_File: 1.000002 Read_Master_Log_Pos: 2170 Relay_Log_File: vtop-relay-bin.000002 Relay_Log_Pos: 99195148 Relay_Master_Log_File: 1.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: 99195010 Relay_Log_Space: 101786354 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: 1 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 Master_UUID: 91ca26be-b429-11df-8456-0800272f46ab Master_Info_File: /home/ksm/oracle/nuts/var/data/rep::general::general_basic-row/2/5.6.99-m5/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Reading event from the relay log 1 row in set (0.00 sec) mysql> select now(); show slave status\G +---------------------+ | now() | +---------------------+ | 2010-08-30 15:30:00 | +---------------------+ 1 row in set (0.00 sec) *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: root Master_Port: 10000 Connect_Retry: 60 Master_Log_File: 1.000002 Read_Master_Log_Pos: 2170 Relay_Log_File: vtop-relay-bin.000002 Relay_Log_Pos: 99195148 Relay_Master_Log_File: 1.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: 99195010 Relay_Log_Space: 101786199 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: 149 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 Master_UUID: 91ca26be-b429-11df-8456-0800272f46ab Master_Info_File: /home/ksm/oracle/nuts/var/data/rep::general::general_basic-row/2/5.6.99-m5/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Reading event from the relay log 1 row in set (0.03 sec) mysql> select now(); show slave status\G +---------------------+ | now() | +---------------------+ | 2010-08-30 15:30:00 | +---------------------+ 1 row in set (0.00 sec) *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: root Master_Port: 10000 Connect_Retry: 60 Master_Log_File: 1.000002 Read_Master_Log_Pos: 2170 Relay_Log_File: vtop-relay-bin.000003 Relay_Log_Pos: 210 Relay_Master_Log_File: 1.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: 99195010 Relay_Log_Space: 101786199 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: 2 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 Master_UUID: 91ca26be-b429-11df-8456-0800272f46ab Master_Info_File: /home/ksm/oracle/nuts/var/data/rep::general::general_basic-row/2/5.6.99-m5/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Reading event from the relay log 1 row in set (0.01 sec) How to repeat: 1. Run master->slave replication 2. Generate statements on master 3. Run (and store results) on slave several times per second: select now(); show slave status\G 4. Check results on slave at moment of relay log rotation.