Bug #65643 event execute more than once at one time(concurrent)
Submitted: 17 Jun 2012 10:43 Modified: 28 Feb 2013 18:29
Reporter: Danniel Wallace Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Stored Routines Severity:S1 (Critical)
Version:5.1.32 OS:Linux
Assigned to: CPU Architecture:Any
Tags: event concurrent

[17 Jun 2012 10:43] Danniel Wallace
Description:
I create a event in my C++ program;

The sql is shown below:
CREATE DEFINER=`root`@`localhost` EVENT IF NOT EXISTS extract_lottery 
ON SCHEDULE EVERY 1 DAY 
STARTS TIMESTAMP '2012-06-14 21:50:00' 
ENDS TIMESTAMP '2012-06-15 00:00:00' 
ENABLE 
DO 
CALL extract_mphone();

It supposed to be execute once every day at 21:50:00.

When we test it, found at most time i work well, but some time the event
execute more than once at one time(concurrent).

The concurrency have confused me several days, hope any one tell me the reason. My email is dannielwallace@gmail.com, if want more detail infomation, please contact me or leave me message here.

I complete have no idea why this happend, only one clue:
when concurrency shown, the mysql server kept several connections for client user, some of client use the same account.(every acount has super priviledge).

Some proof for event concurrency:
err-log:
120614 19:50:00 [Note] Event Scheduler: Last execution of name_head.extract_lottery. Dropping.
120614 19:50:00 [Note] Event Scheduler: Last execution of name_head.extract_lottery. Dropping.
120614 19:50:00 [Note] Event Scheduler: Dropping name_head.extract_lottery
120614 19:50:00 [Note] Event Scheduler: Dropping name_head.extract_lottery
120614 19:50:00 [ERROR] Event Scheduler: [root@localhost][name_head.extract_lottery] Unknown event 'extract_lottery'
120614 19:50:00 [Note] Event Scheduler: [root@localhost].[name_head.extract_lottery] event execution failed.

bin-log(before and after "DROP EVENT `name_head`.`extract_lottery`", is the store program extract_mphone that event called ):
#120614 19:50:00 server id 1  end_log_pos 31512666 	Query	thread_id=422	exec_time=0	error_code=0
use name_head/*!*/;
SET TIMESTAMP=1339674600/*!*/;
BEGIN
/*!*/;
# at 31512666
#120614 19:50:00 server id 1  end_log_pos 31512809 	Query	thread_id=422	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
UPDATE lottery SET Reserve = 1 WHERE (Number =  NAME_CONST('v_number',189))
/*!*/;
# at 31512809
#120614 19:50:00 server id 1  end_log_pos 31512999 	Query	thread_id=422	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
DELETE FROM lottery_candidate where FamilyName= NAME_CONST('v_familyname',_latin1'成娇的茄子' COLLATE 'latin1_swedish_ci')
/*!*/;
# at 31512999
#120614 19:50:00 server id 1  end_log_pos 31513359 	Query	thread_id=422	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
INSERT INTO lottery_prize (Number,FamilyName,Sequency,Reserve,AreaGroup)  			VALUES ( NAME_CONST('v_number',189),  NAME_CONST('v_familyname',_latin1'成娇的茄子' COLLATE 'latin1_swedish_ci'),  NAME_CONST('v_sequency',3), 1,  NAME_CONST('v_areagroup',_latin1'5-90' COLLATE 'latin1_swedish_ci'))
/*!*/;
# at 31513359
#120614 19:50:00 server id 1  end_log_pos 31513386 	Xid = 61469
COMMIT/*!*/;
# at 31513386
#120614 19:50:00 server id 1  end_log_pos 31513494 	Query	thread_id=422	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
DROP EVENT `name_head`.`extract_lottery`
/*!*/;
# at 31513494
#120614 19:50:00 server id 1  end_log_pos 31513567 	Query	thread_id=423	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
BEGIN
/*!*/;
# at 31513567
#120614 19:50:00 server id 1  end_log_pos 31513710 	Query	thread_id=423	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
UPDATE lottery SET Reserve = 1 WHERE (Number =  NAME_CONST('v_number',212))
/*!*/;
# at 31513710
#120614 19:50:00 server id 1  end_log_pos 31513894 	Query	thread_id=423	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
DELETE FROM lottery_candidate where FamilyName= NAME_CONST('v_familyname',_latin1'小明' COLLATE 'latin1_swedish_ci')
/*!*/;
# at 31513894
#120614 19:50:00 server id 1  end_log_pos 31514248 	Query	thread_id=423	exec_time=0	error_code=0
SET TIMESTAMP=1339674600/*!*/;
INSERT INTO lottery_prize (Number,FamilyName,Sequency,Reserve,AreaGroup)  			VALUES ( NAME_CONST('v_number',212),  NAME_CONST('v_familyname',_latin1'小明' COLLATE 'latin1_swedish_ci'),  NAME_CONST('v_sequency',3), 1,  NAME_CONST('v_areagroup',_latin1'5-90' COLLATE 'latin1_swedish_ci'))
/*!*/;
# at 31514248
#120614 19:50:00 server id 1  end_log_pos 31514275 	Xid = 61491
COMMIT/*!*/;
# at 31514275

How to repeat:
I'm trying to repeat it, if succeed later, I will add here
[17 Jun 2012 11:15] Valeriy Kravchuk
Also, please, upgrade to recent version, 5.1.63, before any further checks. 5.1.32 is many years old, and hundreds of bugs were fixed since its release.
[17 Jun 2012 16:03] Danniel Wallace
I check changed history for mysql 5.1.32->5.1.64, found the describe of Bug #61005.

It may caused by Bug #61005:
CREATE IF NOT EXIST event will create multiple running events.

I prepeare to test it, if repeated succeed, another way to complete task is cost cheaper rather than upgrade the version of mysql server.

Anyway, I want get the real reason that cause event's concurrency.Hope anyone give some tips, thanks very much.
[18 Jun 2012 2:56] Danniel Wallace
Repeated.
[29 Jun 2012 14:24] Valeriy Kravchuk
Do you still have the same problem on 5.1.63+? Please, clarify.
[30 Jul 2012 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[12 Oct 2012 2:03] Danniel Wallace
sorry, I don't upgrade the version to 5.1.63
[30 Jan 2013 18:29] Sveta Smirnova
Thank you for the feedback.

This is indeed looks like bug #61005. Please try with current version 5.1.67 and inform us still exists after fix of this bug.
[1 Mar 2013 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".