Description:
This bug is similar to bug #20624, bug #18981, and bug #18953. The symptom is slightly different, so I'm opening a new bug.
main.events_logs_tests [ fail ]
Errors are (from /Users/henry/pb/mysql-5.1-marvel/68/mysql-5.1.21-beta-pb68/mysql-test/var-ps_stm-6/log/mysqltest-time) :
mysqltest: Result length mismatch
(the last lines may be the most important ones)
Below are the diffs between actual and expected results:
-------------------------------------------------------
*** /Users/henry/pb/mysql-5.1-marvel/68/mysql-5.1.21-beta-pb68/mysql-test/r/events_logs_tests.result Thu Aug 2 11:06:00 2007
--- /Users/henry/pb/mysql-5.1-marvel/68/mysql-5.1.21-beta-pb68/mysql-test/r/events_logs_tests.reject Thu Aug 2 12:52:54 2007
***************
*** 48,54 ****
0
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
- USER_HOST SLEEPVAL events_test SELECT SLEEP(2)
SET SESSION long_query_time=300;
"Make it quite long"
TRUNCATE mysql.slow_log;
--- 48,53 ----
-------------------------------------------------------
On a few solaris hosts, we have many more failures:
-------------------------------------------------------
*** /export/home/pushbuild/pb/mysql-5.1-marvel/64/mysql-5.1.21-beta-pb64/mysql-test/r/events_logs_tests.result Mon Jul 30 11:53:56 2007
--- /export/home/pushbuild/pb/mysql-5.1-marvel/64/mysql-5.1.21-beta-pb64/mysql-test/r/events_logs_tests.reject Mon Jul 30 12:37:28 2007
***************
*** 22,28 ****
CALL select_general_log();
user_host argument
USER_HOST CREATE EVENT log_general ON SCHEDULE EVERY 1 MINUTE DO SELECT 'alabala', SLEEP(1) FROM DUAL
- USER_HOST SELECT 'alabala', SLEEP(1) FROM DUAL
DROP PROCEDURE select_general_log;
DROP EVENT log_general;
SET GLOBAL event_scheduler=off;
--- 22,27 ----
***************
*** 39,44 ****
--- 38,44 ----
TRUNCATE mysql.slow_log;
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
+ USER_HOST 838:59:59 events_test TRUNCATE mysql.slow_log
"Set new values"
SET GLOBAL long_query_time=4;
SET SESSION long_query_time=1;
***************
*** 48,53 ****
--- 48,56 ----
0
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
+ USER_HOST SLEEPVAL events_test TRUNCATE mysql.slow_log
+ USER_HOST SLEEPVAL events_test SET GLOBAL long_query_time=4
+ USER_HOST SLEEPVAL events_test SET SESSION long_query_time=1
USER_HOST SLEEPVAL events_test SELECT SLEEP(2)
SET SESSION long_query_time=300;
"Make it quite long"
***************
*** 68,78 ****
"Check our table. Should see 1 row"
SELECT * FROM slow_event_test;
slo_val val
- 20 0
"Check slow log. Should not see anything because 1.5 is under the threshold of 20 for GLOBAL, though over SESSION which is 1"
"This should show that the GLOBAL value is regarded and not the SESSION one of the current connection"
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
"Another test to show that GLOBAL is regarded and not SESSION."
"This should go to the slow log"
SET SESSION long_query_time=10;
--- 71,86 ----
"Check our table. Should see 1 row"
SELECT * FROM slow_event_test;
slo_val val
"Check slow log. Should not see anything because 1.5 is under the threshold of 20 for GLOBAL, though over SESSION which is 1"
"This should show that the GLOBAL value is regarded and not the SESSION one of the current connection"
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
+ root[root] @ localhost [] 838:59:59 events_test TRUNCATE mysql.slow_log
+ root[root] @ localhost [] 838:59:59 events_test CREATE TABLE slow_event_test (slo_val tinyint, val tinyint)
+ root[root] @ localhost [] 838:59:59 events_test SET SESSION long_query_time=1
+ root[root] @ localhost [] 838:59:59 events_test SET SESSION long_query_time=1
+ root[root] @ localhost [] 838:59:59 events_test SET GLOBAL event_scheduler=on
+ root[root] @ localhost [] 838:59:59 events_test SET GLOBAL long_query_time=20
"Another test to show that GLOBAL is regarded and not SESSION."
"This should go to the slow log"
SET SESSION long_query_time=10;
***************
*** 80,94 ****
SET GLOBAL long_query_time=1;
CREATE EVENT long_event2 ON SCHEDULE EVERY 1 MINUTE DO INSERT INTO slow_event_test SELECT @@long_query_time, SLEEP(2);
"Sleep some more time than the actual event run will take"
"Check our table. Should see 2 rows"
SELECT * FROM slow_event_test;
slo_val val
- 20 0
- 1 0
"Check slow log. Should see 1 row because 2 is over the threshold of 1 for GLOBAL, though under SESSION which is 10"
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
! USER_HOST SLEEPVAL events_test INSERT INTO slow_event_test SELECT @@long_query_time, SLEEP(2)
DROP EVENT long_event2;
"Make it quite long"
SET SESSION long_query_time=300;
--- 88,109 ----
SET GLOBAL long_query_time=1;
CREATE EVENT long_event2 ON SCHEDULE EVERY 1 MINUTE DO INSERT INTO slow_event_test SELECT @@long_query_time, SLEEP(2);
"Sleep some more time than the actual event run will take"
+ Timeout in wait_condition.inc for SELECT COUNT(*) = 1 FROM mysql.slow_log
"Check our table. Should see 2 rows"
SELECT * FROM slow_event_test;
slo_val val
"Check slow log. Should see 1 row because 2 is over the threshold of 1 for GLOBAL, though under SESSION which is 10"
SELECT user_host, query_time, db, sql_text FROM mysql.slow_log;
user_host query_time db sql_text
! USER_HOST SLEEPVAL events_test TRUNCATE mysql.slow_log
! USER_HOST SLEEPVAL events_test CREATE TABLE slow_event_test (slo_val tinyint, val tinyint)
! USER_HOST SLEEPVAL events_test SET SESSION long_query_time=1
! USER_HOST SLEEPVAL events_test SET SESSION long_query_time=1
! USER_HOST SLEEPVAL events_test SET GLOBAL event_scheduler=on
! USER_HOST SLEEPVAL events_test SET GLOBAL long_query_time=20
! USER_HOST SLEEPVAL events_test SET SESSION long_query_time=10
! USER_HOST SLEEPVAL events_test SET GLOBAL long_query_time=1
! USER_HOST SLEEPVAL events_test SELECT 30 * 10
DROP EVENT long_event2;
"Make it quite long"
SET SESSION long_query_time=300;
-------------------------------------------------------
How to repeat:
See PushBuild results. For example,
https://intranet.mysql.com/~tsmith/bugs/showpush.pl?dir=mysql-5.1-marvel&order=68
This push on sol10-amd64-a shows even more problems in the results which may need attention:
https://intranet.mysql.com/~tsmith/bugs/showpush.pl?dir=mysql-5.1-marvel&order=64
