MySQL Bugs: #44163: On blackhole engine table autoincrement always returns `1`

Bug #44163	On blackhole engine table autoincrement always returns `1`
Submitted:	8 Apr 2009 18:09	Modified:	27 May 2010 9:23
Reporter:	Sorin Panca	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Documentation	Severity:	S2 (Serious)
Version:	5.1.32, 5.0, 5.1.46, 5.6.99	OS:	Any (FreeBSD, Linux)
Assigned to:	Tony Bedford	CPU Architecture:	Any
Tags:	autoincrement, blackhole

Description:
We set up a master having all tables using the blackhole engine and we had to drop the columns that use autoincrement because on slaves the replication stopped with 'Duplicate entry'. The autoincrement column always contained the value `1`.

How to repeat:
NA

Suggested fix:
I think it would be better *when using a blackhole engine on master* to let slaves decide the value for the autoincrement column.

Thank you for the problem report. What kind of replication do you use, statement-based or row-based?

We're using mixed replication.

Many thanks for writing a bug report.

Unfortunately this is not a bug because of storage engine blackhole.

For getting other values then 1 please use statement based replication.

I know you like facts, so here they are:
sorin@ws39 ~ $ mysql -hbhdb1 # my blackhole master server
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 120365                       
Server version: 5.1.30-log FreeBSD port: mysql-server-5.1.30

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

mysql> set global binlog_format='STATEMENT';
Query OK, 0 rows affected (0.12 sec)

mysql> SHOW GLOBAL VARIABLES LIKE 'binlog_format';                                   
+---------------+-----------+                                                        
| Variable_name | Value     |                                                        
+---------------+-----------+                                                        
| binlog_format | STATEMENT |                                                        
+---------------+-----------+                                                        
1 row in set (0.12 sec)                                                              
mysql> CREATE TABLE pr.sorin (a INT AUTO_INCREMENT, PRIMARY KEY (`a`)) ENGINE=BLACKHOLE;
Query OK, 0 rows affected (0.14 sec)

mysql> Bye

sorin@ws39 ~ $ mysql -hdb1 # one of the slaves
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 338323                       
Server version: 5.1.30-log FreeBSD port: mysql-server-5.1.30

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

mysql> show create table pr.sorin;
+-------+-----------------------------------------------------------------------------------------------------------------------------+                                     
| Table | Create Table                                                |
+-------+-----------------------------------------------------------------------------------------------------------------------------+
| sorin | CREATE TABLE `sorin` (
  `a` int(11) NOT NULL AUTO_INCREMENT,
  PRIMARY KEY (`a`)
) ENGINE=BLACKHOLE DEFAULT CHARSET=latin1 |
+-------+-----------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.14 sec)

mysql> alter table pr.sorin ENGINE=MyISAM;
Query OK, 0 rows affected (0.14 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> show create table pr.sorin;
+-------+--------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table                                             |
+-------+--------------------------------------------------------------------------------------------------------------------------+
| sorin | CREATE TABLE `sorin` (
  `a` int(11) NOT NULL AUTO_INCREMENT,
  PRIMARY KEY (`a`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
+-------+--------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.12 sec)
mysql> Bye

sorin@ws39 ~ $ mysql -hbhdb1 # on master again
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 120370
Server version: 5.1.30-log FreeBSD port: mysql-server-5.1.30

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

mysql> use pr;
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 sorin add ( b int);
Query OK, 0 rows affected (0.15 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> insert into sorin (b) values ( 1 );
Query OK, 1 row affected (0.12 sec)

mysql> insert into sorin (b) values ( 1 );
Query OK, 1 row affected (0.12 sec)

mysql> select * from sorin;
Empty set (0.12 sec)

mysql> Bye

sorin@ws39 ~ $ mysql -db1 # now on the slave....
mysql> select * from pr.sorin;
+---+------+
| a | b    |
+---+------+
| 1 |    1 |
+---+------+
1 row in set (0.11 sec)

mysql> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: bhdb1.psrk.com                  
                  Master_User: website                         
                  Master_Port: 3306                            
                Connect_Retry: 60                              
              Master_Log_File: mysql-bin.000186                
          Read_Master_Log_Pos: 665968451                       
               Relay_Log_File: db1-relay-bin.000569            
                Relay_Log_Pos: 665946381                       
        Relay_Master_Log_File: mysql-bin.000186                
             Slave_IO_Running: Yes                             
            Slave_SQL_Running: No                              
              Replicate_Do_DB:                                 
          Replicate_Ignore_DB:                                 
           Replicate_Do_Table:                                 
       Replicate_Ignore_Table:                                 
      Replicate_Wild_Do_Table:                                 
  Replicate_Wild_Ignore_Table:                                 
                   Last_Errno: 1062                            
                   Last_Error: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'pr'. Query: 'insert into sorin (b) values ( 1 )'               
                 Skip_Counter: 0                                                      
          Exec_Master_Log_Pos: 665946236                                              
              Relay_Log_Space: 665968792                                              
              Until_Condition: None                                                   
               Until_Log_File:                                                        
                Until_Log_Pos: 0                                                      
           Master_SSL_Allowed: No                                                     
           Master_SSL_CA_File:                                                        
           Master_SSL_CA_Path:                                                        
              Master_SSL_Cert:                                                        
            Master_SSL_Cipher:                                                        
               Master_SSL_Key:                                                        
        Seconds_Behind_Master: NULL                                                   
Master_SSL_Verify_Server_Cert: No                                                     
                Last_IO_Errno: 2013                                                   
                Last_IO_Error: error reconnecting to master 'replication@bhdb1.psrk.com:3306' - retry-time: 60  retries: 86400                                                  
               Last_SQL_Errno: 1062                                                   
               Last_SQL_Error: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'pr'. Query: 'insert into sorin (b) values ( 1 )'               
1 row in set (0.12 sec)                                                               

ERROR: 
No query specified

This is a feature request, not a bug...

We have confirmed this on MysQL 5.1.37.  It would be nice to be able to set an AUTOINCREMENT on a BLACKHOLE table and have it work properly.  I believe this is a bug because BLACKHOLE shouldn't try to insert a value for AUTOINCREMENT -- it is BLACKHOLE, it should enter in NULL.

We're using statement-based replication on MySQL 5.1.37 and it sets the INSERT_ID in the binary logs.  This is a *bug*, as with statement-based replication the INSERT_ID should NOT be set by the master -- otherwise it is not BLACKHOLE, it is BLACKHOLE + [pointless] AUTOINCREMENT

On Master:
master [localhost] {msandbox} ((none)) > CREATE TABLE test_blackhole (`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, field1 varchar(10), PRIMARY KEY (`id`)) ENGINE=BLACKHOLE;
Query OK, 0 rows affected (0.03 sec)

Altered to MyISAM on slave:
slave1 [localhost] {msandbox} (test) > ALTER TABLE test_blackhole ENGINE=MyISAM;
Query OK, 0 rows affected (0.00 sec)
Records: 0  Duplicates: 0  Warnings: 0

master [localhost] {msandbox} (test) > SHOW VARIABLES LIKE '%format%';
+---------------------+-------------------+
| Variable_name       | Value             |
+---------------------+-------------------+
| binlog_format       | STATEMENT         | 

master [localhost] {msandbox} (test) > INSERT INTO test_blackhole (field1) VALUES ('statement1');
Query OK, 1 row affected (0.00 sec)

master [localhost] {msandbox} (test) > INSERT INTO test_blackhole (field1) VALUES ('statement2');
Query OK, 1 row affected (0.00 sec)

master [localhost] {msandbox} (test) > INSERT INTO test_blackhole (field1) VALUES ('statement3');
Query OK, 1 row affected (0.00 sec)

Checking binary log:

BEGIN
/*!*/;
# at 3148
#100223 14:41:08 server id 1  end_log_pos 3176  Intvar
SET INSERT_ID=1/*!*/;
# at 3176
#100223 14:41:08 server id 1  end_log_pos 3296  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928868/*!*/;
INSERT INTO test_blackhole (field1) VALUES ('statement1')
/*!*/;
# at 3296
#100223 14:41:08 server id 1  end_log_pos 3365  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928868/*!*/;
COMMIT
/*!*/;
# at 3365
#100223 14:41:10 server id 1  end_log_pos 3433  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928870/*!*/;
BEGIN
/*!*/;
# at 3433
#100223 14:41:10 server id 1  end_log_pos 3461  Intvar
SET INSERT_ID=1/*!*/;
# at 3461
#100223 14:41:10 server id 1  end_log_pos 3581  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928870/*!*/;
INSERT INTO test_blackhole (field1) VALUES ('statement2')
/*!*/;
# at 3581
#100223 14:41:10 server id 1  end_log_pos 3650  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928870/*!*/;
COMMIT
/*!*/;
# at 3650
#100223 14:41:13 server id 1  end_log_pos 3718  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928873/*!*/;
BEGIN
/*!*/;
# at 3718
#100223 14:41:13 server id 1  end_log_pos 3746  Intvar
SET INSERT_ID=1/*!*/;
# at 3746
#100223 14:41:13 server id 1  end_log_pos 3866  Query   thread_id=16    exec_time=0     error_code=0
SET TIMESTAMP=1266928873/*!*/;
INSERT INTO test_blackhole (field1) VALUES ('statement3')

All the INSERT_ID=1, which causes error on slave.

I agree with the previous comment.  This is definitely a bug that we see with binlog mode statement.

maybe fix for bug #35178 wasn't implemented ideally?

Thank you for the feedback.

Verified as described.

Problem is repeatable only if create table with single column, then issue alter table sorin add ( b int); If create table with 2 columns at first time everything works fine. Row-based replication does not help.

Test case for MTR:
--source include/master-slave.inc

set global binlog_format='STATEMENT';
CREATE TABLE sorin (a INT AUTO_INCREMENT, PRIMARY KEY (`a`)) ENGINE=BLACKHOLE;

sleep 1;
connection slave;
alter table sorin engine=myisam;

connection master;
alter table sorin add ( b int);
insert into sorin(b) values(1);
insert into sorin(b) values(2);
insert into sorin(b) values(3);

sleep 1;
connection slave;
select * from sorin;
--vertical_results
show slave status;

Hi!

Blackhole engine is basically a no-op engine. So whatever you
throw at it it will basically do nothing, and this is valid for
auto increment fields as well. Therefore, if one does inserts
without explicit auto increment values, the engine will not
increment the field value for us, as well as it will not keep
auto increment field state.

This means that if setting up replication and:

  1. on the master there is a blackhole table with an auto
     increment field (PK);
  2. on the slave there's the same table in a MyISAM engine;  
  3. inserts are performed into the master's table, omitting the
     auto increment field (either by not setting the value
     explicitly or using SET INSERT_ID);

replication will break. The reason it will break is somewhat
different depending on the binary log formats. Assuming that the
user does not set the value explicitly as mentioned in #3 above,
this is how it will behave:

  - SBR - the INSERT_ID in the context event that precedes each
          insert will always be set to the same value . As a
          consequence, replication will break;

  - RBR - the value in the row that the engine returns for the
          auto increment field will always be the same for each
          insert, thence replication will break.

Expanding analysis a bit, lets take the following test case:

-- source include/master-slave.inc

CREATE TABLE t1 (c1 INT AUTO_INCREMENT PRIMARY KEY, 
                 c2 int) ENGINE=BLACKHOLE;

-- sync_slave_with_master
ALTER TABLE t1 ENGINE=MyISAM;

-- connection master
SET INSERT_ID= 10;
INSERT INTO t1(c2) VALUES (1);
INSERT INTO t1(c2) VALUES (2);
INSERT INTO t1(c2) VALUES (3);

-- sync_slave_with_master
SELECT * FROM t1;

-- exit

Now lets look at what happens in both binary log formats: SBR and RBR.

SBR
===

Lets start by running the aforementioned test case:

$ perl mysql-test-run.pl --mysqld=--binlog-format=statement rpl.bug44163

(...)
INSERT INTO t1(c2) VALUES (2);
INSERT INTO t1(c2) VALUES (3);
rpl.rpl_x                                [ fail ]
(...)
Last_SQL_Errno	1062
Last_SQL_Error	Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t1(c2) VALUES (3)'
(...)

As we can see here the offending statement is the third
insert. Looking a the output from the master's binary log, we can
see that all three insert statements (as expected) are preceded
by 'SET INSERT_ID':

# at 314
#100409 11:53:32 server id 1  end_log_pos 342 	Intvar
SET INSERT_ID=10/*!*/;
# at 342
#100409 11:53:32 server id 1  end_log_pos 434 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1270810412/*!*/;
INSERT INTO t1(c2) VALUES (1)
/*!*/;

(...)

# at 571
#100409 11:53:32 server id 1  end_log_pos 599 	Intvar
SET INSERT_ID=1/*!*/;
# at 599
#100409 11:53:32 server id 1  end_log_pos 691 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1270810412/*!*/;
INSERT INTO t1(c2) VALUES (2)
/*!*/;

(...)

# at 828
#100409 11:53:32 server id 1  end_log_pos 856 	Intvar
SET INSERT_ID=1/*!*/;
# at 856
#100409 11:53:32 server id 1  end_log_pos 948 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1270810412/*!*/;
INSERT INTO t1(c2) VALUES (3)
/*!*/;

So we now see that the INSERT_ID is the same for the two last
insert statements. And this is because blackhole does nothing,
even wrt keeping auto increment state.

RBR
===

Running the same test case but using row binary log format we
get:

$ perl mysql-test-run.pl --mysqld=--binlog-format=row rpl.bug44163

(...)
INSERT INTO t1(c2) VALUES (2);
INSERT INTO t1(c2) VALUES (3);
rpl.rpl_x                                [ fail ]
(...)
Last_Errno	1062
Last_Error	Could not execute Write_rows event on table test.t1; Duplicate entry '1' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log master-bin.000001, end_log_pos 828
(...)

We cannot tell for sure what's the offending insert based on this
output. So lets take a look at the binary log contents in the
master:

(...)
### INSERT INTO test.t1
### SET
###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1 /* INT meta=0 nullable=1 is_null=0 */
(...)
### INSERT INTO test.t1
### SET
###   @1=1 /* INT meta=0 nullable=0 is_null=0 */
###   @2=2 /* INT meta=0 nullable=1 is_null=0 */
(...)
### INSERT INTO test.t1
### SET
###   @1=1 /* INT meta=0 nullable=0 is_null=0 */
###   @2=3 /* INT meta=0 nullable=1 is_null=0 */
(...)

As we can see here, the third insert is the offending insert (as
was the case in statement mode). What's happening here, however,
is that the blackhole engine returns the same value for the
inserted row when the auto increment field is omitted from the
query. Consequently, the slave will replay the two
Write_rows_log_event with the same value for the primary key
field and thence it will stop.

Conclusion
==========

Given this analysis, the blackhole engine is intended to be
mostly used in a relay slave scenario. It's usage as master's
tables engines must take into account the pitfalls described.

I would say this is not a bug. However, existing documentation 
on how blackhole engine and auto increments play together 
seems a bit short.

The 5.0, 5.1, 5.4, 5.5, and 6.0 reference manuals have been updated. Section added on how Blackhole engine handles auto-increment columns, and implications for replication.