Bug #48357 | SHOW BINLOG EVENTS: Wrong offset or I/O error | ||
---|---|---|---|
Submitted: | 27 Oct 2009 18:04 | Modified: | 12 Mar 2010 17:02 |
Reporter: | Vladislav Vaintroub | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
Version: | 5.1, next-mr | OS: | Linux (Fedora 11 ) |
Assigned to: | Luis Soares | CPU Architecture: | Any |
[27 Oct 2009 18:04]
Vladislav Vaintroub
[30 Oct 2009 0:14]
Luis Soares
Tried to reproduce the reported test failure without success. I tried on 4 different hosts: 2 ubuntus and 2 fedoras. Please, find details below: Ubuntu x86 (9.04) ================= - Test results: binlog.binlog_database 'row' [ pass ] 349 binlog.binlog_database 'stmt' [ pass ] 173 binlog.binlog_database 'mix' [ pass ] 165 - Kernel: .../mysql-next-mr$ uname -a Linux mobilos 2.6.28-14-generic #47-Ubuntu SMP Sat Jul 25 01:19:55 UTC 2009 x86_64 GNU/Linux - gcc .../mysql-next-mr$ gcc -v Using built-in specs. Target: x86_64-linux-gnu Configured with: ../src/configure -v --with-pkgversion='Ubuntu 4.3.3-5ubuntu4' --with-bugurl=file:///usr/share/doc/gcc-4.3/README.Bugs --enable-languages=c,c++,fortran,objc,obj-c++ --prefix=/usr --enable-shared --with-system-zlib --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --enable-nls --with-gxx-include-dir=/usr/include/c++/4.3 --program-suffix=-4.3 --enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc --enable-mpfr --with-tune=generic --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu Thread model: posix gcc version 4.3.3 (Ubuntu 4.3.3-5ubuntu4) - FS: /dev/sda4 on /home type ext3 (rw,relatime) Ubuntu x86_64 (9.10) ==================== - Test results: binlog.binlog_database 'row' [ pass ] 141 binlog.binlog_database 'stmt' [ pass ] 272 binlog.binlog_database 'mix' [ pass ] 209 - Kernel: ...mysql-next-mr/mysql-test$ uname -a Linux gaia 2.6.31-14-generic #48-Ubuntu SMP Fri Oct 16 14:05:01 UTC 2009 x86_64 GNU/Linux - gcc: ...mysql-next-mr/mysql-test$ gcc -v Using built-in specs. Target: x86_64-linux-gnu Configured with: ../src/configure -v --with-pkgversion='Ubuntu 4.4.1-4ubuntu8' --with-bugurl=file:///usr/share/doc/gcc-4.4/README.Bugs --enable-languages=c,c++,fortran,objc,obj-c++ --prefix=/usr --enable-shared --enable-multiarch --enable-linker-build-id --with-system-zlib --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --with-gxx-include-dir=/usr/include/c++/4.4 --program-suffix=-4.4 --enable-nls --enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc --disable-werror --with-arch-32=i486 --with-tune=generic --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu Thread model: posix gcc version 4.4.1 (Ubuntu 4.4.1-4ubuntu8) - FS: /dev/mapper/vg--gaia-lv--home on /home type ext3 (rw,relatime) Fedora Core 11 x86 ================== - Test results: binlog.binlog_database 'row' [ pass ] 176 binlog.binlog_database 'stmt' [ pass ] 165 binlog.binlog_database 'mix' [ pass ] 201 - Kernel: [lsoares@fc11dev mysql-test]$ uname -a Linux fc11dev 2.6.30.9-90.fc11.i686.PAE #1 SMP Sat Oct 17 11:24:32 EDT 2009 i686 i686 i386 GNU/Linux - gcc: [lsoares@fc11dev mysql-test]$ gcc -v Using built-in specs. Target: i586-redhat-linux Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --with-bugurl=http://bugzilla.redhat.com/bugzilla --enable-bootstrap --enable-shared --enable-threads=posix --enable-checking=release --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-languages=c,c++,objc,obj-c++,java,fortran,ada --enable-java-awt=gtk --disable-dssi --enable-plugin --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-1.5.0.0/jre --enable-libgcj-multifile --enable-java-maintainer-mode --with-ecj-jar=/usr/share/java/eclipse-ecj.jar --disable-libjava-multilib --with-ppl --with-cloog --with-tune=generic --with-arch=i586 --build=i586-redhat-linux Thread model: posix gcc version 4.4.1 20090725 (Red Hat 4.4.1-2) (GCC) - FS: /dev/mapper/vg_fc11dev-lv_root on / type ext4 (rw) Fedora Core 11 x86_64 ===================== - Test results: binlog.binlog_database 'row' [ pass ] 158 binlog.binlog_database 'stmt' [ pass ] 140 binlog.binlog_database 'mix' [ pass ] 134 - Kernel: [lsoares@fc11dev64 mysql-test]$ uname -a Linux fc11dev64 2.6.30.9-90.fc11.x86_64 #1 SMP Sat Oct 17 11:25:35 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux - gcc: [lsoares@fc11dev64 mysql-test]$ gcc -v Using built-in specs. Target: x86_64-redhat-linux Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --with-bugurl=http://bugzilla.redhat.com/bugzilla --enable-bootstrap --enable-shared --enable-threads=posix --enable-checking=release --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-languages=c,c++,objc,obj-c++,java,fortran,ada --enable-java-awt=gtk --disable-dssi --enable-plugin --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-1.5.0.0/jre --enable-libgcj-multifile --enable-java-maintainer-mode --with-ecj-jar=/usr/share/java/eclipse-ecj.jar --disable-libjava-multilib --with-ppl --with-cloog --with-tune=generic --with-arch_32=i586 --build=x86_64-redhat-linux Thread model: posix gcc version 4.4.1 20090725 (Red Hat 4.4.1-2) (GCC) - FS: /dev/mapper/vg_fc11dev-lv_root on / type ext4 (rw)
[30 Oct 2009 1:25]
Vladislav Vaintroub
Maybe it makes sense to add my configure options. I configured with ./configure only On ubuntu everything is ok in my environment too (and on opensuse)
[30 Oct 2009 1:57]
Vladislav Vaintroub
Here are exact steps what I do bzr branch bzr+ssh://bk-internal.mysql.com/bzrroot/server/mysql-next-mr cd mysql-next-nr BUILD/autorun.sh ./configure make cd mysql-test perl mysql-test-run.pl --suite=binlog binlog_database And here is what I get ============================================================================== TEST RESULT TIME (ms) ------------------------------------------------------------ binlog.binlog_database 'row' [ fail ] Test ended at 2009-10-30 03:54:25 CURRENT_TEST: binlog.binlog_database mysqltest: In included file "./include/show_binlog_events.inc": At line 35: query '$show_binlog_events' failed: 1220: Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error The result from queries just before the failure was: set binlog_format=statement; reset master; create database testing_1; use testing_1; create table t1 (a int); create function sf1 (a int) returns int return a+1; create trigger tr1 before insert on t1 for each row insert into t2 values (2*new.a); create procedure sp1 (a int) insert into t1 values(a); drop database testing_1; - saving '/home/vvaintroub/bzr/mysql-next-mr/mysql-test/var/log/binlog.binlog_database-row/' to '/home/vvaintroub/bzr/mysql-next-mr/mysql-test/var/log/binlog.binlog_database-row/' Only 1 of 3 completed. mysql-test-run: *** ERROR: Not all tests completed
[30 Oct 2009 16:30]
Luis Soares
VERIFICATION ============ I was able to reproduce these failures in the platforms using GCC 4.4.x that I mentioned in my comment ealier: "[30 Oct 1:14] Luís Soares". I followed Wlad's instructions "[30 Oct 2:57] Vladislav Vaintroub". Ubuntu 9.10 (x86_64) ==================== binlog.binlog_database 'row' [ fail ] Test ended at 2009-10-30 15:25:14 CURRENT_TEST: binlog.binlog_database mysqltest: In included file "./include/show_binlog_events.inc": At line 35: query '$show_binlog_events' failed: 1220: Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error The result from queries just before the failure was: set binlog_format=statement; reset master; create database testing_1; use testing_1; create table t1 (a int); create function sf1 (a int) returns int return a+1; create trigger tr1 before insert on t1 for each row insert into t2 values (2*new.a); create procedure sp1 (a int) insert into t1 values(a); drop database testing_1; Fedora Core 11 (x86_64) ======================= binlog.binlog_database 'row' [ fail ] Test ended at 2009-10-30 16:00:51 CURRENT_TEST: binlog.binlog_database mysqltest: In included file "./include/show_binlog_events.inc": At line 35: query '$show_binlog_events' failed: 1220: Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error The result from queries just before the failure was: set binlog_format=statement; reset master; create database testing_1; use testing_1; create table t1 (a int); create function sf1 (a int) returns int return a+1; create trigger tr1 before insert on t1 for each row insert into t2 values (2*new.a); create procedure sp1 (a int) insert into t1 values(a); drop database testing_1; COMMENTS ======== It seems that GCC 4.4 is stricter on aliasing requirements [1]. Furthermore, "recent versions of GCC turn on the option -fstrict-aliasing (which allows alias-based optimizations) by default with -O2" [2]. This can result in undefined behavior if aliasing rules are broken, because the compiler assumes that all changes to variables occur through pointer or references that are type compatible to the accessed variable [2]. Note that per the failures reported happened only on binaries built with -O3 and not on regular debug builds. As such, to fix this for now, we can probably rely on the use of "-fno-strict-aliasing" parameter when building MySQL with -O2 (or higher). REFERENCES ========== [1] http://gcc.gnu.org/gcc-4.4/porting_to.html [2] http://gcc.gnu.org/bugs/ (See section "Casting does not work as expected when optimization is turned on.")
[9 Nov 2009 17:36]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/89843 3195 Luis Soares 2009-11-09 BUG#48357: SHOW BINLOG EVENTS: Wrong offset or I/O error In function log_event.cc:Query_log_event::write, there was a cast that was triggering undefined behavior. The offending cast is the following: write_str_with_code_and_len((char **)(&start), catalog, catalog_len, Q_CATALOG_NZ_CODE); This results in calling write_str_with_code_and_len with first argument pointing to a (char **) while "start" is itself a pointer to uchar (uchar *). Inside write_str_with_..., the content of start is then be updated: (*dst)+= len; The instruction above would cause the (*dst) pointer (ie, the "start" argument, from the caller point of view, and which actually points to uchar instead of pointing to char) to be updated so that it would increment catalog_len. However, this seems to break strict-aliasing rules ultimately causing the increment and assignment to behave unexpectedly. We fix this by removing the cast and by making the types match.
[12 Nov 2009 22:34]
Omer Barnir
triage: setting tag to SR51MRU
[19 Dec 2009 8:27]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091216180721-eoa754i79j4ssd3m) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:30]
Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091211164058-ycpe0f20d1c4h1gl) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:34]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091216180221-a5ps59gajad3pip9) (pib:15)
[11 Jan 2010 17:40]
Paul DuBois
Noted in 5.5.1, 6.0.14 changelogs. SHOW BINLOG EVENTS could fail with a "Wrong offset or I/O error" error. Setting report to NDI pending push to 5.1.x, Celosia.
[13 Jan 2010 15:26]
Sveta Smirnova
Bug #50045 was marked as duplicate of this one.
[15 Jan 2010 8:58]
Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:luis.soares@sun.com-20091207002814-2dv3o41n0hozvhvy) (merge vers: 5.1.42) (pib:16)
[15 Jan 2010 19:06]
Paul DuBois
Noted in 5.1.43 changelog. Setting report to NDI pending push to Celosia.
[12 Mar 2010 14:05]
Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:21]
Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:35]
Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)
[12 Mar 2010 17:02]
Paul DuBois
Fixed in earlier 5.1.x, 5.5.x.