MySQL Bugs: #45670: Secondary auto-incremented primary fields on replicas end up with wrong value

Bug #45670	Secondary auto-incremented primary fields on replicas end up with wrong value
Submitted:	23 Jun 2009 8:43	Modified:	25 Apr 2012 16:39
Reporter:	Tenboro Gray	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.1.35, 5.5.13	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	auto_increment, replication

Description:
If you have a table with two primary keys, and the first primary key is not an auto-increment field but the second one is and is not specified in an INSERT, the replication slaves end up with an erroneous value for the second primary key.

This particular situation was encountered on a table where the first primary key was a user ID, and the second primary key was an auto-incremented user-specific entry.

Binary builds provided by MySQL are used on both master and slaves. Traditional statement-based replication is used.

Master is running: Ver 14.14 Distrib 5.1.35, for unknown-linux-gnu (x86_64) using readline 5.1

Slaves (x2) are running: Ver 14.14 Distrib 5.1.35, for pc-linux-gnu (i686) using readline 5.1

Table status on test table after test is run:

-----------+----------+----------------+---------+
| Name                   | Engine | Version | Row_format | Rows    | Avg_row_length | Data_length | Max_data_length   | Index_length | Data_free | Auto_increment | Create_time         | Update_time         | Check_time          | Collation         | Checksum | Create_options | Comment |
+------------------------+--------+---------+------------+---------+----------------+-------------+-------------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-------------------+----------+----------------+---------+
| ReplicaTest            | MyISAM |      10 | Dynamic    |       3 |             20 |          60 |   281474976710655 |         2048 |         0 |              1 | 2009-06-23 10:26:50 | 2009-06-23 10:27:03 | NULL                | latin1_swedish_ci |     NULL |                |         |

Master configuration:

[mysqld]
server-id=1
log-bin=mysql-bin
binlog-do-db=###

slow_query_log
skip-name-resolve

max_connections=2048
max_user_connections=2040
interactive_timeout=3600
wait_timeout=300
connect_timeout=5
query_cache_type=0
key_buffer_size=4096M
delayed_queue_size=10000
max_allowed_packet=16M
max_heap_table_size=268435456
max_connect_errors=100

innodb_buffer_pool_size=8192M
innodb_log_file_size=256M
innodb_log_buffer_size=4M
innodb_flush_log_at_trx_commit=2
innodb_thread_concurrency=8
innodb_flush_method=O_DIRECT
innodb_file_per_table=1

Slave configuration:

[mysqld]
server-id=3
replicate-do-db=###
replicate-ignore-table=###.######
(10 more)
relay-log=/usr/local/mysql/data/localhost-relay-bin

slow_query_log
skip-name-resolve
low-priority-updates
delay-key-write=ALL
read-only

max_connections=2048
max_user_connections=2040
interactive_timeout=360
wait_timeout=30
connect_timeout=3
query_cache_type=0
key_buffer_size=2048M
delayed_queue_size=10000
max_allowed_packet=16M
max_connect_errors=100

innodb_buffer_pool_size=512M
innodb_log_file_size=256M
innodb_log_buffer_size=4M
innodb_flush_log_at_trx_commit=2
innodb_thread_concurrency=8
innodb_flush_method=O_DIRECT
innodb_file_per_table=1

How to repeat:
On primary:

create table ReplicaTest (t1 int unsigned not null, t2 int unsigned not null auto_increment, t3 varchar(10) not null, primary key(t1, t2));
insert into ReplicaTest (t1, t3) values (1, 'test 1');
insert into ReplicaTest (t1, t3) values (1, 'test 2');
insert into ReplicaTest (t1, t3) values (1, 'test 3');

Result on primary:

mysql> select * from ReplicaTest;
+----+----+--------+
| t1 | t2 | t3     |
+----+----+--------+
|  1 |  1 | test 1 |
|  1 |  2 | test 2 |
|  1 |  3 | test 3 |
+----+----+--------+
3 rows in set (0.00 sec)

Result on Slave #1:

mysql> select * from ReplicaTest;
+----+--------+--------+
| t1 | t2     | t3     |
+----+--------+--------+
|  1 | 718920 | test 1 |
|  1 | 718921 | test 2 |
|  1 | 718922 | test 3 |
+----+--------+--------+
3 rows in set (0.00 sec)

Result on Slave #2:

mysql> select * from ReplicaTest;
+----+--------+--------+
| t1 | t2     | t3     |
+----+--------+--------+
|  1 | 718920 | test 1 |
|  1 | 718921 | test 2 |
|  1 | 718922 | test 3 |
+----+--------+--------+
3 rows in set (0.00 sec)

Expected result: Output from master and slaves should be equal, but isn't. Regression was either introduced somewhere between 5.0.61 and 5.1.35, or is caused by a 64-bit master and 32-bit slaves, which is explicitly supported as per the MySQL documentation.

Thank you for the report.

I can not repeat described behavior with test provided. Have you tried this test in clean environment or is it just generic to show the problem?

Please provide output of SHOW CREATE TABLE and SHOW TABLE STATUS for problem table on both master and slave also.

These tests were run on a server setup that's currently live, I didn't catch the problem during initial testing since my codebase only relied on this behavior at one place in my code. Unfortunately I don't have access to another 64-bit server right now to set up an identical test bed.

SHOW CREATE TABLE:

Master:

+-------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table       | Create Table                                                                                                                                                                                                  |
+-------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ReplicaTest | CREATE TABLE `ReplicaTest` (
  `t1` int(10) unsigned NOT NULL,
  `t2` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `t3` varchar(10) NOT NULL,
  PRIMARY KEY (`t1`,`t2`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
+-------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.03 sec)

Slave:

+-------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table       | Create Table                                                                                                                                                                                                  |
+-------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ReplicaTest | CREATE TABLE `ReplicaTest` (
  `t1` int(10) unsigned NOT NULL,
  `t2` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `t3` varchar(10) NOT NULL,
  PRIMARY KEY (`t1`,`t2`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 |
+-------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.04 sec)

SHOW TABLE STATUS:

Master:

| ReplicaTest            | MyISAM |      10 | Dynamic    |       3 |             20 |          60 |   281474976710655 |         2048 |         0 |              1 | 2009-06-23 08:26:45 | 2009-06-23 08:26:58 | NULL                | latin1_swedish_ci |     NULL |                |         |

Slave:

| ReplicaTest            | MyISAM |      10 | Dynamic    |       3 |             20 |          60 |   281474976710655 |         2048 |         0 |              1 | 2009-06-23 10:26:50 | 2009-06-23 10:27:03 | NULL                | latin1_swedish_ci |     NULL |                |         |

As far as I can tell, they're identical.

Quick followup to this. I've now added a 64-bit replica to the setup using the same build as the master, and this does not share the issue with the 32-bit replicas. That is, running the example above gives the correct result on the 64-bit replica but leaves the 32-bit replicas inconsistent.

Thank you for the feedback.

I still can not repeat described behavior. Could you please check all activities on table ReplicaTest in the binary log in case it something unusual in it like some rows were deleted or inserts were done in concurrent environment? Please also provide slave error log file.

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".

I ran into this bug recently, and have narrowed down what is causing this bug (at least for me).  It is a timing issue of a "replication ignored table" with  auto-increment primary key values leaking over into a non-ignored table with inserts immediately after the ignore table has had rows inserted.

Basically, data from the ignored table is corrupting a non-ignored table on the slave upon immediate inserts.

Here is how to repeat:

On a master issue:

use db;
drop table test;
CREATE TABLE test (id int NOT NULL,   cnt int unsigned  NOT NULL  AUTO_INCREMENT,  PRIMARY KEY (id,cnt) ) ENGINE=MyISAM ;
drop table log;
CREATE TABLE log (id int unsigned NOT NULL AUTO_INCREMENT, log varchar(20),  PRIMARY KEY (id) ) ENGINE=MyISAM AUTO_INCREMENT = 44444;

make sure those two tables are created on the slave through regular replication.

on slave>

desc test;
desc log;

Once replicated, on the master, add the following line to the [mysqld] section of my.cnf, and then restart mysql master.

         replicate-ignore-table=db.log

The on the master, issue the following statements as a copy/paste of all of them at once.  **** It is critical that the statements are executed in immediate succession (no delays)  *****

insert into log values (null,"info1");
insert into log values (null,"info2");
insert into log values (null,"info3");
insert into log values (null,"info4");
insert into test values (1,null);
insert into log values (null,"info5");
insert into test values (1,null);
insert into log values (null,"info6");
insert into test values (2,null);
insert into log values (null,"info7");
insert into test values (2,null);
insert into log values (null,"info8");

Here are the results from the master (all correct):

master>select * from log; 
+-------+-------+
| id    | log   |
+-------+-------+
| 44444 | info1 |
| 44445 | info2 |
| 44446 | info3 |
| 44447 | info4 |
| 44448 | info5 |
| 44449 | info6 |
| 44450 | info7 |
| 44451 | info8 |
+-------+-------+
master>select * from test;
+----+-----+
| id | cnt |
+----+-----+
|  1 |   1 |
|  1 |   2 |
|  2 |   1 |
|  2 |   2 |
+----+-----+

Here are the results from the slave:

slave>select * from log; 

Empty set (0.00 sec)  <--- as expected, since it is ignored 

slave>select * from test;
+----+-------+
| id | cnt   |
+----+-------+
|  1 | 44447 |   <-- should be "1", but has values from "log" on the master
|  1 | 44448 |   <-- should be "2"
|  2 | 44449 |   <-- should be "1"
|  2 | 44450 |   <-- should be "2"
+----+-------+

If there is the slightest delay between the inserts into "log" and "test", the replication happens correctly.

Two additional notes: 

1.  Using the "replicate-wild-ignore-table" option in my.cnf produces the same results.

2.  If the my.cnf "replicate-ignore-table=db.log" setting on the master  is removed and mysql restarted so "db.log" is no longer ignored in replication, this bug goes away and correct results are reported on the slave.

Oops... big typo in above step... add the following line:

  replicate-ignore-table=db.log

to the SLAVE my.cnf, and restart the SLAVE server.  

The master does not need to be restarted or changed. Just the SLAVE.

Hank,

thank you for the feedback and test case.

Verified as described.

Workaround: use row-based replication format

Fixed in 5.1+.

Documented as follows in the 5.1.64/5.5.25/5.6.6 changelogs:

        An INSERT into a table that has a composite primary key that
        includes an AUTO_INCREMENT column that is not the first column
        of this composite key is not safe for statement-based binary
        logging or replication. Such statements are now marked as unsafe
        and fail with an error when using the STATEMENT binary logging
        format. For more information, see
        https://dev.mysql.com/doc/en/replication-rbr-safe-unsafe.html,
        as well as
        https://dev.mysql.com/doc/en/replication-features-auto-increment.html.

          Note:
          Tables using the InnoDB storage engine are not affected by
          this issue, since InnoDB does not allow the creation of a
          composite key that includes an AUTO_INCREMENT column, where
          this column is not the first column in the key.

       See also: Bug#11761686, Bug#54201, Bug#11746146, Bug#23894.

Also updated "Replication and AUTO_INCREMENT" and "Determination of Safe and
Unsafe Statements in Binary Logging" sections of the 5.1/5.5/5.6 Manual.

(NB: The fix for the filtering issue is documented with the changelog entry
for BUG#54201.)

I dispute the resolution.  Seems like it should have been fixed by modifying the Slave to use correct auto-inc value for the _replicated_ table instead of junk from a non-replicated table.