| Bug #47017 | rpl_timezone fails on PB-2 with mismatch error | ||
|---|---|---|---|
| Submitted: | 31 Aug 2009 11:53 | Modified: | 15 Mar 2010 4:19 |
| Reporter: | Andrei Elkin | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | Tests: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.1 | OS: | Any |
| Assigned to: | Magne Mæhre | CPU Architecture: | Any |
| Tags: | experimental, pb2, test failure | ||
[4 Sep 2009 11:49]
Luis Soares
Looking into rpl_timezone, one can find that sometimes, the
following snippet of the test case produces unexpected results:
SET @@session.time_zone='+01:00';
insert into t1 values('2008-12-23 19:39:39',1);
--connection master1
SET @@session.time_zone='+02:00';
insert delayed into t1 values ('2008-12-23 19:39:39',2);
# Forces table t1 to be closed and flushes the query cache.
# This makes sure that 'delayed insert' is executed before next statement.
flush table t1;
flush logs;
select * from t1;
DROP TABLE t1;
let $MYSQLD_DATADIR= `select @@datadir;`;
--exec $MYSQL_BINLOG $MYSQLD_DATADIR/master-bin.000001 | $MYSQL
--connection master1
select * from t1 order by a;
This is the case when the test fails and its output shows:
select * from t1;
date a
2008-12-23 20:39:39 1
-2008-12-23 19:39:39 2
DROP TABLE t1;
select * from t1 order by a;
date a
2008-12-23 20:39:39 1
-2008-12-23 19:39:39 2
From the above, one can infer that:
1. It seems as if in some test runs, the insert delayed is
never executed. This would explain the first:
-2008-12-23 19:39:39 2
2. Since it is not executed, it won't be logged, and that
should be the reason for the second:
-2008-12-23 19:39:39 2
Checking the binary log of a failed test run, one can confirm 2.,
only the first insert is logged, followed by the 'flush table t1'
command.
This seems to suggest that there is some sort of race between the
thread that issues 'flush table t1' and the handler thread for
the insert delayed, causing the insert delayed to never happen.
[29 Sep 2009 9:27]
James Grinter
I see this same test failure with:
- mysql-5.1.38
- Sun Solaris 10 (5/09)
- Sun Studio 12 Update 1
and configured as follows:
CFLAGS="-Xa -fast -native -xstrconst -mt -m64" \
CXXFLAGS="-noex -mt -m64" ASFLAGS="-m64" \
./configure \
--prefix=$MYSQLHOME \
--enable-assembler \
--enable-local-infile \
--enable-thread-safe-client \
--localstatedir=/var/mysql \
--with-unix-socket-path=/var/mysql/mysql.sock \
--with-zlib-dir=bundled \
--with-big-tables \
--with-extra-charsets=complex \
--with-mysqld-user=mysql \
--with-pic \
--with-ssl \
--with-csv-storage-engine \
--with-archive-storage-engine \
--with-blackhole-storage-engine \
--without-example-storage-engine \
--with-federated-storage-engine \
--with-partition \
--with-innodb \
--with-readline \
--with-mysqld-ldflags=-static \
--with-client-ldflags=-static \
--with-mysqld-libs=-lmtmalloc \
--with-named-curses=-lcurses
[27 Oct 2009 10:05]
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/88291 2904 Alexander Nozdrin 2009-10-27 Make rpl_timezone experimental due to Bug#47017.
[31 Oct 2009 8:20]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091031081410-qkxmjsdzjmj840aq) (version source revid:alik@sun.com-20091027100714-26ep7fxosmzznon3) (merge vers: 6.0.14-alpha) (pib:13)
[31 Oct 2009 8:21]
Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091031081110-58tn67wz7226hk03) (version source revid:alik@sun.com-20091027100506-2k0dzw3qoa19ffaa) (merge vers: 5.5.0-beta) (pib:13)
[9 Dec 2009 22:10]
Magne Mæhre
This is not a server bug. What happens is, as suggested in an earlier comment, that there is a race between the INSERT DELAYED thread and the client thread's FLUSH TABLE. The FLUSH TABLE does not guarantee (as is (wrongly) suggested in the test case) that the INSERT DELAYED is ever executed. The execution of the test case will thus not be deterministic. Note: When MDL is introduced, the test case will probably be deterministic.
[10 Dec 2009 1:09]
Luis Soares
Hi Magne,
Until then, can't the following hunk make the test deterministic?
=== modified file 'mysql-test/suite/rpl/t/rpl_timezone.test'
--- mysql-test/suite/rpl/t/rpl_timezone.test 2009-03-25 10:42:16 +0000
+++ mysql-test/suite/rpl/t/rpl_timezone.test 2009-12-10 01:03:51 +0000
@@ -179,8 +179,10 @@
--connection master1
SET @@session.time_zone='+02:00';
insert delayed into t1 values ('2008-12-23 19:39:39',2);
-# Forces table t1 to be closed and flushes the query cache.
-# This makes sure that 'delayed insert' is executed before next statement.
+
+# wait for the delayed insert to be executed
+let $wait_condition= SELECT date FROM t1 WHERE a=2;
+--source include/wait_condition.inc
flush table t1;
flush logs;
select * from t1;
[16 Dec 2009 19:54]
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/94596 3280 Magne Mahre 2009-12-16 Bug#47017 rpl_timezone fails on PB-2 with mismatch error The bug is caused by a race condition between the INSERT DELAYED thread and the client thread's FLUSH TABLE. The FLUSH TABLE does not guarantee (as is (wrongly) suggested in the test case) that the INSERT DELAYED is ever executed. The execution of the test case will thus not be deterministic. The fix has been to do a deterministic verification that both threads are complete by checking the content of the table.
[16 Dec 2009 20:14]
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/94601 3785 Magne Mahre 2009-12-16 After fix of Bug#47017, the rpl_timezone test can be reinstituted (moved out of experimental state)
[19 Dec 2009 8:29]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091217193315-s3ck6ltg8m1zz6r3) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:32]
Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091217150904-ugetvos7v0bo83qe) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:36]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091217191654-rb9sci536v96viaz) (pib:15)
[19 Dec 2009 11:19]
Jon Stephens
Changes affect test code only. No end-user changes to document. Closed.
[15 Jan 2010 9:01]
Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:magne.mahre@sun.com-20091216195356-ofxkjyhl2e21dnzf) (merge vers: 5.1.42) (pib:16)
[10 Feb 2010 10:35]
Luis Soares
Reopening the bug. The test case is still listed in default.experimental in mysql-trunk (revid:alik@sun.com-20100209101036-copgamva3qvs4cc8) "rpl.rpl_timezone* # Bug#47017 2009-10-27 alik rpl_timezone fails on PB-2 with mismatch error" Please fix this and re-close the bug.
[17 Feb 2010 21:17]
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/100679 2981 Magne Mahre 2010-02-17 Bug#47017 rpl_timezone fails on PB-2 with mismatch error This is a post-fix cleanup to move rpl.rpl_timezone out of 'experimental' state.
[25 Feb 2010 19:47]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100225194420-p60r4u90tszj8q2x) (version source revid:magne.mahre@sun.com-20100217212413-546rp2xwppwc1utb) (merge vers: 6.0.14-alpha) (pib:16)
[25 Feb 2010 19:47]
Bugs System
Pushed into 5.5.3-m2 (revid:alik@sun.com-20100225194201-ybqxv77ofcxib3or) (version source revid:magne.mahre@sun.com-20100217211717-ktjzlvcp0g9j7wjj) (merge vers: 5.5.3-m2) (pib:16)
[25 Feb 2010 19:49]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100225194305-h49uyjrlfl3mwo60) (version source revid:magne.mahre@sun.com-20100217211956-5ozkkypq5fspmttd) (pib:16)
[12 Mar 2010 14:12]
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:28]
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:44]
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)
[15 Mar 2010 4:19]
Jon Stephens
Test case only; re-closing.
Description: mysql-5.1-bugteam 507331 tree-gcov-linux-x86_64-tar-gz 507757 tyr35 tree-gcov-linux-x86_64-tar-gz 507757 tyr35 ps rpl rpl_timezone mix 2009-08-28 17:14:08 - Show/hide test output - Original output rpl.rpl_timezone 'mix' [ fail ] Test ended at 2009-08-28 18:53:17 CURRENT_TEST: rpl.rpl_timezone --- /export/home/pb2/build/sb_0-None-1251472658.26/mysql-5.1-bugteam-gcov/mysql-test/suite/rpl/r/rpl_timezone.result 2009-08-28 23:20:21.000000000 +0800 +++ /export/home/pb2/build/sb_0-None-1251472658.26/mysql-5.1-bugteam-gcov/mysql-test/suite/rpl/r/rpl_timezone.reject 2009-08-29 00:53:17.000000000 +0800 @@ -133,12 +133,10 @@ select * from t1; date a 2008-12-23 20:39:39 1 -2008-12-23 19:39:39 2 DROP TABLE t1; http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2294114 shows select * from t1 order by a; date a 2008-12-23 20:39:39 1 -2008-12-23 19:39:39 2 DROP TABLE t1; SET @@session.time_zone = default; End of 5.0 tests mysqltest: Result length mismatch - saving '/export/home/pb2/build/sb_0-None-1251472658.26/mysql-5.1-bugteam-gcov/mysql-test/var/log/rpl.rpl_timezone-mix/' to '/export/home/pb2/build/sb_0-None-1251472658.26/mysql-5.1-bugteam-gcov/mysql-test/var/log/rpl.rpl_timezone-mix/' How to repeat: Look at PB logs.