Bug #30115 crash during RENAME TABLE breaks replication
Submitted: 28 Jul 2007 13:42
Reporter: Guilhem Bichot Email Updates:
Status: Verified Impact on me:
Category:MySQL Server: DDL Severity:S3 (Non-critical)
Version:5.0-bk,5.1-bk OS:Any
Assigned to: CPU Architecture:Any

[28 Jul 2007 13:42] Guilhem Bichot
RENAME TABLE first renames the table then writes to binlog. If the
server dies between the two operations (power failure, crash, out of memory...), the slave will not receive the RENAME statement and so subsequent statements run on master using the new table's name will fail on slave.
This is different from DMLs: if one uses --sync-binlog and InnoDB, we guarantee that in case of crash on master during a INSERT/DELETE/UPDATE, slave and master stay in sync. Here this is not the case with DDLs.

This also breaks recovery from binlogs: on a single server without a slave, the missing RENAME in the binlog will go unnoticed, and if later a restore from a pre-RENAME backup + the binlog is attempted, it will fail (see "how to repeat": statements updating 'u' will fail).

How to repeat:
To provoke the crash, insert "abort()" here in mysql_rename_tables():
  /* Lets hope this doesn't fail as the result will be messy */ 
  if (!silent && !error)
    if (mysql_bin_log.is_open())
                        thd->query, thd->query_length, FALSE, FALSE);
Then run mysqld as master:
[INS 15:18 /m/mysql-5.1/sql $] ./mysqld --skip-grant-tables --datadir=/tmp/data
--language=./share/english --log-bin --server-id=1
Run a second mysqld as slave of the first one:
[INS 15:43 /m/mysql-5.1/sql $] ./mysqld --skip-grant-tables --datadir=/tmp/data2 --language=./share/english --port=3307 --socket=/tmp/second.sock --server-id=2
Connect to slave and start replication:
[INS 15:42 /m/mysql-5.1/client $] ./mysql -uroot -S /tmp/second.sock
mysql> change master to master_host="localhost";
Query OK, 0 rows affected (0.10 sec)

mysql> start slave;
Query OK, 0 rows affected (0.00 sec)

Then connect to master and do:
mysql> create database test;
Query OK, 1 row affected (0.00 sec)

mysql> use test;
Database changed
mysql> create table t(a int) engine=innodb;
Query OK, 0 rows affected (0.05 sec)
mysql> rename table t to u;
ERROR 2013 (HY000): Lost connection to MySQL server during query
(the error above is due to the crash we provoked).
Now, restart the same mysqld, and:
mysql> insert into test.u values(1);
Query OK, 1 row affected (0.02 sec)

See on slave:
mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: localhost
                  Master_User: test
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: gbichot4-bin.000003
          Read_Master_Log_Pos: 106
               Relay_Log_File: gbichot4-relay-bin.000004
                Relay_Log_Pos: 254
        Relay_Master_Log_File: gbichot4-bin.000002
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
                   Last_Errno: 1146
                   Last_Error: Error 'Table 'test.u' doesn't exist' on query. Default database: 'test'. Query: 'insert into test.u values(1)'

Observe all binlogs:
[INS 15:39 /m/mysql-5.1/client $] ll /tmp/data/
total 20516
-rw-rw---- 1 guilhem users      287 2007-07-28 15:38 gbichot4-bin.000001
-rw-rw---- 1 guilhem users      224 2007-07-28 15:38 gbichot4-bin.000002
observe with mysqlbinlog that they show this sequence:
create table t(a int) engine=innodb/*!*/;
insert into test.u values(1)/*!*/;
and thus slave fails.

Suggested fix:
All DDLs in MySQL follow the logic:
- do the operation
- then write it to binlog
and so they are subject to the same bug.
Possibly extend the DDL log to contain an entry which would say "write this to binlog". That would first require BUG#30114 to be fixed.
[28 Jul 2007 19:29] Guilhem Bichot
replication breakage so it's a P2. Also, if RENAME TABLE is used to swap tables:
RENAME TABLE t TO v, u TO t, v to u;
then slave may fail silently (bad data)