SHOW SLAVE STATUS gives wrong output with master-master and using SET uservars
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
MariaDB |
New
|
Undecided
|
Unassigned | ||
MySQL Server |
Unknown
|
Unknown
|
|||
Percona Server moved to https://jira.percona.com/projects/PS |
Fix Released
|
Undecided
|
Alexey Kopytov | ||
5.1 |
Fix Released
|
Undecided
|
Alexey Kopytov | ||
5.5 |
Fix Released
|
Undecided
|
Alexey Kopytov |
Bug Description
Description:
In a master-master setup, a master can show a wrong 'SHOW SLAVE STATUS' output.
Requirements:
- master-master
- log_slave_updates
This is caused when using SET user-variables. and then using it to perform writes.
From then on the master that performed the insert will have a SHOW SLAVE STATUS that is
wrong and it will never update again until a write happens on the other master.
How to repeat:
### set up a masterA(serverid 1)<->masterB(
### enable log-slave-updates on both databasegs
### execute on masterA:
create database test;
use test;
create table test3 (a int);
set @`test`:=0;
insert into test3 values (@test);
### To make it clearer, run the insert statement multiple times. You can even do any
other write you want! doesn't have to be related to test or use a variable.
### run 'show master status' on masterB
masterB> show master status;
+------
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------
| masterB .000004 | 540 | | |
+------
### run 'show slave status' on masterA
masterA> SHOW SLAVE STATUS\G
*******
Slave_IO_State: Waiting for master to send event
Master_Host: localhost
Master_User: r
Master_Port: 3309
Connect_Retry: 60
Master_Log_File: masterB.000004
Read_Master_
Relay_Log_File: masterA-
Relay_Log_Pos: 255
Relay_Master_
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_
Replicate_Do_Table:
Replicate_
Replicate_
Replicate_
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_
Relay_Log_Space: 606
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_
Master_
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_
Master_Server_Id: 1
==> masterA displays that it's waiting for master to send events on an old
exec_master_log_pos
### cat relay-log.info and master.info on masterA
Example:
$ cat masterA/master.info
18
masterB.000004
5261
localhost
r
r
3309
60
0.000
$ cat masterA/
./masterB-
255
masterB.000004
313
$ stat masterA/
File: `2/relay-log.info'
Size: 54 Blocks: 8 IO Block: 4096 regular file
Device: 801h/2049d Inode: 796981 Links: 1
Access: (0660/-rw-rw----) Uid: ( 1000/ gryp) Gid: ( 1000/ gryp)
Access: 2011-09-27 16:59:45.863435966 +0200
Modify: 2011-09-27 16:53:06.874040990 +0200
Change: 2011-09-27 16:53:06.874040990 +0200
$ stat masterA/master.info
File: `2/master.info'
Size: 67 Blocks: 8 IO Block: 4096 regular file
Device: 801h/2049d Inode: 796979 Links: 1
Access: (0660/-rw-rw----) Uid: ( 1000/ gryp) Gid: ( 1000/ gryp)
Access: 2011-09-27 16:59:44.222616027 +0200
Modify: 2011-09-27 16:58:06.323690973 +0200
Change: 2011-09-27 16:58:06.323690973 +0200
==> masterA it's relay-log.info file is not updated anymore but master.info is.
### select * from test.test3 and you can see that all writes will be in there.
masterA> select * from test3;
+------+
| a |
+------+
| 0 |
+------+
1 row in set (0.00 sec)
### Actually the relay log should be empty as it should filter out it's own writes, but
the SET commands are in there, with the masterB serverid: 1
#110927 16:53:06 server id 1 end_log_pos 418 User_var
SET @`test`:=0/*!*/;
### The binary log of masterB will contain something like this,you can see that the SET
commands have changed to it's own serverid:
DROP TABLE IF EXISTS `test3` /* generated by server */
/*!*/;
# at 224
#110927 16:53:06 server id 2 end_log_pos 313 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=
create table test3 (a int)
/*!*/;
# at 313
#110927 16:53:06 server id 2 end_log_pos 372 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=
BEGIN
/*!*/;
# at 372
#110927 16:53:06 server id 1 end_log_pos 418 User_var
SET @`test`:=0/*!*/;
# at 418
#110927 16:53:06 server id 2 end_log_pos 513 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=
insert into test3 values (@test)
/*!*/;
# at 513
#110927 16:53:06 server id 2 end_log_pos 540 Xid = 22
COMMIT/*!*/;
# at 540
#110927 16:57:56 server id 2 end_log_pos 599 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=
BEGIN
/*!*/;
# at 599
#110927 16:57:56 server id 1 end_log_pos 645 User_var
SET @`test`:=0/*!*/;
# at 645
#110927 16:57:56 server id 2 end_log_pos 740 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=
insert into test3 values (@test)
/*!*/;
# at 740
#110927 16:57:56 server id 2 end_log_pos 767 Xid = 30
COMMIT/*!*/;
I have verified this under the following mysql versions:
- mysql-5.1.59
- mysql-5.5.16
- Percona Server 5.1.57-rel12.8
- MariaDB 5.2.7
- MariaDB 5.2.8
I also reported this @ bugs.mysql.com: http://
Related branches
- Laurynas Biveinis (community): Approve
-
Diff: 105 lines (+93/-0)2 files modifiedpatches/bug860910.patch (+92/-0)
patches/series (+1/-0)
- Laurynas Biveinis (community): Approve
-
Diff: 105 lines (+93/-0)2 files modifiedpatches/bug860910.patch (+92/-0)
patches/series (+1/-0)
Changed in percona-server: | |
status: | New → In Progress |
assignee: | nobody → Alexey Kopytov (akopytov) |
milestone: | none → 5.1.60-13.1 |
Changed in percona-server: | |
status: | In Progress → Fix Committed |
tags: | added: upstream |
See bug 1132109.