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.
