MySQL Bugs: #24798: Failed ALTER TABLE is logged in binlog and breaks replication

Bug #24798	Failed ALTER TABLE is logged in binlog and breaks replication
Submitted:	4 Dec 2006 14:31	Modified:	12 Feb 2007 20:31
Reporter:	Baron Schwartz (Basic Quality Contributor)	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server	Severity:	S2 (Serious)
Version:	5.0.26-standard-log	OS:	Linux (Gentoo)
Assigned to:		CPU Architecture:	Any
Tags:	replication innodb binlog alter table

Description:
An ALTER TABLE that fails because of InnoDB constraints still makes it into the binlog, where it breaks replication on the slave.

Both master and slave are running the standard MySQL-supplied binaries.

How to repeat:
Due to private data I can't show you exactly the SQL here, but this is the idea:

Create an InnoDB table with a primary key of smallint unsigned, then create another InnoDB table with a column that is int. Try to make a foreign key from the second column to the first. It fails because they are not the same data type, yet the ALTER TABLE statement goes into the binlog and breaks replication on the slave.

The error in the slave's mysqld.err:

061203 23:51:55 [ERROR] Slave: Error 'Can't create table './database1/#sql-1f48_b86.frm' (errno: 150)' on query. Default database: 'database2'. Query: 'alter table database2.table2
add foreign key (client) references database1.client(client)', Error_code: 1005
061203 23:51:55 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'nepal-bin.000056' position 386715699

The error in the master's SHOW INNODB STATUS:

------------------------
LATEST FOREIGN KEY ERROR
------------------------
061203 10:50:53 Error in foreign key constraint of table database2/#sql-4725_38a8:
foreign key (client) references database1.client(client):
Cannot find an index in the referenced table where the
referenced columns appear as the first columns, or column types
in the table and the referenced table do not match for constraint.
Note that the internal storage type of ENUM and SET changed in
tables created with >= InnoDB-4.1.12, and such columns in old tables
cannot be referenced by such columns in new tables.
See http://dev.mysql.com/doc/refman/5.0/en/innodb-foreign-key-constraints.html
for correct foreign key definition.

If you want to see the exact table definitions of what caused the crash, please add a comment stating that, and I can add it privately. But I think this bug should be easy to reproduce.

Suggested fix:
The statement should not go in the binlog unless it succeeds on the master.

Thank you for a problem report, and sorry for a delay with its processing I was not able to repeat the behaviour described with latest 5.0.36-BK on Linux:

openxs@suse:~/dbs/5.0> bin/mysqld_safe --log-bin &
[1] 8682
openxs@suse:~/dbs/5.0> Starting mysqld daemon with databases from /home/openxs/d
bs/5.0/var

openxs@suse:~/dbs/5.0> bin/mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.0.36-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> create table tii1(c1 smallint unsigned primary key, c2 char (100)) 
engine=InnoDB;
Query OK, 0 rows affected (0.06 sec)

mysql> create table tii2(c1 smallint unsigned primary key, c2 int, c3 char(10))
 engine=InnoDB;
Query OK, 0 rows affected (0.01 sec)

mysql> alter table tii2 add foreign key(c2) references tii1(c1);
ERROR 1005 (HY000): Can't create table './test/#sql-21fc_1.frm' (errno: 150)
mysql> show innodb status\G
*************************** 1. row ***************************
Status:
=====================================
070208 14:35:35 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 41 seconds
...
------------------------
LATEST FOREIGN KEY ERROR
------------------------
070208 14:35:29 Error in foreign key constraint of table test/#sql-21fc_1:
foreign key(c2) references tii1(c1):
Cannot find an index in the referenced table where the
referenced columns appear as the first columns, or column types
in the table and the referenced table do not match for constraint.
Note that the internal storage type of ENUM and SET changed in
tables created with >= InnoDB-4.1.12, and such columns in old tables
cannot be referenced by such columns in new tables.
See http://dev.mysql.com/doc/refman/5.0/en/innodb-foreign-key-constraints.html
for correct foreign key definition.
------------
TRANSACTIONS
------------
...

mysql> show binary logs;
+-----------------+-----------+
| Log_name        | File_size |
+-----------------+-----------+
| suse-bin.000011 |       140 |
...
| suse-bin.000030 |       480 |
+-----------------+-----------+
20 rows in set (0.00 sec)

mysql> show binlog events in 'suse-bin.000030' from 1;
+-----------------+-----+-------------+-----------+-------------+---------------
--------------------------------------------------------------------------------
-----+
| Log_name        | Pos | Event_type  | Server_id | End_log_pos | Info

     |
+-----------------+-----+-------------+-----------+-------------+---------------
--------------------------------------------------------------------------------
-----+
| suse-bin.000030 |   4 | Format_desc |         1 |          98 | Server ver: 5.
0.36-log, Binlog ver: 4
     |
| suse-bin.000030 |  98 | Query       |         1 |         188 | use `test`; DE
LETE FROM `test`.`lookup`
     |
| suse-bin.000030 | 188 | Query       |         1 |         331 | use `test`; cr
eate table tii1(c1 smallint unsigned primary key, c2 char (100)) engine=InnoDB
     |
| suse-bin.000030 | 331 | Query       |         1 |         480 | use `test`; cr
eate table tii2(c1 smallint unsigned primary key, c2 int, c3 char(10)) engine=In
noDB |
+-----------------+-----+-------------+-----------+-------------+---------------
--------------------------------------------------------------------------------
-----+
4 rows in set (0.00 sec)

mysql> exit
Bye
openxs@suse:~/dbs/5.0> bin/mysqlbinlog var/suse-bin.000030
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#070208 14:33:52 server id 1  end_log_pos 98    Start: binlog v 4, server v 5.0.
36-log created 070208 14:33:52 at startup
# Warning: this binlog was not closed properly. Most probably mysqld crashed wri
ting it.
ROLLBACK/*!*/;
# at 98
#070208 14:33:53 server id 1  end_log_pos 188   Query   thread_id=1     exec_tim
e=0     error_code=0
use test/*!*/;
SET TIMESTAMP=1170938033/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.uniq
ue_checks=1/*!*/;
SET @@session.sql_mode=0/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.
collation_server=8/*!*/;
DELETE FROM `test`.`lookup`/*!*/;
# at 188
#070208 14:34:15 server id 1  end_log_pos 331   Query   thread_id=1     exec_tim
e=0     error_code=0
SET TIMESTAMP=1170938055/*!*/;
create table tii1(c1 smallint unsigned primary key, c2 char (100)) engine=InnoDB
/*!*/;
# at 331
#070208 14:34:31 server id 1  end_log_pos 480   Query   thread_id=1     exec_tim
e=0     error_code=0
SET TIMESTAMP=1170938071/*!*/;
create table tii2(c1 smallint unsigned primary key, c2 int, c3 char(10)) engine=
InnoDB/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

So, failed ALTER TABLE is not in the binary log. 

Please, try to repeat with the latest version released officially, 5.0.33, and add comment to this bug report if it still demontrates the same incorrect behaviour.

I can't repeat this either.