| Bug #39863 | events_bugs fails sporadically on pushbuild (extra processes in I_S.PROCESSLIST) | ||
|---|---|---|---|
| Submitted: | 4 Oct 2008 14:56 | Modified: | 28 Nov 2008 18:20 |
| Reporter: | Sven Sandberg | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | Tests: Server | Severity: | S7 (Test Cases) |
| Version: | 5.1, 6.0 | OS: | Any |
| Assigned to: | Matthias Leich | CPU Architecture: | Any |
| Tags: | disabled, events_bugs, pushbuild, sporadic, test failure | ||
[9 Oct 2008 19:58]
Matthias Leich
Different timing related effect which should be also fixed: Logging: ./mysql-test-run.pl --mem events_bugs events_bugs events_bugs events_bugs events_bugs events_bugs events_bugs events_bugs .... Symlinking 'var' to '/dev/shm/var' Installing Master Database ======================================================= TEST RESULT TIME (ms) ------------------------------------------------------- main.events_bugs [ pass ] 18749 main.events_bugs [ fail ] --- ... r/events_bugs.result +++ ... r/events_bugs.reject @@ -5,7 +5,7 @@ use events_test; select * from information_schema.global_variables where variable_name like 'event_scheduler'; VARIABLE_NAME VARIABLE_VALUE -EVENT_SCHEDULER ON +EVENT_SCHEDULER OFF SET GLOBAL event_scheduler = 'OFF'; CREATE EVENT lower_case ON SCHEDULE EVERY 1 MINUTE DO SELECT 1; CREATE EVENT Lower_case ON SCHEDULE EVERY 2 MINUTE DO SELECT 2;
[13 Oct 2008 15:24]
Matthias Leich
Experimenting with the goal to reproduce the problem. Till now no success, but several new bugs in events tests found.
[15 Oct 2008 15:44]
Matthias Leich
The last reported effect is now Bug#39978 main.events_bugs does not clean up
[15 Oct 2008 16:34]
Matthias Leich
The first reported effect (additional line in
PROCESSLIST with info = "select get_lock
('test_bug16407', 60)") seems be caused by:
===========================================
The subtest for Bug#16407 does the following
1. The default session creates the user lock
"test_bug16407.
2. An event which tries to get the same user
lock is created.
3. It is waited till within the PROCESSLIST a
sessions exists which waits for getting
this user lock
= The execution of the event (2.) is running.
4. The default session releases the user lock.
5. It is expected that 4. causes that the event
execution completes because the lock was released
by the default session
= the session which executes the event and hangs
when requesting the user lock disappears from
the PROCESSLIST
And exact this session did not end within the current
bug. The reason might be that the release of the
user lock had no effect. See also
Bug#32782 User lock hash fails to find lock.
There is no obvious mistake within the event_bugs.test
code and logics which could cause the observed effect.
[16 Oct 2008 19:46]
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/56416 2672 Matthias Leich 2008-10-16 - Fix for Bug #39848, #39863, #39978, #39569 Bug#39848 events_bugs fails sporadically on pushbuild (missing rows in table event_log) Details: Reimplement the subtest for BUG 28924 - check if the number of rows within the table event_log changes but don't print rows because the number varies depending on load on testing box - shift DROP USER befor DROP EVENT = Subtest fits again to old bug - remove no more needed comments + variables Bug#39863 events_bugs fails sporadically on pushbuild (extra processes in I_S.PROCESSLIST) Details: Abort with appropriate message to the protocol if release_lock() does not has the intended effect. This cannot prevent problems caused by the probably buggy release_lock() but it reveals if we had a problem in this area. Bug#39978 main.events_bugs does not clean up Detail: Restore global.event_scheduler = ON at end of test Bug#39569 events_bugs fails sporadically on pushbuild (should have failed with errno 1539) Detail: Set $wait_timeout to 4 instead of 2 - Minor improvements of formatting Details: - Add comments - Remove tabs and trailing blanks - Add line breaks for better readability
[17 Oct 2008 12:55]
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/56471 2673 Matthias Leich 2008-10-17 - Fix for Bug #39848, #39863, #39978, #39569 Bug#39848 events_bugs fails sporadically on pushbuild (missing rows in table event_log) Details: Reimplement the subtest for BUG 28924 - check if the number of rows within the table event_log changes but don't print rows because the number varies depending on load on testing box - shift DROP USER befor DROP EVENT = Subtest fits again to old bug - remove no more needed comments + variables Bug#39863 events_bugs fails sporadically on pushbuild (extra processes in I_S.PROCESSLIST) Details: Abort with appropriate message to the protocol if release_lock() does not has the intended effect. This cannot prevent problems caused by the probably buggy release_lock() but it reveals if we had a problem in this area. Bug#39978 main.events_bugs does not clean up Detail: Restore global.event_scheduler = ON at end of test Bug#39569 events_bugs fails sporadically on pushbuild (should have failed with errno 1539) Detail: Set $wait_timeout to 4 instead of 2 - Fix two instabilities (result sets pulled from processlist in subtest for bug 16407) which were found during tests with high parallel I/O load - Minor improvements of formatting Details: - Add comments - Remove tabs and trailing blanks - Add line breaks for better readability
[17 Oct 2008 13:08]
Matthias Leich
One note about the patch above: If we have a non fixed bug within "release_lock" than the patch above cannot avoid that we get sporadic result differences when running "events_bugs". But the patch causes an - appropriate message to the protocol - immediate abort of test if release_lock() does not has the intended effect.
[27 Oct 2008 21:22]
Patrick Crews
Ok to push.
[4 Nov 2008 11:27]
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/57771 2692 Matthias Leich 2008-11-04 - Fix for Bug #39848, #39863, #39978, #39569 Bug#39848 events_bugs fails sporadically on pushbuild (missing rows in table event_log) Details: Reimplement the subtest for BUG 28924 - check if the number of rows within the table event_log changes but don't print rows because the number varies depending on load on testing box - shift DROP USER befor DROP EVENT = Subtest fits again to old bug - remove no more needed comments + variables Bug#39863 events_bugs fails sporadically on pushbuild (extra processes in I_S.PROCESSLIST) Details: Abort with appropriate message to the protocol if release_lock() does not has the intended effect. This cannot prevent problems caused by the probably buggy release_lock() but it reveals if we had a problem in this area. Bug#39978 main.events_bugs does not clean up Detail: Restore global.event_scheduler = ON at end of test Bug#39569 events_bugs fails sporadically on pushbuild (should have failed with errno 1539) Detail: Set $wait_timeout to 4 instead of 2 - Fix two instabilities (result sets pulled from processlist in subtest for bug 16407) which were found during tests with high parallel I/O load - Minor improvements of formatting Details: - Add comments - Remove tabs and trailing blanks - Add line breaks for better readability
[5 Nov 2008 12:27]
Matthias Leich
Pushed to 5.1-bugteam 6.0-bugteam
[10 Nov 2008 10:53]
Bugs System
Pushed into 6.0.8-alpha (revid:matthias.leich@sun.com-20081104112721-bqfae4rvb8tatg2e) (version source revid:matthias.leich@sun.com-20081104183908-ux6g8n3yj43bd43l) (pib:5)
[10 Nov 2008 11:36]
Bugs System
Pushed into 5.1.30 (revid:matthias.leich@sun.com-20081104112721-bqfae4rvb8tatg2e) (version source revid:matthias.leich@sun.com-20081104180256-w9rqsaozf7wby5ab) (pib:5)
[10 Nov 2008 17:43]
Paul DuBois
Test case changes. No changelog entry needed.
[26 Nov 2008 17:06]
Sven Sandberg
Re-opening bug. I got the following failure in a tree which has the above changeset:
--- /data0/pushbuild/pb2-2/pb/bzr_mysql-5.1-rpl/87/mysql-5.1.31-pb87/mysql-test/r/events_bugs.result 2008-11-21 11:24:25.000000000 +0300
+++ /data0/pushbuild/pb2-2/pb/bzr_mysql-5.1-rpl/87/mysql-5.1.31-pb87/mysql-test/r/events_bugs.reject 2008-11-21 12:28:44.000000000 +0300
@@ -170,6 +170,11 @@
order by info;
user host db info
event_scheduler localhost NULL NULL
+root localhost events_test CREATE PROCEDURE `ee_16407_2`() SQL SECURITY INVOKER begin
+select get_lock('ee_16407_2', 60) /*ee_16407_2*/;
+select release_lock('ee_16407_2');
+insert into events_test.events_smode_test values('ee_16407_2','1980-19-02');
+end
root localhost events_test select get_lock('ee_16407_5', 60)
root localhost events_test select get_lock('ee_16407_5', 60)
select release_lock('ee_16407_5');
mysqltest: Result content mismatch
This is from https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-rpl&order=87 sles10-ia64-a-2/ps_row
[26 Nov 2008 17:08]
Sven Sandberg
There are two other symptoms than the two mentioned above. Please ensure that all four get fixed.
==== Failure 3 ====
main.events_bugs [ fail ]
CURRENT_TEST: main.events_bugs
--- /data0/pushbuild/pb/bzr_mysql-6.0-rpl/87/mysql-6.0.8-alpha-pb87/mysql-test/r/events_bugs.result 2008-10-14 13:12:29.000000000 +0300
+++ /data0/pushbuild/pb/bzr_mysql-6.0-rpl/87/mysql-6.0.8-alpha-pb87/mysql-test/r/events_bugs.reject 2008-10-14 13:29:58.000000000 +0300
@@ -61,6 +61,7 @@
"Now if everything is fine the event has compiled and is locked"
select /*1*/ user, host, db, info from information_schema.processlist where command!='Daemon' and (info is null or info not like '%processlist%') order by info;
user host db info
+root localhost NULL NULL
root localhost events_test select get_lock('test_bug16407', 60)
select release_lock('test_bug16407');
release_lock('test_bug16407')
@@ -117,6 +118,7 @@
select /*2*/ user, host, db, info from information_schema.processlist where (command!='Daemon' || user='event_scheduler') and (info is null or info not like '%processlist%') order by info;
user host db info
event_scheduler localhost NULL NULL
+root localhost NULL NULL
root localhost events_test select get_lock('ee_16407_2', 60)
root localhost events_test select get_lock('ee_16407_2', 60)
root localhost events_test select get_lock('ee_16407_2', 60)
mysqltest: Result content mismatch
From https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-5.1-opt&order=402 sol10-sparc-a/ps_row
==== Failure 4 ====
main.events_bugs [ fail ]
--- /export/home/pushbuild/pb/mysql-5.1-marvel/95/mysql-5.1.24-rc-pb95/mysql-test/r/events_bugs.result Wed Feb 27 23:39:48 2008
+++ /export/home/pushbuild/pb/mysql-5.1-marvel/95/mysql-5.1.24-rc-pb95/mysql-test/r/events_bugs.reject Sun Mar 2 18:20:52 2008
@@ -117,6 +117,9 @@
select /*2*/ user, host, db, info from information_schema.processlist where (command!='Daemon' || user='event_scheduler') and (info is null or info not like '%processlist%') order by info;
user host db info
event_scheduler localhost NULL NULL
+root localhost events_test CREATE PROCEDURE `e_16407`() SQL SECURITY INVOKER begin
+select get_lock('test_bug16407', 60);
+end
root localhost events_test select get_lock('ee_16407_2', 60)
root localhost events_test select get_lock('ee_16407_2', 60)
root localhost events_test select get_lock('ee_16407_2', 60)
mysqltest: Result content mismatch
From https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-6.0-runtime&order=12 debx86-b/n_mix
[26 Nov 2008 17:10]
Sven Sandberg
Here is an xref link that shows all the four symptoms above: http://tinyurl.com/6d347q
[28 Nov 2008 18:20]
Matthias Leich
The failures added by Sven will be tracked in Bug#41111 events_bugs fails sporadically on pushbuild
[19 Jan 2009 11:28]
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:06]
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:12]
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)
Description: Pushbuild failure: main.events_bugs [ fail ] --- /export/home/pushbuild/pb/bzr_mysql-5.1-telco-6.3/112/mysql-5.1.28-ndb-6.3.18-pb112/mysql-test/r/events_bugs.result Fri Oct 3 13:30:34 2008 +++ /export/home/pushbuild/pb/bzr_mysql-5.1-telco-6.3/112/mysql-5.1.28-ndb-6.3.18-pb112/mysql-test/r/events_bugs.reject Fri Oct 3 14:25:13 2008 @@ -120,6 +120,7 @@ root localhost events_test select get_lock('ee_16407_2', 60) root localhost events_test select get_lock('ee_16407_2', 60) root localhost events_test select get_lock('ee_16407_2', 60) +root localhost events_test select get_lock('test_bug16407', 60) select release_lock('ee_16407_2'); release_lock('ee_16407_2') 1 mysqltest: Result content mismatch Stopping All Servers Restoring snapshot of databases How to repeat: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-telco-6.3&order=... sol10-amd64-a/ps_row Has failed 39 times according to xref: http://tinyurl.com/47bx7s Suggested fix: Fails in all trees, both 5.1 and 6.0, mostly on slow machines. Probably a race?