Bug #2556 Error in Log_event::read_log_event(): 'Event too big', data_len: 808333356, eve
Submitted: 29 Jan 2004 8:21 Modified: 6 Mar 2004 12:31
Reporter: [ name withheld ] Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:4.0.17 OS:Linux (Mandrake linux 9.2)
Assigned to: CPU Architecture:Any

[29 Jan 2004 8:21] [ name withheld ]
Description:
Have done this 4 times on diferent servers with 4.0.17
Here is the log:

040113 01:42:12  mysqld started

040113  1:42:12  InnoDB: Started
/usr/sbin/mysqld-max: ready for connections.Version: '4.0.17'-Max'-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306

040113  1:42:13  Slave I/O thread: connected to master 'repl@192.168.19.9:3306',  replication started in log 'FIRST' at 			position 4

040115 22:07:53  Slave I/O thread: error reconnecting to master 'repl@192.168.19.9:3306': Error: 'Can't connect to MySQL 			server on '192.168.19.9' (4)'  errno: 2003  retry-time: 60  retries: 86400

040119 18:15:18  Error in Log_event::read_log_event(): 'Event too big', data_len: 808333356, event_type: 101

040119 18:15:18  Error reading relay log event: slave SQL thread aborted because of I/O error

040119 18:15:18  Slave: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted 		(you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can 			check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's 		MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their 		names by issuing 'SHOW SLAVE STATUS' on this slave. Error_code: 0

040119 18:15:18  Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE 		START". We stopped at log 'Faro_s3-bin.004' position 2085468

040119 19:50:47  Slave I/O thread exiting, read up to log 'Faro_s3-bin.005', position 4754377
		ERROR: 1064  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 		'0000e+000,0.00000000000000000e+000,3.80000000000000000e-001,1.90000000000000000e' at line 1

040119 19:50:55  Error in Log_event::read_log_event(): 'Event too big', data_len: 875573298, event_type: 101

040119 19:50:55  Error reading relay log event: slave SQL thread aborted because of I/O error

040119 19:50:55  Slave: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted 		(you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can 			check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's 		MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their 		names by issuing 'SHOW SLAVE STATUS' on this slave. Error_code: 0

040119 19:50:55  Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE 		START". We stopped at log 'Faro_s3-bin.004' position 2085468

040119 19:50:56  Slave I/O thread: connected to master 'repl@192.168.19.9:3306',  replication started in log 				'Faro_s3-bin.005' at position 4754377
ERROR: 1064  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 				'0000e+000,0.00000000000000000e+000,3.80000000000000000e-001,1.90000000000000000e' at line 1

040119 20:54:15  Error in Log_event::read_log_event(): 'Event too big', data_len: 875573298, event_type: 101

040119 20:54:15  Error reading relay log event: slave SQL thread aborted because of I/O error

040119 20:54:15  Slave: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted 		(you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can 			check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's 		MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their 		names by issuing 'SHOW SLAVE STATUS' on this slave. Error_code: 0

040119 20:54:15  Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE 		START". We stopped at log 'Faro_s3-bin.004' position 2085468

040119 22:26:59  Slave: received 0 length packet from server, apparent master shutdown: 

040119 22:26:59  Slave I/O thread: Failed reading log event, reconnecting to retry, log 'Faro_s3-bin.005' position 4754377

040119 22:26:59  Slave I/O thread: error reconnecting to master 'repl@192.168.19.9:3306': Error: 'Lost connection to MySQL 		server during query'  errno: 2013  retry-time: 60  retries: 86400

040119 22:29:11  /usr/sbin/mysqld-max: Normal shutdown

040119 22:29:11  Slave I/O thread exiting, read up to log 'Faro_s3-bin.005', position 4754377

040119 22:29:13  InnoDB: Starting shutdown...

040119 22:29:16  InnoDB: Shutdown completed

040119 22:29:16  /usr/sbin/mysqld-max: Shutdown Complete

040119 22:29:16  mysqld ended

040119 22:38:19  mysqld started

040119 22:38:20  InnoDB: Started
		/usr/sbin/mysqld-max: ready for connections.
		Version: '4.0.17'-Max'-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306

040119 22:38:21  Slave I/O thread: connected to master 'repl@192.168.19.9:3306',  replication started in log 		'Faro_s3-bin.004' at position 2085468

ERROR: 1062  Duplicate entry '302169' for key 1
ERROR: 1062  Duplicate entry '201581' for key 1
ERROR: 1062  Duplicate entry '603180' for key 1
ERROR: 1062  Duplicate entry '603181' for key 1
ERROR: 1062  Duplicate entry '603182' for key 1

040120 16:07:51  Error reading packet from server: log event entry exceeded max_allowed_packet; Increase max_allowed_packet 		on master (server_errno=1236)

040120 16:07:51  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

040120 16:07:51  Slave I/O thread exiting, read up to log 'Faro_s3-bin.008', position 19071740
ERROR: 1064  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 'INSERTuni' at line 1

040120 22:49:49  /usr/sbin/mysqld-max: Normal shutdown

040120 22:49:50  InnoDB: Starting shutdown...

040120 22:49:54  InnoDB: Shutdown completed

040120 22:49:54  /usr/sbin/mysqld-max: Shutdown Complete

040120 22:49:54  mysqld ended

How to repeat:
this happens with big transactions and high updates
[29 Jan 2004 9:42] Dmitry Lenev
Hi, David!

There is high probability that your master's binary log is damaged... 
Could you please provide us with ouput of mysqlbinlog for your masters bin-log 'Faro_s3-bin.004' and position 2085468 ? You can do this by running 

mysqlbinlog --position=2085468 Faro_s3-bin.004 

On your master in directory where binary logs are stored .

Thank you!
[30 Jan 2004 1:47] [ name withheld ]
I already deleted faro_s3-bin.004. But those 3 events in log are very strange (look at dates & time):

040115 22:07:53  Slave I/O thread: error reconnecting to master 'repl@192.168.19.9:3306': Error: 'Can't connect to MySQL	server on
'192.168.19.9' (4)'  errno: 2003  retry-time: 60  retries: 86400

040119 18:15:18  Error in Log_event::read_log_event(): 'Event too big',
data_len: 808333356, event_type: 101

040119 18:15:18  Error reading relay log event: slave SQL thread aborted because
of I/O error
[30 Jan 2004 1:49] [ name withheld ]
it seems that it lost connection on day 15 and on day 19 it corrupted replication.
[30 Jan 2004 3:32] [ name withheld ]
It happens again on another master/slave:
040129 21:09:30  Slave I/O thread exiting, read up to log 'Lagos_s3-bin.010', position 10791128
040129 21:09:58  Slave I/O thread: connected to master 'repl@192.168.13.11:3306',  replication started in log 'Lagos_s3-bin.010' at position 10791128
040129 21:27:06  Error in Log_event::read_log_event(): 'Event too big', data_len: 808464432, event_type: 48
040129 21:27:06  Error reading relay log event: slave SQL thread aborted because of I/O error
040129 21:27:06  Slave: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave. Error_code: 0
040129 21:27:06  Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'Lagos_s3-bin.010' position 12183140
040129 23:01:38  Slave I/O thread: error reconnecting to master 'repl@192.168.13.11:3306': Error: 'Lost connection to MySQL server during query'  errno: 2013  retry-time: 60  retries: 86400

I have done a mysqlbinlog --position=12183140 Lagos_s3-bin.010

result is :

ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 808464432, event_type: 48
ERROR: Could not read entry at offset 12183140 : Error in log format or read error
[30 Jan 2004 5:01] Guilhem Bichot
Please save Lagos_s3-bin.010 and run
mysqlbinlog Lagos_s3-bin.010 > /dev/null
If this prints no line to your screen, then your master's binlog Lagos_s3-bin.010 is correct.
[30 Jan 2004 9:42] [ name withheld ]
This seems to be the same bug as bug #437
I have already done 
mysqlbinlog Lagos_s3-bin.010 > /dev/null 
with no results.
[30 Jan 2004 9:52] Guilhem Bichot
What does
"I have already done 
mysqlbinlog Lagos_s3-bin.010 > /dev/null 
with no results." mean?
Do you mean nothing was printed to the terminal ?
[30 Jan 2004 10:42] [ name withheld ]
yes, nothing was printed on terminal
[2 Feb 2004 7:04] Guilhem Bichot
Hi,
So master's binlog are good and slave's relay log get repeatedly corrupted: indeed it contains impossible queries like:
040120 16:07:51  Slave I/O thread exiting, read up to log 'Faro_s3-bin.008',
position 19071740 ERROR: 1064  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 'INSERTuni' at line 1
The position of the master's binlog reported by the slave when it stops is wrong (it corresponds to no valid event whereas the master's binlog is valid).
Next time you get a problem, please save the slave's relay logs, and run
mysqlbinlog xxx > /dev/null
where xxx is replaced by all saved relay logs names. Run this command for every relay log, and tell me if it prints error messages. This will help us know if the relay log is corrupted, or if it is good but the slave reads it wrongly.
In any case, please keep all relay logs of the moment when the problem happened, because I may like to inspect them. If they are corrupted, looking at the place of corruption may help me understand what is going wrong. For example to know if this happened near a disconnection/reconnection (when the master/slave connection gets interrupted, the slave tries to reconnect immediately; if it succeeds it does not print a message mentioning the disconnection/reconnection; this message is only printed if some more reconnections are needed).
[2 Feb 2004 7:28] [ name withheld ]
What is the meaning of :
"have an error in your SQL syntax.  Check the manual that corresponds to your MySQL server version for the right syntax to use near 'INSERTuni' at line 1"

Where can i find ' INSERTuni' ?
[3 Feb 2004 5:57] Guilhem Bichot
If you open a client to the MySQL server, and you type:
INSERTuni <whatever>;
then you get "you have an error in your syntax".
The same way, your slave is reading the master's binary log and is seeing (don't know why) a query "INSERTuni <whatever>" so parses it (to execute it) but it fails with "you have an error in your syntax".
Such bad query means that the slave is doing something wrong: maybe its relay log contains garbage, maybe the relay log is good but the slave is reading it badly.
Like if in your emails you saw crazy characters everywhere, you would say that either your email files are corrupted or your email client is reading them wrongly.
[6 Feb 2004 6:21] [ name withheld ]
the problem happened again . How can i send you the logs and what logs do you want ?
[6 Feb 2004 6:28] Guilhem Bichot
Hi!

As I said previously:
"Next time you get a problem, please save the slave's relay logs, and
run
mysqlbinlog xxx > /dev/null
where xxx is replaced by all saved relay logs names. Run this command
for every relay log, and tell me if it prints error messages. This will
help us know if the relay log is corrupted, or if it is good but the
slave reads it wrongly.
In any case, please keep all relay logs of the moment when the problem
happened, because I may like to inspect them. If they are corrupted,
looking at the place of corruption may help me understand what is going
wrong. For example to know if this happened near a
disconnection/reconnection (when the master/slave connection gets
interrupted, the slave tries to reconnect immediately; if it succeeds
it does not print a message mentioning the disconnection/reconnection;
this message is only printed if some more reconnections are needed)."

So please first run the mysqlbinlog explained above, on relay logs.

Thanks for your help.
Guilhem
[6 Feb 2004 7:32] [ name withheld ]
One of the relay logs returned an error. I have all relay logs and error logs if you want them. 
We are considering downgrading to version 3.23.56 that we used in the past without a single error on 4 servers. Do you think this can be because of a bad update process?
[6 Feb 2004 7:43] Guilhem Bichot
Please upload the relay log which has an error at
ftp://support.mysql.com/pub/mysql/secret
with a meaningful name like "bug2556", and let me know when it's done.

Thank you.
[6 Feb 2004 8:19] [ name withheld ]
compressed file and update to FTP is complete.
[6 Feb 2004 12:31] Guilhem Bichot
I looked at it. It is truncated: 82 bytes are missing at end.
Can you please upload the next relay log (the one which was created just after the corrupted one, so it's probably faro_s1-relay-bin.030)?
By the way mysqlbinlog shows very strange 'exec_time' values...
Another question: how do you shutdown mysqld on your master?
Thank you!
[14 Feb 2005 22:54] 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".