| Bug #37766 | main.log_output_func randomly fails in pushbuild | ||
|---|---|---|---|
| Submitted: | 1 Jul 2008 14:33 | Modified: | 8 Dec 2008 13:09 |
| Reporter: | Alexander Nozdrin | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | Tests | Severity: | S7 (Test Cases) |
| Version: | 5.1,6.0-BK | OS: | Any |
| Assigned to: | Horst Hunger | CPU Architecture: | Any |
| Tags: | pushbuild, reason unknown, sporadic, test failure | ||
[1 Jul 2008 14:33]
Alexander Nozdrin
[5 Jul 2008 19:44]
Sven Sandberg
Test case log_output_func fails sporadically on pushbuild with this message: =============begin error in pushbuild 6.0============= main.log_output_func [ fail ] --- /data0/pushbuild/pb1/pb/mysql-6.0-bugteam/39/mysql-6.0.6-alpha-pb39/mysql-test/r/log_output_func.result 2008-05-14 13:02:08.000000000 +0300 +++ /data0/pushbuild/pb1/pb/mysql-6.0-bugteam/39/mysql-6.0.6-alpha-pb39/mysql-test/r/log_output_func.reject 2008-05-15 19:32:04.362969657 +0300 @@ -36,7 +36,7 @@ abc SELECT count(*) from mysql.general_log; count(*) -5 +6 'Bug#35371: Changing general_log file is crashing server' 'SET @@global.general_log_file = @log_file;' SET @@global.log_output = 'FILE'; mysqltest: Result content mismatch Stopping All Servers Restoring snapshot of databases =============end error in pushbuild 6.0============= I also got the following on my local machine once: =============begin error on my machine in 5.1-rpl============= main.log_output_func [ fail ] CURRENT_TEST: main.log_output_func --- /home/sven/bzr/debug-max/5.1-rpl/mysql-test/r/log_output_func.result 2008-06-19 16:05:16.000000000 +0300 +++ /home/sven/bzr/debug-max/5.1-rpl/mysql-test/r/log_output_func.reject 2008-07-03 20:35:52.000000000 +0300 @@ -36,7 +36,7 @@ abc SELECT count(*) from mysql.general_log; count(*) -5 +0 'Bug#35371: Changing general_log file is crashing server' 'SET @@global.general_log_file = @log_file;' SET @@global.log_output = 'FILE'; mysqltest: Result content mismatch - saving '/home/sven/bzr/debug-max/5.1-rpl/mysql-test/var/4/log/main.log_output_func/' to '/home/sven/bzr/debug-max/5.1-rpl/mysql-test/var/log/main.log_output_func/' =============begin error on my machine in 5.1-rpl============= Note that the general log here contained 0 rows and in the error from pushbuild 6 rows, whereas the result file expects 5 rows. I have seen it here: E.g., here: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-6.0-bugteam&order=39 , 'debx86-b' 'double whopper', ps_stm https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-6.0&order=80 , 'sapsrv1' Autopush, n_mix [WARNING: that page is huge and crashes my firefox unless i press 'escape' before it has loaded] https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-6.0-build&order=168 , 'sol10-sparc-a' -max, n_mix
[5 Jul 2008 19:51]
Sven Sandberg
If this turns out to be very difficult to debug, we could make the failure give more information, e.g., replacing
SELECT count(*) from mysql.general_log
by
let $count= `SELECT count(*) from mysql.general_log`;
let $not_ok= `SELECT $count != 5`;
if ($not_ok) {
SELECT * FROM mysql.general_log;
}
and wait until it fails again on pushbuild.
[6 Jul 2008 15:37]
Sven Sandberg
mtr logs
Attachment: log_output_func.zip (application/zip, text), 48.96 KiB.
[6 Jul 2008 15:38]
Sven Sandberg
I got the error again on my local machine in 5.1-rpl. The zipfile above contains some info saved by mtr.
[7 Jul 2008 16:21]
Mattias Jonsson
I also got this on an old machine. The bug (getting 6 instead of 5) is that on a slow machine the previous 'disconnect con2;' is getting into the log AFTER it was truncated... A quick fix for the test is to add '--sleep 1' after the 'disconnect con2;' (it solved the problem on my machine...) (the quit in the slower machine's log can be anywhere since it is a timing problem...) On fast machine: main.log_output_func [ fail ] --- mysql-test/r/log_output_func.result 2008-07-03 15:24:42.000000000 +0300 +++ mysql-test/r/log_output_func.reject 2008-07-07 19:07:38.000000000 +0300 @@ -37,6 +37,14 @@ SELECT count(*) from mysql.general_log; count(*) 5 +SELECT * FROM mysql.general_log; +event_time user_host thread_id server_id command_type argument +2008-07-07 19:07:37 root[root] @ localhost [] 2 1 Query DROP TABLE IF EXISTS t1 +2008-07-07 19:07:37 root[root] @ localhost [] 2 1 Query create table t1(a int) +2008-07-07 19:07:37 root[root] @ localhost [] 2 1 Query INSERT INTO t1 value(1) +2008-07-07 19:07:37 root[root] @ localhost [] 2 1 Query SELECT 'abc' +2008-07-07 19:07:37 root[root] @ localhost [] 2 1 Query SELECT count(*) from mysql.general_log +2008-07-07 19:07:37 root[root] @ localhost [] 2 1 Query SELECT * FROM mysql.general_log 'Bug#35371: Changing general_log file is crashing server' 'SET @@global.general_log_file = @log_file;' SET @@global.log_output = 'FILE'; On slow machine: main.log_output_func [ fail ] --- mysql-test/r/log_output_func.resul2008-07-05 13:26:59.000000000 +0300 +++ mysql-test/r/log_output_func.rejec2008-07-07 19:19:51.000000000 +0300 @@ -36,7 +36,16 @@ abc SELECT count(*) from mysql.general_log; count(*) -5 +6 +SELECT * FROM mysql.general_log; +event_time user_host thread_id server_id command_type argument +2008-07-07 19:19:51 root[root] @ localhost [] 3 1 Quit +2008-07-07 19:19:51 root[root] @ localhost [] 2 1 Query DROP TABLE IF EXISTS t1 +2008-07-07 19:19:51 root[root] @ localhost [] 2 1 Query create table t1(a int) +2008-07-07 19:19:51 root[root] @ localhost [] 2 1 Query INSERT INTO t1 value(1) +2008-07-07 19:19:51 root[root] @ localhost [] 2 1 Query SELECT 'abc' +2008-07-07 19:19:51 root[root] @ localhost [] 2 1 Query SELECT count(*) from mysql.general_log +2008-07-07 19:19:51 root[root] @ localhost [] 2 1 Query SELECT * FROM mysql.general_log 'Bug#35371: Changing general_log file is crashing server' 'SET @@global.general_log_file = @log_file;' SET @@global.log_output = 'FILE';
[10 Jul 2008 10:06]
Sven Sandberg
disabling the test in 5.1-rpl.
[3 Sep 2008 6:21]
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/53099 2734 Horst Hunger 2008-09-02 Fix for bug#37766: Inserted replace result.
[3 Sep 2008 6:22]
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/53100 2672 Horst Hunger 2008-09-02 fix for bug#37766: Inserted a replace_result.
[3 Sep 2008 6:22]
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/53101 2672 Horst Hunger 2008-09-02 fix for bug#37766: Inserted a replace_result.
[3 Sep 2008 6:22]
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/53102 2733 Horst Hunger 2008-09-02 Fix for Bug#37766. Made the "failing" select save and fixed the testcase log_output='FILE'.
[25 Nov 2008 17:29]
Ingo Strüwing
Approved with wishes by email.
[27 Nov 2008 14:51]
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/60062 2713 Horst Hunger 2008-11-27 Fix for Bug#37766: Inserted review results. Reason for the failing test was that "SELECT count(*) from mysql.general_log;" was not always the same number. That was fixed by "...count(*)>4..." as the minimal fulfilled condition. As Bug 35371 was fixed the testcase with "log_output = 'FILE'" was enabled and changed to have always the same result.
[27 Nov 2008 15:41]
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/60072 2759 Horst Hunger 2008-11-27 [merge] Merge of fix for bug#37766 from 5.1 to 6.0.
[8 Dec 2008 10:22]
Bugs System
Pushed into 5.1.31 (revid:horst@mysql.com-20081127145148-835ocjot4eo2fl0g) (version source revid:ingo.struewing@sun.com-20081127173943-2d5a4dw8qratv34x) (pib:5)
[8 Dec 2008 11:33]
Bugs System
Pushed into 6.0.9-alpha (revid:horst@mysql.com-20081127153412-36zfu55f5nk10rrk) (version source revid:ingo.struewing@sun.com-20081127214152-x1avx1b1cyfshx1a) (pib:5)
[8 Dec 2008 13:09]
Paul DuBois
Test case changes. No changelog entry needed.
[19 Jan 2009 11:30]
Bugs System
Pushed into 5.1.31-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090119095303-uwwvxiibtr38djii) (version source revid:tomas.ulin@sun.com-20090108105244-8opp3i85jw0uj5ib) (merge vers: 5.1.31-ndb-6.2.17) (pib:6)
[19 Jan 2009 13:08]
Bugs System
Pushed into 5.1.31-ndb-6.3.21 (revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (version source revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (merge vers: 5.1.31-ndb-6.3.21) (pib:6)
[19 Jan 2009 16:14]
Bugs System
Pushed into 5.1.31-ndb-6.4.1 (revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (version source revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (merge vers: 5.1.31-ndb-6.4.1) (pib:6)
