Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Won't Fix
-
10.3(EOL)
-
None
Description
I am filing it as "Tests" issue for now, but it needs to be investigated further, possibly there is an underlying problem there bigger than just tests.
There were numerous test failures (none of which is from the usual sporadically failing bunch) on a build run on Nov 11 between 01:00 and 02:00 in one of US timezones, e.g. p801 running kvm-deb-bionic-ppc64le.
All failures are happening apparently because an event which is supposed to be executed was not.
Current time can be seen in timestamps on ".reject" files.
10.3 |
roles.definer w4 [ fail ]
|
Test ended at 2020-11-01 01:01:29
|
|
CURRENT_TEST: roles.definer
|
--- /usr/share/mysql/mysql-test/suite/roles/definer.result 2020-10-31 21:03:42.000000000 -0400
|
+++ /dev/shm/var/4/log/definer.reject 2020-11-01 01:01:29.721397954 -0400
|
@@ -267,11 +267,15 @@
|
show create event e2;
|
Event sql_mode time_zone Create Event character_set_client collation_connection Database Collation
|
e2 STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION SYSTEM CREATE DEFINER=`role2` EVENT `e2` ON SCHEDULE EVERY 1 SECOND STARTS '2000-01-01 00:00:00' ON COMPLETION NOT PRESERVE ENABLE DO insert t1 values (111, 4, 0) latin1 latin1_swedish_ci latin1_swedish_ci
|
+Timeout in wait_condition.inc for select count(*) >= 4 from t1
|
+Id User Host db Command Time State Info Progress
|
+39 root localhost mysqltest1 Query 0 Init show full processlist 0.000
|
+40 foo localhost mysqltest1 Sleep 30 NULL 0.000
|
+41 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
set global event_scheduler=off;
|
select distinct * from t1;
|
a b c
|
1 10 100
|
-111 4 0
|
2 20 200
|
delete from t1 where a=111;
|
main.create_drop_event w1 [ fail ]
|
Test ended at 2020-11-01 01:02:08
|
|
CURRENT_TEST: main.create_drop_event
|
--- /usr/share/mysql/mysql-test/main/create_drop_event.result 2020-10-31 21:03:38.000000000 -0400
|
+++ /dev/shm/var/1/log/create_drop_event.reject 2020-11-01 01:02:08.489834905 -0400
|
@@ -10,9 +10,12 @@
|
EVENT_NAME EVENT_DEFINITION
|
ev1 INSERT INTO t1 VALUES (10)
|
SET GLOBAL event_scheduler=on;
|
+Timeout in wait_condition.inc for SELECT count(*)>0 FROM t1
|
+Id User Host db Command Time State Info Progress
|
+1098 root localhost test Query 0 Init show full processlist 0.000
|
+1099 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
SELECT DISTINCT a FROM t1;
|
a
|
-10
|
SET GLOBAL event_scheduler=off;
|
DELETE FROM t1;
|
CREATE EVENT ev1 ON SCHEDULE EVERY 1 SECOND DO INSERT INTO t1 VALUES (11);
|
@@ -34,9 +37,12 @@
|
EVENT_NAME EVENT_DEFINITION
|
ev1 INSERT INTO t1 VALUES (13)
|
SET GLOBAL event_scheduler=on;
|
+Timeout in wait_condition.inc for SELECT count(*)>0 FROM t1
|
+Id User Host db Command Time State Info Progress
|
+1098 root localhost test Query 0 Init show full processlist 0.000
|
+1100 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
SELECT DISTINCT a FROM t1;
|
a
|
-13
|
SET GLOBAL event_scheduler=off;
|
DELETE FROM t1;
|
DROP EVENT IF EXISTS ev1;
|
|
mysqltest: Result length mismatch
|
main.openssl_1 w3 [ fail ]
|
Test ended at 2020-11-01 01:02:53
|
|
CURRENT_TEST: main.openssl_1
|
mysqltest: At line 156: query 'SELECT variable_name, variable_value FROM thread_status' failed: 1146: Table 'test.thread_status' doesn't exist
|
|
The result from queries just before the failure was:
|
< snip >
|
End of 5.0 tests
|
DROP TABLE IF EXISTS thread_status;
|
DROP EVENT IF EXISTS event_status;
|
SET GLOBAL event_scheduler=1;
|
CREATE EVENT event_status
|
ON SCHEDULE AT NOW()
|
ON COMPLETION NOT PRESERVE
|
DO
|
BEGIN
|
CREATE TABLE thread_status
|
SELECT variable_name, variable_value
|
FROM information_schema.session_status
|
WHERE variable_name LIKE 'SSL_ACCEPTS' OR
|
variable_name LIKE 'SSL_CALLBACK_CACHE_HITS';
|
END$$
|
Timeout in wait_condition.inc for select count(*) = 0 from information_schema.events where event_name='event_status'
|
Id User Host db Command Time State Info Progress
|
10958 root localhost test Query 0 Init show full processlist 0.000
|
10969 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
SELECT variable_name, variable_value FROM thread_status;
|
|
mysqltest: Result length mismatch
|
main.events_1 w1 [ fail ]
|
Test ended at 2020-11-01 01:04:44
|
|
CURRENT_TEST: main.events_1
|
--- /usr/share/mysql/mysql-test/main/events_1.result 2020-10-31 21:03:38.000000000 -0400
|
+++ /dev/shm/var/1/log/events_1.reject 2020-11-01 01:04:44.403567695 -0400
|
@@ -105,20 +105,27 @@
|
insert into test_nested values(1);
|
end|
|
set global event_scheduler = on;
|
+Timeout in wait_condition.inc for SELECT count(*)>0 from mysql.event where name='e_43' and interval_value= 5
|
+Id User Host db Command Time State Info Progress
|
+26 root localhost events_test Query 0 Init show full processlist 0.000
|
+29 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
select db, name, body, status, interval_field, interval_value from mysql.event;
|
db name body status interval_field interval_value
|
events_test e_43 begin
|
alter event e_43 on schedule every 5 minute;
|
insert into test_nested values(1);
|
-end ENABLED MINUTE 5
|
+end ENABLED SECOND 1
|
drop event e_43;
|
drop table test_nested;
|
"Let's check whether we can use non-qualified names"
|
create table non_qualif(a int);
|
create event non_qualif_ev on schedule every 10 minute do insert into non_qualif values (800219);
|
+Timeout in wait_condition.inc for SELECT count(*)= 1 from non_qualif where a=800219
|
+Id User Host db Command Time State Info Progress
|
+26 root localhost events_test Query 0 Init show full processlist 0.000
|
+29 event_scheduler localhost NULL Daemon 60 Waiting for next activation NULL 0.000
|
select * from non_qualif;
|
a
|
-800219
|
drop event non_qualif_ev;
|
drop table non_qualif;
|
alter event non_existant rename to non_existant_too;
|
|
mysqltest: Result length mismatch
|
main.events_slowlog w3 [ fail ]
|
Test ended at 2020-11-01 01:06:00
|
|
CURRENT_TEST: main.events_slowlog
|
--- /usr/share/mysql/mysql-test/main/events_slowlog.result 2020-10-31 21:03:38.000000000 -0400
|
+++ /dev/shm/var/3/log/events_slowlog.reject 2020-11-01 01:06:00.760404303 -0400
|
@@ -6,7 +6,11 @@
|
create table t1 (i int);
|
insert into t1 values (0);
|
create event ev on schedule at CURRENT_TIMESTAMP + INTERVAL 1 second do update t1 set i=1+sleep(0.5);
|
-FOUND 1 /update t1 set i=1/ in mysqld-slow.log
|
+Timeout in wait_condition.inc for select i from t1 where i > 0
|
+Id User Host db Command Time State Info Progress
|
+9 root localhost test Query 0 Init show full processlist 0.000
|
+10 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
+NOT FOUND /update t1 set i=1/ in mysqld-slow.log
|
drop table t1;
|
set global event_scheduler= @event_scheduler_save;
|
set global slow_query_log= @slow_query_log_save;
|
|
mysqltest: Result length mismatch
|
main.events_2 w2 [ fail ]
|
Test ended at 2020-11-01 01:07:01
|
|
CURRENT_TEST: main.events_2
|
--- /usr/share/mysql/mysql-test/main/events_2.result 2020-10-31 21:03:38.000000000 -0400
|
+++ /dev/shm/var/2/log/events_2.reject 2020-11-01 01:07:00.693056404 -0400
|
@@ -54,13 +54,19 @@
|
"Create an event which tries to acquire a mutex. The event locks on the mutex"
|
create event закачка on schedule every 10 hour do select get_lock("test_lock2", 20);
|
"Should have only 2 processes: the scheduler and the locked event"
|
+Timeout in wait_condition.inc for select count(*) = 2 from information_schema.processlist
|
+where ( (state like 'User lock%' AND info like 'select get_lock%')
|
+OR (command='Daemon' AND user='event_scheduler' AND
|
+state = 'Waiting for next activation'))
|
+Id User Host db Command Time State Info Progress
|
+4 root localhost events_test Query 0 Init show full processlist 0.000
|
+5 event_scheduler localhost NULL Daemon 30 Waiting for next activation NULL 0.000
|
select /*2*/ user, host, db, command, state, info
|
from information_schema.processlist
|
where (info like "select get_lock%" OR user='event_scheduler')
|
order by info;
|
user host db command state info
|
event_scheduler localhost NULL Daemon Waiting for next activation NULL
|
-root localhost events_test Connect User lock select get_lock("test_lock2", 20)
|
"Release the mutex, the event worker should finish."
|
select release_lock("test_lock2");
|
release_lock("test_lock2")
|
@@ -72,21 +78,30 @@
|
1
|
create event закачка21 on schedule every 10 hour do select get_lock("test_lock2_1", 20);
|
"Should have only 2 processes: the scheduler and the locked event"
|
+Timeout in wait_condition.inc for select count(*) = 2 from information_schema.processlist
|
+where ( (state like 'User lock%' AND info like 'select get_lock%')
|
+OR (command='Daemon' AND user='event_scheduler' AND
|
+state = 'Waiting for next activation'))
|
+Id User Host db Command Time State Info Progress
|
+4 root localhost events_test Query 0 Init show full processlist 0.000
|
+5 event_scheduler localhost NULL Daemon 60 Waiting for next activation NULL 0.000
|
select /*3*/ user, host, db, command, state, info
|
from information_schema.processlist
|
where (info like "select get_lock%" OR user='event_scheduler')
|
order by info;
|
user host db command state info
|
event_scheduler localhost NULL Daemon Waiting for next activation NULL
|
-root localhost events_test Connect User lock select get_lock("test_lock2_1", 20)
|
set global event_scheduler=off;
|
+Timeout in wait_condition.inc for select count(*) =1 from information_schema.processlist
|
+where (info like "select get_lock%" OR user='event_scheduler')
|
+Id User Host db Command Time State Info Progress
|
+4 root localhost events_test Query 0 Init show full processlist 0.000
|
"Should have only our process now:"
|
select /*4*/ user, host, db, command, state, info
|
from information_schema.processlist
|
where (info like "select get_lock%" OR user='event_scheduler')
|
order by info;
|
user host db command state info
|
-root localhost events_test Connect User lock select get_lock("test_lock2_1", 20)
|
select release_lock("test_lock2_1");
|
release_lock("test_lock2_1")
|
1
|
|
mysqltest: Result length mismatch
|
main.events_scheduling w4 [ fail ]
|
Test ended at 2020-11-01 01:07:31
|
|
CURRENT_TEST: main.events_scheduling
|
mysqltest: At line 100: query 'DROP EVENT event_3' succeeded - should have failed with errno 1539...
|
|
The result from queries just before the failure was:
|
< snip >
|
Id User Host db Command Time State Info Progress
|
11 root localhost events_test Query 0 Init show full processlist 0.000
|
13 event_scheduler localhost NULL Daemon 60 Waiting for next activation NULL 0.000
|
Timeout in wait_condition.inc for select count(*) = 0 from information_schema.events
|
where event_name='event_3'
|
Id User Host db Command Time State Info Progress
|
11 root localhost events_test Query 0 Init show full processlist 0.000
|
13 event_scheduler localhost NULL Daemon 90 Waiting for next activation NULL 0.000
|
Timeout in wait_condition.inc for select count(*) = 0 from information_schema.events
|
where event_name='event_4' and status='enabled'
|
Id User Host db Command Time State Info Progress
|
11 root localhost events_test Query 0 Init show full processlist 0.000
|
13 event_scheduler localhost NULL Daemon 120 Waiting for next activation NULL 0.000
|
SELECT IF(TIME_TO_SEC(TIMEDIFF(ENDS,STARTS))=6, 'OK', 'ERROR')
|
FROM INFORMATION_SCHEMA.EVENTS
|
WHERE EVENT_SCHEMA=DATABASE() AND EVENT_NAME='event_2';
|
IF(TIME_TO_SEC(TIMEDIFF(ENDS,STARTS))=6, 'OK', 'ERROR')
|
OK
|
"Already dropped because ended. Therefore an error."
|
DROP EVENT event_3;
|