Bug #61420 Crash in replication event.
Submitted: 6 Jun 2011 8:20 Modified: 10 Feb 2012 16:06
Reporter: Alan Hollis Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.5.8-log MySQL Community Server (GPL) OS:Windows (server 2008r2)
Assigned to: CPU Architecture:Any
Tags: compatible_with, replication, table_def

[6 Jun 2011 8:20] Alan Hollis
Description:
Hi all,

MySQL slave crashed with the dump. 

110603 13:01:15 [Note] Slave I/O thread: connected to master 'repl@192.168.1.216:3306',replication started in log 'mysql-bin.000485' at position 308393519
thd: 0x10cbedb0

000000013F5598F2    mysqld.exe!table_def::compatible_with()[rpl_utility.cc:788]
000000013F481D04    mysqld.exe!Rows_log_event::do_apply_event()[log_event.cc:7637]
000000013F39FB8C    mysqld.exe!apply_event_and_update_pos()[slave.cc:2342]
000000013F3A3D73    mysqld.exe!exec_relay_log_event()[slave.cc:2509]
000000013F3A53CA    mysqld.exe!handle_slave_sql()[slave.cc:3320]
000000013F69F44E    mysqld.exe!pthread_start()[my_winthread.c:63]
000000013F726177    mysqld.exe!_callthreadstartex()[threadex.c:348]
000000013F72622B    mysqld.exe!_threadstartex()[threadex.c:326]
000000007763F56D    kernel32.dll!BaseThreadInitThunk()
0000000077773021    ntdll.dll!RtlUserThreadStart()

How to repeat:
I'm not sure, any help as to how I can find out what's happening in the table_def::compatible_with() method would be helpful.

I have the master/relay logs but the file  'mysql-bin.000485' doesn't exist on the master/slave. So I'm assuming it's updating this based on the relay logs but I'm a little confused/out of my depth.
[6 Jun 2011 8:42] Alan Hollis
I think this could be due to a corrupt bin log. Looking through the file using

mysqlbinlog.exe" --start-position=87605047 --stop-position=967616447 ptsrv15-relay-bin.000414

I get 

/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#110511 15:56:50 server id 4  end_log_pos 107   Start: binlog v 4, server v 5.5.8-log created 110511 15:56:50
BINLOG '
sqPKTQ8EAAAAZwAAAGsAAAAAAAQANS41LjgtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 150
#110526  9:15:48 server id 3  end_log_pos 107   Start: binlog v 4, server v 5.5.8-log created 110526  9:15:48
BINLOG '
NAzeTQ8DAAAAZwAAAGsAAAAAAAQANS41LjgtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
ERROR: Error in Log_event::read_log_event(): 'Sanity check failed', data_len: 1800, event_type: 100
ERROR: Could not read entry at offset 87605047: Error in log format or read error.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
[8 Jun 2011 19:30] Sveta Smirnova
Thank you for the report.

This looks very similar to bug #47103 fix for which was not actually ported to 5.5 series (I will create new bug report about this problem).

Could you please run mysqlbinlog --verbose on problem relay log so we can see SQL statements and confirm these are same?
[8 Jun 2011 19:53] Sveta Smirnova
See also bug #61450
[14 Jun 2011 14:19] Alan Hollis
As requested:

c:\mysqllogbackup>"c:\Program Files\MySQL\MySQL Server 5.5\bin\mysqlbinlog.exe" --verbose --start-position=87605047 --st
op-position=967616447 ptsrv15-relay-bin.000414
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#110511 15:56:50 server id 4  end_log_pos 107   Start: binlog v 4, server v 5.5.8-log created 110511 15:56:50
BINLOG '
sqPKTQ8EAAAAZwAAAGsAAAAAAAQANS41LjgtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 150
#110526  9:15:48 server id 3  end_log_pos 107   Start: binlog v 4, server v 5.5.8-log created 110526  9:15:48
BINLOG '
NAzeTQ8DAAAAZwAAAGsAAAAAAAQANS41LjgtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
ERROR: Error in Log_event::read_log_event(): 'Sanity check failed', data_len: 1800, event_type: 100
ERROR: Could not read entry at offset 87605047: Error in log format or read error.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

Any help? I've backed up all the relay logs around that time and am more than happy to help where I can.

Cheers

Alan
[10 Feb 2012 16:06] Valeriy Kravchuk
Duplicate of bug #61450