Bug #62322 Inserting 'NaN' float into a row breaks replication
Submitted: 1 Sep 2011 13:37 Modified: 17 Feb 2012 16:27
Reporter: Jens Rantil Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.1.49 OS:Linux (Debian squeeze)
Assigned to: CPU Architecture:Any

[1 Sep 2011 13:37] Jens Rantil
Description:
Inserting 'NaN' float into a row leads to replication error when
 1. binlog format on master is 'STATEMENT' or 'MIXED'; and
 2. the insert is done using a prepared statement.

Additional information:
 - We are running official Debian MySQL package 5.1.49-3 for squeeze in production and noticed this bug this morning.
 - We have been able to reproduce in on two Ubuntu machines:
  - Slave: 5.1.41-3ubuntu12.10
  - Master: 5.1.41-3ubuntu12.10
 - Reproduction works every time.
 - Production database engine is InnoDB.

How to repeat:
 1. Set up replication from a master to slave.
 2. Issue the following on master:

================================
mysql> CREATE TABLE `testfloat` (`val` float NOT NULL);
Query OK, 0 rows affected (0.01 sec)

mysql> SET GLOBAL binlog_format = 'XXX';
Query OK, 0 rows affected (0.01 sec)
================================

where XXX can be either 'STATEMENT' or 'MIXED'.

 3. Make sure the table was created correctly on slave and that replication is live and kicking:

================================
mysql> DESCRIBE testfloat;
+-------+-------+------+-----+---------+-------+
| Field | Type  | Null | Key | Default | Extra |
+-------+-------+------+-----+---------+-------+
| val   | float | NO   |     | NULL    |       |
+-------+-------+------+-----+---------+-------+

mysql> SELECT * FROM testfloat;
Empty set (0.00 sec)

mysql> SHOW SLAVE STATUS \G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: themaster.telavox.se
                  Master_User: root
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 50776
               Relay_Log_File: theslave-relay-bin.000024
                Relay_Log_Pos: 251
        Relay_Master_Log_File: mysql-bin.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB: thedatabase
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 50776
              Relay_Log_Space: 884
              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: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 0
               Last_SQL_Error: 
1 row in set (0.01 sec)
================================

 4. Issue an INSERT using a prepared statement to the master. I did this using JDBC, cause this is what I had at hand:

      final Transaction transaction = HibernateUtil.getSession().beginTransaction();
      Connection conn = HibernateUtil.getSession().connection();
      PreparedStatement stmnt = conn.prepareStatement("INSERT INTO testfloat(val) VALUES (?)");
      stmnt.setFloat(1, Float.NaN);
      stmnt.execute();
      transaction.commit();

 5. Verify that the INSERT was made on master:

================================
mysql> SELECT * FROM testfloat;
+-----+
| val |
+-----+
|   0 |
+-----+
1 row in set (0.00 sec)

================================

The output looks correct.

 6. Notice that the INSERT was NOT made on slave

================================
mysql> SELECT * FROM testfloat;
Empty set (0.00 sec)

================================

the expected output should a row containing the value 0. IT DID NOT.

 7. Notice that replication failed:
================================
mysql> SHOW SLAVE STATUS\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: themaster.telavox.se
                  Master_User: root
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 51181
               Relay_Log_File: theslave-relay-bin.000024
                Relay_Log_Pos: 443
        Relay_Master_Log_File: mysql-bin.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB: thedatabase
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 1054
                   Last_Error: Error 'Unknown column 'nan' in 'field list'' on query. Default database: 'thedatabase'. Query: 'INSERT INTO testfloat(val) VALUES (nan)'
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 50968
              Relay_Log_Space: 1289
              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: 0
                Last_IO_Error: 
               Last_SQL_Errno: 1054
               Last_SQL_Error: Error 'Unknown column 'nan' in 'field list'' on query. Default database: 'thedatabase'. Query: 'INSERT INTO testfloat(val) VALUES (nan)'
1 row in set (0.00 sec)

================================

expected output was (obviously) no error and "Slave_SQL_Running: Yes".

I also noticed, that the slave was running MyISAM for testfloat, while the master was using InnoDB. Seems this bug is database engine independent.

Suggested fix:
I can see three quickfixes:

1. Switch binlog format on master to 'ROW' by issuing the following command:
SET GLOBAL binlog_format = 'ROW';
(!!! but make sure your slaves can handle the 'ROW' based binlog format !!!)

2. Obviously you can also make sure you never INSERT lines containing 'NaN', by issuing an if-statement in your code.

3. You can also always skip the broken line in your binlog by issuing:
================================
mysql> SLAVE STOP;
mysql> SET GLOBAL SQL_SLAVE_SKIP_COUNTER = 1;
mysql> SLAVE START;
================================
You might have to skip multiple lines.
[1 Sep 2011 13:42] Jens Rantil
This bug also occurs for the when the table column is DOUBLE instead of FLOAT, ie. can be reproduced for
==============================
CREATE TABLE `testfloat` (`val` double NOT NULL);
Query OK, 0 rows affected (0.01 sec)

==============================
, too.
[1 Sep 2011 13:44] Jens Rantil
...as well as for type INTEGER. I guess, you could say it's independent of numeric type. :-)
[2 Sep 2011 8:48] Valeriy Kravchuk
Check old user comment at http://dev.mysql.com/doc/refman/4.1/en/c-api-prepared-statement-problems.html that describes this your case.
[6 Sep 2011 8:10] Jens Rantil
Thanks for commenting Valeriy. It's good that bug was at least documented/commented somewhere. However, I wouldn't say it's a bug in the C API, but rather replication or similar... Wouldn't you agree?
[17 Jan 2012 16:27] Sveta Smirnova
Thank you for the feedback.

I can not repeat described behavior with test case as in Valeriy's comment. Please try with current version 5.1.61 and inform us if problem still exists.
[18 Feb 2012 1:00] Bugs System
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".