Bug #22334 Unreadable characters in binlog hamper replication
Submitted: 14 Sep 2006 7:27 Modified: 16 Sep 2006 9:30
Reporter: Erik Vande Velde Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.0.18 OS:Linux (Linux (Suse))
Assigned to: CPU Architecture:Any
Tags: binlog, replication

[14 Sep 2006 7:27] Erik Vande Velde
Description:
I have a master & slave running on Linux/Suse. Master has a MySQL 5.0.18 installation, slave 5.0.24a. Slave complains about a syntax error during replication:
<<<--------------------------------------------------------------------------------
060911 12:23:41 [ERROR] Slave: 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: 'pdg'. Query: 'insert into job (controlflow, active, createtime, priority, archived, labelid, submitterid) values ( NAME_CONST('job_properties',Tê·€õ·@', Error_code: 1064
--------------------------------------------------------------------------->>>
The complete bogus query, as generated from a stored procedure call, is shown in the mysqlbinlog of the master:
<<<---------------------------------------------------------------------------
#060911 12:23:41 server id 1 end_log_pos 601 Query thread_id=4998 exec_time=0 error_code=0
SET TIMESTAMP=1157970221;
insert into job (controlflow, active, createtime, priority, archived, labelid, submitterid) values ( NAME_CONST('job_properties',Tê·€õ·@ ÀŒW² €0²(ŒW²ôŽ`W²œÛ@ @ àŽW²€0²ŒW²Aw¨Â  (ŒW²Aw_latin1'#Mon Sep 11 12:23:41 CEST 2006
job.label=U115_DEV-2-X_INT_V2.0.66
gclover=true
jvm.name=jdk1.5.0_06
formatter.sql=true
build.label=U115_DEV-2-X_INT_V2.0.66
abt.location=bdg
'), 1, now(), NAME_CONST('job_priority',0), 0, NAME_CONST('label_id',12582), NAME_CONST('submitter_id',2440));
# at 986993
---------------------------------------------------------------------------->>>
After toying around with all kinds of charsets (currently all charset related variables are on 'utf8') the problem persists. I have a feeling the core problem is in the replication mechanism for stored procs. PLEASE HELP !!!

How to repeat:
execute this stored proc on a 5.0.18 server running on linux:
--
DELIMITER $$

DROP PROCEDURE IF EXISTS `pdg`.`proc_save_job_new`$$
CREATE PROCEDURE  `pdg`.`proc_save_job_new`(

inout job_id int(11),
in label_name varchar(250),
in label_type int,
in branch_name varchar(250),
in unit_name varchar(250),
in submitter_email varchar(250),
in job_priority int,
in job_properties text,
in label_comment varchar(250)

)
BEGIN

  declare label_id int(11) default 0;
  declare branch_id int(11) default 0;
  declare unit_id int(11) default 0;
  declare release_id int(11) default 0;
  declare submitter_id int(11) default 0;

  select id into submitter_id from `user` where emailid = submitter_email limit 1;

  select id into release_id from `release` where pattern like 'u13%' and  branch_name like concat('%',substring(pattern,position("_" in pattern),length(pattern)));

  select id into unit_id from unit where short = unit_name limit 1;

  select id into branch_id from branch where name = branch_name;

  select id into label_id from label where name = label_name;

    select job_id, label_id, branch_id, unit_id, release_id;

  if branch_id = 0 then
      insert into branch (name, unitid, releaseid, createtime, createuser) values(branch_name, unit_id, release_id, now(), submitter_id);
      set branch_id = last_insert_id();
  end if;

  if label_id = 0 then
    insert into label(name, labeltype, branchid, createtime, createuser)values(label_name,label_type, branch_id, now(), submitter_id);
    set label_id = last_insert_id();
  else
    update label set labeltype = label_type, branchid = branch_id where id = label_id;
  end if;

  if label_comment is not null then
    update label set comment = label_comment where id = label_id;
  end if;

  if job_id <= 0 then
    insert into job (controlflow, active, createtime, priority, archived, labelid, submitterid) values ( job_properties, 1, now(), job_priority, 0, label_id, submitter_id);
    set job_id = last_insert_id();
  else
    update job set controlflow = job_properties, priority = job_priority, labelid = label_id, submitterid = submitter_id where id = job_id;
  end if;

  select job_id, label_id, branch_id, unit_id, release_id;

END $$

DELIMITER ;
--
The job-insert contains unreadble characters when shown through mysqlbinlog. Table is defined as 
--
DROP TABLE IF EXISTS `pdg`.`job`;
CREATE TABLE  `pdg`.`job` (
  `id` int(11) NOT NULL auto_increment,
  `controlflow` text NOT NULL COMMENT 'control flow',
  `scheduleinfo` text COMMENT 'Schedule information',
  `active` tinyint(1) NOT NULL default '0',
  `createtime` datetime default NULL COMMENT 'job created date time',
  `priority` tinyint(3) NOT NULL default '0' COMMENT 'Priority of the job',
  `archived` tinyint(1) NOT NULL default '0',
  `labelid` int(11) NOT NULL default '0' COMMENT 'Indicates the label id stored in Identity table',
  `submitterid` int(10) unsigned NOT NULL default '0' COMMENT 'Indicates the submitter id stored in Identity table',
  PRIMARY KEY  (`id`),
  KEY `FK_job_labelid` (`labelid`),
  KEY `FK_job_submitterid` (`submitterid`),
  CONSTRAINT `FK_job_labelid` FOREIGN KEY (`labelid`) REFERENCES `label` (`id`),
  CONSTRAINT `FK_job_submitterid` FOREIGN KEY (`submitterid`) REFERENCES `user` (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COMMENT='Scheduled job information';
--
[14 Sep 2006 15:49] Valeriy Kravchuk
Thank you for a problem report. Firs of all, please, upgrade your master to 5.0.24a and try to repeat your procedure call. In case of the same problem, please, send the exact CALL statement executed, with all the parameters passed.
[15 Sep 2006 12:33] Erik Vande Velde
Thanks for the swift response! I upgraded my master to 5.0.24a, and the direct stored proc call was logged correctly now. In reality the call is done from our web application (through JDBC), and that works OK now too. I'll leave the application running for a few days to see if the replication keeps on working  like I hoped it would for all database updates. The reported problem is solved in any case, and this bug can be closed ...
[16 Sep 2006 9:30] Valeriy Kravchuk
Closed as 5.0.24a does not demonstrate the behaviour described.