Bug #93783 Incomplete statement from binary log file

Description:
Hello,

We have a problem with a simple replication topology with a master and a slave.
The slave stopped with this message (read with mysqlbinlog utility) we are in mixed mode :
Got fatal error 1236 from master when reading data from binary log: 'bogus data in log event; the first event 'mysql-bin.000008' at 87987, the last event read from '/var/log/mysql/mysql-bin.000008' at 123, the last byte read from '/var/log/mysql/mysql-bin.000008' at 88006.'

After looking in the corresponding binlog we see this :
181230 23:21:52 server id 5555551 end_log_pos 1671 CRC32 0xb315b28b Anonymous_GTID last_committed=6 sequence_number=7 rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1671
#181230 23:21:52 server id 5555551 end_log_pos 1832 CRC32 0x6849de14 Query thread_id=12587780 exec_time=0 error_code=0
SET TIMESTAMP=1546208512/*!*/;
GRANT SELECT ON `karmakoma`.`article_tarif` TO 'slave_user'@'%'
/*!*/;
# at 1832
#181230 23:21:52 server id 5555551 end_log_pos 1897 CRC32 0x7801b7e5 Anonymous_GTID last_committed=7 sequence_number=8 rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1897
#181230 23:21:52 server id 5555551 end_log_pos 2057 CRC32 0x00000000 Query thread_id=12587780 exec_time=0 error_code=0
SET TIMESTAMP=1546208512/*!*/;
REVOKE SELECT ON karmakoma.article_tarif FROM 'slave_user
/*!*/;
ERROR: Error in Log_event::read_log_event(): 'Event too small', data_len: 0, event_type: 0
ERROR: Could not read entry at offset 2057: Error in log format or read error.
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

Another similar error with an update :
# at 1959
#190101 23:50:23 server id 5555551 end_log_pos 2018 CRC32 0xcf4cc80d Table_map: `lulli`.`flagtarif` mapped to number 6263
# at 2018
#190101 23:50:23 server id 5555551 end_log_pos 2072 CRC32 0x00000000 Update_rows: table id 6263 flags: STMT_END_F

BINLOG '
r+4rXBNfxVQAOwAAAOIHAAAAAHcYAAAAAAEABWx1bGxpAAlmbGFndGFyaWYABAMREREDAAAADA3I
TM8=
r+4rXB9fxVQANgAAABgIAAAAAHcYAAAAAAEAAgAEAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
'/*!*/;
### UPDATE `lulli`.`flagtarif`
### WHERE
ERROR: Error in Log_event::read_log_event(): 'Event too small', data_len: 0, event_type: 0
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

Another one but different

# at 1566
#181225 23:50:00 server id 5555551 end_log_pos 1647 CRC32 0x8dea0590 Write_rows: table id 18069
# at 1647
#181225 23:50:00 server id 5555551 end_log_pos 1794 CRC32 0x1dfc0b22 Write_rows: table id 18066
# at 1794
#181225 23:50:00 server id 5555551 end_log_pos 1875 CRC32 0x0b855ef2 Write_rows: table id 18069
# at 1875
#181225 23:50:00 server id 5555551 end_log_pos 2022 CRC32 0xabd2f301 Write_rows: table id 18066
ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 81, event_type: 30
WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the l                                          og, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
ROLLBACK /* added by mysqlbinlog */ /*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;

The REVOKE Statement is incomplete and we do not know why.
The same problem occur with other servers and similar topology.

An extract of the configuration file :
event_scheduler                 = ON
server-id = 5555551
binlog_do_db                    = karmakoma
expire_logs_days                = 10
max_binlog_size                 = 300M
sync_binlog                     = 1
log_bin                         = /var/log/mysql/mysql-bin.log
slave_compressed_protocol       = 1
transaction-isolation           = READ-COMMITTED
binlog-format                   = mixed

innodb_flush_log_at_trx_commit  = 1
innodb_log_buffer_size = 64M

We do not know if this an external reason, but sync_binlog is on.
There is no recent crash.
there is no error in the system (we have check for I/O or other disk problem) this is a simple virtual machine.

the replication stop frequently because of this and we have to resynchronize the slave, but this is not just a standbye, there is one application for each slave that read this data.

How to repeat:
This is the first time i see this kind of problem, and i do not see any specific configuration.

Hello Nicolas,

Thank you for the report.
This is duplicate of Bug #84752, which was fixed by internal Bug#22252394 - SLAVE I/O THREAD MAY STOP WHEN BINLOG ROTATES.

[1 Oct 2018 10:54] Margaret Fisher
Fixed by another patch, changelog entry now added for MySQL 5.7.25 and 8.0.14:

With sync_binlog=1 set, if the binary log was rotated during a commit before the binary log end position was updated, replication stopped on the slave because the server attempted to use the old binary log end position with the new binary log file. The server now compares the binary log file name with the active binary log file when updating the binary log end position, so that the issue does not occur.

regards,
Umesh

Hi,
we use 5.7.36-enterprise-commercial-advanced-log
and still have the same issue:

 bogus data in log event; the first event 'mysql-bin.018107' at 89009722, the last event read from '/var/lib/mysql/logbin/mysql-bin.018117' at 53355254, the last byte read from '/var/lib/mysql/logbin/mysql-bin.018117' at 53355273.

mysqlbinlog --no-defaults --base64-output=decode-rows --verbose --verbose --start-position=53355273 /var/lib/mysql/logbin/mysql-bin.018117
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
ERROR: Error in Log_event::read_log_event(): 'Event too small', data_len: 0, event_type: 0
ERROR: Could not read entry at offset 53355273: Error in log format or read error.
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;