MySQL Bugs: #38581: mysqlbinlog cannot read a DELETE FROM table LIMIT x; in the binary log

Bug #38581	mysqlbinlog cannot read a DELETE FROM table LIMIT x; in the binary log
Submitted:	5 Aug 2008 18:59	Modified:	12 Aug 2008 4:47
Reporter:	Chris Calender	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: Command-line Clients	Severity:	S3 (Non-critical)
Version:	5.1.26	OS:	Windows
Assigned to:		CPU Architecture:	Any
Tags:	binary log, delete, Error in Log_event::read_log_event(), limit, mysqlbinlog

Description:
The mysqlbinlog from 5.1.26 cannot read a statement of the form:

DELETE FROM tbl LIMIT x;

When you try to view it, you'll get the following error:

ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 593, event_type: 25
Could not read entry at offset 1150:Error in log format or read error

Also, note that the command will not be applied if you try to apply the binary log to a running MySQL instance.

Also, DELETEs without the LIMIT are written/read fine.

How to repeat:
1. Install and start an instance of MySQL 5.1.26 with binary logging enabled.

2. Run the following commands:

DROP DATABASE d1 IF EXISTS;
CREATE DATABASE d1;
USE d1;
CREATE TABLE t1 (id int);
INSERT INTO t1 (id) VALUES (1),(2),(3),(4),(5);
DELETE FROM t1 LIMIT 4;

3. Use mysqlbinlog to check the file.  Note that you'll need to use a mysqlbinlog from 5.1.17 to even see the output (due to bug #38579).

4. Note the error:

ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 593, event_type: 25
Could not read entry at offset 1150:Error in log format or read error

Suggested fix:
Well, I'm not sure here.

Further, I'm not sure if this is a problem with mysqlbinlog or if there is a problem with how the statement is written to the binary log.

Thank you for a problem report. Sorry, but I can not repeat the behaviour described with 5.1.26 on Windows XP:

C:\Program Files\MySQL\MySQL Server 5.1\bin>mysql -uroot -proot -P3310 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.26-rc-community-log MySQL Community Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> DROP DATABASE d1 IF EXISTS;
ERROR 1064 (42000): 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 'IF EX
ISTS' at line 1
mysql> CREATE DATABASE d1;
Query OK, 1 row affected (0.03 sec)

mysql> USE d1;
Database changed
mysql> CREATE TABLE t1 (id int);
Query OK, 0 rows affected (0.19 sec)

mysql> INSERT INTO t1 (id) VALUES (1),(2),(3),(4),(5);
Query OK, 5 rows affected (0.08 sec)
Records: 5  Duplicates: 0  Warnings: 0

mysql> DELETE FROM t1 LIMIT 4;
Query OK, 4 rows affected (0.09 sec)

mysql> show master status;
+-------------------------+----------+--------------+------------------+
| File                    | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+-------------------------+----------+--------------+------------------+
| toshiba-user-bin.000001 |      651 |              |                  |
+-------------------------+----------+--------------+------------------+
1 row in set (0.02 sec)

mysql> exit
Bye

C:\Program Files\MySQL\MySQL Server 5.1\bin>mysqlbinlog "c:\Documents and Settin
gs\All Users\Application Data\MySQL\MySQL Server 5.1\data\toshiba-user-bin.00000
1"
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#080811  8:12:21 server id 1  end_log_pos 106   Start: binlog v 4, server v 5.1.
26-rc-community-log created 080811  8:12:21 at startup
# Warning: this binlog was not closed properly. Most probably mysqld crashed wri
ting it.
ROLLBACK/*!*/;
BINLOG '
NcqfSA8BAAAAZgAAAGoAAAABAAQANS4xLjI2LXJjLWNvbW11bml0eS1sb2cAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA1yp9IEzgNAAgAEgAEBAQEEgAAUwAEGggAAAAICAgC
'/*!*/;
# at 106
#080811  8:12:47 server id 1  end_log_pos 185   Query   thread_id=1     exec_tim
e=0     error_code=0
SET TIMESTAMP=1218431567/*!*/;
SET @@session.pseudo_thread_id=1/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.uniq
ue_checks=1/*!*/;
SET @@session.sql_mode=1344274432/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/
;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@sessio
n.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
CREATE DATABASE d1
/*!*/;
# at 185
#080811  8:12:47 server id 1  end_log_pos 270   Query   thread_id=1     exec_tim
e=0     error_code=0
use d1/*!*/;
SET TIMESTAMP=1218431567/*!*/;
CREATE TABLE t1 (id int)
/*!*/;
# at 270
#080811  8:12:47 server id 1  end_log_pos 336   Query   thread_id=1     exec_tim
e=0     error_code=0
SET TIMESTAMP=1218431567/*!*/;
BEGIN
/*!*/;
# at 336
#080811  8:12:47 server id 1  end_log_pos 443   Query   thread_id=1     exec_tim
e=0     error_code=0
SET TIMESTAMP=1218431567/*!*/;
INSERT INTO t1 (id) VALUES (1),(2),(3),(4),(5)
/*!*/;
# at 443
#080811  8:12:47 server id 1  end_log_pos 470   Xid = 7
COMMIT/*!*/;
# at 470
#080811  8:12:48 server id 1  end_log_pos 536   Query   thread_id=1     exec_tim
e=0     error_code=0
SET TIMESTAMP=1218431568/*!*/;
BEGIN
/*!*/;
# at 536
# at 575
#080811  8:12:48 server id 1  end_log_pos 575   Table_map: `d1`.`t1` mapped to n
umber 15
#080811  8:12:48 server id 1  end_log_pos 624   Delete_rows: table id 15 flags:
STMT_END_F

BINLOG '
UMqfSBMBAAAAJwAAAD8CAAAAAA8AAAAAAAAAAmQxAAJ0MQABAwAB
UMqfSBkBAAAAMQAAAHACAAAQAA8AAAAAAAEAAf/+AQAAAP4CAAAA/gMAAAD+BAAAAA==
'/*!*/;
# at 624
#080811  8:12:48 server id 1  end_log_pos 651   Xid = 8
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

Please, check what I am doing wrong and/or send your my.ini file content.

I now see what you see.  Please close, as this is not a bug.