Bug #14262 SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late (race cond)
Submitted: 24 Oct 2005 15:18 Modified: 9 Nov 2006 14:41
Reporter: Guilhem Bichot Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.0.15 OS:Linux (linux)
Assigned to: CPU Architecture:Any

[24 Oct 2005 15:18] Guilhem Bichot
Description:
By looking at the code: DROP PROCEDURE does:
      result= sp_drop_procedure(thd, lex->spname);
          ...
      switch (result)
      {
      case SP_OK:
        if (mysql_bin_log.is_open())
        {
          thd->clear_error();
          Query_log_event qinfo(thd, thd->query, thd->query_length, 0, FALSE);
          mysql_bin_log.write(&qinfo);
        }
So if between the sp_drop_procedure and the switch(), the procedure is re-created, we may have in binlog:
CREATE;
DROP;
while in fact the procedure does exist in the end. Recovery from binlogs will break, replication too.
Some locking should be done. For example CREATE PROCEDURE is probably ok because it writes to binlog while still holding a lock on the mysql.proc table.
This is just an example. DROP VIEW seems affected too.
The proper bugfix is to inspect all CREATE/DROP/ALTER of features added in 5.0 (routines, views, triggers) and fix all binlog race conditions which will be found.

How to repeat:
hard to repeat except by adding sleep().

Suggested fix:
This is just an example. DROP VIEW seems affected too.
The proper bugfix is to inspect all CREATE/DROP/ALTER of features added in 5.0 (routines, views, triggers) and fix all binlog race conditions which will be found.
[13 Sep 2006 17:14] Andrey Hristov
Mats, maybe Events in 5.1 have the same problem as SP in 5.0?
[22 Sep 2006 19:03] 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/12430

ChangeSet@1.2230, 2006-09-22 15:01:38-04:00, cmiller@zippy.cornsilk.net +8 -0
  Bug #14262: SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late \
  	(race cond)
  
  It was possible for one thread to interrupt a DDI statement and thereby get
  messages to the binlog out of order.  Consider:
  
  Connection 1: Drop table x
  Connection 2: Create or replace table x
  Connection 2: Log "Create or replace table x"
  Connection 1: Log "Drop table x"
  
  Local end would have table x, but the replicated slaves would not.
  
  The fix for this is to wrap all similar events in the same mutex.  Since we
  already use mutexes for the various parts of altering the server, this only
  entails moving the logging events down close to the action, inside the mutex
  protection.
[22 Sep 2006 19:36] 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/12433

ChangeSet@1.2230, 2006-09-22 15:37:52-04:00, cmiller@zippy.cornsilk.net +9 -0
  Bug #14262: SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late \
  	(race cond)
  
  It was possible for one thread to interrupt a Data Definition Language 
  statement and thereby get messages to the binlog out of order.  Consider:
  
  Connection 1: Drop table x
  Connection 2: Create or replace table x
  Connection 2: Log "Create or replace table x"
  Connection 1: Log "Drop table x"
  
  Local end would have table x, but the replicated slaves would not.
  
  The fix for this is to wrap all similar events in the same mutex.  Since we
  already use mutexes for the various parts of altering the server, this only
  entails moving the logging events down close to the action, inside the mutex
  protection.
[25 Sep 2006 21:07] 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/12504

ChangeSet@1.2230, 2006-09-25 17:09:28-04:00, cmiller@zippy.cornsilk.net +9 -0
  Bug #14262: SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late \
  	(race cond)
  
  It was possible for one thread to interrupt a Data Definition Language 
  statement and thereby get messages to the binlog out of order.  Consider:
  
  Connection 1: Drop table x
  Connection 2: Create or replace table x
  Connection 2: Log "Create or replace table x"
  Connection 1: Log "Drop table x"
  
  Local end would have table x, but the replicated slaves would not.
  
  The fix for this is to wrap all similar events in the same mutex.  Since we
  already use mutexes for the various parts of altering the server, this only
  entails moving the logging events down close to the action, inside the mutex
  protection.
[25 Sep 2006 22: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/12506

ChangeSet@1.2230, 2006-09-25 18:53:44-04:00, cmiller@zippy.cornsilk.net +10 -0
  Bug #14262: SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late \
  	(race cond)
  
  It was possible for one thread to interrupt a Data Definition Language 
  statement and thereby get messages to the binlog out of order.  Consider:
  
  Connection 1: Drop table x
  Connection 2: Create or replace table x
  Connection 2: Log "Create or replace table x"
  Connection 1: Log "Drop table x"
  
  Local end would have table x, but the replicated slaves would not.
  
  The fix for this is to wrap all similar events in the same mutex.  Since we
  already use mutexes for the various parts of altering the server, this only
  entails moving the logging events down close to the action, inside the mutex
  protection.
[28 Sep 2006 0:00] 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/12671

ChangeSet@1.2230, 2006-09-27 20:02:18-04:00, cmiller@zippy.cornsilk.net +9 -0
  Bug #14262: SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late \
  	(race cond)
  
  It was possible for one thread to interrupt a Data Definition Language 
  statement and thereby get messages to the binlog out of order.  Consider:
  
  Connection 1: Drop Foo x
  Connection 2: Create or replace Foo x
  Connection 2: Log "Create or replace Foo x"
  Connection 1: Log "Drop Foo x"
  
  Local end would have Foo x, but the replicated slaves would not.
  
  The fix for this is to wrap all DDL and logging of a kind in the same mutex.  
  Since we already use mutexes for the various parts of altering the server, 
  this only entails moving the logging events down close to the action, inside 
  the mutex protection.
[3 Oct 2006 17:41] 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/13030

ChangeSet@1.2230, 2006-10-03 13:38:25-04:00, cmiller@zippy.cornsilk.net +9 -0
  Bug #14262: SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late \
  	(race cond)
  
  It was possible for one thread to interrupt a Data Definition Language 
  statement and thereby get messages to the binlog out of order.  Consider:
  
  Connection 1: Drop Foo x
  Connection 2: Create or replace Foo x
  Connection 2: Log "Create or replace Foo x"
  Connection 1: Log "Drop Foo x"
  
  Local end would have Foo x, but the replicated slaves would not.
  
  The fix for this is to wrap all DDL and logging of a kind in the same mutex.  
  Since we already use mutexes for the various parts of altering the server, 
  this only entails moving the logging events down close to the action, inside 
  the mutex protection.
[12 Oct 2006 21:52] 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/13633

ChangeSet@1.2347, 2006-10-12 17:51:56-04:00, cmiller@zippy.cornsilk.net +3 -0
  Additional patch for 5.1 commit for Bug#14262.
[13 Oct 2006 20:31] 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/13684

ChangeSet@1.2305, 2006-10-13 16:31:36-04:00, cmiller@zippy.cornsilk.net +8 -0
  Revert patch for Bug#14262 .
[17 Oct 2006 15:06] 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/13806

ChangeSet@1.2307, 2006-10-17 11:06:11-04:00, cmiller@zippy.cornsilk.net +4 -0
  Fix previous bad patch for Bug#14262.
  
  Remove table engine qualification where it's unnecessary.
[26 Oct 2006 16:35] 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/14434

ChangeSet@1.2330, 2006-10-26 18:34:24+02:00, msvensson@neptunus.(none) +1 -0
  Bug #14262  	SP: DROP PROCEDURE|VIEW (maybe more) write to binlog too late (race cond)
  - Rmove duplicate code to log a "DROP VIEW..", must be a merge miss
[9 Nov 2006 14:41] Paul DuBois
Noted in 5.0.30 (not 5.0.29), 5.1.13 changelogs.

Statements such as DROP PROCEDURE and DROP VIEW were written to the
binary log too late due to a race condition.
[7 Sep 2007 9:43] James Day
This bug fix caused bug #25044 "ALTER TABLE tbl ENABLE KEYS; acquires a global lock which blocks opening of all other tables", fixed in 5.0.36 and 5.1.16. Anyone who needs this fix should upgrade to at least one of those two releases instead of 5.0.30 or 5.1.13.