Bug #25419 MySQL replication breaks with error 1236
Submitted: 4 Jan 2007 17:57 Modified: 23 May 2007 11:06
Reporter: Martin Tsachev Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.0.27 OS:FreeBSD (FreeBSD 4.11)
Assigned to: CPU Architecture:Any

[4 Jan 2007 17:57] Martin Tsachev
Description:
We have mysql replication which has run fine for a while, it suddenly stopped and this is logged on the slave when I issue start slave:

070104 12:23:08 [Note] Slave I/O thread: connected to master 'slave@10.0.0.1:3306',  replication started in log 'mysql-bin.000048' at position 219042630
070104 12:23:08 [ERROR] Error reading packet from server: error reading log entry ( server_errno=1236)
070104 12:23:08 [ERROR] Got fatal error 1236: 'error reading log entry' from master when reading data from binary log
070104 12:23:08 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000048', position 219042630

There's nothing logged before that would identify the reason why it stopped.

This is the output of show slave status:

*************************** 1. row ***************************
             Slave_IO_State: 
                Master_Host: 10.0.0.1
                Master_User: slave
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000048
        Read_Master_Log_Pos: 219042630
             Relay_Log_File: relay-bin.000142
              Relay_Log_Pos: 235
      Relay_Master_Log_File: mysql-bin.000048
           Slave_IO_Running: No
          Slave_SQL_Running: Yes
            Replicate_Do_DB: 
        Replicate_Ignore_DB: 
         Replicate_Do_Table: 
     Replicate_Ignore_Table: 
    Replicate_Wild_Do_Table: 
Replicate_Wild_Ignore_Table: 
                 Last_Errno: 0
                 Last_Error: 
               Skip_Counter: 0
        Exec_Master_Log_Pos: 219042630
            Relay_Log_Space: 235
            Until_Condition: None
             Until_Log_File: 
              Until_Log_Pos: 0
         Master_SSL_Allowed: No
         Master_SSL_CA_File: 
         Master_SSL_CA_Path: 
            Master_SSL_Cert: 
          Master_SSL_Cipher: 
             Master_SSL_Key: 
      Seconds_Behind_Master: NULL
1 row in set (0.00 sec)

Master continues to write to the log just fine:

+------------------+-----------+--------------+------------------+
| File             | Position  | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+-----------+--------------+------------------+
| mysql-bin.000048 | 495332003 |              |                  | 
+------------------+-----------+--------------+------------------+
1 row in set (0.00 sec)

and it can process the binlog w/o any errors:

[db s1 12:31 PM| /var/db/mysql]# mysqlbinlog mysql-bin.000048 > /dev/null
[db s1 12:31 PM| /var/db/mysql]# 

How to repeat:
Start replication, wait, entry shown above is logged and replication breaks.

Suggested fix:
Replication shouldn't break in the first place.
[4 Jan 2007 17:57] Martin Tsachev
Both master and slave are 5.0.27 on 4.11.
[5 Jan 2007 12:00] Valeriy Kravchuk
Thank you for a problem report. Is it possible for you to upload that binary log, mysql-bin.000048. I want to check what event is in that 'mysql-bin.000048', position 219042630.
[5 Jan 2007 13:18] Martin Tsachev
We haven't stopped binary logging so the file is 1GB. I can use cut/dd to extract only the exact position if it is specified in bytes, not sure how much to get though.

I tried to read just this event but go even too big. Tried to set max_allowed_packet in /etc/my.cnf [mysqlbinlog] but it complains that it doesn't understand it:

mysqlbinlog: unknown variable 'max_allowed_packet=5M'

same for read_buffer_size.

mysqlbinlog --start-position=219042630 -f mysql-bin.000047 
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
ERROR: Error in Log_event::read_log_event(): 'Event too big', data_len: 1462197280, event_type: 110
Could not read entry at offset 219042630:Error in log format or read error
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
[8 Jan 2007 12:21] Martin Tsachev
Weird, I tried to just start slave and got a different error:

070108  6:54:57 [Note] Slave I/O thread: connected to master 'slave@10.0.0.1:3306',  replication started in log 'mysql-bin.000048' at position 219042630
070108  6:54:57 [ERROR] Error reading packet from server: log event entry exceeded max_allowed_packet; Increase max_allowed_packet on master ( server_errno=1236)
070108  6:54:57 [ERROR] Got fatal error 1236: 'log event entry exceeded max_allowed_packet; Increase max_allowed_packet on master' from master when reading data from binary log
070108  6:54:57 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000048', position 219042630

Doing what it suggested helped. Sorry for bugging, I thought my error was different because I saw similar logs in other bugs but mine didn't have the max_allowed_packet part.
[12 Jan 2007 7:59] Sveta Smirnova
Thank you for the additional information.

To be sure your porblem is not a result of a bug, please, increase max_allowed_packet value and check if it solves the problem.
[13 Feb 2007 0:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[2 May 2007 2:17] Michiel Dethmers
would be useful to be able to relate bugs to each other as a user. Just searching on things finds way too many similar issues, and then it's hard to determine which one to add a comment to.

I added one to 27956 which is "Severity S3", and this one is basically the same on S2. I think it's S2 for sure.
[23 May 2007 9:49] Valeriy Kravchuk
Martin,

Can you, please, check with a newer version, 5.0.41. Check also if Sveta's suggestion from the last her comment is relevant.
[23 May 2007 9:54] Martin Tsachev
Increasing max_allowed_packet fixed the problem.
[23 May 2007 11:06] Sveta Smirnova
Thank you for the feedback, Martin.

I'll close the report as "Not a Bug"