Bug #69389 mysqlbinlog missing delimiter with mixed mode binary logging
Submitted: 3 Jun 2013 18:19 Modified: 4 Jun 2013 19:27
Reporter: Peter Sylvester Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S2 (Serious)
Version:5.5.15 OS:Linux (CentOS release 5.7)
Assigned to: CPU Architecture:Any
Tags: mysqlbinlog mixed mode delimiter

[3 Jun 2013 18:19] Peter Sylvester
Description:
When using mysqlbinlog to get a point in time recovery sql script I have found that there are missing delimiters.  This caused an issue recently while trying to do a point in time recovery for one of our databases.  Here is an example of what was found in the mysqlbinlog output...

/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;

….

#130528  2:01:56 server id 1  end_log_pos 97499 	Write_rows: table id 145656
#130528  2:01:56 server id 1  end_log_pos 97645 	Write_rows: table id 145663

BINLOG '
VEikURMBAAAASQAAANh4AQAAAPg4AgAAAAEACWNhcmVtb3JlMgANUmVhZGluZ1dlaWdodAAMAwkJ
AQwMAwwDDw8BBDwAlgCkDw==
VEikURMBAAAAOwAAABN5AQAAAPk4AgAAAAEACWNhcmVtb3JlMgAPUmVhZGluZ1dlaWdodElkAAED
AAA=
VEikURMBAAAASQAAAFx5AQAAAPs4AgAAAAEACWNhcmVtb3JlMgARcmVhZGluZ0NvbXBsaWFuY2UA
CQMDDAwPDAP8DAM8AASMAQ==
VEikURMBAAAARgAAAKJ5AQAAAP44AgAAAAEACWNhcmVtb3JlMgALUmVhZGluZ1BsYW4ACQICDwEC
/hADBwaWAP4DAQCEAQ==
VEikURMBAAAAQwAAAOV5AQAAAP84AgAAAAEACWNhcmVtb3JlMgAGQWxlcnRzAAwDAw8HARACAvwD
DAMFcBcBAAQEDw==
VEikURMBAAAASQAAAC56AQAAAAA5AgAAAAEACWNhcmVtb3JlMgASUGF0aWVudFJlYWRpbmdQbGFu
AAsDAwIHDAIMAwIMAwDwBw==
VEikURMBAAAARgAAAHR6AQAAAAE5AgAAAAEACWNhcmVtb3JlMgAPUmVhZGluZ1JlbGF5TG9nAAgD
AgMBDAwPDwQsAQAw+A==
VEikURMBAAAATAAAAMB6AQAAAAc5AgAAAAEACWNhcmVtb3JlMgAScGF0aWVudE1lc3NhZ2VQbGFu
AAwDAwMMDAIPAwoKAwcCPAD0Dw==
VEikURMBAAAARQAAAAV7AQAAAAw5AgAAAAEACWNhcmVtb3JlMgAMVGFza01ldGFEYXRhAAsDAwL+
DAMMDAMDAwL3ATIE
VEikURMBAAAAUQAAAFZ7AQAAAA05AgAAAAEACWNhcmVtb3JlMgAFVGFza3MAFQMQAgMDEAIDDBD8
AgMD/AMPDAMMAwoBAAEAAQAEBEgALPwf
VEikURMBAAAAXAAAAPl7AQAAABI5AgAAAAEACWNhcmVtb3JlMgAMaWxjc01lc3NhZ2VzABgDAwMM
AwwBDAwMAQwD/AMQEAMMDw8PAQwLBAEAAQA8AJYAlgDs//8=
VEikURMBAAAATAAAAEV8AQAAAAc5AgAAAAEACWNhcmVtb3JlMgAScGF0aWVudE1lc3NhZ2VQbGFu
AAwDAwMMDAIPAwoKAwcCPAD0Dw==
VEikURcBAAAAIgAAAGd8AQAAAPk4AgAAAAAAAf/+j1sSAA==
VEikURcBAAAAdAAAANt8AQAAAPg4AgAAAAAADP//gPGIRh8AHT8AnxwABdBi+QBPEgAA/GL5AE8S
AACPWxIADjAyMjAxMDAwMDAwMjE5JDE5MDlkZWNlLWM3NWMtMTFlMi04MGIxLTAwMjQ4MWFhYmE5
MAc=
VEikURcBAAAAkgAAAG19AQAAAP84AgAAAAAADP//APfAYAIAiEYfAFoAV2VpZ2h0IGluY3JlYXNl
IG9mIDMgTGJzIG92ZXIgMSBjb25zZWN1dGl2ZSByZWFkaW4gLSBXZWlnaHQ6IDE2MSBsYnMuLCBN
YXkgMjcgMjAxMyAxMTowMVBNVEikUQMAAgB1AI9bEgA=
# at 97844
#130528  2:01:56 server id 1  end_log_pos 97871 	Xid = 118714280
COMMIT/*!*/;
# at 97871
#130528  2:01:56 server id 1  end_log_pos 97952 	Query	thread_id=261481	exec_time=0	error_code=0
SET TIMESTAMP=1369720916/*!*/;

You'll notice that between the last line of the binlog entry 'YxkgMjcgMjAxMyAxMTowMVBNVEikUQMAAgB1AI9bEgA=' and the next comment '# at 97844' there is no delimiter '/*!*/;'

When running the output of this file against mysql it fails when it gets to this line.  We were able to write a regex script to look for the absence of delimiters and put them in, however a lot of manual work was required to clean up the script completely before we were able to perform the point in time recovery.

How to repeat:
mysqlbinlog --database=<database> <binary log file> > /tmp/<outputfile>
[4 Jun 2013 19:26] Peter Sylvester
After submitting the ticket I realized that this could not be a problem with the way the binary log file was being generated as replication was unaffected by the problem, so it had to be an issue with how mysqlbinlog was parsing the file.  So to test I created a new VM running CentOS 5.9, installed the latest version of mysql (5.5.32) and then copied over one of the binary log files from my production server.  Once copied I ran the command to parse and export to a sql file and then compared the old exported file with the new one created by the mysqlbinlog package that comes with 5.5.32. 

As a result I found the issue was fixed, though it would have to be resolved by either updating CentOS to 5.9 from 5.7, or updating MySQL from 5.5.15 to 5.5.32.  Either way the problem was resolved.  I apologize for creating this ticket.
[4 Jun 2013 19:27] Peter Sylvester
Was able to resolve issue by updating OS and MySQL version.