MySQL Bugs: #59530: Filter by server id in mysqlbinlog fails

Bug #59530	Filter by server id in mysqlbinlog fails
Submitted:	16 Jan 2011 5:56	Modified:	29 Mar 2011 11:16
Reporter:	Jesper Wisborg Krogh (OCA)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Command-line Clients	Severity:	S3 (Non-critical)
Version:	5.1.45, 5.1.56, 5.5.8	OS:	Any (Mac OS X 10.6, Windows XP)
Assigned to:	Nirbhay Choubey	CPU Architecture:	Any
Tags:	mysqlbinlog

Description:
When filtering the output of mysqlbinlog by server id, mysqlbinlog sometimes fail.

How to repeat:
Run the following statements in the mysql client:

SET GLOBAL server_id := 1;
reset master;
drop table if exists t1;
create table t1 (id int auto_increment not null primary key);
insert into t1 values ();

SET GLOBAL server_id := 2;
insert into t1 values ();

flush logs;

Then run mysqlbinlog:

mysqlbinlog --server-id=2 binary-log.000001

gives:

/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 27, event_type: 16
ERROR: Could not read entry at offset 527: Error in log format or read error.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

When filtering by --server-id=1 it works fine.

Suggested fix:
I wonder whether some of the statements inserted by mysqlbinlog at the top of the output (e.g. SET @@session.pseudo_thread_id=1/*!*/;) are not being set correctly when filtering by a server id that is not the first to appear it the binary log?

I think it could be related to this:

DELIMITER /*!*/;

I tried in 'mysql' client this

 -> delimiter /*!*/ ;
 -> select 1;
 ->
 ->
 ->
 ->
 ->
 ->
 ->
 ->
 ->
... etc. ('mysql>' prompt never appears)

With a comment between the DELIMITER keyword and the delimiter defined things seem unpredictable.

I posted this (what may be related):
http://bugs.mysql.com/bug.php?id=59534

I am not sure those two bugs are related. I have attached the full output from mysqlbinlog without any arguments, i.e.

mysqlbinlog binary-log.000001 > binary-log.sql

and that contains the same syntax for DELIMITER. Note that the DELIMITER statement is added by mysqlbinlog and is not part of the statements run in the mysql client.

The output of mysqlbinlog when invoked without arguments

Attachment: binary-log.sql (application/octet-stream, text), 2.42 KiB.

Thank you for the report.

I can not repeat describe behavior on Mac OSX 10.4 and Linux. Please indicate accurate name of package you are using and accurate OS version.

I am using Mac OS 10.6 and MySQL was compiled from source. The only configuration parameter I used was setting the prefix.

Verified on Windows XP also:

...
C:\Program Files\MySQL\MySQL Server 5.5\bin>mysqlbinlog --server-id=2 -uroot -pr
oot "c:\Documents and Settings\All Users\Application Data\MySQL\MySQL Server 5.1
\data\toshiba-user-bin.000009"
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log'
, data_len: 27, event_type: 16
ERROR: Could not read entry at offset 351: Error in log format or read error.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

Documented fix as follows in the 5.1.57, 5.5.12, and 5.6.3 changelogs:

        Using the --server-id option with mysqlbinlog could cause format
        description log events to be filtered out of the binary log,
        leaving mysqlbinlog unable to read the remainder of the log. Now
        such events are always read without regard to the value of this
        option.

        As part of the the fix for this problem, mysqlbinlog now also
        reads rotate log events without regard to the value of
        --server-id.

Closed.