Arch Linux

Please read this before reporting a bug:
https://wiki.archlinux.org/title/Bug_reporting_guidelines

Do NOT report bugs when a package is just outdated, or it is in the AUR. Use the 'flag out of date' link on the package page, or the Mailing List.

REPEAT: Do NOT report bugs for outdated packages!
Tasklist

FS#16105 - [mysql] corrupt binlog

Attached to Project: Arch Linux
Opened by Brent Pitman (bpitman0001) - Wednesday, 09 September 2009, 03:42 GMT
Last edited by Allan McRae (Allan) - Sunday, 27 September 2009, 21:59 GMT
Task Type Bug Report
Category Packages: Extra
Status Closed
Assigned To Pierre Schmitz (Pierre)
Douglas Soares de Andrade (dsa)
Architecture x86_64
Severity High
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Certain apps are causing corruption in the master bin-log. I was able to reproduce this on three servers:

Run `mysql_upgrade`, which runs `mysql_fix_privilege_tables`. It executes on the database just fine, but the sql in the binlog is corrupt (all replication stops). I also have a php site running in apache that corrupts the binlog (not sure if it's on every write). However, I have a java site running in tomcat that isn't causing any problems.

I do not think I was having any problems with the i686 build, but can't prove it and am unable to test (I just finished upgrading all servers to x86_64).

[root@arizona mysqld]# pacman -Qi mysql
Name : mysql
Version : 5.1.37-1
URL : http://www.mysql.com/
Licenses : GPL
Groups : None
Provides : None
Depends On : mysql-clients>=5.1.37 tcp_wrappers zlib perl
Optional Deps : perl-dbi
perl-dbd-mysql
Required By : kmbrnt-bugzilla
Conflicts With : None
Replaces : None
Installed Size : 60136.00 K
Packager : Douglas Soares de Andrade <douglas@archlinux.org>
Architecture : x86_64
Build Date : Fri 31 Jul 2009 11:31:45 AM PDT
Install Date : Sat 01 Aug 2009 08:44:02 AM PDT
Install Reason : Explicitly installed
Install Script : No
Description : A fast SQL database server


[root@arizona mysqld]# mysqlbinlog arizona-bin.000004 | tail -XXX
# at 1168723
#090908 19:35:25 server id 10 end_log_pos 1168856 Query thread_id=4319 exec_time=0 error_code=0
SET TIMESTAMP=1252463725/*!*/;
ALTER TABLE procs_priv
MODIFY Timestamp timestamp(14) AFTER Proc_priv
/*!*/;
# at 1168856
#090908 19:35:25 server id 10 end_log_pos 1171069 Query thread_id=4319 exec_time=0 error_code=0
use SYSTEMmysql/*!*/;
SET TIMESTAMP=1252463725/*!*/;
mysqlALTER TABLE proc MODIFY name char(64) DEFAULT '' NOT NULL,
MODIFY specific_name char(64) DEFAULT '' NOT NULL,
MODIFY sql_data_access
enum('CONTAINS_SQL',
'NO_SQL',
'READS_SQL_DATA',
'MODIFIES_SQL_DATA'
) DEFAULT 'CONTAINS_SQL' NOT NULL,
MODIFY body longblob NOT NULL,
MODIFY returns longblob NOT NULL,
MODIFY sql_mode
set('REAL_AS_FLOAT',
'PIPES_AS_CONCAT',
'ANSI_QUOTES',
'IGNORE_SPACE',
'NOT_USED',
'ONLY_FULL_GROUP_BY',
'NO_UNSIGNED_SUBTRACTION',
'NO_DIR_IN_CREATE',
'POSTGRESQL',
'ORACLE',
'MSSQL',
'DB2',
'MAXDB',
'NO_KEY_OPTIONS',
'NO_TABLE_OPTIONS',
'NO_FIELD_OPTIONS',
'MYSQL323',
'MYSQL40',
'ANSI',
'NO_AUTO_VALUE_ON_ZERO',
'NO_BACKSLASH_ESCAPES',
'STRICT_TRANS_TABLES',
'STRICT_ALL_TABLES',
'NO_ZERO_IN_DATE',
'NO_ZERO_DATE',
'INVALID_DATES',
'ERROR_FOR_DIVISION_BY_ZERO',
'TRADITIONAL',
'NO_AUTO_CREATE_USER',
'HIGH_NOT_PRECEDENCE',
'NO_ENGINE_SUBSTITUTION',
'PAD_CHAR_TO_FULL_LENGTH'
) DEFAULT '' NOT NULL,
DEFAULT CHARACTER SE
/*!*/;

Note that I've syncing the binlog to disk on every write:
[root@arizona mysqld]# grep sync /etc/my.cnf
sync-binlog = 1
** whether this field is set to 0 or 1, it seems to have no impact
This task depends upon

Closed by  Allan McRae (Allan)
Sunday, 27 September 2009, 21:59 GMT
Reason for closing:  Fixed
Comment by Brent Pitman (bpitman0001) - Wednesday, 09 September 2009, 03:48 GMT
Just to be clear, these are the problems (text inserted, lost and truncated from sql):

use SYSTEMmysql/*!*/;
...
mysqlALTER TABLE proc MODIFY name char(64) DEFAULT '' NOT NULL,
...
) DEFAULT '' NOT NULL,
DEFAULT CHARACTER SE
/*!*/;
Comment by Brent Pitman (bpitman0001) - Wednesday, 09 September 2009, 06:20 GMT
I reviewed my `pacman -S --refresh` logs. I'm pretty sure I was running a i686 version of mysql-5.1.37-1 without any problems (it was running for about a month). During that time, one slave was running the x86_64 version. Replication was working fine (though, nothing was replicating from that slave, nor did I ever validate the relay bin logs).
Comment by Douglas Soares de Andrade (dsa) - Wednesday, 09 September 2009, 07:13 GMT
Hi Allan,

Any idea on this one ? It is not clear to me what to do.

I will update mysql to 5.1.38 and we can see if it is still happening.
Comment by Allan McRae (Allan) - Wednesday, 09 September 2009, 07:27 GMT
No idea on this one... Also no idea why it was assigned to me! :P
Comment by Gerardo Exequiel Pozzi (djgera) - Thursday, 10 September 2009, 00:56 GMT
oops, the intention was assign to Pierre,
Comment by Brent Pitman (bpitman0001) - Thursday, 10 September 2009, 04:08 GMT
I just tried rebuilding the database to see if it would help. It didn't.

1) Stop updates to mysql
> echo set global read_only = 1 | mysql -h myhost -p
2) Dump the database
> /usr/bin/mysqldump -h myhost --user=root --password=XxXxXxXx --single-transaction --flush-logs --master-data=2 --all-databases | gzip -c | mysql.dump.sql.gz
3) Stop mysql (also stop all slaves)
> /etc/rc.d/mysql stop
4) Move datadir to backup location
> mv $datadir $datadir.bk
5) Create new datadir
> mkdir $datadir
> mysql_install_db
> mkdir $datadir/$innodbdirs
> chown mysql:mysql -R $datadir
6) Start new mysql
> /etc/rc.d/mysql start
> echo set global read_only = 1 | mysql -h myhost -p
> ## wait for innodb to initialize
7) Fix root password
8) Insert dumped sql into new instance
> gzip -cd mysql.dump.sql.gz | mysql -h myhost -p

I ran this with no errors. All of the databases that were in the old mysql are now in the new mysql (in other words, it appears to have inserted all the old data). However, the binlog is corrupt - it stops at the insert of the bugzilla `bugs` table into the `bugs` database (which is about half way through the old data). While there is much more data in the file (corruption starts at about position 116335566 of a 193432733 byte file), mysqlbinlog isn't showing any of it.

-rw-rw---- 1 mysql mysql 193432733 2009-09-09 20:30 arizona-bin.000003

ERROR: Error in Log_event::read_log_event(): 'Sanity check failed', data_len: 655946, event_type: 76
ERROR: Could not read entry at offset 116407281: Error in log format or read error.
# at 116335566
#090909 20:23:24 server id 10 end_log_pos 116407281 Query thread_id=4 exec_time=0 error_code=0
use +00:00bugs/*!*/;
SET TIMESTAMP=1252553004/*!*/;
0bugsINSERT INTO `bugs` VALUES
...-01-04 12:44:17',1,1,1,'0.00','0.00'
/*!*/;

Reviewing the sql from the dump, it only truncated 6 chars from the end on the INSERT - it should have ended with:
...-01-04 12:44:17',1,1,1,'0.00','0.00',NULL)
/*!*/;

Also interesting to note that the text entered in the `use` statement has been 6 chars in every instance of corruption I've investigated (I've seem 'SYSTEM' and '+00:00') and the text inserted before the INSERT (or UPDATE, etc) has been 5 chars (I've seen '_live', 'mysql', '0bugs' - they are all the last 5 chars of the database name, 0 padded).
Comment by Brent Pitman (bpitman0001) - Sunday, 13 September 2009, 21:59 GMT
Where can I find the options we use to compile mysql for archlinux x86_64? The PKGBUILD file? Thanks.
Comment by Brent Pitman (bpitman0001) - Sunday, 13 September 2009, 22:28 GMT
I downloaded 5.1.38 source from mysql and ran into the exact same problem.

## configuration options
./configure --prefix=/usr/local/mysql --with-plugins=innobase,innodb_plugin

ERROR: Error in Log_event::read_log_event(): 'Sanity check failed', data_len: 655946, event_type: 76
# at 116335566
#090913 15:15:54 server id 10 end_log_pos 116407281 Query thread_id=3 exec_time=0 error_code=0
use +00:00bugs/*!*/;
SET TIMESTAMP=1252880154/*!*/;
0bugsINSERT INTO `bugs` VALUES
...-01-04 12:44:17',1,1,1,'0.00','0.00'
/*!*/;
Comment by Brent Pitman (bpitman0001) - Sunday, 13 September 2009, 23:27 GMT
Same problem after compiling 5.0.85. I'll keep trying to find a pre-compiled release on mysql.com. Not sure if this is a bug in the mysql x86_64 code and/or the archlinux x86_64 environment.
Comment by Brent Pitman (bpitman0001) - Sunday, 13 September 2009, 23:58 GMT
Downloaded and ran mysql-5.1.38-linux-x86_64-glibc23.tar.gz (no compiling, just untar in /usr/local). No errors in binlog after importing database dump. I think there is something wrong with the archlinux x86_64 compile environment.

[root@alabama mysqld]# mysqlbinlog alabama-bin.000003 | tail
/*!*/;
# at 193450211
#090913 16:53:11 server id 1 end_log_pos 193450325 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1252885991/*!*/;
/*!40000 ALTER TABLE `ccm_users` ENABLE KEYS */
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
Comment by Allan McRae (Allan) - Monday, 14 September 2009, 00:28 GMT
Try rebuilding mysql-clients and mysql with the same CFLAGS as in libmysqlclient

i.e. add this to their PKGBUILDs
CFLAGS="-fPIC ${CFLAGS} -fno-strict-aliasing"
CXXFLAGS="-fPIC ${CXXFLAGS} -fno-strict-aliasing"
Comment by Brent Pitman (bpitman0001) - Monday, 14 September 2009, 01:34 GMT
That's much better. Using source 5.1.38.

#configuration options
./configure --prefix=/usr/local/mysql --with-plugins=innobase,innodb_plugin CFLAGS="-fPIC ${CFLAGS} -fno-strict-aliasing" CXXFLAGS="-fPIC ${CXXFLAGS} -fno-strict-aliasing"

[root@arizona mysqld]# mysql -v
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.1.38-log Source distribution


No errors importing database:
[root@arizona mysqld]# mysqlbinlog arizona-bin.000003 | tail
/*!*/;
# at 193450211
#090913 18:31:09 server id 10 end_log_pos 193450325 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1252891869/*!*/;
/*!40000 ALTER TABLE `ccm_users` ENABLE KEYS */
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
Comment by Brent Pitman (bpitman0001) - Wednesday, 16 September 2009, 01:46 GMT
Anyone have an eta for when an updated mysql package will be available with these compiler settings? Is there anything I can do to help?
Comment by Brent Pitman (bpitman0001) - Sunday, 27 September 2009, 16:36 GMT
The new version fixed the problem (5.1.38-1).

Loading...