| Bug #68892 | Invalid use of GRANT command breaks replication | ||
|---|---|---|---|
| Submitted: | 9 Apr 2013 0:05 | Modified: | 19 Sep 2013 14:16 |
| Reporter: | Maciej Dobrzanski | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S2 (Serious) |
| Version: | 5.6 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | grant, replication, revoke | ||
[10 Apr 2013 13:00]
MySQL Verification Team
Hello Maciej, Thank you for the report. Verified as described. Thanks, Umesh
[10 Apr 2013 13:01]
MySQL Verification Team
## invalid Grant breaks replication
## Master
mysql> show processlist;
+----+------+-----------------+------+-------------+------+-----------------------------------------------------------------------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------------+------+-------------+------+-----------------------------------------------------------------------+------------------+
| 1 | root | localhost:40250 | test | Query | 0 | init | show processlist |
| 2 | repl | localhost:36515 | NULL | Binlog Dump | 16 | Master has sent all binlog to slave; waiting for binlog to be updated | NULL |
+----+------+-----------------+------+-------------+------+-----------------------------------------------------------------------+------------------+
2 rows in set (0.00 sec)
mysql> GRANT FILE ON test.* TO test@127.0.0.1;
ERROR 1221 (HY000): Incorrect usage of DB GRANT and GLOBAL PRIVILEGES
## Slave
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: localhost
Master_User: repl
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: ushastry-bin.000002
Read_Master_Log_Pos: 120
Relay_Log_File: ushastry-relay-bin.000002
Relay_Log_Pos: 286
Relay_Master_Log_File: ushastry-bin.000001
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1590
Last_Error: The incident LOST_EVENTS occured on the master. Message: error writing to the binary log
Skip_Counter: 0
Exec_Master_Log_Pos: 817
Relay_Log_Space: 1087
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: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1590
Last_SQL_Error: The incident LOST_EVENTS occured on the master. Message: error writing to the binary log
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
Master_UUID: c837062c-a1d9-11e2-9ced-0800272e2cce
Master_Info_File: /tmp/5610slave_/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State:
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp: 130410 18:06:40
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set:
Executed_Gtid_Set:
Auto_Position: 0
1 row in set (0.00 sec)
#130410 18:06:40 server id 1 end_log_pos 874 CRC32 0x4d815dbc
# Incident: LOST_EVENTS
RELOAD DATABASE; # Shall generate syntax error
# at 874
#130410 18:06:40 server id 1 end_log_pos 924 CRC32 0x9079cacf Rotate to ushastry-bin.000002 pos: 4
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
[root@ushastry 5610_]# /home/ushastry/mybuilds/mysql-5.6.10/bin/mysqlbinlog -v --base64-output=DECODE-ROWS ushastry-bin.000002
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130410 18:06:40 server id 1 end_log_pos 120 CRC32 0x9d129815 Start: binlog v 4, server v 5.6.10-debug-log created 130410 18:06:40
# Warning: this binlog is either in use or was not closed properly.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
[root@ushastry 5610_]#
[30 Apr 2013 20:21]
Paul Court
Also seeing this in a 5.6.11 install. Not quite sure how the severity scales are generally used, but shouldn't a trivial command that breaks the one feature that is being splatted all over the homepage as having significant improvements be a little higher than "non-critical" ?
[30 May 2013 6:09]
Szilard Gyorgy
HI There is any update with this problem ? Every time when somebody change some rights the replication crash. Also the Second_behind_master value is flapping - in one moment I have 10000s a minute after 0 and after another one minute is back to 100000. And how can be Second_behind_master 0 when I use SQL_Delay: 3600 ? Best, Szilard Gyorgy
[8 Aug 2013 4:03]
Ronald Bradford
I am getting the same error with 5.6.13-log. Extremely annoying because now I have to fix 6 slaves, all because of an SQL Statement that should have failed and never sent to the binary log???? This is more then non-critical!
[9 Aug 2013 12:36]
Moritz Schuepp
Replication also breaks if you revoke the grant option from a database or table if the grant is not defined. mysql> REVOKE GRANT OPTION ON `testdb`.`test_table` FROM 'testuser'@'127.0.0.1'; ERROR 1141 (42000): There is no such grant defined for user 'testuser' on host '127.0.0.1' Leads to the same "Incident: LOST_EVENTS"-Entry in binary log and makes the slaves stop. phpMyAdmin for example removes the grant option by default if you modify user rights even if there is no grant option defined for that user, so Replication always breaks if you user phpMyAdmin to modify user rights for a certain table on which the user has no grant option.
[28 Aug 2013 11:07]
Jason Temple
Hello, This bug was created in April. Here we are with a critical bug (not listed here as such, but that is not relevant), and four months later, there has not been any resolution. Can we expect a patch for this any time, or should we just give up on ever issuing GRANT commands if we want to use replication? Thanks, Jason
[17 Sep 2013 2:25]
James Day
I've updated the severity from 3 to 2 to show the severity we've actually been using for this. The fix for this is likely to be released within a few months. As usual, issues found in testing could delay things, so don't count on it until it is actually released. James Day, MySQL Senior Principal Support Engineer, Oracle
[19 Sep 2013 14:16]
Jon Stephens
Fixed in 5.6+. Documented fix in the 5.6.15 and 5.7.3 changelogs, as follows:
Issuing a GRANT statement with invalid parameters caused the
master to write LOST_EVENTS events into its binary logs, causing
replication to stop. Now such cases, if one or more grants or
revocations of privileges are successful, an incident is written
to the log; otherwise, only a warning is logged.
Closed.
[4 Dec 2013 11:30]
Laurynas Biveinis
5.6$ bzr log -r 5449 ------------------------------------------------------------ revno: 5449 committer: Bill Qu <bill.qu@Oracle.com> branch nick: mysql-5.6 timestamp: Fri 2013-09-13 10:29:30 +0800 message: Bug #16629195 INVALID USE OF GRANT COMMAND BREAKS REPLICATION To failed REVOKE/GRANT statement, we wrote an incident event into binary log, which breaks replication on all slaves. Before ACLs are changed to execute fully or none at all, we go with the following fix, write an incident if one or more users are granted/revoked successfully (it has a partial execution), otherwise, do not write an incident, just log a warning. 5.6$ bzr log -r 5450 ------------------------------------------------------------ revno: 5450 committer: Bill Qu <bill.qu@Oracle.com> branch nick: mysql-5.6 timestamp: Fri 2013-09-13 14:24:17 +0800 message: Bug #16629195 INVALID USE OF GRANT COMMAND BREAKS REPLICATION Post-fix failed thread_pool.thread_pool_connect.
[8 Jan 2014 16:50]
Jeff Bilbro
We just hit this bug running 5.6.14. I see a fix is available, but that doesn't help me much right now. Can someone tell me how to get replication working again?
[9 Jun 2014 10:29]
Leandro Morgado
Jeff, if you don't need this GRANT to be executed on the slave, simply skip the event: http://dev.mysql.com/doc/refman/5.1/en/set-global-sql-slave-skip-counter.html Alternatively, you can look into executing the same GRANT on the slave to synchronize the master and slave user accounts. Please be careful with sql_slave_skip_counter as skipping the wrong transactions can cause master and slave to go out of sync. As a last resort, a rebuild of the slave will also work.
[11 Aug 2014 22:17]
Leandro Morgado
If using GTIDs, please see Scott's comment in Bug 69811: === [2 Jul 15:15] Scott Noyes The problem is that the LOST_EVENT does not have a GTID, so we can't replace it with an empty transaction. The workaround is to manually execute the next transaction, then reset replication. Use mysqlbinlog to find the next transaction. It is probably the first transaction in the next log file after the LOST_EVENT. Copy everything up to the COMMIT for that transaction, being sure to include the SET @@SESSION.GTID_NEXT. Even if you're using ROW format, you can still run BINLOG row events in the command line client. STOP SLAVE; Run the transaction copied above. The mysqlbinlog output sets the delimiter to /*!*/;, so set it back: DELIMITER ; SET GTID_NEXT=automatic; RESET SLAVE; START SLAVE; ====
[3 Mar 2017 18:01]
monty solomon
This happens on 5.7.17. Please update the documentation to reflect that this can happen and how to fix it when it does.
Slave_IO_State: Waiting for master to send event
Master_Host: bold-band
Master_User: SUSR_Repl
Master_Port: 3306
Connect_Retry: 15
Master_Log_File: bin.004161
Read_Master_Log_Pos: 44021782
Relay_Log_File: relay.002528
Relay_Log_Pos: 355
Relay_Master_Log_File: bin.004157
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1590
Last_Error: The incident LOST_EVENTS occured on the master. Message: REVOKE/GRANT failed while granting/revoking privileges in databases.
[3 Mar 2017 18:24]
Paul Court
Wait a min, this is still happening 4 YEARS LATER, and the fix is "put a work around in the docs"!?
[3 Mar 2017 19:20]
monty solomon
The previous comments in this bug report are how to work around the bug.
[3 Mar 2017 19:45]
monty solomon
Here are the entries from the relay log files. relay.002528 # at 355 #170227 21:58:00 server id 3569742263 end_log_pos 368 CRC32 0xd7679266 # Incident: LOST_EVENTS RELOAD DATABASE; # Shall generate syntax error # at 449 #170228 18:27:44 server id 3152558033 end_log_pos 492 CRC32 0xcca5a878 Rotate to relay.002529 pos: 4 relay.002530 # at 355 #170227 21:58:00 server id 3569742263 end_log_pos 368 CRC32 0xd7679266 # Incident: LOST_EVENTS RELOAD DATABASE; # Shall generate syntax error # at 449 #170228 18:27:44 server id 3152558033 end_log_pos 492 CRC32 0xdb65110b Rotate to relay.002531 pos: 4 relay.002532 # at 887854 #170227 22:38:49 server id 3569742263 end_log_pos 887867 CRC32 0x88d1b178 # Incident: LOST_EVENTS RELOAD DATABASE; # Shall generate syntax error # at 887948 #170228 18:27:44 server id 3152558033 end_log_pos 887991 CRC32 0x19a4330f Rotate to relay.002533 pos: 4 relay.002534 # at 2432 #170227 22:38:54 server id 3569742263 end_log_pos 2405 CRC32 0x071799a4 # Incident: LOST_EVENTS RELOAD DATABASE; # Shall generate syntax error # at 2526 #170228 18:27:44 server id 3152558033 end_log_pos 2569 CRC32 0x11addf2a Rotate to relay.002535 pos: 4
Description: Issuing a GRANT statement with invalid parameters causes master to write LOST_EVENTS event into its binary logs, which effectively breaks replication on all slaves: *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 18675 Connect_Retry: 60 Master_Log_File: mysql-bin.000003 Read_Master_Log_Pos: 120 Relay_Log_File: mysql_sandbox18676-relay-bin.000004 Relay_Log_Pos: 283 Relay_Master_Log_File: mysql-bin.000002 Slave_IO_Running: Yes Slave_SQL_Running: No Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 1590 Last_Error: The incident LOST_EVENTS occured on the master. Message: error writing to the binary log Skip_Counter: 0 Exec_Master_Log_Pos: 120 Relay_Log_Space: 1155 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: NULL Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 1590 Last_SQL_Error: The incident LOST_EVENTS occured on the master. Message: error writing to the binary log Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_UUID: 4d9b6b99-a0a4-11e2-950b-00270e0ffdb6 Master_Info_File: /home/psce/sandboxes/rsandbox_mysql-5_6_10/node1/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: 130409 01:54:13 Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 How to repeat: Issue the following statement: master [localhost] {root} (mysql) > GRANT FILE ON test.* TO test@127.0.0.1; ERROR 1221 (HY000): Incorrect usage of DB GRANT and GLOBAL PRIVILEGES Instead of writing the bad statement or ignoring it altogether, MySQL writes the following event into the binary log: #130409 1:54:13 server id 1 end_log_pos 177 CRC32 0x110405fc # Incident: LOST_EVENTS RELOAD DATABASE; # Shall generate syntax error # at 177