Bug #39569 events_bugs fails sporadically on pushbuild (should have failed with errno 1539)
Submitted: 21 Sep 2008 15:17 Modified: 10 Nov 2008 17:43
Reporter: Sven Sandberg Email Updates:
Status: Closed Impact on me:
None 
Category:Tests: Replication Severity:S7 (Test Cases)
Version:5.1, 6.0, all trees OS:Any
Assigned to: Matthias Leich CPU Architecture:Any
Tags: disabled, events_bugs, pushbuild, sporadic, test failure

[21 Sep 2008 15:17] Sven Sandberg
Description:
events_bugs fails sporadically on pushbuild with this error message:

main.events_bugs                         [ fail ]

CURRENT_TEST: main.events_bugs
mysqltest: At line 904: query 'DROP EVENT e1' succeeded - should have failed with errno 1539...

The result from queries just before the failure was:
< snip >

# Waiting for the event scheduler to execute and drop event e1...
Timeout in wait_condition.inc for SELECT COUNT(*) = 0
FROM INFORMATION_SCHEMA.EVENTS
WHERE event_schema = 'events_test' AND event_name = 'e1'

# Waiting for the event scheduler to execute and update event e2...

SET GLOBAL EVENT_SCHEDULER = OFF;

SELECT
event_name,
last_executed IS NULL,
definer
FROM INFORMATION_SCHEMA.EVENTS
WHERE event_schema = 'events_test';
event_name	last_executed IS NULL	definer
e1	1	mysqltest_u1@localhost
e2	0	mysqltest_u1@localhost

More results from queries before failure can be found in e:\var-ps_row-101\1\log\events_bugs.log

 - saving 'e:/var-ps_row-101/1/log/main.events_bugs/' to 'e:/var-ps_row-101/log/main.events_bugs/'

Retrying test, attempt(2/3)...

cygpath -m C:/cygwin/home/pushbuild/pb1/pb/bzr_mysql-5.1-rpl/56/mysql-5.1.30-pb56/sql/release/mysqld.exe
cygpath -m e:/var-ps_row-101/1/mysqld.1/mysqld.err
cygpath -m e:/var-ps_row-101/1/mysqld.1/mysqld.err
cygpath -m C:/cygwin/home/pushbuild/pb1/pb/bzr_mysql-5.1-rpl/56/mysql-5.1.30-pb56/client/release//mysqltest.exe
cygpath -m e:/var-ps_row-101/1/tmp/check-mysqld_1.err
cygpath -m C:/cygwin/home/pushbuild/pb1/pb/bzr_mysql-5.1-rpl/56/mysql-5.1.30-pb56/client/release//mysqltest.exe
cygpath -m e:/var-ps_row-101/1/log/current_test

How to repeat:
E.g., here: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-rpl&order=56 'vm-win2003-32-a' Win32 VS2003 -max-nt/ps_row

See also xref: http://tinyurl.com/3wtpox
[16 Oct 2008 19:20] Matthias Leich
The problem:
============
--echo # Waiting for the event scheduler to execute and drop event e1...
let $wait_timeout = 2;
<======= This wait_timeout is a bit small.
  My experience with testing boxes and high parallel
  load is, that there might be a delay between execution
  of one statement and the next one of up to ~ 2 seconds.
  This is especially valid if we have a switch to another
  thread between the statement executions.
let $wait_condition =
  SELECT COUNT(*) = 0
  FROM INFORMATION_SCHEMA.EVENTS
  WHERE event_schema = 'events_test' AND event_name = 'e1';
--source include/wait_condition.inc
<======= The protocol of the problematic test run shows
  here "Timeout in wait_condition.inc ...."
  = The event e1 did not disappear.

--echo
--echo # Waiting for the event scheduler to execute and update event e2...
let $wait_condition =
  SELECT last_executed IS NOT NULL
  FROM INFORMATION_SCHEMA.EVENTS
  WHERE event_schema = 'events_test' AND event_name = 'e2';
--source include/wait_condition.inc

--echo

SET GLOBAL EVENT_SCHEDULER = OFF;
<=== Now the EVENT_SCHEDULER is OFF which means even if
     there are actions to be done by him like removal of
     event "e1" he cannot do this.
     

--echo

SELECT
  event_name,
  last_executed IS NULL,
  definer
FROM INFORMATION_SCHEMA.EVENTS
WHERE event_schema = 'events_test';
<== The protocol of the problematic test run shows here
   event_name	last_executed IS NULL	definer
   e1	1	mysqltest_u1@localhost
   e2	0	mysqltest_u1@localhost
    whereas it is expected that the event e1
    does no more exists.

--echo

--error ER_EVENT_DOES_NOT_EXIST
DROP EVENT e1;
<== We get here
    DROP EVENT e1' succeeded - should have failed with
    errno 1539...
    because the EVENT SCHEDULER had with
    no 

Conclusion: $wait_timeout has to be increased
[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
[27 Oct 2008 21:23] 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:24] Matthias Leich
Pushed to
5.1-bugteam
6.0-bugteam
[10 Nov 2008 10:51] 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.
[19 Jan 2009 11:33] 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:09] 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:15] 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)