MySQL Bugs: #34289: Incorrect NAME_CONST substitution in stored procedures breaks replication

Bug #34289	Incorrect NAME_CONST substitution in stored procedures breaks replication
Submitted:	4 Feb 2008 16:58	Modified:	29 Mar 2008 17:10
Reporter:	Matt Nathan	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.0.45, 5.0, 5.1, 6.0 BK	OS:	Any (Linux)
Assigned to:	Sergey Vojtovich	CPU Architecture:	Any
Tags:	binary log, name_const, replication, stored procedure

Description:
The automatic substitution of variable names for NAME_CONST('varName', varVal) in the binary logging of stored procedures is incorrect under certain conditions. 

The two cases which have caused us problems are listed below:

1) replication of collation casting

a procedure like this
create procedure collationCast()
begin
 declare var char(10) default 'the value';
 update t1 set v = 'updated' where q = var collate latin1_general_cs;
end//

This gets logged in the binary log as:
  update t1 set v = 'updated' where q = NAME_CONST('var',_latin1'the value') collate latin1_general_cs
Which is invalid and throws an exception stating:
  COLLATION 'latin1_general_cs' is not valid for CHARACTER SET 'binary'
I would guess that this is because it it trying to collate a binary result set (NAME_CONST) instead of a character variable.

2) replication using reserved words

While this is less important as it is easy to work around it does cause some problems when it cannot be avoided. Stored procedures like this:
create procedure reservedWord()
begin
  declare `order` int default 1;
  insert into t2 values(`order`);
end//

places the following into the binary log:
  insert into t2 values(` NAME_CONST('order',1)`)
which gives the error:
  Unknown column ' NAME_CONST('order',1)' in 'field list'

Work arounds

For problem 1 you cab use a user variable instead of a SP variable, something like this:
create procedure collateCastFix()
begin
  declare var char(10) default 'the value';
  set @varTmp = var;
  update t1 set v = 'update fix' where q = @varTmp collate latin1_general_cs;
end//

For problem 2 it should be possible to change the name of the SP variable to something that is not a reserved word allowing you to exclude the `` when defining it.

How to repeat:
drop database if exists testdb;
create database testdb;
use testdb;

-- for error 1
create table t1 (v char(10), q char(10)) character set latin1 collate latin1_general_ci;
insert into t1 values ('original', 'the value');
delimiter //
create procedure collationCast()
begin
 declare var char(10) default 'the value';
 update t1 set v = 'updated' where q = var collate latin1_general_cs;
end//
delimiter ;

-- for error 2
create table t2 (`order` int);
delimiter //
create procedure reservedWord()
begin
  declare `order` int default 1;
  insert into t2 values(`order`);
end//
delimiter ;

-- enable the binary log then run the following:
call collationCast();
call reservedWord();

-- the binary log should now show two invalid queries.

Thank you for a problem report. Please, try to repeat with a newer version, 5.0.51a, and inform about the results.

Having tested on the latest 5.0.51a community server the first problem (collation casting) still breaks, the second problem (variable escaping) has been fixed.

The variable escaping now produces binary log entries like:
  insert into t2 values( NAME_CONST('order',1))
instead of:
  insert into t2 values(` NAME_CONST('order',1)`)

The collation casting still produces binary log entries like:
  update t1 set v = 'updated' where q =  NAME_CONST('var',_latin1'the value') collate latin1_general_cs

Thank you for the feedback. It is the below error are you reporting?

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: localhost
                  Master_User: miguel
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: windows-bin.000009
          Read_Master_Log_Pos: 106
               Relay_Log_File: amanhecer-relay-bin.000023
                Relay_Log_Pos: 253
        Relay_Master_Log_File: windows-bin.000009
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB:
          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: 106
              Relay_Log_Space: 559
              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.00 sec)

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: localhost
                  Master_User: miguel
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: windows-bin.000009
          Read_Master_Log_Pos: 1385
               Relay_Log_File: amanhecer-relay-bin.000023
                Relay_Log_Pos: 1240
        Relay_Master_Log_File: windows-bin.000009
             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: 1253
                   Last_Error: Error 'COLLATION 'latin1_general_cs' is not valid for CHARACTER SET 'binary'' on query. Default database: 'testdb'. Que
ry: 'update t1 set v = 'updated' where q =  NAME_CONST('var',_latin1'the value') collate latin1_general_cs'
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 1093
              Relay_Log_Space: 1838
              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: 1253
               Last_SQL_Error: Error 'COLLATION 'latin1_general_cs' is not valid for CHARACTER SET 'binary'' on query. Default database: 'testdb'. Que
ry: 'update t1 set v = 'updated' where q =  NAME_CONST('var',_latin1'the value') collate latin1_general_cs'
1 row in set (0.00 sec)

mysql>

Thanks in advance.

Yes, this is the error we are getting.

Thank you for the report.

Verified as described.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/42555

ChangeSet@1.2575, 2008-02-19 18:16:17+04:00, svoj@mysql.com +3 -0
  BUG#34289 - Incorrect NAME_CONST substitution in stored procedures
              breaks replication
  
  NAME_CONST() didn't replicate constant character set and collation
  correctly.
  
  With this fix NAME_CONST() inherits collation from the value argument.

The patch http://lists.mysql.com/commits/42555 is ok to push.

Pushed into 5.1.24-rc

Pushed into 5.0.60

Pushed into 6.0.5-alpha

Bugfix documented in the 5.0.60, 5.1.24, and 6.0.5 changelogs as follows:

        The character sets and collations used for constant identifiers in
        stored procedures were not replicated correctly.

Also noted in the 5.1.23-ndb-6.3.11 changelog.

I am experiencing the same problem with mysql, no matter if it is database server 5.1.57 or community server 5.5.12 on Sparc Solaris 10. When I start replication, after a few minutes I receive the error 

Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '' at line 1' on query. Default database: 'V2DB'. Query: 'UPDATE Users SET IsForgotPassword =  NAME_CONST('InValue','

Research said there was a bug (http://bugs.mysql.com/bug.php?id=26199) and a said a workaround was to change the BIT value to INT.  This would take a lot of work since it is used a lot though-out the application.

Research also showed a patch (http://lists.mysql.com/commits/42555) I could apply but it fails every time with this

# /usr/local/bin/patch -p0 < ../NameConstantPatch.txt

patching file b/mysql-test/r/func_misc.result
Hunk #1 FAILED at 225.
1 out of 1 hunk FAILED -- saving rejects to file b/mysql-test/r/func_misc.result.rej
patching file b/mysql-test/t/func_misc.test
Hunk #1 FAILED at 237.
1 out of 1 hunk FAILED -- saving rejects to file b/mysql-test/t/func_misc.test.rej
patching file b/sql/item.cc
Hunk #1 FAILED at 1240.
1 out of 1 hunk FAILED -- saving rejects to file b/sql/item.cc.rej
#

When I looked into the files that are being patched it seems the versions already have the code incorporate.  Has anyone experienced this issue and how did they resolve it?  Am I doing something wrong too?  The patch is in the top level of the mysql_### release.

Here is the patch
# more MysqlPatch
--- mysql-test/r/func_misc.result       2008-01-23 19:01:27 +04:00
+++ mysql-test/r/func_misc.result_a     2008-02-19 18:16:15 +04:00
@@ -225,4 +225,7 @@ select min(a) from t1 group by inet_ntoa
 min(a)
 -2
 drop table t1;
+SELECT NAME_CONST('var', 'value') COLLATE latin1_general_cs;
+NAME_CONST('var', 'value') COLLATE latin1_general_cs
+value
 End of 5.0 tests

--- mysql-test/t/func_misc.test 2008-01-23 19:01:27 +04:00
+++ mysql-test/t/func_misc.test_a       2008-02-19 18:16:15 +04:00
@@ -237,5 +237,11 @@ insert into t1 values (-1), (-2);
 select min(a) from t1 group by inet_ntoa(a);
 drop table t1;

+#
+# BUG#34289 - Incorrect NAME_CONST substitution in stored procedures breaks
+# replication
+#
+SELECT NAME_CONST('var', 'value') COLLATE latin1_general_cs;
+
 --echo End of 5.0 tests

--- sql/item.cc 2008-02-08 14:55:54 +04:00
+++ sql/item.cc_a       2008-02-19 18:16:15 +04:00
@@ -1240,6 +1240,7 @@ bool Item_name_const::fix_fields(THD *th
     return TRUE;
   }
   set_name(item_name->ptr(), (uint) item_name->length(), system_charset_info);
+  collation.set(value_item->collation.collation, DERIVATION_IMPLICIT);
   max_length= value_item->max_length;
   decimals= value_item->decimals;
   fixed= 1;
#

I tried another syntax with my patch command and receive the same errors

# /usr/local/bin/patch -i ../MysqlPatch
patching file func_misc.result_a
Hunk #1 FAILED at 225.
1 out of 1 hunk FAILED -- saving rejects to file func_misc.result_a.rej
patching file func_misc.test_a
Hunk #1 FAILED at 237.
1 out of 1 hunk FAILED -- saving rejects to file func_misc.test_a.rej
patching file item.cc_a
Hunk #1 FAILED at 1240.
1 out of 1 hunk FAILED -- saving rejects to file item.cc_a.rej