MySQL Bugs: #60188: ALTER TABLE not binlogged with --binlog-ignore-db and fully qualified tablenames

Bug #60188	ALTER TABLE not binlogged with --binlog-ignore-db and fully qualified tablenames
Submitted:	21 Feb 2011 10:38	Modified:	3 May 2013 9:23
Reporter:	Peter Laursen (Basic Quality Contributor)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.0, 5.1, 5.5.11-bzr	OS:	Any (Windows, Mac OS X)
Assigned to:		CPU Architecture:	Any
Tags:	qc

Description:
An ALTER TABLE statement does not write to binlog if server started with "--binlog-ignore-db somedatabase" and 'fully qualified' tablenames are used in the ALTER TABLE statement altering table different from current database context.

This is reproducible with any recent 5.1 and 5.5 version. Also with old 5.0 versions (5.0.22) but not recent 5.0x (at least 5.0.86 works fine)

How to repeat:
CREATE TABLE test.`tst` (
  `id` int(11) NOT NULL, 
  `txt` varchar(10) DEFAULT NULL
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

2. Start server with binlog enabled and 'binlog-ignore-db=mysql' setting.

2. From one client instance execute 

RESET MASTER; 
SHOW MASTER STATUS;
-- Note the current binlog position it shows.

3. Execute ALTER TABLE statement from another client.
ALTER TABLE `test`.`tst` ADD COLUMN `column13` BIGINT(5) NULL AFTER `txt`;

4.Then again execute 

SHOW MASTER STATUS
-- and note it shows the same position as before. 

If step 3) is replaced with

USE TEST;
ALTER TABLE `tst` ADD COLUMN `column13` BIGINT(5) NULL AFTER `txt`; 

.. it does binlog (binlog position reported by SHOW MASTER STATUS increases).

Suggested fix:
Identify and fix regression

in step (3) what is your current database?  "select database();" ?

Is is a freshly opened client and thus no database selected at all. SELECT DATABASE returns NULL.

I am now not at the system where this test case has been set up, but I thought that it would happen if 'current database' is not `test`.

OK .. it seems to happen only in no case no database is selected.  If I "USE mysql" or "USE sakila" or whatever database I have binlog position *does* increase.

So probably some string comparison here that is not NULL-safe.

Verified with current mysql-5.5 on Mac OS X:

macbook-pro:5.5 openxs$ bin/mysql -uroot
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.5.11-debug-log Source distribution

Copyright (c) 2000, 2010, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select database();
+------------+
| database() |
+------------+
| NULL       |
+------------+
1 row in set (0.02 sec)

mysql> CREATE TABLE test.`tst` (   `id` int(11) NOT NULL,    `txt` varchar(10),  PRIMARY KEY (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8;
Query OK, 0 rows affected (0.11 sec)

mysql> show master status;
+------------------------+----------+--------------+------------------+
| File                   | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------------+----------+--------------+------------------+
| macbook-pro-bin.000001 |      107 |              | mysql            |
+------------------------+----------+--------------+------------------+
1 row in set (0.02 sec)

mysql> ALTER TABLE `test`.`tst` ADD COLUMN `column13` BIGINT(5) NULL AFTER `txt`;
Query OK, 0 rows affected (0.15 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> show master status;
+------------------------+----------+--------------+------------------+
| File                   | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------------+----------+--------------+------------------+
| macbook-pro-bin.000001 |      107 |              | mysql            |
+------------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql> use test;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> ALTER TABLE `test`.`tst` ADD COLUMN `column13` BIGINT(5) NULL AFTER `txt`;
ERROR 1060 (42S21): Duplicate column name 'column13'
mysql> ALTER TABLE `test`.`tst` ADD COLUMN `column14` BIGINT(5) NULL AFTER `txt`;
Query OK, 0 rows affected (0.08 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> show master status;
+------------------------+----------+--------------+------------------+
| File                   | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------------+----------+--------------+------------------+
| macbook-pro-bin.000001 |      243 |              | mysql            |
+------------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

Actually I forgot to mention one consideration and that is that if a client has the 'reconnect flag' enabled the situation where the current database context is NULL it may happen randomly.  Client app or user has no chance to know when reconnect takes place and database context suddenly is NULL.

Peter,

Can you copy/paste the results that proves your claim that 5.0.86 is NOT affected?

I don't remember details now.  I will try to reconstruct.  I've put a shortcut on my desktop as a reminder.

Sorry .. I forgot to reply here.

I don't have a 5.0.86 server available but 5.0.90 behaves like 5.1 and 5.5 with the test case.  So I probably messed up something.

I wonder if there is any activity on this bug and what is the priority of looking into a fix.

The report is now 1 year old. This bugs makes it easy to break replication.  You cannot take for granted that every user that has access to the server with privilege to ALTER TABLE knows that he must "USE"+"ALTER table" and not just issue a single statement "ALTER database.table". Also applications designed for general use (such as GUI-clients etc.) will most often "ALTER database.table".

This week we had an replication outage because of this bug. It's really serious and I wonder, why does it take so long to resolve such issue. Seems easy to fix.

Thanks, Vojtech

Also see: http://bugs.mysql.com/bug.php?id=64565

After review/discussion between development, Support, and Documentation, the consensus appears to be that this behaviour is intentional.

Changing category to Docs and reassigning to myself for review as a possible documentation issue.

BUG#64562 is a duplicate of this bug.

Per https://dev.mysql.com/doc/refman/5.1/en/replication-options-binary-log.html#option_mysqld_... :

> When using statement-based logging, the following example does not work as you
> might expect. Suppose that the server is started with --binlog-ignore-db=sales
> and you issue the following statements:  

>   USE prices;
>   UPDATE sales.january SET amount=amount+1000;

> The UPDATE statement is logged in such a case because --binlog-ignore-db
> applies only to the default database (determined by the USE statement).
> Because the sales database was specified explicitly in the statement, the
> statement has not been filtered. 

So, yes, this is expected behaviour when using SBL, and yes, in such cases, you must USE the database containing the table in order for statements affecting that table to be ignored.

Expected behaviour and documented as such -> Closed / not a bug.

Now .. what if a reconnect takes place (automatically due to reconnect flag in mysql_options()) and latest USE does not get reinstantiated? 

The implementation of 'binlog_ignore_db' etc. along with replication in MySQL is error-prone!

I am reopening this as a docs request:

The paragraph reading:

"Automatic reconnection can be convenient because you need not implement your own reconnect code, but if a reconnection does occur, several aspects of the connection state are reset on the server side and your application will not know about it. The connection-related state is affected as follows: 

*Any active transactions are rolled back and autocommit mode is reset. 
*All table locks are released. 
*All TEMPORARY tables are closed (and dropped). 
*Session variables are reinitialized to the values of the corresponding variables. This also affects variables that are set implicitly by statements such as SET NAMES. 
*User variable settings are lost. 
*Prepared statements are released. 
*HANDLER variables are closed. 
*The value of LAST_INSERT_ID() is reset to 0. 
*Locks acquired with GET_LOCK() are released.

.. should have add one important point (THE MOST important point IMHO)

*The current database context (default database) is lost.  After a reconnect the default database is NULL. If the server is a replication master THIS MAY CAUSE REPLICATION TO FAIL with specific settings for replication control (such as binlog_ignore_db).

.. But I find it is sad (again) that you just consider this as 'intended because it works like that'.  The client/API should cache what settings are required to 're-instantiate' everything to the new conenction after a reconnect creating an identical environment.

I agree with Peter. Though documented, this behavior is not user friendly at all.
It can cause replication to break due to DDL differences.

This bug is being reviewed by the replication team to take appropriate actions.

This is for now being handled as a Server:Replication bug.

Thank you for your bug report. This issue has been committed to our source repository of that product and will be incorporated into the next release.

If necessary, you can access the source repository and build the latest available version, including the bug fix. More information about accessing the source trees is available at

    http://dev.mysql.com/doc/en/installing-source.html

Fixed in 5.1+.

Documented as follows in the 5.1.70, 5.5.32, 5.6.12, and 5.7.2 changelogs:

        When the server was running with --binlog-ignore-db and SELECT
        DATABASE() returned NULL (that is, there was no currently
        selected database), statements using fully qualified table names
        in dbname.tblname format were not written to the binary log.
        This was because the lack of a currently selected database in
        such cases was treated as a match for any possible ignore option
        rather than for no such option; this meant that these statements
        were always ignored.

        Now, if there is no current database, a statement using fully
        qualified table names is always written to the binary log.

Also updated the description of this option in the Manual accordingly.

Closed.