Bug #51987 revoke privileges logs wrong error code
Submitted: 12 Mar 2010 11:45 Modified: 21 Jun 2010 0:56
Reporter: Axel Schwenke Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.1.40 OS:Any
Assigned to: Luis Soares CPU Architecture:Any
Triage: Triaged: D2 (Serious)

[12 Mar 2010 11:45] Axel Schwenke
Description:
A failed REVOKE statement is logged with error=0 and thus causes the slave to stop when it fails there too.

How to repeat:
On master:

grant all on *.* to foo@"1.2.3.4";
Query OK, 0 rows affected (0,00 sec)

revoke all privileges, grant option from "foo";
ERROR 1269 (HY000): Can't revoke all privileges for one or more of the requested users

Causes on slave:

show slave status\G
Slave_SQL_Running: No
Last_SQL_Errno: 1269
Last_SQL_Error: Error 'Can't revoke all privileges for one or more of the requested users' on query. Default database: ''. Query: 'revoke all privileges, grant option from "foo"'

Binlog:

# at 106
#100312 12:38:05 server id 1  end_log_pos 198   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1268393885/*!*/;
SET @@session.pseudo_thread_id=1/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
grant all on *.* to foo@"1.2.3.4"
/*!*/;
# at 198
#100312 12:38:21 server id 1  end_log_pos 303   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1268393901/*!*/;
revoke all privileges, grant option from "foo"
/*!*/;
DELIMITER ;
# End of log file

Suggested fix:
The statement yields error 1269 on both master and slave. It should also be logged with this error.
[15 Mar 2010 9:04] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/103184

3400 Luis Soares	2010-03-15
      BUG#51987: revoke privileges logs wrong error code
      
      A failed REVOKE statement is logged with error=0, thus causing
      the slave to stop. The slave should not stop as this was an
      expected error. Given that the execution failed on the master as
      well the error code should be logged so that the slave can replay
      the statement, get an error and compare with the master's
      execution outcome. If errors match, then slave can proceed with
      replication, as the error it got, when replaying the statement,
      was expected.
      
      In this particular case, the bug surfaces because the error code
      is pushed to the THD diagnostics area after writing the event to
      the binary log. Therefore, it would be logged with the THD
      diagnostics area clean, hence its error code would not contain 
      the correct code.
      
      We fix this by moving the error reporting ahead of the call to
      the routine that writes the event to the binary log.
[22 Mar 2010 9:51] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/103946

3415 Luis Soares	2010-03-22
      BUG#51987: revoke privileges logs wrong error code
      
      A failed REVOKE statement is logged with error=0, thus causing
      the slave to stop. The slave should not stop as this was an
      expected error. Given that the execution failed on the master as
      well the error code should be logged so that the slave can replay
      the statement, get an error and compare with the master's
      execution outcome. If errors match, then slave can proceed with
      replication, as the error it got, when replaying the statement,
      was expected.
      
      In this particular case, the bug surfaces because the error code
      is pushed to the THD diagnostics area after writing the event to
      the binary log. Therefore, it would be logged with the THD
      diagnostics area clean, hence its error code would not contain 
      the correct code.
      
      We fix this by moving the error reporting ahead of the call to
      the routine that writes the event to the binary log.
[16 Apr 2010 1:12] Luis Soares
Queued in mysql-5.1-bugteam and mysql-pe:
  - http://pb2.norway.sun.com/web.py?template=push_details&push=1172855
  - http://pb2.norway.sun.com/web.py?template=push_details&push=1172849
[5 May 2010 15:07] Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:kristofer.pettersson@sun.com-20100416145616-vdcdyz9eu7j86lp7) (merge vers: 5.1.47) (pib:16)
[6 May 2010 12:17] Jon Stephens
Documented bugfix in the 5.1.47 changelog as follows:

        The failure of a REVOKE statement was logged with the wrong
        error code, causing replication slaves to stop even when the
        failure was expected on the master.

NM - waiting for post-5.1 merges.
[28 May 2010 6:02] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)
[28 May 2010 6:30] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:alik@sun.com-20100422150658-fkhgnwwkyugtxrmu) (merge vers: 6.0.14-alpha) (pib:16)
[28 May 2010 6:58] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:alexey.kopytov@sun.com-20100429203306-tg0wz4y2xyx8edrl) (merge vers: 5.5.5-m3) (pib:16)
[3 Jun 2010 6:12] Jon Stephens
Also documented in the 5.5.5 and 6.0.14 changelogs; closed.
[17 Jun 2010 12:05] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:50] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:33] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)