MySQL Bugs: #51987: revoke privileges logs wrong error code

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

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.

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.

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.

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

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)

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.

Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)

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)

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)

Also documented in the 5.5.5 and 6.0.14 changelogs; closed.

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)

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)

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)